Feed from one input stops updating, others feeds continue to work

etricky · 2 June 2019 16:32

Hello. I recently noticed that 2 of my feeds were not updating. I have an emontx3 with 2 inputs and this only happens to the feeds House Power and House Power kWh of the first input, power1. The feeds of power2 continue to work just fine.

I know that these screeenshots show both feeds working!

The gap is visible in the feed graph. The gap in the Heating Power (in blue) is because I restarted emonhub service.

When I restart the emonhub service it starts working again. In the log from emonhub, I see that the emontx3 continues to send values for both inputs so I know emontx3 is working fine and emonbase is getting those values.

2019-06-02 16:25:02,900 DEBUG    RFM2Pi     4694 NEW FRAME : OK 8 63 1 63 0 0 0 0 0 34 90 184 11 184 11 184 11 184 11 184 11 184 11 0 0 0 0 (-30)
2019-06-02 16:25:02,903 DEBUG    RFM2Pi     4694 Timestamp : 1559489102.9
2019-06-02 16:25:02,904 DEBUG    RFM2Pi     4694 From Node : 8
2019-06-02 16:25:02,904 DEBUG    RFM2Pi     4694    Values : [319, 63, 0, 0, 230.74, 300, 300, 300, 300, 300, 300, 0]
2019-06-02 16:25:02,905 DEBUG    RFM2Pi     4694      RSSI : -30
2019-06-02 16:25:02,906 DEBUG    RFM2Pi     4694 Sent to channel(start)' : ToEmonCMS
2019-06-02 16:25:02,906 DEBUG    RFM2Pi     4694 Sent to channel(end)' : ToEmonCMS
2019-06-02 16:25:03,096 DEBUG    MQTT       Publishing: emon/emontx3/power1 319
2019-06-02 16:25:03,098 DEBUG    MQTT       Publishing: emon/emontx3/power2 63
2019-06-02 16:25:03,099 DEBUG    MQTT       Publishing: emon/emontx3/power3 0
2019-06-02 16:25:03,101 DEBUG    MQTT       Publishing: emon/emontx3/power4 0
2019-06-02 16:25:03,102 DEBUG    MQTT       Publishing: emon/emontx3/vrms 230.74
2019-06-02 16:25:03,103 DEBUG    MQTT       Publishing: emon/emontx3/temp1 300
2019-06-02 16:25:03,104 DEBUG    MQTT       Publishing: emon/emontx3/temp2 300
2019-06-02 16:25:03,106 DEBUG    MQTT       Publishing: emon/emontx3/temp3 300
2019-06-02 16:25:03,108 DEBUG    MQTT       Publishing: emon/emontx3/temp4 300
2019-06-02 16:25:03,110 DEBUG    MQTT       Publishing: emon/emontx3/temp5 300
2019-06-02 16:25:03,111 DEBUG    MQTT       Publishing: emon/emontx3/temp6 300
2019-06-02 16:25:03,113 DEBUG    MQTT       Publishing: emon/emontx3/pulse 0
2019-06-02 16:25:03,115 DEBUG    MQTT       Publishing: emon/emontx3/rssi -30
2019-06-02 16:25:03,117 INFO     MQTT       Publishing: emonhub/rx/8/values 319,63,0,0,230.74,300,300,300,300,300,300,0,-30
2019-06-02 16:25:08,549 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 0 88 59 223 1 207 237 126 108 56 148 243 105 172 38 62 150 61 98 1 26 (-96)
2019-06-02 16:25:09,913 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 2 18 194 131 1 239 16 254 248 159 81 187 77 164 168 124 176 54 46 118 217 (-96)
2019-06-02 16:25:11,147 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 5 14 19 252 34 19 212 72 237 46 4 76 198 51 205 237 245 85 154 157 140 (-96)
2019-06-02 16:25:11,253 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 5 74 253 240 0 247 28 71 227 159 26 249 163 113 5 46 227 29 208 179 94 (-95)
2019-06-02 16:25:11,457 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 28 152 83 12 70 232 85 183 246 48 194 134 109 32 50 9 168 51 67 77 24 (-93)
2019-06-02 16:25:12,073 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 12 111 192 144 137 206 1 63 89 66 19 49 15 13 237 194 198 133 244 228 216 (-95)
2019-06-02 16:25:12,805 DEBUG    RFM2Pi     4695 NEW FRAME : OK 8 61 1 63 0 0 0 0 0 73 90 184 11 184 11 184 11 184 11 184 11 184 11 0 0 0 0 (-31)
2019-06-02 16:25:12,808 DEBUG    RFM2Pi     4695 Timestamp : 1559489112.8
2019-06-02 16:25:12,809 DEBUG    RFM2Pi     4695 From Node : 8
2019-06-02 16:25:12,809 DEBUG    RFM2Pi     4695    Values : [317, 63, 0, 0, 231.13, 300, 300, 300, 300, 300, 300, 0]
2019-06-02 16:25:12,810 DEBUG    RFM2Pi     4695      RSSI : -31
2019-06-02 16:25:12,810 DEBUG    RFM2Pi     4695 Sent to channel(start)' : ToEmonCMS
2019-06-02 16:25:12,811 DEBUG    RFM2Pi     4695 Sent to channel(end)' : ToEmonCMS
2019-06-02 16:25:12,999 DEBUG    MQTT       Publishing: emon/emontx3/power1 317
2019-06-02 16:25:13,001 DEBUG    MQTT       Publishing: emon/emontx3/power2 63
2019-06-02 16:25:13,003 DEBUG    MQTT       Publishing: emon/emontx3/power3 0
2019-06-02 16:25:13,005 DEBUG    MQTT       Publishing: emon/emontx3/power4 0
2019-06-02 16:25:13,007 DEBUG    MQTT       Publishing: emon/emontx3/vrms 231.13
2019-06-02 16:25:13,008 DEBUG    MQTT       Publishing: emon/emontx3/temp1 300
2019-06-02 16:25:13,010 DEBUG    MQTT       Publishing: emon/emontx3/temp2 300
2019-06-02 16:25:13,012 DEBUG    MQTT       Publishing: emon/emontx3/temp3 300
2019-06-02 16:25:13,014 DEBUG    MQTT       Publishing: emon/emontx3/temp4 300
2019-06-02 16:25:13,016 DEBUG    MQTT       Publishing: emon/emontx3/temp5 300
2019-06-02 16:25:13,018 DEBUG    MQTT       Publishing: emon/emontx3/temp6 300
2019-06-02 16:25:13,019 DEBUG    MQTT       Publishing: emon/emontx3/pulse 0
2019-06-02 16:25:13,021 DEBUG    MQTT       Publishing: emon/emontx3/rssi -31
2019-06-02 16:25:13,023 INFO     MQTT       Publishing: emonhub/rx/8/values 317,63,0,0,231.13,300,300,300,300,300,300,0,-31

