MQTT inputs not updating at startup using older Pi Model B / pi-zero

phil.turner2768 · 1 August 2016 17:16

I have the latest software version installed on a 256MB ram version Raspberry Pi, with a RFM12Pi module. I have altered the setup so that the o/s runs from a usb flash drive and have also had to edit the emonhub config file to change the baud rate to 9600. From this point, the three nodes that I have become visible on the inputs page of emoncms. After a period of time though (the length of time varies) the data stops updating as indicated by the “updated” time. The led on the RFM12Pi is still flashing, indicating that the data is still being received.

Could it be that the software has outgrown my dated hardware?

glyn.hudson · 1 August 2016 21:17

Emonhub and emoncms should work fine on your Pi. Are you running a pre-built card image? If not I recommend trying the latest 03May16 emonSD card image. Please post your emonhub.log

phil.turner2768 · 1 August 2016 21:44

I am using the latest pre built card image.
emonhub.log.txt (1.1 MB)

glyn.hudson · 2 August 2016 00:28

Great, it looks like emonhub is working nicely. I can see data being successful received from your emonTx (node 10) and posted to mqtt.

Next step: does your emoncms.log give any insight?

Try restarting mqtt process

sudo service mqtt_input restart

phil.turner2768 · 2 August 2016 10:32

I didn’t get much time to fully look at the logs this morning, but I didn’t see anything that stood out. I will reboot the Pi this evening a post a copy of the log.

Restarting the mqtt process seems to have got the inputs updating again, they have been updating now for a couple of hours. Again, I will check this evening when get back home.

Thanks again for your help.

phil.turner2768 · 2 August 2016 21:39

Inputs were still updating some ten hours after restarting the mqtt process, so thats good. I rebooted the Pi and the same pattern occured, initially the inputs were updating but then stopped. The Pi then becomes somewhat unresponsive for a while. At about ten minutes after booting, I can restart the mqtt process and the inputs start updating again. I have attached the emoncms.log which is for the first ten minutes after boot.emoncms.log.txt (29.7 KB)

glyn.hudson · 2 August 2016 23:10

Interesting your logfile shows mqtt process connecting then quickly disconnecting from the mqtt server.

Could you post the output of these following commands:

$ ls /boot | grep emonSD

And

$ mosquitto -v
$ php -v

phil.turner2768 · 2 August 2016 23:20

emonSD-03May16

mosquitto version 1.4.8 (build date Sun, 14 Feb 2016 15:06:55 +0000) starting
1470179859: Using default config.
1470179860: Opening ipv4 listen socket on port 1883.
1470179860: Error: Address already in use

PHP 5.6.20-0+deb8u1 (cli) (built: Apr 28 2016 00:01:26)
Copyright (c) 1997-2016 The PHP Group
Zend Engine v2.6.0, Copyright (c) 1998-2016 Zend Technologies
with Zend OPcache v7.0.6-dev, Copyright (c) 1999-2016, by Zend Technologies

glyn.hudson · 3 August 2016 00:09

Those version numbers look fine. However there are more recent versions of mosquitto and php. Pleae try a apt-get update and upgrade to see if this helps.

We have done most of our testing on Pi3 but there is no reason why the pre built sd card setup should not work on an older Pi. The system is not very processor or ram intensive. Can you see in local emoncms admin how much ram and disk space is free?

phil.turner2768 · 3 August 2016 00:19

Ok, will try the update/upgrade later today.

I have zram enabled, not sure if it’s a help or hindrance.

Memory RAM
Used 93.41%
Total: 228.96 MB Used: 213.86 MB Free: 15.09 MB
Swap
Used 80.33%
Total: 64 MB Used: 51.41 MB Free: 12.59 MB
Disk Mount Stats
/
Used 3.87%
Total: 57.02 GB Used: 2.21 GB Free: 52.33 GB
/boot
Used 33.22%
Total: 59.95 MB Used: 19.91 MB Free: 40.03 MB
/home/pi/data
Used 16.05%
Total: 193.66 MB Used: 31.09 MB Free: 152.58 MB

