Diese Woche gab es auf einem Server das Phänomen, dass die LOAD bei über 2500% (ca. 150 bei 6 CPUs), aber die CPU Auslastung lag nur bei etwa 5%, was also darauf hindeutete, dass due CPU-Last nicht nicht der Grund für die hohe LOAD sein konnte:
top - 15:53:42 up 7 days, 10:01, 2 users, load average: 159,47, 149,89, 160,80 Tasks: 540 total, 1 running, 468 sleeping, 0 stopped, 0 zombie %Cpu(s): 2,0 us, 2,0 sy, 0,0 ni, 0,0 id, 95,6 wa, 0,0 hi, 0,4 si, 0,0 st KiB Mem : 12296516 total, 607940 free, 9710388 used, 1978188 buff/cache KiB Swap: 12578812 total, 7439140 free, 5139672 used. 1752884 avail Mem PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 5564 user@xyz 20 0 99712 36384 5308 D 4,6 0,3 0:00.22 spamassassin 1539 root 20 0 2394080 55984 7412 S 2,0 0,5 1365:51 fail2ban-server 4561 root 20 0 33784 6168 3700 S 1,3 0,1 0:02.39 htop 8 root 20 0 0 0 0 I 0,7 0,0 11:17.44 rcu_sched ...
Festplattenzugriffe als mögliche Ursache
Neben einer hohen CPU-Auslastung kann auch eine hohe IO-Last, als viele lesende oder schreibende Zugriffe auf die Festplatte zu einer hohen LOAD führen.
Analysetools
Es gibt eine ganz Menge an Tools, mit denen man die IO analysieren kann. Neben vmstat
, pmstat
und iostat
gibt es das Tool iotop
, welches sehr ähnlich zu top
bzw. htop
funktioniert. Die Ausgabe sieht in etwa wie folgt aus:
Total DISK READ : 3.25 M/s | Total DISK WRITE : 97.42 K/s Actual DISK READ: 3.35 M/s | Actual DISK WRITE: 151.97 K/s TID PRIO USER DISK READ DISK WRITE SWAPIN IO> COMMAND 14457 be/4 example- 1067.69 K/s 0.00 B/s 0.00 % 78.58 % php-fpm: pool 160096117520684 958 be/4 example- 2.20 M/s 0.00 B/s 0.00 % 71.42 % php-fpm: pool 160096117520684 19990 be/4 mysql 3.90 K/s 3.90 K/s 0.00 % 0.50 % mysqld --daemonize --pid-file=/run/mysqld/mysqld.pid ...
Man kann hier mit den Cursortasten die Spalte wählen, nach der sortiert werden soll (hier ist aktuell die Spalte IO
ausgewählt, markiert durch das >
am Ende).
Auch diese Ansicht zeigte keinen einzelnen Prozesse, die ungewöhnlich hohe Zugriffsraten hatten. Es fiel aber auf, dass sehr viele php-fpm
Prozesse dabei waren.
Auffinden von blockierten Prozessen
Der Grund für die sehr hohe LOAD waren Prozesse, die darauf warteten ausgeführt zu werden. Möchten solche Prozesse auf die Disk zugreifen, können dies aber gerade nicht, dann fallen sie in den „uninterruptible sleep“. Solche Prozesse kann man mit dem ps
Befehl finden:
$ ps -ax | grep D PID TTY STAT TIME COMMAND 6292 ? D 1:26 php-fpm: pool 151673661024723 8746 pts/0 S+ 0:00 grep --color=auto D 22261 ? D 0:03 php-fpm: pool 160096117520684 24583 ? D 0:03 php-fpm: pool 16104533493131 24886 ? D 0:02 php-fpm: pool 160096117520684 24894 ? D 0:02 php-fpm: pool 160096117520684 24896 ? D 0:02 php-fpm: pool 160096117520684 25048 ? D 0:02 php-fpm: pool 160096117520684 25050 ? D 0:01 php-fpm: pool 160096117520684 25052 ? D 0:01 php-fpm: pool 160096117520684 26265 ? D 0:01 php-fpm: pool 16104533493131 26315 ? D 0:01 php-fpm: pool 16104533493131 27967 ? D 0:01 php-fpm: pool 16104533493131 28711 ? D 0:01 php-fpm: pool 16104533493131 28966 ? D 0:01 php-fpm: pool 16104533493131 29202 ? D 0:01 php-fpm: pool 160096117520684 ...
Diese einfache Suche zeigte (neben ein paar falschen Suchtreffern) sehr viele php-fpm
Prozesse an, die aktuell in diesem Zustand waren.
Lösung: Prozesse neustarten
Die Lösung war eigentlich recht einfach. Durch einen Neustart der verschiedenen php-fpm
Services (auf dem Server sind mehrere PHP-Versionen installiert) konnten die blockierten Prozesse abgebrochen werden. Die LOAD war im Anschluss bei etwa 0,5 und der Server somit nicht mehr stark ausgelastet.
Fazit
Wenn ein Server eine hohe LOAD hat, dann ist der Grund nicht immer eine hohe CPU-Auslastung. Auch viele Festplattenzugriffe oder aber blockierte Prozesse können zu einer hohen Last führen. Mit den richtigen Tools an der Hand lassen sich solche Fehler aber auch finden und beheben.