Unerklärliche CPU Auslastung durch PHP

xse

New Member
Hi,

ich bin gerade mit einem Projekt auf einen neuen vServer (HostEurope) umgezogen. Vorher war ich über ein Jahr lang auch auf einem Server von HE, mit PHP 5.4.x

Auf dem neuen Server läuft natürlich PHP7.
Bei der Webseite handelt es sich um ein Laravel Projekt. Ich hatte auf dem alten Server keine großartigen Performance-Probleme und bin umgezogen, weil ich die im neuen Server verbaute SSD und generell neue Software (Plesk Onyx) haben möchte.

Seit dem Umzug habe ich alle paar Minuten eine Auslastung von 100% auf allen CPUs, das geht dann über ca. 10-30 Sekunden. Die Auslastung ist so krass, dass auf der Webseite nichts mehr geht. Im Anhang ein Screenshot von HTOP.

Ich habe natürlich schon so einiges probiert, um den Fehler einzugrenzen:
- Statische Dateien (es werden sehr viele Bilder ausgeliefert), von Amazon S3 liefern lassen
- PHP 5.6 installiert, gleiches Ergebnis
- PHP im FPM und CGI Modus getestet, gleiches Ergebnis
- Alle Cron-Jobs ausgeschaltet
- MySQL Datenbank von meinem alten vServer liefern lassen (also MySQL ist nicht das Problem)
- Access log beobachtet (direkt über Plesk, mit der Echtzeitaktualisierung), keine Auffälligkeiten
- Fail2Ban & ModSecurity sind aktiviert
- Die Firewall lässt nur die für Apache relevanten Einstellungen zu, alles andere ist dicht. E-Mails werden nicht über den Server gesendet.
- Diverse Server-Neustarts

OpCache ist aktiv und Redis läuft als Objekt-Cache für intensive Datenbankabfragen (dort habe ich aber auch schon einen File-Cache probiert und Redis ausgeschaltet)

Ich weiss nicht mehr, wo ich jetzt noch schauen soll. Ich habe mir auch die aktuellen Verbindungen anzeigen lassen, mit

netstat -anp |grep 'tcp\|udp' | awk '{print $5}' | cut -d: -f1 | sort | uniq -c

Aber dort sieht für mich auch alles normal aus. Sobald ich die Webseite "abstelle" (das Home-Verzeichnis wechsle) ist der Server ruhig. Sofort, wenn ich das Verzeichnis wieder auf das korrekte wechsle, bekomme ich diese CPU Spikes, so schnell können die Nutzer gar nicht sein...

Hat jemand noch irgendeine Idee?

viele Grüße,
Alex
 

Attachments

  • cpuspikes.jpg
    cpuspikes.jpg
    374.2 KB · Views: 527
Last edited by a moderator:
Pfade und Rechte sind alle sauber konfiguriert? Ggf. (Filesystem)-Caches gelöscht? Wie hast Du denn den Umzug durchgeführt? Ist sichergestellt, daß keine Server-spezifischen Einträge in der Software selbst drin sind?

Ein guter Anhaltspunkt ist ggf. auch immer mal, das Script direkt von der Konsole ausführen. Ggf. noch ein strace darüber.

... und mal prüfen, ob es ein generelles php-Problem darstellt oder nur das eine Projekt betrifft.
 
Last edited by a moderator:
Wenn ich mich nicht irre, stellen rote Bars in htop die kernel time dar.
Auf Deutsch: ich würde auch mal in Richtung io wait forschen, bzw. die cpu steal time überprüfen.

Ps: ich habe nochmal nachgelesen und Orange wäre im Detailed Mode sogar ganz konkret die io wait time.
 
Last edited by a moderator:
Hat jemand noch irgendeine Idee?

Schau dir auch mal das Tool sar, was z.B. bei CentOS 7 mit dem Paket sysstat mit installiert wird, genauer an.

Denn schon die einfache Ausgabe per sar für einen Tag zeigt beeindruckend die Systemauslastung des betroffenen Servers z.B. wie folgt an:

Code:
00:00:01    CPU     %user     %nice   %system   %iowait    %steal     %idle
00:10:01    all      0,43      0,00      1,15      1,02      1,60     98,79
00:20:01    all      0,46      0,00      1,12      1,01      1,48     98,93
00:30:01    all      0,46      0,00      1,15      1,01      1,53     98,85
00:40:01    all      0,45      0,00      1,16      1,01      1,48     98,90
00:50:01    all      0,45      0,00      1,17      1,01      1,55     98,82
01:00:01    all      0,55      0,00      1,22      1,02      1,56     98,65
01:10:01    all      0,55      0,00      1,21      1,01      1,53     98,71
01:20:01    all      0,45      0,00      1,15      1,01      1,42     98,97
01:30:01    all      0,45      0,00      1,14      1,01      1,45     98,96
01:40:01    all      0,47      0,00      1,19      1,01      1,48     98,85
Da auf meinem virtuellen Server mit einem Prozessor E5-2680V4, mit 12 dedizierten Kernen laut Provider und 36 GB DDR4 ECC RAM, von dem dieser Auszug stammt, nur ein minimalistisches CentOS 7 mit dem SSH-Daemon installiert ist, würde ich sogar mal aufgrund der doch hohen Werte behaupten, daß man mit Hilfe dieses Tools sogar die Auslastung des Hostsystems, auf dem dieser virtuelle Server läuft, im gewissen Maße sehen kann.

