Bug #27655 Excessive SHOW VARIABLES LIKE 'tx_isolation'
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
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.
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