emonPi hangs and stops logging

TrystanLea · 19 March 2018 20:27

Hello Jon, do you mean that you have a full data history on emoncms.org?

stabuck · 19 March 2018 21:03

Yes, EmonCMS (the one on the internet) is fine and up to date, emonpi (the one in my house) is showing no data for just over 12-months.

stabuck · 19 March 2018 21:18

At 9.09pm on March 2nd 2017 my power was 2425W both locally and at emoncms.org - one minute later and locally it is zero (and has been ever since) and is still at about 2.4kw at emoncms.org and continues to log normally up until the present day.

It was 12-months ago - it is quite possible I did something to it.

stabuck · 19 March 2018 21:19

pb66 · 19 March 2018 22:00

@stabuck - How many setups do you have?

I ask because I’m confused by this new thread where you suggest you may not have checked your emonPi for over a year, since you have another thread that you started 22days ago by saying your emonpi regularly stops posting data fro hours or days, sometimes weeks. Are these the same systems?

If they are, the fact your emoncms.org account continues to collect data is a massive piece of information that would help that discussion. It rules out the emonpi board hanging, emonhub crashing and points the finger squarely at a likely MQTT issue, most likely the mqtt_input service.

Can you please confirm your setup and if these 2 threads are linked. I think we should merge this new discussion with that other thread unless you are talking about a completely independent system.

stabuck · 20 March 2018 06:07

I have the one emonPi, this is the same emonPi. I don’t know if the two topics are related, it is quite possible as I can only see 4 or 5 incidents of “stops logging” between May 2015 and March 2017. I noticed this thread’s problem after it stopped logging and checked the EmonPi as you suggested in the other thread and found it would not respond to me.
Logging in and it does not like the command “sudo systemctl status emonhub”, “sudo: systemctl: command not found”

emonhoub.log

2018-03-20 05:54:28,434 INFO     MQTT       Could not connect...
2018-03-20 05:54:30,876 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 16 33 226 40 208 28 160 9 192 15 96 41 58 36 17 2 131 13 128 128 70 (-110)
2018-03-20 05:54:31,810 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 4 1 64 32 225 32 116 20 167 196 2 1 104 17 15 0 104 28 144 33 126 (-111)
2018-03-20 05:54:33,345 DEBUG    RFM2Pi     110614 NEW FRAME : OK 5 226 19 0 0 226 19 61 95 4 0 194 0 81 0 0 0 0 0 0 0 50 0 0 0 (-0)
2018-03-20 05:54:33,348 DEBUG    RFM2Pi     110614 Timestamp : 1521525273.35
2018-03-20 05:54:33,349 DEBUG    RFM2Pi     110614 From Node : 5
2018-03-20 05:54:33,349 DEBUG    RFM2Pi     110614    Values : [5090, 0, 5090, 243.81, 0.4, 19.400000000000002, 8.1, 0, 0, 0, 50]
2018-03-20 05:54:33,350 DEBUG    RFM2Pi     110614 Sent to channel(start)' : ToEmonCMS
2018-03-20 05:54:33,350 DEBUG    RFM2Pi     110614 Sent to channel(end)' : ToEmonCMS
2018-03-20 05:54:33,455 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 17 38 9 37 139 3 32 34 10 136 96 139 168 0 5 213 255 0 26 66 97 (-111)
2018-03-20 05:54:33,651 INFO     MQTT       Connecting to MQTT Server
2018-03-20 05:54:33,652 INFO     MQTT       Could not connect...
2018-03-20 05:54:34,466 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 18 29 124 232 160 62 60 145 176 67 129 12 132 46 127 173 41 49 128 32 146 (-106)
2018-03-20 05:54:35,074 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 9 150 73 0 35 56 1 12 194 128 34 0 125 2 127 173 41 49 128 32 146 (-111)
2018-03-20 05:54:35,483 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 29 9 136 172 4 248 64 115 100 66 188 1 24 168 80 113 155 178 132 140 173 (-112)
2018-03-20 05:54:36,894 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 6 50 148 244 0 9 49 200 1 74 0 2 93 29 25 0 160 43 184 48 0 (-111)
2018-03-20 05:54:37,394 DEBUG    emoncmsorg Buffer size: 6
2018-03-20 05:54:37,396 INFO     emoncmsorg sending: http://emoncms.org/input/bulk.json?apikey=E-M-O-N-C-M-S-A-P-I-K-E-Y&data=[[1521525248.273787,5,5072,0,5072,243.49,0.30000000000000004,19.400000000000002,8.1,0,0,0,50],[1521525253.335623,5,5086,0,5086,243.73000000000002,0.30000000000000004,19.400000000000002,8.1,0,0,0,50],[1521525258.326553,5,5100,0,5100,244.04,0.30000000000000004,19.400000000000002,8.1,0,0,0,50],[1521525263.360134,5,5072,0,5072,243.42000000000002,0.30000000000000004,19.400000000000002,8.1,0,0,0,50],[1521525268.281153,5,5072,0,5072,243.42000000000002,0.4,19.400000000000002,8.1,0,0,0,50],[1521525273.34531,5,5090,0,5090,243.81,0.4,19.400000000000002,8.1,0,0,0,50]]&sentat=1521525277
2018-03-20 05:54:37,793 DEBUG    emoncmsorg acknowledged receipt with 'ok' from http://emoncms.org
2018-03-20 05:54:38,313 DEBUG    RFM2Pi     110615 NEW FRAME : OK 5 214 19 0 0 214 19 37 95 4 0 195 0 81 0 0 0 0 0 0 0 50 0 0 0 (-0)
2018-03-20 05:54:38,317 DEBUG    RFM2Pi     110615 Timestamp : 1521525278.31
2018-03-20 05:54:38,318 DEBUG    RFM2Pi     110615 From Node : 5
2018-03-20 05:54:38,319 DEBUG    RFM2Pi     110615    Values : [5078, 0, 5078, 243.57, 0.4, 19.5, 8.1, 0, 0, 0, 50]
2018-03-20 05:54:38,320 DEBUG    RFM2Pi     110615 Sent to channel(start)' : ToEmonCMS
2018-03-20 05:54:38,320 DEBUG    RFM2Pi     110615 Sent to channel(end)' : ToEmonCMS
2018-03-20 05:54:38,428 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 12 216 168 203 3 59 77 223 131 240 193 27 255 162 38 163 72 28 175 9 240 (-111)
2018-03-20 05:54:38,470 INFO     MQTT       Connecting to MQTT Server
2018-03-20 05:54:38,471 INFO     MQTT       Could not connect...
2018-03-20 05:54:39,338 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 0 25 128 40 3 59 77 223 131 240 193 27 255 162 38 163 72 28 175 9 240 (-110)
2018-03-20 05:54:40,449 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 17 65 134 0 3 59 77 223 131 240 193 27 255 162 38 163 72 28 175 9 240 (-111)