I looked for anything that could tell me why this is happening and the only thing I noticed is in the mosquitto log. Emonhub and mqtt services were up and running (otherwise the feeds from the second input would not update).

mosquitto.log

1559489023: Warning: Received PUBREL from auto-8F084150-79CF-5097-3304-2568B53BD998 for an unknown packet identifier 65493.
1559489033: Warning: Received PUBREL from auto-8F084150-79CF-5097-3304-2568B53BD998 for an unknown packet identifier 65507.
1559489043: Warning: Received PUBREL from auto-8F084150-79CF-5097-3304-2568B53BD998 for an unknown packet identifier 65521.
1559489053: Warning: Received PUBREL from auto-8F084150-79CF-5097-3304-2568B53BD998 for an unknown packet identifier 65535.
1559489063: Warning: Received PUBREL from auto-8F084150-79CF-5097-3304-2568B53BD998 for an unknown packet identifier 14.
1559489073: Warning: Received PUBREL from auto-8F084150-79CF-5097-3304-2568B53BD998 for an unknown packet identifier 15.
1559489073: Warning: Received PUBREL from auto-8F084150-79CF-5097-3304-2568B53BD998 for an unknown packet identifier 28.
1559489083: Warning: Received PUBREL from auto-8F084150-79CF-5097-3304-2568B53BD998 for an unknown packet identifier 29.
1559489083: Warning: Received PUBREL from auto-8F084150-79CF-5097-3304-2568B53BD998 for an unknown packet identifier 42.
1559489093: Warning: Received PUBREL from auto-8F084150-79CF-5097-3304-2568B53BD998 for an unknown packet identifier 43.
1559489093: Warning: Received PUBREL from auto-8F084150-79CF-5097-3304-2568B53BD998 for an unknown packet identifier 56.
1559489103: Warning: Received PUBREL from auto-8F084150-79CF-5097-3304-2568B53BD998 for an unknown packet identifier 57.
1559489103: Warning: Received PUBREL from auto-8F084150-79CF-5097-3304-2568B53BD998 for an unknown packet identifier 70.
1559489113: Warning: Received PUBREL from auto-8F084150-79CF-5097-3304-2568B53BD998 for an unknown packet identifier 71.
1559489113: Warning: Received PUBREL from auto-8F084150-79CF-5097-3304-2568B53BD998 for an unknown packet identifier 84.
1559489121: Socket error on client auto-8F084150-79CF-5097-3304-2568B53BD998, disconnecting.
1559489132: New connection from 127.0.0.1 on port 1883.
1559489132: New client connected from 127.0.0.1 as auto-FFFACBAE-C836-B1DF-2D67-14ED47556EE6 (p2, c1, k60, u'emonpi').
1559489142: Warning: Received PUBREL from auto-FFFACBAE-C836-B1DF-2D67-14ED47556EE6 for an unknown packet identifier 15.
1559489162: Warning: Received PUBREL from auto-FFFACBAE-C836-B1DF-2D67-14ED47556EE6 for an unknown packet identifier 29.
1559489172: Warning: Received PUBREL from auto-FFFACBAE-C836-B1DF-2D67-14ED47556EE6 for an unknown packet identifier 43.

