[MDEV-21146] Assertion `m_lock_type == 2' failed in handler::ha_drop_table upon LOAD DATA Created: 2019-11-26  Updated: 2019-12-02  Resolved: 2019-11-28

Status: Closed
Project: MariaDB Server
Component/s: Versioned Tables, Views
Affects Version/s: 10.3, 10.4
Fix Version/s: N/A

Type: Bug Priority: Critical
Reporter: Elena Stepanova Assignee: Aleksey Midenkov
Resolution: Duplicate Votes: 0
Labels: affects-tests, regression

Issue Links:
Duplicate
duplicates MDEV-21155 Assertion with versioned table upon D... Closed
Relates
relates to MDEV-15534 InnoDB: Failing assertion: prebuilt->... Open
relates to MDEV-21155 Assertion with versioned table upon D... Closed

 Description    

CREATE TABLE t1 (a INT);
 
CREATE VIEW v1 AS SELECT * FROM t1;
 
CREATE OR REPLACE TABLE t1 (b INT) WITH SYSTEM VERSIONING;
 
--error ER_VIEW_INVALID
 
LOAD DATA INFILE 'xx' INTO TABLE v1;
 
 
 
# Cleanup
 
DROP VIEW v1;
 
DROP TABLE t1;

10.3 0076dce2c

 
mysqld: /data/src/10.3-bug-post/sql/handler.cc:4696: void handler::ha_drop_table(const char*): Assertion `m_lock_type == 2' failed.
 
191126  2:51:53 [ERROR] mysqld got signal 6 ;
 
 
 
#7  0x00007f512d698f12 in __GI___assert_fail (assertion=0x555d32724dc3 "m_lock_type == 2", file=0x555d32723ce0 "/data/src/10.3-bug-post/sql/handler.cc", line=4696, function=0x555d327276e0 <handler::ha_drop_table(char const*)::__PRETTY_FUNCTION__> "void handler::ha_drop_table(const char*)") at assert.c:101
 
#8  0x0000555d31c7e3f0 in handler::ha_drop_table (this=0x7f510c1211d8, name=0x7f510c096d10 "./test/t1") at /data/src/10.3-bug-post/sql/handler.cc:4696
 
#9  0x0000555d319d2b30 in free_tmp_table (thd=0x7f510c000af0, entry=0x7f510c120590) at /data/src/10.3-bug-post/sql/sql_select.cc:18863
 
#10 0x0000555d3190d5a9 in mysql_derived_prepare (thd=0x7f510c000af0, lex=0x7f510c0048f8, derived=0x7f510c012958) at /data/src/10.3-bug-post/sql/sql_derived.cc:821
 
#11 0x0000555d3190bf7e in mysql_handle_single_derived (lex=0x7f510c0048f8, derived=0x7f510c012958, phases=2) at /data/src/10.3-bug-post/sql/sql_derived.cc:199
 
#12 0x0000555d31a87d02 in TABLE_LIST::handle_derived (this=0x7f510c012958, lex=0x7f510c0048f8, phases=2) at /data/src/10.3-bug-post/sql/table.cc:8282
 
#13 0x0000555d3192570e in LEX::handle_list_of_derived (this=0x7f510c0048f8, table_list=0x7f510c012958, phases=2) at /data/src/10.3-bug-post/sql/sql_lex.h:4019
 
#14 0x0000555d31948933 in mysql_load (thd=0x7f510c000af0, ex=0x7f510c0128d0, table_list=0x7f510c012958, fields_vars=..., set_fields=..., set_values=..., handle_duplicates=DUP_ERROR, ignore=false, read_file_from_client=false) at /data/src/10.3-bug-post/sql/sql_load.cc:411
 
#15 0x0000555d3195e7c2 in mysql_execute_command (thd=0x7f510c000af0) at /data/src/10.3-bug-post/sql/sql_parse.cc:4873
 