pb66 · 20 March 2018 10:25

Jon can you please post your system data from the emoncms admin page, if it is reasonably up to date it will have a “copy to clipboard” button.

Can you also supply the emonpi_update.log, usually found in /home/pi/data ?

The fact it gives the “sudo: systemctl: command not found” error suggests this is a very early emonpi running a Raspbian Wheezy OS. The updater should not be working, it should abort when it finds this is an earlier build. That assumes the updater was never used prior to the checks being added to avoid a situation where a update fails due to incompatibilities and results in a unusable or unrecoverable system.

We need to establish exactly what you do have and/or think about possibly moving your setup over to the latest image.

stabuck · 20 March 2018 13:08

No “copy to clipboard” button.

Emoncms version: low-write-v8.5

Log file found at /var/log/emonpiupdate.log

Stopping system emonPiLCD daemon:start-stop-daemon: warning: failed to kill 2489: No such process
No process in pidfile '/var/run/emonPiLCD.pid' found running; none killed.
 failed!
I2C LCD NOT DETECTED on either 0x['27', '3f'] ...exiting LCD script

Starting emonPi Update >
via update
Mon Mar 19 20:11:02 UTC 2018

#############################################################

emonSD version: emonSD-17Jun2015

ERROR: emonSD base image old or undefined...update will not continue
See latest verson: https://github.com/openenergymonitor/emonpi/wiki/emonSD-pre-built-SD-card-Download-&-Change-Log
Stopping update
Job is already running!
Job is already running!
Job is already running!
Job is already running!
Job is already running!
Job is already running!
[repeats hundreds of times]

Looks to me like you have found the problem?!
If so, how do I update it?

Thank you so much!

pb66 · 20 March 2018 13:44

Well at least it looks like your system is intact and not caught out “mid update”.

Only as to why the emonpi hasn’t updated and the systenctl commands not working, we still don’t know why the data stops, however, yes this may have been fixed in the later versions.

Good question, I wish I had a better answer than “not easily”, there will be several posts on this forum about making the change, but I do not recall the detail or which posts they are. Hopefully someone might jump in with some advice here.

Because the system is intact and the fault isn’t terminal or making the system unusable you are not under pressure to upgrade quickly or immediately. You might find it easier to start with a fresh image and migrate your data over. There were significant differences when upgrading emoncms <v8.5 to >v9 so it’s not going to be directly compatible, there will be changes required to your dashboards for example.

Since the fault only occurs once in a blue moon, it might even be worth considering sticking with what you have and crossing your fingers for a new emonSD image, I have not heard anything to suggest that be happening, but the current image is getting quite dated now and I wouldn’t want to recommend you convert to the current image, only to find a new one is released any time soon.