Bill.Thomson · 3 August 2016 03:08

Glyn,

Correct me if I’m wrong. Isn’t the error indicating a port conflict?

glyn.hudson · 3 August 2016 08:50

The command mosquitto -v seems to try and fire up another mosquitto server instance which obviously fails since the mosquitto server is already running on port 1883. Nothing to worry about.

Disk space and ram don’t look out of the ordinary. Most of your ram is used but this is to be expected given you only have 250Mb.

I can’t see anything out of the ordinary with your setup. The only difference is the model of Pi you’re using. Since you say this issue only effects the mqtt process on startup, then after a mqtt-input service restart all is fine, maybe it’s just some sort of race condition at setup where mqtt-input tries to connect to the mqtt server before it’s ready. This is not an issue on pi3 since process startup is much faster. You could try adding a delay to step mqtt-input later or add in a delay to restart the service a number of seconds after startup.

phil.turner2768 · 3 August 2016 08:53

I have for now added a longer delay.

Thanks again for your input.

MikeSims · 3 August 2016 11:30

I have been having the same issue, except that it happens long after bootup. Previously I just rebooted the Pi. It just happened again this morning, 19 days after the last reboot, and I have just tried restarting the mqtt_input service as you suggested and it is working fine again.

My system is a WiFi-dongled RPi0 connected serially to an adjacent Arduino Uno with an EmonTxv2.4 radioless shield, with the Pi0 running the 3May2016 emonPi image. This system appears to be completely stable apart from this one issue. It monitors one CT, plus the voltage, and a reedswitch-pulse-based gas meter. The only tweaks are for a custom MyDualfuel webapp which is just a straight rip off of the MySolarPV web app. The Pi0’s Tx pin is not connected, so no possibility for my customised CM firmware to be inadvertently overwritten.

I had suspected that mqtt was probably the culprit, but wasn’t sure how to proceed (yet another learning curve!).

glyn.hudson · 3 August 2016 13:46

Could you provide details of how you have added this delay so @MikeSims can also implement? We could look at including the delay in the default setup since it would not really adversely effect Pi3 users

MikeSims · 3 August 2016 14:39

My versions of mosquitto and php are the same as Phil’s, so I am also carrying out a sudo apt-get update and upgrade, however unlike Phil’s issue, startup has not been a problem, just a days-long delay until mqtt drops out, 19 days was the last time after reboot, and previous delays were similar in length.

I note that my mqtt also has multiple attempts to connect to emon/# at startup, but only over a couple of minutes then it settles down.

2016-07-15 07:27:27.815|WARN|phpmqtt_input.php|Subscribed to topic: emon/#
2016-08-03 09:09:21.128|WARN|phpmqtt_input.php|Disconnected cleanly
2016-08-03 09:09:24.400|WARN|phpmqtt_input.php|Subscribing to: emon/#
2016-08-03 09:09:26.814|WARN|phpmqtt_input.php|Not connected, retrying connection
2016-08-03 09:09:29.344|WARN|phpmqtt_input.php|Connecting to MQTT server: Connection Accepted.: code: 0
2016-08-03 09:09:33.053|WARN|phpmqtt_input.php|Subscribed to topic: emon/#
2016-08-03 09:09:34.761|WARN|phpmqtt_input.php|Disconnected cleanly
2016-08-03 09:09:38.953|WARN|phpmqtt_input.php|Subscribing to: emon/#
2016-08-03 09:09:41.684|WARN|phpmqtt_input.php|Not connected, retrying connection
2016-08-03 09:09:45.262|WARN|phpmqtt_input.php|Connecting to MQTT server: Connection Accepted.: code: 0
2016-08-03 09:09:50.712|WARN|phpmqtt_input.php|Subscribed to topic: emon/#
2016-08-03 09:09:54.904|WARN|phpmqtt_input.php|Disconnected cleanly
2016-08-03 09:10:01.576|WARN|phpmqtt_input.php|Subscribing to: emon/#
2016-08-03 09:10:08.393|WARN|phpmqtt_input.php|Not connected, retrying connection
2016-08-03 09:10:16.646|WARN|phpmqtt_input.php|Connecting to MQTT server: Connection Accepted.: code: 0
2016-08-03 09:10:19.138|WARN|phpmqtt_input.php|Disconnected cleanly
2016-08-03 09:10:24.031|WARN|phpmqtt_input.php|Subscribing to: emon/#
2016-08-03 09:10:29.043|WARN|phpmqtt_input.php|Not connected, retrying connection
2016-08-03 09:10:38.264|WARN|phpmqtt_input.php|Connecting to MQTT server: Connection Accepted.: code: 0
2016-08-03 09:10:49.084|WARN|phpmqtt_input.php|Subscribed to topic: emon/#
2016-08-03 10:38:34.840|WARN|phpmqtt_input.php|Starting MQTT Input script       It was around here I noticed the issue
2016-08-03 10:38:36.160|WARN|phpmqtt_input.php|Subscribing to: emon/#
2016-08-03 10:38:36.167|WARN|phpmqtt_input.php|Not connected, retrying connection
2016-08-03 10:38:36.168|WARN|phpmqtt_input.php|Connecting to MQTT server: Connection Accepted.: code: 0
2016-08-03 10:38:36.170|WARN|phpmqtt_input.php|Subscribed to topic: emon/#

