I’ve had problems with the inputs on my EmonBase, so I decided do a full restore of the system and reset the SD-card to a fresh Build. Well, said and done the reinstallation went fine but when everything is up I still have errors relating to MQTT
This comes from the log, when just having booted up
LAST ENTRIES ON THE LOG FILE
2018-04-29 14:57:52.412|ERROR|phpmqtt_input.php|exception 'Mosquitto\Exception' in /var/www/emoncms/scripts/phpmqtt_input.php:125
Stack trace:
#0 /var/www/emoncms/scripts/phpmqtt_input.php(125): Mosquitto\Client->connect('localhost', 1883, 5)
#1 {main}
2018-04-29 14:57:52.561|WARN|phpmqtt_input.php|Not connected, retrying connection
2018-04-29 14:57:58.001|WARN|phpmqtt_input.php|Not connected, retrying connection
2018-04-29 14:57:58.006|WARN|phpmqtt_input.php|Connecting to MQTT server: Connection Accepted.: code: 0
2018-04-29 14:58:06.210|WARN|phpmqtt_input.php|Not connected, retrying connection
2018-04-29 14:58:06.240|WARN|phpmqtt_input.php|Connecting to MQTT server: Connection Accepted.: code: 0
2018-04-29 15:01:11.662|WARN|phpmqtt_input.php|Not connected, retrying connection
2018-04-29 15:01:11.681|WARN|phpmqtt_input.php|Connecting to MQTT server: Connection Accepted.: code: 0
Check emonhub.log either via the emoncms - emonhub config page or by checking the files at /var/log/emonhub/emonhub.log
Can you also uncollapse one of your inputs on the input page of emoncms and check for duplicated inputs, ie 2 complete sets of inputs under one heading, the first set not updating and the second set in green.
Luckily the emonhub.log is still found in the same place on all linux based installs at /var/log/emonhub/emonhub.log.
Although I’m not entirely sure the “Active: active (exited)” is indicative of a failed or stopped service, we see this quite frequently (eg emonPi hangs and stops logging - #38 by borpin). I’m tempted to say it’s more likely to be linked to the fact the emonhub and feedwriter services are systemV init scripts being run in “compatibility mode” by systemd, but I cannot be sure. Both Mosquitto and mqtt_input services are systemd units.
Looking at the “server information” that shows the feedwriter as running and I see no “errors” in the short log attached to the emonhub service status, only some valid start up lines and the last entry is a keyboard interrupt. @Daniel_Edvall have you manually stopped the emonhub service to try minicom?
What I do find interesting is that both the emonhub and mqtt_input services are only running 6mins were as the other 2 are running 15hours, @Daniel_Edvall did something significant ocurr 6mins before checking the statuses? eg running the emonpi update again.
It’s always been an issue since MQTT was first implemented, the apparent changes in frequency have been due to other issues coming and going so more or less logs are seen, and at some point the code was changed so the errors weren’t logged but the problem has always been there.
Presumably you mean since MQTT was implemented in emonhub. I use the HTTP API from emonhub without issue and MQTT for other inputs. I do not see these connections/disconnections so it implies it is an emonhub implementation of MQTT rather than the emoncms side (though the 2 could be interacting to cause the issues).
Sorry, yes, I should have been clearer. It has always been a problem since MQTT was implemented on the emonPi, the mqtt implementation in emonhub and emoncms were rolled out together and both parts have been replaced/rewritten since their original release.
I do not know what part is at fault for this specific issue, I just know that both parts are “not right” for various reasons and together they have a problem on the emonSD image. I assume that the Mosquito broker or MQTT in general isn’t to blame but the emonPi image also has openHab and nodered and emonLCD etc that I’m not familiar with, but I have seen error logs showing they have issues too, but is that a cause or effect? chicken and egg situation!
That is how the emoncms admin page is updated with the feedwriter service status. The systend status check should be the correct way of checking, we just need to learn how to interpret the messages with some confidence and perhaps make some changes so they work correctly if necessary.
I just did some very basic tests and I now suspect emonhub is NOT running. Despite the other occurances, I have not been able to recreate emonhub running and observe a “Active: active (exited)” service (although I wouldn’t class my tests as conclusive) but what I have noticed is the way the log entries seem to work and the service log seems to show a keyboard interrupt. I suspect that can only occur if emonhub is started from the command line using
/usr/share/emonhub/emonhub.py
and then stopping that instance with CTRL-C.
BUT that might then refer to the command line instance not the daemon. I think we need to know more about what @Daniel_Edvall has been trying.
sudo service xyz status and sudo systemctl status xyz should return the same data as they are doing the same job, the 1st is just to offer backward compatibility. eg
pi@emonpi(rw):~$ sudo service emonhub status
â emonhub.service - LSB: Start/stop emonHub
Loaded: loaded (/etc/init.d/emonhub)
Active: active (running) since Mon 2018-04-30 10:49:31 UTC; 18min ago
Process: 9273 ExecStop=/etc/init.d/emonhub stop (code=exited, status=0/SUCCESS)
Process: 9826 ExecStart=/etc/init.d/emonhub start (code=exited, status=0/SUCCESS)
CGroup: /system.slice/emonhub.service
ââ9876 python /usr/share/emonhub/emonhub.py --config-file /home/pi/data/emonhub.conf --logfile /var/log/emonhub/emonhub.log
Apr 30 10:49:30 emonpi sudo[9836]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 30 10:49:30 emonpi sudo[9836]: pam_unix(sudo:session): session closed for user root
Apr 30 10:49:30 emonpi sudo[9847]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown -R emonhub /var/log/emonhub
Apr 30 10:49:30 emonpi sudo[9847]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 30 10:49:30 emonpi sudo[9847]: pam_unix(sudo:session): session closed for user root
Apr 30 10:49:30 emonpi sudo[9856]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown -R emonhub /var/log/emonhub
Apr 30 10:49:31 emonpi sudo[9856]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 30 10:49:31 emonpi sudo[9856]: pam_unix(sudo:session): session closed for user root
Apr 30 10:49:31 emonpi emonhub[9826]: Starting OpenEnergyMonitor emonHub: emonhub has been started ok.
Apr 30 10:49:31 emonpi systemd[1]: Started LSB: Start/stop emonHub.
pi@emonpi(rw):~$ sudo systemctl status emonhub
â emonhub.service - LSB: Start/stop emonHub
Loaded: loaded (/etc/init.d/emonhub)
Active: active (running) since Mon 2018-04-30 10:49:31 UTC; 18min ago
Process: 9273 ExecStop=/etc/init.d/emonhub stop (code=exited, status=0/SUCCESS)
Process: 9826 ExecStart=/etc/init.d/emonhub start (code=exited, status=0/SUCCESS)
CGroup: /system.slice/emonhub.service
ââ9876 python /usr/share/emonhub/emonhub.py --config-file /home/pi/data/emonhub.conf --logfile /var/log/emonhub/emonhub.log
Apr 30 10:49:30 emonpi sudo[9836]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 30 10:49:30 emonpi sudo[9836]: pam_unix(sudo:session): session closed for user root
Apr 30 10:49:30 emonpi sudo[9847]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown -R emonhub /var/log/emonhub
Apr 30 10:49:30 emonpi sudo[9847]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 30 10:49:30 emonpi sudo[9847]: pam_unix(sudo:session): session closed for user root
Apr 30 10:49:30 emonpi sudo[9856]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown -R emonhub /var/log/emonhub
Apr 30 10:49:31 emonpi sudo[9856]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 30 10:49:31 emonpi sudo[9856]: pam_unix(sudo:session): session closed for user root
Apr 30 10:49:31 emonpi emonhub[9826]: Starting OpenEnergyMonitor emonHub: emonhub has been started ok.
Apr 30 10:49:31 emonpi systemd[1]: Started LSB: Start/stop emonHub.
pi@emonpi(rw):~$
Well, uhm, the inactive feeds now seems to be active again. My procedure:
Shut down the PI and with surgial precision made sure that the RFM69Pi module were inserted properly. This time I also made shure the LED on RFM69Pi lighted up on boot, and sometimes blinked. What was different this time other than this, compared to the other 10 times I’ve done this, I do not know, but upon boot the feeds kicked alive and started recieving data.
Out if interest, you still want me to give some logs and statuses? @pb66, @borpin
