[MDEV-32089] Assertion `!strcmp(&path[strlen(path) - strlen(dot_ext[IBD])], dot_ext[IBD])' failed in void mtr_t::log_file_op(mfile_type_t, uint32_t, const char*, const char*) Created: 2023-09-04  Updated: 2023-12-07

Status: Stalled
Project: MariaDB Server
Component/s: Virtual Columns
Affects Version/s: 10.9, 10.10, 10.11, 11.0, 11.1, 11.2, 11.3
Fix Version/s: 10.11, 11.0, 11.1, 11.2

Type: Bug Priority: Major
Reporter: Ramesh Sivaraman Assignee: Aleksey Midenkov
Resolution: Unresolved Votes: 0
Labels: ASAN, debug, duplicate

Issue Links:
Duplicate
duplicates MDEV-30926 Segfault after MyISAM repair of vcol-... In Review
Relates
relates to MDEV-5800 indexes on virtual (not materialized)... Closed

 Description   

CREATE TABLE t (a INT GENERATED ALWAYS AS (1) VIRTUAL,KEY(a)) ENGINE=MyISAM;
INSERT INTO t VALUES(),();
CHECK TABLE t EXTENDED;
CREATE TABLE fts_t (f INT KEY,f2 CHAR(1),FULLTEXT (f2)) ENGINE=InnoDB;
CREATE PROCEDURE p() UPDATE t SET a=a;
CALL p;
SHUTDOWN;

11.3.0 8951f7d940166063db3fe64c35c40a5e5fabcf7d (Debug)

mariadbd: /test/11.3_dbg/storage/innobase/fil/fil0fil.cc:1608: void mtr_t::log_file_op(mfile_type_t, uint32_t, const char*, const char*): Assertion `!strcmp(&path[strlen(path) - strlen(dot_ext[IBD])], dot_ext[IBD])' failed.

11.3.0 8951f7d940166063db3fe64c35c40a5e5fabcf7d (Debug)

