Details
-
Bug
-
Status: Closed (View Workflow)
-
Critical
-
Resolution: Fixed
-
10.6, 10.7(EOL)
Description
The following error was observed in https://buildbot.mariadb.org/#/builders/195/builds/3048/steps/7/logs/stdio and is nondeterministically repeatable locally. I got it replayed under rr after setting -DPLUGIN_PERFSCHEMA=NO:
10.6 b740b2356d539a27f8a7a9e9b6455f31bc6c9196 |
Version: '10.6.5-MariaDB-debug-log' socket: '/dev/shm/10.6msan/mysql-test/var/tmp/mysqld.1.sock' port: 16060 Source distribution
|
==1210070==WARNING: MemorySanitizer: use-of-uninitialized-value
|
#0 0x56542be6fbff in int10_to_str /mariadb/10.6/strings/int2str.c:168:3
|
#1 0x56542be77b1a in process_int_arg /mariadb/10.6/strings/my_vsnprintf.c
|
#2 0x56542be7256f in my_vsnprintf_ex /mariadb/10.6/strings/my_vsnprintf.c:764:11
|
#3 0x56542be783d3 in my_vsnprintf /mariadb/10.6/strings/my_vsnprintf.c:815:10
|
#4 0x56542be783d3 in my_snprintf /mariadb/10.6/strings/my_vsnprintf.c:824:11
|
#5 0x565429507e96 in thd_get_error_context_description /mariadb/10.6/sql/sql_show.cc:10190:8
|
#6 0x56542ac3bb84 in innobase_mysql_print_thd(_IO_FILE*, THD*, unsigned int) /mariadb/10.6/storage/innobase/handler/ha_innodb.cc:2333:8
|
#7 0x56542aebb2b9 in lock_trx_print_wait_and_mvcc_state(_IO_FILE*, trx_t const*, my_hrtime_t) /mariadb/10.6/storage/innobase/lock/lock0lock.cc:4185:2
|
Here is a better stack trace from my rr replay session:
10.6 b740b2356d539a27f8a7a9e9b6455f31bc6c9196 |
(rr) set print frame-arguments scalars
|
(rr) bt
|
#0 innobase_mysql_print_thd (f=0x714000000a00, f@entry=0x7fe86a231318, thd=0x72b00007e018, max_query_len=600) at /mariadb/10.6/storage/innobase/handler/ha_innodb.cc:2330
|
#1 0x000056542b4a1d4d in trx_print_low (f=<optimized out>, f@entry=0x38, trx=trx@entry=0xfffffffffffff290, max_query_len=56, max_query_len@entry=140636058381456, n_rec_locks=80,
|
n_rec_locks@entry=124519691848192, n_trx_locks=n_trx_locks@entry=6269010687742184054, heap_size=<optimized out>) at /mariadb/10.6/storage/innobase/trx/trx0trx.cc:1744
|
#2 0x000056542b4a20ba in trx_print_latched (f=0x38, f@entry=0x7fe86a231318, trx=<optimized out>, trx@entry=0x7fe86a231318, max_query_len=140636058381456, max_query_len@entry=600)
|
at /mariadb/10.6/storage/innobase/trx/trx0trx.cc:1763
|
#3 0x000056542aebb2ba in lock_trx_print_wait_and_mvcc_state (file=0x714000000a00, trx=0x7fe86a231318, now=...) at /mariadb/10.6/storage/innobase/lock/lock0lock.cc:4185
|
#4 0x000056542aeed8b5 in lock_print_info::operator() (this=this@entry=0x7fe8624d7068, trx=...) at /mariadb/10.6/storage/innobase/lock/lock0lock.cc:4251
|
#5 0x000056542aee5ff6 in thread_safe_trx_ilist_t::for_each<lock_print_info> (this=0x56542cdf6d40 <trx_sys+128>, callback=...) at /mariadb/10.6/storage/innobase/include/trx0sys.h:828
|
#6 0x000056542aebdf6f in lock_print_info_all_transactions (file=<optimized out>) at /mariadb/10.6/storage/innobase/lock/lock0lock.cc:4272
|
#7 0x000056542b3aec49 in srv_printf_innodb_monitor (file=0x714000000a00, nowait=nowait@entry=0, trx_start_pos=trx_start_pos@entry=0x7fe8624d7970, trx_end=trx_end@entry=0x7fe8624d7968)
|
at /mariadb/10.6/storage/innobase/srv/srv0srv.cc:830
|
#8 0x000056542acd1d2c in innodb_show_status (hton=<optimized out>, thd=0x72b000070018,
|
stat_print=0x565429ea61a0 <stat_print(THD*, char const*, unsigned long, char const*, unsigned long, char const*, unsigned long)>) at /mariadb/10.6/storage/innobase/handler/ha_innodb.cc:16109
|
#9 innobase_show_status (hton=<optimized out>, hton@entry=0x714000000818, thd=thd@entry=0x72b000070018,
|
stat_print=0x565429ea61a0 <stat_print(THD*, char const*, unsigned long, char const*, unsigned long, char const*, unsigned long)>, stat_type=<optimized out>)
|
at /mariadb/10.6/storage/innobase/handler/ha_innodb.cc:16191
|
#10 0x0000565429ea59c3 in ha_show_status (thd=thd@entry=0x72b000070018, db_type=0x714000000818, stat=stat@entry=HA_ENGINE_STATUS) at /mariadb/10.6/sql/handler.cc:6898
|
The transaction had been created here:
Thread 5 hit Hardware watchpoint 2: -location trx.id
|
|
Old value = 0
|
New value = 88
|
trx_sys_t::register_rw (this=0x56542cdf6cc0 <trx_sys>, trx=0x7fe86a231318) at /mariadb/10.6/storage/innobase/include/trx0sys.h:1102
|
1102 rw_trx_hash.insert(trx);
|
(rr) bt
|
#0 trx_sys_t::register_rw (this=0x56542cdf6cc0 <trx_sys>, trx=0x7fe86a231318) at /mariadb/10.6/storage/innobase/include/trx0sys.h:1102
|
#1 trx_start_low (trx=<optimized out>, read_write=true) at /mariadb/10.6/storage/innobase/trx/trx0trx.cc:947
|
#2 0x000056542b4a5e62 in trx_start_internal_low (trx=0x0, trx@entry=0x7fe86a231318, read_write=<optimized out>) at /mariadb/10.6/storage/innobase/trx/trx0trx.cc:2100
|
#3 0x000056542b7ff1b5 in dict_stats_save (table_orig=0x719000020398, table_orig@entry=0x716000041d88, only_for_index=only_for_index@entry=0x0) at /mariadb/10.6/storage/innobase/dict/dict0stats.cc:3106
|
#4 0x000056542b80c4a1 in dict_stats_update (table=<optimized out>, table@entry=0x716000041d88, stats_upd_option=stats_upd_option@entry=DICT_STATS_RECALC_PERSISTENT)
|
at /mariadb/10.6/storage/innobase/dict/dict0stats.cc:3854
|
#5 0x000056542b82db1a in dict_stats_process_entry_from_recalc_pool (thd=0x72b00007e018) at /mariadb/10.6/storage/innobase/dict/dict0stats_bg.cc:340
|
#6 dict_stats_func () at /mariadb/10.6/storage/innobase/dict/dict0stats_bg.cc:393
|
#7 0x000056542ba63910 in tpool::thread_pool_generic::timer_generic::run (this=0x711000014640) at /mariadb/10.6/tpool/tpool_generic.cc:313
|
Starting with the fix of MDEV-25919, background THDs may wait for MDL or InnoDB locks.
The problem appears to be that thd->real_id is not initialized. Its value consists of 0xa5 bytes, and the MSAN shadow bits for it are all set.
10190 len= my_snprintf(header, sizeof(header), |
10191 "MariaDB thread id %u, OS thread handle %lu, query id %llu", |
10192 (uint)thd->thread_id, (ulong) thd->real_id, (ulonglong) thd->query_id);
|
Attachments
Issue Links
- is caused by
-
MDEV-25919 InnoDB reports misleading lock wait timeout on DDL operations
- Closed