Bug #84332 | compression of mysql.gtid_executed has been prevented when super_read_only = 1 | ||
---|---|---|---|
Submitted: | 25 Dec 2016 3:30 | Modified: | 7 Jun 2017 3:49 |
Reporter: | yu zou | Email Updates: | |
Status: | Duplicate | Impact on me: | |
Category: | MySQL Server: Replication | Severity: | S2 (Serious) |
Version: | 5.7.16 5.7.17 | OS: | Any |
Assigned to: | Assigned Account | CPU Architecture: | Any |
Tags: | super_read_only mysql.gtid_executed |
[25 Dec 2016 3:30]
yu zou
[25 Dec 2016 3:39]
yu zou
with grid_mode=1 ----> with gtid_mode = 1
[25 Dec 2016 11:08]
MySQL Verification Team
I'm waiting for my slave to start increasing substantially in memory usage. In mean time, I've gotten these counts: mysql> select count(*),now(),version(),@@super_read_only,@@read_only from mysql.gtid_executed; +----------+---------------------+------------+-------------------+-------------+ | count(*) | now() | version() | @@super_read_only | @@read_only | +----------+---------------------+------------+-------------------+-------------+ | 67636 | 2016-12-24 16:39:12 | 5.7.17-log | 1 | 1 | +----------+---------------------+------------+-------------------+-------------+ 1 row in set (1.46 sec) mysql> select count(*),now(),version(),@@super_read_only,@@read_only from mysql.gtid_executed; +----------+---------------------+------------+-------------------+-------------+ | count(*) | now() | version() | @@super_read_only | @@read_only | +----------+---------------------+------------+-------------------+-------------+ | 69444 | 2016-12-24 16:39:18 | 5.7.17-log | 1 | 1 | +----------+---------------------+------------+-------------------+-------------+ 1 row in set (3.07 sec) mysql> select count(*),now(),version(),@@super_read_only,@@read_only from mysql.gtid_executed; +----------+---------------------+------------+-------------------+-------------+ | count(*) | now() | version() | @@super_read_only | @@read_only | +----------+---------------------+------------+-------------------+-------------+ | 76575 | 2016-12-24 16:39:46 | 5.7.17-log | 1 | 1 | +----------+---------------------+------------+-------------------+-------------+ 1 row in set (0.22 sec)
[25 Dec 2016 11:45]
MySQL Verification Team
I've noticed this on the slave now.... ---TRANSACTION 4706006, ACTIVE 253 sec rollback mysql tables in use 1, locked 1 ROLLING BACK 5798 lock struct(s), heap size 433768, 1257611 row lock(s), undo log entries 22345 MySQL thread id 4, OS thread handle 5164, query id 0 Compressing gtid_executed table
[25 Dec 2016 11:51]
MySQL Verification Team
Verifying on 5.7.17. Though, I'm not seeing a memory leak yet. But this gtid compression thread taking locks and rolling back is a serious problem. When table grows larger and it tries to lock entire table row-by-row, innodb buffer pool won't have enough memory for the lock structs.
[25 Dec 2016 11:52]
MySQL Verification Team
Another symptom, I'm seeing the slave complain more and more due to this: [Warning] Slave SQL for channel '': Error in Xid_log_event: Commit could not be completed, 'Lock wait timeout exceeded; try restarting transaction', Error_code: 1205 [Warning] Slave SQL for channel '': Error in Xid_log_event: Commit could not be completed, 'Lock wait timeout exceeded; try restarting transaction', Error_code: 1205
[25 Dec 2016 12:24]
MySQL Verification Team
fwiw, this is fixed in the current source tree of 5.7. I'll see what change fixed it, as this should be a duplicate of that bug...
[25 Dec 2016 12:34]
yu zou
In our case, it takes about 3-5 days to OOM, very slowly, it had happened on MySQL5.7.16(5.7.16-log MySQL Community Server (GPL))+centos6.2 & MySQL5.7.17(compile with tcmalloc) +centos 6.4 .
[25 Dec 2016 12:41]
MySQL Verification Team
I will suggest we wait for the next version 5.7.18 and test. I search quite a bit, but wasn't able to find which bugfix fixed this, but I've tested; mysql> select count(*),now(),version(),@@super_read_only,@@read_only from mysql.gtid_executed; +----------+---------------------+------------+-------------------+-------------+ | count(*) | now() | version() | @@super_read_only | @@read_only | +----------+---------------------+------------+-------------------+-------------+ | 6 | 2016-12-25 14:41:09 | 5.7.18-log | 1 | 1 | +----------+---------------------+------------+-------------------+-------------+ 1 row in set (0.00 sec) mysql> select count(*),now(),version(),@@super_read_only,@@read_only from mysql.gtid_executed; +----------+---------------------+------------+-------------------+-------------+ | count(*) | now() | version() | @@super_read_only | @@read_only | +----------+---------------------+------------+-------------------+-------------+ | 753 | 2016-12-25 14:41:09 | 5.7.18-log | 1 | 1 | +----------+---------------------+------------+-------------------+-------------+ 1 row in set (0.00 sec) mysql> select count(*),now(),version(),@@super_read_only,@@read_only from mysql.gtid_executed; +----------+---------------------+------------+-------------------+-------------+ | count(*) | now() | version() | @@super_read_only | @@read_only | +----------+---------------------+------------+-------------------+-------------+ | 69 | 2016-12-25 14:41:10 | 5.7.18-log | 1 | 1 | +----------+---------------------+------------+-------------------+-------------+ 1 row in set (0.00 sec)
[19 Jan 2017 4:58]
Marcos Albe
we stumbled upon identical case; Running flush-logs before is a good workaround, but sadly there's another bug that prevents running unattended (http://bugs.mysql.com/bug.php?id=84350 ; https://bugs.mysql.com/bug.php?id=84437) # shutdown thread mysqld_4305.pmp: 1 pthread_join(libpthread.so.0),terminate_compress_gtid_table_thread,mysqld_main,__libc_start_main(libc.so.6),_start # gtid compress thread mysqld_4305.pmp: 1 fsync(libpthread.so.0),os_file_flush_func,fil_flush,log_write_up_to,trx_commit_low,trx_commit,trx_rollback_to_savepoint_low,trx_rollback_low,trx_rollback_for_mysql,innobase_rollback,ha_rollback_low,MYSQL_BIN_LOG::rollback,ha_rollback_trans,ha_commit_trans,System_table_access::close_table,Gtid_table_access_context::deinit,Gtid_table_persistor::compress_in_single_transaction,Gtid_table_persistor::compress,compress_gtid_table,pfs_spawn_thread,start_thread(libpthread.so.0),clone(libc.so.6)
[19 Jan 2017 5:35]
Marcos Albe
Another pair of stacks mysqld_4304.pmp: 1 pthread_join(libpthread.so.0),terminate_compress_gtid_table_thread,mysqld_main,__libc_start_main(libc.so.6),_start ...snip... mysqld_4304.pmp: 1 cmp_rec_rec_with_match,btr_estimate_number_of_different_key_vals,dict_stats_update_transient_for_index,dict_stats_update_transient,dict_stats_update,row_update_for_mysql_using_upd_graph,row_update_for_mysql,ha_innobase::delete_row,handler::ha_delete_row,Gtid_table_persistor::compress_first_consecutive_range,Gtid_table_persistor::compress_in_single_transaction,Gtid_table_persistor::compress,compress_gtid_table,pfs_spawn_thread,start_thread(libpthread.so.0),clone(libc.so.6)
[7 Jun 2017 3:49]
Venkatesh Duggirala
Post by developer: ================== This bug is fixed in 5.7.18 with the following bug "Bug #22857926 ASSERTION `! IS_SET()' AT SQL_ERROR.CC:38 IN READ_ONLY MODE FOR MANY RPL CMDS". Note copied from 5.7.18 release notes: ====================================== Replication: The server prevented several replication-related administrative statements from working if the read_only system variable was enabled. (Bug #22857926) Regards, Venkatesh.