Wie man dieses Toll komfortabel und sehr bequem bedienen kann, wird hier sehr gut erklärt.
 
- Access log beobachtet (direkt über Plesk, mit der Echtzeitaktualisierung), keine Auffälligkeiten
Hast du auch die Error-Logs resp. FPM-Logs geprüft?
Nicht, dass da aufgrund eines Fehlers in deinen Scripten, welcher erst durch die neue PHP-Version oder irgendwelche fehlenden Module verursacht wird sichtbar wird und Endlosschleifen erzeugt...
 
ich bin gerade mit einem Projekt auf einen neuen vServer (HostEurope) umgezogen. Vorher war ich über ein Jahr lang auch auf einem Server von HE, mit PHP 5.4.x

Ich habe natürlich schon so einiges probiert, um den Fehler einzugrenzen:
- PHP 5.6 installiert, gleiches Ergebnis

Ich weiss nicht mehr, wo ich jetzt noch schauen soll.

Hat jemand noch irgendeine Idee?

Falls du dein Problem noch nicht behoben haben solltest, könntest du auch mal probieren, auf deinem neuen Server die gleiche PHP-Version 5.4.x, die auf deinem älteren Server lief, zu installieren. Denn eventuell gibt es einige von dir benutzte Funktionen, die in den neueren PHP-Versionen > 5.4.x nicht mehr unterstützt werden.
 
Hi Leute,

vielen Dank für eure schnelle und ausführliche Hilfe!

Vorweg:
Ich habe noch einige Zeit mit dem Server gekämpft und irgendwann radikal Dienste deaktiviert und die Webseite 1x komplett gelöscht und neu aufgesetzt. Seitdem läuft es deutlich stabiler, ich weiss allerdings leider trotzdem nicht, was die Ursache war. Ich werde das mal weiter beobachten...

Pfade und Rechte sind alle sauber konfiguriert? Ggf. (Filesystem)-Caches gelöscht? Wie hast Du denn den Umzug durchgeführt? Ist sichergestellt, daß keine Server-spezifischen Einträge in der Software selbst drin sind?

Ein guter Anhaltspunkt ist ggf. auch immer mal, das Script direkt von der Konsole ausführen. Ggf. noch ein strace darüber.

... und mal prüfen, ob es ein generelles php-Problem darstellt oder nur das eine Projekt betrifft.

Ja, ich denke die Rechte etc. sind alle sauber konfiguriert, ich habe alles so gemacht wie auf dem alten Server. Ist natürlich nicht auszuschließen, dass ich da irgendwo etwas vergessen habe, aber ich habe mir extra ein Protokoll beim Aufsetzen des alten Servers angelegt, dass ich nachvollzogen habe.

Die PHP Skripte habe ich bisher nur lokal mit xDebug & kCachegrind untersucht, aber nichts auffälliges gefunden.

Wenn ich mich nicht irre, stellen rote Bars in htop die kernel time dar.
Auf Deutsch: ich würde auch mal in Richtung io wait forschen, bzw. die cpu steal time überprüfen.

Ps: ich habe nochmal nachgelesen und Orange wäre im Detailed Mode sogar ganz konkret die io wait time.

habe stealtime & iowait überprüft (auch während es voll ausgelastet war), war aber beides bei 0 oder knapp drüber.

Aber das mit den roten Bars in HTOP wundert mich auch, dass sollen ja Systemprozesse sein und ich habe auch das Gefühl, dass nicht meine Webseite schuld ist, sondern irgendwelche Prozesse, die dort im Hintergrund rumwerkeln. Würde ja auch erklären, warum er jetzt besser läuft, wo ich einiges abgestellt habe (?) Wenn ich aktiv au der Webseite einen intensiven Prozess (zB Suchfunktion) auslöse, dann gehen die grünen Bars ein wenig hoch, aber längst nicht so, dass es ein Problem wäre.

Schau dir auch mal das Tool sar, was z.B. bei CentOS 7 mit dem Paket sysstat mit installiert wird, genauer an.

