Bug #52453 handler_commit is incremented for InnoDB SELECT queries
Submitted: 29 Mar 2010 22:16 Modified: 30 Mar 2010 1:14
Reporter: Justin Swanhart Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server Severity:S2 (Serious)
Version:5.1.43 OS:Any
Assigned to: CPU Architecture:Any
Tags: regression
Triage: Triaged: D3 (Medium)

[29 Mar 2010 22:16] Justin Swanhart
Description:
mysql> 
mysql> CREATE TABLE test.t1 (c1 int) engine=innodb;
Query OK, 0 rows affected (0.20 sec)

mysql> flush status;
Query OK, 0 rows affected (0.00 sec)

mysql> show status like 'handler_commit';
+----------------+-------+
| Variable_name  | Value |
+----------------+-------+
| Handler_commit | 0     |
+----------------+-------+
1 row in set (0.00 sec)

mysql> select * from test.t1;
Empty set (0.00 sec)

mysql> show status like 'handler_commit';
+----------------+-------+
| Variable_name  | Value |
+----------------+-------+
| Handler_commit | 1     | <-- This should be 0
+----------------+-------+
1 row in set (0.00 sec)

mysql> 

How to repeat:
CREATE TABLE test.t1 (c1 int) engine=innodb;
flush status;
show status like 'handler_commit';
select * from test.t1;
show status like 'handler_commit';

Why the counter is incremented:
sql/handler.cc:dispatch_command() calls ha_rollback_or_autocommit() which eventually calls ha_commit_one_phase() which increments the counter.

Suggested fix:
Unknown.  I'm not familiar enough with the InnoDB code to know if it is safe to only call ha_rollback_or_autocommit for dispatched commands which might have modified data.  I don't think it makes sense to call ha_autocommit_or_rollback for SELECT queries.
[29 Mar 2010 23:06] Miguel Solorzano
Thank you for the bug report.

[miguel@tikal ~]$ dbs/5.0/bin/mysql -uroot test
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1
Server version: 5.0.91-debug Source distribution

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> CREATE TABLE test.t1 (c1 int) engine=innodb;
Query OK, 0 rows affected (0.08 sec)

mysql> flush status;
Query OK, 0 rows affected (0.00 sec)

mysql> show status like 'handler_commit';
+----------------+-------+
| Variable_name  | Value |
+----------------+-------+
| Handler_commit | 0     | 
+----------------+-------+
1 row in set (0.00 sec)

mysql> select * from test.t1;
Empty set (0.00 sec)

mysql> show status like 'handler_commit';
+----------------+-------+
| Variable_name  | Value |
+----------------+-------+
| Handler_commit | 0     | 
+----------------+-------+
1 row in set (0.00 sec)

mysql> exit
Bye
[miguel@tikal ~]$ dbs/5.0/bin/mysqladmin -uroot shutdown
skipped 9 bytes from file: socket (3)
[miguel@tikal ~]$ dbs/5.1/bin/mysql -uroot test
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1
Server version: 5.1.46-debug Source distribution

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> CREATE TABLE test.t1 (c1 int) engine=innodb;
Query OK, 0 rows affected (0.11 sec)

mysql> flush status;
Query OK, 0 rows affected (0.00 sec)

mysql> show status like 'handler_commit';
+----------------+-------+
| Variable_name  | Value |
+----------------+-------+
| Handler_commit | 0     |
+----------------+-------+
1 row in set (0.00 sec)

mysql> select * from test.t1;
Empty set (0.00 sec)

mysql> show status like 'handler_commit';
+----------------+-------+
| Variable_name  | Value |
+----------------+-------+
| Handler_commit | 1     |
+----------------+-------+
1 row in set (0.00 sec)

mysql>
[30 Mar 2010 1:14] Justin Swanhart
I meant sql_parse.cc, not handler.cc
[1 Apr 2010 4:19] Jimmy Yang
MySQL folks should look into this:

The difference (between 5.1 and 5.0) comes from an additional call to ha_autocommit_or_rollback() in 5.1 at the end of dispatch_command()

#0  ha_autocommit_or_rollback
#1  0x000000000061f6c6 in dispatch_command () at sql_parse.cc:1577

And the ha_commit_count is incremented by
status_var_increment(thd->status_var.ha_commit_count) in ha_commit_one_phase() a bit later:

ha_commit_one_phase
ha_commit_trans
ha_autocommit_or_rollback
dispatch_command

In fact in both 5.1 and 5.0, the select transaction already committed in following stack before this ha_autocommit_or_rollback() call:

trx_commit_for_mysql
innobase_commit_low
innobase_commit
ha_innobase::external_lock
handler::ha_external_lock
unlock_external 
mysql_unlock_read_tables
JOIN::join_free

