Emonhub died

Not had a chance to investigate, but emonhub died on me. There were a number of exceptions before this.

It has been running for weeks - possibly months (since the last power cut). I do think this is a pretty old version though - actually a beta of the Python3.

I’ll reinstall tomorrow and see what happens.

pi@raspberrypi:/opt/openenergymonitor/emonhub $ git show
commit 6975b0d36099f43871c47b8639dcfd6c05532ef9 (HEAD -> python3, origin/python3)
Author: Bruce Duncan <[email protected]>
Date:   Tue Dec 10 13:48:31 2019 +0000

    Use a beta version number.

diff --git a/src/emonhub.py b/src/emonhub.py
index 52243c4..d7112bd 100755
--- a/src/emonhub.py
+++ b/src/emonhub.py
@@ -49,7 +49,7 @@ Controlled by the user via EmonHubSetup

 class EmonHub:

-    __version__ = "emonHub emon-pi variant v3"
+    __version__ = "emonHub emon-pi variant v3-beta"

     def __init__(self, setup):
         """Setup an OpenEnergyMonitor emonHub.

Logs around the crash.

2021-01-09 14:17:41,974 WARNING  MainThread emoncmsorg thread is dead.
2021-01-09 14:17:41,977 WARNING  MainThread Attempting to restart thread emoncmsorg (thread has been restarted 96 times...
2021-01-09 14:17:41,984 INFO     MainThread Setting RFM2Pi quiet: 1 (1q)
2021-01-09 14:17:42,050 DEBUG    RFM2Pi     acknowledged command: > 1q
2021-01-09 14:17:42,989 INFO     MainThread Setting RFM2Pi calibration: 230V (1p)
2021-01-09 14:17:43,064 DEBUG    RFM2Pi     acknowledged command: > 1p
2021-01-09 14:17:43,529 DEBUG    RFM2Pi     acknowledged command: <nn> i     - set node ID (standard node ids are 1..26)
2021-01-09 14:17:43,654 DEBUG    RFM2Pi     acknowledged command: <n> b      - set MHz band (4 = 433, 8 = 868, 9 = 915)
2021-01-09 14:17:43,785 DEBUG    RFM2Pi     acknowledged command: <nnn> g    - set network group (RFM12 only allows 212, 0 = any)
2021-01-09 14:17:43,910 DEBUG    RFM2Pi     acknowledged command: <n> c      - set collect mode (advanced, normally 0)
2021-01-09 14:17:43,996 INFO     MainThread Creating EmonHubEmoncmsHTTPInterfacer 'emoncmsorg'
2021-01-09 14:17:44,002 DEBUG    MainThread Setting emoncmsorg pubchannels: ['ToRFM12']
2021-01-09 14:17:44,005 DEBUG    MainThread Setting emoncmsorg subchannels: ['ToEmonCMS']
2021-01-09 14:17:44,008 INFO     MainThread Setting emoncmsorg apikey: set
2021-01-09 14:17:44,010 INFO     MainThread Setting emoncmsorg url: http://192.168.7.47/emoncms
2021-01-09 14:17:44,013 INFO     MainThread Setting emoncmsorg senddata: 1
2021-01-09 14:17:44,023 INFO     MainThread Setting emoncmsorg sendstatus: 1
2021-01-09 14:17:44,043 DEBUG    RFM2Pi     acknowledged command: ...,<nn> a - send data packet to node <nn>, with ack
2021-01-09 14:17:44,167 DEBUG    RFM2Pi     acknowledged command: ...,<nn> s - send data packet to node <nn>, no ack
2021-01-09 14:17:44,355 DEBUG    RFM2Pi     acknowledged command: <n> l      - turn activity LED on DIG8 on or off
2021-01-09 14:17:44,581 DEBUG    RFM2Pi     device settings updated: 69 i5 g210 @ 433 MHz  Lock: 1
2021-01-09 14:17:51,720 DEBUG    RFM2Pi     741116 NEW FRAME : 10 145 4 0 0 0 0 0 0 128 92 48 117 48 117 48 117 48 117 48 117 48 117 0 0 0 0
2021-01-09 14:17:51,731 DEBUG    RFM2Pi     741116 Timestamp : 1610201871.7198367
2021-01-09 14:17:51,734 DEBUG    RFM2Pi     741116 From Node : 10
2021-01-09 14:17:51,737 DEBUG    RFM2Pi     741116    Values : [1169, 0, 0, 0, 236.8, 300, 300, 300, 300, 300, 300, 0]
2021-01-09 14:17:51,740 DEBUG    RFM2Pi     741116 Sent to channel(start)' : ToEmonCMS
2021-01-09 14:17:51,743 DEBUG    RFM2Pi     741116 Sent to channel(end)' : ToEmonCMS
2021-01-09 14:17:51,989 INFO     MQTT       Connecting to MQTT Server
2021-01-09 14:17:51,993 INFO     MQTT-193   Connecting to MQTT Server
2021-01-09 14:17:52,007 INFO     MQTT-193   Could not connect...
2021-01-09 14:17:52,011 INFO     MQTT       Could not connect...
2021-01-09 14:17:52,035 DEBUG    emoncmsorg Buffer size: 1
2021-01-09 14:17:52,038 INFO     emoncmsorg sending: http://192.168.7.47/emoncms/input/bulk.json?apikey=E-M-O-N-C-M-S-A-P-I-K-E-Y&data=[[1610201871.7198367,10,1169,0,0,0,236.8,300,300,300,300,300,300,0]]&sentat=1610201872
2021-01-09 14:17:52,078 WARNING  emoncmsorg emoncmsorg couldn't send to server: HTTPConnectionPool(host='192.168.7.47', port=80): Max retries exceeded with url: /emoncms/input/bulk.json?apikey=XXXXXX(Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0xb3822d10>: Failed to establish a new connection: [Errno 101] Network is unreachable'))
2021-01-09 14:17:52,084 WARNING  emoncmsorg Exception caught in emoncmsorg thread. Traceback (most recent call last):
  File "/opt/openenergymonitor/emonhub/src/emonhub_interfacer.py", line 32, in wrapper
    return f(*args)
  File "/opt/openenergymonitor/emonhub/src/emonhub_interfacer.py", line 127, in run
    self.action()
  File "/opt/openenergymonitor/emonhub/src/emonhub_interfacer.py", line 198, in action
    self.flush()
  File "/opt/openenergymonitor/emonhub/src/emonhub_interfacer.py", line 216, in flush
    if self._process_post(databuffer):
  File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubEmoncmsHTTPInterfacer.py", line 71, in _process_post
    reply = self._send_post(post_url, {'data': data_string, 'sentat': str(sentat)})
  File "/opt/openenergymonitor/emonhub/src/emonhub_interfacer.py", line 257, in _send_post
    return reply.text
UnboundLocalError: local variable 'reply' referenced before assignment

2021-01-09 14:17:52,096 WARNING  MainThread emoncmsorg thread is dead.
2021-01-09 14:17:52,099 WARNING  MainThread Attempting to restart thread emoncmsorg (thread has been restarted 97 times...
2021-01-09 14:17:52,106 INFO     MainThread Setting RFM2Pi quiet: 1 (1q)
2021-01-09 14:17:52,156 DEBUG    RFM2Pi     acknowledged command: > 1q
2021-01-09 14:17:53,111 INFO     MainThread Setting RFM2Pi calibration: 230V (1p)
2021-01-09 14:17:53,169 DEBUG    RFM2Pi     acknowledged command: > 1p
2021-01-09 14:17:53,636 DEBUG    RFM2Pi     acknowledged command: <nn> i     - set node ID (standard node ids are 1..26)
2021-01-09 14:17:53,761 DEBUG    RFM2Pi     acknowledged command: <n> b      - set MHz band (4 = 433, 8 = 868, 9 = 915)
2021-01-09 14:17:53,890 DEBUG    RFM2Pi     acknowledged command: <nnn> g    - set network group (RFM12 only allows 212, 0 = any)
2021-01-09 14:17:54,015 DEBUG    RFM2Pi     acknowledged command: <n> c      - set collect mode (advanced, normally 0)
2021-01-09 14:17:54,118 INFO     MainThread Creating EmonHubEmoncmsHTTPInterfacer 'emoncmsorg'
2021-01-09 14:17:54,124 DEBUG    MainThread Setting emoncmsorg pubchannels: ['ToRFM12']
2021-01-09 14:17:54,135 DEBUG    MainThread Setting emoncmsorg subchannels: ['ToEmonCMS']
2021-01-09 14:17:54,137 INFO     MainThread Setting emoncmsorg apikey: set
2021-01-09 14:17:54,140 INFO     MainThread Setting emoncmsorg url: http://192.168.7.47/emoncms
2021-01-09 14:17:54,153 INFO     MainThread Setting emoncmsorg senddata: 1
2021-01-09 14:17:54,156 INFO     MainThread Setting emoncmsorg sendstatus: 1
2021-01-09 14:17:54,166 DEBUG    RFM2Pi     acknowledged command: ...,<nn> a - send data packet to node <nn>, with ack
2021-01-09 14:17:54,290 DEBUG    RFM2Pi     acknowledged command: ...,<nn> s - send data packet to node <nn>, no ack
2021-01-09 14:17:54,448 DEBUG    RFM2Pi     acknowledged command: <n> l      - turn activity LED on DIG8 on or off
2021-01-09 14:17:54,696 DEBUG    RFM2Pi     device settings updated: 69 i5 g210 @ 433 MHz  Lock: 1
2021-01-11 20:28:54,257 INFO     MainThread EmonHub emonHub emon-pi variant v3-beta
2021-01-11 20:28:54,274 INFO     MainThread Opening hub...
2021-01-11 20:28:54,277 INFO     MainThread Logging level set to DEBUG

Wow! Where to start?

What is this? Is it a Pi with a rfm2pi board? I assume not an emonPi?

Where is the MQTT broker? on the LAN or on the same machine?

Is it WiFi or Ethernet?

On the surface it looks like a network issue.

2021-01-09 14:17:51,989 INFO     MQTT       Connecting to MQTT Server
2021-01-09 14:17:51,993 INFO     MQTT-193   Connecting to MQTT Server
2021-01-09 14:17:52,007 INFO     MQTT-193   Could not connect...
2021-01-09 14:17:52,011 INFO     MQTT       Could not connect...
. . . 
2021-01-09 14:17:52,038 INFO     emoncmsorg sending: http://192.168.7.47/emoncms/input/bulk.json?apikey=E-M-O-N-C-M-S-A-P-I-K-E-Y&data=[[1610201871.7198367,10,1169,0,0,0,236.8,300,300,300,300,300,300,0]]&sentat=1610201872
2021-01-09 14:17:52,078 WARNING  emoncmsorg emoncmsorg couldn't send to server: HTTPConnectionPool(host='192.168.7.47', port=80): Max retries exceeded with url: /emoncms/input/bulk.json?apikey=1fc1d6d9d679a35a3dfe38758b18b94e (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0xb3822d10>: Failed to establish a new connection: [Errno 101] Network is unreachable'))

Not sure why “Could not connect…” is only INFO level not warning but that’s not the cause.

The emoncmsorg thread is crashing and being repeatedly restarted to no avail, 97 times so far, I wonder if there is a limit??? I’m not convinced this approach is the best way to get things fixed, just keep trying until it works then carry on as if it didn’t happen isn’t great.

2021-01-09 14:17:52,096 WARNING  MainThread emoncmsorg thread is dead.
2021-01-09 14:17:52,099 WARNING  MainThread Attempting to restart thread emoncmsorg (thread has been restarted 97 times...

but at least the traceback is there

  File "/opt/openenergymonitor/emonhub/src/emonhub_interfacer.py", line 257, in _send_post
    return reply.text
UnboundLocalError: local variable 'reply' referenced before assignment

is correct looking at the current code

as reply isn’t declared before the try/catch so if it fails, there is no reply let alone a reply.text hence it falls over.

probably just needs something like reply = None before the try/catch and then the return expanded to return the text if/when available, but even that’s a bit messy.

Assuming the previous 96 tracebacks are the same it would suggest a simple network issue poorly handled in emonhub. Had the network issue cleared before you noticed, the issue “referenced before assignment” might have never been spotted.

I’m intrigued as to why the rfm2pi settings are repeating after just 10 secs

2021-01-09 14:17:41,984 INFO     MainThread Setting RFM2Pi quiet: 1 (1q)
2021-01-09 14:17:42,050 DEBUG    RFM2Pi     acknowledged command: > 1q
2021-01-09 14:17:42,989 INFO     MainThread Setting RFM2Pi calibration: 230V (1p)
2021-01-09 14:17:43,064 DEBUG    RFM2Pi     acknowledged command: > 1p
. . . . 
2021-01-09 14:17:52,106 INFO     MainThread Setting RFM2Pi quiet: 1 (1q)
2021-01-09 14:17:52,156 DEBUG    RFM2Pi     acknowledged command: > 1q
2021-01-09 14:17:53,111 INFO     MainThread Setting RFM2Pi calibration: 230V (1p)
2021-01-09 14:17:53,169 DEBUG    RFM2Pi     acknowledged command: > 1p

probably unrelated but it doesn’t look like the rfm2pi interfacer is being restarted so why it’s repeating parts of the settings I’m not sure. Does it do that all the time? possibly some loose ends being dragged through by the emoncmsorg interfacer restarting.

The 1p command isn’t recognised by the serial device (rfm2pi?) hence the noise returned, listing the available commands.

2021-01-09 14:17:42,989 INFO     MainThread Setting RFM2Pi calibration: 230V (1p)
2021-01-09 14:17:43,064 DEBUG    RFM2Pi     acknowledged command: > 1p
2021-01-09 14:17:43,529 DEBUG    RFM2Pi     acknowledged command: <nn> i     - set node ID (standard node ids are 1..26)
2021-01-09 14:17:43,654 DEBUG    RFM2Pi     acknowledged command: <n> b      - set MHz band (4 = 433, 8 = 868, 9 = 915)
2021-01-09 14:17:43,785 DEBUG    RFM2Pi     acknowledged command: <nnn> g    - set network group (RFM12 only allows 212, 0 = any)
2021-01-09 14:17:43,910 DEBUG    RFM2Pi     acknowledged command: <n> c      - set collect mode (advanced, normally 0)

but why it’s reoccurring and why the 1q is getting in on the action is unclear.

So probably just a network issue perhaps?

Pi with an RFM2Pi board and just emonhub installled.

LAN - (ProxmoxVE LXC container - just the best implementation).

However, I think this is the HTTP interfacer that is failing (as there is a URL) - I could be wrong.

Yes almost certainly as it is a wired connection and I was moving it to a new switch.

I’d have hoped it handled it better though.

You don’t need to decalare variables in Python3 I think. The issue is that the exception tries to return it when it has not been set to anything.

I’m not clear (as in I do not understand the architecture of emonhub sufficiently) if the function should simply not return anything and let the exception propagate, or set the reply to something the calling process can intelligently work with to know the send failed.

I think the assumption was that the exception would only be raised if 200 was not returned in which case there would be some reply text.

You should comment out the calibration = 230V line in emonhub.conf, that is only understood by the emonpi boards.

Indeed, the MQTT was also not connecting was just hint towards a network issue.

Absolutely, that is a core facility of emonhub to be able to hold the data locally until it can post, as you know. This is what I would call a “normal” error situation that emonhub should be able to easily ride out with no loss of data.

Correct, in any Python you can just assign values to unassigned variables eg

        reply = requests.post(post_url, post_body, timeout=60)

but what you cannot do is reference something that hasn’t been assigned eg

return reply.text

that line depends on reply being assigned by either the if or else lines in the try/catch, if that code was robust enough to always succeed it would not need to be in a try/catch.

No, I’m not sure what exactly is wanted/needed. I try to wear heavy blinkers when looking at emonhub code and look very locally at just the bit in question to avoid noticing other issues.

Looking at it again, perhaps the best “quick fix” would be to just change that last line

return reply.text

to something with an indent so it gets returned only in the case of the exception.

    return None

currently line 255 is redundant as the last line is called in all cases, putting different return values inside the try and except would negate the need for pre-assignment of reply and the return value in the exception can be tailored to the application, a warning string or failure flag etc.

I just opened an emonhub issue for this

and was rather blown away to only just realise this “http” code is in the main core emonhub_interfacer.py file when it should be in the http interfacer. At that point I decided not to delve any deeper so I can’t recommend an exception return value.

1 Like

That’s a good point :frowning:

I also found that simply restarting the service did not bring the RFM card back to life, nor did a soft reboot. It needed a hard power cycle.

That’s to be expected, emonhub has no control over the reset line of the rfm2pi mcu so restarting emonhub or indeed rebooting the os will not reset the rfm2pi, that’s a HW limitation.

If your rfm gets stuck eg a brownout, and I am referring to the rfm module onboard the rfm device rather than the whole device. You can “bring the RFM card back to life” by simply changing an rfm runtimesetting in emonhub.conf eg change the base id, group of freq, then save, then change it back and save. This causes the rfm2pi FW to reinitialise the rfm module after applying the change of settings.

For other “reset” situations, somewhere buried on the forums is a little script I wrote to pulse the reset pin (gpio4 pin 7) by running rfm2pi_reset from the commandline but I doubt it’s included on the image.

[edit] Here ya go I just searched for “reset_rfm2pi” and found this

[edit2] A little more info. The script used to be downloadable from the old oem forum. Looking at the post referenced ( RFM12PI receiver goes hard down sometimes) within the script from that linked post above, I’ve posted this code a couple of times

sudo wget -O /usr/bin/reset_rfm2pi http://openenergymonitor.org/emon/sites/default/files/reset_rfm2pi.txt
sudo chmod +x /usr/bin/reset_rfm2pi

which was an easy way to download and install the reset script to avoid the need for power cycling (no longer available on the url), I wonder if it’s still out there somewhere or perhaps we can put it in useful scripts or something?

1 Like

I did a Google on reset_rfm2pi.txt which threw up https://openenergymonitor.org/forum-archive/sites/default/files/reset_rfm2pi.txt :slight_smile:.

For posterity

#!/usr/bin/env python
"""


