Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Fixed
-
10.2(EOL)
-
None
Description
perl ./mtr --mysqld=--loose-innodb-sync-debug
|
Over a hundred tests fail with several different assertion failures. Here is the list of the tests that failed on my machine (excluding those that failed on different reasons):
binlog_encryption.rpl_parallel
|
binlog_encryption.rpl_mixed_binlog_max_cache_size
|
federated.federated_transactions
|
multi_source.gtid_ignore_duplicates
|
rpl.rpl_ddl
|
rpl.rpl_innodb_mixed_dml
|
rpl.rpl_mixed_binlog_max_cache_size
|
rpl.rpl_drop_db_fail
|
rpl.rpl_gtid_crash
|
rpl.rpl_gtid_mdev4484
|
rpl.rpl_gtid_until
|
rpl.rpl_multi_engine
|
rpl.rpl_parallel
|
rpl.rpl_parallel_optimistic
|
rpl.rpl_read_only
|
rpl.rpl_truncate_3innodb
|
rpl.rpl_row_create_table
|
rpl.rpl_row_tabledefs_3innodb
|
rpl.rpl_old_master
|
rpl.rpl_gtid_strict
|
rpl.rpl_stm_binlog_max_cache_size
|
rpl.rpl_stm_stop_middle_group
|
binlog.flashback
|
binlog.binlog_row_mix_innodb_myisam
|
binlog.binlog_mysqlbinlog_row_trans
|
main-test_sql_discovery.mdl_sync
|
binlog.binlog_stm_mix_innodb_myisam
|
main.mdl_sync
|
main.partition_innodb_semi_consistent
|
innodb.innodb-16k
|
encryption.innodb_encrypt_log_corruption
|
encryption.innodb-bad-key-change
|
encryption.innodb_onlinealter_encryption
|
innodb.101_compatibility
|
innodb_zip.restart
|
innodb.truncate_purge_debug
|
main.commit_1innodb
|
main.sp_trans
|
parts.partition_debug_sync_innodb
|
innodb_fts.innodb-fts-stopword
|
innodb_fts.create
|
parts.partition_mgm_lc1_innodb
|
tokudb.truncate_txn_rollback_innodb
|
mroonga/wrapper.truncate
|
main.statistics_index_crash-7362
|
gcol.gcol_update
|
gcol.innodb_virtual_blob
|
gcol.innodb_virtual_index
|
handler.innodb
|
innodb.autoinc_persist
|
innodb.ibuf_not_empty
|
innodb.innodb-get-fk
|
gcol.innodb_virtual_basic
|
mariabackup.xb_fulltext_encrypted
|
main.innodb_mysql_sync
|
main.partition_explicit_prune
|
main.truncate-stale-6500
|
parts.partition_auto_increment_innodb
|
parts.partition_engine_innodb
|
innodb.innodb-truncate
|
innodb.innodb_blob_truncate
|
parts.partition_mgm_lc0_innodb
|
innodb.innodb_bug34300
|
innodb.innodb_bug38231
|
innodb.innodb_force_recovery
|
innodb.innodb_stats
|
innodb.log_corruption
|
innodb.read_only_recovery
|
innodb_fts.fulltext_multi
|
innodb_fts.fulltext_order_by
|
innodb_fts.fulltext_update
|
innodb_fts.fulltext_var
|
main.alter_table
|
innodb_fts.innodb-fts-basic
|
main.alter_table_trans
|
innodb_fts.innodb-fts-ddl
|
innodb_fts.innodb_fts_large_records
|
innodb_fts.innodb_fts_misc_1
|
innodb_fts.innodb_fts_multiple_index
|
innodb_fts.innodb_fts_plugin
|
innodb_fts.innodb-fts-fic
|
innodb_fts.innodb_fts_proximity
|
innodb_fts.innodb_fts_misc
|
innodb_fts.innodb_fts_stopword_charset
|
innodb_fts.innodb_fts_result_cache_limit
|
innodb_fts.innodb_fts_transaction
|
innodb_fts.misc_debug
|
main.commit
|
main.auto_increment_ranges_innodb
|
sys_vars.foreign_key_checks_func
|
innodb.row_format_redundant
|
vcol.vcol_ins_upd_innodb
|
innodb.temporary_table
|
innodb.tmpdir
|
innodb.truncate_debug
|
main.loaddata_autocom_innodb
|
innodb_fts.crash_recovery
|
innodb_fts.fulltext
|
innodb_fts.fulltext2
|
innodb_fts.fulltext_cache
|
innodb_fts.fulltext_distinct
|
innodb_fts.fulltext_left_join
|
innodb_fts.fulltext_misc
|
perfschema.innodb_table_io
|
I will put the assertion failures in the comment, to make them searchable for future, it might be helpful.
Apart from straightforward test failures, there are lots of reports
Errors/warnings were found in logfiles during server shutdown after running the
|
following sequence(s) of tests:
|
Mostly they're related to tests already mentioned among failures, so its side-effects, but possibly not all of them. The set needs to be re-run for catching those after the failures themselves have been fixed.
Attachments
Issue Links
- relates to
-
MDEV-11634 Improve the InnoDB change buffer
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-
(4 relates to)
Activity
Assertion failures:
2017-08-09 16:30:51 0x7ff0f4096700 InnoDB: Assertion failure in file /data/src/10.2/storage/innobase/sync/sync0debug.cc line 290
|
InnoDB: Failing assertion: latches->empty() || level == SYNC_LEVEL_VARYING || level == SYNC_NO_ORDER_CHECK || latches->back().m_latch->get_level() == SYNC_LEVEL_VARYING || latches->back().m_latch->get_level() == SYNC_NO_ORDER_CHECK || latches->back().get_level() >= level || it != latches->end()
|
mysqld: /data/src/10.2/storage/innobase/include/log0log.ic:498: void log_free_check(): Assertion `!sync_check_iterate( sync_allowed_latches(latches, latches + (sizeof(latches) / sizeof((latches)[0]))))' failed.
|
2017-08-09 16:56:03 140128881575680 [Note] InnoDB: Stopping purge
|
2017-08-09 16:56:04 140128651560704 [ERROR] InnoDB: Thread 140128651560704 already owns a latch SRV_DICT_TMPFILE at level 63 (SYNC_DICT_OPERATION ), which is at a lower/same level than the requested latch: 64 (SYNC_FILE_FORM
|
AT_TAG). RW-LATCH: thread id 140128651560704 addr: 0x55a8e3b9fcc0 Locked from: /data/src/10.2/storage/innobase/row/row0purge.cc:853
|
2017-08-09 16:56:04 140128651560704 [ERROR] InnoDB: Latches already owned by this thread:
|
2017-08-09 16:56:04 140128651560704 [ERROR] InnoDB: SRV_DICT_TMPFILE -> 63 (SYNC_DICT_OPERATION)
|
2017-08-09 16:56:04 0x7f723e7fc700 InnoDB: Assertion failure in file /data/src/10.2/storage/innobase/sync/sync0debug.cc line 584
|
2017-08-09 17:05:40 139847223179008 [Note] InnoDB: Starting shutdown...
|
2017-08-09 17:05:40 0x7f30b80f7700 InnoDB: Assertion failure in file /data/src/10.2/storage/innobase/include/sync0types.h line 1036
|
InnoDB: Failing assertion: m_id != LATCH_ID_NONE
|
bb-10.2-marko ce41068d80ff081ad2cfbfa387a7770ddc074557
|
Failing tests |
rpl.rpl_parallel_retry
|
encryption.innodb_encrypt_log_corruption
|
innodb.101_compatibility
|
innodb_zip.wl5522_debug_zip
|
gcol.gcol_update
|
innodb.ibuf_not_empty
|
innodb.innodb-get-fk
|
innodb.innodb_force_recovery
|
innodb.log_corruption
|
innodb.read_only_recovery
|
innodb.row_format_redundant
|
innodb.temporary_table
|
Failures:
#3 <signal handler called>
|
#4 0x00007f66b54f53c8 in ?? () from /lib/x86_64-linux-gnu/libc.so.6
|
#5 0x00007f66b54f6a5d in fnmatch () from /lib/x86_64-linux-gnu/libc.so.6
|
#6 0x0000564f4a62086a in InList (linkp=0x8f8f8f8f8f8f8f8f, cp=0x564f4a76dcff "info", exact_match=0) at /home/elenst/git/bb-10.2-marko/dbug/dbug.c:1515
|
#7 0x0000564f4a620d17 in _db_keyword_ (cs=0x7f6624048f00, keyword=0x564f4a76dcff "info", strict=0) at /home/elenst/git/bb-10.2-marko/dbug/dbug.c:1717
|
#8 0x0000564f4a62005c in _db_pargs_ (_line_=448, keyword=0x564f4a76dcff "info") at /home/elenst/git/bb-10.2-marko/dbug/dbug.c:1236
|
#9 0x0000564f49f9e2c3 in binlog_cache_data::truncate (this=0x7f662404a960, pos=0) at /home/elenst/git/bb-10.2-marko/sql/log.cc:448
|
#10 0x0000564f49f9e033 in binlog_cache_data::reset (this=0x7f662404a960) at /home/elenst/git/bb-10.2-marko/sql/log.cc:303
|
#11 0x0000564f49f9e44e in binlog_cache_mngr::reset (this=0x7f662404a7c0, do_stmt=true, do_trx=true) at /home/elenst/git/bb-10.2-marko/sql/log.cc:487
|
#12 0x0000564f49f86e00 in binlog_flush_cache (thd=0x7f6624000930, cache_mngr=0x7f662404a7c0, end_ev=0x7f66a45127e0, all=true, using_stmt=true, using_trx=true) at /home/elenst/git/bb-
|
10.2-marko/sql/log.cc:1758
|
#13 0x0000564f49f87334 in binlog_commit_flush_xid_caches (thd=0x7f6624000930, cache_mngr=0x7f662404a7c0, all=true, xid=4224) at /home/elenst/git/bb-10.2-marko/sql/log.cc:1848
|
#14 0x0000564f49f9acae in MYSQL_BIN_LOG::log_and_order (this=0x564f4b17db00 <mysql_bin_log>, thd=0x7f6624000930, xid=4224, all=true, need_prepare_ordered=false, need_commit_ordered=t
|
rue) at /home/elenst/git/bb-10.2-marko/sql/log.cc:9357
|
#15 0x0000564f49e8b346 in ha_commit_trans (thd=0x7f6624000930, all=true) at /home/elenst/git/bb-10.2-marko/sql/handler.cc:1448
|
#16 0x0000564f49d76ffb in trans_commit (thd=0x7f6624000930) at /home/elenst/git/bb-10.2-marko/sql/transaction.cc:307
|
#17 0x0000564f49fb344f in Xid_log_event::do_apply_event (this=0x7f6624040000, rgi=0x7f662803fd10) at /home/elenst/git/bb-10.2-marko/sql/log_event.cc:8441
|
#18 0x0000564f49b79633 in Log_event::apply_event (this=0x7f6624040000, rgi=0x7f662803fd10) at /home/elenst/git/bb-10.2-marko/sql/log_event.h:1452
|
#19 0x0000564f49b6e570 in apply_event_and_update_pos_apply (ev=0x7f6624040000, thd=0x7f6624000930, rgi=0x7f662803fd10, reason=0) at /home/elenst/git/bb-10.2-marko/sql/slave.cc:3571
|
#20 0x0000564f49b6eb73 in apply_event_and_update_pos_for_parallel (ev=0x7f6624040000, thd=0x7f6624000930, rgi=0x7f662803fd10) at /home/elenst/git/bb-10.2-marko/sql/slave.cc:3746
|
#21 0x0000564f49dcf948 in rpt_handle_event (qev=0x7f6624040100, rpt=0x7f662803ccb0) at /home/elenst/git/bb-10.2-marko/sql/rpl_parallel.cc:50
|
#22 0x0000564f49dd1872 in retry_event_group (rgi=0x7f662803fd10, rpt=0x7f662803ccb0, orig_qev=0x7f6628041ce0) at /home/elenst/git/bb-10.2-marko/sql/rpl_parallel.cc:921
|
#23 0x0000564f49dd2869 in handle_rpl_parallel_thread (arg=0x7f662803ccb0) at /home/elenst/git/bb-10.2-marko/sql/rpl_parallel.cc:1274
|
#24 0x0000564f4a5a309c in pfs_spawn_thread (arg=0x7f662803e6f0) at /home/elenst/git/bb-10.2-marko/storage/perfschema/pfs.cc:1862
|
#25 0x00007f66b60936ba in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
|
#26 0x00007f66b552882d in clone () from /lib/x86_64-linux-gnu/libc.so.6
|
5 0x00007f1fc52c102a in abort () from /lib/x86_64-linux-gnu/libc.so.6
|
#6 0x0000556153bb4854 in ut_dbg_assertion_failed (expr=0x55615413bc17 "m_id != LATCH_ID_NONE", file=0x55615413bb80 "/home/elenst/git/bb-10.2-marko/storage/innobase/include/sync0type
|
s.h", line=1035) at /home/elenst/git/bb-10.2-marko/storage/innobase/ut/ut0dbg.cc:60
|
#7 0x0000556153b5f6ce in latch_t::get_level (this=0x7f1fc02e3420) at /home/elenst/git/bb-10.2-marko/storage/innobase/include/sync0types.h:1035
|
#8 0x0000556153b6713a in sync_check_lock_validate (latch=0x7f1fc02e3420) at /home/elenst/git/bb-10.2-marko/storage/innobase/sync/sync0debug.cc:1143
|
#9 0x00005561539c0558 in MutexDebug<TTASEventMutex<GenericPolicy> >::enter (this=0x556154aca750 <fil_crypt_threads_mutex+16>, mutex=0x556154aca740 <fil_crypt_threads_mutex>, name=0x5561541b67c0 "/home/elenst/git/bb-10.2-marko/storage/innobase/fil/fil0crypt.cc", line=336) at /home/elenst/git/bb-10.2-marko/storage/innobase/include/sync0policy.ic:72
|
#10 0x00005561539bf2d6 in GenericPolicy<TTASEventMutex<GenericPolicy> >::enter (this=0x556154aca750 <fil_crypt_threads_mutex+16>, mutex=..., filename=0x5561541b67c0 "/home/elenst/git/bb-10.2-marko/storage/innobase/fil/fil0crypt.cc", line=336) at /home/elenst/git/bb-10.2-marko/storage/innobase/include/sync0policy.h:348
|
#11 0x00005561539bd967 in PolicyMutex<TTASEventMutex<GenericPolicy> >::enter (this=0x556154aca740 <fil_crypt_threads_mutex>, n_spins=30, n_delay=6, name=0x5561541b67c0 "/home/elenst/git/bb-10.2-marko/storage/innobase/fil/fil0crypt.cc", line=336) at /home/elenst/git/bb-10.2-marko/storage/innobase/include/ib0mutex.h:633
|
#12 0x0000556153cb3fca in fil_space_destroy_crypt_data (crypt_data=0x55615609b188) at /home/elenst/git/bb-10.2-marko/storage/innobase/fil/fil0crypt.cc:336
|
#13 0x0000556153c9f82a in fil_space_free_low (space=0x55615609afc0) at /home/elenst/git/bb-10.2-marko/storage/innobase/fil/fil0fil.cc:1526
|
#14 0x0000556153ca165c in fil_close_all_files () at /home/elenst/git/bb-10.2-marko/storage/innobase/fil/fil0fil.cc:2150
|
#15 0x0000556153a3117d in logs_empty_and_mark_files_at_shutdown () at /home/elenst/git/bb-10.2-marko/storage/innobase/log/log0log.cc:2131
|
#16 0x0000556153b58728 in innodb_shutdown () at /home/elenst/git/bb-10.2-marko/storage/innobase/srv/srv0start.cc:2820
|
#17 0x00005561539933e0 in innobase_end () at /home/elenst/git/bb-10.2-marko/storage/innobase/handler/ha_innodb.cc:4542
|
#18 0x00005561537879d4 in ha_finalize_handlerton (plugin=0x556155936ae0) at /home/elenst/git/bb-10.2-marko/sql/handler.cc:451
|
#19 0x0000556153530fa0 in plugin_deinitialize (plugin=0x556155936ae0, ref_check=true) at /home/elenst/git/bb-10.2-marko/sql/sql_plugin.cc:1215
|
#20 0x0000556153531436 in reap_plugins () at /home/elenst/git/bb-10.2-marko/sql/sql_plugin.cc:1292
|
#21 0x0000556153533494 in plugin_shutdown () at /home/elenst/git/bb-10.2-marko/sql/sql_plugin.cc:1950
|
#22 0x0000556153437fe9 in clean_up (print_message=true) at /home/elenst/git/bb-10.2-marko/sql/mysqld.cc:2213
|
#23 0x0000556153437b27 in unireg_end () at /home/elenst/git/bb-10.2-marko/sql/mysqld.cc:2088
|
#24 0x0000556153437a21 in kill_server (sig_ptr=0x0) at /home/elenst/git/bb-10.2-marko/sql/mysqld.cc:2015
|
#25 0x0000556153437a63 in kill_server_thread (arg=0x7f1fc03c1e00) at /home/elenst/git/bb-10.2-marko/sql/mysqld.cc:2038
|
#26 0x0000556153ea109c in pfs_spawn_thread (arg=0x7f1fa40012d0) at /home/elenst/git/bb-10.2-marko/storage/perfschema/pfs.cc:1862
|
#27 0x00007f1fc5efb6ba in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
|
#28 0x00007f1fc539082d in clone () from /lib/x86_64-linux-gnu/libc.so.6
|
2017-08-21 20:17:50 0x7fc7f87f8700 InnoDB: Assertion failure in file /home/elenst/git/bb-10.2-marko/storage/innobase/sync/sync0debug.cc line 235
|
InnoDB: Failing assertion: latches->empty() || level == SYNC_LEVEL_VARYING || level == SYNC_NO_ORDER_CHECK || latches->back().get_level() == SYNC_NO_ORDER_CHECK || latches->back().m_latch->get_level() == SYNC_LEVEL_VARYING || latches->back().get_level() >= level
|
|
|
#6 0x0000558eb7124854 in ut_dbg_assertion_failed (expr=0x558eb76ad2f8 "latches->empty() || level == SYNC_LEVEL_VARYING || level == SYNC_NO_ORDER_CHECK || latches->back().get_level()
|
== SYNC_NO_ORDER_CHECK || latches->back().m_latch->get_level() == SYNC_LEVEL_VARYING || l"..., file=0x558eb76ad298 "/home/elenst/git/bb-10.2-marko/storage/innobase/sync/sync0debug.c
|
c", line=235) at /home/elenst/git/bb-10.2-marko/storage/innobase/ut/ut0dbg.cc:60
|
#7 0x0000558eb70dad16 in LatchDebug::lock_validate (this=0x558ebab804f0, latch=0x7fc7f87f2e60, level=SYNC_IBUF_PESS_INSERT_MUTEX) at /home/elenst/git/bb-10.2-marko/storage/innobase/
|
sync/sync0debug.cc:228
|
#8 0x0000558eb70d7155 in sync_check_lock_validate (latch=0x7fc7f87f2e60) at /home/elenst/git/bb-10.2-marko/storage/innobase/sync/sync0debug.cc:1144
|
#9 0x0000558eb6f30558 in MutexDebug<TTASEventMutex<GenericPolicy> >::enter (this=0x558eb7fee570 <ibuf_pessimistic_insert_mutex+16>, mutex=0x558eb7fee560 <ibuf_pessimistic_insert_mut
|
ex>, name=0x558eb7628fd8 "/home/elenst/git/bb-10.2-marko/storage/innobase/ibuf/ibuf0ibuf.cc", line=3448) at /home/elenst/git/bb-10.2-marko/storage/innobase/include/sync0policy.ic:72
|
#10 0x0000558eb6f2f2d6 in GenericPolicy<TTASEventMutex<GenericPolicy> >::enter (this=0x558eb7fee570 <ibuf_pessimistic_insert_mutex+16>, mutex=..., filename=0x558eb7628fd8 "/home/elen
|
st/git/bb-10.2-marko/storage/innobase/ibuf/ibuf0ibuf.cc", line=3448) at /home/elenst/git/bb-10.2-marko/storage/innobase/include/sync0policy.h:348
|
#11 0x0000558eb6f2d967 in PolicyMutex<TTASEventMutex<GenericPolicy> >::enter (this=0x558eb7fee560 <ibuf_pessimistic_insert_mutex>, n_spins=30, n_delay=6, name=0x558eb7628fd8 "/home/e
|
lenst/git/bb-10.2-marko/storage/innobase/ibuf/ibuf0ibuf.cc", line=3448) at /home/elenst/git/bb-10.2-marko/storage/innobase/include/ib0mutex.h:633
|
#12 0x0000558eb6f730bd in ibuf_insert_low (mode=32801, op=IBUF_OP_DELETE_MARK, no_counter=0, entry=0x7fc7a40774d8, entry_size=528, index=0x7fc7a4065508, page_id=..., page_size=..., t
|
hr=0x7fc7a406e300) at /home/elenst/git/bb-10.2-marko/storage/innobase/ibuf/ibuf0ibuf.cc:3448
|
#13 0x0000558eb6f73e47 in ibuf_insert (op=IBUF_OP_DELETE_MARK, entry=0x7fc7a40774d8, index=0x7fc7a4065508, page_id=..., page_size=..., thr=0x7fc7a406e300) at /home/elenst/git/bb-10.2
|
-marko/storage/innobase/ibuf/ibuf0ibuf.cc:3832
|
#14 0x0000558eb71503cc in btr_cur_search_to_nth_level (index=0x7fc7a4065508, level=0, tuple=0x7fc7a40774d8, mode=PAGE_CUR_LE, latch_mode=2, cursor=0x7fc7f87f4f90, has_search_latch=0,
|
file=0x558eb7687db0 "/home/elenst/git/bb-10.2-marko/storage/innobase/row/row0row.cc", line=1069, mtr=0x7fc7f87f5510, autoinc=0) at /home/elenst/git/bb-10.2-marko/storage/innobase/bt
|
r/btr0cur.cc:1156
|
#15 0x0000558eb70754f3 in btr_pcur_open_low (index=0x7fc7a4065508, level=0, tuple=0x7fc7a40774d8, mode=PAGE_CUR_LE, latch_mode=4098, cursor=0x7fc7f87f4f90, file=0x558eb7687db0 "/home
|
/elenst/git/bb-10.2-marko/storage/innobase/row/row0row.cc", line=1069, autoinc=0, mtr=0x7fc7f87f5510) at /home/elenst/git/bb-10.2-marko/storage/innobase/include/btr0pcur.ic:457
|
#16 0x0000558eb7077cc7 in row_search_index_entry (index=0x7fc7a4065508, entry=0x7fc7a40774d8, mode=4098, pcur=0x7fc7f87f4f90, mtr=0x7fc7f87f5510) at /home/elenst/git/bb-10.2-marko/st
|
orage/innobase/row/row0row.cc:1069
|
#17 0x0000558eb70a9741 in row_upd_sec_index_entry (node=0x7fc7a406df70, thr=0x7fc7a406e300) at /home/elenst/git/bb-10.2-marko/storage/innobase/row/row0upd.cc:2381
|
#18 0x0000558eb70aa032 in row_upd_sec_step (node=0x7fc7a406df70, thr=0x7fc7a406e300) at /home/elenst/git/bb-10.2-marko/storage/innobase/row/row0upd.cc:2537
|
#19 0x0000558eb70ac37a in row_upd (node=0x7fc7a406df70, thr=0x7fc7a406e300) at /home/elenst/git/bb-10.2-marko/storage/innobase/row/row0upd.cc:3298
|
#20 0x0000558eb70ac6d2 in row_upd_step (thr=0x7fc7a406e300) at /home/elenst/git/bb-10.2-marko/storage/innobase/row/row0upd.cc:3415
|
#21 0x0000558eb704ee5f in row_update_for_mysql (prebuilt=0x7fc7a406b0f8) at /home/elenst/git/bb-10.2-marko/storage/innobase/row/row0mysql.cc:1947
|
#22 0x0000558eb6f0ed3e in ha_innobase::delete_row (this=0x7fc7a405c918, record=0x7fc7a4069028 "\370V") at /home/elenst/git/bb-10.2-marko/storage/innobase/handler/ha_innodb.cc:9543
|
#23 0x0000558eb6d05434 in handler::ha_delete_row (this=0x7fc7a405c918, buf=0x7fc7a4069028 "\370V") at /home/elenst/git/bb-10.2-marko/sql/handler.cc:6025
|
#24 0x0000558eb6e9209c in mysql_delete (thd=0x7fc7a4000b00, table_list=0x7fc7a40125d0, conds=0x7fc7a4012d78, order_list=0x7fc7a4005020, limit=18446744073709551600, options=0, result=
|
0x0) at /home/elenst/git/bb-10.2-marko/sql/sql_delete.cc:583
|
#25 0x0000558eb6a8c398 in mysql_execute_command (thd=0x7fc7a4000b00) at /home/elenst/git/bb-10.2-marko/sql/sql_parse.cc:4612
|
#26 0x0000558eb6a96ba3 in mysql_parse (thd=0x7fc7a4000b00, rawbuf=0x7fc7a40124c8 "DELETE FROM test_wl5522.t1 WHERE c2 = 1", length=39, parser_state=0x7fc7f87f7200, is_com_multi=false
|
, is_next_command=false) at /home/elenst/git/bb-10.2-marko/sql/sql_parse.cc:7886
|
#27 0x0000558eb6a848c7 in dispatch_command (command=COM_QUERY, thd=0x7fc7a4000b00, packet=0x7fc7a4008881 "DELETE FROM test_wl5522.t1 WHERE c2 = 1", packet_length=39, is_com_multi=fal
|
se, is_next_command=false) at /home/elenst/git/bb-10.2-marko/sql/sql_parse.cc:1812
|
#28 0x0000558eb6a8323a in do_command (thd=0x7fc7a4000b00) at /home/elenst/git/bb-10.2-marko/sql/sql_parse.cc:1360
|
#29 0x0000558eb6bcf7cc in do_handle_one_connection (connect=0x558ebabe3350) at /home/elenst/git/bb-10.2-marko/sql/sql_connect.cc:1354
|
#30 0x0000558eb6bcf54c in handle_one_connection (arg=0x558ebabe3350) at /home/elenst/git/bb-10.2-marko/sql/sql_connect.cc:1260
|
#31 0x0000558eb741109c in pfs_spawn_thread (arg=0x558ebabc61a0) at /home/elenst/git/bb-10.2-marko/storage/perfschema/pfs.cc:1862
|
#32 0x00007fc8087f46ba in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
|
#33 0x00007fc807c8982d in clone () from /lib/x86_64-linux-gnu/libc.so.6
|
2017-08-21 20:23:25 140016874006272 [Note] InnoDB: Stopping purge
|
2017-08-21 20:23:26 140016395216640 [ERROR] InnoDB: Thread 140016395216640 already owns a latch DICT_OPERATION at level 63 (SYNC_DICT_OPERATION ), which is at a lower/same level than the requested latch: 64 (SYNC_FILE_FORMAT_TAG). RW-LATCH: thread id 140016395216640 addr: 0x55cbad8e0c40 Locked from: /home/elenst/git/bb-10.2-marko/storage/innobase/row/row0purge.cc:853
|
2017-08-21 20:23:26 140016395216640 [ERROR] InnoDB: Latches already owned by this thread:
|
2017-08-21 20:23:26 140016395216640 [ERROR] InnoDB: DICT_OPERATION -> 63 (SYNC_DICT_OPERATION)
|
2017-08-21 20:23:26 0x7f581b7fe700 InnoDB: Assertion failure in file /home/elenst/git/bb-10.2-marko/storage/innobase/sync/sync0debug.cc line 584
|
InnoDB: We intentionally generate a memory trap.
|
...
|
#6 0x000055cbab285854 in ut_dbg_assertion_failed (expr=0x0, file=0x55cbab80e298 "/home/elenst/git/bb-10.2-marko/storage/innobase/sync/sync0debug.cc", line=584) at /home/elenst/git/b
|
b-10.2-marko/storage/innobase/ut/ut0dbg.cc:60
|
#7 0x000055cbab236dff in LatchDebug::crash (this=0x55cbad649870, latches=0x7f5808008910, latched=0x7f5808008930, level=SYNC_FILE_FORMAT_TAG) at /home/elenst/git/bb-10.2-marko/storag
|
e/innobase/sync/sync0debug.cc:584
|
#8 0x000055cbab236f37 in LatchDebug::basic_check (this=0x55cbad649870, latches=0x7f5808008910, requested_level=SYNC_FILE_FORMAT_TAG, in_level=64) at /home/elenst/git/bb-10.2-marko/s
|
torage/innobase/sync/sync0debug.cc:631
|
#9 0x000055cbab2372c5 in LatchDebug::check_order (this=0x55cbad649870, latch=0x7f581b7fcc70, level=SYNC_FILE_FORMAT_TAG) at /home/elenst/git/bb-10.2-marko/storage/innobase/sync/sync
|
0debug.cc:792
|
#10 0x000055cbab23bbf8 in LatchDebug::lock_validate (this=0x55cbad649870, latch=0x7f581b7fcc70, level=SYNC_FILE_FORMAT_TAG) at /home/elenst/git/bb-10.2-marko/storage/innobase/sync/sy
|
nc0debug.cc:226
|
#11 0x000055cbab238155 in sync_check_lock_validate (latch=0x7f581b7fcc70) at /home/elenst/git/bb-10.2-marko/storage/innobase/sync/sync0debug.cc:1144
|
#12 0x000055cbab091558 in MutexDebug<TTASEventMutex<GenericPolicy> >::enter (this=0x55cbac198ba0 <file_format_max+32>, mutex=0x55cbac198b90 <file_format_max+16>, name=0x55cbab81ef10
|
"/home/elenst/git/bb-10.2-marko/storage/innobase/trx/trx0sys.cc", line=796) at /home/elenst/git/bb-10.2-marko/storage/innobase/include/sync0policy.ic:72
|
#13 0x000055cbab0902d6 in GenericPolicy<TTASEventMutex<GenericPolicy> >::enter (this=0x55cbac198ba0 <file_format_max+32>, mutex=..., filename=0x55cbab81ef10 "/home/elenst/git/bb-10.2
|
-marko/storage/innobase/trx/trx0sys.cc", line=796) at /home/elenst/git/bb-10.2-marko/storage/innobase/include/sync0policy.h:348
|
#14 0x000055cbab08e967 in PolicyMutex<TTASEventMutex<GenericPolicy> >::enter (this=0x55cbac198b90 <file_format_max+16>, n_spins=30, n_delay=6, name=0x55cbab81ef10 "/home/elenst/git/b
|
b-10.2-marko/storage/innobase/trx/trx0sys.cc", line=796) at /home/elenst/git/bb-10.2-marko/storage/innobase/include/ib0mutex.h:633
|
#15 0x000055cbab26c079 in trx_sys_file_format_max_upgrade (name=0x55cbac14f040 <innobase_file_format_max>, format_id=1) at /home/elenst/git/bb-10.2-marko/storage/innobase/trx/trx0sys
|
.cc:796
|
#16 0x000055cbab068e18 in ha_innobase::open (this=0x7f580800d388, name=0x7f58080099d0 "./test/t1") at /home/elenst/git/bb-10.2-marko/storage/innobase/handler/ha_innodb.cc:6776
|
#17 0x000055cbaae5cfe2 in handler::ha_open (this=0x7f580800d388, table_arg=0x7f580800c780, name=0x7f58080099d0 "./test/t1", mode=2, test_if_locked=18) at /home/elenst/git/bb-10.2-mar
|
ko/sql/handler.cc:2469
|
#18 0x000055cbaaceb59f in open_table_from_share (thd=0x7f5808000b00, share=0x7f58080094c8, alias=0x7f581b7fdb80 "t1", db_stat=33, prgflag=8, ha_open_flags=18, outparam=0x7f580800c780
|
, is_create_table=false) at /home/elenst/git/bb-10.2-marko/sql/table.cc:3321
|
#19 0x000055cbaab78195 in open_table (thd=0x7f5808000b00, table_list=0x7f58080119c8, ot_ctx=0x7f581b7fd6f0) at /home/elenst/git/bb-10.2-marko/sql/sql_base.cc:1877
|
#20 0x000055cbaaba8e62 in open_purge_table (thd=0x7f5808000b00, db=0x7f581b7fda30 "test", dblen=4, tb=0x7f581b7fdb80 "t1", tblen=2) at /home/elenst/git/bb-10.2-marko/sql/sql_class.cc:4467
|
#21 0x000055cbab086f3b in innobase_find_mysql_table_for_vc (thd=0x7f5808000b00, table=0x7f5808011028) at /home/elenst/git/bb-10.2-marko/storage/innobase/handler/ha_innodb.cc:22198
|
#22 0x000055cbab087040 in innobase_init_vc_templ (table=0x7f5808011028) at /home/elenst/git/bb-10.2-marko/storage/innobase/handler/ha_innodb.cc:22221
|
#23 0x000055cbab1d1315 in row_purge_parse_undo_rec (node=0x55cbad8f1bf8, undo_rec=0x7f580c00e1b0 "\f\255\016", updated_extern=0x7f581b7fddde, thr=0x55cbad8f1a40) at /home/elenst/git/bb-10.2-marko/storage/innobase/row/row0purge.cc:886
|
#24 0x000055cbab1d17cb in row_purge (node=0x55cbad8f1bf8, undo_rec=0x7f580c00e1b0 "\f\255\016", thr=0x55cbad8f1a40) at /home/elenst/git/bb-10.2-marko/storage/innobase/row/row0purge.cc:1015
|
#25 0x000055cbab1d1a81 in row_purge_step (thr=0x55cbad8f1a40) at /home/elenst/git/bb-10.2-marko/storage/innobase/row/row0purge.cc:1097
|
#26 0x000055cbab15e0a0 in que_thr_step (thr=0x55cbad8f1a40) at /home/elenst/git/bb-10.2-marko/storage/innobase/que/que0que.cc:1053
|
#27 0x000055cbab15e29e in que_run_threads_low (thr=0x55cbad8f1a40) at /home/elenst/git/bb-10.2-marko/storage/innobase/que/que0que.cc:1115
|
#28 0x000055cbab15e447 in que_run_threads (thr=0x55cbad8f1a40) at /home/elenst/git/bb-10.2-marko/storage/innobase/que/que0que.cc:1155
|
#29 0x000055cbab21f29b in srv_task_execute () at /home/elenst/git/bb-10.2-marko/storage/innobase/srv/srv0srv.cc:2598
|
#30 0x000055cbab21f3e9 in srv_worker_thread (arg=0x0) at /home/elenst/git/bb-10.2-marko/storage/innobase/srv/srv0srv.cc:2645
|
#31 0x00007f583ec0e6ba in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
|
#32 0x00007f583e0a382d in clone () from /lib/x86_64-linux-gnu/libc.so.6
|
Based on above test results there is still work to be done in here. Current patch looks good to me.
elenst, thank you for the update. For some reason, many failures are sporadic and not repeatable when rerunning the failing tests.
The innodb.temporary_table failure was repeatable on Buildbot as well. I failed to adjust that test to the removal of the unused temporary file srv_dict_tmpfile.
With the following command, I can repeat a number of failures, both with and without AddressSanitizer:
./mtr --max-test-fail=0 --mysqld=--innodb-sync-debug=1 --mem --parallel=auto --force rpl.rpl_parallel_retry encryption.innodb_encrypt_log_corruption innodb.101_compatibility innodb_zip.wl5522_debug_zip gcol.gcol_update innodb.ibuf_not_empty innodb.innodb-get-fk innodb.innodb_force_recovery innodb.log_corruption innodb.read_only_recovery innodb.row_format_redundant
|
I cannot repeat any failure of rpl.rpl_parallel_retry. Looking at the reported stack traces, I suppose it goes with this crash in binlog_cache_data::truncate():
void truncate(my_off_t pos)
|
{
|
DBUG_PRINT("info", ("truncating to position %lu", (ulong) pos));
|
This should be due to some memory corruption, probably unrelated to the --innodb-sync-debug setting.
Many InnoDB tests fail at shutdown. I applied the following patch to work around MDEV-13093:
diff --git a/storage/innobase/fil/fil0crypt.cc b/storage/innobase/fil/fil0crypt.cc
|
index 17608b686d6..bd58330958d 100644
|
--- a/storage/innobase/fil/fil0crypt.cc
|
+++ b/storage/innobase/fil/fil0crypt.cc
|
@@ -212,6 +212,7 @@ fil_space_create_crypt_data(
|
uint key_id)
|
{
|
fil_space_crypt_t* crypt_data = NULL;
|
+#if 0
|
if (void* buf = ut_zalloc_nokey(sizeof(fil_space_crypt_t))) {
|
crypt_data = new(buf)
|
fil_space_crypt_t(
|
@@ -220,6 +221,7 @@ fil_space_create_crypt_data(
|
key_id,
|
encrypt_mode);
|
}
|
+#endif
|
|
return crypt_data;
|
} |
With this patch applied, only the following tests fail:
innodb_zip.wl5522_debug_zip gcol.gcol_update innodb.innodb-get-fk innodb.row_format_redundant
|
The innodb.innodb-get-fk failure was due to MDEV-13614. This leaves 3 tests to debug.
bb-10.2-marko fb74e52aa7b47817be0cb17d948f2e11ed5d145c + local patch in innobase/fil/fil0crypt.cc
|
rpl.rpl_domain_id_filter_io_crash |
170822 13:24:36 [ERROR] mysqld got signal 11 ;
|
|
|
#3 <signal handler called>
|
#4 0x00007f359b87a3c8 in ?? () from /lib/x86_64-linux-gnu/libc.so.6
|
#5 0x00007f359b87ba5d in fnmatch () from /lib/x86_64-linux-gnu/libc.so.6
|
#6 0x0000560dc8ce0712 in InList (linkp=0x8f8f8f8f157a3468, cp=0x560dc8d56006 "debug_sync_point", exact_match=0) at /home/elenst/git/bb-10.2-marko/dbug/dbug.c:1515
|
#7 0x0000560dc8ce0bbf in _db_keyword_ (cs=0x7f3560000a30, keyword=0x560dc8d56006 "debug_sync_point", strict=0) at /home/elenst/git/bb-10.2-marko/dbug/dbug.c:1717
|
#8 0x0000560dc8cdff04 in _db_pargs_ (_line_=1541, keyword=0x560dc8d56006 "debug_sync_point") at /home/elenst/git/bb-10.2-marko/dbug/dbug.c:1236
|
#9 0x0000560dc830c598 in debug_sync (thd=0x7f3560000b00, sync_point_name=0x560dc8d3e543 "before_close_thread_tables", name_len=26) at /home/elenst/git/bb-10.2-marko/sql/debug_sync.c
|
c:1541
|
#10 0x0000560dc8266f46 in close_thread_tables (thd=0x7f3560000b00) at /home/elenst/git/bb-10.2-marko/sql/sql_base.cc:726
|
#11 0x0000560dc829a15b in reset_thd (thd=0x7f3560000b00) at /home/elenst/git/bb-10.2-marko/sql/sql_class.cc:4531
|
#12 0x0000560dc8750a0b in innobase_reset_background_thd (thd=0x7f3560000b00) at /home/elenst/git/bb-10.2-marko/storage/innobase/handler/ha_innodb.cc:1750
|
#13 0x0000560dc88c2b58 in row_purge_step (thr=0x560dcb0ff038) at /home/elenst/git/bb-10.2-marko/storage/innobase/row/row0purge.cc:1108
|
#14 0x0000560dc884f10c in que_thr_step (thr=0x560dcb0ff038) at /home/elenst/git/bb-10.2-marko/storage/innobase/que/que0que.cc:1053
|
#15 0x0000560dc884f30a in que_run_threads_low (thr=0x560dcb0ff038) at /home/elenst/git/bb-10.2-marko/storage/innobase/que/que0que.cc:1115
|
#16 0x0000560dc884f4b3 in que_run_threads (thr=0x560dcb0ff038) at /home/elenst/git/bb-10.2-marko/storage/innobase/que/que0que.cc:1155
|
#17 0x0000560dc8910327 in srv_task_execute () at /home/elenst/git/bb-10.2-marko/storage/innobase/srv/srv0srv.cc:2598
|
#18 0x0000560dc8910475 in srv_worker_thread (arg=0x0) at /home/elenst/git/bb-10.2-marko/storage/innobase/srv/srv0srv.cc:2645
|
#19 0x00007f359c4186ba in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
|
#20 0x00007f359b8ad82d in clone () from /lib/x86_64-linux-gnu/libc.so.6
|
|
rpl.rpl_binlog_errors |
170822 13:29:19 [ERROR] mysqld got signal 11 ;
|
|
|
#3 <signal handler called>
|
#4 0x00007f585433d3c8 in ?? () from /lib/x86_64-linux-gnu/libc.so.6
|
#5 0x00007f585433ea5d in fnmatch () from /lib/x86_64-linux-gnu/libc.so.6
|
#6 0x000055da934da712 in InList (linkp=0x21, cp=0x55da936a81cf "ib_que", exact_match=0) at /home/elenst/git/bb-10.2-marko/dbug/dbug.c:1515
|
#7 0x000055da934dabbf in _db_keyword_ (cs=0x7f5814000a30, keyword=0x55da936a81cf "ib_que", strict=0) at /home/elenst/git/bb-10.2-marko/dbug/dbug.c:1717
|
#8 0x000055da934d9f04 in _db_pargs_ (_line_=995, keyword=0x55da936a81cf "ib_que") at /home/elenst/git/bb-10.2-marko/dbug/dbug.c:1236
|
#9 0x000055da93048e70 in que_thr_step (thr=0x55da960bb080) at /home/elenst/git/bb-10.2-marko/storage/innobase/que/que0que.cc:993
|
#10 0x000055da9304930a in que_run_threads_low (thr=0x55da960bb080) at /home/elenst/git/bb-10.2-marko/storage/innobase/que/que0que.cc:1115
|
#11 0x000055da930494b3 in que_run_threads (thr=0x55da960bb080) at /home/elenst/git/bb-10.2-marko/storage/innobase/que/que0que.cc:1155
|
#12 0x000055da9310a327 in srv_task_execute () at /home/elenst/git/bb-10.2-marko/storage/innobase/srv/srv0srv.cc:2598
|
#13 0x000055da9310a475 in srv_worker_thread (arg=0x0) at /home/elenst/git/bb-10.2-marko/storage/innobase/srv/srv0srv.cc:2645
|
#14 0x00007f5854edb6ba in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
|
#15 0x00007f585437082d in clone () from /lib/x86_64-linux-gnu/libc.so.6
|
The remaining two rpl test failures seem related to MDEV-5800. Perhaps setting --innodb-sync-debug is affecting the timing so much that it makes those failures easier to repeat.
In one of the core dumps, no SQL was executing inside InnoDB (the only ha_innodb.cc function among the stack traces was thd_destructor_proxy). Maybe RESET MASTER is somehow invalidating the THD objects, causing trouble for the InnoDB purge threads?
bb-10.2-marko 6e2fb69a7940
|
innodb_zip.wl5522_zip,4k,innodb innodb_zip.wl5522_zip,8k,innodb |
2017-08-23 21:28:01 0x7fd8885f6700 InnoDB: Assertion failure in file /home/elenst/git/bb-10.2-marko/storage/innobase/sync/sync0debug.cc line 235
|
InnoDB: Failing assertion: latches->empty() || level == SYNC_LEVEL_VARYING || level == SYNC_NO_ORDER_CHECK || latches->back().get_level() == SYNC_NO_ORDER_CHECK || latches->back().m_latch->get_level() == SYNC_LEVEL_VARYING || latches->back().get_level() >= level
|
|
|
#5 0x00007fd89cb4702a in abort () from /lib/x86_64-linux-gnu/libc.so.6
|
#6 0x000055a44d753846 in ut_dbg_assertion_failed (expr=0x55a44dcdd598 "latches->empty() || level == SYNC_LEVEL_VARYING || level == SYNC_NO_ORDER_CHECK || latches->back().get_level() == SYNC_NO_ORDER_CHECK || latches->back().m_latch->get_level() == SYNC_LEVEL_VARYING || l"..., file=0x55a44dcdd538 "/home/elenst/git/bb-10.2-marko/storage/innobase/sync/sync0debug.cc", line=235) at /home/elenst/git/bb-10.2-marko/storage/innobase/ut/ut0dbg.cc:60
|
#7 0x000055a44d709d08 in LatchDebug::lock_validate (this=0x55a4502b4360, latch=0x7fd8885efe60, level=SYNC_IBUF_PESS_INSERT_MUTEX) at /home/elenst/git/bb-10.2-marko/storage/innobase/sync/sync0debug.cc:228
|
#8 0x000055a44d706147 in sync_check_lock_validate (latch=0x7fd8885efe60) at /home/elenst/git/bb-10.2-marko/storage/innobase/sync/sync0debug.cc:1144
|
#9 0x000055a44d55f558 in MutexDebug<TTASEventMutex<GenericPolicy> >::enter (this=0x55a44e61f570 <ibuf_pessimistic_insert_mutex+16>, mutex=0x55a44e61f560 <ibuf_pessimistic_insert_mutex>, name=0x55a44dc580d8 "/home/elenst/git/bb-10.2-marko/storage/innobase/ibuf/ibuf0ibuf.cc", line=2119) at /home/elenst/git/bb-10.2-marko/storage/innobase/include/sync0policy.ic:72
|
#10 0x000055a44d55e2d6 in GenericPolicy<TTASEventMutex<GenericPolicy> >::enter (this=0x55a44e61f570 <ibuf_pessimistic_insert_mutex+16>, mutex=..., filename=0x55a44dc580d8 "/home/elenst/git/bb-10.2-marko/storage/innobase/ibuf/ibuf0ibuf.cc", line=2119) at /home/elenst/git/bb-10.2-marko/storage/innobase/include/sync0policy.h:348
|
#11 0x000055a44d55c967 in PolicyMutex<TTASEventMutex<GenericPolicy> >::enter (this=0x55a44e61f560 <ibuf_pessimistic_insert_mutex>, n_spins=30, n_delay=6, name=0x55a44dc580d8 "/home/elenst/git/bb-10.2-marko/storage/innobase/ibuf/ibuf0ibuf.cc", line=2119) at /home/elenst/git/bb-10.2-marko/storage/innobase/include/ib0mutex.h:633
|
#12 0x000055a44d59f480 in ibuf_remove_free_page () at /home/elenst/git/bb-10.2-marko/storage/innobase/ibuf/ibuf0ibuf.cc:2119
|
#13 0x000055a44d59f929 in ibuf_free_excess_pages () at /home/elenst/git/bb-10.2-marko/storage/innobase/ibuf/ibuf0ibuf.cc:2245
|
#14 0x000055a44d85fbc2 in fseg_create_general (space_id=0, page=0, byte_offset=84, has_done_reservation=0, mtr=0x7fd8885f0d20) at /home/elenst/git/bb-10.2-marko/storage/innobase/fsp/fsp0fsp.cc:2113
|
#15 0x000055a44d860031 in fseg_create (space=0, page=0, byte_offset=84, mtr=0x7fd8885f0d20) at /home/elenst/git/bb-10.2-marko/storage/innobase/fsp/fsp0fsp.cc:2212
|
#16 0x000055a44d76071c in btr_create (type=3, space=0, page_size=..., index_id=62, index=0x7fd83c080978, btr_redo_create_info=0x0, mtr=0x7fd8885f0d20) at /home/elenst/git/bb-10.2-marko/storage/innobase/btr/btr0btr.cc:1185
|
#17 0x000055a44d7f2b3c in dict_create_index_tree_step (node=0x7fd83c075478) at /home/elenst/git/bb-10.2-marko/storage/innobase/dict/dict0crea.cc:910
|
#18 0x000055a44d7f4492 in dict_create_index_step (thr=0x7fd83c07f6d0) at /home/elenst/git/bb-10.2-marko/storage/innobase/dict/dict0crea.cc:1527
|
#19 0x000055a44d62c0f5 in que_thr_step (thr=0x7fd83c07f6d0) at /home/elenst/git/bb-10.2-marko/storage/innobase/que/que0que.cc:1063
|
#20 0x000055a44d62c270 in que_run_threads_low (thr=0x7fd83c07f6d0) at /home/elenst/git/bb-10.2-marko/storage/innobase/que/que0que.cc:1115
|
#21 0x000055a44d62c419 in que_run_threads (thr=0x7fd83c07f6d0) at /home/elenst/git/bb-10.2-marko/storage/innobase/que/que0que.cc:1155
|
#22 0x000055a44d67fb6c in row_create_index_for_mysql (index=0x7fd83c075158, trx=0x7fd892a72cc0, field_lengths=0x7fd83c05e5a0) at /home/elenst/git/bb-10.2-marko/storage/innobase/row/row0mysql.cc:2626
|
#23 0x000055a44d55bd22 in create_index (trx=0x7fd892a72cc0, form=0x7fd8885f1ae0, flags=33, table_name=0x7fd8885f1610 "test/t1", key_num=0) at /home/elenst/git/bb-10.2-marko/storage/innobase/handler/ha_innodb.cc:12013
|
#24 0x000055a44d5451dd in create_table_info_t::create_table (this=0x7fd8885f15c0) at /home/elenst/git/bb-10.2-marko/storage/innobase/handler/ha_innodb.cc:13155
|
#25 0x000055a44d545c3a in ha_innobase::create (this=0x7fd83c075c48, name=0x7fd8885f4320 "./test/t1", form=0x7fd8885f1ae0, create_info=0x7fd8885f4920) at /home/elenst/git/bb-10.2-marko/storage/innobase/handler/ha_innodb.cc:13452
|
#26 0x000055a44d32fe8e in handler::ha_create (this=0x7fd83c075c48, name=0x7fd8885f4320 "./test/t1", form=0x7fd8885f1ae0, info_arg=0x7fd8885f4920) at /home/elenst/git/bb-10.2-marko/sql/handler.cc:4339
|
#27 0x000055a44d330dba in ha_create_table (thd=0x7fd83c000b00, path=0x7fd8885f4320 "./test/t1", db=0x7fd83c012c30 "test", table_name=0x7fd83c0125e8 "t1", create_info=0x7fd8885f4920, frm=0x7fd8885f4310) at /home/elenst/git/bb-10.2-marko/sql/handler.cc:4710
|
#28 0x000055a44d1d07fd in rea_create_table (thd=0x7fd83c000b00, frm=0x7fd8885f4310, path=0x7fd8885f4320 "./test/t1", db=0x7fd83c012c30 "test", table_name=0x7fd83c0125e8 "t1", create_info=0x7fd8885f4920, file=0x7fd83c013310, no_ha_create_table=false) at /home/elenst/git/bb-10.2-marko/sql/unireg.cc:419
|
#29 0x000055a44d17fa08 in create_table_impl (thd=0x7fd83c000b00, orig_db=0x7fd83c012c30 "test", orig_table_name=0x7fd83c0125e8 "t1", db=0x7fd83c012c30 "test", table_name=0x7fd83c0125e8 "t1", path=0x7fd8885f4320 "./test/t1", options=..., create_info=0x7fd8885f4920, alter_info=0x7fd8885f4870, create_table_mode=0, is_trans=0x7fd8885f457e, key_info=0x7fd8885f4300, key_count=0x7fd8885f42f4, frm=0x7fd8885f4310) at /home/elenst/git/bb-10.2-marko/sql/sql_table.cc:4887
|
#30 0x000055a44d18000c in mysql_create_table_no_lock (thd=0x7fd83c000b00, db=0x7fd83c012c30 "test", table_name=0x7fd83c0125e8 "t1", create_info=0x7fd8885f4920, alter_info=0x7fd8885f4870, is_trans=0x7fd8885f457e, create_table_mode=0) at /home/elenst/git/bb-10.2-marko/sql/sql_table.cc:4999
|
#31 0x000055a44d180280 in mysql_create_table (thd=0x7fd83c000b00, create_table=0x7fd83c012620, create_info=0x7fd8885f4920, alter_info=0x7fd8885f4870) at /home/elenst/git/bb-10.2-marko/sql/sql_table.cc:5061
|
#32 0x000055a44d0b93b5 in mysql_execute_command (thd=0x7fd83c000b00) at /home/elenst/git/bb-10.2-marko/sql/sql_parse.cc:3964
|
#33 0x000055a44d0c5ba3 in mysql_parse (thd=0x7fd83c000b00, rawbuf=0x7fd83c0124c8 "CREATE TABLE t1(\nc1 INT NOT NULL AUTO_INCREMENT PRIMARY KEY,\nc2 INT) ENGINE=InnoDB", length=82, parser_state=0x7fd8885f5200, is_com_multi=false, is_next_command=false) at /home/elenst/git/bb-10.2-marko/sql/sql_parse.cc:7886
|
#34 0x000055a44d0b38c7 in dispatch_command (command=COM_QUERY, thd=0x7fd83c000b00, packet=0x7fd83c008881 "CREATE TABLE t1(\nc1 INT NOT NULL AUTO_INCREMENT PRIMARY KEY,\nc2 INT) ENGINE=InnoDB", packet_length=82, is_com_multi=false, is_next_command=false) at /home/elenst/git/bb-10.2-marko/sql/sql_parse.cc:1812
|
#35 0x000055a44d0b223a in do_command (thd=0x7fd83c000b00) at /home/elenst/git/bb-10.2-marko/sql/sql_parse.cc:1360
|
#36 0x000055a44d1fe7cc in do_handle_one_connection (connect=0x55a450321010) at /home/elenst/git/bb-10.2-marko/sql/sql_connect.cc:1354
|
#37 0x000055a44d1fe54c in handle_one_connection (arg=0x55a450321010) at /home/elenst/git/bb-10.2-marko/sql/sql_connect.cc:1260
|
#38 0x000055a44da3ff60 in pfs_spawn_thread (arg=0x55a450303e60) at /home/elenst/git/bb-10.2-marko/storage/perfschema/pfs.cc:1862
|
#39 0x00007fd89d7816ba in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
|
#40 0x00007fd89cc1682d in clone () from /lib/x86_64-linux-gnu/libc.so.6
|
Seems to be reliably reproducible by running
perl ./mtr --mysqld=--loose-innodb-sync-debug --mem --noreorder innodb_zip.innodb-zip,4k,innodb innodb_zip.wl5522_debug_zip,4k,innodb innodb_zip.wl5522_zip,4k,innodb
|
The failure is caused by lazy eviction from the change buffer, which we should fix in MDEV-11634.
When an index or table is dropped, buffered changes may be left behind for those pages. The changes will not be discarded until the same page is being allocated for something else.
In this case, the stack trace directly implies this:
print *latches
|
$1 = std::vector of length 4, capacity 32 = {{m_latch = 0x55bb13b5aaa0,
|
m_level = SYNC_DICT_OPERATION}, {m_latch = 0x55bb13b5ab90,
|
m_level = SYNC_DICT}, {m_latch = 0x55bb13b0c1d8, m_level = SYNC_FSP}, {
|
m_latch = 0x55bb13b0c1d8, m_level = SYNC_FSP}}
|
This scenario should be more likely in the system tablespace, because DROP TABLE for an .ibd file should actually remove all change buffer entries for that tablespace ID. For .ibd files, you could theoretically get this by executing DROP INDEX (so that some changes were buffered) followed by CREATE INDEX. In this case, we are discarding buffered changes for a freed-and-reused page in the system tablespace:
# Export/import on the same instance, with --innodb-file-per-table=0
|
# This should fail because it is not supported
|
SET GLOBAL innodb_file_per_table = 0;
|
|
|
CREATE TABLE t1(
|
c1 INT NOT NULL AUTO_INCREMENT PRIMARY KEY,
|
c2 INT) ENGINE=InnoDB;
|
I will have to think if this could lead to a genuine deadlock, or if the debug assertion is simply too strict and should be relaxed.
This code in fseg_create_general() looks suspicious:
if (rw_lock_get_x_lock_count(&space->latch) == 1) {
|
/* This thread did not own the latch before this call: free
|
excess pages from the insert buffer free list */
|
|
|
if (space_id == IBUF_SPACE_ID) {
|
ibuf_free_excess_pages();
|
}
|
}
|
I believe that it would be better to do this ‘housekeeping’ while not holding any latches. Basically, it should be done in create_table_info_t::create_table() or earlier, as soon as we have decided that the table will be created in the system tablespace.
bb-10.2-marko ac33db347cb0e14
Test run is considered successful.
5 failures total: two of the previously analyzed kind (presumably related to MDEV-5800), two sysvar wrong results (expected with non-default innodb-sync-debug), and one sporadic failure unrelated to the current task (MDEV-13259).
Here is the same list as in description, but with test per line (on some reason, description doesn't allow it):
binlog_encryption.rpl_parallelbinlog_encryption.rpl_mixed_binlog_max_cache_sizefederated.federated_transactionsmulti_source.gtid_ignore_duplicatesrpl.rpl_ddlrpl.rpl_innodb_mixed_dmlrpl.rpl_mixed_binlog_max_cache_sizerpl.rpl_drop_db_failrpl.rpl_gtid_crashrpl.rpl_gtid_mdev4484rpl.rpl_gtid_untilrpl.rpl_multi_enginerpl.rpl_parallelrpl.rpl_parallel_optimisticrpl.rpl_read_onlyrpl.rpl_truncate_3innodbrpl.rpl_row_create_tablerpl.rpl_row_tabledefs_3innodbrpl.rpl_old_masterrpl.rpl_gtid_strictrpl.rpl_stm_binlog_max_cache_sizerpl.rpl_stm_stop_middle_groupbinlog.flashbackbinlog.binlog_row_mix_innodb_myisambinlog.binlog_mysqlbinlog_row_transmain-test_sql_discovery.mdl_syncbinlog.binlog_stm_mix_innodb_myisammain.mdl_syncmain.partition_innodb_semi_consistentinnodb.innodb-16kencryption.innodb_encrypt_log_corruptionencryption.innodb-bad-key-changeencryption.innodb_onlinealter_encryptioninnodb.101_compatibilityinnodb_zip.restartinnodb.truncate_purge_debugmain.commit_1innodbmain.sp_transparts.partition_debug_sync_innodbinnodb_fts.innodb-fts-stopwordinnodb_fts.createparts.partition_mgm_lc1_innodbtokudb.truncate_txn_rollback_innodbmroonga/wrapper.truncatemain.statistics_index_crash-7362gcol.gcol_updategcol.innodb_virtual_blobgcol.innodb_virtual_indexhandler.innodbinnodb.autoinc_persistinnodb.ibuf_not_emptyinnodb.innodb-get-fkgcol.innodb_virtual_basicmariabackup.xb_fulltext_encryptedmain.innodb_mysql_syncmain.partition_explicit_prunemain.truncate-stale-6500parts.partition_auto_increment_innodbparts.partition_engine_innodbinnodb.innodb-truncateinnodb.innodb_blob_truncateparts.partition_mgm_lc0_innodbinnodb.innodb_bug34300innodb.innodb_bug38231innodb.innodb_force_recoveryinnodb.innodb_statsinnodb.log_corruptioninnodb.read_only_recoveryinnodb_fts.fulltext_multiinnodb_fts.fulltext_order_byinnodb_fts.fulltext_updateinnodb_fts.fulltext_varmain.alter_tableinnodb_fts.innodb-fts-basicmain.alter_table_transinnodb_fts.innodb-fts-ddlinnodb_fts.innodb_fts_large_recordsinnodb_fts.innodb_fts_misc_1innodb_fts.innodb_fts_multiple_indexinnodb_fts.innodb_fts_plugininnodb_fts.innodb-fts-ficinnodb_fts.innodb_fts_proximityinnodb_fts.innodb_fts_miscinnodb_fts.innodb_fts_stopword_charsetinnodb_fts.innodb_fts_result_cache_limitinnodb_fts.innodb_fts_transactioninnodb_fts.misc_debugmain.commitmain.auto_increment_ranges_innodbsys_vars.foreign_key_checks_funcinnodb.row_format_redundantvcol.vcol_ins_upd_innodbinnodb.temporary_tableinnodb.tmpdirinnodb.truncate_debugmain.loaddata_autocom_innodbinnodb_fts.crash_recoveryinnodb_fts.fulltextinnodb_fts.fulltext2innodb_fts.fulltext_cacheinnodb_fts.fulltext_distinctinnodb_fts.fulltext_left_joininnodb_fts.fulltext_miscperfschema.innodb_table_io