rsyslog Masterserver: 100% CPU

[killerbees19]

Hi,

ich habe seit einigen Monaten mit einem seltsamen Problem zu kämpfen. Die Ausgangslage ist ein rsyslogd unter Debian Wheezy (amd64) in einem Linux-VServer Gastsystem, der als Masterserver für alle anderen rsyslog-Clients dient. Dieser Server loggt alles direkt in eine MySQL-Tabelle. Die Verbindung der Clients zum Server erfolgt ausschließlich via TCP/TLS über ein internes Netz, in diesem Fall über OpenVPN, das über das Hostsystem eingebunden ist. Das Setup funktioniert soweit problemlos seit mehr als einem Jahr.

Bisher passierte es dann alle paar Monate einmal, dass ich folgendes Verhalten beobachten konnte: Der VPN-Server bzw. dessen Netzwerk ist kurzfristig nicht erreichbar. Der rsyslogd-Master läuft dann plötzlich mit 100% CPU Amok und loggt keine Zeile mehr zu MySQL. Ein simpler Neustart des Dienstes hilft, dann werden auch alle zwischengespeicherten Ereignisse sofort in die DB eingetragen und er läuft ohne Probleme weiter.

Hatte so ein Problem schon einmal jemand? Oder irgendwelche Tipps zum Eingrenzen des Fehlers?
Wenn der Fehler das nächste Mal auftritt, werde ich mit strace schauen, ob etwas interessantes dabei ist.

Ein identisches Setup im lokalen Netzwerk zeigt hingegen keine Auffälligkeiten.
Allerdings kommt hier auch kein VPN, keine Container-Virtualisierung und eine andere Prozessorarchitektur zum Einsatz.


MfG Christian

 

[Lord Gurke]

Bei sowas hänge ich mich gerne mit strace an den Prozess und sehe mal nach was er denn da so treibt.
Aufruf üblicherweise mit
strace -f -p <PID>

Eventuell erkennt man dort dann irgendwelche verräterischen Dinge die einem zumindest helfen in der richtigen Richtung zu suchen (z.B. permanente Anfrage eines DNS-Namen, permanente Abfrage der aktuellen Zeit....)

 

[killerbees19]

Gestern gab es genauso einen Netzwerkausfall wieder, allerdings lief der rsyslogd ohne Probleme weiter. Weihnachtsfrieden?


MfG Christian

 

[killerbees19]

Jetzt war es mal wieder so weit
Das einzige was ich massenhaft (>100 pro Sekunde) sehe:

[pid  3553] recvfrom(38, 0x7f2618118940, 138, 0, 0, 0) = -1 EAGAIN (Resource temporarily unavailable)

Und in selteneren Abständen:

futex(0x10b2a10, FUTEX_WAKE_PRIVATE, 1) = 0
poll([{fd=47, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
write(47, "\223\1\0\0\3INSERT INTO `queue` (`time`"..., 407) = 407
read(47, "\n\0\0\1\0\1\375\32\351I\2\0\0\0", 16384) = 14

Wirklich schlau werde ich daraus aber nicht
Ich habe die strace-Logs trotzdem einmal von allen rsyslog-Threads gespeichert und hebe sie auf.


MfG Christian

 

[killerbees19]

Seit damals ist es trotz mehrerer Netzwerkausfälle übrigens nie wieder passiert. Es gab dazwischen auch einige Updates für das rsyslog Package. Eventuell floss da ein Bugfix mit ein.


MfG Christian

 

[killerbees19]

Eventuell floss da ein Bugfix mit ein.

Offenbar nicht, vor einigen Tagen war es nach langer Zeit wieder soweit. Das nur als abschließendes Feedback, dieses Linux-VServer Gastsystem wird in einigen Tagen/Wochen nämlich stillgelegt. Weiß der Geier, warum das so extrem sporadisch aufgetreten ist und was schuld war.


MfG Christian