Mosquitto not starting after emonSD update & upgrade

nicklaws · 2016-09-21T01:43:47.853Z

Hello, I have purchased the pre-loaded SD card for my RPi 3, a RFM69, and a emonTx. The emonTx CTs are all hooked up and it is plugged in. I have followed all of the steps and trouble shooting tips, but it appears that my emonBase (updated today) is not connecting to the emonTx:

tail /var/log/emoncms.log

2016-09-21 01:40:40.000|WARN|phpmqtt_input.php|Not connected, retrying connection

sudo service emonhub status

● emonhub.service - LSB: Start/stop emonHub
   Loaded: loaded (/etc/init.d/emonhub)
   Active: active (running) since Wed 2016-09-21 01:17:15 UTC; 4min 40s ago
  Process: 496 ExecStart=/etc/init.d/emonhub start (code=exited, status=0/SUCCESS)
   CGroup: /system.slice/emonhub.service
           └─681 python /usr/share/emonhub/emonhub.py --logfile /var/log/emonhub/emonhub.log --c...

Sep 21 01:17:15 emonpi sudo[526]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 21 01:17:15 emonpi sudo[526]: pam_unix(sudo:session): session closed for user root
Sep 21 01:17:15 emonpi sudo[626]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chow...nhub
Sep 21 01:17:15 emonpi sudo[626]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 21 01:17:15 emonpi sudo[626]: pam_unix(sudo:session): session closed for user root
Sep 21 01:17:15 emonpi sudo[636]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chow...nhub
Sep 21 01:17:15 emonpi sudo[636]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 21 01:17:15 emonpi sudo[636]: pam_unix(sudo:session): session closed for user root
Sep 21 01:17:15 emonpi emonhub[496]: Starting OpenEnergyMonitor emonHub: emonhub has been st... ok.
Sep 21 01:17:15 emonpi systemd[1]: Started LSB: Start/stop emonHub.

tail /var/log/emonhub/emonhub.log

2016-09-21 01:22:26,309 INFO     MQTT       Could not connect...
2016-09-21 01:22:26,969 DEBUG    RFM2Pi     72 NEW FRAME : OK 8 0 0 232 255 114 0 4 0 223 48 184 11 184 11 184 11 184 11 184 11 184 11 1 0 0 0 (-37)
2016-09-21 01:22:26,971 DEBUG    RFM2Pi     72 Timestamp : 1474420946.97
2016-09-21 01:22:26,971 DEBUG    RFM2Pi     72 From Node : 8
2016-09-21 01:22:26,972 DEBUG    RFM2Pi     72    Values : [0, -24, 114, 4, 125.11, 300, 300, 300, 300, 300, 300, 1]
2016-09-21 01:22:26,972 DEBUG    RFM2Pi     72      RSSI : -37
2016-09-21 01:22:26,973 DEBUG    RFM2Pi     72 adding frame to buffer => [1474420946, 8, 0, -24, 114, 4, 125.11, 300, 300, 300, 300, 300, 300, 1, -37]
2016-09-21 01:22:26,973 DEBUG    RFM2Pi     72 Sent to channel' : ToEmonCMS
2016-09-21 01:22:27,419 INFO     MQTT       Connecting to MQTT Server
2016-09-21 01:22:27,420 INFO     MQTT       Could not connect...

Any tips?

nicklaws · 2016-09-21T02:27:03.912Z

PS emoncms shows “n/a” and “NaN” for the updated and value columns in inputs.

and minicom looks good?:
OK 8 0 0 246 255 53 0 5 0 6 49 184 11 184 11 184 11 184 11 184 11 184 11 1 0 0 0 (-53)
OK 8 0 0 245 255 52 0 5 0 254 48 184 11 184 11 184 11 184 11 184 11 184 11 1 0 0 0 (-53)
OK 8 0 0 246 255 52 0 5 0 5 49 184 11 184 11 184 11 184 11 184 11 184 11 1 0 0 0 (-54)
OK 8 0 0 245 255 51 0 5 0 22 49 184 11 184 11 184 11 184 11 184 11 184 11 1 0 0 0 (-50)

pb66 · 2016-09-21T07:28:38.454Z

Hi Nick,

I moved your posts to this new thread (from Connecting emonBase and emonTx) as the issue isn’t an emontx to emonbase issue, but a problem with MQTT, Your first log shows emoncms is not connected to MQTT and the 3rd one shows emonhub cannot connect either.

