Crash on DROP DATABASE due to out-of-bounds result from InnoDB SUBSTR() function

Workflow

1. Bootstrap and start DB server  MariaDB 10.5.14

     origin/10.5 2776635cb98d35867447d375fdc04a44ef11a697 2021-12-16

     Maybe problematic: innodb_undo_tablespaces=3 , innodb_undo_log_truncate=ON

2. Create some initial data and run some DDL/DML in one session.

     Maybe problematic:  TRUNCATE TABLE , ALTER TABLE ADD/DROP FOREIGN KEY

3. Dump schemas and table data

4. Send SIGTERM to DB server and wait till its finished

5. Restart with 10.7.2

    origin/10.7 92a4e76a2c1c15fb44dc0cb05e06d5aa408a8e35 2021-12-14

6. Run the upgrade script   bin/mysql_upgrade

     # 2021-12-20T18:50:38 [2705670] | [rr 2761342 49673][rr 2761342 49677]==2761342==ERROR: AddressSanitizer: heap-buffer-overflow on address 0x602000009bb7 at pc 0x7e864e7cbd00 bp 0x595748e692a0 sp 0x595748e68a48

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 49680][rr 2761342 49682]READ of size 19 at 0x602000009bb7 thread T16

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55570]    #0 0x7e864e7cbcff  (/lib/x86_64-linux-gnu/libasan.so.5+0xdacff)

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55604]    #1 0x5649c7645c4d in cmp_data(unsigned long, unsigned long, unsigned char const*, unsigned long, unsigned char const*, unsigned long) /data/Server/10.7A/storage/innobase/rem/rem0cmp.cc:322

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55608]    #2 0x5649c764137f in cmp_data_data(unsigned long, unsigned long, unsigned char const*, unsigned long, unsigned char const*, unsigned long) /data/Server/10.7A/storage/innobase/rem/rem0cmp.cc:378

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55620]    #3 0x5649c7a3872e in cmp_dfield_dfield /data/Server/10.7A/storage/innobase/include/rem0cmp.ic:49

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55622]    #4 0x5649c7a39770 in eval_cmp(func_node_t*) /data/Server/10.7A/storage/innobase/eval/eval0eval.cc:183

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55624]    #5 0x5649c7a3aa0a in eval_func(func_node_t*) /data/Server/10.7A/storage/innobase/eval/eval0eval.cc:595

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55634]    #6 0x5649c7a3b694 in eval_exp /data/Server/10.7A/storage/innobase/include/eval0eval.ic:117

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55636]    #7 0x5649c7a3bb68 in if_step(que_thr_t*) /data/Server/10.7A/storage/innobase/eval/eval0proc.cc:48

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55656]    #8 0x5649c7631bc1 in que_thr_step /data/Server/10.7A/storage/innobase/que/que0que.cc:611

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55658]    #9 0x5649c7632328 in que_run_threads_low /data/Server/10.7A/storage/innobase/que/que0que.cc:709

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55660]    #10 0x5649c76324ca in que_run_threads(que_thr_t*) /data/Server/10.7A/storage/innobase/que/que0que.cc:729

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55662]    #11 0x5649c76327f0 in que_eval_sql(pars_info_t*, char const*, trx_t*) /data/Server/10.7A/storage/innobase/que/que0que.cc:768

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55702]    #12 0x5649c7357604 in innodb_drop_database /data/Server/10.7A/storage/innobase/handler/ha_innodb.cc:1504

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55729]    #13 0x5649c6ad849e in dropdb_handlerton /data/Server/10.7A/sql/handler.cc:826

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55741]    #14 0x5649c6345e45 in plugin_foreach_with_mask(THD*, char (*)(THD*, st_plugin_int**, void*), int, unsigned int, void*) /data/Server/10.7A/sql/sql_plugin.cc:2509

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55743]    #15 0x5649c6ad84d7 in ha_drop_database(char const*) /data/Server/10.7A/sql/handler.cc:833

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55747]    #16 0x5649c61e7ff8 in drop_database_objects(THD*, st_mysql_const_lex_string const*, st_mysql_const_lex_string const*, bool) /data/Server/10.7A/sql/sql_db.cc:987

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55749]    #17 0x5649c61e8c27 in mysql_rm_db_internal /data/Server/10.7A/sql/sql_db.cc:1132

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55751]    #18 0x5649c61e9f5d in mysql_rm_db(THD*, st_mysql_const_lex_string const*, bool) /data/Server/10.7A/sql/sql_db.cc:1307

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55765]    #19 0x5649c62deceb in mysql_execute_command(THD*, bool) /data/Server/10.7A/sql/sql_parse.cc:5179

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55775]    #20 0x5649c636f5d3 in Prepared_statement::execute(String*, bool) /data/Server/10.7A/sql/sql_prepare.cc:5210

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55785]    #21 0x5649c636ab72 in Prepared_statement::execute_loop(String*, bool, unsigned char*, unsigned char*) /data/Server/10.7A/sql/sql_prepare.cc:4633

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55787]    #22 0x5649c6364f28 in mysql_sql_stmt_execute(THD*) /data/Server/10.7A/sql/sql_prepare.cc:3684

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55789]    #23 0x5649c62d5d38 in mysql_execute_command(THD*, bool) /data/Server/10.7A/sql/sql_parse.cc:3960

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55791]    #24 0x5649c62f0ffa in mysql_parse(THD*, char*, unsigned int, Parser_state*) /data/Server/10.7A/sql/sql_parse.cc:8028

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55793]    #25 0x5649c62c92bf in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /data/Server/10.7A/sql/sql_parse.cc:1894

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55795]    #26 0x5649c62c6697 in do_command(THD*, bool) /data/Server/10.7A/sql/sql_parse.cc:1402

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55801]    #27 0x5649c66f9577 in do_handle_one_connection(CONNECT*, bool) /data/Server/10.7A/sql/sql_connect.cc:1418

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55803]    #28 0x5649c66f8e03 in handle_one_connection /data/Server/10.7A/sql/sql_connect.cc:1312

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55811]    #29 0x7f6f2f0b8608 in start_thread /build/glibc-eX1tMB/glibc-2.31/nptl/pthread_create.c:477

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 55813]    #30 0x725523e1f292 in __clone (/lib/x86_64-linux-gnu/libc.so.6+0x122292)

