Ausfall der Datenannahme am 1. November 2018 um 06:52 Uhr

Entwicklung / Development Fehleranalyse / Troubleshooting
1

Leider ist auch heute Morgen der Mosquitto Dienst abgeschmiert, wie in letzter Zeit immer öfter am 1. Tag des Monats:

Außerdem waren wir heute Morgen nicht auf Zack, so dass die Störung bis 10:54 Uhr CET anhielt. Herzlichen Dank an dieser Stelle an @thias für die Entstörung!

Auch diesmal hat die Überwachung per Monit den Ausfall zwar feststellen können (process is not running), der Mechanismus zum automatischen Neustart hat jedoch versagt (failed to start (exit status 0) -- no output). Schade! Entschuldigt bitte die Unannehmlichkeiten.

2

In der Logdatei /var/log/mosquitto/mosquitto.log findet sich zur relevanten Zeit (Thursday, November 1, 2018 6:52:04 AM GMT+01:00) der lapidare Eintrag

1541051524: mosquitto version 1.5.3 terminating
3

journalctl -u mosquitto reveals a bit more information:

Nov 01 06:52:04 elbanco systemd[1]: Stopping LSB: mosquitto MQTT v3.1 message broker...
Nov 01 06:52:04 elbanco mosquitto[22355]: Stopping network daemon:: mosquitto.
Nov 01 06:52:04 elbanco systemd[1]: Starting LSB: mosquitto MQTT v3.1 message broker...
Nov 01 06:52:04 elbanco mosquitto[22364]: Starting network daemon:: mosquitto.
Nov 01 06:52:04 elbanco systemd[1]: Started LSB: mosquitto MQTT v3.1 message broker.
Nov 01 06:53:15 elbanco systemd[1]: Started LSB: mosquitto MQTT v3.1 message broker.
Nov 01 06:55:45 elbanco systemd[1]: Started LSB: mosquitto MQTT v3.1 message broker.
Nov 01 06:58:16 elbanco systemd[1]: Started LSB: mosquitto MQTT v3.1 message broker.
Nov 01 07:00:46 elbanco systemd[1]: Started LSB: mosquitto MQTT v3.1 message broker.
Nov 01 07:03:16 elbanco systemd[1]: Started LSB: mosquitto MQTT v3.1 message broker.
Nov 01 07:05:46 elbanco systemd[1]: Started LSB: mosquitto MQTT v3.1 message broker.
[...]
Nov 01 10:36:08 elbanco systemd[1]: Started LSB: mosquitto MQTT v3.1 message broker.
Nov 01 10:38:38 elbanco systemd[1]: Started LSB: mosquitto MQTT v3.1 message broker.
Nov 01 10:41:09 elbanco systemd[1]: Started LSB: mosquitto MQTT v3.1 message broker.
Nov 01 10:43:39 elbanco systemd[1]: Started LSB: mosquitto MQTT v3.1 message broker.
Nov 01 10:44:10 elbanco systemd[1]: Stopping LSB: mosquitto MQTT v3.1 message broker...
Nov 01 10:44:10 elbanco mosquitto[14841]: Stopping network daemon:: mosquitto.
Nov 01 10:44:10 elbanco systemd[1]: Starting LSB: mosquitto MQTT v3.1 message broker...
Nov 01 10:44:10 elbanco mosquitto[14850]: Starting network daemon:: mosquitto.
Nov 01 10:44:10 elbanco systemd[1]: Started LSB: mosquitto MQTT v3.1 message broker.
4

Haben die upgrades etwas mit der Lösung des Problems zu tun oder habt ihr das nur prophylaktisch gemacht?

Die Ausstiegszeiten schauen schon lustig aus. Haben wir irgendwelche Services laufen, die am 1. jeden Monats starten und sich dann nach ein paar Stunden totlaufen oder den Mosquitto crashen? Backups, neu angelegte / gerefreshte Dashboards, …?

5

Wir sind weiterhin ratlos, was die Kernursache angeht. Deswegen…

Ja, genau.

Weitere Gedanken

Der naheliegendste Kandidat für solche Phänomene ist sicherlich die Logfile Rotation. Die läuft allerdings täglich und ist dabei meistens erfolgreich, das kann also nicht die Primärursache sein.

Ich tippe auf ungünstige systemd Geschichten, wir kennen solche Phänomene auch von anderen Servern. Nach dem Upgrade werden wir dann von systemd Version 215 (jessie) auf Version 232 (stretch) oder ggf. sogar 239 (stretch-backports) gehen können.

Darüber hinaus haben wir beim letzten Mal festgestellt, dass Mosquitto auf einem »Debian GNU/Linux 8 (jessie)«, scheinbar noch per SysVinit ( /etc/init.d/mosquitto ) gestartet und verwaltet wird. Vielleicht wird das alles auf einem neuen Debian besser, ansonsten gehen wir vielleicht auf den von Debian mitgelieferten Mosquitto Dienst mit Version 1.4.10 zurück, derzeit beziehen wir das Paket direkt von mosquitto.org (aktuell in der Version 1.5.3).

Falls das noch nicht automatisch so ausgeliefert wird, könnten wir die systemd unit Ansteuerung auch selbst umsetzen, im Quelltext Repository von Mosquitto finden sich bereits entsprechende Blaupausen bei mosquitto/service/systemd at master · eclipse/mosquitto · GitHub.

6

Ich hab gerade die aktuelleren 1.4.15er und 1.5.3er Pakete überprüft: Alle liefern die Datei /etc/init.d/mosquitto aus und sind damit weiterhin SysVinit orientiert.

Allerdings wird der automatisch generierte systemd wrapper unter Debian stretch leicht anders aussehen als unter Debian jessie:

# Automatically generated by systemd-sysv-generator

[Unit]
Documentation=man:systemd-sysv-generator(8)
SourcePath=/etc/init.d/mosquitto
Description=LSB: mosquitto MQTT v3.1 message broker
Before=multi-user.target
Before=multi-user.target
Before=multi-user.target
Before=graphical.target
After=remote-fs.target

[Service]
Type=forking
Restart=no
TimeoutSec=5min
IgnoreSIGPIPE=no
KillMode=process
GuessMainPID=no
RemainAfterExit=yes
SuccessExitStatus=5 6
ExecStart=/etc/init.d/mosquitto start
ExecStop=/etc/init.d/mosquitto stop
ExecReload=/etc/init.d/mosquitto reload