We recently upgraded (in-place) an Aurora MySQL 3.04.1 cluster to 3.05.2 (one writer, two reader instances, all db.t3.medium). That's a test system currently with very little load, the reader instances are not used by the application, they only serve as warm stand-by replicas.
Prior to the upgrade, the error logs were empty. After the upgrade, the writer instance's error log is still empty. However, the reader instances log INNODB MONITOR OUTPUT every 10 seconds on average. The innodb_status_output value is OFF. The issue persists after rebooting the readers, or after rebooting the writer, triggering a fail-over (now the new writer has an empty error log, while the previous writer, now reader, logs the innodb output).
Why is this happening, and is that a reason for concern?
The 8.0.29 release notes, referring to MySQL bug 93878 mention
Enabling and disabling of the standard monitor by InnoDB is now performed independently of the user-settable innodb_status_output variable.
and the bug description itself contains some reasons why this can happen, but from the example output below, I cannot understand what is wrong.
=====================================
2024-08-06 09:00:06 22665578403584 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 9 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 0 srv_active, 0 srv_shutdown, 0 srv_idle
srv_master_thread log flush and writes: 0
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 1648
OS WAIT ARRAY INFO: signal count 1648
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
------------
TRANSACTIONS
------------
Trx id counter 188252161
Purge done for trx's n:o < 0 undo n:o < 0 state: disabled
History list length 0
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 304140574008456, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 304140574007600, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 304140574009312, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 304140574010168, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 304140574006744, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request (read thread)
I/O thread 1 state: waiting for i/o request (write thread)
I/O thread 2 state: waiting for i/o request (write thread)
I/O thread 3 state: waiting for i/o request (write thread)
I/O thread 4 state: waiting for i/o request (write thread)
Pending normal aio reads: [0] , aio writes: [0, 0, 0, 0]
Pending flushes (fsync) log: 0; buffer pool: 0
0 OS file reads, 0 OS file writes, 0 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
0.00 hash searches/s, 4.67 non-hash searches/s
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 0
Dictionary memory allocated 3604320
Buffer pool size 95868
Free buffers 95281
Database pages 587
Old database pages 0
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 587, created 0, written 0
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: 587, 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 47934
Free buffers 47701
Database pages 233
Old database pages 0
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 233, created 0, written 0
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: 233, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 1
Buffer pool size 47934
Free buffers 47580
Database pages 354
Old database pages 0
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 354, created 0, written 0
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: 354, 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=0, Main thread ID=thread::id of a non-executing thread , state=
Number of rows inserted 0, updated 0, deleted 0, read 0
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
Number of system rows inserted 0, updated 0, deleted 0, read 453726436
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 5.00 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================
AWS公式更新しました 2年前
Thank you Vedanshi A, that was it! We use Percona Monitoring and Management with the metrics resolution set to "Standard", implying a sample every 10 seconds. When I change this to "Rare" (collecting every 180 seconds), an Innodb Monitor Log is appended every 180 seconds.
Interesting that those logs didn't show up with Aurora 3.04.1, but perhaps we have to upgrade PMM as well. In any event, that was the culprit. Thanks again!
(Edit on 2024-08-19: Originally (11 days ago) posted the above text mistakenly as answer, now deleted that and instead add it as comment.)