If the fault occurs again please try and catch the emonhub.log before it rotates out and use the following commands (instead of systemctl) to check the services

sudo service emonhub status

sudo service feedwriter status

sudo service mqtt_input status

TrystanLea · 20 March 2018 15:03

Yes, The update procedure from low-write-v8.5 to the latest is not straightforward unfortunately as there where a number of large updates to the operating system between the older version and more recent versions.

If your happy to do so, the recommended approach is to download the latest SD card image here free of charge https://github.com/openenergymonitor/emonpi/wiki/emonSD-pre-built-SD-card-Download-&-Change-Log and write it to a 8GB SD card yourself. There’s an easy to use tool called etcher that can be used to write the image to an SD card: https://etcher.io/.

Before doing this step you may want to use the emoncms backup tool for the data on your existing SD card see https://guide.openenergymonitor.org/setup/import/.

If your not comfortable with doing the above, please send us an email at [email protected] and Glyn, Gwil or I will try our best to help.

stabuck · 20 March 2018 20:17

Thank you, I have done all of the above, it was not so hard - backed up old database, put latest OS on new SD card, set up user and wifi, imported old database… all looks like it worked fine but unfortunately it is still not displaying that it is logging locally and is now also appears to not be uploading to EmonCMS.

emoncms.log

2018-03-20 19:27:58.344|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-03-20 19:27:58.541|WARN|phpmqtt_input.php|Not connected, retrying connection
2018-03-20 19:28:04.002|WARN|phpmqtt_input.php|Not connected, retrying connection
2018-03-20 19:28:04.004|WARN|phpmqtt_input.php|Connecting to MQTT server: Connection Accepted.: code: 0
2018-03-20 19:28:11.957|WARN|phpmqtt_input.php|Not connected, retrying connection
2018-03-20 19:28:11.979|WARN|phpmqtt_input.php|Connecting to MQTT server: Connection Accepted.: code: 0

emonhub.log

2018-03-20 19:17:32,881 INFO     MainThread EmonHub emonHub emon-pi variant v2.1.1
2018-03-20 19:17:32,883 INFO     MainThread Opening hub...
2018-03-20 19:17:32,884 INFO     MainThread Logging level set to DEBUG
2018-03-20 19:17:32,885 INFO     MainThread Creating EmonHubJeeInterfacer 'RFM2Pi' 
2018-03-20 19:17:32,889 DEBUG    MainThread Opening serial port: /dev/ttyAMA0 @ 38400 bits/s
2018-03-20 19:17:34,896 INFO     MainThread RFM2Pi device firmware version & configuration: not available
2018-03-20 19:17:34,898 INFO     MainThread Setting RFM2Pi frequency: 433 (4b)
2018-03-20 19:17:35,900 INFO     MainThread Setting RFM2Pi group: 210 (210g)
2018-03-20 19:17:36,903 INFO     MainThread Setting RFM2Pi quiet: 0 (0q)
2018-03-20 19:17:37,905 INFO     MainThread Setting RFM2Pi baseid: 5 (5i)
2018-03-20 19:17:38,908 INFO     MainThread Setting RFM2Pi calibration: 230V (1p)
2018-03-20 19:17:39,911 DEBUG    MainThread Setting RFM2Pi subchannels: ['ToRFM12']
2018-03-20 19:17:39,912 DEBUG    MainThread Setting RFM2Pi pubchannels: ['ToEmonCMS']
2018-03-20 19:17:39,914 INFO     MainThread Creating EmonHubMqttInterfacer 'MQTT' 
2018-03-20 19:17:39,920 DEBUG    MainThread Setting MQTT subchannels: ['ToEmonCMS']
2018-03-20 19:17:39,922 DEBUG    MainThread Setting MQTT pubchannels: ['ToRFM12']
2018-03-20 19:17:39,923 INFO     MainThread Setting MQTT nodevar_format_enable: 1
2018-03-20 19:17:39,925 INFO     MainThread Setting MQTT node_format_enable: 1
2018-03-20 19:17:39,928 INFO     MainThread Setting MQTT nodevar_format_basetopic: emon/
2018-03-20 19:17:39,931 INFO     MainThread Creating EmonHubEmoncmsHTTPInterfacer 'emoncmsorg' 
2018-03-20 19:17:39,934 DEBUG    MainThread Setting emoncmsorg subchannels: ['ToEmonCMS']
2018-03-20 19:17:39,937 DEBUG    MainThread Setting emoncmsorg pubchannels: ['ToRFM12']
2018-03-20 19:17:39,938 INFO     MainThread Setting emoncmsorg url: https://emoncms.org
2018-03-20 19:17:39,940 INFO     MainThread Setting emoncmsorg senddata: 1
2018-03-20 19:17:39,943 WARNING  MainThread Setting emoncmsorg apikey: obscured
2018-03-20 19:17:39,945 INFO     MainThread Setting emoncmsorg sendstatus: 1
2018-03-20 19:17:40,003 DEBUG    RFM2Pi     device settings updated: E i5 g210 @ 433 MHz q1 USA 0
2018-03-20 19:17:40,111 DEBUG    RFM2Pi     device settings updated: E i5 g210 @ 433 MHz q1 USA 0
2018-03-20 19:17:40,218 DEBUG    RFM2Pi     1 NEW FRAME : OK 5 0 0 0 0 0 0 174 95 30 0 180 0 85 0 0 0 0 0 0 0 1 0 0 0 (-0)
2018-03-20 19:17:40,221 DEBUG    RFM2Pi     1 Timestamp : 1521573460.22
2018-03-20 19:17:40,222 DEBUG    RFM2Pi     1 From Node : 5
2018-03-20 19:17:40,223 DEBUG    RFM2Pi     1    Values : [0, 0, 0, 244.94, 3, 18, 8.5, 0, 0, 0, 1]
2018-03-20 19:17:40,224 DEBUG    RFM2Pi     1 Sent to channel(start)' : ToEmonCMS
2018-03-20 19:17:40,225 DEBUG    RFM2Pi     1 Sent to channel(end)' : ToEmonCMS
2018-03-20 19:17:40,329 DEBUG    RFM2Pi     device settings updated: E i5 g210 @ 433 MHz q0 USA 0
2018-03-20 19:17:40,432 DEBUG    RFM2Pi     device settings updated: E i5 g210 @ 433 MHz q0 USA 0
2018-03-20 19:17:40,434 INFO     MQTT       Connecting to MQTT Server
2018-03-20 19:17:40,436 INFO     MQTT       Could not connect...
2018-03-20 19:17:40,541 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 6 121 255 192 234 131 220 68 64 217 69 179 3 109 211 221 120 16 194 6 111 (-100)
2018-03-20 19:17:40,554 DEBUG    emoncmsorg Buffer size: 1
2018-03-20 19:17:40,645 DEBUG    RFM2Pi     device settings updated: E i5 g210 @ 433 MHz q0 USA 0
2018-03-20 19:17:40,754 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 16 186 241 64 50 83 200 92 62 220 120 241 4 28 76 185 116 177 245 213 59 (-106)
2018-03-20 19:17:40,865 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 4 98 42 126 60 36 39 115 18 178 99 187 219 95 106 10 233 16 9 179 102 (-109)
2018-03-20 19:17:42,686 DEBUG    RFM2Pi     2 NEW FRAME : OK 5 0 0 0 0 0 0 11 96 30 0 180 0 85 0 0 0 0 0 0 0 1 0 0 0 (-0)
2018-03-20 19:17:42,689 DEBUG    RFM2Pi     2 Timestamp : 1521573462.69
2018-03-20 19:17:42,690 DEBUG    RFM2Pi     2 From Node : 5
2018-03-20 19:17:42,691 DEBUG    RFM2Pi     2    Values : [0, 0, 0, 245.87, 3, 18, 8.5, 0, 0, 0, 1]
2018-03-20 19:17:42,692 DEBUG    RFM2Pi     2 Sent to channel(start)' : ToEmonCMS
2018-03-20 19:17:42,693 DEBUG    RFM2Pi     2 Sent to channel(end)' : ToEmonCMS
2018-03-20 19:17:42,801 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 7 124 213 192 91 165 117 55 47 229 100 2 38 239 36 42 150 230 248 52 150 (-101)
2018-03-20 19:17:42,947 INFO     MQTT       Connecting to MQTT Server
2018-03-20 19:17:42,949 INFO     MQTT       Could not connect...
2018-03-20 20:14:53,557 DEBUG    emoncmsorg Buffer size: 1
2018-03-20 20:14:53,995 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 18 200 90 211 19 38 239 112 12 15 153 155 98 140 162 230 166 66 20 40 137 (-102)
2018-03-20 20:14:54,205 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 18 105 58 189 48 224 145 79 35 252 71 199 183 62 179 20 150 0 78 185 215 (-105)
2018-03-20 20:14:56,222 DEBUG    RFM2Pi     3 NEW FRAME : OK 5 0 0 0 0 0 0 175 95 30 0 180 0 85 0 0 0 0 0 0 0 1 0 0 0 (-0)
2018-03-20 20:14:56,225 DEBUG    RFM2Pi     3 Timestamp : 1521576896.22
2018-03-20 20:14:56,226 DEBUG    RFM2Pi     3 From Node : 5
2018-03-20 20:14:56,227 DEBUG    RFM2Pi     3    Values : [0, 0, 0, 244.95000000000002, 3, 18, 8.5, 0, 0, 0, 1]
2018-03-20 20:14:56,232 DEBUG    RFM2Pi     3 Sent to channel(start)' : ToEmonCMS
2018-03-20 20:14:56,233 DEBUG    RFM2Pi     3 Sent to channel(end)' : ToEmonCMS
2018-03-20 20:14:56,302 INFO     MQTT       Connecting to MQTT Server
2018-03-20 20:14:56,305 INFO     MQTT       Could not connect...
2018-03-20 20:14:59,055 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 5 73 164 32 146 237 227 175 21 104 192 75 100 152 164 32 30 127 107 226 189 (-105)
2018-03-20 20:14:59,669 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 24 208 159 52 243 141 160 34 136 106 40 240 100 152 164 32 30 127 107 226 189 (-110)
2018-03-20 20:15:01,285 DEBUG    RFM2Pi     4 NEW FRAME : OK 5 0 0 0 0 0 0 135 95 30 0 180 0 85 0 0 0 0 0 0 0 1 0 0 0 (-0)
2018-03-20 20:15:01,289 DEBUG    RFM2Pi     4 Timestamp : 1521576901.28
2018-03-20 20:15:01,290 DEBUG    RFM2Pi     4 From Node : 5
2018-03-20 20:15:01,291 DEBUG    RFM2Pi     4    Values : [0, 0, 0, 244.55, 3, 18, 8.5, 0, 0, 0, 1]
2018-03-20 20:15:01,292 DEBUG    RFM2Pi     4 Sent to channel(start)' : ToEmonCMS
2018-03-20 20:15:01,293 DEBUG    RFM2Pi     4 Sent to channel(end)' : ToEmonCMS
2018-03-20 20:15:01,334 INFO     MQTT       Connecting to MQTT Server
2018-03-20 20:15:01,337 INFO     MQTT       Could not connect...
2018-03-20 20:15:01,420 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 6 101 114 205 59 214 137 161 167 102 157 20 24 97 244 238 156 0 211 131 228 (-101)
2018-03-20 20:15:01,631 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 23 114 232 221 92 3 2 153 133 23 157 20 24 97 244 238 156 0 211 131 228 (-103)
2018-03-20 20:15:04,048 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 19 109 50 178 132 55 6 43 139 245 143 9 145 131 55 151 252 116 16 111 83 (-101)
2018-03-20 20:15:04,158 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 8 55 98 173 8 21 6 43 139 245 143 9 145 131 55 151 252 116 16 111 83 (-108)
2018-03-20 20:15:05,184 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 5 96 61 144 169 70 227 76 134 209 10 88 19 211 16 6 128 28 63 185 64 (-111)
2018-03-20 20:15:06,297 DEBUG    RFM2Pi     5 NEW FRAME : OK 5 0 0 0 0 0 0 159 95 31 0 180 0 85 0 0 0 0 0 0 0 1 0 0 0 (-0)
2018-03-20 20:15:06,301 DEBUG    RFM2Pi     5 Timestamp : 1521576906.3
2018-03-20 20:15:06,302 DEBUG    RFM2Pi     5 From Node : 5
2018-03-20 20:15:06,302 DEBUG    RFM2Pi     5    Values : [0, 0, 0, 244.79, 3.1, 18, 8.5, 0, 0, 0, 1]
2018-03-20 20:15:06,303 DEBUG    RFM2Pi     5 Sent to channel(start)' : ToEmonCMS
2018-03-20 20:15:06,304 DEBUG    RFM2Pi     5 Sent to channel(end)' : ToEmonCMS
2018-03-20 20:15:06,364 INFO     MQTT       Connecting to MQTT Server
2018-03-20 20:15:06,469 INFO     MQTT       connection status: Connection successful
2018-03-20 20:15:06,471 DEBUG    MQTT       CONACK => Return code: 0
2018-03-20 20:15:06,573 INFO     MQTT       on_subscribe
2018-03-20 20:15:07,230 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 0 208 118 175 196 206 42 121 76 233 240 213 237 224 5 161 234 82 106 120 111 (-99)
2018-03-20 20:15:07,943 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 11 37 202 50 150 205 200 57 221 128 48 143 6 45 96 147 120 40 87 108 112 (-102)
2018-03-20 20:15:08,155 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 17 224 151 111 11 117 17 143 249 96 230 28 123 59 223 176 99 160 23 12 144 (-101)
2018-03-20 20:15:08,570 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 4 17 208 34 248 23 126 94 20 232 216 46 32 28 181 193 5 136 30 15 249 (-102)
2018-03-20 20:15:11,305 DEBUG    RFM2Pi     6 NEW FRAME : OK 5 0 0 0 0 0 0 177 95 30 0 180 0 85 0 0 0 0 0 0 0 1 0 0 0 (-0)
2018-03-20 20:15:11,309 DEBUG    RFM2Pi     6 Timestamp : 1521576911.31
2018-03-20 20:15:11,310 DEBUG    RFM2Pi     6 From Node : 5
2018-03-20 20:15:11,311 DEBUG    RFM2Pi     6    Values : [0, 0, 0, 244.97, 3, 18, 8.5, 0, 0, 0, 1]
2018-03-20 20:15:11,311 DEBUG    RFM2Pi     6 Sent to channel(start)' : ToEmonCMS
2018-03-20 20:15:11,312 DEBUG    RFM2Pi     6 Sent to channel(end)' : ToEmonCMS
2018-03-20 20:15:11,401 DEBUG    MQTT       Publishing: emon/emonpi/power1 0
2018-03-20 20:15:11,403 DEBUG    MQTT       Publishing: emon/emonpi/power2 0
2018-03-20 20:15:11,404 DEBUG    MQTT       Publishing: emon/emonpi/power1pluspower2 0
2018-03-20 20:15:11,406 DEBUG    MQTT       Publishing: emon/emonpi/vrms 244.97
2018-03-20 20:15:11,407 DEBUG    MQTT       Publishing: emon/emonpi/t1 3
2018-03-20 20:15:11,409 DEBUG    MQTT       Publishing: emon/emonpi/t2 18
2018-03-20 20:15:11,410 DEBUG    MQTT       Publishing: emon/emonpi/t3 8.5
2018-03-20 20:15:11,412 DEBUG    MQTT       Publishing: emon/emonpi/t4 0
2018-03-20 20:15:11,417 DEBUG    MQTT       Publishing: emon/emonpi/t5 0
2018-03-20 20:15:11,419 DEBUG    MQTT       Publishing: emon/emonpi/t6 0
2018-03-20 20:15:11,421 DEBUG    MQTT       Publishing: emon/emonpi/pulsecount 1
2018-03-20 20:15:11,423 INFO     MQTT       Publishing: emonhub/rx/5/values 0,0,0,244.97,3,18,8.5,0,0,0,1
2018-03-20 20:15:11,428 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 0 20 246 167 178 205 247 114 227 131 242 203 126 147 74 159 249 239 31 228 155 (-110)
2018-03-20 20:15:11,641 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 22 62 160 31 218 9 234 20 73 172 171 144 131 183 113 48 112 128 196 239 40 (-105)
2018-03-20 20:15:11,852 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 27 206 74 108 176 243 144 223 161 48 115 38 116 160 241 242 90 61 20 202 96 (-107)
2018-03-20 20:15:14,710 DEBUG    RFM2Pi     Discarding RX frame 'unreliable content'? 10 36 121 108 121 149 185 219 166 2 100 54 112 214 50 101 239 78 235 77 123 (-100)