The minicom output and the emonhub logs both show the emontx data is being received by the emonbase, but there is an issue with the connection between emonhub and emoncms via the MQTT broker.

Hopefully someone with some experience of the emonSD and this MQTT issue in particular can jump in and advise you.

jeremypoulter · 2016-09-21T10:14:07.871Z

That sounds similar to the problems I had.

Log in to the console and see if Mosquitto is running;

pi@home:~ $ ps aux | grep mosquitto
mosquit+  1185  0.1  0.3   5436  3876 ?        S    Sep14  12:24 /usr/sbin/mosquitto -c /etc/mosquitto/mosquitto.conf
pi       15793  0.0  0.2   4280  2016 pts/0    S+   10:11   0:00 grep --color=auto mosquitto

Don’t trust service mosquitto status it lied to me and caused me to waste lots of time looking for an alternative problem.

nicklaws · 2016-09-21T12:50:39.678Z

Thanks so much Paul and Jeremy!

Looks like mosquitto is not running:

pi@emonpi:~ $ ps aux | grep mosquitto
pi 12218 0.0 0.1 5976 1956 pts/0 S+ 08:16 0:00 grep --color=auto mosquitto

I did some searching around, and read through emoncms/MQTT.md at master · emoncms/emoncms · GitHub, but that doesn’t seem to be my problem.

The only piece that I was missing was (which I did):
“If PHP extension config files /etc/php5/cli/conf.d/20-mosquitto.ini and /etc/php5/apache2/conf.d/20-mosquitto.ini don’t exist then create with:”

sudo sh -c ‘echo “extension=mosquitto.so” > /etc/php5/cli/conf.d/20-mosquitto.ini’
sudo sh -c ‘echo “extension=mosquitto.so” > /etc/php5/apache2/conf.d/20-mosquitto.ini’

Did a reboot and checked: Mosquitto still not running. What do you suggest a try next?

jeremypoulter · 2016-09-21T23:12:01.264Z

Just try running it on the command line.

sudo mosquitto

If it complains about not being able to write to /var/log/mosquitto/... then it is the same issue I had, and the fix is in the thread I posted.

glyn.hudson · 2016-09-22T08:20:27.568Z

Hi Nick,

Sorry to hear your having trouble. Are you running the stock emonSD-08May16 sd card? I’ve not experienced this issue, I’m running mosquitto version 1.4.9. Could you check what version your running?

$ mosquitto -h

nicklaws · 2016-09-24T00:27:59.299Z

I am running the stock SD card (that I just received in the mail). I have mosquitto version 1.4.10:

