Crashes on Semaphore wait > 600 seconds

InnoDB: ###### Diagnostic info printed to the standard error stream

2020-12-09  9:55:45 0 [ERROR] [FATAL] InnoDB: Semaphore wait has lasted > 600 seconds. We intentionally crash the server because it appears to be hung.

201209  9:55:45 [ERROR] mysqld got signal 6 ;

This could be because you hit a bug. It is also possible that this binary

or one of the libraries it was linked against is corrupt, improperly built,

or misconfigured. This error can also be caused by malfunctioning hardware.

To report this bug, see https://mariadb.com/kb/en/reporting-bugs

We will try our best to scrape up some info that will hopefully help

diagnose the problem, but since we have already crashed, 

something is definitely wrong and this may fail.

Server version: 10.4.17-MariaDB-log

key_buffer_size=31457280

read_buffer_size=131072

max_used_connections=152

max_threads=4002

thread_count=161

It is possible that mysqld could use up to 

key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 8837909 K  bytes of memory

Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x0

Attempting backtrace. You can use the following information to find out

where mysqld died. If you see no messages after this, something went

terribly wrong...

stack_bottom = 0x0 thread_stack 0x49000

/usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x560adb3d04ae]

/usr/sbin/mysqld(handle_fatal_signal+0x30f)[0x560adae63e1f]

/lib64/libpthread.so.0(+0xf600)[0x7feabd373600]

/lib64/libc.so.6(gsignal+0x37)[0x7feabb89c3a7]

/lib64/libc.so.6(abort+0x148)[0x7feabb89da98]

/usr/sbin/mysqld(+0xc1bd60)[0x560adb159d60]

/usr/sbin/mysqld(+0xbd4232)[0x560adb112232]

/lib64/libpthread.so.0(+0x7e75)[0x7feabd36be75]

/lib64/libc.so.6(clone+0x6d)[0x7feabb9648fd]

The manual page at https://mariadb.com/kb/en/how-to-produce-a-full-stack-trace-for-mysqld/ contains

information that should help you find out what is causing the crash.

Writing a core file...

InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info:

InnoDB: Pending reads 0, writes 0

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

2020-12-09 09:43:53 0x7fe4bcbfc700 INNODB MONITOR OUTPUT

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

Per second averages calculated from the last 60 seconds

-----------------

BACKGROUND THREAD

-----------------

srv_master_thread loops: 102524 srv_active, 0 srv_shutdown, 221160 srv_idle

srv_master_thread log flush and writes: 323650

----------

SEMAPHORES

----------

OS WAIT ARRAY INFO: reservation count 3217156

--Thread 140620618213120 has waited at buf0flu.cc line 1176 for 241.00 seconds the semaphore:

SX-lock on RW-latch at 0x7fe6e6989208 created in file buf0buf.cc line 1568

a writer (thread id 140620299949824) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: e0000000

Last time write locked in file btr0cur.cc line 2417

--Thread 140620387563264 has waited at fsp0fsp.cc line 1984 for 227.00 seconds the semaphore:

X-lock on RW-latch at 0x7fe4a280aec0 created in file fil0fil.cc line 1266

a writer (thread id 140620299949824) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: dfffffff

Last time write locked in file fsp0fsp.cc line 2402

OS WAIT ARRAY INFO: signal count 22529095

RW-shared spins 41276936, rounds 128593064, OS waits 1031233

RW-excl spins 27792813, rounds 117073205, OS waits 1025437

RW-sx spins 1932526, rounds 13959835, OS waits 165716

Spin rounds per wait: 3.12 RW-shared, 4.21 RW-excl, 7.22 RW-sx

------------

TRANSACTIONS

------------

Trx id counter 17462604867

Purge done for trx's n:o < 17462603855 undo n:o < 0 state: running

History list length 487

LIST OF TRANSACTIONS FOR EACH SESSION:

---TRANSACTION 17462604866, ACTIVE 67 sec setting auto-inc lock

mysql tables in use 1, locked 1

LOCK WAIT 1 lock struct(s), heap size 1128, 0 row lock(s)

MySQL thread id 18649, OS thread handle 140620601120512, query id 777866038 172.31.66.100 dbworkerfactorysecure Executing

INSERT INTO ******

------- TRX HAS BEEN WAITING 67 SEC FOR THIS LOCK TO BE GRANTED:

TABLE LOCK table `leanload_landingzone`.`database_action_log` trx id 17462604866 lock mode AUTO-INC waiting

------------------

---TRANSACTION 17462604865, ACTIVE 144 sec inserting

mysql tables in use 1, locked 1

2 lock struct(s), heap size 1128, 0 row lock(s)

MySQL thread id 18646, OS thread handle 140619220154112, query id 777865925 172.31.66.223 dbworkerfactorysecure Executing

INSERT INTO ******

---TRANSACTION 422120853290824, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853286568, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 17462604837, ACTIVE 234 sec inserting

mysql tables in use 19, locked 13

2 lock struct(s), heap size 1128, 0 row lock(s), undo log entries 203216

MySQL thread id 18631, OS thread handle 140619223607040, query id 777476378 172.31.66.68 dbworkerfactorysecure Creating sort index

INSERT *****

Trx read view will not see trx with id >= 17462604819, sees < 17462603853

---TRANSACTION 17462603853, ACTIVE 325 sec inserting

mysql tables in use 5, locked 2

2 lock struct(s), heap size 1128, 0 row lock(s), undo log entries 3713879

MySQL thread id 18627, OS thread handle 140620299949824, query id 777462590 172.31.66.142 dbworkerfactorysecure Sending data

INSERT INTO ****

Trx read view will not see trx with id >= 17462603853, sees < 17462603853

---TRANSACTION 422120853273800, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853269544, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853265288, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853261032, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853167400, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853256776, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853252520, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853248264, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853244008, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853239752, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853235496, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853231240, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853226984, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853222728, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853218472, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853214216, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853209960, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853205704, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853201448, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853197192, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853192936, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853188680, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853184424, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853180168, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853175912, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853171656, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853163144, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853158888, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853154632, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853150376, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853146120, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853141864, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853137608, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853133352, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853129096, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853124840, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853120584, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853116328, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853112072, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853107816, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853103560, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853099304, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853095048, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 422120853090792, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 17462604858, ACTIVE 220 sec inserting

mysql tables in use 1, locked 1

3 lock struct(s), heap size 1128, 1 row lock(s), undo log entries 1

MySQL thread id 10, OS thread handle 140646178735872, query id 777865730

---TRANSACTION 422120853082280, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

--------

FILE I/O

--------

I/O thread 0 state: waiting for completed aio requests (insert buffer thread)

I/O thread 1 state: waiting for completed aio requests (log thread)

I/O thread 2 state: waiting for completed aio requests (read thread)

I/O thread 3 state: waiting for completed aio requests (read thread)

I/O thread 4 state: waiting for completed aio requests (read thread)

I/O thread 5 state: waiting for completed aio requests (read thread)

I/O thread 6 state: waiting for completed aio requests (write thread)

I/O thread 7 state: waiting for completed aio requests (write thread)

I/O thread 8 state: waiting for completed aio requests (write thread)

I/O thread 9 state: waiting for completed aio requests (write thread)

Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 0, 0, 0] ,

 ibuf aio reads:, log i/o's:, sync i/o's:

Pending flushes (fsync) log: 0; buffer pool: 0

24188890 OS file reads, 29232470 OS file writes, 4530146 OS fsyncs

0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s

-------------------------------------

INSERT BUFFER AND ADAPTIVE HASH INDEX

-------------------------------------

Ibuf: size 1, free list len 209942, seg size 209944, 1509741 merges

