How can I slove the log InnoDB: page_cleaner: 1000ms intended loop took 4604ms?

by fengzhao   Last Updated September 12, 2019 02:26 AM

There are many "2019-09-12T10:02:01.290295+08:00 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 4499ms. The settings might not be optimal. (flushed=431 and evicted=161, during the time.)" in my MySQL log and my query is very slow , I search on the stackoverflow , and adjust the innodb_lru_scan_depth from '1024' to '256' , but it doesn't matter .
I am not sure if it is a disk performance problem ?

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

2019-09-12 10:20:46 0x7fe3b5513700 INNODB MONITOR OUTPUT

Per second averages calculated from the last 57 seconds

BACKGROUND THREAD

srv_master_thread loops: 42172 srv_active, 0 srv_shutdown, 56 srv_idle

srv_master_thread log flush and writes: 42228

SEMAPHORES

OS WAIT ARRAY INFO: reservation count 4214007 --Thread 140615978735360 has waited at btr0sea.ic line 90 for 0.00 seconds the semaphore: X-lock on RW-latch at 0x5723bf98 created in file btr0sea.cc line 195 a writer (thread id 140615283693312) has reserved it in mode exclusive number of readers 0, waiters flag 1, lock_word: 0 Last time read locked in file btr0sea.ic line 128 Last time write locked in file /export/home/pb2/build/sb_0-33648028-1555164244.06/mysql-5.7.26/storage/innobase/btr/btr0sea.cc line 1300 --Thread 140615258515200 has waited at btr0sea.cc line 1300 for 0.00 seconds the semaphore: X-lock on RW-latch at 0x5723bf98 created in file btr0sea.cc line 195 a writer (thread id 140615283693312) has reserved it in mode exclusive number of readers 0, waiters flag 1, lock_word: 0 Last time read locked in file btr0sea.ic line 128 Last time write locked in file /export/home/pb2/build/sb_0-33648028-1555164244.06/mysql-5.7.26/storage/innobase/btr/btr0sea.cc line 1300 OS WAIT ARRAY INFO: signal count 49120925 RW-shared spins 0, rounds 15491658, OS waits 854774 RW-excl spins 0, rounds 81394698, OS waits 1357368 RW-sx spins 558294, rounds 3897462, OS waits 30879 Spin rounds per wait: 15491658.00 RW-shared, 81394698.00 RW-excl, 6.98 RW-sx


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: 1 18329554 OS file reads, 7623277 OS file writes, 1006307 OS fsyncs 3 pending preads, 0 pending pwrites

148.96 reads/s, 16384 avg bytes/read, 110.28 writes/s, 13.79 fsyncs/s

INSERT BUFFER AND ADAPTIVE HASH INDEX

Ibuf: size 122499, free list len 537561, seg size 660061, 1474228 merges merged operations: insert 14136401, delete mark 11522266, delete 6639920 discarded operations: insert 0, delete mark 0, delete 0 Hash table size 13279583, node heap has 16609 buffer(s) Hash table size 13279583, node heap has 119679 buffer(s) Hash table size 13279583, node heap has 3817 buffer(s) Hash table size 13279583, node heap has 74778 buffer(s) Hash table size 13279583, node heap has 5174 buffer(s) Hash table size 13279583, node heap has 11518 buffer(s) Hash table size 13279583, node heap has 17680 buffer(s) Hash table size 13279583, node heap has 1165 buffer(s)

323159.94 hash searches/s, 23726.18 non-hash searches/s

LOG

Log sequence number 182570962657077 Log flushed up to 182570962203699 Pages flushed up to 182565227988600 Last checkpoint at 182565227412889 0 pending log flushes, 0 pending chkp writes

790639 log i/o's done, 26.84 log i/o's/second

BUFFER POOL AND MEMORY

Total large memory allocated 54971596800 Dictionary memory allocated 18245442 Buffer pool size 3276400 Free buffers 1639 Database pages 3015758 Old database pages 1113233 Modified db pages 387306 Pending reads 3 Pending writes: LRU 9, flush list 45, single page 0 Pages made young 4384259, not young 948589363 19.00 youngs/s, 3191.28 non-youngs/s Pages read 18067596, created 4577082, written 6596647 148.93 reads/s, 25.67 creates/s, 77.54 writes/s Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 1 / 1000 Pages read ahead 8.98/s, evicted without access 0.00/s, Random read ahead 0.00/s LRU len: 3015758, unzip_LRU len: 10

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

INDIVIDUAL BUFFER POOL INFO

