[Warning] InnoDB A long semaphore wait

2020-06-29T23:04:20.245804+08:00 0 [Warning] InnoDB: A long semaphore wait:

--Thread 140585006524160 has waited at trx0purge.cc line 154 for 241 seconds the semaphore:

Mutex at 0x37045c0, Mutex REDO_RSEG created trx0rseg.cc:211, lock var 1

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

InnoDB: Pending preads 0, pwrites 0

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

2020-06-29 23:04:22 0x7fdc84a6e700 INNODB MONITOR OUTPUT

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

Per second averages calculated from the last 48 seconds

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

BACKGROUND THREAD

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

srv_master_thread loops: 15472 srv_active, 0 srv_shutdown, 67992 srv_idle

srv_master_thread log flush and writes: 83464

----------

SEMAPHORES

----------

OS WAIT ARRAY INFO: reservation count 15143

--Thread 140585128785664 has waited at buf0flu.cc line 1209 for 237 seconds the semaphore:

SX-lock on RW-latch at 0x7fdb1fbe3f80 created in file buf0buf.cc line 1460

a writer (thread id 140584786024192) has reserved it in mode SX

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

Last time read locked in file row0sel.cc line 3758

Last time write locked in file /export/home/pb2/build/sb_0-34537258-1560179931.8/mysql-5.7.27/storage/innobase/fsp/fsp0fsp.cc line 167

--Thread 140585006524160 has waited at trx0purge.cc line 154 for 243 seconds the semaphore:

Mutex at 0x37045c0, Mutex REDO_RSEG created trx0rseg.cc:211, lock var 1

OS WAIT ARRAY INFO: signal count 18821

RW-shared spins 0, rounds 19214, OS waits 6858

RW-excl spins 0, rounds 28090, OS waits 790

RW-sx spins 746, rounds 4563, OS waits 41

Spin rounds per wait: 19214.00 RW-shared, 28090.00 RW-excl, 6.12 RW-sx

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

TRANSACTIONS

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

Trx id counter 66764403

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

History list length 47

LIST OF TRANSACTIONS FOR EACH SESSION:

---TRANSACTION 66764401, ACTIVE (PREPARED) 243 sec committing

mysql tables in use 1, locked 1

913 lock struct(s), heap size 139472, 3064 row lock(s), undo log entries 1532

MySQL thread id 182762, OS thread handle 140584794011392, query id 12450329 192.158.58.248 sgajzdry query end

DELETE FROM v_yellow_person WHERE id_card IN ( '413026xxxxxx' , '140222xxxxxx' , '510823xxxxxx' , '3621321xxxxxx' , '330381198xxxxxx' , '1402221xxxxxx' , '1401021xxxxxx' , '412723xxxxxx' , '210112xxxxxx' , '21122419xxxxxx' , '13063319xxxxxx' , '4112221xxxxxx' , 

---TRANSACTION 66764359, ACTIVE 369 sec inserting

mysql tables in use 1, locked 1

1 lock struct(s), heap size 1136, 0 row lock(s), undo log entries 988242

MySQL thread id 182481, OS thread handle 140584786024192, query id 12446519 192.166.162.242 sgajzdry update

INSERT INTO `nuclein_result` VALUES (0, '130434xxxxxx', 'xxx', '2020-06-18', '北京核子华曦医学检测实验室', '阴性', NULL, NULL, NULL, NULL, NULL, '2020-06-27 00:00:00')

--------

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

1143654 OS file reads, 415098 OS file writes, 176831 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 1556, seg size 1558, 505 merges

merged operations:

insert 3400, delete mark 34283, delete 0

discarded operations:

insert 0, delete mark 0, delete 0

Hash table size 138389, node heap has 4 buffer(s)

Hash table size 138389, node heap has 33 buffer(s)

Hash table size 138389, node heap has 1 buffer(s)

Hash table size 138389, node heap has 0 buffer(s)

Hash table size 138389, node heap has 2 buffer(s)

Hash table size 138389, node heap has 7 buffer(s)

Hash table size 138389, node heap has 1 buffer(s)

Hash table size 138389, node heap has 3 buffer(s)

0.00 hash searches/s, 0.00 non-hash searches/s

---

LOG

---

Log sequence number 190313177636

Log flushed up to 190313177636

Pages flushed up to 190286367265

Last checkpoint at 190286367265

0 pending log flushes, 0 pending chkp writes

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

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

BUFFER POOL AND MEMORY

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

Total large memory allocated 549715968

Dictionary memory allocated 556818

Buffer pool size 32767

Free buffers 1024

Database pages 31684

Old database pages 11675

Modified db pages 3711

Pending reads 0

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

Pages made young 217059, not young 44586700

0.00 youngs/s, 0.00 non-youngs/s

Pages read 1143553, created 75542, written 264028

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

No buffer pool page gets since the last printout

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

LRU len: 31684, 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

0 read views open inside InnoDB

Process ID=84906, Main thread ID=140585017014016, state: sleeping

Number of rows inserted 11108786, updated 0, deleted 190625, read 426136154

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

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

END OF INNODB MONITOR OUTPUT

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

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

重点：InnoDB A long semaphore wait

故障场景：开发导入大量数据，中途卡主无法进行，连接不上服务。

解决办法：

原来linux内核信号量默认设置太小，造成大量等待， 

默认 cat /proc/sys/kernel/sem

250     32000   32      128

第一列：表示每个信号集中的最大信号量数目。

第二列：表示系统范围内的最大信号量总数目。

第三列：表示每个信号发生时的最大系统操作数目。

第四列：表示系统范围内的最大信号集数目。

将第三列调大一点，参考网上的数据

echo "kernel.sem=250 32000 100 128" >> /etc/sysctl.conf 

然后sysctl -p 

重启mysql

错误不再出现，问题即可解决