I’m rery much at the limit of my understanding, please help.

borpin · 20 March 2018 20:57

Did you run an update on the new image? Not sure if the image is the latest release.

Can you go into the admin page and click on ‘Copy to Clipboard’ next to the Server line and then paste it in a reply please.

Again try the commands, and post the results please,

pb66 · 20 March 2018 23:09

2018-03-20 19:17:39,943 WARNING  MainThread Setting emoncmsorg apikey: obscured

That line tells me you haven’t added your emoncmsorg write apikey to emonhub.conf.

If you add that you should see data at emoncms.org, from there you can see what data is present or missing.

You could try restarting the mqtt_input service as sometimes that needs restarting when new nodes are added (old fault but service may not have been restarted since update)

sudo systemctl restart mqtt_input

In fact, if you haven’t already, try a reboot to reset everything after the updates.

stabuck · 21 March 2018 06:55

Thank you for your help, I am making progress.

I ran the updaters on the Admin page on the emonPi and let them complete, they both appeared to make no changes.

/$ sudo systemctl status emonhub
● emonhub.service - LSB: Start/stop emonHub
   Loaded: loaded (/etc/init.d/emonhub)
   Active: active (exited) since Tue 2018-03-20 21:40:24 UTC; 8h ago

Mar 20 21:40:24 emonpi sudo[6436]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mkdir -p /var/log/emonhub
Mar 20 21:40:24 emonpi sudo[6436]: pam_unix(sudo:session): session opened for user root by (uid=0)
Mar 20 21:40:24 emonpi sudo[6436]: pam_unix(sudo:session): session closed for user root
Mar 20 21:40:24 emonpi sudo[6444]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/touch /var/log/emonhub/emonhub.log
Mar 20 21:40:24 emonpi sudo[6444]: pam_unix(sudo:session): session opened for user root by (uid=0)
Mar 20 21:40:24 emonpi sudo[6444]: pam_unix(sudo:session): session closed for user root
Mar 20 21:40:24 emonpi sudo[6453]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown -R emonhub /var/log/emonhub
Mar 20 21:40:24 emonpi sudo[6453]: pam_unix(sudo:session): session opened for user root by (uid=0)
Mar 20 21:40:24 emonpi sudo[6453]: pam_unix(sudo:session): session closed for user root
Mar 20 21:40:24 emonpi sudo[6462]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown -R emonhub /var/log/emonhub
Mar 20 21:40:24 emonpi sudo[6462]: pam_unix(sudo:session): session opened for user root by (uid=0)
Mar 20 21:40:24 emonpi sudo[6462]: pam_unix(sudo:session): session closed for user root
Mar 20 21:40:24 emonpi emonhub[6434]: Starting OpenEnergyMonitor emonHub: emonhub has been started ok.
Mar 20 21:40:24 emonpi systemd[1]: Started LSB: Start/stop emonHub.
/$ sudo systemctl status feedwriter
● feedwriter.service - LSB: feedwriter script daemon
   Loaded: loaded (/etc/init.d/feedwriter)
   Active: active (exited) since Tue 2018-03-20 21:28:47 UTC; 9h ago