NOTE: These logs also include the emonhub restart.

When the identifier reaches 65536 and resets, the feeds stops updating! I have seen this happening several times and it’s always the same pattern.

Attached emonhub.log and mosquitto.log
logs.zip (313.0 KB)

This started to happen after I updated emoncms to the latest version a couple weeks ago and also after I ran apt upgrade on the OS.

Any idea why this is happening? As always, your help is greatly appreciated!

pb66 · 2 June 2019 17:15

What version Mosquito broker are you running?

See Emon MQTT data incomplete

etricky · 2 June 2019 23:44

@pb66 I have version 1.6.2. As I said, I only ran apt upgrade, I never added or changed any of the apt repositories that came with the pre-loaded SD card! My current list of repositories is this:

pi@emonpi(rw):sources.list.d$ ll /var/lib/apt/lists/
total 51244
drwxr-xr-x 3 root root     4096 Jun  3 00:17 .
drwxr-xr-x 5 root root     4096 May 31 01:14 ..
-rw-r--r-- 1 root root    22943 May 31 15:55 archive.raspberrypi.org_debian_dists_jessie_InRelease
-rw-r--r-- 1 root root   708766 May 31 15:53 archive.raspberrypi.org_debian_dists_jessie_main_binary-armhf_Packages
-rw-r--r-- 1 root root   341250 May 31 15:53 archive.raspberrypi.org_debian_dists_jessie_ui_binary-armhf_Packages
-rw-r--r-- 1 root root     4584 May 29 00:54 deb.nodesource.com_node%5f10.x_dists_jessie_InRelease
-rw-r--r-- 1 root root     1195 May 29 00:54 deb.nodesource.com_node%5f10.x_dists_jessie_main_binary-armhf_Packages
-rw-r--r-- 1 root root        0 Jan 28 19:39 deb.nodesource.com_node%5f10.x_dists_jessie_main_source_Sources
-rw-r--r-- 1 root root   479966 Jun 28  2017 dl.bintray.com_openhab_apt-repo_dists_stable_main_binary-armhf_Packages
-rw-r--r-- 1 root root     6051 Jun 28  2017 dl.bintray.com_openhab_apt-repo_dists_stable_Release
-rw-r--r-- 1 root root      821 Jun 28  2017 dl.bintray.com_openhab_apt-repo_dists_stable_Release.gpg
-rw-r----- 1 root root        0 Nov 21  2015 lock
-rw-r--r-- 1 root root   154189 Feb  9 04:14 mirrordirector.raspbian.org_raspbian_dists_jessie_contrib_binary-armhf_Packages
-rw-r--r-- 1 root root    14962 Jun  2 23:14 mirrordirector.raspbian.org_raspbian_dists_jessie_InRelease
-rw-r--r-- 1 root root 50143133 Jun  1 11:14 mirrordirector.raspbian.org_raspbian_dists_jessie_main_binary-armhf_Packages
-rw-r--r-- 1 root root   391416 Apr  2 11:14 mirrordirector.raspbian.org_raspbian_dists_jessie_non-free_binary-armhf_Packages
-rw-r--r-- 1 root root     2689 Feb  9 04:14 mirrordirector.raspbian.org_raspbian_dists_jessie_rpi_binary-armhf_Packages
drwxr-xr-x 2 root root     4096 Jun  3 00:17 partial
-rw-r--r-- 1 root root    17555 Apr 18 16:49 ppa.launchpad.net_webupd8team_java_ubuntu_dists_xenial_InRelease
-rw-r--r-- 1 root root        0 Apr 18 16:49 ppa.launchpad.net_webupd8team_java_ubuntu_dists_xenial_main_binary-armhf_Packages
-rw-r--r-- 1 root root        0 Apr 18 16:49 ppa.launchpad.net_webupd8team_java_ubuntu_dists_xenial_main_i18n_Translation-en
-rw-r--r-- 1 root root        0 Apr 18 16:49 ppa.launchpad.net_webupd8team_java_ubuntu_dists_xenial_main_source_Sources
-rw-r--r-- 1 root root    10969 Apr 30 15:47 repo.mosquitto.org_debian_dists_jessie_InRelease
-rw-r--r-- 1 root root   118793 Apr 30 15:47 repo.mosquitto.org_debian_dists_jessie_main_binary-armhf_Packages