#16 0x0000555d31968577 in mysql_parse (thd=0x7f510c000af0, rawbuf=0x7f510c012808 "LOAD DATA INFILE 'xx' INTO TABLE v1", length=35, parser_state=0x7f51280985e0, is_com_multi=false, is_next_command=false) at /data/src/10.3-bug-post/sql/sql_parse.cc:7818
 
#17 0x0000555d319550c3 in dispatch_command (command=COM_QUERY, thd=0x7f510c000af0, packet=0x7f510c008c61 "LOAD DATA INFILE 'xx' INTO TABLE v1", packet_length=35, is_com_multi=false, is_next_command=false) at /data/src/10.3-bug-post/sql/sql_parse.cc:1856
 
#18 0x0000555d31953a0b in do_command (thd=0x7f510c000af0) at /data/src/10.3-bug-post/sql/sql_parse.cc:1401
 
#19 0x0000555d31acae4c in do_handle_one_connection (connect=0x555d351c51b0) at /data/src/10.3-bug-post/sql/sql_connect.cc:1403
 
#20 0x0000555d31acabae in handle_one_connection (arg=0x555d351c51b0) at /data/src/10.3-bug-post/sql/sql_connect.cc:1308
 
#21 0x0000555d324774ee in pfs_spawn_thread (arg=0x555d351e0170) at /data/src/10.3-bug-post/storage/perfschema/pfs.cc:1862
 
#22 0x00007f512f20e4a4 in start_thread (arg=0x7f5128099700) at pthread_create.c:456
 
#23 0x00007f512d755d0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

Reproducible on 10.3-10.5.

The problem appeared in 10.3 with this commit:

commit 0076dce2c89248b6c0252ec4385879194f9aadbf
 
Author: Aleksey Midenkov
 
Date:   Fri Nov 22 14:29:03 2019 +0300
 
 
 
    MDEV-18727 improve DML operation of System Versioning
 
    MDEV-18957 UPDATE with LIMIT clause is wrong for versioned partitioned tables
 
    
    UPDATE, DELETE: replace linear search of current/historical records
 
    with vers_setup_conds().
 
    
    Additional DML cases in view.test



 Comments   
Comment by Elena Stepanova [ 2019-11-27 ]

Variations on a non-debug build.

With MyISAM:

CREATE TABLE t1 (a INT);
 
CREATE VIEW v1 AS SELECT * FROM t1;
 
CREATE OR REPLACE TABLE t1 (b INT) WITH SYSTEM VERSIONING;
 
--error ER_VIEW_INVALID
 
LOAD DATA INFILE 'xx' INTO TABLE v1;
 
 
# Cleanup
 
DROP VIEW v1;
 
DROP TABLE t1;

Similar to MDEV-21155, but without prepared statements:

10.3 RelWithDebInfo bf58ec77

 
#3  <signal handler called>
 
#4  mi_extra (info=0x0, function=HA_EXTRA_DETACH_CHILDREN, extra_arg=0x0) at /data/src/10.3/storage/myisam/mi_extra.c:42
 
#5  0x000055738891e9e0 in close_thread_tables (thd=thd@entry=0x7fc4180009a8) at /data/src/10.3/sql/sql_base.cc:756
 
#6  0x0000557388975a8c in mysql_execute_command (thd=thd@entry=0x7fc4180009a8) at /data/src/10.3/sql/sql_parse.cc:6115
 
#7  0x000055738897d679 in mysql_parse (thd=thd@entry=0x7fc4180009a8, rawbuf=<optimized out>, length=35, parser_state=parser_state@entry=0x7fc42a2be620, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /data/src/10.3/sql/sql_parse.cc:7818
 
#8  0x000055738897fe8d in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7fc4180009a8, packet=packet@entry=0x7fc4180070b9 "LOAD DATA INFILE 'xx' INTO TABLE v1", packet_length=packet_length@entry=35, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /data/src/10.3/sql/sql_parse.cc:1856
 
#9  0x0000557388980b06 in do_command (thd=0x7fc4180009a8) at /data/src/10.3/sql/sql_parse.cc:1401
 