Mar 20 21:17:22 emonpi systemd[1]: Starting LSB: feedwriter script daemon...
Mar 20 21:17:22 emonpi feedwriter[1660]: Log is turned off
Mar 20 21:17:22 emonpi feedwriter[1660]: Starting RPI
Mar 20 21:28:47 emonpi systemd[1]: Started LSB: feedwriter script daemon.
/$ sudo systemctl status mqtt_input
● mqtt_input.service - Emoncms MQTT Input Script
   Loaded: loaded (/etc/systemd/system/mqtt_input.service; enabled)
   Active: active (running) since Tue 2018-03-20 21:40:59 UTC; 8h ago
     Docs: https://github.com/emoncms/emoncms/blob/master/docs/RaspberryPi/MQTT.md
 Main PID: 7045 (php)
   CGroup: /system.slice/mqtt_input.service
           └─7045 /usr/bin/php /var/www/emoncms/scripts/phpmqtt_input.php

Mar 20 21:40:59 emonpi systemd[1]: Started Emoncms MQTT Input Script.

API corrected and data is now flowing from emonPi to emonCMS. You can see it working here - Emoncms - dashboard view

However, all feeds still showing as “inactive” on emonPi but all feeds now present and correct at emonCMS. Are there any other settings in emonhub.conf or anywhere else that I should look at? I had assumed they would come across with the backup file.