This transaction is registered with mysql in following stack:

trans_register_ha
innobase_register_stmt
innobase_register_trx_and_stmt
ha_innobase::external_lock
handler::ha_external_lock 
lock_external
mysql_lock_tables
lock_tables
open_and_lock_tables_derived

Please Note, this registration set only if OPTION_NOT_AUTOCOMMIT is set.

The reason that MyISAM table does not have the counter incremented is due to thd->transaction.stmt.ha_list is null, so it directly returns in ha_autocommit_or_rollback():

(gdb) p thd->transaction.stmt.ha_list
$17 = (Ha_trx_info *) 0x0

So in this case, the additional ha_autocommit_or_rollback() in dispatch_command() cause this difference of increasing the ha_commit_count.

However, there does exist a stmt transaction for the select (for XA etc.).
[11 Mar 2011 14:57] Cyril SCETBON
Still exists in 5.5.9 :

mysql> show status like 'Handler_Commit';
+----------------+-------+
| Variable_name  | Value |
+----------------+-------+
| Handler_commit | 0     |
+----------------+-------+
1 row in set (0.00 sec)

mysql> select 1 from t1 limit 1;
+---+
| 1 |
+---+
| 1 |
+---+
1 row in set (0.00 sec)

mysql> show status like 'Handler_Commit';
+----------------+-------+
| Variable_name  | Value |
+----------------+-------+
| Handler_commit | 1     |
+----------------+-------+
1 row in set (0.00 sec)
[11 Mar 2011 15:00] Cyril SCETBON
However, when I do not access a table it's not incremented :

mysql> show status like 'Handler_Commit';
+----------------+-------+
| Variable_name  | Value |
+----------------+-------+
| Handler_commit | 1     |
+----------------+-------+
1 row in set (0.00 sec)

mysql> select 1;
+---+
| 1 |
+---+
| 1 |
+---+
1 row in set (0.00 sec)

mysql> show status like 'Handler_Commit';
+----------------+-------+
| Variable_name  | Value |
+----------------+-------+
| Handler_commit | 1     |
+----------------+-------+
1 row in set (0.00 sec)
[22 Mar 2012 9:34] yang wang
handler_commit/rollback

Attachment: 1.JPG (image/jpeg, text), 44.73 KiB.

[22 Mar 2012 9:37] yang wang
I testing this case in mysql-comm 5.5.21 and mysql-comm 5.1.47 with builtin innodb as follow

1)mysql-comm 5.5.21
mysql> show global variables like '%version%';
+-------------------------+---------------------+
| Variable_name           | Value               |
+-------------------------+---------------------+
| innodb_version          | 1.1.8               |
| protocol_version        | 10                  |
| slave_type_conversions  |                     |
| version                 | 5.5.20-log          |
| version_comment         | Source distribution |
| version_compile_machine | x86_64              |
| version_compile_os      | Linux               |
+-------------------------+---------------------+
7 rows in set (0.01 sec)

mysql> show global status like '%handler_commit%';
+----------------+-------+
| Variable_name  | Value |
+----------------+-------+
| Handler_commit | 2     |
+----------------+-------+
1 row in set (0.00 sec)

mysql> select sql_no_cache * from t1;
Empty set (0.00 sec)

mysql> show global status like '%handler_commit%';
+----------------+-------+
| Variable_name  | Value |
+----------------+-------+
| Handler_commit | 3     |
+----------------+-------+
1 row in set (0.01 sec)

mysql> select sql_no_cache * from t1;
Empty set (0.00 sec)

mysql> show global status like '%handler_commit%';
+----------------+-------+
| Variable_name  | Value |
+----------------+-------+
| Handler_commit | 4     |
+----------------+-------+
1 row in set (0.00 sec)

2)mysql-comm 5.1.47 with builtin innodb
root@localhost:d1 17:27:26>show global variables like '%version%';
+-------------------------+---------------------+
| Variable_name           | Value               |
+-------------------------+---------------------+
| protocol_version        | 10                  |
| version                 | 5.1.47-log          |
| version_comment         | Source distribution |
| version_compile_machine | x86_64              |
| version_compile_os      | unknown-linux-gnu   |
+-------------------------+---------------------+
5 rows in set (0.00 sec)

root@localhost:d1 17:27:29>show global status like '%handler_commit%';
+----------------+-------+
| Variable_name  | Value |
+----------------+-------+
| Handler_commit | 1     |
+----------------+-------+
1 row in set (0.00 sec)

root@localhost:d1 17:27:35>select sql_no_cache * from t1;
+----+-----+
| id | num |
+----+-----+
|  1 |   3 |
+----+-----+
1 row in set (0.00 sec)

