CPUもメモリも異常ないのにレスポンスが遅い

Question

CPUにもメモリにも余裕があるのに、レスポンスが異常に遅いのは、原因として何が考えられるでしょうか？

とある日の16:10~16:25くらいににかけ、一時的にリクエストが多くなりました。
合計1000件ほどのアクセスに対して、3秒数以内返却したのが100件、それ以上かかって返却されたのが700件、タイムアウトエラーで返却されなかったのが200件ほどです。

CPUにもメモリにも余裕があったのと、表示されるのはワードプレスのページなので、ioの多さやアルゴリズム的な複雑さもないと思います。

以下がその時のcpuやメモリなど必要とされるような諸々の情報です。

CPU使用率(20%程度)
$ sar -f /var/log/sa/sa26
                CPU     %user     %nice   %system   %iowait    %steal     %idle
16時10分01秒     all      6.49      0.24      0.56      0.03      0.00     92.69
16時20分01秒     all     23.62      0.48      1.40      0.06      0.00     74.44
16時30分01秒     all     18.97      0.43      1.17      0.04      0.00     79.39
16時40分01秒     all     14.60      0.34      1.04      0.03      0.00     83.98
16時50分01秒     all      7.28      0.24      0.59      0.03      0.00     91.86
CPU使用率(20%程度)
$ sar -P ALL -f /var/log/sa/sa26
16時00分01秒     CPU     %user     %nice   %system   %iowait    %steal     %idle
16時10分01秒     all      6.49      0.24      0.56      0.03      0.00     92.69
16時10分01秒       0      6.43      0.24      0.57      0.03      0.00     92.73
16時10分01秒       1      6.54      0.24      0.55      0.02      0.00     92.65
16時10分01秒     CPU     %user     %nice   %system   %iowait    %steal     %idle
16時20分01秒     all     23.62      0.48      1.40      0.06      0.00     74.44
16時20分01秒       0     23.45      0.47      1.41      0.06      0.00     74.61
16時20分01秒       1     23.79      0.48      1.39      0.07      0.00     74.28
16時20分01秒     CPU     %user     %nice   %system   %iowait    %steal     %idle
16時30分01秒     all     18.97      0.43      1.17      0.04      0.00     79.39
16時30分01秒       0     19.24      0.40      1.23      0.04      0.00     79.09
16時30分01秒       1     18.69      0.45      1.11      0.04      0.00     79.70
16時30分01秒     CPU     %user     %nice   %system   %iowait    %steal     %idle
16時40分01秒     all     14.60      0.34      1.04      0.03      0.00     83.98
16時40分01秒       0     15.40      0.32      1.07      0.03      0.00     83.18
16時40分01秒       1     13.81      0.36      1.01      0.04      0.00     84.77
メモリ使用率(26%~47%程度)
$ sar -r -f /var/log/sa/sa26         
            kbmemfree kbmemused  %memused kbbuffers  kbcached  kbcommit   %commit  kbactive   kbinact   kbdirty
00時10分01秒    413320   3382712     89.11         0   2552440    989200     26.06   2248264    723984       492
00時20分01秒    358596   3437436     90.55         0   2553140   1047120     27.58   2302032    724676       436
00時30分01秒    342204   3453828     90.99         0   2553612   1067000     28.11   2318408    725140       428
00時40分01秒    329552   3466480     91.32         0   2553764   1072684     28.26   2330764    725336       412
00時50分01秒    391956   3404076     89.67         0   2554528   1011784     26.65   2267452    726004       308
01時00分01秒    343128   3452904     90.96         0   2555264   1060292     27.93   2315324    726780       304
:
16時00分01秒    491216   3304816     87.06         0   2442844   1021424     26.91   2284784    606752       452
16時10分01秒    227232   3568800     94.01         0   2118176   1666288     43.90   2656520    492964      1120
16時20分01秒    142184   3653848     96.25         0   2106720   1799872     47.41   2717712    515224       648
16時30分01秒    858788   2937244     77.38         0   2102212   1016348     26.77   2015924    507928       736
16時40分01秒    792996   3003036     79.11         0   2109280   1105068     29.11   2076968    513420       672
受信/送信パケット数
[22:02]                IFACE   rxpck/s   txpck/s    rxkB/s    txkB/s   rxcmp/s   txcmp/s  rxmcst/s
15時20分01秒      eth0     46.51     68.15     79.51     55.22      0.00      0.00      0.00
15時20分01秒        lo      0.00      0.00      0.00      0.00      0.00      0.00      0.00
15時30分01秒      eth0     14.88     26.98     22.38     23.24      0.00      0.00      0.00
15時30分01秒        lo      0.00      0.00      0.00      0.00      0.00      0.00      0.00
15時40分01秒      eth0     19.79     32.99     30.62     27.87      0.00      0.00      0.00
15時40分01秒        lo      0.00      0.00      0.00      0.00      0.00      0.00      0.00
15時50分01秒      eth0     22.33     43.37     33.66     40.24      0.00      0.00      0.00
15時50分01秒        lo      0.00      0.00      0.00      0.00      0.00      0.00      0.00
16時00分01秒      eth0     19.94     36.89     30.12     32.96      0.00      0.00      0.00
16時00分01秒        lo      0.00      0.00      0.00      0.00      0.00      0.00      0.00
16時10分01秒      eth0    122.76    340.28    202.97    391.11      0.00      0.00      0.00
16時10分01秒        lo      0.00      0.00      0.00      0.00      0.00      0.00      0.00
16時20分01秒      eth0    484.76    546.66   1095.37    271.87      0.00      0.00      0.00
16時20分01秒        lo      0.00      0.00      0.00      0.00      0.00      0.00      0.00
16時30分01秒      eth0    408.35    692.92    815.13    609.67      0.00      0.00      0.00
16時30分01秒        lo      0.00      0.00      0.00      0.00      0.00      0.00      0.00
16時40分01秒      eth0    298.65    693.84    555.05    741.04      0.00      0.00      0.00
16時40分01秒        lo      1.54      1.54      0.45      0.45      0.00      0.00      0.00
16時50分01秒      eth0    151.34    402.27    252.23    453.93      0.00      0.00      0.00
16時50分01秒        lo      0.00      0.00      0.00      0.00      0.00      0.00      0.00
スワップ（なし）
$ sar -S -f /var/log/sa/sa26
00時00分01秒 kbswpfree kbswpused  %swpused  kbswpcad   %swpcad
16時10分01秒         0         0      0.00         0      0.00
16時20分01秒         0         0      0.00         0      0.00
16時30分01秒         0         0      0.00         0      0.00
16時40分01秒         0         0      0.00         0      0.00

環境はamazon linux2,nginx,php(word press)です。
他に大きいミドルウェアは使用していません。(DBはRDSを使用)
amazon linux2のインスタンスタイプはc5.largeで、vcpuが2,メモリが4GBです。
php-fpmの設定は以下のようになっています。

pm = dynamic
pm.start_servers     = 4
pm.min_spare_servers = 4
pm.max_spare_servers = 10
pm.max_children      = 20

回答よろしくお願いします。

Comments

[hoshi-takanori]

負荷テストしてみてはいかがでしょうか。
https://wp.remotemanager.me/wp-stress-test/

Answer 1

• マルチテント構成で、他の同居していたユーザのI/O 負荷が非常に高かった。
• ストレージ等に故障が発生して、冗長構成で故障を回避していたが、回避作業のために平均的に処理時間が長くなり、障害にヒットしたリクエストは、タイムアウトした。

Comments

[hana_yama_san]

私もタイトルを見ただけでディスクIOに問題有と思いました。