Wir haben heute morgen festgestellt, dass der Mosquitto Dienst spontan kaputtgegangen ist, genauso wie beim Ausfall der Datenannahme am 1. Juli 2018 um 06:45 Uhr. @einsiedlerkrebs hat ihn dann neugestartet (vielen Dank dafür!) und seither sollte wieder alles einwandfrei laufen. Wir werden uns in Folge darum kümmern, ihn genauer zu überwachen und ggf. automatisch neuzustarten. Dafür eignet sich der Klassiker “Monit” hervorragend.
Entschuldigt bitte die Unannehmlichkeiten!
Viele Grüße vom Hiveeyes Team.
P.S.: Hier die Meldungen zu dem Vorfall aus unserem Monitoringsystem:
Hier nochmal rückblickend die Analyse des mosquitto.log zum besagten Zeitpunkt am Saturday, September 1, 2018, die Uhrzeiten sind jeweils AM GMT+02:00 DST, alle identifizierenden Merkmale wurden anonymisiert:
Zeitpunkt des Crashs?
# 06:51:02 AM
1535777462: New connection from 80.135.176.42 on port 1883.
# 06:52:05 AM
1535777525: mosquitto version 1.5 starting
1535777525: Config loaded from /etc/mosquitto/mosquitto.conf.
1535777525: Opening ipv4 listen socket on port 1883.
1535777525: Error: Address already in use
# 06:51:02 AM
1535777462: Client b7873cc2-9814-4ccc-ba41-91855c208e1e already connected, closing old connection.
1535777462: Socket error on client b7873cc2-9814-4ccc-ba41-91855c208e1e, disconnecting.
1535777462: New client connected from 80.135.176.42 as b7873cc2-9814-4ccc-ba41-91855c208e1e (c1, k300, u'user2').
# 06:52:05 AM
1535777525: mosquitto version 1.5 terminating
Manueller Neustart
# 10:08:06 AM
1535789286: mosquitto version 1.5 starting
1535789286: Config loaded from /etc/mosquitto/mosquitto.conf.
1535789286: Opening ipv4 listen socket on port 1883.
1535789286: Opening ipv6 listen socket on port 1883.
Bewertung
Ich werde aus den Einträgen im Logfile nicht ganz schlau. Der Mosquitto Dienst will um 06:52:05 AM starten, was jedoch per Error: Address already in use fehlschlägt. Eigentlich müsste er zu diesem Zeitpunkt noch laufen, woher kommt also das Signal zum nochmaligen Starten? Auch die Fehlermeldung weist ja darauf hin, dass der Dienst weiterhin läuft und den Port (1883) gebunden hat. Auf jeden Fall terminiert der Dienst dann in Folge des aufgetretenen Fehlers und bleibt scheinbar aus. Hm.
P.S.: Die Einträge im Logfile sind in der exakten Reihenfolge wiedergegeben wie dargestellt. Dass sie nicht in dieser Reihenfolge aufgetreten sein können, sieht man an den Zeitstempeln. Die krumme Reihenfolge liegt vermutlich an internen Mechanismen wie Logfile Buffering, so we are probably Suffering from Buffering? here. No matter what, the Mosquitto service finally seems to get terminated by Murphy, so we will just take care of this.
check process mosquitto with pidfile /var/run/mosquitto.pid
start = "/bin/systemctl start mosquitto"
stop = "/bin/systemctl stop mosquitto"
if failed port 1883 then restart
Es wird nun alle zwei Minuten geprüft, ob a) der Mosquitto Dienst noch läuft und b) auf Port 1883 antwortet. Falls nicht, wird er neugestartet.
In mosquitto 1.4.x gab es im letzten Jahr den bug CVE-2017-7652, der bei einigen Ubuntu-basierenden distros mit z.B. 1.4.8 erst jüngst ausgebügelt wurde - daran erinnerte mich das zuerst.
Nun sehe ich aber, daß das inzwischen 1.5 ist, Du schriebst zuletzt, daß eine 1.4.10 installiert wurde, da debian stable, - und nun eine 1.5 ?! Wolltest Du 1.4.15 nicht mehr installieren und hast gleich eine 1.5.x gebaut (1.5 oder 1.5.1)?
Jedenfalls scheint es bei 1.5(.0) eine regression zu geben (bug tracker: #825, #882), dessen Vermeidung liest sich hart:
As a work around, comment out the listener 1883 section.
Inwiefern da zur Zeit ein erwähnter systemd-Bug noch mit eine Rolle spielt, kann ich nicht einschätzen. - Wenn 1.5 sein muß, dann gleich die 1.5.1 draus machen.
root@elbanco:~# cat /etc/apt/sources.list.d/mosquitto-jessie.list
deb http://repo.mosquitto.org/debian jessie main
Da sollte also eigentlich die aktuellste Version anliegen. Die Dateien mosquitto, mosquitto_pub, und mosquitto_sub auf der Maschine sind vom 8. August - das klingt recht in Ordnung?
systemd woes
Das System ist ein »Debian GNU/Linux 8 (jessie)«, da wird Mosquitto scheinbar noch per SysVinit (/etc/init.d/mosquitto) gestartet. Hier ist weit und breit kein entsprechendes natives systemd unit file zu sehen. Einzig der folgende automatisch generierte Wrapper ist wohl im Einsatz:
Korrektur: Die 1.5.1er kam erst am 16. August raus, ergo läuft hier vermutlich noch die Mosquitto Version 1.5.0. JP wartet ebenfalls schon auf ein neues Debian Paket:
