...

2020-09-10  9:18:44 0 [Note] Recovering after a crash using mysql-bin

2020-09-10  9:18:44 0 [Note] InnoDB: Loading buffer pool(s) from /dev/shm/vardir/1599750400/110/1/data/ib_buffer_pool

2020-09-10  9:18:45 0 [Note] InnoDB: Buffer pool(s) load completed at 200910  9:18:45

2020-09-10  9:18:47 0 [Note] InnoDB: To roll back: 4 transactions, 193 rows

2020-09-10  9:18:48 0 [Note] Starting crash recovery...

2020-09-10  9:18:48 0 [Note] Crash recovery finished.

2020-09-10  9:18:52 0 [Note] InnoDB: Rolled back recovered transaction 102402

mysqld: storage/innobase/row/row0uins.cc:532: dberr_t row_undo_ins(undo_node_t*, que_thr_t*): Assertion `node->table->is_temporary() || lock_table_has_locks(node->table)' failed.

...

(rr) bt

#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50

#1  0x0000405d491ac859 in __GI_abort () at abort.c:79

#2  0x0000405d491ac729 in __assert_fail_base (fmt=0x405d49342588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x557283fde500 "node->table->is_temporary() || lock_table_has_locks(node->table)", 

    file=0x557283fde920 "storage/innobase/row/row0uins.cc", line=532, function=<optimized out>) at assert.c:92

#3  0x0000405d491bdf36 in __GI___assert_fail (assertion=assertion@entry=0x557283fde500 "node->table->is_temporary() || lock_table_has_locks(node->table)", 

    file=file@entry=0x557283fde920 "storage/innobase/row/row0uins.cc", line=line@entry=532, function=function@entry=0x557283fde580 "dberr_t row_undo_ins(undo_node_t*, que_thr_t*)") at assert.c:101

#4  0x00005572832d80ea in row_undo_ins (node=node@entry=0x61b000051020, thr=thr@entry=0x6170000311e8) at storage/innobase/include/dict0mem.h:1795

#5  0x0000557282cf2b21 in row_undo (node=node@entry=0x61b000051020, thr=thr@entry=0x6170000311e8) at storage/innobase/row/row0undo.cc:433

#6  0x0000557282cf7602 in row_undo_step (thr=thr@entry=0x6170000311e8) at /storage/innobase/row/row0undo.cc:494

#7  0x0000557282b2b96b in que_thr_step (thr=thr@entry=0x6170000311e8) at storage/innobase/que/que0que.cc:945

#8  0x0000557282b2c8dc in que_run_threads_low (thr=thr@entry=0x6170000311e8) at storage/innobase/que/que0que.cc:1009

#9  0x0000557282b2d618 in que_run_threads (thr=0x6170000311e8) at storage/innobase/que/que0que.cc:1049

#10 0x0000557282e1a38d in trx_rollback_active (trx=trx@entry=0x3002289a20b8) at storage/innobase/trx/trx0roll.cc:628

#11 0x0000557282e223d6 in trx_rollback_recovered (all=all@entry=true) at storage/innobase/trx/trx0roll.cc:782

#12 0x0000557282e234e1 in trx_rollback_all_recovered () at storage/innobase/trx/trx0roll.cc:836

#13 0x00007c755c863609 in start_thread (arg=<optimized out>) at pthread_create.c:477

#14 0x0000405d492a9103 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

(rr)

Workflow

========

1. Start the server, load some initial data

2. Several concurrent sessions run a DDL/DML mix

3. At some point of time (2. is ongoing) the server process gets killed with ABRT

4. Attempt to restart that server

MariaDB

=======

origin/bb-10.5-MDEV-23399 29e8b54c1289f212eb8e820fab584b0769c6c69e 2020-09-10T14:28:45+03:00

The server claims to be a 10.5.6-MariaDB-debug-log.

RQG

====

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

origin/experimental 26f374c2dbcebdbe72321f3728c564f1c327bba6 2020-09-02T13:10:22+02:00

perl rqg.pl \

--grammar=conf/mariadb/innodb_compression_encryption.yy \

--gendata=conf/mariadb/innodb_compression_encryption.zz \

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

--mysqld=--loose-file-key-management-filename=/home/mleich/RQG/conf/mariadb/encryption_keys.txt \

--mysqld=--innodb-encrypt-log \

--mysqld=--innodb-encrypt-tables \

--reporters=CrashRecovery1 \

--redefine=conf/mariadb/redefine_innodb_undo.yy \

--mysqld=--innodb-immediate-scrub-data-uncompressed=1 \

--mysqld=--innodb_use_native_aio=1 \

--mysqld=--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 \

--validators=None \

--mysqld=--log_output=none \

--mysqld=--log-bin \

--mysqld=--log_bin_trust_function_creators=1 \

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

--engine=InnoDB \

--restart_timeout=120 \

--duration=300 \

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

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

--mysqld=--innodb_stats_persistent=off \

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

--threads=33 \

--mysqld=--innodb_page_size=4K \

--mysqld=--innodb-buffer-pool-size=8M \

--duration=300 \

--no_mask \

--workdir=<local settings> \

--vardir=<local settings> \

--mtr-build-thread=<local settings> \

--basedir1=<local settings> \

--script_debug=_nix_ \

--rr=Server \

--rr_options=--chaos

Innodb compression and encryption are involved but its unknown if

they are required for the current defect.

The likelihood to replay the current problem is rather low.