root@localhost:d1 17:27:47>show global status like '%handler_commit%';
+----------------+-------+
| Variable_name  | Value |
+----------------+-------+
| Handler_commit | 2     |
+----------------+-------+
1 row in set (0.00 sec)

root@localhost:d1 17:27:51>select sql_no_cache * from t1;
+----+-----+
| id | num |
+----+-----+
|  1 |   3 |
+----+-----+
1 row in set (0.00 sec)

root@localhost:d1 17:28:35>show global status like '%handler_commit%';
+----------------+-------+
| Variable_name  | Value |
+----------------+-------+
| Handler_commit | 3     |
+----------------+-------+
1 row in set (0.00 sec)
[22 Mar 2012 12:22] xiaobin lin
A command query is a single transaction, perhaps every select increase handler_commit is ok.
But I think it is puzzled that these statements:
>begin;
>select * from innodb_table1;
>select * from innodb_table2;
>commit;

add 3 to the handler_commit value.

is it better to add a "if (is_real_trans)" before "status_var_increment(thd->status_var.ha_commit_count);' ?
t
[23 Mar 2012 7:05] yang wang
Handler_rollbac testing in mysql-comm5.5.20 and mysql-comm 5.1.47 within builtin innodb,the env same as last testing box;

mysql> show global variables like '%version%';
+-------------------------+---------------------+
| Variable_name           | Value               |
+-------------------------+---------------------+
| innodb_version          | 1.1.8               |
| protocol_version        | 10                  |
| slave_type_conversions  |                     |
| version                 | 5.5.20-log          |
| version_comment         | Source distribution |
| version_compile_machine | x86_64              |
| version_compile_os      | Linux               |
+-------------------------+---------------------+
7 rows in set (0.00 sec)

mysql> show create table t1\G
*************************** 1. row ***************************
       Table: t1
Create Table: CREATE TABLE `t1` (
  `c1` int(11) DEFAULT NULL,
  UNIQUE KEY `unq_c1` (`c1`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8
1 row in set (0.00 sec)

mysql> show global status like '%handler_roll%';
+------------------+-------+
| Variable_name    | Value |
+------------------+-------+
| Handler_rollback | 1     |
+------------------+-------+
1 row in set (0.00 sec)

mysql> handler t1 open;     
Query OK, 0 rows affected (0.00 sec)

mysql> handler t1 read unq_c1=(4);   
Empty set (0.00 sec)

mysql> handler t1 close;
Query OK, 0 rows affected (0.00 sec)

mysql> show global status like '%handler_roll%';
+------------------+-------+
| Variable_name    | Value |
+------------------+-------+
| Handler_rollback | 1     |
+------------------+-------+
1 row in set (0.00 sec)

mysql> select sql_no_cache * from t1;
Empty set (0.00 sec)

root@localhost:d1 14:53:08>show global variables like '%version%';
+-------------------------+---------------------+
| Variable_name           | Value               |
+-------------------------+---------------------+
| protocol_version        | 10                  |
| version                 | 5.1.47-log          |
| version_comment         | Source distribution |
| version_compile_machine | x86_64              |
| version_compile_os      | unknown-linux-gnu   |
+-------------------------+---------------------+
5 rows in set (0.00 sec)

root@localhost:d1 14:53:14>show create table t1\G
*************************** 1. row ***************************
       Table: t1
Create Table: CREATE TABLE `t1` (
  `id` int(10) unsigned NOT NULL AUTO_INCREMENT,
  `num` tinyint(3) unsigned NOT NULL,
  PRIMARY KEY (`id`),
  UNIQUE KEY `unq_num` (`num`)
) ENGINE=InnoDB AUTO_INCREMENT=2 DEFAULT CHARSET=utf8
1 row in set (0.00 sec)

root@localhost:d1 14:53:19>show global status like '%handler_roll%';
+------------------+-------+
| Variable_name    | Value |
+------------------+-------+
| Handler_rollback | 0     |
+------------------+-------+
1 row in set (0.00 sec)

root@localhost:d1 14:53:42>handler t1 open;       
Query OK, 0 rows affected (0.00 sec)

root@localhost:d1 14:53:48>handler t1 read unq_num=(4);
Empty set (0.00 sec)

root@localhost:d1 14:54:03>handler t1 close;
Query OK, 0 rows affected (0.00 sec)

root@localhost:d1 14:54:12>show global status like '%handler_roll%';
+------------------+-------+
| Variable_name    | Value |
+------------------+-------+
| Handler_rollback | 0     |
+------------------+-------+
1 row in set (0.00 sec)

root@localhost:d1 14:55:07>select sql_no_cache * from t1;
+----+-----+
| id | num |
+----+-----+
|  1 |   3 |
+----+-----+
1 row in set (0.00 sec)
[30 Apr 2013 11:15] Vojtech Kurka
Still repeatable on 5.6.11