Details
-
Bug
-
Status: Closed (View Workflow)
-
Critical
-
Resolution: Duplicate
-
10.5.12, 10.5.13, 10.6
Description
We got a crash like this:
10.6 101da87228f11a1d7582f5dccfda7f30ac3b5668 |
==2645651==ERROR: AddressSanitizer: use-after-poison on address 0x1b9a262b3db0 at pc 0x5583f42fdaeb bp 0x20cf03661100 sp 0x20cf036610f0
|
READ of size 8 at 0x1b9a262b3db0 thread T44
|
2021-06-24 4:15:01 240 [Warning] Aborted connection 240 to db: 'test' user: 'root' host: 'localhost' (This connection closed normally)
|
#0 0x5583f42fdaea in innobase_kill_query /data/Server/10.6D/storage/innobase/handler/ha_innodb.cc:4895
|
#1 0x5583f38ef057 in kill_handlerton /data/Server/10.6D/sql/handler.cc:933
|
#2 0x5583f30e4dce in plugin_foreach_with_mask(THD*, char (*)(THD*, st_plugin_int**, void*), int, unsigned int, void*) /data/Server/10.6D/sql/sql_plugin.cc:2510
|
#3 0x5583f38f9c2d in ha_kill_query(THD*, thd_kill_levels) /data/Server/10.6D/sql/handler.cc:940
|
#4 0x5583f2f7a2cc in THD::awake_no_mutex(killed_state) /data/Server/10.6D/sql/sql_class.cc:1925
|
#5 0x5583f309484a in kill_one_thread(THD*, long long, killed_state, killed_type) /data/Server/10.6D/sql/sql_parse.cc:9256
|
…
|
Shadow bytes around the buggy address:
|
…
|
=>0x0373c4c4e7b0: 00 f7 04 f7 f7 f7[f7]f7 f7 04 00 f7 f7 f7 f7 f7
|
ssh sdp
|
rr replay /data/Results/1624532926/TBR-975/dev/shm/vardir/1624532926/5/1/rr/latest-trace
|
(rr) continue
|
…
|
Thread 3 received signal SIGABRT, Aborted.
|
…
|
(rr) watch *(char*)0x0373c4c4e7b6
|
Hardware watchpoint 1: *(char*)0x0373c4c4e7b6
|
(rr) when
|
Current event: 562471
|
(rr) reverse-continue
|
Continuing.
|
[Switching to Thread 2645651.2646885]
|
|
Thread 34 hit Hardware watchpoint 1: *(char*)0x0373c4c4e7b6
|
|
Old value = -9 '\367'
|
New value = 0 '\000'
|
__memset_avx2_unaligned_erms () at ../sysdeps/x86_64/multiarch/memset-vec-unaligned-erms.S:244
|
244 ../sysdeps/x86_64/multiarch/memset-vec-unaligned-erms.S: No such file or directory.
|
(rr) thr a 3 bt
|
|
Thread 3 (Thread 2645651.2647440):
|
#0 __lll_lock_wait (futex=futex@entry=0x5583f6dda640 <THR_LOCK_mutex>, private=0) at lowlevellock.c:52
|
#1 0x00003424383dd235 in __GI___pthread_mutex_lock (mutex=0x5583f6dda640 <THR_LOCK_mutex>) at ../nptl/pthread_mutex_lock.c:135
|
#2 0x00005583f4e348c0 in safe_mutex_lock (mp=mp@entry=0x5583f6dda2a0 <LOCK_alarm>, my_flags=my_flags@entry=0, file=file@entry=0x5583f58e4f40 "/data/Server/10.6D/mysys/thr_alarm.c", line=line@entry=455) at /data/Server/10.6D/mysys/thr_mutex.c:333
|
#3 0x00005583f4e2e459 in inline_mysql_mutex_lock (src_line=455, src_file=0x5583f58e4f40 "/data/Server/10.6D/mysys/thr_alarm.c", that=0x5583f6dda2a0 <LOCK_alarm>) at /data/Server/10.6D/include/mysql/psi/mysql_thread.h:750
|
#4 thr_alarm_kill (thread_id=107) at /data/Server/10.6D/mysys/thr_alarm.c:455
|
#5 0x00005583f2f7a53e in THD::awake_no_mutex (this=this@entry=0x62b000230218, state_to_set=state_to_set@entry=KILL_CONNECTION) at /data/Server/10.6D/sql/sql_class.cc:1916
|
#6 0x00005583f309484b in kill_one_thread (thd=thd@entry=0x62b0002df218, id=id@entry=107, kill_signal=kill_signal@entry=KILL_CONNECTION, type=type@entry=KILL_TYPE_ID) at /data/Server/10.6D/sql/sql_parse.cc:9256
|
#7 0x00005583f3095320 in sql_kill (thd=thd@entry=0x62b0002df218, id=107, state=state@entry=KILL_CONNECTION, type=type@entry=KILL_TYPE_ID) at /data/Server/10.6D/sql/sql_parse.cc:9378
|
#8 0x00005583f30d1e02 in mysql_execute_command (thd=thd@entry=0x62b0002df218, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /data/Server/10.6D/sql/sql_parse.cc:5530
|
#9 0x00005583f308ae69 in mysql_parse (thd=thd@entry=0x62b0002df218, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x20cf03662390) at /data/Server/10.6D/sql/sql_parse.cc:8028
|
#10 0x00005583f30b8f51 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x62b0002df218, packet=packet@entry=0x6290010c7219 " KILL SOFT CONNECTION @kill_id /* E_R Thread31 QNO 741 CON_ID 131 */ ", packet_length=packet_length@entry=69, blocking=blocking@entry=true) at /data/Server/10.6D/sql/sql_class.h:1337
|
#11 0x00005583f30c114b in do_command (thd=0x62b0002df218, blocking=blocking@entry=true) at /data/Server/10.6D/sql/sql_parse.cc:1406
|
#12 0x00005583f34f9777 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x6080000b8138, put_in_cache=put_in_cache@entry=true) at /data/Server/10.6D/sql/sql_connect.cc:1410
|
#13 0x00005583f34fa325 in handle_one_connection (arg=0x6080000b8138) at /data/Server/10.6D/sql/sql_connect.cc:1312
|
#14 0x00003424383da609 in start_thread (arg=<optimized out>) at pthread_create.c:477
|
#15 0x00007ffe871f7293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|
(rr) bt
|
#0 __memset_avx2_unaligned_erms () at ../sysdeps/x86_64/multiarch/memset-vec-unaligned-erms.S:244
|
#1 0x000038c565d8f022 in __asan_poison_memory_region () from /usr/lib/x86_64-linux-gnu/libasan.so.5
|
#2 0x00005583f48d2d58 in trx_t::free (this=this@entry=0x1b9a262b2de8) at /data/Server/10.6D/storage/innobase/trx/trx0trx.cc:422
|
#3 0x00005583f42f6edf in innobase_close_connection (hton=<optimized out>, thd=0x62b000230218) at /data/Server/10.6D/storage/innobase/handler/ha_innodb.cc:4882
|
#4 0x00005583f38f9a89 in ha_close_connection (thd=thd@entry=0x62b000230218) at /data/Server/10.6D/sql/handler.cc:916
|
#5 0x00005583f2f78b37 in THD::free_connection (this=this@entry=0x62b000230218) at /data/Server/10.6D/sql/sql_class.cc:1624
|
#6 0x00005583f2dc8aee in unlink_thd (thd=0x62b000230218) at /data/Server/10.6D/sql/mysqld.cc:2693
|
#7 0x00005583f34f9caa in do_handle_one_connection (connect=<optimized out>, connect@entry=0x608000003b38, put_in_cache=put_in_cache@entry=true) at /data/Server/10.6D/sql/sql_connect.cc:1421
|
#8 0x00005583f34fa325 in handle_one_connection (arg=0x608000003b38) at /data/Server/10.6D/sql/sql_connect.cc:1312
|
#9 0x00003424383da609 in start_thread (arg=<optimized out>) at pthread_create.c:477
|
#10 0x00007ffe871f7293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|
At the time of the crash, the crashing Thread 3 would have proceeded to the following:
#6 0x000038c565d941ab in __asan_report_load8 () from /usr/lib/x86_64-linux-gnu/libasan.so.5
|
#7 0x00005583f42fdaeb in innobase_kill_query (thd=0x62b000230218) at /usr/include/c++/9/bits/atomic_base.h:734
|
#8 0x00005583f38ef058 in kill_handlerton (thd=0x62b000230218, plugin=<optimized out>, level=0x20cf03661320) at /data/Server/10.6D/sql/handler.cc:933
|
#9 0x00005583f30e4dcf in plugin_foreach_with_mask (thd=thd@entry=0x62b000230218, func=func@entry=0x5583f38eef15 <kill_handlerton(THD*, plugin_ref, void*)>, type=type@entry=1, state_mask=state_mask@entry=8,
|
arg=arg@entry=0x20cf03661320) at /data/Server/10.6D/sql/sql_plugin.cc:2510
|
#10 0x00005583f38f9c2e in ha_kill_query (thd=thd@entry=0x62b000230218, level=<optimized out>) at /data/Server/10.6D/sql/handler.cc:940
|
#11 0x00005583f2f7a2cd in THD::awake_no_mutex (this=this@entry=0x62b000230218, state_to_set=state_to_set@entry=KILL_CONNECTION) at /data/Server/10.6D/sql/sql_class.cc:1925
|
#12 0x00005583f309484b in kill_one_thread (thd=thd@entry=0x62b0002df218, id=id@entry=107, kill_signal=kill_signal@entry=KILL_CONNECTION, type=type@entry=KILL_TYPE_ID) at /data/Server/10.6D/sql/sql_parse.cc:9256
|
#13 0x00005583f3095320 in sql_kill (thd=thd@entry=0x62b0002df218, id=107, state=state@entry=KILL_CONNECTION, type=type@entry=KILL_TYPE_ID) at /data/Server/10.6D/sql/sql_parse.cc:9378
|
#14 0x00005583f30d1e02 in mysql_execute_command (thd=thd@entry=0x62b0002df218, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /data/Server/10.6D/sql/sql_parse.cc:5530
|
#15 0x00005583f308ae69 in mysql_parse (thd=thd@entry=0x62b0002df218, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x20cf03662390) at /data/Server/10.6D/sql/sql_parse.cc:8028
|
#16 0x00005583f30b8f51 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x62b0002df218,
|
packet=packet@entry=0x6290010c7219 " KILL SOFT CONNECTION @kill_id /* E_R Thread31 QNO 741 CON_ID 131 */ ", packet_length=packet_length@entry=69, blocking=blocking@entry=true)
|
at /data/Server/10.6D/sql/sql_class.h:1337
|
I suspect that this affects earlier versions as well.
Note: There already is an ASAN error report about KILL QUERY, with RQG grammar, in MDEV-24571, affecting 10.2.
Also note that InnoDB used to work around this kind of races in MDEV-17092, but that work-around was removed in MDEV-23536 when the problem was supposedly fixed.
Attachments
Issue Links
- duplicates
-
MDEV-29368 Assertion `trx->mysql_thd == thd' failed in innobase_kill_query from process_timers/timer_handler and use-after-poison in innobase_kill_query
- Closed
- relates to
-
MDEV-24571 ASAN failure during KILL CONNECTION
- Open
-
MDEV-17092 ERROR: AddressSanitizer: use-after-poison around lock_trx_handle_wait_low
- Closed
-
MDEV-23536 Race condition between KILL and transaction commit
- Closed