Bug #27655 Excessive SHOW VARIABLES LIKE 'tx_isolation'

Submitted: 4 Apr 2007 18:09 Modified: 13 Apr 2007 8:31
Reporter: Jeremy Cole (Basic Quality Contributor) (OCA) Email Updates:
Status: Closed Impact on me:
None 
Category:Connector / J Severity:S3 (Non-critical)
Version:5.0.5 OS:Any
Assigned to: CPU Architecture:Any

[4 Apr 2007 18: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 18: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 5: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 8:31] MC Brown
A note has been added to the 5.0.6 changelog.

Portions of this website are copyright © 2001, 2002 The PHP Group

Page generated in 0.052 sec. using MySQL 8.4.7-u6-cloud

Timestamp references displayed by the system are UTC.
Content reproduced on this site is the property of the respective copyright holders.
It is not reviewed in advance by Oracle and does not necessarily represent the opinion of Oracle or any other party.