Core was generated by `/test/MD240823-mariadb-11.3.0-linux-x86_64-dbg/bin/mariadbd --no-defaults --cor'.
Program terminated with signal SIGABRT, Aborted.
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
[Current thread is 1 (Thread 0x14ce9478b980 (LWP 3326205))]
(gdb) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x000014ce94964859 in __GI_abort () at abort.c:79
#2  0x000014ce94964729 in __assert_fail_base (fmt=0x14ce94afa588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55f87e5f4448 "!strcmp(&path[strlen(path) - strlen(dot_ext[IBD])], dot_ext[IBD])", file=0x55f87e5f1d00 "/test/11.3_dbg/storage/innobase/fil/fil0fil.cc", line=1608, function=<optimized out>) at assert.c:92
#3  0x000014ce94975fd6 in __GI___assert_fail (assertion=assertion@entry=0x55f87e5f4448 "!strcmp(&path[strlen(path) - strlen(dot_ext[IBD])], dot_ext[IBD])", file=file@entry=0x55f87e5f1d00 "/test/11.3_dbg/storage/innobase/fil/fil0fil.cc", line=line@entry=1608, function=function@entry=0x55f87e5f43f8 "void mtr_t::log_file_op(mfile_type_t, uint32_t, const char*, const char*)") at assert.c:101
#4  0x000055f87e0b0576 in mtr_t::log_file_op (new_path=0x0, path=0x14ce2408c190 "./test/FTS_", '0' <repeats 14 times>, "\001", space_id=9, type=FILE_MODIFY, this=0x7ffc8a7a1e70) at /test/11.3_dbg/storage/innobase/fil/fil0fil.cc:1608
#5  fil_name_write (space_id=9, name=<optimized out>, mtr=mtr@entry=0x7ffc8a7a1e70) at /test/11.3_dbg/storage/innobase/fil/fil0fil.cc:1661
#6  0x000055f87e0b114e in fil_names_clear (lsn=lsn@entry=75263) at /test/11.3_dbg/storage/innobase/fil/fil0fil.cc:3191
#7  0x000055f87e04338d in log_checkpoint_low (oldest_lsn=oldest_lsn@entry=75263, end_lsn=end_lsn@entry=75263) at /test/11.3_dbg/storage/innobase/buf/buf0flu.cc:1909
#8  0x000055f87e043bfe in log_checkpoint () at /test/11.3_dbg/storage/innobase/buf/buf0flu.cc:1950
#9  0x000055f87e043f03 in buf_flush_wait_flushed (sync_lsn=75263) at /test/11.3_dbg/storage/innobase/buf/buf0flu.cc:2040
#10 0x000055f87e043f55 in log_make_checkpoint () at /usr/include/c++/9/bits/atomic_base.h:413
#11 0x000055f87de2749d in logs_empty_and_mark_files_at_shutdown () at /test/11.3_dbg/storage/innobase/log/log0log.cc:1207
#12 0x000055f87df74710 in innodb_shutdown () at /test/11.3_dbg/storage/innobase/srv/srv0start.cc:1980
#13 0x000055f87dd7dec5 in innobase_end () at /test/11.3_dbg/storage/innobase/handler/ha_innodb.cc:4246
#14 0x000055f87da9371a in ha_finalize_handlerton (plugin=0x55f87fc0f800) at /test/11.3_dbg/sql/handler.cc:599
#15 0x000055f87d7a977b in plugin_deinitialize (plugin=0x55f87fc0f800, ref_check=ref_check@entry=true) at /test/11.3_dbg/sql/sql_plugin.cc:1270
#16 0x000055f87d7aa07b in reap_plugins () at /test/11.3_dbg/sql/sql_plugin.cc:1344
#17 0x000055f87d7ace4f in plugin_shutdown () at /test/11.3_dbg/sql/sql_plugin.cc:2055
#18 0x000055f87d6633af in clean_up (print_message=print_message@entry=true) at /test/11.3_dbg/sql/mysqld.cc:2013
#19 0x000055f87d66f5da in mysqld_main (argc=<optimized out>, argv=<optimized out>) at /test/11.3_dbg/sql/mysqld.cc:6091
#20 0x000055f87d662b76 in main (argc=<optimized out>, argv=<optimized out>) at /test/11.3_dbg/sql/main.cc:34

Bug confirmed present in:
MariaDB: 10.9.8 (dbg), 10.10.6 (dbg), 10.11.5 (dbg), 11.0.3 (dbg), 11.1.2 (dbg), 11.2.2 (dbg), 11.3.0 (dbg)

Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.4.31 (dbg), 10.4.31 (opt), 10.4.32 (dbg), 10.4.32 (opt), 10.5.22 (dbg), 10.5.22 (opt), 10.6.15 (opt), 10.6.15 (dbg), 10.9.8 (opt), 10.10.6 (opt), 10.11.5 (opt), 11.0.3 (opt), 11.1.2 (opt), 11.2.2 (opt), 11.3.0 (opt)



 Comments   
Comment by Marko Mäkelä [ 2023-09-04 ]

Please test also with AddressSanitizer when there is a bug that involves virtual columns. The statement UPDATE t a=a triggers the following:

10.10 cb384d0d04bed63b714d6d7b02d26b19d22740cc

==175820==ERROR: AddressSanitizer: heap-use-after-free on address 0x60600003f458 at pc 0x55ab63f853a1 bp 0x7fdd6d1c3940 sp 0x7fdd6d1c3938
READ of size 1 at 0x60600003f458 thread T23
    #0 0x55ab63f853a0 in Field::set_notnull(long long) /mariadb/10.10/sql/field.h:1405
    #1 0x55ab63f853a0 in save_int_value_in_field /mariadb/10.10/sql/item.cc:6919
    #2 0x55ab63f85445 in Item_int::save_in_field(Field*, bool) /mariadb/10.10/sql/item.cc:6926
    #3 0x55ab6493a827 in TABLE::update_virtual_fields(handler*, enum_vcol_update_mode) /mariadb/10.10/sql/table.cc:8928
    #4 0x55ab6407a136 in handler::ha_rnd_next(unsigned char*) /mariadb/10.10/sql/handler.cc:3473
    #5 0x55ab64326d4c in rr_sequential(READ_RECORD*) /mariadb/10.10/sql/records.cc:519
    #6 0x55ab6490bca7 in READ_RECORD::read_record() /mariadb/10.10/sql/records.h:81
    #7 0x55ab6490bca7 in mysql_update(THD*, TABLE_LIST*, List<Item>&, List<Item>&, Item*, unsigned int, st_order*, unsigned long long, bool, unsigned long long*, unsigned long long*) /mariadb/10.10/sql/sql_update.cc:1023
    #8 0x55ab6464836f in mysql_execute_command(THD*, bool) /mariadb/10.10/sql/sql_parse.cc:4421
    #9 0x55ab643808c4 in sp_instr_stmt::exec_core(THD*, unsigned int*) /mariadb/10.10/sql/sp_head.cc:3854
    #10 0x55ab643913a1 in sp_lex_keeper::reset_lex_and_exec_core(THD*, unsigned int*, bool, sp_instr*) /mariadb/10.10/sql/sp_head.cc:3579
    #11 0x55ab643921e2 in sp_instr_stmt::execute(THD*, unsigned int*) /mariadb/10.10/sql/sp_head.cc:3760
    #12 0x55ab6439a498 in sp_head::execute(THD*, bool) /mariadb/10.10/sql/sp_head.cc:1456
    #13 0x55ab6439d2ff in sp_head::execute_procedure(THD*, List<Item>*) /mariadb/10.10/sql/sp_head.cc:2443
    #14 0x55ab6462c0f8 in do_execute_sp /mariadb/10.10/sql/sql_parse.cc:3034
    #15 0x55ab64635f57 in Sql_cmd_call::execute(THD*) /mariadb/10.10/sql/sql_parse.cc:3280
    #16 0x55ab64652131 in mysql_execute_command(THD*, bool) /mariadb/10.10/sql/sql_parse.cc:6024
    #17 0x55ab64653af5 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /mariadb/10.10/sql/sql_parse.cc:8057

We already have a similar bug MDEV-30926 with somewhat different symptoms of the heap-use-after-free.

Comment by Marko Mäkelä [ 2023-09-04 ]

This looks pretty similar to MDEV-31782, which you had filed less than 2 months ago.

Generated at Thu Feb 08 10:28:44 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.