Details
-
Bug
-
Status: Done
-
Low
-
Resolution: Fixed
-
5.7.x, 8.0.x, Not 5.6.x
-
None
Description
On 5.7, innodb.percona_log_slow_innodb crashes intermittently on debug:
[ 85%] innodb.percona_log_slow_innodb w8 [ fail ] Test ended at 2019-02-26 18:33:43 CURRENT_TEST: innodb.percona_log_slow_innodb mysqltest: At line 105: query 'SET @saved_slow_query_log = @@GLOBAL.slow_query_log' failed: 2006: MySQL server has gone away ... mysqld: /tmp/ps/sql/log.cc:1479: bool Query_logger::slow_log_write(THD*, const char*, size_t): Assertion `thd->enable_slow_log && opt_slow_log' failed. 18:33:42 UTC - mysqld got signal 6 ; ... #7 0x00007f19e34d8412 in __GI___assert_fail (assertion=0x5610d6728d78 "thd->enable_slow_log && opt_slow_log", file=0x5610d6728542 "/tmp/ps/sql/log.cc", line=1479, function=0x5610d67294e0 <Query_logger::slow_log_write(THD*, char const*, unsigned long)::__PRETTY_FUNCTION__> "bool Query_logger::slow_log_write(THD*, const char*, size_t)") at assert.c:101 #8 0x00005610d5b0c1e0 in Query_logger::slow_log_write (this=0x5610d7500680 <query_logger>, thd=0x7f19cac19000, query=0x7f19cac27030 "COMMIT", query_length=6) at /tmp/ps/sql/log.cc:1479 #9 0x00005610d5b0d9b4 in log_slow_do (thd=0x7f19cac19000) at /tmp/ps/sql/log.cc:1993 #10 0x00005610d5b0d9e4 in log_slow_statement (thd=0x7f19cac19000) at /tmp/ps/sql/log.cc:2000 #11 0x00005610d5c22268 in dispatch_command (thd=0x7f19cac19000, com_data=0x7f19e5d37d80, command=COM_QUERY) at /tmp/ps/sql/sql_parse.cc:1978 #12 0x00005610d5c1f9a0 in do_command (thd=0x7f19cac19000) at /tmp/ps/sql/sql_parse.cc:1053 #13 0x00005610d5d6490a in handle_connection (arg=0x7f19d9a5c640) at /tmp/ps/sql/conn_handler/connection_handler_per_thread.cc:318 #14 0x00005610d605e02c in pfs_spawn_thread (arg=0x7f19de7b8120) at /tmp/ps/storage/perfschema/pfs.cc:2190 #15 0x00007f19e552f6db in start_thread (arg=0x7f19e5d38700) at pthread_create.c:463 #16 0x00007f19e35c988f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
Two things wrong with that assert:
1) Two conditions tested through conjunction, no indication which part failed
2) opt_slow_log test is racy with other threads updating this variable after the current thread has already made the decision to log