Applicable to:
- Plesk Onyx for Linux
Symptoms
The following error log can be found in
/var/log/apache2/error.log
for Debian/Ubuntu OS and in
/var/log/httpd/error_log
for CentOS/Redhat OS:
CONFIG_TEXT: [Tue Oct 03 10:32:41.965156 2017] [pagespeed:error] [pid 23476] [mod_pagespeed 1.12.34.2-0 @23476] Slow ReadFile operation on file /var/cache/mod_pagespeed/v3/example.com/https,3A/,2Fwww.example.com/forums,: 4039.37ms; configure SlowFileLatencyUs to change threshold\n
Cause
Slow disk I/O performance.
Resolution
PageSpeed is logging this error because reading the file from its cache takes 4039.37ms.
To solve the issue adjust disk I/O performance.
Comments
3 comments
I've checked my IO performance with the command:
fio --name=rand-write --ioengine=libaio --iodepth=32 --rw=randwrite --invalidate=1 --bsrange=4k:4k,4k:4k --size=512m --runtime=120 --time_based --do_verify=1 --direct=1 --group_reporting --numjobs=6
I get these results:
-------------------
Jobs: 6 (f=6): [w(6)][100.0%][r=0KiB/s,w=3847KiB/s][r=0,w=961 IOPS][eta 00m:00s]
rand-write: (groupid=0, jobs=6): err= 0: pid=24795: Wed Mar 18 12:13:58 2020
write: IOPS=1027, BW=4108KiB/s (4207kB/s)(482MiB/120155msec)
slat (usec): min=6, max=458077, avg=2948.31, stdev=17190.57
clat (usec): min=222, max=2171.3k, avg=183947.71, stdev=107919.06
lat (usec): min=290, max=2262.9k, avg=186897.62, stdev=108515.38
clat percentiles (usec):
| 1.00th=[ 1893], 5.00th=[ 4424], 10.00th=[ 33162],
| 20.00th=[ 110625], 30.00th=[ 147850], 40.00th=[ 168821],
| 50.00th=[ 185598], 60.00th=[ 196084], 70.00th=[ 217056],
| 80.00th=[ 252707], 90.00th=[ 304088], 95.00th=[ 333448],
| 99.00th=[ 467665], 99.50th=[ 599786], 99.90th=[ 884999],
| 99.95th=[1182794], 99.99th=[2164261]
bw ( KiB/s): min= 8, max=15760, per=16.71%, avg=686.51, stdev=874.81, samples=1435
iops : min= 2, max= 3940, avg=171.56, stdev=218.70, samples=1435
lat (usec) : 250=0.01%, 500=0.01%, 750=0.02%, 1000=0.14%
lat (msec) : 2=1.00%, 4=3.13%, 10=3.95%, 20=0.74%, 50=2.45%
lat (msec) : 100=6.55%, 250=61.22%, 500=19.97%, 750=0.58%, 1000=0.15%
cpu : usr=0.17%, sys=0.62%, ctx=17157, majf=0, minf=192
IO depths : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=0.1%, 32=99.8%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.1%, 64=0.0%, >=64=0.0%
issued rwts: total=0,123411,0,0 short=0,0,0,0 dropped=0,0,0,0
latency : target=0, window=0, percentile=100.00%, depth=32
Run status group 0 (all jobs):
WRITE: bw=4108KiB/s (4207kB/s), 4108KiB/s-4108KiB/s (4207kB/s-4207kB/s), io=482MiB (505MB), run=120155-120155msec
Disk stats (read/write):
sda: ios=1648/130551, merge=176/114324, ticks=17675/14634838, in_queue=14655855, util=100.00%
-------------------
Do you think if I get the error message it's because I have IO performance issues?
Here's my pagespeed settings:
------------------------------
------------------------------
I tried it again using tmpfs as a cache directory. And the same result. I don't understand how using memory as a cache I can get the same result.
On the other hand, I'm not sure how much it is, for example, "118.763ms". Is it 118 milliseconds or 118 seconds? It's impossible that any reading task would have taken 118 seconds to complete.
And if it is 118 milliseconds, which is what I expect, how is it possible that having also configured "ModPagespeedSlowFileLatencyUs 500000" I have those messages?
The new configuration with tmpfs and Latency parameter:
-----------------------------------------
-----------------------------------------
Hello Nerque
> I'm not sure how much it is, for example, "118.763ms". Is it 118 milliseconds or 118 seconds?
That's 118 milliseconds.
According to the information I've found 500000 for that parameter stands for 500ms. That indeed should be enough.
Please, make sure you've restarted Apache and PHP-FPM handler (if in use) after setting this parameter value.
In case this is already done, consider submitting a request to Plesk Support.
Please sign in to leave a comment.