merged operations:

 insert 3862925, delete mark 11675526, delete 1201855

discarded operations:

 insert 0, delete mark 0, delete 0

Hash table size 5843809, node heap has 3791 buffer(s)

Hash table size 5843809, node heap has 5577 buffer(s)

Hash table size 5843809, node heap has 3297 buffer(s)

Hash table size 5843809, node heap has 5687 buffer(s)

Hash table size 5843809, node heap has 3953 buffer(s)

Hash table size 5843809, node heap has 7772 buffer(s)

Hash table size 5843809, node heap has 18181 buffer(s)

Hash table size 5843809, node heap has 10925 buffer(s)

7.32 hash searches/s, 2.65 non-hash searches/s

---

LOG

---

Log sequence number 102422876480104

Log flushed up to   102422876480104

Pages flushed up to 102422800703925

Last checkpoint at  102422800703925

0 pending log flushes, 0 pending chkp writes

1642503 log i/o's done, 0.00 log i/o's/second

----------------------

BUFFER POOL AND MEMORY

----------------------

Total large memory allocated 23655874560

Dictionary memory allocated 4009296

Buffer pool size   1412752

Free buffers       4632

Database pages     1348936

Old database pages 497782

Modified db pages  5220

Percent of dirty pages(LRU & free pages): 0.386

Max dirty pages percent: 75.000

Pending reads 0

Pending writes: LRU 0, flush list 2, single page 0

Pages made young 12285071, not young 736294742

0.00 youngs/s, 0.00 non-youngs/s

Pages read 24091045, created 6416261, written 26204033

0.00 reads/s, 0.00 creates/s, 0.00 writes/s

Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000

Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s

LRU len: 1348936, unzip_LRU len: 0

I/O sum[0]:cur[0], unzip sum[0]:cur[0]

----------------------

INDIVIDUAL BUFFER POOL INFO

----------------------

---BUFFER POOL 0

Buffer pool size   176594

Free buffers       575

Database pages     168645

Old database pages 62233

Modified db pages  825

Percent of dirty pages(LRU & free pages): 0.488

Max dirty pages percent: 75.000

Pending reads 0

Pending writes: LRU 0, flush list 0, single page 0

Pages made young 1530158, not young 89652355

0.00 youngs/s, 0.00 non-youngs/s

Pages read 3000704, created 820651, written 4459033

0.00 reads/s, 0.00 creates/s, 0.00 writes/s

Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000

Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s

LRU len: 168645, unzip_LRU len: 0

I/O sum[0]:cur[0], unzip sum[0]:cur[0]

---BUFFER POOL 1

Buffer pool size   176594

Free buffers       546

Database pages     168545

Old database pages 62196

Modified db pages  661

Percent of dirty pages(LRU & free pages): 0.391

Max dirty pages percent: 75.000

Pending reads 0

Pending writes: LRU 0, flush list 0, single page 0

Pages made young 1548223, not young 93971088

0.00 youngs/s, 0.00 non-youngs/s

Pages read 3064144, created 797585, written 2957721

0.00 reads/s, 0.00 creates/s, 0.00 writes/s

Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000

Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s

LRU len: 168545, unzip_LRU len: 0

I/O sum[0]:cur[0], unzip sum[0]:cur[0]

---BUFFER POOL 2

Buffer pool size   176594

Free buffers       621

Database pages     168578

Old database pages 62208

Modified db pages  608

Percent of dirty pages(LRU & free pages): 0.359

Max dirty pages percent: 75.000

Pending reads 0

Pending writes: LRU 0, flush list 0, single page 0

Pages made young 1553285, not young 91180805

0.00 youngs/s, 0.00 non-youngs/s

Pages read 3023249, created 801831, written 2881988

0.00 reads/s, 0.00 creates/s, 0.00 writes/s

Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000

Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s

LRU len: 168578, unzip_LRU len: 0

I/O sum[0]:cur[0], unzip sum[0]:cur[0]

