Power outage, and suddenly stops sending data to emoncms

lukew151 · 19 February 2024 21:34

I had a mains power outage at the weekend. Since the power returned, I’ve had no data from my EmonHub to my EmonCMS - despite there being zero configuration changes. This has worked for years, and now it’s just stopped, and I’m losing my mind trying to work out why.

I have two emonTX in different parts of the house.
I have a Raspberry Pi with a RFM69 receiver, this runs EmonHub.
I have a separate atom PC running EmonCMS.
I have yet another Raspberry Pi, sending temperatures to EmonCMS.

On the PC (3) EmonCMS is running fine, and it’s receiving the temperatures every minute from pi (4) - apache access.log:

172.29.181.242 - - [19/Feb/2024:21:06:02 +0000] "GET /emoncms/input/post.json?node=1&json=%7B%22Tbed%22:17.750%7D&apikey=<key> HTTP/1.1" 200 
172.29.181.242 - - [19/Feb/2024:21:07:02 +0000] "GET /emoncms/input/post.json?node=1&json=%7B%22Tbed%22:17.750%7D&apikey=<key> HTTP/1.1" 200 
172.29.181.242 - - [19/Feb/2024:21:08:02 +0000] "GET /emoncms/input/post.json?node=1&json=%7B%22Tbed%22:17.750%7D&apikey=<key> HTTP/1.1" 200 
172.29.181.242 - - [19/Feb/2024:21:09:02 +0000] "GET /emoncms/input/post.json?node=1&json=%7B%22Tbed%22:17.687%7D&apikey=<key> HTTP/1.1" 200 
172.29.181.242 - - [19/Feb/2024:21:10:02 +0000] "GET /emoncms/input/post.json?node=1&json=%7B%22Tbed%22:17.687%7D&apikey=<key> HTTP/1.1" 200 
172.29.181.242 - - [19/Feb/2024:21:11:02 +0000] "GET /emoncms/input/post.json?node=1&json=%7B%22Tbed%22:17.687%7D&apikey=<key> HTTP/1.1" 200 
172.29.181.242 - - [19/Feb/2024:21:12:02 +0000] "GET /emoncms/input/post.json?node=1&json=%7B%22Tbed%22:17.687%7D&apikey=<key> HTTP/1.1" 200 
172.29.181.242 - - [19/Feb/2024:21:13:02 +0000] "GET /emoncms/input/post.json?node=1&json=%7B%22Tbed%22:17.687%7D&apikey=<key> HTTP/1.1" 200 
172.29.181.242 - - [19/Feb/2024:21:14:02 +0000] "GET /emoncms/input/post.json?node=1&json=%7B%22Tbed%22:17.687%7D&apikey=<key> HTTP/1.1" 200 
172.29.181.242 - - [19/Feb/2024:21:15:02 +0000] "GET /emoncms/input/post.json?node=1&json=%7B%22Tbed%22:17.687%7D&apikey=<key> HTTP/1.1" 200

However, we’re getting absolutely nothing from EmonHub (2). Nothing in apache error.log either.

Checking EmonHub on (2) with the debug logging enabled. EmonHub is running, and it’s receiving data from both EmonTX (1):

2024-02-19 21:18:48,447 DEBUG    RFM2Pi     2523 NEW FRAME : OK 8 239 0 0 0 0 0 0 0 103 96 180 0 184 11 184 11 184 11 184 11 184 11 1 0 0 0 (-48)
2024-02-19 21:18:48,451 DEBUG    RFM2Pi     2523 Timestamp : 1708377528.447455
2024-02-19 21:18:48,452 DEBUG    RFM2Pi     2523 From Node : 8
2024-02-19 21:18:48,454 DEBUG    RFM2Pi     2523    Values : [239, 0, 0, 0, 246.79, 18, 300, 300, 300, 300, 300, 1]
2024-02-19 21:18:48,455 DEBUG    RFM2Pi     2523      RSSI : -48
2024-02-19 21:18:48,456 DEBUG    RFM2Pi     2523 Sent to channel(start)' : ToEmonCMS
2024-02-19 21:18:48,457 DEBUG    RFM2Pi     2523 Sent to channel(end)' : ToEmonCMS
2024-02-19 21:18:57,405 DEBUG    RFM2Pi     2524 NEW FRAME : OK 15 117 92 85 85 117 55 82 85 85 85 85 85 85 85 84 84 85 85 70 85 85 85 85 85 85 85 85 85 85 85 67 90 101 32 101 32 84 85 85 85 (-70)
2024-02-19 21:18:57,409 DEBUG    RFM2Pi     2524 Timestamp : 1708377537.405045
2024-02-19 21:18:57,411 DEBUG    RFM2Pi     2524 From Node : 15
2024-02-19 21:18:57,412 DEBUG    RFM2Pi     2524    Values : [2336, 251.20000000000002, 7, 0, 0, 0, 257, 19, 0, 0, 38.62, 300, 300, 1, 50, 3.849114703618168]
2024-02-19 21:18:57,413 DEBUG    RFM2Pi     2524      RSSI : -70
2024-02-19 21:18:57,414 DEBUG    RFM2Pi     2524 Sent to channel(start)' : ToEmonCMS
2024-02-19 21:18:57,415 DEBUG    RFM2Pi     2524 Sent to channel(end)' : ToEmonCMS
2024-02-19 21:19:07,365 DEBUG    RFM2Pi     2525 NEW FRAME : OK 15 116 92 85 85 116 55 82 85 85 85 85 85 85 85 84 84 85 85 70 85 85 85 85 85 85 85 85 85 85 85 67 90 101 32 101 32 84 85 85 85 (-71)
2024-02-19 21:19:07,370 DEBUG    RFM2Pi     2525 Timestamp : 1708377547.365289
2024-02-19 21:19:07,371 DEBUG    RFM2Pi     2525 From Node : 15
2024-02-19 21:19:07,372 DEBUG    RFM2Pi     2525    Values : [2337, 251.21, 7, 0, 0, 0, 257, 19, 0, 0, 38.62, 300, 300, 1, 50, 3.8461538461538463]
2024-02-19 21:19:07,373 DEBUG    RFM2Pi     2525      RSSI : -71
2024-02-19 21:19:07,374 DEBUG    RFM2Pi     2525 Sent to channel(start)' : ToEmonCMS
2024-02-19 21:19:07,376 DEBUG    RFM2Pi     2525 Sent to channel(end)' : ToEmonCMS
2024-02-19 21:19:08,291 DEBUG    RFM2Pi     2526 NEW FRAME : OK 8 235 0 0 0 0 0 0 0 82 96 180 0 184 11 184 11 184 11 184 11 184 11 1 0 0 0 (-48)
2024-02-19 21:19:08,295 DEBUG    RFM2Pi     2526 Timestamp : 1708377548.291056
2024-02-19 21:19:08,296 DEBUG    RFM2Pi     2526 From Node : 8
2024-02-19 21:19:08,297 DEBUG    RFM2Pi     2526    Values : [235, 0, 0, 0, 246.58, 18, 300, 300, 300, 300, 300, 1]
2024-02-19 21:19:08,299 DEBUG    RFM2Pi     2526      RSSI : -48
2024-02-19 21:19:08,300 DEBUG    RFM2Pi     2526 Sent to channel(start)' : ToEmonCMS
2024-02-19 21:19:08,301 DEBUG    RFM2Pi     2526 Sent to channel(end)' : ToEmonCMS