pi@emonpi:~ $ sudo mosquitto
1474676184: mosquitto version 1.4.10 (build date Thu, 25 Aug 2016 10:12:09 +0100) starting
1474676184: Using default config.
1474676184: Opening ipv4 listen socket on port 1883.
1474676184: Opening ipv6 listen socket on port 1883.
1474676184: New connection from 127.0.0.1 on port 1883.
1474676184: New client connected from 127.0.0.1 as paho/828FDA3EF4EC95567D (c1, k60, u’emonpi’).
1474676185: Socket error on client paho/828FDA3EF4EC95567D, disconnecting.
1474676185: New connection from 127.0.0.1 on port 1883.
1474676185: New client connected from 127.0.0.1 as paho/828FDA3EF4EC95567D (c1, k60, u’emonpi’).
1474676185: New connection from 127.0.0.1 on port 1883.
1474676185: New client connected from 127.0.0.1 as openhab.1474676185586 (c1, k60, u’emonpi’).
1474676187: New connection from ::1 on port 1883.
1474676187: New client connected from ::1 as mosq/Jq=j?h77ej=UO>9:_s (c1, k5, u’emonpi’).
1474676191: Socket error on client mosq/Jq=j?h77ej=UO>9:_s, disconnecting.
1474676192: New connection from ::1 on port 1883.
1474676192: New client connected from ::1 as mosq/`02FPtT\2DnaWvp]m] (c1, k5, u’emonpi’).
1474676194: New connection from 127.0.0.1 on port 1883.
1474676194: New client connected from 127.0.0.1 as mqtt_f54f1159.0ab0f (c1, k15, u’emonpi’).

It just seems to hang after giving the above output. Sorry I’m unfamiliar with mosquitto. Perhaps I should revert to version 1.4.9?

I tried:
pi@emonpi:~ $ sudo apt-get install mosquitto=1.4.9
W: Not using locking for read only lock file /var/lib/dpkg/lock
E: Unable to write to /var/cache/apt/
E: The package lists or status file could not be parsed or opened.

nicklaws · 2016-09-24T02:35:57.241Z

Hooray! I flashed another SD card with the latest image, and then DID NOT UPDATE: getting numbers in emoncms now!

So perhaps an issue with mosquitto 1.4.10?

nicklaws · 2016-09-24T04:06:34.270Z

However… the numbers are not refreshing in emoncms. The RFM69Pi V3 led is not flashing every 10 seconds, though it did in the past (when I was getting n/a’s in emoncms). Should I try updating?

It seems (from minicom) that any signals are being discarded except the very first signal received after a reboot.

jeremypoulter · 2016-09-24T15:25:47.211Z

nicklaws:

Hooray! I flashed another SD card with the latest image, and then DID NOT UPDATE: getting numbers in emoncms now!

So perhaps an issue with mosquitto 1.4.10?

Yeah, I think that 1.4.10 is a bit more picky about the creating the log files. I will create a PR for the changes that fixed this issue.

glyn.hudson · 2016-09-25T00:37:17.259Z

nicklaws:

It seems (from minicom) that any signals are being discarded except the very first signal received after a reboot

Could you post the Minicom output?

Its fine to run emonpi update (be emoncms admin web interface) but hold off running any system upgrades until your up and running so we can limit the number of variables.

I will try and investigate mosquitto 1.4.10 next week

nicklaws · 2016-09-25T00:47:06.496Z

Hi Glyn, sorry I didn’t post it sooner, but I’m fully operational now.

I believe that the issue was interference from my wireless router: the emonbase was plugged into the router with ethernet so the two were very close to eachother (and the emonTx was only ~4m and one wall away).

So I unplugged the emonbase (have RPi3 so using wireless now) and put it much closer to the emonTx, and further from the wireless router.

Thanks for all your help. I hope to contribute to development in the future (I’m handy with python) and if you’re ever climbing in Colorado look me up!

Nick

Bill.Thomson · 2016-09-25T00:51:49.739Z

Hi Nick,

Your post doesn’t quite make sense as emonhub is software.
Perhaps you have it confused with something else?

nicklaws · 2016-09-25T00:54:36.267Z

Sorry, I meant emonBase

glyn.hudson · 2016-09-25T00:55:45.621Z

I think @nicklaws means emonBase (raspi + rfm69pi) when he says emonhub? Is this correct?

Good to hear you’re up and running

I will report mosquitto logfile investigation. @jeremypoulter did you hint that you’ve got a fix for this? What was the issue?

We should split this topic into a new one to continue discussion.

Bill.Thomson · 2016-09-25T00:58:08.934Z

Not a problem. I fixed it for you.

jeremypoulter · 2016-09-25T10:26:30.913Z

glyn.hudson:

I will report mosquitto logfile investigation. @jeremypoulter did you hint that you’ve got a fix for this? What was the issue?

Have a look at MQTT Log files:

MQTT Log files emonSD

I have just set up a Raspberry Pi with EmonCMS (mostly) following the instructions on building the SD card and I ran into some troubles with Mosquitto not starting (even though the service status was running…). It took a bit of hear pulling but turned out to be that I needed to create /var/log/mosquitto and set the owner as with the other services (in rc.local) So my question is why doe the emonSD image not need this change, or to phrase it another way, what step did i miss ;-)? FYI the versio…

glyn.hudson · 2016-09-28T09:48:59.460Z

This issue has now been fixed:

MQTT Log files emonSD

Thanks to @jeremypoulter and @Jon for helping to debug this. The fix has now been committed to emonpi, after emonpi update and a reboot the mosquitto log file folder will be created and mosquitto V1.4.10 will now run happily

Xino · 2016-11-13T13:05:32.913Z

Having the same issue after apt-get update & upgrade. I have also run the emonPi update and reboot but the mosquitto folder and log files have not been created.

I can only get the MQTT Server started via command prompt, ie. mosquitto &
It then works as normal.

TIA