Details
-
Bug
-
Status: Closed (View Workflow)
-
Critical
-
Resolution: Fixed
-
10.5.4
Description
This bug was not easy to reduce. The issue seems sporadic (or requires at least two runs), and is repeatable with a short SQL testcase, run at least 2 times. Issue will almost definitely happen on second attempt during the LOCK query. Another compounding issue is that core dumps do not always seem to be written for this bug. Any line or specific SQL (like the charset) in the final SQL testcase below may not be strictly necessary. This is as far as I got for the moment after several hours of debugging, though I may be able to add more testcases later, as I am seeing this bug with some regularity in the runs.
Place the following into in.sql (seems to "work" better) and SOURCE the same from the CLI, or execute at least twice in succession from the CLI. Perhaps MTR with repeat may work also.
DROP DATABASE test;CREATE DATABASE test;USE test;
|
SET SQL_MODE='';
|
SET SESSION storage_engine=Aria;
|
CREATE TABLE t3 (c1 DATE,c2 NUMERIC(65) UNSIGNED ZEROFILL,c3 DECIMAL(2)) ENGINE=Aria;
|
CREATE TABLE t2 (c1 VARCHAR(100)) ENGINE=Aria;
|
CREATE TABLE t1 (c1 INTEGER);
|
LOCK TABLES t3 WRITE,t2 WRITE,t1 WRITE;
|
INSERT INTO t1 VALUES (CONVERT(_ucs2 0x062C064706270646 USING utf8));
|
CREATE TRIGGER ai AFTER INSERT ON t1 FOR EACH ROW UPDATE t1 SET v=1 WHERE b=new.a;
|
INSERT INTO t1 VALUES (CONVERT(_ucs2 0x062C064706270646 USING utf8));
|
Leads to:
|
10.5.4 6877ef9a7c9c7ee55d67e4baaf4e8f7b874c9f89 |
200608 15:04:22 [ERROR] mysqld got signal 11 ;
|
...
|
Query (0x154add047030): LOCK TABLES t3 WRITE,t2 WRITE,t1 WRITE
|
|
10.5.4 6877ef9a7c9c7ee55d67e4baaf4e8f7b874c9f89 |
Core was generated by `/ram/MD060620-mariadb-10.5.4-linux-x86_64-opt/bin/mysqld --no-defaults --core-f'.
|
Program terminated with signal SIGSEGV, Segmentation fault.
|
#0 __pthread_kill (threadid=<optimized out>, signo=signo@entry=11) at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
|
[Current thread is 1 (Thread 0x154b02e64700 (LWP 3651885))]
|
(gdb) bt
|
#0 __pthread_kill (threadid=<optimized out>, signo=signo@entry=11) at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
|
#1 0x000055bee61a2927 in my_write_core (sig=sig@entry=11) at /test/10.5_opt/mysys/stacktrace.c:518
|
#2 0x000055bee5b6e33a in handle_fatal_signal (sig=11) at /test/10.5_opt/sql/signal_handler.cc:330
|
#3 <signal handler called>
|
#4 _ma_reset_history (share=0x154add06c218) at /test/10.5_opt/storage/maria/ma_state.c:822
|
#5 _ma_trnman_end_trans_hook (trn=0x154affca42d8, commit=1 '\001', active_transactions=0 '\000')
|
at /test/10.5_opt/storage/maria/ma_state.c:483
|
#6 0x000055bee5d3eece in trnman_end_trn (trn=trn@entry=0x154affca42d8, commit=commit@entry=1 '\001')
|
at /test/10.5_opt/storage/maria/trnman.c:475
|
#7 0x000055bee5d654cf in ma_commit (trn=trn@entry=0x154affca42d8) at /test/10.5_opt/storage/maria/ma_commit.c:73
|
#8 0x000055bee5d3762f in ha_maria::external_lock (this=0x154add0d1830, thd=0x154add012018, lock_type=2)
|
at /test/10.5_opt/storage/maria/ha_maria.cc:2854
|
#9 0x000055bee5b7961c in handler::ha_external_lock (this=0x154add0d1830, thd=thd@entry=0x154add012018, lock_type=lock_type@entry=2)
|
at /test/10.5_opt/sql/handler.cc:6521
|
#10 0x000055bee5c5d1ba in handler::ha_external_unlock (thd=0x154add012018, this=<optimized out>) at /test/10.5_opt/sql/handler.h:3400
|
#11 unlock_external (count=<optimized out>, table=0x154add0302f8, thd=0x154add012018) at /test/10.5_opt/sql/lock.cc:727
|
#12 mysql_unlock_tables (thd=0x154add012018, sql_lock=0x154add030298, free_lock=<optimized out>) at /test/10.5_opt/sql/lock.cc:432
|
#13 0x000055bee5c5d863 in mysql_unlock_tables (thd=thd@entry=0x154add012018, sql_lock=<optimized out>) at /test/10.5_opt/sql/lock.cc:417
|
#14 0x000055bee5911ce6 in close_thread_tables (thd=thd@entry=0x154add012018) at /test/10.5_opt/sql/sql_base.cc:908
|
#15 0x000055bee59129d8 in Locked_tables_list::unlock_locked_tables (this=this@entry=0x154add015cb0, thd=thd@entry=0x154add012018)
|
at /test/10.5_opt/sql/sql_base.cc:2358
|
#16 0x000055bee597757a in mysql_execute_command (thd=thd@entry=0x154add012018) at /test/10.5_opt/sql/sql_parse.cc:5059
|
#17 0x000055bee597e19c in mysql_parse (thd=0x154add012018, rawbuf=<optimized out>, length=38, parser_state=0x154b02e63430,
|
is_com_multi=<optimized out>, is_next_command=<optimized out>) at /test/10.5_opt/sql/sql_parse.cc:7992
|
#18 0x000055bee5973485 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x154add012018,
|
packet=packet@entry=0x154add03a019 "LOCK TABLES t3 WRITE,t2 WRITE,t1 WRITE", packet_length=packet_length@entry=38,
|
is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.5_opt/sql/sql_parse.cc:1874
|
#19 0x000055bee5971874 in do_command (thd=0x154add012018) at /test/10.5_opt/sql/sql_parse.cc:1355
|
#20 0x000055bee5a66e51 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x154affc339b8,
|
put_in_cache=put_in_cache@entry=true) at /test/10.5_opt/sql/sql_connect.cc:1411
|
#21 0x000055bee5a671b4 in handle_one_connection (arg=arg@entry=0x154affc339b8) at /test/10.5_opt/sql/sql_connect.cc:1313
|
#22 0x000055bee5dd48ca in pfs_spawn_thread (arg=0x154affc4e818) at /test/10.5_opt/storage/perfschema/pfs.cc:2201
|
#23 0x0000154b01ddd6db in start_thread (arg=0x154b02e64700) at pthread_create.c:463
|
#24 0x0000154b011db88f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|
Also ran the same through ASAN, and this output looks related, though may be related to the crash:
|
10.5.4 c2a929185c147fc85bbf91e2c537bcdd98f2e680 |
/test/10.5_opt/storage/maria/ma_state.c:822:29: runtime error: member access within null pointer of type 'struct MARIA_STATE_HISTORY'
|
ASAN:DEADLYSIGNAL
|
=================================================================
|
==3743828==ERROR: AddressSanitizer: SEGV on unknown address 0x000000000008 (pc 0x55ce6930133c bp 0x1512be0bbd30 sp 0x1512be0bbba0 T13)
|
==3743828==The signal is caused by a WRITE memory access.
|
==3743828==Hint: address points to the zero page.
|
#0 0x55ce6930133b in _ma_reset_history /test/10.5_opt/storage/maria/ma_state.c:822
|
#1 0x55ce6930133b in _ma_trnman_end_trans_hook /test/10.5_opt/storage/maria/ma_state.c:483
|
#2 0x55ce693783ee in trnman_end_trn /test/10.5_opt/storage/maria/trnman.c:475
|
#3 0x55ce6940284f in ma_commit /test/10.5_opt/storage/maria/ma_commit.c:73
|
#4 0x55ce693485c6 in ha_maria::external_lock(THD*, int) /test/10.5_opt/storage/maria/ha_maria.cc:2851
|
#5 0x55ce6853903a in handler::ha_external_lock(THD*, int) /test/10.5_opt/sql/handler.cc:6508
|
#6 0x55ce68dbcc0d in handler::ha_external_unlock(THD*) /test/10.5_opt/sql/handler.h:3393
|
#7 0x55ce68dbcc0d in unlock_external /test/10.5_opt/sql/lock.cc:727
|
#8 0x55ce68dbcc0d in mysql_unlock_tables(THD*, st_mysql_lock*, bool) /test/10.5_opt/sql/lock.cc:432
|
#9 0x55ce67353889 in close_thread_tables(THD*) /test/10.5_opt/sql/sql_base.cc:908
|
#10 0x55ce673583a7 in Locked_tables_list::unlock_locked_tables(THD*) /test/10.5_opt/sql/sql_base.cc:2355
|
#11 0x55ce6766029e in mysql_execute_command(THD*) /test/10.5_opt/sql/sql_parse.cc:5059
|
#12 0x55ce676961f5 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /test/10.5_opt/sql/sql_parse.cc:7991
|
#13 0x55ce6764455d in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /test/10.5_opt/sql/sql_parse.cc:1874
|
#14 0x55ce6763cfd8 in do_command(THD*) /test/10.5_opt/sql/sql_parse.cc:1355
|
#15 0x55ce67ce443e in do_handle_one_connection(CONNECT*, bool) /test/10.5_opt/sql/sql_connect.cc:1411
|
#16 0x55ce67ce7495 in handle_one_connection /test/10.5_opt/sql/sql_connect.cc:1313
|
#17 0x55ce6967d050 in pfs_spawn_thread /test/10.5_opt/storage/perfschema/pfs.cc:2201
|
#18 0x1512df4a96da in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x76da)
|
#19 0x1512dd33488e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0x12188e)
|
|
|
AddressSanitizer can not provide additional info.
|
SUMMARY: AddressSanitizer: SEGV /test/10.5_opt/storage/maria/ma_state.c:822 in _ma_reset_history
|
Thread T13 created by T0 here:
|
#0 0x55ce66ffe62f in pthread_create (/test/ASAN_MD280520-mariadb-10.5.4-linux-x86_64-opt/bin/mariadbd+0x561e62f)
|
#1 0x55ce6968f984 in my_thread_create /test/10.5_opt/storage/perfschema/my_thread.h:34
|
#2 0x55ce6968f984 in pfs_spawn_thread_v1 /test/10.5_opt/storage/perfschema/pfs.cc:2252
|
#3 0x55ce670f5b86 in inline_mysql_thread_create /test/10.5_opt/include/mysql/psi/mysql_thread.h:1321
|
#4 0x55ce670f5b86 in create_thread_to_handle_connection(CONNECT*) /test/10.5_opt/sql/mysqld.cc:5952
|
#5 0x55ce67107e9f in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /test/10.5_opt/sql/mysqld.cc:6076
|
#6 0x55ce67108e14 in handle_connections_sockets() /test/10.5_opt/sql/mysqld.cc:6203
|
#7 0x55ce6710b426 in mysqld_main(int, char**) /test/10.5_opt/sql/mysqld.cc:5621
|
#8 0x1512dd234b96 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x21b96)
|
|
|
==3743828==ABORTING
|
The issue does not seem to affect 10.4.14 (opt)
Attachments
Issue Links
- relates to
-
-
- Confirmed
-
-
-
- Closed
-
-
-
- Closed
-
Activity
Secondary testcase, reduced from another occurrence. It likely requires the C connector to reproduce, does not reproduce at CLI. I am adding it here for reference/comparison as to problem area.
DROP DATABASE test; CREATE DATABASE test; USE test;
|
SET default_storage_engine=InnoDB;
|
CREATE FUNCTION char not null(f1 char not null) returns char not null return f1;
|
CREATE TABLE t1 (c1 DECIMAL(1,1) PRIMARY KEY,c2 DECIMAL(40,30) UNSIGNED,c3 MEDIUMINT(1) ZEROFILL) ENGINE=Aria;
|
LOCK TABLES mysql.time_zone READ, mysql.proc READ, t1 WRITE;
|
SET @@global.max_statement_time = 0.123456;
|
INSERT INTO t1 (c1,c2,c3) VALUES ('a','a',8), ('a','a',2), ('a','b',3), ('a','c',4), ('a','d',5);
|
select insert('hello', -1, 1, 'hi');
|
CREATE TRIGGER t_after_insert AFTER INSERT ON t1 FOR EACH ROW SET @bug42188 = 10;
|
UNLOCK TABLES;
|
SELECT SLEEP(5);
|
Here is what seems to be a deterministic and client-independent test case (it's the same test case as in the original description, I just cleaned it up):
CREATE TABLE t1 (f1 INT) ENGINE=Aria; |
CREATE TABLE t2 (f2 INT) ENGINE=Aria; |
|
|
LOCK TABLES t2 WRITE, t1 WRITE;
|
INSERT INTO t1 VALUES (1); |
--error ER_BAD_FIELD_ERROR
|
CREATE TRIGGER ai AFTER INSERT ON t1 FOR EACH ROW UPDATE t1 SET v=1 WHERE b=new.a; |
UNLOCK TABLES;
|
|
|
# Cleanup
|
DROP TABLE t1, t2; |
|
10.5 01e8459d |
#3 <signal handler called>
|
#4 0x000055e16ba3bae5 in _ma_reset_history (share=0x7fce1c1fcbe8) at /data/src/10.5/storage/maria/ma_state.c:822
|
#5 0x000055e16ba3af59 in _ma_trnman_end_trans_hook (trn=0x55e16faf4278, commit=1 '\001', active_transactions=0 '\000') at /data/src/10.5/storage/maria/ma_state.c:483
|
#6 0x000055e16ba584f3 in trnman_end_trn (trn=0x55e16faf4278, commit=1 '\001') at /data/src/10.5/storage/maria/trnman.c:475
|
#7 0x000055e16ba91415 in ma_commit (trn=0x55e16faf4278) at /data/src/10.5/storage/maria/ma_commit.c:73
|
#8 0x000055e16ba52a99 in ha_maria::external_lock (this=0x7fce1c1fae20, thd=0x7fce1c000b18, lock_type=2) at /data/src/10.5/storage/maria/ha_maria.cc:2854
|
#9 0x000055e16b7d1ea6 in handler::ha_external_lock (this=0x7fce1c1fae20, thd=0x7fce1c000b18, lock_type=2) at /data/src/10.5/sql/handler.cc:6521
|
#10 0x000055e16b57224c in handler::ha_external_unlock (this=0x7fce1c1fae20, thd=0x7fce1c000b18) at /data/src/10.5/sql/handler.h:3400
|
#11 0x000055e16b90d05b in unlock_external (thd=0x7fce1c000b18, table=0x7fce1c048e20, count=1) at /data/src/10.5/sql/lock.cc:727
|
#12 0x000055e16b90c393 in mysql_unlock_tables (thd=0x7fce1c000b18, sql_lock=0x7fce1c048dd8, free_lock=true) at /data/src/10.5/sql/lock.cc:432
|
#13 0x000055e16b90c2e4 in mysql_unlock_tables (thd=0x7fce1c000b18, sql_lock=0x7fce1c048dd8) at /data/src/10.5/sql/lock.cc:417
|
#14 0x000055e16b3be3de in close_thread_tables (thd=0x7fce1c000b18) at /data/src/10.5/sql/sql_base.cc:908
|
#15 0x000055e16b3c1906 in Locked_tables_list::unlock_locked_tables (this=0x7fce1c004968, thd=0x7fce1c000b18) at /data/src/10.5/sql/sql_base.cc:2358
|
#16 0x000055e16b46ea2e in mysql_execute_command (thd=0x7fce1c000b18) at /data/src/10.5/sql/sql_parse.cc:5044
|
#17 0x000055e16b478479 in mysql_parse (thd=0x7fce1c000b18, rawbuf=0x7fce1c013960 "UNLOCK TABLES", length=13, parser_state=0x7fce46017520, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:7992
|
#18 0x000055e16b4647ff in dispatch_command (command=COM_QUERY, thd=0x7fce1c000b18, packet=0x7fce1c0086b9 "UNLOCK TABLES", packet_length=13, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:1875
|
#19 0x000055e16b462f37 in do_command (thd=0x7fce1c000b18) at /data/src/10.5/sql/sql_parse.cc:1356
|
#20 0x000055e16b607981 in do_handle_one_connection (connect=0x55e16fb07a88, put_in_cache=true) at /data/src/10.5/sql/sql_connect.cc:1411
|
#21 0x000055e16b6076e9 in handle_one_connection (arg=0x55e16fb07a88) at /data/src/10.5/sql/sql_connect.cc:1313
|
#22 0x000055e16bb40b56 in pfs_spawn_thread (arg=0x55e16fb076b8) at /data/src/10.5/storage/perfschema/pfs.cc:2201
|
#23 0x00007fce52a5f4a4 in start_thread (arg=0x7fce46018700) at pthread_create.c:456
|
#24 0x00007fce50b93d0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97
|
The failure appeared in 10.5 with this commit:
commit 4102f1589c23309de968a5bf9511d3228a1b9319
|
Author: Monty <monty@mariadb.org>
|
Date: Sat May 2 13:19:53 2020 +0300
|
|
|
Aria will now register it's transactions
|
elenst: Thank you very much! Confirmed the new testcase seems deterministic on my side also.
|
10.5.4 6877ef9a7c9c7ee55d67e4baaf4e8f7b874c9f89 |
10.5.4>CREATE TRIGGER ai AFTER INSERT ON t1 FOR EACH ROW UPDATE t1 SET v=1 WHERE b=new.a;
|
ERROR 1054 (42S22): Unknown column 'a' in 'NEW'
|
10.5.4>UNLOCK TABLES;
|
ERROR 2013 (HY000): Lost connection to MySQL server during query
|
Fixed in bb-10.5-monty, to be pushed to 10.5 soon.
Problem was that we didn't properly release transactions for tables used with CREATE TRIGGER.
Fixed by using same steps as ALTER TABLE to tell the engine that we are going to close and reopen the table
Please also see
MDEV-21413and MDEV-17754 (ref stack)