Running the command “sudo systemctl restart mqtt_input” seems to do nothing, the window just hangs.

Also the Admin option in the Setup drop down keeps disappearing, if I log out and log back in it reappears for a while and then disappears again. When the Admin option is not available, if I go to http://emonpi.local/emoncms/admin/view then I get the message “Admin re-authentication required”. Log out and back in again, and Admin becomes available again.

I have rebooted, no change.

I have to go to work now, I may not be home for 36 hours but I will be back, thank you again for all your help!

pb66 · 21 March 2018 11:30

I’m not sure what “the backup file” is as I do not know what you’ve done to migrate to the new image. If you have exported and imported the mysql tables then yes i would expect the same.

When you look at the inputs page is there any processing in the inputs or are they blank?

Since you have feeds on the feeds page but they are not updating, I suspect you have migrated the tables.

That doesn’t sound good.

That sounds correct, the user can remain logged in (using remember me) but the admin level session times out as a security feature (see Admin session expiry and logout).

There is another discussion going on about high memory usage by the mqtt_input service (see Mqtt_input service high memory usage) that may (or may not) be related, perhaps we might know more by the time you return.

stabuck · 21 March 2018 13:28

I used the backup facility on the EmonPi to back it up, then I cleared the SD card and installed the new OS onto it, then I used the facility on the same page in the EmonPi to import the backup files.

When I look at the Inputs page on the local EmonPi I see their current values, when I look at the Feeds page it says each is “inactive”.

When I run the “sudo systemctl status emonhub” or “sudo systemctl status feedwriter” or “sudo systemctl status mqtt_input” I get a response in the terminal window, stuff happens. When I run “sudo systemctl restart mqtt_input” nothing happens. I’ll read the high memory usage by the mqtt_input service thread now.

I’ll ignore the loss of Admin level access if that is a feature. Sorry for the red herring.

I am back home at some point tomorrow and will try out any suggestions then.

Thank you again!

pb66 · 21 March 2018 13:46

On the inputs page are there any blue blocks next to any of the inputs? These are the input processes that connect the feeds to the inputs.

When the inputs update the processes are run and that updates the feed values in redis which gets persisted every 60s by the feedwriter.

So

Are the correct inputs being updated, ie are there any duplicated inputs where some are being upadted and some not?
Is the input processing present and correct? ie are those blue blocks there on the inputs page and no red error blocks?
is the feedwriter running? You can check that on the admin page and/or using “sudo systemctl status feedwriter”
Are the permissions for the data files ok? Check to see if there are any errors in the emoncms,log from the admin page.
Is there room for the data? did you expand the emonSD image to fit the SD card? Use the “df -h” command to check the disk usage.