Creating a firewall rule, and leaving it to run for 10 mins on (2), confirms that no packets are being sent by EmonHub:

sudo nft add rule filter OUTPUT ip daddr 172.29.181.222 tcp dport 80 counter accept
#wait 10 mins
sudo nft list chain filter OUTPUT
table ip filter {
	chain OUTPUT {
		type filter hook output priority filter; policy accept;
		ip daddr 172.29.181.222 tcp dport 80 counter packets 0 bytes 0 accept
	}
}
ping 172.29.181.222
PING 172.29.181.222 (172.29.181.222) 56(84) bytes of data.
64 bytes from 172.29.181.222: icmp_seq=1 ttl=64 time=1.12 ms
64 bytes from 172.29.181.222: icmp_seq=2 ttl=64 time=0.695 ms
^C

EmonHub config is unchanged, and I’m at a loss as to why it’s suddenly just stopped sending packets to EmonCMS. EmonHub config:

[interfacers]
### This interfacer manages the RFM12Pi/RFM69Pi/emonPi module
[[RFM2Pi]]
    Type = EmonHubJeeInterfacer
    [[[init_settings]]]
        com_port = /dev/ttyAMA0
        com_baud = 38400                        # 9600 for old RFM12Pi
    [[[runtimesettings]]]
        pubchannels = ToEmonCMS,
        subchannels = ToRFM12,

        group = 210
        frequency = 433
        baseid = 5                              # emonPi / emonBase nodeID
        calibration = 230V                      # (UK/EU: 230V, US: 110V)
[[emoncmsorg]]
    Type = EmonHubEmoncmsHTTPInterfacer
    [[[init_settings]]]
    [[[runtimesettings]]]
        pubchannels = ToRFM12,
        subchannels = ToEmonCMS,
        url = http://172.29.181.222/emoncms
        apikey = xxxx my Api  is correct xxxx
        senddata = 1                    # Enable sending data to Emoncms.org
        sendstatus = 1                  # Enable sending WAN IP to Emoncms.org MyIP > https://emoncms.org/myip/list
        sendinterval= 30                # Bulk send interval to Emoncms.org in seconds
        sendnames = 1

(cut the [nodes] stanza for brevity) none of this config has changed. This is driving me crazy! Why aren’t I seeing any traffic from EmonHub to EmonCMS?

borpin · 20 February 2024 07:08

Has the IP address of the Emoncms machine changed?

Open 2 SSH windows and on one follow the system log journalctl -f -u emonhub and in the other restart emonhub sudo systemctl restart emonhub.service

What emonhub log do you see at startup?

lukew151 · 20 February 2024 08:27

Neither IP address has changed, still .222 and .243

The start-up log for emonhub is:

