MySQL Bugs: #71670: InnoDB monitor output written every 20s, not every 15s as the manual says

Bug #71670	InnoDB monitor output written every 20s, not every 15s as the manual says
Submitted:	11 Feb 2014 12:46	Modified:	11 Feb 2014 15:31
Reporter:	Hartmut Holzgraefe	Email Updates:
Status:	Verified	Impact on me:	None
Category:	MySQL Server: InnoDB storage engine	Severity:	S3 (Non-critical)
Version:	5.5.30, 5.6.15	OS:	Any
Assigned to:		CPU Architecture:	Any

Description:
http://dev.mysql.com/doc/refman/5.6/en/innodb-monitors.html says:

"When switched on, InnoDB Monitors print data about every 15 seconds."

When checking the actual output the interval is every 20s, not every 15s though:

Looking at the code I can see that the monitoring thread sleeps in increments of 5 seconds (5000000 microseconds). If then checks whether more than 15 seconds have elapsed, with time_elapsed being calculated as integer value.

So unless the server is under pretty heavy load and actual time_elapsed rounds up to 16 seconds a fourth 5s interval goes by before time_elapsed becomes 20s and so >15s

How to repeat:
Check code in srv/srv0srv.cc:

        os_event_wait_time_low(srv_monitor_event, 5000000, sig_count);

        current_time = ut_time();

        time_elapsed = difftime(current_time, last_monitor_time);

        if (time_elapsed > 15) {

or simply enable the innodb_monitor and check generated timestamps

Suggested fix:
change

        if (time_elapsed > 15) {

to

        if (time_elapsed >= 15) {

While this is mostly a cosmetic issue it becomes more "interesting" when monitoring becomes auto-enabled, e.g. due to long semaphore waits:

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

Here a true 15s sample interval would cause to monitor output snapshots being written, but with 20s intervals there is only one output event triggered within
the 30s interval instead of two ...

Indeed, Hartmut's calculus is truly correct. If we are checking for the elapsed time that is greater then 15 seconds, and it it incremented in 5 seconds units, then the output is written every 20 seconds.

It remains to be decided whether to change code or documentation.