Hello,
I just upgraded my emonpi following instructions here : emonPi KRACK fix and upgraded emonpi/emonbase using web GUI.
But, at boot time, Mosquitto wouldn’t start. After some investigation reading this : Mosquitto not starting after emonSD update & upgrade - #18 by jeremypoulter and this : MQTT Log files - #9 by glyn.hudson, checking the rc.local_jessieminima
had been properly updated, and the log file directory was properly created, I had a look at the service startup logs :
pi@emonpi(ro):mosquitto$ sudo journalctl -u mosquitto
-- Logs begin at Tue 2017-11-07 22:09:42 CET, end at Tue 2017-11-07 22:27:13 CET. --
Nov 07 22:09:44 emonpi systemd[1]: Starting Mosquitto MQTT Broker...
Nov 07 22:09:44 emonpi systemd[1]: Started Mosquitto MQTT Broker.
Nov 07 22:09:44 emonpi mosquitto[515]: 1510088984: Error: Unable to open log file /var/log/mosquitto/mosquitto.log for writing.
Nov 07 22:09:45 emonpi systemd[1]: mosquitto.service: main process exited, code=exited, status=1/FAILURE
Nov 07 22:09:45 emonpi systemd[1]: Unit mosquitto.service entered failed state.
Nov 07 22:09:45 emonpi systemd[1]: mosquitto.service holdoff time over, scheduling restart.
Nov 07 22:09:45 emonpi systemd[1]: Stopping Mosquitto MQTT Broker...
Nov 07 22:09:45 emonpi systemd[1]: Starting Mosquitto MQTT Broker...
Nov 07 22:09:45 emonpi systemd[1]: Started Mosquitto MQTT Broker.
Nov 07 22:09:45 emonpi mosquitto[625]: 1510088985: Error: Unable to open log file /var/log/mosquitto/mosquitto.log for writing.
Nov 07 22:09:45 emonpi systemd[1]: mosquitto.service: main process exited, code=exited, status=1/FAILURE
Nov 07 22:09:45 emonpi systemd[1]: Unit mosquitto.service entered failed state.
Nov 07 22:09:45 emonpi systemd[1]: mosquitto.service holdoff time over, scheduling restart.
Nov 07 22:09:45 emonpi systemd[1]: Stopping Mosquitto MQTT Broker...
Nov 07 22:09:45 emonpi systemd[1]: Starting Mosquitto MQTT Broker...
Nov 07 22:09:45 emonpi systemd[1]: Started Mosquitto MQTT Broker.
Nov 07 22:09:45 emonpi mosquitto[690]: 1510088985: Error: Unable to open log file /var/log/mosquitto/mosquitto.log for writing.
Nov 07 22:09:45 emonpi systemd[1]: mosquitto.service: main process exited, code=exited, status=1/FAILURE
Nov 07 22:09:45 emonpi systemd[1]: Unit mosquitto.service entered failed state.
Nov 07 22:09:45 emonpi systemd[1]: mosquitto.service holdoff time over, scheduling restart.
Nov 07 22:09:45 emonpi systemd[1]: Stopping Mosquitto MQTT Broker...
Nov 07 22:09:45 emonpi systemd[1]: Starting Mosquitto MQTT Broker...
Nov 07 22:09:45 emonpi systemd[1]: Started Mosquitto MQTT Broker.
Nov 07 22:09:45 emonpi mosquitto[715]: 1510088985: Error: Unable to open log file /var/log/mosquitto/mosquitto.log for writing.
Nov 07 22:09:45 emonpi systemd[1]: mosquitto.service: main process exited, code=exited, status=1/FAILURE
Nov 07 22:09:45 emonpi systemd[1]: Unit mosquitto.service entered failed state.
Nov 07 22:09:46 emonpi systemd[1]: mosquitto.service holdoff time over, scheduling restart.
Nov 07 22:09:46 emonpi systemd[1]: Stopping Mosquitto MQTT Broker...
Nov 07 22:09:46 emonpi systemd[1]: Starting Mosquitto MQTT Broker...
Nov 07 22:09:46 emonpi systemd[1]: Started Mosquitto MQTT Broker.
Nov 07 22:09:46 emonpi mosquitto[790]: 1510088986: Error: Unable to open log file /var/log/mosquitto/mosquitto.log for writing.
Nov 07 22:09:46 emonpi systemd[1]: mosquitto.service: main process exited, code=exited, status=1/FAILURE
Nov 07 22:09:46 emonpi systemd[1]: Unit mosquitto.service entered failed state.
Nov 07 22:09:46 emonpi systemd[1]: mosquitto.service holdoff time over, scheduling restart.
Nov 07 22:09:46 emonpi systemd[1]: Stopping Mosquitto MQTT Broker...
Nov 07 22:09:46 emonpi systemd[1]: Starting Mosquitto MQTT Broker...
Nov 07 22:09:46 emonpi systemd[1]: mosquitto.service start request repeated too quickly, refusing to start.
Nov 07 22:09:46 emonpi systemd[1]: Failed to start Mosquitto MQTT Broker.
Nov 07 22:09:46 emonpi systemd[1]: Unit mosquitto.service entered failed state.
Nov 07 22:09:51 emonpi systemd[1]: Starting Mosquitto MQTT Broker...
Nov 07 22:09:51 emonpi systemd[1]: mosquitto.service start request repeated too quickly, refusing to start.
Nov 07 22:09:51 emonpi systemd[1]: Failed to start Mosquitto MQTT Broker.
The last try (the one done by rc script I think) occurs 5 seconds after the “throttling” (5 restart in 10 secs by default)
If I finally start the service manually it works
Nov 07 22:14:13 emonpi systemd[1]: Starting Mosquitto MQTT Broker...
Nov 07 22:14:13 emonpi systemd[1]: Started Mosquitto MQTT Broker.
So I just added a sleep just before the services restart in rc.local_jessieminima
# Restart services,they should run happy now log dir's are created
sleep 11
service apache2 restart
service redis-server restart
service mosquitto restart
service supervisor restart
And voila ! It works again on boot
-- Logs begin at Tue 2017-11-07 22:37:51 CET, end at Tue 2017-11-07 22:39:07 CET. --
Nov 07 22:37:53 emonpi systemd[1]: Starting Mosquitto MQTT Broker...
Nov 07 22:37:53 emonpi systemd[1]: Started Mosquitto MQTT Broker.
Nov 07 22:37:53 emonpi mosquitto[519]: 1510090673: Error: Unable to open log file /var/log/mosquitto/mosquitto.log for writing.
Nov 07 22:37:54 emonpi systemd[1]: mosquitto.service: main process exited, code=exited, status=1/FAILURE
Nov 07 22:37:54 emonpi systemd[1]: Unit mosquitto.service entered failed state.
Nov 07 22:37:54 emonpi systemd[1]: mosquitto.service holdoff time over, scheduling restart.
Nov 07 22:37:54 emonpi systemd[1]: Stopping Mosquitto MQTT Broker...
Nov 07 22:37:54 emonpi systemd[1]: Starting Mosquitto MQTT Broker...
Nov 07 22:37:54 emonpi systemd[1]: Started Mosquitto MQTT Broker.
Nov 07 22:37:54 emonpi mosquitto[624]: 1510090674: Error: Unable to open log file /var/log/mosquitto/mosquitto.log for writing.
Nov 07 22:37:54 emonpi systemd[1]: mosquitto.service: main process exited, code=exited, status=1/FAILURE
Nov 07 22:37:54 emonpi systemd[1]: Unit mosquitto.service entered failed state.
Nov 07 22:37:54 emonpi systemd[1]: mosquitto.service holdoff time over, scheduling restart.
Nov 07 22:37:54 emonpi systemd[1]: Stopping Mosquitto MQTT Broker...
Nov 07 22:37:54 emonpi systemd[1]: Starting Mosquitto MQTT Broker...
Nov 07 22:37:54 emonpi systemd[1]: Started Mosquitto MQTT Broker.
Nov 07 22:37:54 emonpi mosquitto[685]: 1510090674: Error: Unable to open log file /var/log/mosquitto/mosquitto.log for writing.
Nov 07 22:37:54 emonpi systemd[1]: mosquitto.service: main process exited, code=exited, status=1/FAILURE
Nov 07 22:37:54 emonpi systemd[1]: Unit mosquitto.service entered failed state.
Nov 07 22:37:54 emonpi systemd[1]: mosquitto.service holdoff time over, scheduling restart.
Nov 07 22:37:54 emonpi systemd[1]: Stopping Mosquitto MQTT Broker...
Nov 07 22:37:54 emonpi systemd[1]: Starting Mosquitto MQTT Broker...
Nov 07 22:37:54 emonpi systemd[1]: Started Mosquitto MQTT Broker.
Nov 07 22:37:54 emonpi mosquitto[700]: 1510090674: Error: Unable to open log file /var/log/mosquitto/mosquitto.log for writing.
Nov 07 22:37:54 emonpi systemd[1]: mosquitto.service: main process exited, code=exited, status=1/FAILURE
Nov 07 22:37:54 emonpi systemd[1]: Unit mosquitto.service entered failed state.
Nov 07 22:37:54 emonpi systemd[1]: mosquitto.service holdoff time over, scheduling restart.
Nov 07 22:37:54 emonpi systemd[1]: Stopping Mosquitto MQTT Broker...
Nov 07 22:37:54 emonpi systemd[1]: Starting Mosquitto MQTT Broker...
Nov 07 22:37:54 emonpi systemd[1]: Started Mosquitto MQTT Broker.
Nov 07 22:37:54 emonpi mosquitto[717]: 1510090674: Error: Unable to open log file /var/log/mosquitto/mosquitto.log for writing.
Nov 07 22:37:54 emonpi systemd[1]: mosquitto.service: main process exited, code=exited, status=1/FAILURE
Nov 07 22:37:55 emonpi systemd[1]: Unit mosquitto.service entered failed state.
Nov 07 22:37:55 emonpi systemd[1]: mosquitto.service holdoff time over, scheduling restart.
Nov 07 22:37:55 emonpi systemd[1]: Stopping Mosquitto MQTT Broker...
Nov 07 22:37:55 emonpi systemd[1]: Starting Mosquitto MQTT Broker...
Nov 07 22:37:55 emonpi systemd[1]: mosquitto.service start request repeated too quickly, refusing to start.
Nov 07 22:37:55 emonpi systemd[1]: Failed to start Mosquitto MQTT Broker.
Nov 07 22:37:55 emonpi systemd[1]: Unit mosquitto.service entered failed state.
Nov 07 22:38:22 emonpi systemd[1]: Starting Mosquitto MQTT Broker...
Nov 07 22:38:22 emonpi systemd[1]: Started Mosquitto MQTT Broker.
The last restart occurs after the 10 seconds of “throttling”
But I don’t like much adding “sleep” everywhere. Is there another way for correcting this ? Should I disable automatic start on boot so that the rc script only starts the services instead of restarting them ? Any drawbacks ?
Thanks.
JS