#10 0x0000557388a47b44 in do_handle_one_connection (connect=connect@entry=0x55738b301d18) at /data/src/10.3/sql/sql_connect.cc:1403
 
#11 0x0000557388a47bf4 in handle_one_connection (arg=arg@entry=0x55738b301d18) at /data/src/10.3/sql/sql_connect.cc:1308
 
#12 0x0000557388fb6fd4 in pfs_spawn_thread (arg=0x55738b29ce78) at /data/src/10.3/storage/perfschema/pfs.cc:1862
 
#13 0x00007fc431c374a4 in start_thread (arg=0x7fc42a2bf700) at pthread_create.c:456
 
#14 0x00007fc43017ed0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

With InnoDB:

--source include/have_innodb.inc
 
 
 
CREATE TABLE t1 (a INT) ENGINE=InnoDB;
 
CREATE VIEW v1 AS SELECT * FROM t1;
 
CREATE OR REPLACE TABLE t1 (b INT) WITH SYSTEM VERSIONING;
 
--error ER_VIEW_INVALID
 
LOAD DATA INFILE 'xx' INTO TABLE v1;
 
 
# Cleanup
 
DROP VIEW v1;
 
DROP TABLE t1;

10.3 RelWithDebInfo bf58ec77

 
2019-11-27 20:28:47 0x7effc0b81700  InnoDB: Assertion failure in file /data/src/10.3/storage/innobase/row/row0mysql.cc line 1060
 
InnoDB: Failing assertion: prebuilt->magic_n == ROW_PREBUILT_ALLOCATED
 
 
 
#5  0x00007effc77bd42a in __GI_abort () at abort.c:89
 
#6  0x000055718ae7fe47 in ut_dbg_assertion_failed (expr=expr@entry=0x55718b75e588 "prebuilt->magic_n == ROW_PREBUILT_ALLOCATED", file=file@entry=0x55718b75e048 "/data/src/10.3/storage/innobase/row/row0mysql.cc", line=line@entry=1060) at /data/src/10.3/storage/innobase/ut/ut0dbg.cc:60
 
#7  0x000055718b32e518 in row_update_prebuilt_trx (prebuilt=<optimized out>, trx=trx@entry=0x7effc1649090) at /data/src/10.3/storage/innobase/row/row0mysql.cc:1060
 
#8  0x000055718b282b58 in ha_innobase::update_thd (this=0x7eff7406ad60, this=0x7eff7406ad60, thd=0x7eff740009a8) at /data/src/10.3/storage/innobase/handler/ha_innodb.cc:2963
 
#9  ha_innobase::external_lock (this=0x7eff7406ad60, thd=0x7eff740009a8, lock_type=2) at /data/src/10.3/storage/innobase/handler/ha_innodb.cc:15732
 
#10 0x000055718b11b7cc in handler::ha_external_lock (this=0x7eff7406ad60, thd=thd@entry=0x7eff740009a8, lock_type=lock_type@entry=2) at /data/src/10.3/sql/handler.cc:6371
 
#11 0x000055718b1deea7 in unlock_external (thd=thd@entry=0x7eff740009a8, table=0x7eff74012220, count=<optimized out>) at /data/src/10.3/sql/lock.cc:708
 
#12 0x000055718b1df043 in mysql_unlock_tables (thd=0x7eff740009a8, sql_lock=0x7eff74012200, free_lock=<optimized out>) at /data/src/10.3/sql/lock.cc:429
 
#13 0x000055718b1df621 in mysql_unlock_tables (thd=<optimized out>, sql_lock=<optimized out>) at /data/src/10.3/sql/lock.cc:415
 
#14 0x000055718aef1a91 in close_thread_tables (thd=thd@entry=0x7eff740009a8) at /data/src/10.3/sql/sql_base.cc:854
 
#15 0x000055718af48a8c in mysql_execute_command (thd=thd@entry=0x7eff740009a8) at /data/src/10.3/sql/sql_parse.cc:6115
 