Danke, habe SAR nun installiert, aber da der Server momentan ja ganz gut läuft habe ich noch keine Daten gesammelt, die interessant sind (sieht etwa so aus, wie in deinem Beispiel)

Hast du auch die Error-Logs resp. FPM-Logs geprüft?
Nicht, dass da aufgrund eines Fehlers in deinen Scripten, welcher erst durch die neue PHP-Version oder irgendwelche fehlenden Module verursacht wird sichtbar wird und Endlosschleifen erzeugt...

ja, das habe ich als erstes gemacht. Die einzigen Fehler die ich dauernd hab (hatte) waren "Max Execution time...", weil der Server die Anfrage wegen der Last eben nicht mehr verarbeiten konnte. Sonst keine Fehler im Script (wie gesagt, die Seite lieft ja vorher schon ein ganzes Jahr problemlos)

Also IO-Wait mit hoher CPU-Auslastung ist schon sehr eigenartig und passt nicht zusammen.
Anstatt hier zu raten, wäre eine Möglichkeit den PHP-Code zu profilieren: http://stackoverflow.com/questions/21133/simplest-way-to-profile-a-php-script

Dann wirst du auch sehen, welche Statements/Funktionen am meisten Zeit brauchen. Hat das hier eigentlich schon mal jemand versucht? Würde mich wundern, falls nicht.

Siehe weiter oben, mit xDebug / kCachegrind, aber bisher nur lokal

Falls du dein Problem noch nicht behoben haben solltest, könntest du auch mal probieren, auf deinem neuen Server die gleiche PHP-Version 5.4.x, die auf deinem älteren Server lief, zu installieren. Denn eventuell gibt es einige von dir benutzte Funktionen, die in den neueren PHP-Versionen > 5.4.x nicht mehr unterstützt werden.

ich habe zumindest PHP 5.6 mal installiert (glaube von 5.4 > 5.6 gab es keine bahnbrechenden Neuerungen), war immernoch so mit der Auslastung.

viele Grüße,
Alex
 
Da auf meinem virtuellen Server mit einem Prozessor E5-2680V4, mit 12 dedizierten Kernen laut Provider und 36 GB DDR4 ECC RAM, von dem dieser Auszug stammt, nur ein minimalistisches CentOS 7 mit dem SSH-Daemon installiert ist, würde ich sogar mal aufgrund der doch hohen Werte behaupten, daß man mit Hilfe dieses Tools sogar die Auslastung des Hostsystems, auf dem dieser virtuelle Server läuft, im gewissen Maße sehen kann.
Durchaus korrekt, zumindest die Stealtime kann man meines Wissens nicht ohne erheblichen Aufwand (d.h. massive Codeänderungen in der Virtualisierung) faken. Hier kann man gut sehen, ob ein Anbieter die CPU aktiv überbucht, was insbesondere bei vermeintlich dedizierter Leistung schon für manche Überraschung gesorgt hat. Zu beachten sind jedoch einige Dinge:

- Eine dauerhafte Stealtime von exakt 0,0% ist technisch auch bei einer "grünen" Auslastung des Hosts nicht möglich, insbesondere nicht, wenn es sich nicht um auf physikalische CPU-Kerne gepinnte Cores handelt.
- Je mehr Kerne eine VM (genauer: jede VM) hat, desto höher ist der Scheduling-Aufwand des Hypervisors, was die Stealtime gegenüber einzelnen Kernen erhöhen kann.
- Dein sar misst natürlich zu einer für den Host ungünstigen Zeit, nämlich alle zehn Minuten. Diese klassischen "Cron-Zeiten" sorgen meist für einen kleinen Peak in der Stealtime (oder eben für einen großen Peak, wenn der Provider aktiv überbucht). Der Wert ist bei dir aber völlig im Rahmen. Der I/O-Wait erscheint mir für ein SSD-System subjektiv hoch, dies ist aber zu sehr von deinem eigenen System abhängig (Dateisystem, Mountoptionen, eigene Cronjobs zu dieser Zeit), als dass man hier pauschal auf den Provider "zeigen" könnte, während die Stealtime nicht wirklich von der eigenen Auslastung abhängen sollte.

Die PHP Skripte habe ich bisher nur lokal mit xDebug & kCachegrind untersucht, aber nichts auffälliges gefunden.
Wir profilen Kundenapplikationen gerne mit https://tideways.io - das Tool ist von vorne bis hinten genial und spart immer wieder viel Zeit.