---BUFFER POOL 3

Buffer pool size   176594

Free buffers       623

Database pages     168501

Old database pages 62180

Modified db pages  621

Percent of dirty pages(LRU & free pages): 0.367

Max dirty pages percent: 75.000

Pending reads 0

Pending writes: LRU 0, flush list 0, single page 0

Pages made young 1544401, not young 92782155

0.00 youngs/s, 0.00 non-youngs/s

Pages read 3055426, created 798407, written 3548916

0.00 reads/s, 0.00 creates/s, 0.00 writes/s

Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000

Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s

LRU len: 168501, unzip_LRU len: 0

I/O sum[0]:cur[0], unzip sum[0]:cur[0]

---BUFFER POOL 4

Buffer pool size   176594

Free buffers       570

Database pages     168653

Old database pages 62236

Modified db pages  605

Percent of dirty pages(LRU & free pages): 0.358

Max dirty pages percent: 75.000

Pending reads 0

Pending writes: LRU 0, flush list 0, single page 0

Pages made young 1530555, not young 93768585

0.00 youngs/s, 0.00 non-youngs/s

Pages read 3023945, created 798087, written 3336562

0.00 reads/s, 0.00 creates/s, 0.00 writes/s

Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000

Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s

LRU len: 168653, unzip_LRU len: 0

I/O sum[0]:cur[0], unzip sum[0]:cur[0]

---BUFFER POOL 5

Buffer pool size   176594

Free buffers       530

Database pages     168808

Old database pages 62293

Modified db pages  641

Percent of dirty pages(LRU & free pages): 0.379

Max dirty pages percent: 75.000

Pending reads 0

Pending writes: LRU 0, flush list 2, single page 0

Pages made young 1547158, not young 91440491

0.00 youngs/s, 0.00 non-youngs/s

Pages read 2993753, created 800748, written 2959769

0.00 reads/s, 0.00 creates/s, 0.00 writes/s

Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000

Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s

LRU len: 168808, unzip_LRU len: 0

I/O sum[0]:cur[0], unzip sum[0]:cur[0]

---BUFFER POOL 6

Buffer pool size   176594

Free buffers       537

Database pages     168617

Old database pages 62223

Modified db pages  636

Percent of dirty pages(LRU & free pages): 0.376

Max dirty pages percent: 75.000

Pending reads 0

Pending writes: LRU 0, flush list 0, single page 0

Pages made young 1514961, not young 89712669

0.00 youngs/s, 0.00 non-youngs/s

Pages read 2978655, created 800363, written 2979454

0.00 reads/s, 0.00 creates/s, 0.00 writes/s

Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000

Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s

LRU len: 168617, unzip_LRU len: 0

I/O sum[0]:cur[0], unzip sum[0]:cur[0]

---BUFFER POOL 7

Buffer pool size   176594

Free buffers       630

Database pages     168589

Old database pages 62213

Modified db pages  623

Percent of dirty pages(LRU & free pages): 0.368

Max dirty pages percent: 75.000

Pending reads 0

Pending writes: LRU 0, flush list 0, single page 0

Pages made young 1516330, not young 93786594

0.00 youngs/s, 0.00 non-youngs/s

Pages read 2951169, created 798589, written 3080590

0.00 reads/s, 0.00 creates/s, 0.00 writes/s

Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000

Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s

LRU len: 168589, unzip_LRU len: 0

I/O sum[0]:cur[0], unzip sum[0]:cur[0]

--------------

ROW OPERATIONS

--------------

0 queries inside InnoDB, 0 queries in queue

2 read views open inside InnoDB

Process ID=2563, Main thread ID=140620421134080, state: sleeping

Number of rows inserted 291442737, updated 43530027, deleted 16560971, read 18102275991

0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 21.62 reads/s

Number of system rows inserted 839287, updated 0, deleted 839231, read 839237

0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s

----------------------------

END OF INNODB MONITOR OUTPUT

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