Marko Mäkelä added a comment - 2020-09-22 08:04 This is a rather interesting bug. The DATA DIRECTORY flag will be wrongly set. And not only that, the table->data_dir_path will have been truncated to "./t" : 10.2 e05650e6868eab2dbb9f58c4786bcc71afc4ffce Thread 3 hit Watchpoint 8: table->data_dir_path[3]   Old value = 101 'e' New value = 0 '\000' os_file_make_data_dir_path (data_dir_path=<optimized out>) at /mariadb/10.2o/storage/innobase/os/os0file.cc:1393 1393 } (rr) bt #0 os_file_make_data_dir_path (data_dir_path=<optimized out>) at /mariadb/10.2o/storage/innobase/os/os0file.cc:1393 #1 0x000055685158363d in dict_save_data_dir_path (table=0x7f635816c6b0, filepath=<optimized out>) at /mariadb/10.2o/storage/innobase/dict/dict0load.cc:2724 #2 dict_get_and_save_data_dir_path (table=0x7f635816c6b0, dict_mutex_own=false) at /mariadb/10.2o/storage/innobase/dict/dict0load.cc:2755 #3 0x00005568512eeaa2 in ha_innobase::truncate (this=0x7f6358091f60) at /mariadb/10.2o/storage/innobase/handler/ha_innodb.cc:13706 I was suspecting heap-use-after-free , but WITH_ASAN will not flag anything before the assertion failure. We seem to get this truncated data_file_name = "./t" on the first invocation of ha_innobase::truncate() .

Marko Mäkelä added a comment - 2020-09-22 08:30 After ALTER TABLE t DISCARD TABLESPACE , the tablespace will no longer exist, and dict_get_and_save_data_dir_path() would invoke dict_get_first_path() to read an entry from SYS_DATAFILES (which we plan to remove in MDEV-22343 ). For some reason, DISCARD TABLESPACE would not to remove the entry from there. I did not try to figure out why we truncate the name from "./test/t.ibd" to "./t" . I think that this entire function dict_get_and_save_data_dir_path() is unnecessary (because unlike MySQL 5.7, we do not support CREATE TABLESPACE for InnoDB) and should be removed, possibly as part of MDEV-22343 .