MikeSims · 3 August 2016 17:13

After the update/upgrade mentioned in the previous post, I had to reboot as the feedwriter had stopped immediately after the upgrade, but mqtt connected virtually instantly;

PHP is now Version5.6.24-0+deb8u1 (Zend Version 2.6.0),
mosquitto version 1.4.9 (build date Fri, 03 Jun 2016 09:02:12 +0100)

Will just have to watch it for a while to see if the problem recurs.

phil.turner2768 · 3 August 2016 21:50

Glyn,

I’ve simply increased the sleep period but put it in a script (there are better ways to do this)

#!/bin/bash # $1：delay time in seconds

$2：command

delay 480 “service mqtt_input restart”

sleep $1
exec $2

I’ve called it ‘delay’ and i’ve put it in the /home/pi folder. I then run it from /etc/rc.local

In rc.local i’ve commented out the bottom two lines:

sleep 5
service mqtt_input restart

And after those two lines i’ve added:

/home/pi/delay

I don’t think that will help Mike though, as the issue occurs for him after some time (days)

glyn.hudson · 4 August 2016 00:50

Just had a look there is already a 5-second sleep before mqtt_input is started in rc.local. I will increase this to 20s. This should be plenty. You can pull in the changes by running emonPi update from local emoncms admin menu

github.com

openenergymonitor/emonpi/blob/master/rc.local_jessieminimal#L28

    
      
          for i in "emoncms.log" "mysql.log" "mqtt_input.log" "redis/redis-server.log" "service-runner.log" "mysql/error.log" "apache2/error.log" "supervisor/supervisord.log" "ntp_update.log"; do touch /var/log/"$i"; done
          for i in "emoncms.log" "mysql.log" "mqtt_input.log" "redis/redis-server.log" "service-runner.log" "mysql/error.log" "apache2/error.log" "supervisor/supervisord.log" "ntp_update.log"; do ""chmod 666"" /var/log/"$i"; done
          chown -R root:adm /var/log/apache2
          chown -R redis:redis /var/log/redis
          chown -R mysql:adm /var/log/mysql
          chown -R openhab:openhab /var/log/openhab
          chown -R pi:pi /var/log/logrotate
          chown -R mosquitto:mosquitto /var/log/mosquitto
          chown -R dataplicity:dataplicity /var/log/supervisor;
          chown -R emonhub:emonhub /var/log/emonhub
          chown -R pi:pi /var/log/emoncms
          
          
touch /home/pi/data/emonpiupdate.log
          ln -s /home/pi/data/emonpiupdate.log /var/log/emoncms/emonpiupdate.log
          
          
# Restart random seed process now ~/data RW partition has been mounted 
          sudo systemctl restart systemd-random-seed.service
          
          
# Start / Restart services,they should run happy now log dir's are created
          sleep 3
          service mysql restart