Sep 11 15:40:58 otto-m1 mysqld[1814]: 2020-09-11 15:40:58 0x7f90e3be5700  InnoDB: Assertion failure in file /home/buildbot/buildbot/build/mariadb-10.3.24/storage/innobase/sync/sync0rw.cc line 258

Sep 11 15:40:58 otto-m1 mysqld[1814]: InnoDB: Failing assertion: my_atomic_load32_explicit(&lock->lock_word, MY_MEMORY_ORDER_RELAXED) == X_LOCK_DECR

Sep 11 15:40:58 otto-m1 mysqld[1814]: InnoDB: We intentionally generate a memory trap.

Sep 11 15:40:58 otto-m1 mysqld[1814]: InnoDB: Submit a detailed bug report to https://jira.mariadb.org/

Sep 11 15:40:58 otto-m1 mysqld[1814]: InnoDB: If you get repeated assertion failures or crashes, even

Sep 11 15:40:58 otto-m1 mysqld[1814]: InnoDB: immediately after the mysqld startup, there may be

Sep 11 15:40:58 otto-m1 mysqld[1814]: InnoDB: corruption in the InnoDB tablespace. Please refer to

Sep 11 15:40:58 otto-m1 mysqld[1814]: InnoDB: https://mariadb.com/kb/en/library/innodb-recovery-modes/

Sep 11 15:40:58 otto-m1 mysqld[1814]: InnoDB: about forcing recovery.

Sep 11 15:40:58 otto-m1 mysqld[1814]: 200911 15:40:58 [ERROR] mysqld got signal 6 ;

Sep 11 15:40:58 otto-m1 mysqld[1814]: This could be because you hit a bug. It is also possible that this binary

Sep 11 15:40:58 otto-m1 mysqld[1814]: or one of the libraries it was linked against is corrupt, improperly built,

Sep 11 15:40:58 otto-m1 mysqld[1814]: or misconfigured. This error can also be caused by malfunctioning hardware.

Sep 11 15:40:58 otto-m1 mysqld[1814]: To report this bug, see https://mariadb.com/kb/en/reporting-bugs

Sep 11 15:40:58 otto-m1 mysqld[1814]: We will try our best to scrape up some info that will hopefully help

Sep 11 15:40:58 otto-m1 mysqld[1814]: diagnose the problem, but since we have already crashed,

Sep 11 15:40:58 otto-m1 mysqld[1814]: something is definitely wrong and this may fail.

Sep 11 15:40:58 otto-m1 mysqld[1814]: Server version: 10.3.24-MariaDB-1:10.3.24+maria~bionic

Sep 11 15:40:58 otto-m1 mysqld[1814]: key_buffer_size=134217728

Sep 11 15:40:58 otto-m1 mysqld[1814]: read_buffer_size=131072

Sep 11 15:40:58 otto-m1 mysqld[1814]: max_used_connections=499

Sep 11 15:40:58 otto-m1 mysqld[1814]: max_threads=1002

Sep 11 15:40:58 otto-m1 mysqld[1814]: thread_count=163

Sep 11 15:40:58 otto-m1 mysqld[1814]: It is possible that mysqld could use up to

Sep 11 15:40:58 otto-m1 mysqld[1814]: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 2333977 K  bytes of memory

Sep 11 15:40:58 otto-m1 mysqld[1814]: Hope that's ok; if not, decrease some variables in the equation.

Sep 11 15:40:58 otto-m1 mysqld[1814]: Thread pointer: 0x7f92f4000c08

Sep 11 15:40:58 otto-m1 mysqld[1814]: Attempting backtrace. You can use the following information to find out

Sep 11 15:40:58 otto-m1 mysqld[1814]: where mysqld died. If you see no messages after this, something went

Sep 11 15:40:58 otto-m1 mysqld[1814]: terribly wrong...

Sep 11 15:40:58 otto-m1 mysqld[1814]: stack_bottom = 0x7f90e3be4dd8 thread_stack 0x49000

Sep 11 15:40:59 otto-m1 mysqld[1814]: *** buffer overflow detected ***: /usr/sbin/mysqld terminated

diff --git a/storage/innobase/buf/buf0buf.cc b/storage/innobase/buf/buf0buf.cc

index 6a8c4869659..5977271dc20 100644

--- a/storage/innobase/buf/buf0buf.cc

+++ b/storage/innobase/buf/buf0buf.cc

