数据库开启慢查询和非索引查询后。发现太多的慢日志和未经过索引的查询

[hd900415]

现象

数据库开启了慢查询和非索引查询日志
SET GLOBAL slow_query_log = 'ON';
SET GLOBAL log_queries_not_using_indexes = 'ON';
发现数据库经常死锁。
以及慢查询有时会达到30S+

日志

mysql> SHOW ENGINE INNODB STATUS\G;
*************************** 1. row ***************************
Type: InnoDB
Name:
Status:

2024-08-05 13:54:53 140201741391424 INNODB MONITOR OUTPUT

Per second averages calculated from the last 6 seconds

BACKGROUND THREAD

srv_master_thread loops: 140860 srv_active, 0 srv_shutdown, 6963 srv_idle
srv_master_thread log flush and writes: 0

SEMAPHORES

OS WAIT ARRAY INFO: reservation count 143559707
OS WAIT ARRAY INFO: signal count 109988462
RW-shared spins 0, rounds 0, OS waits 0
RW-excl spins 0, rounds 0, OS waits 0
RW-sx spins 0, rounds 0, OS waits 0
Spin rounds per wait: 0.00 RW-shared, 0.00 RW-excl, 0.00 RW-sx

LATEST DETECTED DEADLOCK

2024-08-05 13:54:23 140203089032768
*** (1) TRANSACTION:
TRANSACTION 105448546, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 6 lock struct(s), heap size 1128, 5 row lock(s), undo log entries 1
MySQL thread id 1091254, OS thread handle 140201747740224, query id 97813683 ip-172-31-22-181.ap-east-1.compute.internal 172.31.22.181 root update
INSERT INTO message_extra (clone_no,message_id,message_seq,from_uid,channel_id,channel_type,readed_count,version) VALUES ('','1820337455270723584',791,'7ba353c77b8148e080e05aa331e361df','a655eee56d034ba0bcfdd53efe69875c',2,4,1073612) ON DUPLICATE KEY UPDATE clone_no=IF(clone_no='',VALUES(clone_no),clone_no),readed_count=VALUES(readed_count),version=VALUES(version)

*** (1) HOLDS THE LOCK(S):
RECORD LOCKS space id 245 page no 36928 n bits 88 index PRIMARY of table changyan.message_extra trx id 105448546 lock_mode X
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
0: len 8; hex 73757072656d756d; asc supremum;;

*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 245 page no 36928 n bits 88 index PRIMARY of table changyan.message_extra trx id 105448546 lock_mode X insert intention waiting
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
0: len 8; hex 73757072656d756d; asc supremum;;

*** (2) TRANSACTION:
TRANSACTION 105448545, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 7 lock struct(s), heap size 1128, 5 row lock(s), undo log entries 1
MySQL thread id 1091267, OS thread handle 140201750898240, query id 97813684 ip-172-31-22-181.ap-east-1.compute.internal 172.31.22.181 root update
INSERT INTO message_extra (clone_no,message_id,message_seq,from_uid,channel_id,channel_type,readed_count,version) VALUES ('','1820270282993041408',5496,'591e0e487f4e40659798b651bb727b4a','4d981eef992742988cbb9852815a6dba',2,129,2354156) ON DUPLICATE KEY UPDATE clone_no=IF(clone_no='',VALUES(clone_no),clone_no),readed_count=VALUES(readed_count),version=VALUES(version)

*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 245 page no 36928 n bits 88 index PRIMARY of table changyan.message_extra trx id 105448545 lock_mode X
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
0: len 8; hex 73757072656d756d; asc supremum;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 245 page no 36928 n bits 88 index PRIMARY of table changyan.message_extra trx id 105448545 lock_mode X insert intention waiting
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
0: len 8; hex 73757072656d756d; asc supremum;;

*** WE ROLL BACK TRANSACTION (1)

TRANSACTIONS

Trx id counter 105450974
Purge done for trx's n:o < 105450955 undo n:o < 0 state: running but idle
History list length 24
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 421678525334200, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421678525332584, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421678525331776, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421678525329352, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421678525324504, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421678525330968, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421678525328544, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421678525327736, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421678525326928, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421678525326120, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421678525330160, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421678525323696, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421678525322888, 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 ((null))
I/O thread 1 state: waiting for completed aio requests (insert buffer 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)
Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 0, 0, 0] ,
ibuf aio reads:
Pending flushes (fsync) log: 0; buffer pool: 0
1978731037 OS file reads, 91979944 OS file writes, 64681346 OS fsyncs
7612.83 reads/s, 16384 avg bytes/read, 425.73 writes/s, 295.35 fsyncs/s

INSERT BUFFER AND ADAPTIVE HASH INDEX

Ibuf: size 1, free list len 3093, seg size 3095, 1867928 merges
merged operations:
insert 6664578, delete mark 310693, delete 23317
discarded operations:
insert 0, delete mark 0, delete 0
Hash table size 34679, node heap has 60 buffer(s)
Hash table size 34679, node heap has 5 buffer(s)
Hash table size 34679, node heap has 43 buffer(s)
Hash table size 34679, node heap has 78 buffer(s)
Hash table size 34679, node heap has 73 buffer(s)
Hash table size 34679, node heap has 124 buffer(s)
Hash table size 34679, node heap has 1 buffer(s)
Hash table size 34679, node heap has 171 buffer(s)
7711.21 hash searches/s, 22043.99 non-hash searches/s

LOG

Log sequence number 142460469975
Log buffer assigned up to 142460469975
Log buffer completed up to 142460469975
Log written up to 142460469975
Log flushed up to 142460469975
Added dirty pages up to 142460469975
Pages flushed up to 142454810773
Last checkpoint at 142454767916
Log minimum file id is 43492
Log maximum file id is 43502
35761159 log i/o's done, 184.83 log i/o's/second

BUFFER POOL AND MEMORY

Total large memory allocated 0
Dictionary memory allocated 1285469
Buffer pool size 8192
Free buffers 0
Database pages 7637
Old database pages 2804
Modified db pages 580
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 14586500, not young 19277610693
29.29 youngs/s, 44025.45 non-youngs/s
Pages read 1978751559, created 1323088, written 36833205
7612.83 reads/s, 0.97 creates/s, 170.45 writes/s
Buffer pool hit rate 934 / 1000, young-making rate 0 / 1000 not 385 / 1000
Pages read ahead 395.95/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 7637, unzip_LRU len: 0
I/O sum[517793]:cur[4431], unzip sum[0]:cur[0]

ROW OPERATIONS

0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
Process ID=157061, Main thread ID=140203055461952 , state=sleeping
Number of rows inserted 61166740, updated 14062104, deleted 146, read 29545219397
21.33 inserts/s, 92.15 updates/s, 0.00 deletes/s, 113296.78 reads/s
Number of system rows inserted 8, updated 331, deleted 8, read 8711
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s

END OF INNODB MONITOR OUTPUT

1 row in set (0.00 sec)

ERROR:
No query specified




这个是日常的在线用户数。高峰期，是三倍。数据库经常死亡。造成死锁。用户无法访问。