Ok then can you try these 3 commands in turn and post the complete output

sudo systemctl status mqtt_input
sudo systemctl stop mqtt_input
sudo systemctl start mqtt_input

Although I’m starting to think the issue is less likely to be the mqtt_input service if you can see the input values changing on the emoncms inputs page. (and therefore the other thread is unlikely to be related)

borpin · 21 March 2018 21:42

Both strike me as odd as I’d expect Active: active (running) in the status but if data is getting to emoncms.org both must be running. Confused!

Did you go through the setup process? Although some of the config will come across, I’d expect some of the system configurations to need updating.

Strictly you do not get any output to the terminal (which in this case, no news is good news). if you then do a ‘status’ command you will see it has been running for a few seconds (i.e. it has just been restarted).

pb66 · 21 March 2018 22:41

Good point Brian I was still focused on the previous comment

@stabuck can you confirm if the command prompt is returning almost imediately or if you are waiting indefinitely for that to happen? and as Brian says, you can check the running time has restarted by checking the status.

stabuck · 22 March 2018 12:25

At http://emonpi.local/emoncms/input/view
I see no blue or red blocks. All the Inputs are present and correct, I see none that are not updating, I see no weird values, I see no duplications.

/var/log/emoncms.log

2018-03-21 07:51:32.957|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-03-21 07:51:32.976|WARN|phpmqtt_input.php|Not connected, retrying connection
2018-03-21 07:51:38.002|WARN|phpmqtt_input.php|Not connected, retrying connection
2018-03-21 07:51:38.004|WARN|phpmqtt_input.php|Connecting to MQTT server: Connection Accepted.: code: 0
2018-03-21 07:51:46.866|WARN|phpmqtt_input.php|Not connected, retrying connection
2018-03-21 07:51:46.889|WARN|phpmqtt_input.php|Connecting to MQTT server: Connection Accepted.: code: 0
2018-03-22 12:10:35.390|WARN|phpmqtt_input.php|Not connected, retrying connection
2018-03-22 12:10:35.415|WARN|phpmqtt_input.php|Connecting to MQTT server: Connection Accepted.: code: 0

/$ sudo systemctl status feedwriter

/$ sudo systemctl status feedwriter
feedwriter.service - LSB: feedwriter script daemon
Loaded: loaded (/etc/init.d/feedwriter)
Active: active (running) since Wed 2018-03-21 07:51:33 UTC; 1 day 4h ago
Process: 1663 ExecStart=/etc/init.d/feedwriter start (code=exited, status=0/SUCCESS)
CGroup: /system.slice/feedwriter.service
           └─1851 /usr/bin/php -f /var/www/emoncms/scripts/feedwriter.php

Mar 21 07:17:22 emonpi feedwriter[1663]: Log is turned off
Mar 21 07:17:22 emonpi feedwriter[1663]: Starting RPI
Mar 21 07:51:33 emonpi systemd[1]: Started LSB: feedwriter script daemon.

/$ df -h

/$ df -h
Filesystem      Size  Used Avail Use% Mounted on
/dev/root       3.4G  2.0G  1.2G  63% /
devtmpfs        481M     0  481M   0% /dev
tmpfs           486M     0  486M   0% /dev/shm
tmpfs           486M   19M  467M   4% /run
tmpfs           5.0M  4.0K  5.0M   1% /run/lock
tmpfs           486M     0  486M   0% /sys/fs/cgroup
tmpfs            40M  6.6M   34M  17% /var/lib/openhab
tmpfs           1.0M  4.0K 1020K   1% /var/lib/dhcpcd5
tmpfs           1.0M  4.0K 1020K   1% /var/lib/dhcp
tmpfs            50M  5.3M   45M  11% /var/log
tmpfs            30M   36K   30M   1% /tmp
/dev/mmcblk0p1   60M   22M   39M  37% /boot
/dev/mmcblk0p3  969M   97M  823M  11% /home/pi/data

/$ sudo systemctl status mqtt_input

/$ sudo systemctl status mqtt_input
mqtt_input.service - Emoncms MQTT Input Script
Loaded: loaded (/etc/systemd/system/mqtt_input.service; enabled)
Active: active (running) since Wed 2018-03-21 07:51:44 UTC; 1 day 4h ago
Docs: https://github.com/emoncms/emoncms/blob/master/docs/RaspberryPi/MQTT.md
Main PID: 1993 (php)
CGroup: /system.slice/mqtt_input.service
           └─1993 /usr/bin/php /var/www/emoncms/scripts/phpmqtt_input.php

Mar 21 07:51:44 emonpi systemd[1]: Started Emoncms MQTT Input Script.
/$ sudo systemctl stop mqtt_input
/$ sudo systemctl start mqtt_input

Did you go through the setup process? Although some of the config will come across, I’d expect some of the system configurations to need updating.

I am going to send this message and then check to see…