"""

__author__ = 'Paul Burnell (pb66)'
__date__ = '14-05-2015'
# http://openenergymonitor.org/emon/node/5549

import RPi.GPIO as GPIO
import time

pin = 7 # P1-7 (BCM pin 4 or WiringPi pin 7)

try:
	GPIO.setmode(GPIO.BOARD)
	GPIO.setup(pin, GPIO.OUT)
	GPIO.output(pin, GPIO.HIGH)
	time.sleep(0.12)
	GPIO.output(pin, GPIO.LOW)
	GPIO.cleanup()
except Exception as e:
	print(e)

Does this need a Python3 wand?

Putting a python3 version in usefulscripts sounds like a plan.

[edit]
Thinking about it, is there any reason not to provide this from the emonhub UI?

Well done, so it’s just swapping “emon/” for “forum-archive/” in the url path due to the old forum being archived.

I doubt it, there’s really not that much to it, you could try it, the new commands would be

sudo wget -O /usr/bin/reset_rfm2pi http://openenergymonitor.org/forum-archive/sites/default/files/reset_rfm2pi.txt
sudo chmod +x /usr/bin/reset_rfm2pi

To force Python3 just add a “3” to the end of the shebang

Putting a python3 compatible version in usefulscripts, yes, But it does not need to be exclusively python3! Keeping it as just python, would allow it to run on which ever python version is invoked, there are many old OEM images out there still and even the very latest RaspiOS still uses python2 by default, I’m aware it’s “officially EoL” but it’s still very much alive in reality. There is no good reason to exclude users unless unavoidable.

True but currently I think python defaults to 2.7 in most cases and 2.7 is EOL.

As I said

Any user that wants all “python” to specifically run as “python3” rather than “python2” can change the default on their OS, it’s not for us to demand they only use python3. The script doesn’t need to be py3 so it just needs to be left alone to be assigned by the OS.

Just overwrite the hyperlink to point at python3

pi@Pi4:~ $ ls -la /usr/bin/python
lrwxrwxrwx 1 root root 7 Mar  4  2019 /usr/bin/python -> python2

and any “python” shebang will result in python3.

Sorry missed that bit.

[edit]
Not forcing anyone to do anything, which was why I suggested putting a ‘compatible’ version in (if there is anything incompatible) - implicitly, the original can go there as well.