Aber das mit den roten Bars in HTOP wundert mich auch, dass sollen ja Systemprozesse sein
Das ist ein weit verbreiteter Irrglaube :) Es sind weder "Systemprozesse" (für die es vermutlich ohnehin keine allgemeingültige Definition gibt) noch Kernelthreads, sondern die CPU-Zeit, die im Kernelspace statt Userspace verbracht wurde. Die meisten Prozesse im Userspace beanspruchen auch CPU-Zeit im Kernelspace, bzw. jeder Prozess tut das, aber nicht jeder gleichermaßen. Tools wie perf können diese "Kernelzeiten" noch besser zerlegen. So oder so zeigt dein Screenshot klar, dass die CPU-Last von einem deiner PHP-FPM-Pools ausgeht, dort ist daher das Problem zu suchen - die roten Balken sind nur ein zusätzliches Symptom.

Die einzigen Fehler die ich dauernd hab (hatte) waren "Max Execution time...", weil der Server die Anfrage wegen der Last eben nicht mehr verarbeiten konnte.
Auch ein Irrglaube :) Die max_execution_time regelt nicht die Skriptlaufzeit, sondern die tatsächliche CPU-Zeit. Wenn ein Skript mit einer max_execution_time von 60 Sekunden gestartet wird und durchschnittlich 50% eines CPU-Kerns saturiert, könnte es zwei Minuten laufen, bevor es abgebrochen wird. Wenn du hier also drangestoßen bist, bestätigt das meine Aussage aus dem vorherigen Absatz: Deine Applikation hat tatsächlich irgendetwas getan, was viel CPU-Last generiert hat. Oftmals handelt es sich um Endlosschleifen. Sowas lässt sich übrigens schon mit strace ziemlich gut herausfinden, da braucht es meist keine richtigen Profiler für.


Viele Grüße
Tim
 
Hi Tim,

vielen Dank für deine Aufklärung zu einige Punkten.

Der Server hat leider wieder zwischendurch diese heftigen Auslastunganfälle, ich habe jetzt noch mal ein Strace-log auf einem der PHP Prozesse laufen lassen, die 100% CPU Auslastung verursachen. Ich habe das Log ca. 7 Sekunden laufen lassen und eine Logdatei mit sage und schreibe 650.000 Zeilen erhalten.

Es wiederholt sich immer dieser Block, so oder so ähnlich:

Code:
01:50:34.711767 lstat("/var/www/vhosts/domain.com/httpdocs/app/storage/sessions/8b75f41f12747d4855cf0646b8d41d552d7a9c3a", {st_mode=S_IFREG|0644, st_size=197, ...}) = 0
01:50:34.711797 lstat("/var/www/vhosts/domain.com/httpdocs/app/storage/sessions", {st_mode=S_IFDIR|0755, st_size=7016448, ...}) = 0
01:50:34.711826 lstat("/var/www/vhosts/domain.com/httpdocs/app/storage", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
01:50:34.711854 lstat("/var/www/vhosts/domain.com/httpdocs/app", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
01:50:34.711881 lstat("/var/www/vhosts/domain.com/httpdocs", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
01:50:34.711909 lstat("/var/www/vhosts/domain.com", {st_mode=S_IFDIR|0710, st_size=4096, ...}) = 0
01:50:34.711936 lstat("/var/www/vhosts", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
01:50:34.711963 lstat("/var/www", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
01:50:34.711990 lstat("/var", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0

ist da irgendwas mit dem session management kaputt? Jemand nen' tip (Laravel legt die Sessions in /app/storage ab)? Ich recherchiere mal weiter...

* Edit: Ich sehe gerade im Session-Ordner sind wahnsinnig viele Dateien angelegt worden (viel mehr, als ich Nutzer habe), da kann irgendwas nicht stimmen. Ich habe den Session-Driver mal auf "Cookie" statt auf "File" gesetzt und bin dabei, den Ordner zu löschen

viele Grüße,
Alex
 
Last edited by a moderator:
Hallo Alex,

für die Standard-PHP-Sessionpfade hat man normalerweise einen Cronjob, der die Verzeichnisse bereinigt. Wenn deine Applikation natürlich einen eigenen Ordner nutzt, muss sie sich auch selbst um die Bereinigung kümmern. Geschieht dies nicht, würde das erklären, warum einige Zeit nach der Serverneuinstallation das Problem noch nicht aufgetreten ist.


Viele Grüße
Tim
 
Ja, das wird es wohl gewesen sein. Der Server läuft heute jedenfalls wie geschmiert.

Eigentlich kümmert sich Laravel selbst um die Bereinigung des Sessions-Ordners, dass ging ja kurioserweise auf dem alten Server auch immer (da hatte ich dafür auch keinen Cron-Job angelegt).

Bin wohl auch nicht der einzige, bei dem dieses Problem aufgetreten ist:

https://laracasts.com/index.php/discuss/channels/general-discussion/laravel-5-creates-a-new-session-after-each-request


danke nochmal für die Hilfe und frohe Festtage,

Alex
 
Back
Top