[MDEV-14776] InnoDB Monitor output generated by specific error is flooding error logs Created: 2017-12-26  Updated: 2020-08-25  Resolved: 2018-01-09

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB, Storage Engine - XtraDB
Affects Version/s: 10.1
Fix Version/s: 10.1.31

Type: Bug Priority: Critical
Reporter: Chris Calender (Inactive) Assignee: Jan Lindström (Inactive)
Resolution: Fixed Votes: 0
Labels: None

Issue Links:
Duplicate
duplicates MDEV-12327 InnoDB status monitor gets enabled af... Closed
duplicates MDEV-12557 INNODB MONITOR OUTPUT write every min... Closed
Relates
relates to MDEV-11215 Several locks taken to same record in... Stalled
relates to MDEV-16339 Upgrading to 10.1.32 shows innodb_emp... Closed
relates to MDEV-16617 After upgrading from 5.5.52 to 10.1.3... Closed

 Description   

We've ran into an unusual case where InnoDB Monitor output is flooding the error logs, and eventually leading to disk space issues.

Apparently these cases where the InnoDB Monitor was turned on was triggered by this kind of error message:

2017-12-19 23:38:26 7f5f729fc700 InnoDB: Warning: difficult to find free blocks in
 
InnoDB: the buffer pool (338 search iterations)!
 
InnoDB: 0 failed attempts to flush a page! Consider
 
InnoDB: increasing the buffer pool size.
 
InnoDB: It is also possible that in your Unix version
 
InnoDB: fsync is very slow, or completely frozen inside
 
InnoDB: the OS kernel. Then upgrading to a newer version
 
InnoDB: of your operating system may help. Look at the
 
InnoDB: number of fsyncs in diagnostic info below.
 
InnoDB: Pending flushes (fsync) log: 0; buffer pool: 0
 
InnoDB: 105756 OS file reads, 62064 OS file writes, 16768 OS fsyncs
 
InnoDB: Starting InnoDB Monitor to print further
 
InnoDB: diagnostics to the standard output.

Once this occurs, innodb monitor seems to get switched on permanently here, and there does not seem to be a way to stop it that point.

A restart seems to "fix" it temporarily.

Also, explicitly setting innodb_status_output to OFF seems to prevent it (after a restart).

Unlike with long semaphore waits monitor output is enabled permanently here, not just for 30s like with long semaphore waits?

What exactly should we look for in the generated monitor output to track down the root cause?

 Comments   
Comment by Elena Stepanova [ 2017-12-26 ]

We already had some complaints about the monitor: MDEV-12557, MDEV-12327. Assigning to jplindst to decide what should be done about this.

Comment by Jan Lindström (Inactive) [ 2018-01-08 ]

https://github.com/MariaDB/server/commit/5ce916ddfcbc9b99f271465d813f595c0e6c5144

Comment by Jan Lindström (Inactive) [ 2018-01-09 ]

commit 07aa98597984391a6e8c85f634106aef4b096a24
Author: Jan Lindström <jan.lindstrom@mariadb.com>
Date: Tue Jan 9 12:37:58 2018 +0200

MDEV-14776: InnoDB Monitor output generated by specific error is flooding error logs

innodb/buf_LRU_get_free_block
Add debug instrumentation to produce error message about
no free pages. Print error message only once and do not
enable innodb monitor.

xtradb/buf_LRU_get_free_block
Add debug instrumentation to produce error message about
no free pages. Print error message only once and do not
enable innodb monitor. Remove code that does not seem to
be used.

innodb-lru-force-no-free-page.test
New test case to force produce desired error message.

Generated at Thu Feb 08 08:16:11 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.