Issue InnoDB: page_cleaner: 1000ms intended loop took ****ms

[Shark]

I have an issue. From mysql log (/var/log/mysql/error.log) a see the following notes:

2018-02-26T02:36:22.968979Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 100495ms. The settings might not be optimal. (flushed=10 and evicted=0, during the time.)
2018-02-26T07:53:09.480163Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 4679ms. The settings might not be optimal. (flushed=9 and evicted=0, during the time.)
2018-02-26T09:06:17.151791Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 28253ms. The settings might not be optimal. (flushed=10 and evicted=0, during the time.)
2018-02-26T09:16:25.843047Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 40637ms. The settings might not be optimal. (flushed=2 and evicted=0, during the time.)
2018-02-26T09:22:07.994275Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 79914ms. The settings might not be optimal. (flushed=3 and evicted=0, during the time.)
2018-02-26T09:28:30.971972Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 147862ms. The settings might not be optimal. (flushed=6 and evicted=0, during the time.)
2018-02-26T09:34:51.904685Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 102905ms. The settings might not be optimal. (flushed=2 and evicted=0, during the time.)
2018-02-26T09:35:20.671356Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 11724ms. The settings might not be optimal. (flushed=20 and evicted=0, during the time.)
2018-02-26T09:43:32.227162Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 20470ms. The settings might not be optimal. (flushed=31 and evicted=0, during the time.)
2018-02-26T09:52:12.216678Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 215956ms. The settings might not be optimal. (flushed=3 and evicted=0, during the time.)
2018-02-26T09:52:57.180148Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 20940ms. The settings might not be optimal. (flushed=3 and evicted=0, during the time.)
2018-02-26T13:56:29.553409Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 26629ms. The settings might not be optimal. (flushed=3 and evicted=0, during the time.)
2018-02-26T14:02:34.417982Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 13847ms. The settings might not be optimal. (flushed=9 and evicted=0, during the time.)

When this occurs serverload is very high. And sites are not accessible in that period. And I cannot login with ssh etc.. When page_cleaner is finished, i can access sites again and serverload is going back to normal.

Server details:
CPU Intel(R) Xeon(R) CPU E5-2680 v3 @ 2.50GHz (2 core(s))
Version Plesk Onyx v17.5.3_build1705170317.16 os_Ubuntu 16.04 Update #41
OS Ubuntu 16.04.3 LTS

Mysql: 5.7.21

I changed this in mysql from 1024 to 256:
SET GLOBAL innodb_lru_scan_depth=256;

Expand/Collapse Block: Common info

OS:
Ubuntu 16.04.3 LTS x86_64

Is virtuozzo container?:
Yep. Is VZ.

Product:
17.5.3 Ubuntu 16.04 1705170317.16

Microupdate:
version 41 installed-at 20180226T032414

Upgrade history:
2017-09-19 23:02:44 17.5.3 NULL Ubuntu 16.04 NULL
2017-09-19 23:04:50 17.5.3 NULL Ubuntu 16.04 22
2017-09-26 03:20:00 17.5.3 NULL Ubuntu 16.04 23
2017-10-03 03:20:38 17.5.3 NULL Ubuntu 16.04 24
2017-10-17 03:20:28 17.5.3 NULL Ubuntu 16.04 25
2017-10-25 03:23:34 17.5.3 NULL Ubuntu 16.04 26
2017-10-31 03:20:52 17.5.3 NULL Ubuntu 16.04 27
2017-11-08 03:20:31 17.5.3 NULL Ubuntu 16.04 28
2017-11-15 03:25:35 17.5.3 NULL Ubuntu 16.04 29
2017-11-16 03:21:30 17.5.3 NULL Ubuntu 16.04 30
2017-11-24 03:20:22 17.5.3 NULL Ubuntu 16.04 31
2017-11-29 03:25:42 17.5.3 NULL Ubuntu 16.04 32
2017-12-05 03:24:45 17.5.3 NULL Ubuntu 16.04 33
2017-12-13 03:23:40 17.5.3 NULL Ubuntu 16.04 34
2017-12-20 03:27:03 17.5.3 NULL Ubuntu 16.04 35
2018-01-11 03:26:57 17.5.3 NULL Ubuntu 16.04 37
2018-01-23 03:26:26 17.5.3 NULL Ubuntu 16.04 38
2018-01-31 03:22:51 17.5.3 NULL Ubuntu 16.04 39
2018-02-06 03:28:57 17.5.3 NULL Ubuntu 16.04 40
2018-02-20 03:23:32 17.5.3 NULL Ubuntu 16.04 41

Count of domains:
16

Nginx enabled:


Collected info date:
1519672771 (Mon Feb 26 19:19:31 UTC 2018)

User Beancounters:
See attached file

But didn't help

 

[IgorG]

Please check that in plesk php error logs you have something like:

'SQLSTATE[HY000]: General error: 1205 Lock wait timeout exceeded; try restarting transaction'

The error 1205 Lock wait timeout is caused by the fact that some table or database was locked by several simultaneous queries. The issue is described here:
Plesk inaccessible with 504 Gateway Timeout: 1205 Lock wait timeout exceeded
So I suggest applying this article.
Also you may want to increase innodb_lock_wait_timeout:

1. # plesk db
   
   
2. Find the current value of innodb_lock_wait_timeout:
   
   mysql> show variables like 'innodb_lock_wait_timeout';
   
   
3. Increase the value to 100:
   
   mysql> set innodb_lock_wait_timeout=100;
   

 

[Shark]

I checked the /var/log/plesk/panel.log and no entries with "Lock wait timeout exceeded"

 

[IgorG]

What about logs from /var/log/plesk-phpXX-fpm/ ?

 

[Shark]

I checked the following logs files in:
/var/log/plesk-php56-fpm
/var/log/plesk-php70-fpm
/var/log/plesk-php71-fpm

But no "Lock wait timeout"

 

[Shark]

someone else can help me?

 

[Shark]

Nobody else experience with this? Issue still exist..