In repo.mosquitto.org there’s no 1.4.10 version available as suggested in the case you mentioned.

Can you tell me which are the steps I need to take to fix this, please?

TrystanLea · 4 June 2019 13:36

Tried updating a test emonpi here to see if it pulls in mosquitto 1.6.2 and I get:

pi@emonpi:~ $ sudo apt-get upgrade mosquitto
Reading package lists... Done
Building dependency tree       
Reading state information... Done
mosquitto is already the newest version (1.4.10-3+deb9u4).
Calculating upgrade... Done
0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.

and running the version command:

pi@emonpi:~ $ mosquitto -v
1559655168: mosquitto version 1.4.10 (build date Wed, 13 Feb 2019 00:45:38 +0000) starting
1559655168: Using default config.
1559655168: Opening ipv4 listen socket on port 1883.
1559655168: Error: Address already in use

Are you sure its version 1.6.2 @etricky?

borpin · 4 June 2019 13:53

That is what is says in the mosquitto log that was attached to one of the messages.

[edit]
Could something else have installed the upstream version? How do you check the repos being used for mosquitto?

pb66 · 4 June 2019 14:07

The root of the issue is this section on the emonSD build guide

wget http://repo.mosquitto.org/debian/mosquitto-repo.gpg.key
sudo apt-key add mosquitto-repo.gpg.key
cd /etc/apt/sources.list.d/
sudo wget http://repo.mosquitto.org/debian/mosquitto-jessie.list
sudo apt-get update
sudo apt-get install mosquitto mosquitto-clients libmosquitto-dev -y

