Bug #27655 Excessive SHOW VARIABLES LIKE 'tx_isolation'
Submitted: 4 Apr 2007 20:09 Modified: 13 Apr 2007 10:31
Reporter: Jeremy Cole (Basic Quality Contributor)
Status: Closed
Category:Connector/J Severity:S3 (Non-critical)
Version:5.0.5 OS:Any
Assigned to: Target Version:

[4 Apr 2007 20:09] Jeremy Cole 
Description:
MySQL Connector/J 5.0.5 is issuing a SHOW VARIABLES LIKE 'tx_isolation' from
Connection.getTransactionIsolation with the following code:

if (versionMeetsMinimum(4, 0, 3)) {
  query = "SHOW VARIABLES LIKE 'tx_isolation'"; 
} else {
  query = "SHOW VARIABLES LIKE 'transaction_isolation'";
}

This is called from ReplicationConnection.swapConnections every time.

This should use SELECT @@session.tx_isolation instead (or even better, cache the value?),
as SHOW VARIABLES LIKE is not very cheap, and seems to only get more expensive with time
(INFORMATION_SCHEMA, etc.).  Note the different code path taken by the two:

mysql> show profiles;
+----------+------------+------------------------------------+
| Query_ID | Duration   | Query                              |
+----------+------------+------------------------------------+
|        0 | 0.00008700 | set profiling = 1                  | 
|        1 | 0.00105600 | show variables like 'tx_isolation' | 
|        2 | 0.00014700 | select @@session.tx_isolation      | 
+----------+------------+------------------------------------+

mysql> show profile source for query 1;
+--------------------+------------+-----------------------+---------------+-------------+
| Status             | Duration   | Source_function       | Source_file   | Source_line
|
+--------------------+------------+-----------------------+---------------+-------------+
| Opening tables     | 0.00003800 | open_tables           | sql_base.cc   |        2106 |

| System lock        | 0.00004800 | mysql_lock_tables     | lock.cc       |         153 |

| Table lock         | 0.00000600 | mysql_lock_tables     | lock.cc       |         162 |

| init               | 0.00001100 | mysql_select          | sql_select.cc |        2073 |

| optimizing         | 0.00001300 | optimize              | sql_select.cc |         617 |

| statistics         | 0.00000600 | optimize              | sql_select.cc |         773 |

| preparing          | 0.00001300 | optimize              | sql_select.cc |         783 |

| executing          | 0.00001200 | exec                  | sql_select.cc |        1407 |

| Sending data       | 0.00007800 | exec                  | sql_select.cc |        1925 |

| end                | 0.00075100 | mysql_select          | sql_select.cc |        2118 |

| query end          | 0.00001000 | mysql_execute_command | sql_parse.cc  |        5085 |

| freeing items      | 0.00000600 | mysql_parse           | sql_parse.cc  |        5973 |

| closing tables     | 0.00001600 | dispatch_command      | sql_parse.cc  |        2120 |

| removing tmp table | 0.00000500 | free_tmp_table        | sql_select.cc |        9856 |

| closing tables     | 0.00003100 | free_tmp_table        | sql_select.cc |        9884 |

| logging slow query | 0.00000700 | log_slow_statement    | sql_parse.cc  |        2178 |

| cleaning up        | 0.00000500 | dispatch_command      | sql_parse.cc  |        2143 |

+--------------------+------------+-----------------------+---------------+-------------+
17 rows in set (0.00 sec)

mysql> show profile source for query 2;
+----------------------+------------+-----------------------+---------------+-------------+
| Status               | Duration   | Source_function       | Source_file   | Source_line
|
+----------------------+------------+-----------------------+---------------+-------------+
| checking permissions | 0.00004100 | check_access          | sql_parse.cc  |        5256
| 
| Opening tables       | 0.00000800 | open_tables           | sql_base.cc   |        2106
| 
| init                 | 0.00001200 | mysql_select          | sql_select.cc |        2073
| 
| optimizing           | 0.00001800 | optimize              | sql_select.cc |         617
| 
| executing            | 0.00000600 | exec                  | sql_select.cc |        1407
| 
| end                  | 0.00002600 | mysql_select          | sql_select.cc |        2118
| 
| query end            | 0.00000800 | mysql_execute_command | sql_parse.cc  |        5085
| 
| freeing items        | 0.00000600 | mysql_parse           | sql_parse.cc  |        5973
| 
| logging slow query   | 0.00001600 | log_slow_statement    | sql_parse.cc  |        2178
| 
| cleaning up          | 0.00000600 | dispatch_command      | sql_parse.cc  |        2143
| 
+----------------------+------------+-----------------------+---------------+-------------+
10 rows in set (0.00 sec)

This is causing a system with already fairly high CPU to spend a lot of real time in SHOW
VARIABLES.

How to repeat:
ReplicationConnection.swapConnections
[4 Apr 2007 20:41] Mark Matthews 
For now, a workaround would be to add useLocalSessionState=true to your JDBC url, and the
driver will "trust" the state for autocommit and transaction isolation that it has
cached.

I'll look into SELECT @@session.tx_isolation, but recently it re-surfaced that there are
bugs surrounding that functionality always returning the correct transaction isolation
level.
[5 Apr 2007 7:38] Bugs System 
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/23855
[13 Apr 2007 10:31] MC Brown 
A note has been added to the 5.0.6 changelog.