@@ -3840,7 +3840,7 @@ buf_page_create(fil_space_t *space, uint32_t offset,

     const bool drop_hash_entry= block->page.state() == BUF_BLOCK_FILE_PAGE &&

       UNIV_LIKELY_NULL(block->index);

     if (UNIV_UNLIKELY(drop_hash_entry))

-      block->page.set_io_fix(BUF_IO_PIN);

+      rw_lock_x_lock(&block->lock);

 #endif /* BTR_CUR_HASH_ADAPT */

     /* Page can be found in buf_pool */

@@ -3851,7 +3851,7 @@ buf_page_create(fil_space_t *space, uint32_t offset,

     if (UNIV_UNLIKELY(drop_hash_entry))

     {

       btr_search_drop_page_hash_index(block);

-      block->page.io_unfix();

+      rw_lock_x_unlock(&block->lock);

     }

 #endif /* BTR_CUR_HASH_ADAPT */

I got a similar assert on some development tree

origin/bb-10.3-MDEV-23072 23f5afe7fdb13e8f968eb9a587c1c8cf319927e8 2020-10-16T12:05:18+05:30

The server claims to be a 10.3.26.

Thread 4 received signal SIGABRT, Aborted.

...

# 2020-10-16T11:51:20 [908677] | Thread 4 (Thread 910010.910312):

# 2020-10-16T11:51:20 [908677] | #0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50

# 2020-10-16T11:51:20 [908677] | #1  0x000014c6b0928859 in __GI_abort () at abort.c:79

# 2020-10-16T11:51:20 [908677] | #2  0x000055809f72f033 in ut_dbg_assertion_failed (expr=expr@entry=0x5580a073f440 "my_atomic_load32_explicit(&lock->lock_word, MY_MEMORY_ORDER_RELAXED) == X_LOCK_DECR", file=file@entry=0x5580a073f660 "/home/mleich/Server/bb-10.3-MDEV-23072A/storage/innobase/sync/sync0rw.cc", line=line@entry=257) at /home/mleich/Server/bb-10.3-MDEV-23072A/storage/innobase/ut/ut0dbg.cc:60

# 2020-10-16T11:51:20 [908677] | #3  0x000055809f62183f in rw_lock_free_func (lock=lock@entry=0x4a6c5ade1440) at /home/mleich/Server/bb-10.3-MDEV-23072A/storage/innobase/sync/sync0rw.cc:257

# 2020-10-16T11:51:20 [908677] | #4  0x000055809f82bc2e in pfs_rw_lock_free_func (lock=0x4a6c5ade1440) at /home/mleich/Server/bb-10.3-MDEV-23072A/storage/innobase/include/sync0rw.ic:626

# 2020-10-16T11:51:20 [908677] | #5  0x000055809f86ab52 in buf_pool_resize () at /home/mleich/Server/bb-10.3-MDEV-23072A/storage/innobase/buf/buf0buf.cc:2928

# 2020-10-16T11:51:20 [908677] | #6  0x000055809f86dc61 in buf_resize_thread () at /home/mleich/Server/bb-10.3-MDEV-23072A/storage/innobase/buf/buf0buf.cc:3207

# 2020-10-16T11:51:20 [908677] | #7  0x0000137d33c62609 in start_thread (arg=<optimized out>) at pthread_create.c:477

# 2020-10-16T11:51:20 [908677] | #8  0x000014c6b0a25103 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

rr:/home/leich/RQG/storage/1602842276/

001086.log -- RQG log

001086.tgz -- Archive of remains including rr trace

Replaying via "rr"

==============

cd /home/mleich/RQG/storage/1602842276/TBR-580/dev/shm/vardir/1602842276/35/1/rr

_RR_TRACE_DIR="." rr replay --mark-stdio

RQG

====

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

perl rqg.pl \

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

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

--gendata_sql=conf/mariadb/table_stress.sql \

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

--mysqld=--loose-innodb_fatal_semaphore_wait_threshold=400 \

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

--mysqld=--innodb_stats_persistent=on \

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

--threads=33 \

--mysqld=--innodb_page_size=32K \

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

--duration=400 \

--no_mask \

--workdir=<local settings> \

--vardir=<local settings> \

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

--basedir1=<local settings> \

--script_debug=_nix_ \

--rr=Server \

--rr_options=--chaos

RQG error tagging pattern

[ 'TBR-580' , 'InnoDB: Assertion failure in file.{1,150}sync0rw.cc.{1,250}InnoDB: Failing assertion: my_atomic_load32_explicit\(&lock->lock_word, MY_MEMORY_ORDER_RELAXED\) == X_LOCK_DECR' ],

Hitting that problem is very rare.