...

# 2021-12-20T18:50:38 [2705670] | Query (0x62900004b2d0): DROP DATABASE IF EXISTS performance_schema

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 73077]

# 2021-12-20T18:50:38 [2705670] | Connection ID (thread ID): 13

# 2021-12-20T18:50:38 [2705670] | [rr 2761342 73079]Status: NOT_KILLED

pluto:/data/results/1640025904/TBR-1315/rqg.log

     Protocol of the RQG run

pluto:/data/results/1640025904/TBR-1315/dev/shm/rqg/1640025904/154/1/data_orig

     Copy of the data directory made after the SIGTERM and before the restart with 10.7.

cd /data/results/1640025904/TBR-1315/dev/shm/rqg/1640025904/154/1/rr/

_RR_TRACE_DIR="." rr replay --mark-stdio mysqld-1 # Fate of the DB server (10.5) till arrival of SIGTERM

_RR_TRACE_DIR="." rr replay --mark-stdio mysqld-2 # Fate of the DB server (10.7) till ASAN failure

RQG

===

# git clone https://github.com/mleich1/rqg --branch experimental RQG

#

# GIT_SHOW: HEAD -> experimental, origin/experimental 62e549d1b378ee71215e439c95eb5b1519434137 2021-12-20T18:19:03+01:00

# rqg.pl  : Version 4.0.4 (2021-12)

#

# $RQG_HOME/rqg.pl \

# --gendata=conf/mariadb/fk_truncate.zz \

# --grammar=conf/mariadb/fk_truncate.yy \

# --mysqld=--loose-innodb_lock_schedule_algorithm=fcfs \

# --mysqld=--loose-idle_write_transaction_timeout=0 \

# --mysqld=--loose-idle_transaction_timeout=0 \

# --mysqld=--loose-idle_readonly_transaction_timeout=0 \

# --mysqld=--connect_timeout=60 \

# --mysqld=--interactive_timeout=28800 \

# --mysqld=--slave_net_timeout=60 \

# --mysqld=--net_read_timeout=30 \

# --mysqld=--net_write_timeout=60 \

# --mysqld=--loose-table_lock_wait_timeout=50 \

# --mysqld=--wait_timeout=28800 \

# --mysqld=--lock-wait-timeout=86400 \

# --mysqld=--innodb-lock-wait-timeout=50 \

# --no-mask \

# --queries=10000000 \

# --seed=random \

# --reporters=Backtrace \

# --reporters=ErrorLog \

# --reporters=Deadlock1 \

# --reporters=Upgrade1 \

# --validators=None \

# --mysqld=--log_output=none \

# --mysqld=--log_bin_trust_function_creators=1 \

# --mysqld=--loose-debug_assert_on_not_freed_memory=0 \

# --engine=InnoDB \

# --restart_timeout=240 \

# --upgrade-test \

# --mysqld=--plugin-load-add=file_key_management.so \

# --mysqld=--loose-file-key-management-filename=$RQG_HOME/conf/mariadb/encryption_keys.txt \

# --duration=120 \

# --mysqld=--loose-innodb_fatal_semaphore_wait_threshold=300 \

# --mysqld=--loose-innodb_read_only_compressed=OFF \

# --mysqld=--loose-innodb-sync-debug \

# --mysqld=--innodb_stats_persistent=off \

# --mysqld=--innodb_adaptive_hash_index=off \

# --mysqld=--log-bin \

# --mysqld=--sync-binlog=1 \

# --mysqld=--loose-innodb_evict_tables_on_commit_debug=off \

# --mysqld=--loose-max-statement-time=30 \

# --threads=1 \

# --mysqld=--innodb-use-native-aio=0 \

# --mysqld=--loose-gdb \

# --mysqld=--loose-debug-gdb \

# --rr=Extended \

# --rr_options=--chaos --wait \

# --mysqld=--innodb_undo_tablespaces=3 \

# --mysqld=--innodb_undo_log_truncate=ON \

# --vardir_type=fast \

# --mysqld=--innodb_page_size=4K \

# --mysqld=--innodb-buffer-pool-size=256M \

# --no_mask \

# --mtr-build-thread=883 \

# --batch \

# <certain local settings>