2024-02-20 08:23:51,584 INFO     MainThread EmonHub v2.6.5
2024-02-20 08:23:51,586 INFO     MainThread Opening hub...
2024-02-20 08:23:51,587 INFO     MainThread Running as user: luke
2024-02-20 08:23:51,588 INFO     MainThread Logging level set to DEBUG
2024-02-20 08:23:51,588 INFO     MainThread Creating EmonHubJeeInterfacer 'RFM2Pi'
2024-02-20 08:23:51,591 DEBUG    MainThread Opening serial port: /dev/ttyAMA0 @ 38400 bits/s
2024-02-20 08:23:53,600 INFO     MainThread RFM2Pi device firmware version: [RF12demo.12]
2024-02-20 08:23:53,601 INFO     MainThread RFM2Pi device current settings:  E i5 g210 @ 433 MHz q1
2024-02-20 08:23:53,603 INFO     MainThread Setting RFM2Pi calibration: 230V (1p)
2024-02-20 08:23:54,605 DEBUG    MainThread Setting RFM2Pi pubchannels: ['ToEmonCMS']
2024-02-20 08:23:54,606 DEBUG    MainThread Setting RFM2Pi subchannels: ['ToRFM12']
2024-02-20 08:23:54,611 INFO     MainThread Creating EmonHubMqttInterfacer 'MQTT'
2024-02-20 08:23:54,614 DEBUG    MainThread Setting MQTT pubchannels: ['ToRFM12']
2024-02-20 08:23:54,615 DEBUG    MainThread Setting MQTT subchannels: ['ToEmonCMS']
2024-02-20 08:23:54,617 INFO     MainThread Setting MQTT node_format_enable: 1
2024-02-20 08:23:54,618 INFO     MainThread Setting MQTT nodevar_format_enable: 1
2024-02-20 08:23:54,619 INFO     MainThread Setting MQTT nodevar_format_basetopic: emon/
2024-02-20 08:23:54,620 INFO     MainThread Setting MQTT node_JSON_enable: 0
2024-02-20 08:23:54,621 DEBUG    RFM2Pi     acknowledged command: > 1p
2024-02-20 08:23:54,623 INFO     MainThread Creating EmonHubEmoncmsHTTPInterfacer 'emoncmsorg'
2024-02-20 08:23:54,628 DEBUG    MainThread Setting emoncmsorg interval: 30
2024-02-20 08:23:54,629 DEBUG    MainThread Setting emoncmsorg pubchannels: ['ToRFM12']
2024-02-20 08:23:54,630 DEBUG    MainThread Setting emoncmsorg subchannels: ['ToEmonCMS']
2024-02-20 08:23:54,631 INFO     MainThread Setting emoncmsorg apikey: set
2024-02-20 08:23:54,632 INFO     MainThread Setting emoncmsorg url: http://172.29.181.222/emoncms
2024-02-20 08:23:54,633 INFO     MainThread Setting emoncmsorg senddata: 1
2024-02-20 08:23:54,633 INFO     MainThread Setting emoncmsorg sendstatus: 1
2024-02-20 08:23:54,634 INFO     MainThread Setting emoncmsorg sendnames: 1
2024-02-20 08:23:54,635 INFO     MainThread Setting emoncmsorg compress: 0
2024-02-20 08:23:54,637 DEBUG    MainThread Automatic configuration of nodes disabled
2024-02-20 08:23:54,678 ERROR    MainThread 'available'
2024-02-20 08:23:54,935 DEBUG    RFM2Pi     acknowledged command: <nn> i     - set node ID (standard node ids are 1..30)
2024-02-20 08:23:55,044 DEBUG    RFM2Pi     acknowledged command: <n> b      - set MHz band (4 = 433, 8 = 868, 9 = 915)
2024-02-20 08:23:55,154 DEBUG    RFM2Pi     acknowledged command: <nnnn> o   - change frequency offset within the band (default 1600)
2024-02-20 08:23:55,371 DEBUG    RFM2Pi     acknowledged command: <nnn> g    - set network group (RFM12 only allows 212, 0 = any)
2024-02-20 08:23:55,479 DEBUG    RFM2Pi     acknowledged command: <n> c      - set collect mode (advanced, normally 0)
2024-02-20 08:23:55,696 DEBUG    RFM2Pi     acknowledged command: ...,<nn> a - send data packet to node <nn>, request ack
2024-02-20 08:23:55,803 DEBUG    RFM2Pi     acknowledged command: ...,<nn> s - send data packet to node <nn>, no ack
2024-02-20 08:23:55,912 DEBUG    RFM2Pi     acknowledged command: <n> q      - set quiet mode (1 = don't report bad packets)
2024-02-20 08:23:56,022 DEBUG    RFM2Pi     acknowledged command: <n> x      - set reporting format (0: decimal, 1: hex, 2: hex+ascii)
2024-02-20 08:23:56,344 DEBUG    RFM2Pi     acknowledged command: <hchi>,<hclo>,<addr>,<cmd> f     - FS20 command (868 MHz)
2024-02-20 08:23:56,453 DEBUG    RFM2Pi     acknowledged command: <addr>,<dev>,<on> k              - KAKU command (433 MHz)
2024-02-20 08:23:56,661 DEBUG    RFM2Pi     device settings updated: E i5 g210 @ 433 MHz q1
2024-02-20 08:23:59,683 DEBUG    RFM2Pi     7 NEW FRAME : OK 8 138 0 0 0 0 0 0 0 203 95 183 0 184 11 184 11 184 11 184 11 184 11 1 0 0 0 (-46)
2024-02-20 08:23:59,687 DEBUG    RFM2Pi     7 Timestamp : 1708417439.682868
2024-02-20 08:23:59,688 DEBUG    RFM2Pi     7 From Node : 8
2024-02-20 08:23:59,689 DEBUG    RFM2Pi     7    Values : [138, 0, 0, 0, 245.23000000000002, 18.3, 300, 300, 300, 300, 300, 1]
2024-02-20 08:23:59,690 DEBUG    RFM2Pi     7      RSSI : -46
2024-02-20 08:23:59,691 DEBUG    RFM2Pi     7 Sent to channel(start)' : ToEmonCMS
2024-02-20 08:23:59,692 DEBUG    RFM2Pi     7 Sent to channel(end)' : ToEmonCMS
2024-02-20 08:24:01,015 DEBUG    RFM2Pi     8 NEW FRAME : OK 15 144 77 85 85 199 52 91 85 85 85 85 85 85 85 13 84 85 85 64 85 85 85 85 85 85 85 85 85 85 85 122 90 101 32 101 32 84 85 85 85 (-70)
2024-02-20 08:24:01,019 DEBUG    RFM2Pi     8 Timestamp : 1708417441.014521
2024-02-20 08:24:01,020 DEBUG    RFM2Pi     8 From Node : 15
2024-02-20 08:24:01,021 DEBUG    RFM2Pi     8    Values : [6341, 249.78, 14, 0, 0, 0, 344, 21, 0, 0, 38.87, 300, 300, 1, 0, 0]
2024-02-20 08:24:01,022 DEBUG    RFM2Pi     8      RSSI : -70
2024-02-20 08:24:01,022 DEBUG    RFM2Pi     8 Sent to channel(start)' : ToEmonCMS
2024-02-20 08:24:01,023 DEBUG    RFM2Pi     8 Sent to channel(end)' : ToEmonCMS
2024-02-20 08:24:09,566 DEBUG    RFM2Pi     9 NEW FRAME : OK 8 138 0 0 0 0 0 0 0 203 95 183 0 184 11 184 11 184 11 184 11 184 11 1 0 0 0 (-46)
2024-02-20 08:24:09,570 DEBUG    RFM2Pi     9 Timestamp : 1708417449.566445
2024-02-20 08:24:09,571 DEBUG    RFM2Pi     9 From Node : 8
2024-02-20 08:24:09,572 DEBUG    RFM2Pi     9    Values : [138, 0, 0, 0, 245.23000000000002, 18.3, 300, 300, 300, 300, 300, 1]
2024-02-20 08:24:09,573 DEBUG    RFM2Pi     9      RSSI : -46
2024-02-20 08:24:09,574 DEBUG    RFM2Pi     9 Sent to channel(start)' : ToEmonCMS
2024-02-20 08:24:09,575 DEBUG    RFM2Pi     9 Sent to channel(end)' : ToEmonCMS
2024-02-20 08:24:10,999 DEBUG    RFM2Pi     10 NEW FRAME : OK 15 147 77 85 85 244 52 91 85 85 85 85 85 85 85 13 84 85 85 64 85 85 85 85 85 85 85 85 85 85 85 122 90 101 32 101 32 84 85 85 85 (-70)
2024-02-20 08:24:11,003 DEBUG    RFM2Pi     10 Timestamp : 1708417450.998670
2024-02-20 08:24:11,004 DEBUG    RFM2Pi     10 From Node : 15
2024-02-20 08:24:11,005 DEBUG    RFM2Pi     10    Values : [6342, 249.93, 14, 0, 0, 0, 344, 21, 0, 0, 38.87, 300, 300, 1, 0, 0.0]
2024-02-20 08:24:11,006 DEBUG    RFM2Pi     10      RSSI : -70
2024-02-20 08:24:11,007 DEBUG    RFM2Pi     10 Sent to channel(start)' : ToEmonCMS
2024-02-20 08:24:11,007 DEBUG    RFM2Pi     10 Sent to channel(end)' : ToEmonCMS

left it all night, still nada in the OUTPUT chain of the firewall:

sudo nft list chain filter OUTPUT
table ip filter {
	chain OUTPUT {
		type filter hook output priority filter; policy accept;
		ip daddr 172.29.181.222 tcp dport 80 counter packets 0 bytes 0 accept
	}
}

borpin · 20 February 2024 09:09

It doesn’t look like that is from the journalctl output.

If there are any Python errors, they will only occur in the journalctl log output (hence the reason for asking you did that).

lukew151 · 20 February 2024 10:06

It’s just this:

sudo journalctl -f -u emonhub
-- Logs begin at Mon 2024-02-19 17:42:57 GMT. --
Feb 19 21:30:57 deimos systemd[1]: emonhub.service: Succeeded.
Feb 19 21:30:57 deimos systemd[1]: Stopped emonHub data multiplexer.
Feb 19 21:31:13 deimos systemd[1]: Starting emonHub data multiplexer...
Feb 19 21:31:13 deimos systemd[1]: Started emonHub data multiplexer.
Feb 20 08:23:49 deimos systemd[1]: Stopping emonHub data multiplexer...
Feb 20 08:23:49 deimos systemd[1]: emonhub.service: Main process exited, code=killed, status=15/TERM
Feb 20 08:23:49 deimos systemd[1]: emonhub.service: Succeeded.
Feb 20 08:23:49 deimos systemd[1]: Stopped emonHub data multiplexer.
Feb 20 08:23:49 deimos systemd[1]: Starting emonHub data multiplexer...
Feb 20 08:23:49 deimos systemd[1]: Started emonHub data multiplexer.

borpin · 20 February 2024 10:24

That is odd.

I presume you have checked you can ping between the machines?

You will only see one entry every 30 seconds trying to send data to emoncms so an error in that process will be shown at that time.

On the inputs page, top right Input API Help there are some curl examples you could try.

lukew151 · 20 February 2024 14:05

Ping works.

I took the data from this frame in the EmonHub log:

2024-02-20 13:58:37,117 DEBUG    RFM2Pi     3908 NEW FRAME : OK 15 243 117 85 85 254 52 50 85 85 85 85 85 85 85 203 86 85 85 77 85 85 85 85 85 85 85 85 85 85 85 122 90 101 32 101 32 84 85 85 85 (-74)
2024-02-20 13:58:37,121 DEBUG    RFM2Pi     3908 Timestamp : 1708437517.116683
2024-02-20 13:58:37,122 DEBUG    RFM2Pi     3908 From Node : 15
2024-02-20 13:58:37,123 DEBUG    RFM2Pi     3908    Values : [8358, 250.03, 103, 0, 0, 0, 926, 24, 0, 0, 38.87, 300, 300, 1, 74, 3.668815071888944]
2024-02-20 13:58:37,124 DEBUG    RFM2Pi     3908      RSSI : -74
2024-02-20 13:58:37,126 DEBUG    RFM2Pi     3908 Sent to channel(start)' : ToEmonCMS
2024-02-20 13:58:37,127 DEBUG    RFM2Pi     3908 Sent to channel(end)' : ToEmonCMS

and constructed this curl data using the input api help:
node=15&data={MSG:8358,Vrms:250.03,P1:103,P2:0,T1:38.87}&apikey=secretKey

table ip filter {
	chain OUTPUT {
		type filter hook output priority filter; policy accept;
		ip daddr 172.29.181.222 tcp dport 80 counter packets 0 bytes 0 accept
	}
}
luke@deimos:~ $ curl --data "node=15&data={MSG:8358,Vrms:250.03,P1:103,P2:0,T1:38.87}&apikey=secretkey" \
>   "http://172.29.181.222/emoncms/input/post"
okluke@deimos:~ $ sudo nft list chain filter OUTPUT
table ip filter {
	chain OUTPUT {
		type filter hook output priority filter; policy accept;
		ip daddr 172.29.181.222 tcp dport 80 counter packets 6 bytes 582 accept
	}
}
luke@deimos:~ $

And that sends, packets show in the nft counters, and that data was recieved by EmonCMS!

So why has it stopped working for me. I guess tonight I’ll try a full re-install.

borpin · 20 February 2024 15:09

Look at a 1 minute selection of the log and see what the log says when it tries to send the data via http.

lukew151 · 20 February 2024 16:47

Brian, I’m not seeing it attempt to POST data. every line in the log starts date DEBUG RFM2Pi which I assume is the RFM2Pi interface, so it’s appears to not be logging anything from the emoncmsorg interface? There’s just pages and pages of RFM2Pi frames being decoded. I’ve tried taking the interval away, and that’s no different.

borpin · 20 February 2024 20:57

@TrystanLea - any ideas?

Yes from

equally the HTTP interfacer is created here

lukew151:

2024-02-20 08:23:54,623 INFO     MainThread Creating EmonHubEmoncmsHTTPInterfacer 'emoncmsorg'
2024-02-20 08:23:54,628 DEBUG    MainThread Setting emoncmsorg interval: 30
2024-02-20 08:23:54,629 DEBUG    MainThread Setting emoncmsorg pubchannels: ['ToRFM12']
2024-02-20 08:23:54,630 DEBUG    MainThread Setting emoncmsorg subchannels: ['ToEmonCMS']
2024-02-20 08:23:54,631 INFO     MainThread Setting emoncmsorg apikey: set
2024-02-20 08:23:54,632 INFO     MainThread Setting emoncmsorg url: http://172.29.181.222/emoncms
2024-02-20 08:23:54,633 INFO     MainThread Setting emoncmsorg senddata: 1
2024-02-20 08:23:54,633 INFO     MainThread Setting emoncmsorg sendstatus: 1
2024-02-20 08:23:54,634 INFO     MainThread Setting emoncmsorg sendnames: 1
2024-02-20 08:23:54,635 INFO     MainThread Setting emoncmsorg compress: 0

so you should see some emoncmsorg entries as it attempts to send the data.

Have you got an MQTT broker setup on the emoncms machine (or one that instace points to)? If so all I can suggest is trying that.

Cannot see why else it isn’t working. At the very least it should be attempting to send the data and you should see that in the log.

lukew151 · 22 February 2024 23:36

Deleted installed files, git reset --hard; git pull; ./install.sh clean install

pip had one error:

Collecting py-sds011
  Could not find a version that satisfies the requirement py-sds011 (from versions: )
No matching distribution found for py-sds011

emonhub.service requires var-log.mount commented this out as /var/log/ is on my root partition on a default raspian install.

Added the following back into emonhub.conf:

[hub]
    ### loglevel must be one of DEBUG, INFO, WARNING, ERROR, and CRITICAL
    loglevel = DEBUG
    autoconf = 1
[interfacers]
    ### This interfacer manages the RFM12Pi/RFM69Pi/emonPi module
    [[EmonPi2]]
        Type = EmonHubOEMInterfacer
        [[[init_settings]]]
            com_port = /dev/ttyAMA0
#            com_baud = 115200
            com_baud = 38400
        [[[runtimesettings]]]
            pubchannels = ToEmonCMS,
            subchannels = ToRFM12,
    [[emoncmsorg]]
        Type = EmonHubEmoncmsHTTPInterfacer
        [[[init_settings]]]
        [[[runtimesettings]]]
            pubchannels = ToRFM12,
            subchannels = ToEmonCMS,
#            url = https://emoncms.org
#            apikey = xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
            url = http://172.29.181.222/emoncms
            apikey = <keygoeshere>
            senddata = 1    # Enable sending data to Emoncms.org
            sendnames = 1    # Send full input names (compression will be automatically enabled)
#            interval = 30    # Bulk send interval to Emoncms.org in seconds

[nodes]
[[8]]
    nodename = emontx3
    [[[rx]]]
       names = power1, power2, power3, power4, vrms, temp1, temp2, temp3, temp4, temp5, temp6, pulse
       datacodes = h,h,h,h,h,h,h,h,h,h,h,L
       scales = 1,1,1,1,0.01,0.1,0.1, 0.1,0.1,0.1,0.1,1
       units = W,W,W,W,V,C,C,C,C,C,C,p
[[15]]
    nodename = emontx3cm15
    [[[rx]]]
       names = MSG, Vrms, P1, P2, P3, P4, E1, E2, E3, E4, T1, T2, T3, pulse
       datacodes = L,h,h,h,h,h,l,l,l,l,h,h,h,L
       scales = 1,0.01,1,1,1,1,1,1,1,1,0.01,0.01,0.01,1
       units = n,V,W,W,W,W,Wh,Wh,Wh,Wh,C,C,C,p
       whitening = 1

Starts up, looks promising, but still not reporting packages back to emoncms:

2024-02-22 23:26:20,027 INFO     MainThread EmonHub v2.6.5
2024-02-22 23:26:20,029 INFO     MainThread Opening hub...
2024-02-22 23:26:20,030 INFO     MainThread Running as user: luke
2024-02-22 23:26:20,031 INFO     MainThread Logging level set to DEBUG
2024-02-22 23:26:20,032 INFO     MainThread Creating EmonHubOEMInterfacer 'EmonPi2'
2024-02-22 23:26:20,035 DEBUG    MainThread Opening serial port: /dev/ttyAMA0 @ 38400 bits/s
2024-02-22 23:26:20,038 INFO     MainThread Creating EmonHubMqttInterfacer 'MQTT'
2024-02-22 23:26:20,040 DEBUG    MainThread Setting MQTT pubchannels: ['ToRFM12']
2024-02-22 23:26:20,041 DEBUG    MainThread Setting MQTT subchannels: ['ToEmonCMS']
2024-02-22 23:26:20,042 INFO     MainThread Setting MQTT node_format_enable: 0
2024-02-22 23:26:20,042 INFO     MainThread Setting MQTT nodevar_format_enable: 1
2024-02-22 23:26:20,043 INFO     MainThread Setting MQTT nodevar_format_basetopic: emon/
2024-02-22 23:26:20,043 INFO     MainThread Setting MQTT node_JSON_enable: 0
2024-02-22 23:26:20,045 INFO     MainThread Creating EmonHubEmoncmsHTTPInterfacer 'emoncmsorg'
2024-02-22 23:26:20,047 DEBUG    MainThread Setting emoncmsorg pubchannels: ['ToRFM12']
2024-02-22 23:26:20,048 DEBUG    MainThread Setting emoncmsorg subchannels: ['ToEmonCMS']
2024-02-22 23:26:20,049 INFO     MainThread Setting emoncmsorg apikey: set
2024-02-22 23:26:20,049 INFO     MainThread Setting emoncmsorg url: http://172.29.181.222/emoncms
2024-02-22 23:26:20,050 INFO     MainThread Setting emoncmsorg senddata: 1
2024-02-22 23:26:20,050 INFO     MainThread Setting emoncmsorg sendstatus: 0
2024-02-22 23:26:20,051 INFO     MainThread Setting emoncmsorg sendnames: 1
2024-02-22 23:26:20,052 INFO     MainThread Setting emoncmsorg compress: 0
2024-02-22 23:26:20,053 DEBUG    MainThread Automatic configuration of nodes enabled
2024-02-22 23:26:20,064 ERROR    MainThread 'available'
2024-02-22 23:26:22,064 DEBUG    EmonPi2    ---------------------------------------------------------------------
2024-02-22 23:26:22,069 DEBUG    EmonPi2    Config format: old
2024-02-22 23:26:22,070 DEBUG    EmonPi2    ---------------------------------------------------------------------
2024-02-22 23:26:22,176 DEBUG    EmonPi2    [RF12demo.12] E i5 g210 @ 433 MHz q1
2024-02-22 23:26:23,593 DEBUG    EmonPi2    3 NEW FRAME : OK 8 149 0 0 0 0 0 0 0 38 95 166 0 184 11 184 11 184 11 184 11 184 11 1 0 0 0 (-52)
2024-02-22 23:26:23,597 DEBUG    EmonPi2    3 Timestamp : 1708644383.592669
2024-02-22 23:26:23,598 DEBUG    EmonPi2    3 From Node : 8
2024-02-22 23:26:23,599 DEBUG    EmonPi2    3    Values : [149, 0, 0, 0, 243.58, 16.6, 300, 300, 300, 300, 300, 1]
2024-02-22 23:26:23,601 DEBUG    EmonPi2    3      RSSI : -52
2024-02-22 23:26:23,602 DEBUG    EmonPi2    3 Sent to channel(start)' : ToEmonCMS
2024-02-22 23:26:23,603 DEBUG    EmonPi2    3 Sent to channel(end)' : ToEmonCMS
2024-02-22 23:26:31,952 DEBUG    EmonPi2    4 NEW FRAME : OK 15 159 36 85 85 82 52 82 85 85 85 85 85 85 85 102 92 85 85 123 85 85 85 85 85 85 85 85 85 85 85 213 91 101 32 101 32 84 85 85 85 (-69)
2024-02-22 23:26:31,956 DEBUG    EmonPi2    4 Timestamp : 1708644391.951758
2024-02-22 23:26:31,957 DEBUG    EmonPi2    4 From Node : 15
2024-02-22 23:26:31,959 DEBUG    EmonPi2    4    Values : [29130, 248.39000000000001, 7, 0, 0, 0, 2355, 46, 0, 0, 37.12, 300, 300, 1, 0, 0]
2024-02-22 23:26:31,960 DEBUG    EmonPi2    4      RSSI : -69
2024-02-22 23:26:31,961 DEBUG    EmonPi2    4 Sent to channel(start)' : ToEmonCMS
2024-02-22 23:26:31,962 DEBUG    EmonPi2    4 Sent to channel(end)' : ToEmonCMS
2024-02-22 23:26:33,480 DEBUG    EmonPi2    5 NEW FRAME : OK 8 146 0 0 0 0 0 0 0 89 95 166 0 184 11 184 11 184 11 184 11 184 11 1 0 0 0 (-51)
2024-02-22 23:26:33,484 DEBUG    EmonPi2    5 Timestamp : 1708644393.479808
2024-02-22 23:26:33,485 DEBUG    EmonPi2    5 From Node : 8
2024-02-22 23:26:33,486 DEBUG    EmonPi2    5    Values : [146, 0, 0, 0, 244.09, 16.6, 300, 300, 300, 300, 300, 1]
2024-02-22 23:26:33,487 DEBUG    EmonPi2    5      RSSI : -51
2024-02-22 23:26:33,488 DEBUG    EmonPi2    5 Sent to channel(start)' : ToEmonCMS
2024-02-22 23:26:33,490 DEBUG    EmonPi2    5 Sent to channel(end)' : ToEmonCMS
2024-02-22 23:26:41,938 DEBUG    EmonPi2    6 NEW FRAME : OK 15 158 36 85 85 72 52 82 85 85 85 85 85 85 85 102 92 85 85 123 85 85 85 85 85 85 85 85 85 85 85 213 91 101 32 101 32 84 85 85 85 (-69)
2024-02-22 23:26:41,942 DEBUG    EmonPi2    6 Timestamp : 1708644401.938009
2024-02-22 23:26:41,944 DEBUG    EmonPi2    6 From Node : 15
2024-02-22 23:26:41,945 DEBUG    EmonPi2    6    Values : [29131, 248.61, 7, 0, 0, 0, 2355, 46, 0, 0, 37.12, 300, 300, 1, 0, 0.0]
2024-02-22 23:26:41,946 DEBUG    EmonPi2    6      RSSI : -69
2024-02-22 23:26:41,947 DEBUG    EmonPi2    6 Sent to channel(start)' : ToEmonCMS
2024-02-22 23:26:41,948 DEBUG    EmonPi2    6 Sent to channel(end)' : ToEmonCMS
2024-02-22 23:26:43,367 DEBUG    EmonPi2    7 NEW FRAME : OK 8 147 0 0 0 0 0 0 0 73 95 165 0 184 11 184 11 184 11 184 11 184 11 1 0 0 0 (-52)
2024-02-22 23:26:43,371 DEBUG    EmonPi2    7 Timestamp : 1708644403.366723
2024-02-22 23:26:43,372 DEBUG    EmonPi2    7 From Node : 8
2024-02-22 23:26:43,373 DEBUG    EmonPi2    7    Values : [147, 0, 0, 0, 243.93, 16.5, 300, 300, 300, 300, 300, 1]
2024-02-22 23:26:43,374 DEBUG    EmonPi2    7      RSSI : -52
2024-02-22 23:26:43,376 DEBUG    EmonPi2    7 Sent to channel(start)' : ToEmonCMS
2024-02-22 23:26:43,377 DEBUG    EmonPi2    7 Sent to channel(end)' : ToEmonCMS
2024-02-22 23:26:51,826 DEBUG    EmonPi2    8 NEW FRAME : OK 15 153 36 85 85 77 52 82 85 85 85 85 85 85 85 102 92 85 85 123 85 85 85 85 85 85 85 85 85 85 85 213 91 101 32 101 32 84 85 85 85 (-69)
2024-02-22 23:26:51,829 DEBUG    EmonPi2    8 Timestamp : 1708644411.825774
2024-02-22 23:26:51,831 DEBUG    EmonPi2    8 From Node : 15
2024-02-22 23:26:51,832 DEBUG    EmonPi2    8    Values : [29132, 248.56, 7, 0, 0, 0, 2355, 46, 0, 0, 37.12, 300, 300, 1, 0, 0.0]
2024-02-22 23:26:51,833 DEBUG    EmonPi2    8      RSSI : -69
2024-02-22 23:26:51,834 DEBUG    EmonPi2    8 Sent to channel(start)' : ToEmonCMS
2024-02-22 23:26:51,835 DEBUG    EmonPi2    8 Sent to channel(end)' : ToEmonCMS
2024-02-22 23:26:53,353 DEBUG    EmonPi2    9 NEW FRAME : OK 8 147 0 0 0 0 0 0 0 64 95 166 0 184 11 184 11 184 11 184 11 184 11 1 0 0 0 (-50)
2024-02-22 23:26:53,357 DEBUG    EmonPi2    9 Timestamp : 1708644413.353035
2024-02-22 23:26:53,359 DEBUG    EmonPi2    9 From Node : 8
2024-02-22 23:26:53,360 DEBUG    EmonPi2    9    Values : [147, 0, 0, 0, 243.84, 16.6, 300, 300, 300, 300, 300, 1]
2024-02-22 23:26:53,361 DEBUG    EmonPi2    9      RSSI : -50
2024-02-22 23:26:53,363 DEBUG    EmonPi2    9 Sent to channel(start)' : ToEmonCMS
2024-02-22 23:26:53,365 DEBUG    EmonPi2    9 Sent to channel(end)' : ToEmonCMS
2024-02-22 23:27:01,814 DEBUG    EmonPi2    10 NEW FRAME : OK 15 152 36 85 85 82 52 93 85 85 85 85 85 85 85 102 92 85 85 123 85 85 85 85 85 85 85 85 85 85 85 213 91 101 32 101 32 84 85 85 85 (-68)
2024-02-22 23:27:01,818 DEBUG    EmonPi2    10 Timestamp : 1708644421.813735
2024-02-22 23:27:01,819 DEBUG    EmonPi2    10 From Node : 15
2024-02-22 23:27:01,820 DEBUG    EmonPi2    10    Values : [29133, 248.39000000000001, 8, 0, 0, 0, 2355, 46, 0, 0, 37.12, 300, 300, 1, 0, 0.0]
2024-02-22 23:27:01,822 DEBUG    EmonPi2    10      RSSI : -68
2024-02-22 23:27:01,823 DEBUG    EmonPi2    10 Sent to channel(start)' : ToEmonCMS
2024-02-22 23:27:01,824 DEBUG    EmonPi2    10 Sent to channel(end)' : ToEmonCMS
2024-02-22 23:27:03,241 DEBUG    EmonPi2    11 NEW FRAME : OK 8 199 0 0 0 0 0 0 0 49 95 165 0 184 11 184 11 184 11 184 11 184 11 1 0 0 0 (-51)
2024-02-22 23:27:03,245 DEBUG    EmonPi2    11 Timestamp : 1708644423.241030
2024-02-22 23:27:03,246 DEBUG    EmonPi2    11 From Node : 8
2024-02-22 23:27:03,247 DEBUG    EmonPi2    11    Values : [199, 0, 0, 0, 243.69, 16.5, 300, 300, 300, 300, 300, 1]
2024-02-22 23:27:03,249 DEBUG    EmonPi2    11      RSSI : -51
2024-02-22 23:27:03,250 DEBUG    EmonPi2    11 Sent to channel(start)' : ToEmonCMS
2024-02-22 23:27:03,251 DEBUG    EmonPi2    11 Sent to channel(end)' : ToEmonCMS
2024-02-22 23:27:11,700 DEBUG    EmonPi2    12 NEW FRAME : OK 15 155 36 85 85 94 52 82 85 85 85 85 85 85 85 102 92 85 85 123 85 85 85 85 85 85 85 85 85 85 85 213 91 101 32 101 32 84 85 85 85 (-68)
2024-02-22 23:27:11,704 DEBUG    EmonPi2    12 Timestamp : 1708644431.700001
2024-02-22 23:27:11,706 DEBUG    EmonPi2    12 From Node : 15
2024-02-22 23:27:11,707 DEBUG    EmonPi2    12    Values : [29134, 248.43, 7, 0, 0, 0, 2355, 46, 0, 0, 37.12, 300, 300, 1, 0, 0.0]
2024-02-22 23:27:11,708 DEBUG    EmonPi2    12      RSSI : -68
2024-02-22 23:27:11,710 DEBUG    EmonPi2    12 Sent to channel(start)' : ToEmonCMS
2024-02-22 23:27:11,711 DEBUG    EmonPi2    12 Sent to channel(end)' : ToEmonCMS
2024-02-22 23:27:13,128 DEBUG    EmonPi2    13 NEW FRAME : OK 8 183 0 0 0 0 0 0 0 54 95 166 0 184 11 184 11 184 11 184 11 184 11 1 0 0 0 (-52)
2024-02-22 23:27:13,132 DEBUG    EmonPi2    13 Timestamp : 1708644433.128231
2024-02-22 23:27:13,133 DEBUG    EmonPi2    13 From Node : 8
2024-02-22 23:27:13,135 DEBUG    EmonPi2    13    Values : [183, 0, 0, 0, 243.74, 16.6, 300, 300, 300, 300, 300, 1]
2024-02-22 23:27:13,136 DEBUG    EmonPi2    13      RSSI : -52
2024-02-22 23:27:13,137 DEBUG    EmonPi2    13 Sent to channel(start)' : ToEmonCMS
2024-02-22 23:27:13,138 DEBUG    EmonPi2    13 Sent to channel(end)' : ToEmonCMS
2024-02-22 23:27:21,687 DEBUG    EmonPi2    14 NEW FRAME : OK 15 154 36 85 85 91 52 82 85 85 85 85 85 85 85 102 92 85 85 123 85 85 85 85 85 85 85 85 85 85 85 213 91 101 32 101 32 84 85 85 85 (-70)
2024-02-22 23:27:21,691 DEBUG    EmonPi2    14 Timestamp : 1708644441.686708
2024-02-22 23:27:21,692 DEBUG    EmonPi2    14 From Node : 15
2024-02-22 23:27:21,693 DEBUG    EmonPi2    14    Values : [29135, 248.46, 7, 0, 0, 0, 2355, 46, 0, 0, 37.12, 300, 300, 1, 0, 0.0]
2024-02-22 23:27:21,695 DEBUG    EmonPi2    14      RSSI : -70
2024-02-22 23:27:21,696 DEBUG    EmonPi2    14 Sent to channel(start)' : ToEmonCMS
2024-02-22 23:27:21,697 DEBUG    EmonPi2    14 Sent to channel(end)' : ToEmonCMS

lots of packets from serial, but not being sent to emonCMS. Still no joy.

borpin · 23 February 2024 07:23

Is there any susequent log entry that references emoncmsorg (which is the HTTP interfacer)?

There should be one every 30s

lukew151 · 23 February 2024 08:29

I’ve checked hours and hours of logs - nothing at all to [[emoncmsorg]]

borpin · 23 February 2024 14:25

A short term solution is to use an MQTT interfacer.

@TrystanLea - I’m stumped.

christian · 23 February 2024 17:32

I wonder why MainThread ‘available’ is an ERROR?

TrystanLea · 24 February 2024 15:03

Also at a loss here.

This looks like it could be coming from this exception but not 100% sure emonhub/src/emonhub_auto_conf.py at master · openenergymonitor/emonhub · GitHub.

What goes git status say in the emonhub repository? Is there anything wrong with emonhub/conf/available.conf. Or is it all clean and on latest master branch?

lukew151 · 24 February 2024 15:09

TrystanLea · 24 February 2024 16:30

Thanks, could you try running emonhub manually on the command line? start by stopping the service and then try:

cd /opt/openenergymonitor/emonhub
python3 src/emonhub.py --config-file=/etc/emonhub/emonhub.conf

I wonder if we are missing some python errors that are not getting into the log, this should show anything we may be missing.

TrystanLea · 24 February 2024 16:33

It might also be worth double checking the emoncms apikey, make sure there are no spaces after the key. Double checking the code here and this could be a cause of quiet failure by the looks of it:

In EmonHubEmoncmsHTTPInterfacer.py:

def _process_post(self, databuffer):
    """Send data to server."""

    # databuffer is of format:
    # [[timestamp, nodeid, datavalues][timestamp, nodeid, datavalues]]
    # [[1399980731, 10, 150, 250 ...]]

    if 'apikey' not in self._settings or len(str(self._settings['apikey'])) != 32 \
            or str(self._settings['apikey']).lower() == 'x' * 32:
        # Return true to clear buffer if the apikey is not set
        return True

There’s no reported error here if the apikey does not match those checks…

lukew151 · 25 February 2024 16:59

Hi Trystan. /usr/local/bin/emonhub/ is a symlink to /home/luke/git/emonhub/ as this is a vanilla raspberrypiOS. I’ve double checked the API key in emonhub.conf is correct. It’s the Read & Write key from emoncms, and there is no whitespace before or after it.

Logs:
https://pastebin.com/29U7t3bB