Roel Van de Paar added a comment - 2020-10-02 07:48 - edited Whilst this bug is resolved, I still had an older testcase which I wanted to add as it's quite different and sporadic (requires 10 to 500 executions to hit, and interestingly the drop/create does not seem to be required to hit the [now-fixed] bug): DROP DATABASE test; CREATE DATABASE test; SET SQL_MODE=''; USE test; CREATE TABLE tab(c1 int NOT NULL PRIMARY KEY,c2 POINT NOT NULL, c3 LINESTRING NOT NULL,c4 POLYGON NOT NULL,c5 GEOMETRY NOT NULL) ROW_FORMAT=COMPRESSED KEY_BLOCK_SIZE=8; ALTER TABLE tab DISCARD TABLESPACE; SET @@enforce_storage_engine=INNODB; ALTER TABLE tab ENGINE Aria; It leads to the same assert on 10.4, does not produce on 10.5. I build 10.4.15 at revision bd64c2e8cc610dc774411c5f0a8ab163fc685934 today, and the bug does not reproduce there anymore with this testcase, or the one above (both tested on debug only), so I consider it solved. Interestingly, the testcase above (or quite close to it) led also to this assert (on the older revision) in the original run (and was reduced to the above). Perhaps the occurrence of this particular assert is even less pronounced, or requires the C-API for replay. 10.4.15 eae968f62d285de97ed607c87bc131cd863d5d03 mysqld: /test/10.4_dbg/include/mysql/psi/mysql_socket.h:744: inline_mysql_socket_send: Assertion `mysql_socket.fd != -1' failed. 10.4.15 eae968f62d285de97ed607c87bc131cd863d5d03 Core was generated by `/test/MD110820-mariadb-10.4.15-linux-x86_64-dbg/bin/mysqld --no-defaults --max_'. Program terminated with signal SIGABRT, Aborted. #0 __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:57 [Current thread is 1 (Thread 0x14813c0ad700 (LWP 843609))] (gdb) bt #0 __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:57 #1 0x0000558484cae8a6 in my_write_core (sig=sig@entry=6) at /test/10.4_dbg/mysys/stacktrace.c:482 #2 0x000055848442acdc in handle_fatal_signal (sig=6) at /test/10.4_dbg/sql/signal_handler.cc:343 #3 <signal handler called> #4 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51 #5 0x0000148146df48b1 in __GI_abort () at abort.c:79 #6 0x0000148146de442a in __assert_fail_base (fmt=0x148146f6ba38 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x55848534bd6a "mysql_socket.fd != -1", file=file@entry=0x55848534bb78 "/test/10.4_dbg/include/mysql/psi/mysql_socket.h", line=line@entry=744, function=function@entry=0x55848534beb0 <__PRETTY_FUNCTION__.15660> "inline_mysql_socket_send") at assert.c:92 #7 0x0000148146de44a2 in __GI___assert_fail (assertion=assertion@entry=0x55848534bd6a "mysql_socket.fd != -1", file=file@entry=0x55848534bb78 "/test/10.4_dbg/include/mysql/psi/mysql_socket.h", line=line@entry=744, function=function@entry=0x55848534beb0 <__PRETTY_FUNCTION__.15660> "inline_mysql_socket_send") at assert.c:101 #8 0x0000558484d0eca6 in inline_mysql_socket_send (flags=64, n=84, buf=0x1480e08ab840, mysql_socket={fd = -1, m_psi = 0x0}, src_line=301, src_file=0x55848534b9e0 "/test/10.4_dbg/vio/viosocket.c") at /test/10.4_dbg/include/mysql/psi/mysql_socket.h:744 #9 vio_write (vio=0x55848900b640, buf=0x1480e08ab840 "\001", size=84) at /test/10.4_dbg/vio/viosocket.c:300 #10 0x000055848459de2d in net_real_write (net=net@entry=0x1480e0001048, packet=0x1480e08ab840 "\001", len=<optimized out>) at /test/10.4_dbg/sql/net_serv.cc:693 #11 0x000055848459e094 in net_flush (net=net@entry=0x1480e0001048) at /test/10.4_dbg/sql/net_serv.cc:384 #12 0x000055848459e5df in net_write_command (net=net@entry=0x1480e0001048, command=command@entry=255 '\377', header=header@entry=0x558484f61b76 "", head_len=head_len@entry=0, packet=packet@entry=0x14813c0abf00 "\207\a#70100Connection was killed", len=29) at /test/10.4_dbg/sql/net_serv.cc:533 #13 0x0000558484089ea3 in net_send_error_packet (thd=0x1480e0000d50, sql_errno=sql_errno@entry=1927, err=<optimized out>, err@entry=0x1480e0006753 "Connection was killed", sqlstate=sqlstate@entry=0x1480e0006738 "70100") at /test/10.4_dbg/sql/protocol.cc:475 #14 0x000055848408a101 in Protocol::send_error (this=0x1480e0001318, sql_errno=1927, err_msg=0x1480e0006753 "Connection was killed", sql_state=0x1480e0006738 "70100") at /test/10.4_dbg/sql/protocol.cc:672 #15 0x000055848408a300 in Protocol::end_statement (this=0x1480e0001318) at /test/10.4_dbg/sql/protocol.cc:596 #16 0x0000558484186c9f in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x1480e0000d50, packet=<optimized out>, packet@entry=0x1480e08ab841 "", packet_length=<optimized out>, packet_length@entry=76, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.4_dbg/sql/sql_parse.cc:2424 #17 0x000055848418835b in do_command (thd=0x1480e0000d50) at /test/10.4_dbg/sql/sql_parse.cc:1352 #18 0x00005584842b48b6 in do_handle_one_connection (connect=connect@entry=0x558488fc2560) at /test/10.4_dbg/sql/sql_connect.cc:1412 #19 0x00005584842b49d6 in handle_one_connection (arg=arg@entry=0x558488fc2560) at /test/10.4_dbg/sql/sql_connect.cc:1316 #20 0x0000558484bc1898 in pfs_spawn_thread (arg=0x558488ed0440) at /test/10.4_dbg/storage/perfschema/pfs.cc:1869 #21 0x0000148147d5b6db in start_thread (arg=0x14813c0ad700) at pthread_create.c:463 #22 0x0000148146ed5a3f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95 In any case, I will add this to the filters, and immediately remark this one as well as the original one. So, if any of this shows again, we'll pick up on it and know it's related.

Roel Van de Paar added a comment - 2020-10-02 07:50 - edited Also interesting (and perhaps another bug) is that on the current version, the second truncate does not give the same warning as the first: 10.4.15 bd64c2e8cc610dc774411c5f0a8ab163fc685934 (Debug) 10.4.15>CREATE TABLE t(c INT) ENGINE=InnoDB; Query OK, 0 rows affected (0.012 sec)   10.4.15>ALTER TABLE t DISCARD TABLESPACE; Query OK, 0 rows affected (0.004 sec)   10.4.15>RENAME TABLE t TO u; Query OK, 0 rows affected (0.009 sec)   10.4.15>TRUNCATE u; Query OK, 0 rows affected, 1 warning (0.017 sec)   10.4.15>show warnings; +---------+------+---------------------------------------------+ | Level | Code | Message | +---------+------+---------------------------------------------+ | Warning | 1814 | Tablespace has been discarded for table `u` | +---------+------+---------------------------------------------+ 1 row in set (0.000 sec)   10.4.15>TRUNCATE u; Query OK, 0 rows affected (0.022 sec) Not sure how that second truncate is able to complete "OK"? marko do you consider this another bug?

Roel Van de Paar added a comment - 2020-10-02 09:23 Interestingly, the assertion `mysql_socket.fd != -1' is seen a lot of my runs on scanning the same. I wonder if it is a separate bug as well.

Marko Mäkelä added a comment - 2020-10-02 16:02 Roel , I believe the ALTER TABLE t DISCARD TABLESPACE is broken by design, basically corrupting the table by removing the data file while retaining the metadata. TRUNCATE TABLE will fix this corruption by creating an empty table. It will also issue a warning if the tablespace had been discarded. If you see assertions mysql_socket.fd != 1 failing, those should have nothing to do with InnoDB. In any case, that should be a separate bug.