#16 0x000055718af50679 in mysql_parse (thd=thd@entry=0x7eff740009a8, rawbuf=<optimized out>, length=35, parser_state=parser_state@entry=0x7effc0b80620, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /data/src/10.3/sql/sql_parse.cc:7818
 
#17 0x000055718af52e8d in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7eff740009a8, packet=packet@entry=0x7eff740070b9 "LOAD DATA INFILE 'xx' INTO TABLE v1", packet_length=packet_length@entry=35, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /data/src/10.3/sql/sql_parse.cc:1856
 
#18 0x000055718af53b06 in do_command (thd=0x7eff740009a8) at /data/src/10.3/sql/sql_parse.cc:1401
 
#19 0x000055718b01ab44 in do_handle_one_connection (connect=connect@entry=0x55718d7455e8) at /data/src/10.3/sql/sql_connect.cc:1403
 
#20 0x000055718b01abf4 in handle_one_connection (arg=arg@entry=0x55718d7455e8) at /data/src/10.3/sql/sql_connect.cc:1308
 
#21 0x000055718b589fd4 in pfs_spawn_thread (arg=0x55718d745848) at /data/src/10.3/storage/perfschema/pfs.cc:1862
 
#22 0x00007effc932a4a4 in start_thread (arg=0x7effc0b81700) at pthread_create.c:456
 
#23 0x00007effc7871d0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

With Aria:

CREATE TABLE t1 (a INT);
 
CREATE VIEW v1 AS SELECT * FROM t1;
 
CREATE OR REPLACE TABLE t1 (b INT) WITH SYSTEM VERSIONING ENGINE=Aria;
 
--error ER_VIEW_INVALID
 
LOAD DATA INFILE 'xx' INTO TABLE v1;
 
 
# Cleanup
 
DROP VIEW v1;
 
DROP TABLE t1;


#3  <signal handler called>
 
#4  ha_maria::extra (this=0x7ff9840aa170, operation=HA_EXTRA_DETACH_CHILDREN) at /data/src/10.3/storage/maria/ha_maria.cc:2510
 
#5  0x000055d6e8f5d9e0 in close_thread_tables (thd=thd@entry=0x7ff9840009a8) at /data/src/10.3/sql/sql_base.cc:756
 
#6  0x000055d6e8fb4a8c in mysql_execute_command (thd=thd@entry=0x7ff9840009a8) at /data/src/10.3/sql/sql_parse.cc:6115
 
#7  0x000055d6e8fbc679 in mysql_parse (thd=thd@entry=0x7ff9840009a8, rawbuf=<optimized out>, length=35, parser_state=parser_state@entry=0x7ff994512620, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /data/src/10.3/sql/sql_parse.cc:7818
 
#8  0x000055d6e8fbee8d in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7ff9840009a8, packet=packet@entry=0x7ff9840070b9 "LOAD DATA INFILE 'xx' INTO TABLE v1", packet_length=packet_length@entry=35, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /data/src/10.3/sql/sql_parse.cc:1856
 
#9  0x000055d6e8fbfb06 in do_command (thd=0x7ff9840009a8) at /data/src/10.3/sql/sql_parse.cc:1401
 
#10 0x000055d6e9086b44 in do_handle_one_connection (connect=connect@entry=0x55d6ebfefd08) at /data/src/10.3/sql/sql_connect.cc:1403
 
#11 0x000055d6e9086bf4 in handle_one_connection (arg=arg@entry=0x55d6ebfefd08) at /data/src/10.3/sql/sql_connect.cc:1308
 
#12 0x000055d6e95f5fd4 in pfs_spawn_thread (arg=0x55d6ebf8ae68) at /data/src/10.3/storage/perfschema/pfs.cc:1862
 
#13 0x00007ff99be8b4a4 in start_thread (arg=0x7ff994513700) at pthread_create.c:456
 
#14 0x00007ff99a3d2d0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

Comment by Elena Stepanova [ 2019-11-29 ]

Yet another variation of a stack trace, for a record/search:

10.4 3826178d non-debug ASAN build

 
==14462==ERROR: AddressSanitizer: heap-use-after-free on address 0x62900019a220 at pc 0x55ff8deb3366 bp 0x7f94a201cbd0 sp 0x7f94a201cbc8
 
WRITE of size 8 at 0x62900019a220 thread T27
 
    #0 0x55ff8deb3365 in relink_trn_used_instances /data/src/10.4/storage/maria/ma_trnman.h:94
 
    #1 0x55ff8deb3365 in ha_maria::implicit_commit(THD*, bool) /data/src/10.4/storage/maria/ha_maria.cc:2909
 
    #2 0x55ff8ce83190 in mysql_execute_command(THD*) /data/src/10.4/sql/sql_parse.cc:6163
 
    #3 0x55ff8ce9bd98 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.4/sql/sql_parse.cc:7901
 
    #4 0x55ff8cea1674 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.4/sql/sql_parse.cc:1842
 
    #5 0x55ff8cea5577 in do_command(THD*) /data/src/10.4/sql/sql_parse.cc:1360
 
    #6 0x55ff8d1139e7 in do_handle_one_connection(CONNECT*) /data/src/10.4/sql/sql_connect.cc:1412
 
    #7 0x55ff8d113c0a in handle_one_connection /data/src/10.4/sql/sql_connect.cc:1316
 
    #8 0x7f94c53f04a3 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x74a3)
 
    #9 0x7f94c3937d0e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe8d0e)
 
 
 
0x62900019a220 is located 32 bytes inside of 18208-byte region [0x62900019a200,0x62900019e920)
 
freed by thread T27 here:
 
    #0 0x7f94c56c7a10 in free (/usr/lib/x86_64-linux-gnu/libasan.so.3+0xc1a10)
 
    #1 0x55ff8df75acd in maria_close /data/src/10.4/storage/maria/ma_close.c:257
 
 
 
previously allocated by thread T27 here:
 
    #0 0x7f94c56c7d28 in malloc (/usr/lib/x86_64-linux-gnu/libasan.so.3+0xc1d28)
 
    #1 0x55ff8e1cbbdc in my_malloc /data/src/10.4/mysys/my_malloc.c:101
 
 
 
Thread T27 created by T0 here:
 
    #0 0x7f94c5636f59 in __interceptor_pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.3+0x30f59)
 
    #1 0x55ff8cc7c0b6 in inline_mysql_thread_create /data/src/10.4/include/mysql/psi/mysql_thread.h:1268
 
    #2 0x55ff8cc7c0b6 in create_thread_to_handle_connection(CONNECT*) /data/src/10.4/sql/mysqld.cc:6234
 
 
 
SUMMARY: AddressSanitizer: heap-use-after-free /data/src/10.4/storage/maria/ma_trnman.h:94 in relink_trn_used_instances
 
Shadow bytes around the buggy address:
 
  0x0c528002b3f0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c528002b400: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c528002b410: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c528002b420: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c528002b430: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
=>0x0c528002b440: fd fd fd fd[fd]fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c528002b450: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c528002b460: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c528002b470: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c528002b480: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c528002b490: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
Shadow byte legend (one shadow byte represents 8 application bytes):
 
  Addressable:           00
 
  Partially addressable: 01 02 03 04 05 06 07 
  Heap left redzone:       fa
 
  Heap right redzone:      fb
 
  Freed heap region:       fd
 
  Stack left redzone:      f1
 
  Stack mid redzone:       f2
 
  Stack right redzone:     f3
 
  Stack partial redzone:   f4
 
  Stack after return:      f5
 
  Stack use after scope:   f8
 
  Global redzone:          f9
 
  Global init order:       f6
 
  Poisoned by user:        f7
 
  Container overflow:      fc
 
  Array cookie:            ac
 
  Intra object redzone:    bb
 
  ASan internal:           fe
 
  Left alloca redzone:     ca
 
  Right alloca redzone:    cb
 
==14462==ABORTING
 
----------SERVER LOG END-------------

Generated at Thu Feb 08 09:04:56 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.