MySQL Bugs: #72137: inaccurate handling of srv_activity

Bug #72137	inaccurate handling of srv_activity_count
Submitted:	26 Mar 2014 21:32	Modified:	19 Aug 2014 14:26
Reporter:	Inaam Rana (OCA)	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: InnoDB storage engine	Severity:	S3 (Non-critical)
Version:	5.6	OS:	Any
Assigned to:		CPU Architecture:	Any

Description:
This is related to bug#71988 but is about different code.

srv_acitivity_count keeps track whether server is idle or busy. From handler/ha_innodb.cc:

  230 /* The following counter is used to convey information to InnoDB
  231 about server activity: in selects it is not sensible to call
  232 srv_active_wake_master_thread after each fetch or search, we only do
  233 it every INNOBASE_WAKE_INTERVAL'th step. */
  234 
  235 #define INNOBASE_WAKE_INTERVAL  32
  236 static ulong    innobase_active_counter = 0;

 1338 /********************************************************************//**
 1339 Increments innobase_active_counter and every INNOBASE_WAKE_INTERVALth
 1340 time calls srv_active_wake_master_thread. This function should be used
 1341 when a single database operation may introduce a small need for
 1342 server utility activity, like checkpointing. */
 1343 static inline
 1344 void
 1345 innobase_active_small(void)
 1346 /*=======================*/
 1347 {
 1348         innobase_active_counter++;
 1349 
 1350         if ((innobase_active_counter % INNOBASE_WAKE_INTERVAL) == 0) {
 1351                 srv_active_wake_master_thread();
 1352         }
 1353 }

The comment at line 230 is not correct because we use this counter to tell server about DML (write_row, update_row, delete_row) and not SELECTs.

But we also call srv_active_wake_master_thread() directly and one of the places is innobase_commit (and prepare as well). This call not only wakes up the master thread but also increments the srv_activity_count which tells the page_cleaner that server is not idle.

The problem is that innobase_commit() is in the code path of autocommiting selects as well. It appears that the intention of the code was that we don't consider selects as kind of activity which triggers any background utility thread work. But by putting this call to srv_active_wake_master_thread() in innobase_commit() we make all selects count as activity.

So why is this bad? First we wake up master thread when there is really no need to do so (and that also on each select). Secondly, because we increment srv_activity_count we'll make page_cleaner think that there is DML work happening forcing it to stay in adaptive flushing loop instead of switching to the background idle flushing loop.

How to repeat:
Have a simple select in tight with auto commit.
Have DML workload that increases the number of dirty pages significantly. Note that the adaptive flushing has kicked in.
Terminate the DML workload. Keep the selects going in tight loop. Now because no new dirty pages are generated and LSN is not moving therefore adaptive flushing will go nill. That is expected behaviour. But because srv_activity_count is constantly being incremented because of innobase_commit() therefore the page_cleaner will think that the server is busy and won't do any background/idle flushing.
The result will be that number of dirty pages will stay where it is.

Suggested fix:
Do we really need to wake master thread in innobase_commit (innobase_prepare)? If not then we can get rid of these calls. If it is needed then perhaps do it only if the trx that is committing(preparing) is not a read only trx.

Thank you for the report.

Verified as described.

To repeat:

1. Start MTR as: ./mtr --start innodb &

2. Create Gypsy file:

i|1|drop table if exists t1
i|1|create table t1(f1 int not null auto_increment primary key, f2 varchar(255), f3 timestamp) engine=innodb
i|10000|insert into t1(f2) values(md5(?))|int
n|1000|select * from t1 where f1=?|int

3. Run it as gypsy --host=127.0.0.1:13000 --user=root --queryfile=bug72137_1.query --threads=50 --duration=1000 

4. Before 50 threads, doing select start, connect to MySQL server and measure number of dirty pages:

mysql> show status like 'innodb%dirty%';
+--------------------------------+---------+
| Variable_name                  | Value   |
+--------------------------------+---------+
| Innodb_buffer_pool_pages_dirty | 204     |
| Innodb_buffer_pool_bytes_dirty | 3342336 |
+--------------------------------+---------+
2 rows in set (0.03 sec)

5. Watch these numbers while SELECTs are running, notice numbers do not change.

6. Watch the numbers after SELECTs stop.

Uploading patch.

patch to fix activity count increment with selects

Attachment: srv_act_5.6.patch (application/octet-stream, text), 5.32 KiB.

Fixed as of the upcoming 5.6.21, 5.7.5 release, and here's the changelog entry:

"srv_active_wake_master_thread()" was called directly in
"innobase_commit" and "innobase_prepare", waking up the master thread and
incrementing "srv_activity_count". "srv_active_wake_master_thread()"
should only be called after committing write transactions, not after
read-only transactions or rollbacks. This patch also replaces some calls
to "srv_active_wake_master_thread()" with calls to
"ib_wake_master_thread()". 

Thank you for the bug report.

revno: 6119
committer: bin.x.su@oracle.com
branch nick: mysql-5.6
timestamp: Tue 2014-08-19 15:10:06 +0800
message:
  Bug#18477009 - INACCURATE HANDLING OF SRV_ACTIVITY_COUNT
  
  We call srv_active_wake_master_thread() directly and one of the places is
  innobase_commit (and prepare as well). This call not only wakes up the
  master thread but also increments the srv_activity_count which tells
  the page_cleaner that server is not idle. That's no what we expect.
  
  We should call srv_active_wake_master_thread() only after the commitment
  of a write trx, but not read-only trx, or after a rollback. This patch also
  changes some call of srv_active_wake_master_thread() to
  ib_wake_master_thread().
  
  Original patch is provided by Inaam.
  
  rb#5909, approved by Jimmy.