[Another part of build guide apparently not used for the oct2018 image]

To fix this the mosquitto repo needs removing from the source list so that the Debian Stretch stable version is used from the Debian repos, that’s the version you are currently installing.

However, I’ve not had a chance to look into how to get a clean roll-back.

I do not believe that the Debian stable version can be aware of what the latest mosquitto repo version might have installed so it cannot be relied upon to “fix” (ie rollback). Therefore if it were me I would uninstall/purge before editing the sources list and then reinstall from the debian repo. However, that may require some special steps taken to preserve the config file since the build guide edits the package maintained conf rather than using a drop in.

Bill.Thomson · 4 June 2019 14:10

If an apt-get remove is done without the “–purge” argument, the config file(s) won’t be removed.

etricky · 4 June 2019 15:47

First of all, I would like to say thank you so much for all your help! I really appreciate it.

Just for clarity, I do have 1.6.2 version of mosquitto and I have not followed the emonSD build guide as I acquired the SD card already pre-loaded back in 2017. This is the first time that I had any issue after an apt upgrade.

Regarding what all of you said, I not completely sure which are the next steps. I’m not an expert on Linux but it seems to me that I will need to remove the repository, remove mosquitto and then install it again? Are these the right steps and on the correct order? Do I need to add another repository for mosquitto to be installed? Are there other steps I need to take, perhaps, backup some config files?

One other question (remember, not an Linux expert here!), if there’s a dependency for a specific version of mosquitto or for other packages, couldn’t that be managed by having a package installed with those requirements to prevent this from occurring?

borpin · 4 June 2019 16:01

Ah that explains it. That SD card build pointed to that repository because at the time the version in the main Raspbian repositories were not up to date enough. Now the opposite is true .

TBH as you are on a Jessie based SD, the path of least resistance will be to get a new SD Card, either from the shop (preloaded) or download a new image and flash it to the SD card. Warning, if you have a Pi2 you need to follow the instructions on the download page. Having looked they are a bit hidden so…

To use this image on Pi2 remove the following lines from /boot/config.txt :

arm_freq=1200
arm_freq_min=600

Also note Node-Red and OpenHAB have been removed from this image as standard (you can install them if you wish).

Run a backup from your current system. Put the new card in, leave it for a while to update itself, then upload the backup to the new card.

You should be back in business.

@TrystanLea - could these update instructions be converted to a Wiki page as repeating them is getting a little tiresome? Perhaps even add a link to them from the Admin Page if the image is old enough.

Bill.Thomson · 4 June 2019 17:08

To use this image on Pi2 remove the following lines from /boot/config.txt :

arm_freq=1200
arm_freq_min=600

If /boot/config.txt used conditional filters,

Ref: Raspberry Pi Documentation - Configuration

the arm_freq variables could be handled automatically, i.e, no user intervention required.

Something similar to

[pi3]
arm_freq=1200
arm_freq_min=600

[pi2]
arm_freq=900
arm_freq_min=600

[all]

would remove the need to modify the config.txt file when used with a Pi 2.
The Pi Zero and the Pi 1 can be accommodated this way, as well.
Details at the link above.

@TrystanLea ? @glyn.hudson?

TrystanLea · 4 June 2019 17:12

Thanks @borpin good idea

@Bill.Thomson that sounds like a good approach.

etricky · 5 June 2019 00:08

I have a RPI3+ so I just flashed the latest version of emonSD, restored the backup and I’m now up and running again!

Thank you so much for all your help!