Description:
When executing a repeated, non-concurrent RESTORE of a 100K file containing dozens of tables, against a background workload of DDL and KILL, the restore asserted as follows:
mysqld: sql_error.cc:358: void Diagnostics_area::set_ok_status(THD*, ulonglong, ulonglong, const char*): Assertion `! is_set()' failed.
# 13:05:47 #6 0x000000315a42bec9 in __assert_fail () from /lib64/libc.so.6
# 13:05:47 #7 0x0000000000747eb9 in Diagnostics_area::set_ok_status (this=0x7ff0661b9da0, thd=0x7ff060320a18, affected_rows_arg=0, last_insert_id_arg=0,
# 13:05:47 message_arg=0x0) at sql_error.cc:358
# 13:05:47 #8 0x0000000000581e2c in my_ok (thd=0x7ff060320a18, affected_rows=0, id=0, message=0x0) at sql_class.h:2648
# 13:05:47 #9 0x000000000075597b in mysql_truncate (thd=0x7ff060320a18, table_list=0x2ed64b8, dont_send_ok=false) at sql_delete.cc:1280
# 13:05:47 #10 0x0000000000688294 in mysql_execute_command (thd=0x7ff060320a18) at sql_parse.cc:3373
# 13:05:47 #11 0x000000000073f4e1 in Execute_sql_statement::execute_server_code (this=0x7ff0661b9c70, thd=0x7ff060320a18) at sql_prepare.cc:2934
# 13:05:47 #12 0x000000000073eb6d in Prepared_statement::execute_server_runnable (this=0x7ff0661b9800, server_runnable=0x7ff0661b9c70) at sql_prepare.cc:3438
# 13:05:47 #13 0x000000000073fac2 in Ed_connection::execute_direct (this=0x7ff0661b9da0, server_runnable=0x7ff0661b9c70) at sql_prepare.cc:3967
# 13:05:47 #14 0x000000000073fbe3 in Ed_connection::execute_direct (this=0x7ff0661b9da0, sql_text=
# 13:05:47 {str = 0x3327e18 "TRUNCATE TABLE `testdb_N`.`t1_base92_N`", length = 39}) at sql_prepare.cc:3933
# 13:05:47 #15 0x00000000008ad3ad in run_service_interface_sql (thd=0x7ff060320a18, ed_connection=0x7ff0661b9da0, query=0x7ff0661ba088, get_warnings=true)
# 13:05:47 at si_objects.cc:242
# 13:05:47 #16 0x00000000008adc8a in obs::truncate_tables (thd=0x7ff060320a18, table_list=0x3627b38) at si_objects.cc:3525
# 13:05:47 #17 0x0000000000ad7efd in Backup_restore_ctx::lock_tables_for_restore (this=0x7ff0661ba210) at kernel.cc:1125
# 13:05:47 #18 0x0000000000ad856b in Backup_restore_ctx::do_restore (this=0x7ff0661ba210, overwrite=true) at kernel.cc:1660
# 13:05:47 #19 0x0000000000ada7ce in execute_backup_command (thd=0x7ff060320a18, lex=0x7ff0603222f8, backupdir=0x7ff0661bb190, overwrite=true, skip_gap_event=false)
# 13:05:47 at kernel.cc:296
# 13:05:47 #20 0x0000000000685b57 in mysql_execute_command (thd=0x7ff060320a18) at sql_parse.cc:2482
# 13:05:47 #21 0x000000000068d787 in mysql_parse (thd=0x7ff060320a18, inBuf=0x2fdac50 "RESTORE FROM '/tmp/backup5975-288' OVERWRITE", length=44,
# 13:05:47 found_semicolon=0x7ff0661bbf00) at sql_parse.cc:5985
# 13:05:47 #22 0x000000000068e320 in dispatch_command (command=COM_QUERY, thd=0x7ff060320a18, packet=0x7ff060d2d4e9 "RESTORE FROM '/tmp/backup5975-288' OVERWRITE",
# 13:05:47 packet_length=44) at sql_parse.cc:1078
# 13:05:47 #23 0x000000000068f892 in do_command (thd=0x7ff060320a18) at sql_parse.cc:760
# 13:05:47 #24 0x000000000067c6b0 in handle_one_connection (arg=0x7ff060320a18) at sql_connect.cc:1164
# 13:05:47 #25 0x000000315b0073da in start_thread () from /lib64/libpthread.so.0
# 13:05:47 #26 0x000000315a4e627d in clone () from /lib64/libc.so.6
My speculation is that there has been an intermingle of messages from the RESTORE and from the TRUNCATE to the client. In a non-debug binary, this may cause the client and the server to lose synchronization, possibly causing an error on the client side and/or the loss of the ID number returned by the RESTORE.
How to repeat:
This was seen only once over hundreds of RESTOREs. If it is repeatable, a test case will be provided. In the meantime, the core and the binary will be uploaded.
Description: When executing a repeated, non-concurrent RESTORE of a 100K file containing dozens of tables, against a background workload of DDL and KILL, the restore asserted as follows: mysqld: sql_error.cc:358: void Diagnostics_area::set_ok_status(THD*, ulonglong, ulonglong, const char*): Assertion `! is_set()' failed. # 13:05:47 #6 0x000000315a42bec9 in __assert_fail () from /lib64/libc.so.6 # 13:05:47 #7 0x0000000000747eb9 in Diagnostics_area::set_ok_status (this=0x7ff0661b9da0, thd=0x7ff060320a18, affected_rows_arg=0, last_insert_id_arg=0, # 13:05:47 message_arg=0x0) at sql_error.cc:358 # 13:05:47 #8 0x0000000000581e2c in my_ok (thd=0x7ff060320a18, affected_rows=0, id=0, message=0x0) at sql_class.h:2648 # 13:05:47 #9 0x000000000075597b in mysql_truncate (thd=0x7ff060320a18, table_list=0x2ed64b8, dont_send_ok=false) at sql_delete.cc:1280 # 13:05:47 #10 0x0000000000688294 in mysql_execute_command (thd=0x7ff060320a18) at sql_parse.cc:3373 # 13:05:47 #11 0x000000000073f4e1 in Execute_sql_statement::execute_server_code (this=0x7ff0661b9c70, thd=0x7ff060320a18) at sql_prepare.cc:2934 # 13:05:47 #12 0x000000000073eb6d in Prepared_statement::execute_server_runnable (this=0x7ff0661b9800, server_runnable=0x7ff0661b9c70) at sql_prepare.cc:3438 # 13:05:47 #13 0x000000000073fac2 in Ed_connection::execute_direct (this=0x7ff0661b9da0, server_runnable=0x7ff0661b9c70) at sql_prepare.cc:3967 # 13:05:47 #14 0x000000000073fbe3 in Ed_connection::execute_direct (this=0x7ff0661b9da0, sql_text= # 13:05:47 {str = 0x3327e18 "TRUNCATE TABLE `testdb_N`.`t1_base92_N`", length = 39}) at sql_prepare.cc:3933 # 13:05:47 #15 0x00000000008ad3ad in run_service_interface_sql (thd=0x7ff060320a18, ed_connection=0x7ff0661b9da0, query=0x7ff0661ba088, get_warnings=true) # 13:05:47 at si_objects.cc:242 # 13:05:47 #16 0x00000000008adc8a in obs::truncate_tables (thd=0x7ff060320a18, table_list=0x3627b38) at si_objects.cc:3525 # 13:05:47 #17 0x0000000000ad7efd in Backup_restore_ctx::lock_tables_for_restore (this=0x7ff0661ba210) at kernel.cc:1125 # 13:05:47 #18 0x0000000000ad856b in Backup_restore_ctx::do_restore (this=0x7ff0661ba210, overwrite=true) at kernel.cc:1660 # 13:05:47 #19 0x0000000000ada7ce in execute_backup_command (thd=0x7ff060320a18, lex=0x7ff0603222f8, backupdir=0x7ff0661bb190, overwrite=true, skip_gap_event=false) # 13:05:47 at kernel.cc:296 # 13:05:47 #20 0x0000000000685b57 in mysql_execute_command (thd=0x7ff060320a18) at sql_parse.cc:2482 # 13:05:47 #21 0x000000000068d787 in mysql_parse (thd=0x7ff060320a18, inBuf=0x2fdac50 "RESTORE FROM '/tmp/backup5975-288' OVERWRITE", length=44, # 13:05:47 found_semicolon=0x7ff0661bbf00) at sql_parse.cc:5985 # 13:05:47 #22 0x000000000068e320 in dispatch_command (command=COM_QUERY, thd=0x7ff060320a18, packet=0x7ff060d2d4e9 "RESTORE FROM '/tmp/backup5975-288' OVERWRITE", # 13:05:47 packet_length=44) at sql_parse.cc:1078 # 13:05:47 #23 0x000000000068f892 in do_command (thd=0x7ff060320a18) at sql_parse.cc:760 # 13:05:47 #24 0x000000000067c6b0 in handle_one_connection (arg=0x7ff060320a18) at sql_connect.cc:1164 # 13:05:47 #25 0x000000315b0073da in start_thread () from /lib64/libpthread.so.0 # 13:05:47 #26 0x000000315a4e627d in clone () from /lib64/libc.so.6 My speculation is that there has been an intermingle of messages from the RESTORE and from the TRUNCATE to the client. In a non-debug binary, this may cause the client and the server to lose synchronization, possibly causing an error on the client side and/or the loss of the ID number returned by the RESTORE. How to repeat: This was seen only once over hundreds of RESTOREs. If it is repeatable, a test case will be provided. In the meantime, the core and the binary will be uploaded.