---BUFFER POOL 0 Buffer pool size 409550 Free buffers 251 Database pages 377032 Old database pages 139160 Modified db pages 66829 Pending reads 0 Pending writes: LRU 7, flush list 0, single page 0 Pages made young 554461, not young 117830801 2.70 youngs/s, 726.83 non-youngs/s Pages read 2272372, created 598623, written 847426 17.74 reads/s, 5.40 creates/s, 9.16 writes/s Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 3 / 1000 Pages read ahead 2.25/s, evicted without access 0.00/s, Random read ahead 0.00/s LRU len: 377032, unzip_LRU len: 0 I/O sum[9790]:cur[68], unzip sum[0]:cur[0] ---BUFFER POOL 1 Buffer pool size 409550 Free buffers 174 Database pages 376978 Old database pages 139177 Modified db pages 46437 Pending reads 1 Pending writes: LRU 0, flush list 0, single page 0 Pages made young 552002, not young 118212494 3.16 youngs/s, 939.21 non-youngs/s Pages read 2252309, created 573620, written 824715 21.91 reads/s, 2.37 creates/s, 10.46 writes/s Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 3 / 1000 Pages read ahead 2.25/s, evicted without access 0.00/s, Random read ahead 0.00/s LRU len: 376978, unzip_LRU len: 2 I/O sum[9790]:cur[68], unzip sum[0]:cur[0] ---BUFFER POOL 2 Buffer pool size 409550 Free buffers 234 Database pages 376859 Old database pages 139104 Modified db pages 45706 Pending reads 0 Pending writes: LRU 0, flush list 11, single page 0 Pages made young 543989, not young 118808465 2.09 youngs/s, 33.96 non-youngs/s Pages read 2260832, created 584995, written 820268 17.91 reads/s, 3.32 creates/s, 7.53 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: 376859, unzip_LRU len: 2 I/O sum[9790]:cur[68], unzip sum[0]:cur[0] ---BUFFER POOL 3 Buffer pool size 409550 Free buffers 256 Database pages 377038 Old database pages 139173 Modified db pages 46510 Pending reads 0 Pending writes: LRU 0, flush list 11, single page 0 Pages made young 548950, not young 118407647 2.47 youngs/s, 457.99 non-youngs/s Pages read 2261728, created 570069, written 834081 18.28 reads/s, 4.05 creates/s, 10.23 writes/s Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 2 / 1000 Pages read ahead 1.12/s, evicted without access 0.00/s, Random read ahead 0.00/s LRU len: 377038, unzip_LRU len: 2 I/O sum[9790]:cur[68], unzip sum[0]:cur[0] ---BUFFER POOL 4 Buffer pool size 409550 Free buffers 199 Database pages 376920 Old database pages 139136 Modified db pages 45194 Pending reads 1 Pending writes: LRU 0, flush list 13, single page 0 Pages made young 541833, not young 117472699 2.04 youngs/s, 87.45 non-youngs/s Pages read 2251926, created 571700, written 817782 17.25 reads/s, 3.23 creates/s, 9.93 writes/s Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000 Pages read ahead 1.12/s, evicted without access 0.00/s, Random read ahead 0.00/s LRU len: 376920, unzip_LRU len: 0 I/O sum[9790]:cur[68], unzip sum[0]:cur[0] ---BUFFER POOL 5 Buffer pool size 409550 Free buffers 214 Database pages 376981 Old database pages 139165 Modified db pages 46211 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages made young 545556, not young 120462711 2.26 youngs/s, 314.35 non-youngs/s Pages read 2256728, created 555736, written 814774 17.91 reads/s, 2.56 creates/s, 9.67 writes/s Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000 Pages read ahead 1.12/s, evicted without access 0.00/s, Random read ahead 0.00/s LRU len: 376981, unzip_LRU len: 2 I/O sum[9790]:cur[68], unzip sum[0]:cur[0] ---BUFFER POOL 6 Buffer pool size 409550 Free buffers 211 Database pages 376865 Old database pages 139123 Modified db pages 45485 Pending reads 0 Pending writes: LRU 0, flush list 10, single page 0 Pages made young 545930, not young 117127396 2.04 youngs/s, 409.98 non-youngs/s Pages read 2245897, created 555453, written 813372 18.70 reads/s, 2.37 creates/s, 11.11 writes/s Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 2 / 1000 Pages read ahead 1.12/s, evicted without access 0.00/s, Random read ahead 0.00/s LRU len: 376865, unzip_LRU len: 2 I/O sum[9790]:cur[68], unzip sum[0]:cur[0] ---BUFFER POOL 7 Buffer pool size 409550 Free buffers 100 Database pages 377085 Old database pages 139195 Modified db pages 44934 Pending reads 1 Pending writes: LRU 2, flush list 0, single page 0 Pages made young 551538, not young 120267150 2.25 youngs/s, 221.50 non-youngs/s Pages read 2265804, created 566886, written 824229 19.23 reads/s, 2.37 creates/s, 9.47 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: 377085, unzip_LRU len: 0

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

ROW OPERATIONS

0 queries inside InnoDB, 0 queries in queue 2 read views open inside InnoDB Process ID=444920, Main thread ID=140616423962368, state: sleeping Number of rows inserted 320931029, updated 17666710, deleted 3125126, read 38234204684

856.70 inserts/s, 640.52 updates/s, 0.00 deletes/s, 3861931.28 reads/s

END OF INNODB MONITOR OUTPUT

Tags : mysql


Related Questions