MySQL Bugs: #31222: com_% global status counters behave randomly with mysql_change

Bug #31222	com_% global status counters behave randomly with mysql_change_user
Submitted:	27 Sep 2007 6:26	Modified:	10 Feb 2009 21:20
Reporter:	Shane Bester (Platinum Quality Contributor)	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: General	Severity:	S3 (Non-critical)
Version:	5.0.50, 5.1.23	OS:	Any
Assigned to:	Alexander Nozdrin	CPU Architecture:	Any
Tags:	mysql_change_user

Description:
I was monitoring status variable to debug a problem, and found this output is wrong:

mysql> show global status like '%stmt%';
+-------------------------+-------+
| Variable_name           | Value |
+-------------------------+-------+
| Com_stmt_close          | 52495 |
| Com_stmt_execute        | 52644 |
| Com_stmt_fetch          | 0     |
| Com_stmt_prepare        | 74145 |
| Com_stmt_reset          | 0     |
| Com_stmt_send_long_data | 0     |
| Prepared_stmt_count     | 12    |
+-------------------------+-------+
7 rows in set (0.00 sec)

mysql> show global status like '%stmt%';
+-------------------------+-------+
| Variable_name           | Value |
+-------------------------+-------+
| Com_stmt_close          | 52493 | <--decreased!
| Com_stmt_execute        | 52642 | <--decreased!
| Com_stmt_fetch          | 0     |
| Com_stmt_prepare        | 74143 | <--decreased!
| Com_stmt_reset          | 0     |
| Com_stmt_send_long_data | 0     |
| Prepared_stmt_count     | 12    |
+-------------------------+-------+
7 rows in set (0.00 sec)

How to repeat:
I think this is possible memory corruption.  I'll make a testcase.
Indeed, mysqld-debug printed some errors to the logs from safemalloc that might be a root cause of this:

Version: '5.1.23-beta-debug'  socket: '/tmp/mysql.sock'  port: 3306  yes
Error: Memory allocated at sql_string.cc:51 was overrun, discovered at 'sql_select.cc:6493'
Error: Memory allocated at sql_string.cc:51 was overrun, discovered at 'mf_iocache.c:1825'
Error: Memory allocated at sql_string.cc:51 was overrun, discovered at 'lock.cc:389'
Error: Memory allocated at sql_string.cc:51 was overrun, discovered at 'array.c:281'

Suggested fix:
a counter should never go backwards. Looking at the code, I cannot see how this is possible.  Therefore I suspect memory corruption.

evidence of memory corruption:

mysql> call p1('select now()');
ERROR 1054 (42S22): Unknown column 'R☻.root.☻' in 'field list'
mysql>

I now suspect the cause of the problem is mysql_change_user call. after removing those from my application, the counters looks correct again.

testcase to show mysql_change_user messes up global variables.

Attachment: bug31222.php (application/octet-stream, text), 1.23 KiB.

ok, I uploaded a php testcase to show how com_select is affected by mysql_change_user.  I think the memory corruptions can be a different problem afterall.  Sorry for the mess here.

E:\wrk\bugs\bug31222>php bug31222.php
global status before select:
Array
(
    [0] => Com_select
    [Variable_name] => Com_select
    [1] => 0
    [Value] => 0
)
now running 100 selects
....................................................................................................
global status after select:
Array
(
    [0] => Com_select
    [Variable_name] => Com_select
    [1] => 100
    [Value] => 100
)
about to change user
global status after change user:
Array
(
    [0] => Com_select
    [Variable_name] => Com_select
    [1] => 0
    [Value] => 0 <-----what happened to the hundred selects??
)

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/42123

ChangeSet@1.2546, 2008-02-12 20:59:09+03:00, anozdrin@quad. +3 -0
  Fix for Bug#31222: com_% global status counters
  behave randomly with mysql_change_user.
    
  The problem was that global status variables were not updated
  in THD::check_user(), so thread statistics were lost after
  COM_CHANGE_USER.
    
  The fix is to update global status variables with the thread ones
  before preparing the thread for new user.

Pushed into 5.1-runtime.

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/42131

ChangeSet@1.2547, 2008-02-12 21:42:15+03:00, anozdrin@quad. +1 -0
  Additional fix for Bug#31222.

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/42198

ChangeSet@1.2550, 2008-02-13 13:00:24+03:00, anozdrin@quad. +5 -0
  Additional patch for Bug#31222: com_% global status counters
  behave randomly with mysql_change_user.
  
  The test case had to be moved into not_embedded_server.test file,
  because SHOW GLOBAL STATUS does not work properly in embedded
  server (see bug 34517).

Pushed into 5.1.24-rc

Pushed into 6.0.5-alpha

Noted in 5.1.24, 6.0.5 changelogs.

The mysql_change_user() C API function caused global Com_xxx status
variable values to be incorrect.

Also documented fix for 5.1.23-ndb-6.3.11.

Changing status to reflect the pending backport of this fix to 5.0

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/63329

2729 Alexander Nozdrin	2009-01-15
      Backport patch for Bug#31222 (com_% global status counters behave randomly
      with mysql_change_user) to 5.0.

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/63332

2735 Alexander Nozdrin	2009-01-15 [merge]
      Merge backport of patch for Bug#31222 from 5.0 to 5.1

Patch queued in 5.0-bugteam.

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/63352

2737 Alexander Nozdrin	2009-01-15
      Bug#31222: adding missed file.

Pushed into 6.0.10-alpha (revid:joro@sun.com-20090119171328-2hemf2ndc1dxl0et) (version source revid:timothy.smith@sun.com-20090116165151-xtp5e4z6qsmxyvy0) (merge vers: 6.0.10-alpha) (pib:6)

This has already been pushed into 6.0 (in 6.0.5).

Setting report to NDI pending push into 5.0.x.

Pushed into 5.0.78 (revid:joro@sun.com-20090203090422-v91rh3gmx2ulhbu9) (version source revid:chad@mysql.com-20090126173455-ia9503yxdqi30guh) (merge vers: 5.0.77) (pib:6)

Pushed into 5.1.32 (revid:joro@sun.com-20090203090549-gos3v4320vimrzg6) (version source revid:alik@sun.com-20090115115832-xw350j3qas13t5ga) (merge vers: 5.1.31) (pib:6)

Noted in 5.0.78 changelog.

Pushed into 5.1.32-ndb-6.3.23 (revid:tomas.ulin@sun.com-20090217131017-6u8qz1edkjfiobef) (version source revid:tomas.ulin@sun.com-20090203133556-9rclp06ol19bmzs4) (merge vers: 5.1.32-ndb-6.3.22) (pib:6)

Pushed into 5.1.32-ndb-6.4.3 (revid:tomas.ulin@sun.com-20090217134419-5ha6xg4dpedrbmau) (version source revid:tomas.ulin@sun.com-20090203133556-9rclp06ol19bmzs4) (merge vers: 5.1.32-ndb-6.3.22) (pib:6)

Pushed into 5.1.32-ndb-6.2.17 (revid:tomas.ulin@sun.com-20090217134216-5699eq74ws4oxa0j) (version source revid:tomas.ulin@sun.com-20090202111723-1zzwax187rtls913) (merge vers: 5.1.32-ndb-6.2.17) (pib:6)

Bug #48443 was marked as a duplicate of this one.