Local emonpi out of sync with MQTT?

a23452533 · 4 October 2022 10:37

I’ve happily been running emoncms on a pi since 2014 with 2 emontxes. The Pi is running low-write 11.2.2

I’ve recently commented out the httpinterfacer lines in emonhub.conf so that emoncms picks up just from MQTT. I am running Mosquito elsewhere on my LAN, and have disabled the one on the Pi.

I can see the correct messages appearing in MQTT explorer every 10 seconds from my 2 emontxv3 units. However the Inputs screen on the Pi shows a lag of several messages compared with MQTT, and sometimes the message count jumps backwards. The lag seems to get worse over time. A few minutes after restart, the lag is a minute or so, and after a day, it is at least 10 minutes behind MQTT.

Here’s a chart of the MSG count from MQTT explorer showing the number incrementing regularly every 10s since I restarted it this morning.

And here’s a chart of the MSG feed from my 1st emontx in my local emoncms. It should be the same straight line, but it is jumping around for some reason. Anyone any ideas why?

Interestingly here’s the MSG feed on the 2nd emontx which has not jumped around in the last hour.

Here’s the last section of emoncms.log. There are a few MQTT connection errors there.

2022-10-04 10:30:36.003|WARN|emoncms_mqtt.php|Not connected, retrying connection
2022-10-04 10:30:36.015|WARN|emoncms_mqtt.php|Connecting to MQTT server: Connection Accepted.: code: 0
2022-10-04 10:30:36.015|INFO|emoncms_mqtt.php|Subscribed to: emon/# ID - 1708
2022-10-04 10:30:36.027|INFO|emoncms_mqtt.php|Callback subscribed to topic: openevseintegration/SurplusPVforEV
2022-10-04 10:30:36.032|INFO|feed_model.php|EngineClass() Autoloaded new instance of 'PHPTimeSeries'.
2022-10-04 10:30:36.085|INFO|feed_model.php|get_timevalue() calling VIRTUAL lastvalue 227
2022-10-04 10:30:36.085|INFO|feed_model.php|EngineClass() Autoloaded new instance of 'VirtualFeed'.
2022-10-04 10:30:36.112|INFO|emoncms_mqtt.php|emon/openevse/amp 0
2022-10-04 10:30:36.120|INFO|feed_model.php|post() feedid=149 updatetime=1664879436 feedtime=1664879436 value=0 arg=
2022-10-04 10:30:36.125|INFO|feed_model.php|post() feedid=185 updatetime=1664879436 feedtime=1664879436 value=0 arg=
2022-10-04 10:30:36.130|INFO|emoncms_mqtt.php|emon/openevse/voltage 245.95
2022-10-04 10:30:36.145|INFO|emoncms_mqtt.php|emon/openevse/pilot 32
2022-10-04 10:30:36.153|INFO|feed_model.php|post() feedid=157 updatetime=1664879436 feedtime=1664879436 value=32 arg=
2022-10-04 10:30:36.158|INFO|emoncms_mqtt.php|emon/openevse/wh 3173600
2022-10-04 10:30:36.163|INFO|feed_model.php|EngineClass() Autoloaded new instance of 'PHPFina'.
2022-10-04 10:30:36.168|INFO|feed_model.php|post() feedid=186 updatetime=1664879436 feedtime=1664879436 value=590.84588623047 arg=join
2022-10-04 10:30:36.172|INFO|emoncms_mqtt.php|emon/openevse/temp 242
2022-10-04 10:30:36.180|INFO|emoncms_mqtt.php|emon/openevse/temp1 false
2022-10-04 10:30:36.187|INFO|emoncms_mqtt.php|emon/openevse/temp2 242
2022-10-04 10:30:36.195|INFO|feed_model.php|post() feedid=153 updatetime=1664879436 feedtime=1664879436 value=24.2 arg=
2022-10-04 10:30:36.198|INFO|emoncms_mqtt.php|emon/openevse/temp3 false
2022-10-04 10:30:36.205|INFO|emoncms_mqtt.php|emon/openevse/state 255
2022-10-04 10:30:36.213|INFO|feed_model.php|post() feedid=154 updatetime=1664879436 feedtime=1664879436 value=255 arg=
2022-10-04 10:30:36.216|INFO|emoncms_mqtt.php|emon/openevse/vehicle 1
2022-10-04 10:30:36.224|INFO|feed_model.php|post() feedid=155 updatetime=1664879436 feedtime=1664879436 value=1 arg=
2022-10-04 10:30:36.228|INFO|emoncms_mqtt.php|emon/openevse/colour 6
2022-10-04 10:30:36.236|INFO|emoncms_mqtt.php|emon/openevse/manual_override 0
2022-10-04 10:30:36.243|INFO|feed_model.php|post() feedid=188 updatetime=1664879436 feedtime=1664879436 value=0 arg=
2022-10-04 10:30:36.247|INFO|emoncms_mqtt.php|emon/openevse/freeram 110312
2022-10-04 10:30:36.254|INFO|emoncms_mqtt.php|emon/openevse/divertmode 2
2022-10-04 10:30:36.261|INFO|feed_model.php|post() feedid=158 updatetime=1664879436 feedtime=1664879436 value=2 arg=
2022-10-04 10:30:36.265|INFO|emoncms_mqtt.php|emon/openevse/srssi 0
2022-10-04 10:30:36.303|INFO|feed_model.php|EngineClass() Autoloaded new instance of 'PHPTimeSeries'.
2022-10-04 10:30:36.355|INFO|feed_model.php|get_timevalue() calling VIRTUAL lastvalue 227
2022-10-04 10:30:36.356|INFO|feed_model.php|EngineClass() Autoloaded new instance of 'VirtualFeed'.
2022-10-04 10:30:38.282|INFO|feed_model.php|EngineClass() Autoloaded new instance of 'PHPFina'.
2022-10-04 10:30:38.397|INFO|feed_model.php|EngineClass() Autoloaded new instance of 'PHPTimeSeries'.
2022-10-04 10:30:38.450|INFO|feed_model.php|get_timevalue() calling VIRTUAL lastvalue 227
2022-10-04 10:30:38.451|INFO|feed_model.php|EngineClass() Autoloaded new instance of 'VirtualFeed'.
2022-10-04 10:30:40.-475|INFO|emoncms_mqtt.php|emon/emontx2/MSG 70022
2022-10-04 10:30:40.-463|INFO|feed_model.php|post() feedid=243 updatetime=1664879440 feedtime=1664879440 value=70022 arg=
2022-10-04 10:30:40.-455|INFO|emoncms_mqtt.php|emon/emontx2/Vrms 244.55
2022-10-04 10:30:40.-443|INFO|feed_model.php|post() feedid=223 updatetime=1664879440 feedtime=1664879440 value=244.55 arg=
2022-10-04 10:30:40.-437|INFO|emoncms_mqtt.php|emon/emontx2/P1 615
2022-10-04 10:30:40.-428|INFO|feed_model.php|post() feedid=201 updatetime=1664879440 feedtime=1664879440 value=615 arg=
2022-10-04 10:30:40.-423|INFO|feed_model.php|post() feedid=207 updatetime=1664879440 feedtime=1664879440 value=615 arg=
2022-10-04 10:30:40.-417|INFO|feed_model.php|post() feedid=73 updatetime=1664879440 feedtime=1664879440 value=13591.980632572 arg=join
2022-10-04 10:30:40.-412|INFO|feed_model.php|post() feedid=208 updatetime=1664879440 feedtime=1664879440 value=0 arg=
2022-10-04 10:30:40.-405|INFO|feed_model.php|post() feedid=90 updatetime=1664879440 feedtime=1664879440 value=3319.5455413195 arg=join
2022-10-04 10:30:40.-401|INFO|feed_model.php|post() feedid=109 updatetime=1664879440 feedtime=1664879440 value=12 arg=
2022-10-04 10:30:40.-395|INFO|feed_model.php|post() feedid=110 updatetime=1664879440 feedtime=1664879440 value=8554.6666120845 arg=join
2022-10-04 10:30:40.-389|INFO|feed_model.php|post() feedid=107 updatetime=1664879440 feedtime=1664879440 value=1463 arg=
2022-10-04 10:30:40.-383|INFO|feed_model.php|post() feedid=108 updatetime=1664879440 feedtime=1664879440 value=25329.066048272 arg=join
2022-10-04 10:30:40.-377|INFO|feed_model.php|post() feedid=196 updatetime=1664879440 feedtime=1664879440 value=1103 arg=
2022-10-04 10:30:40.-371|INFO|feed_model.php|post() feedid=219 updatetime=1664879440 feedtime=1664879440 value=0 arg=
2022-10-04 10:30:40.-365|INFO|feed_model.php|post() feedid=220 updatetime=1664879440 feedtime=1664879440 value=72.903045654297 arg=join
2022-10-04 10:30:40.-360|INFO|feed_model.php|post() feedid=217 updatetime=1664879440 feedtime=1664879440 value=615 arg=
2022-10-04 10:30:40.-353|INFO|feed_model.php|post() feedid=218 updatetime=1664879440 feedtime=1664879440 value=188.69768884388 arg=join
2022-10-04 10:30:40.-349|INFO|emoncms_mqtt.php|emon/emontx2/P2 540
2022-10-04 10:30:40.-340|INFO|feed_model.php|post() feedid=203 updatetime=1664879440 feedtime=1664879440 value=540 arg=
2022-10-04 10:30:40.-334|INFO|feed_model.php|post() feedid=75 updatetime=1664879440 feedtime=1664879440 value=8909.0572161109 arg=join
2022-10-04 10:30:40.-330|INFO|feed_model.php|post() feedid=206 updatetime=1664879440 feedtime=1664879440 value=877 arg=
2022-10-04 10:30:40.-324|INFO|feed_model.php|post() feedid=86 updatetime=1664879440 feedtime=1664879440 value=15423.15529045 arg=join
2022-10-04 10:30:40.-318|INFO|emoncms_mqtt.php|emon/emontx2/P3 12
2022-10-04 10:30:40.-310|INFO|feed_model.php|post() feedid=204 updatetime=1664879440 feedtime=1664879440 value=12 arg=
2022-10-04 10:30:40.-303|INFO|feed_model.php|post() feedid=241 updatetime=1664879440 feedtime=1664879440 value=3071.490990756 arg=join
2022-10-04 10:30:40.-299|INFO|emoncms_mqtt.php|emon/emontx2/P4 322
2022-10-04 10:30:40.-291|INFO|feed_model.php|post() feedid=202 updatetime=1664879440 feedtime=1664879440 value=322 arg=
2022-10-04 10:30:40.-283|INFO|feed_model.php|post() feedid=77 updatetime=1664879440 feedtime=1664879440 value=6983.5942382642 arg=join
2022-10-04 10:30:40.-279|INFO|emoncms_mqtt.php|emon/emontx2/E1 173878
2022-10-04 10:30:40.-270|INFO|emoncms_mqtt.php|emon/emontx2/E2 86062
2022-10-04 10:30:40.-259|INFO|feed_model.php|post() feedid=236 updatetime=1664879440 feedtime=1664879440 value=5089.0958945312 arg=join
2022-10-04 10:30:40.-248|INFO|feed_model.php|post() feedid=237 updatetime=1664879440 feedtime=1664879440 value=5687.3960351562 arg=join
2022-10-04 10:30:40.-233|INFO|emoncms_mqtt.php|emon/emontx2/E3 52906
2022-10-04 10:30:40.-221|INFO|feed_model.php|post() feedid=238 updatetime=1664879440 feedtime=1664879440 value=2500.4700957031 arg=join
2022-10-04 10:30:40.-214|INFO|emoncms_mqtt.php|emon/emontx2/E4 60357
2022-10-04 10:30:40.-202|INFO|feed_model.php|post() feedid=239 updatetime=1664879440 feedtime=1664879440 value=3681.4870332031 arg=join
2022-10-04 10:30:40.-196|INFO|emoncms_mqtt.php|emon/emontx2/T1 0
2022-10-04 10:30:40.-187|INFO|emoncms_mqtt.php|emon/emontx2/T2 0
2022-10-04 10:30:40.-177|INFO|emoncms_mqtt.php|emon/emontx2/T3 0
2022-10-04 10:30:40.-168|INFO|emoncms_mqtt.php|emon/emontx2/pulse 0
2022-10-04 10:30:40.-115|INFO|emoncms_mqtt.php|emon/openevse/divert_update 0
2022-10-04 10:30:40.-106|INFO|emoncms_mqtt.php|emon/openevse/grid_ie 1103
2022-10-04 10:30:40.-97|INFO|feed_model.php|post() feedid=197 updatetime=1664879440 feedtime=1664879440 value=1103 arg=
2022-10-04 10:30:40.-92|INFO|emoncms_mqtt.php|emon/openevse/charge_rate 0
2022-10-04 10:30:40.-84|INFO|feed_model.php|post() feedid=198 updatetime=1664879440 feedtime=1664879440 value=0 arg=
2022-10-04 10:30:40.-80|INFO|emoncms_mqtt.php|emon/openevse/voltage 245.95
2022-10-04 10:30:40.-72|INFO|emoncms_mqtt.php|emon/openevse/available_current 0
2022-10-04 10:30:40.-64|INFO|feed_model.php|post() feedid=199 updatetime=1664879440 feedtime=1664879440 value=0 arg=
2022-10-04 10:30:40.-59|INFO|emoncms_mqtt.php|emon/openevse/smoothed_available_current 3.375832e-6
2022-10-04 10:30:40.-50|INFO|feed_model.php|post() feedid=200 updatetime=1664879440 feedtime=1664879440 value=3.375832e-6 arg=
2022-10-04 10:30:40.-46|INFO|emoncms_mqtt.php|emon/openevse/pilot 32
2022-10-04 10:30:40.-35|INFO|feed_model.php|post() feedid=157 updatetime=1664879440 feedtime=1664879440 value=32 arg=
2022-10-04 10:30:41.020|INFO|emoncms_mqtt.php|Disconnected cleanly
2022-10-04 10:30:41.-182|INFO|feed_model.php|EngineClass() Autoloaded new instance of 'RedisBuffer'.
2022-10-04 10:30:42.005|WARN|emoncms_mqtt.php|Not connected, retrying connection
2022-10-04 10:30:42.018|WARN|emoncms_mqtt.php|Connecting to MQTT server: Connection Accepted.: code: 0
2022-10-04 10:30:42.018|INFO|emoncms_mqtt.php|Subscribed to: emon/# ID - 1710
2022-10-04 10:30:42.031|INFO|emoncms_mqtt.php|Callback subscribed to topic: openevseintegration/SurplusPVforEV
2022-10-04 10:30:44.-88|INFO|emoncms_mqtt.php|emon/20/1 2256
2022-10-04 10:30:47.015|INFO|emoncms_mqtt.php|Disconnected cleanly
2022-10-04 10:30:48.000|WARN|emoncms_mqtt.php|Not connected, retrying connection
2022-10-04 10:30:48.013|WARN|emoncms_mqtt.php|Connecting to MQTT server: Connection Accepted.: code: 0
2022-10-04 10:30:48.013|INFO|emoncms_mqtt.php|Subscribed to: emon/# ID - 1711
2022-10-04 10:30:48.025|INFO|emoncms_mqtt.php|Callback subscribed to topic: openevseintegration/SurplusPVforEV
2022-10-04 10:30:48.277|INFO|feed_model.php|EngineClass() Autoloaded new instance of 'PHPFina'.
2022-10-04 10:30:48.391|INFO|feed_model.php|EngineClass() Autoloaded new instance of 'PHPTimeSeries'.
2022-10-04 10:30:48.443|INFO|feed_model.php|get_timevalue() calling VIRTUAL lastvalue 227
2022-10-04 10:30:48.444|INFO|feed_model.php|EngineClass() Autoloaded new instance of 'VirtualFeed'.
2022-10-04 10:30:50.-319|INFO|emoncms_mqtt.php|emon/emontx2/MSG 70023
2022-10-04 10:30:50.-306|INFO|feed_model.php|post() feedid=243 updatetime=1664879450 feedtime=1664879450 value=70023 arg=
2022-10-04 10:30:50.-297|INFO|emoncms_mqtt.php|emon/emontx2/Vrms 244.5
2022-10-04 10:30:50.-287|INFO|feed_model.php|post() feedid=223 updatetime=1664879450 feedtime=1664879450 value=244.5 arg=
2022-10-04 10:30:50.-280|INFO|emoncms_mqtt.php|emon/emontx2/P1 549
2022-10-04 10:30:50.-270|INFO|feed_model.php|post() feedid=201 updatetime=1664879450 feedtime=1664879450 value=549 arg=
2022-10-04 10:30:50.-264|INFO|feed_model.php|post() feedid=207 updatetime=1664879450 feedtime=1664879450 value=549 arg=
2022-10-04 10:30:50.-256|INFO|feed_model.php|post() feedid=73 updatetime=1664879450 feedtime=1664879450 value=13591.982157572 arg=join
2022-10-04 10:30:50.-251|INFO|feed_model.php|post() feedid=208 updatetime=1664879450 feedtime=1664879450 value=0 arg=
2022-10-04 10:30:50.-243|INFO|feed_model.php|post() feedid=90 updatetime=1664879450 feedtime=1664879450 value=3319.5455413195 arg=join
2022-10-04 10:30:50.-237|INFO|feed_model.php|post() feedid=109 updatetime=1664879450 feedtime=1664879450 value=12 arg=
2022-10-04 10:30:50.-230|INFO|feed_model.php|post() feedid=110 updatetime=1664879450 feedtime=1664879450 value=8554.6666454178 arg=join
2022-10-04 10:30:50.-223|INFO|feed_model.php|post() feedid=107 updatetime=1664879450 feedtime=1664879450 value=1411 arg=
2022-10-04 10:30:50.-215|INFO|feed_model.php|post() feedid=108 updatetime=1664879450 feedtime=1664879450 value=25329.069967716 arg=join
2022-10-04 10:30:50.-210|INFO|feed_model.php|post() feedid=196 updatetime=1664879450 feedtime=1664879450 value=1037 arg=
2022-10-04 10:30:50.-205|INFO|feed_model.php|post() feedid=219 updatetime=1664879450 feedtime=1664879450 value=0 arg=
2022-10-04 10:30:50.-199|INFO|feed_model.php|post() feedid=220 updatetime=1664879450 feedtime=1664879450 value=72.903045654297 arg=join
2022-10-04 10:30:50.-194|INFO|feed_model.php|post() feedid=217 updatetime=1664879450 feedtime=1664879450 value=549 arg=
2022-10-04 10:30:50.-189|INFO|feed_model.php|post() feedid=218 updatetime=1664879450 feedtime=1664879450 value=188.69921384388 arg=join
2022-10-04 10:30:50.-185|INFO|emoncms_mqtt.php|emon/emontx2/P2 582
2022-10-04 10:30:50.-170|INFO|feed_model.php|post() feedid=203 updatetime=1664879450 feedtime=1664879450 value=582 arg=
2022-10-04 10:30:50.-160|INFO|feed_model.php|post() feedid=75 updatetime=1664879450 feedtime=1664879450 value=8909.0588327776 arg=join
2022-10-04 10:30:50.-154|INFO|feed_model.php|post() feedid=206 updatetime=1664879450 feedtime=1664879450 value=904 arg=
2022-10-04 10:30:50.-148|INFO|feed_model.php|post() feedid=86 updatetime=1664879450 feedtime=1664879450 value=15423.157801561 arg=join
2022-10-04 10:30:50.-141|INFO|emoncms_mqtt.php|emon/emontx2/P3 12
2022-10-04 10:30:50.-131|INFO|feed_model.php|post() feedid=204 updatetime=1664879450 feedtime=1664879450 value=12 arg=
2022-10-04 10:30:50.-125|INFO|feed_model.php|post() feedid=241 updatetime=1664879450 feedtime=1664879450 value=3071.4910240893 arg=join
2022-10-04 10:30:50.-120|INFO|emoncms_mqtt.php|emon/emontx2/P4 317
2022-10-04 10:30:50.-112|INFO|feed_model.php|post() feedid=202 updatetime=1664879450 feedtime=1664879450 value=317 arg=
2022-10-04 10:30:50.-106|INFO|feed_model.php|post() feedid=77 updatetime=1664879450 feedtime=1664879450 value=6983.5951188198 arg=join
2022-10-04 10:30:50.-102|INFO|emoncms_mqtt.php|emon/emontx2/E1 173880
2022-10-04 10:30:50.-94|INFO|emoncms_mqtt.php|emon/emontx2/E2 86064
2022-10-04 10:30:50.-85|INFO|feed_model.php|post() feedid=236 updatetime=1664879450 feedtime=1664879450 value=5089.0978945312 arg=join
2022-10-04 10:30:50.-79|INFO|feed_model.php|post() feedid=237 updatetime=1664879450 feedtime=1664879450 value=5687.3990351562 arg=join
2022-10-04 10:30:50.-75|INFO|emoncms_mqtt.php|emon/emontx2/E3 52906
2022-10-04 10:30:50.-66|INFO|feed_model.php|post() feedid=238 updatetime=1664879450 feedtime=1664879450 value=2500.4700957031 arg=join
2022-10-04 10:30:50.-63|INFO|emoncms_mqtt.php|emon/emontx2/E4 60358
2022-10-04 10:30:50.-54|INFO|feed_model.php|post() feedid=239 updatetime=1664879450 feedtime=1664879450 value=3681.4880332031 arg=join
2022-10-04 10:30:50.-50|INFO|emoncms_mqtt.php|emon/emontx2/T1 0
2022-10-04 10:30:50.-43|INFO|emoncms_mqtt.php|emon/emontx2/T2 0
2022-10-04 10:30:50.-35|INFO|emoncms_mqtt.php|emon/emontx2/T3 0
2022-10-04 10:30:50.-28|INFO|emoncms_mqtt.php|emon/emontx2/pulse 0
2022-10-04 10:30:51.051|INFO|emoncms_mqtt.php|emon/openevse/divert_update 0
2022-10-04 10:30:51.058|INFO|emoncms_mqtt.php|emon/openevse/grid_ie 1037
2022-10-04 10:30:51.065|INFO|feed_model.php|post() feedid=197 updatetime=1664879451 feedtime=1664879451 value=1037 arg=
2022-10-04 10:30:51.069|INFO|emoncms_mqtt.php|emon/openevse/charge_rate 0
2022-10-04 10:30:51.076|INFO|feed_model.php|post() feedid=198 updatetime=1664879451 feedtime=1664879451 value=0 arg=
2022-10-04 10:30:51.080|INFO|emoncms_mqtt.php|emon/openevse/voltage 246.24
2022-10-04 10:30:51.088|INFO|emoncms_mqtt.php|emon/openevse/available_current 0
2022-10-04 10:30:51.095|INFO|feed_model.php|post() feedid=199 updatetime=1664879451 feedtime=1664879451 value=0 arg=
2022-10-04 10:30:51.098|INFO|emoncms_mqtt.php|emon/openevse/smoothed_available_current 3.207041e-6
2022-10-04 10:30:51.105|INFO|feed_model.php|post() feedid=200 updatetime=1664879451 feedtime=1664879451 value=3.207041e-6 arg=
2022-10-04 10:30:51.109|INFO|emoncms_mqtt.php|emon/openevse/pilot 32
2022-10-04 10:30:51.117|INFO|feed_model.php|post() feedid=157 updatetime=1664879451 feedtime=1664879451 value=32 arg=
2022-10-04 10:30:51.-482|INFO|emoncms_mqtt.php|emon/emontx1/MSG 563
2022-10-04 10:30:51.-471|INFO|feed_model.php|post() feedid=244 updatetime=1664879451 feedtime=1664879451 value=563 arg=
2022-10-04 10:30:51.-454|INFO|emoncms_mqtt.php|emon/emontx1/Vrms 245.82
2022-10-04 10:30:51.-443|INFO|feed_model.php|post() feedid=222 updatetime=1664879451 feedtime=1664879451 value=245.82 arg=
2022-10-04 10:30:51.-439|INFO|feed_model.php|post() feedid=221 updatetime=1664879451 feedtime=1664879451 value=245.82 arg=
2022-10-04 10:30:51.-434|INFO|emoncms_mqtt.php|emon/emontx1/P1 -3
2022-10-04 10:30:51.-424|INFO|feed_model.php|post() feedid=83 updatetime=1664879451 feedtime=1664879451 value=-3 arg=
2022-10-04 10:30:51.-417|INFO|feed_model.php|post() feedid=84 updatetime=1664879451 feedtime=1664879451 value=635.42894117744 arg=join
2022-10-04 10:30:51.-412|INFO|emoncms_mqtt.php|emon/emontx1/P2 181
2022-10-04 10:30:51.-402|INFO|feed_model.php|post() feedid=160 updatetime=1664879451 feedtime=1664879451 value=181 arg=
2022-10-04 10:30:51.-395|INFO|feed_model.php|post() feedid=161 updatetime=1664879451 feedtime=1664879451 value=3276.8961545656 arg=join
2022-10-04 10:30:51.-390|INFO|emoncms_mqtt.php|emon/emontx1/P3 18
2022-10-04 10:30:51.-374|INFO|feed_model.php|post() feedid=164 updatetime=1664879451 feedtime=1664879451 value=18 arg=
2022-10-04 10:30:51.-368|INFO|feed_model.php|post() feedid=165 updatetime=1664879451 feedtime=1664879451 value=361.16794683047 arg=join
2022-10-04 10:30:51.-363|INFO|emoncms_mqtt.php|emon/emontx1/P4 4
2022-10-04 10:30:51.-353|INFO|feed_model.php|post() feedid=205 updatetime=1664879451 feedtime=1664879451 value=4 arg=
2022-10-04 10:30:51.-347|INFO|feed_model.php|post() feedid=82 updatetime=1664879451 feedtime=1664879451 value=3567.9224908993 arg=join
2022-10-04 10:30:51.-342|INFO|emoncms_mqtt.php|emon/emontx1/E1 -3
2022-10-04 10:30:51.-329|INFO|feed_model.php|post() feedid=233 updatetime=1664879451 feedtime=1664879451 value=29.905000747681 arg=join
2022-10-04 10:30:51.-324|INFO|emoncms_mqtt.php|emon/emontx1/E2 290
2022-10-04 10:30:51.-311|INFO|feed_model.php|post() feedid=232 updatetime=1664879451 feedtime=1664879451 value=178.00799279785 arg=join
2022-10-04 10:30:51.-305|INFO|emoncms_mqtt.php|emon/emontx1/E3 28
2022-10-04 10:30:51.-281|INFO|feed_model.php|post() feedid=234 updatetime=1664879451 feedtime=1664879451 value=16.506999420166 arg=join
2022-10-04 10:30:51.-273|INFO|emoncms_mqtt.php|emon/emontx1/E4 6
2022-10-04 10:30:51.-260|INFO|feed_model.php|post() feedid=235 updatetime=1664879451 feedtime=1664879451 value=1.4749999542236 arg=join
2022-10-04 10:30:51.-254|INFO|emoncms_mqtt.php|emon/emontx1/T1 0
2022-10-04 10:30:51.-243|INFO|emoncms_mqtt.php|emon/emontx1/T2 0
2022-10-04 10:30:51.-232|INFO|emoncms_mqtt.php|emon/emontx1/T3 0
2022-10-04 10:30:51.-221|INFO|emoncms_mqtt.php|emon/emontx1/pulse 0
2022-10-04 10:30:53.009|INFO|emoncms_mqtt.php|Disconnected cleanly
2022-10-04 10:30:54.004|WARN|emoncms_mqtt.php|Not connected, retrying connection
2022-10-04 10:30:54.016|WARN|emoncms_mqtt.php|Connecting to MQTT server: Connection Accepted.: code: 0
2022-10-04 10:30:54.017|INFO|emoncms_mqtt.php|Subscribed to: emon/# ID - 1713
2022-10-04 10:30:54.029|INFO|emoncms_mqtt.php|Callback subscribed to topic: openevseintegration/SurplusPVforEV
2022-10-04 10:30:54.-33|INFO|emoncms_mqtt.php|emon/20/1 2256
2022-10-04 10:30:58.280|INFO|feed_model.php|EngineClass() Autoloaded new instance of 'PHPFina'.
2022-10-04 10:30:58.398|INFO|feed_model.php|EngineClass() Autoloaded new instance of 'PHPTimeSeries'.
2022-10-04 10:30:58.451|INFO|feed_model.php|get_timevalue() calling VIRTUAL lastvalue 227
2022-10-04 10:30:58.452|INFO|feed_model.php|EngineClass() Autoloaded new instance of 'VirtualFeed'.
2022-10-04 10:30:59.016|INFO|emoncms_mqtt.php|Disconnected cleanly
2022-10-04 10:31:00.001|WARN|emoncms_mqtt.php|Not connected, retrying connection
2022-10-04 10:31:00.013|WARN|emoncms_mqtt.php|Connecting to MQTT server: Connection Accepted.: code: 0
2022-10-04 10:31:00.014|INFO|emoncms_mqtt.php|Subscribed to: emon/# ID - 1714
2022-10-04 10:31:00.026|INFO|emoncms_mqtt.php|Callback subscribed to topic: openevseintegration/SurplusPVforEV
2022-10-04 10:31:00.-376|INFO|emoncms_mqtt.php|emon/emontx2/MSG 70024
2022-10-04 10:31:00.-365|INFO|feed_model.php|post() feedid=243 updatetime=1664879460 feedtime=1664879460 value=70024 arg=
2022-10-04 10:31:00.-358|INFO|emoncms_mqtt.php|emon/emontx2/Vrms 244.28
2022-10-04 10:31:00.-348|INFO|feed_model.php|post() feedid=223 updatetime=1664879460 feedtime=1664879460 value=244.28 arg=
2022-10-04 10:31:00.-311|INFO|emoncms_mqtt.php|emon/emontx2/P1 461
2022-10-04 10:31:00.-301|INFO|feed_model.php|post() feedid=201 updatetime=1664879460 feedtime=1664879460 value=461 arg=
2022-10-04 10:31:00.-296|INFO|feed_model.php|post() feedid=207 updatetime=1664879460 feedtime=1664879460 value=461 arg=
2022-10-04 10:31:00.-290|INFO|feed_model.php|post() feedid=73 updatetime=1664879460 feedtime=1664879460 value=13591.983438128 arg=join
2022-10-04 10:31:00.-285|INFO|feed_model.php|post() feedid=208 updatetime=1664879460 feedtime=1664879460 value=0 arg=
2022-10-04 10:31:00.-279|INFO|feed_model.php|post() feedid=90 updatetime=1664879460 feedtime=1664879460 value=3319.5455413195 arg=join
2022-10-04 10:31:00.-273|INFO|feed_model.php|post() feedid=109 updatetime=1664879460 feedtime=1664879460 value=12 arg=
2022-10-04 10:31:00.-267|INFO|feed_model.php|post() feedid=110 updatetime=1664879460 feedtime=1664879460 value=8554.6666787511 arg=join
2022-10-04 10:31:00.-261|INFO|feed_model.php|post() feedid=107 updatetime=1664879460 feedtime=1664879460 value=1360 arg=
2022-10-04 10:31:00.-255|INFO|feed_model.php|post() feedid=108 updatetime=1664879460 feedtime=1664879460 value=25329.073745494 arg=join
2022-10-04 10:31:00.-249|INFO|feed_model.php|post() feedid=196 updatetime=1664879460 feedtime=1664879460 value=949 arg=
2022-10-04 10:31:00.-243|INFO|feed_model.php|post() feedid=219 updatetime=1664879460 feedtime=1664879460 value=0 arg=
2022-10-04 10:31:00.-236|INFO|feed_model.php|post() feedid=220 updatetime=1664879460 feedtime=1664879460 value=72.903045654297 arg=join
2022-10-04 10:31:00.-231|INFO|feed_model.php|post() feedid=217 updatetime=1664879460 feedtime=1664879460 value=461 arg=
2022-10-04 10:31:00.-225|INFO|feed_model.php|post() feedid=218 updatetime=1664879460 feedtime=1664879460 value=188.70049439944 arg=join
2022-10-04 10:31:00.-222|INFO|emoncms_mqtt.php|emon/emontx2/P2 634
2022-10-04 10:31:00.-214|INFO|feed_model.php|post() feedid=203 updatetime=1664879460 feedtime=1664879460 value=634 arg=
2022-10-04 10:31:00.-210|INFO|feed_model.php|post() feedid=75 updatetime=1664879460 feedtime=1664879460 value=8909.0605938887 arg=join
2022-10-04 10:31:00.-206|INFO|feed_model.php|post() feedid=206 updatetime=1664879460 feedtime=1664879460 value=951 arg=
2022-10-04 10:31:00.-202|INFO|feed_model.php|post() feedid=86 updatetime=1664879460 feedtime=1664879460 value=15423.160443228 arg=join
2022-10-04 10:31:00.-198|INFO|emoncms_mqtt.php|emon/emontx2/P3 13
2022-10-04 10:31:00.-191|INFO|feed_model.php|post() feedid=204 updatetime=1664879460 feedtime=1664879460 value=13 arg=
2022-10-04 10:31:00.-186|INFO|feed_model.php|post() feedid=241 updatetime=1664879460 feedtime=1664879460 value=3071.4910602004 arg=join
2022-10-04 10:31:00.-183|INFO|emoncms_mqtt.php|emon/emontx2/P4 318
2022-10-04 10:31:00.-176|INFO|feed_model.php|post() feedid=202 updatetime=1664879460 feedtime=1664879460 value=318 arg=
2022-10-04 10:31:00.-171|INFO|feed_model.php|post() feedid=77 updatetime=1664879460 feedtime=1664879460 value=6983.5960021531 arg=join
2022-10-04 10:31:00.-167|INFO|emoncms_mqtt.php|emon/emontx2/E1 173882
2022-10-04 10:31:00.-160|INFO|emoncms_mqtt.php|emon/emontx2/E2 86065
2022-10-04 10:31:00.-151|INFO|feed_model.php|post() feedid=236 updatetime=1664879460 feedtime=1664879460 value=5089.0988945312 arg=join
2022-10-04 10:31:00.-145|INFO|feed_model.php|post() feedid=237 updatetime=1664879460 feedtime=1664879460 value=5687.4010351562 arg=join
2022-10-04 10:31:00.-141|INFO|emoncms_mqtt.php|emon/emontx2/E3 52906
2022-10-04 10:31:00.-132|INFO|feed_model.php|post() feedid=238 updatetime=1664879460 feedtime=1664879460 value=2500.4700957031 arg=join
2022-10-04 10:31:00.-128|INFO|emoncms_mqtt.php|emon/emontx2/E4 60359
2022-10-04 10:31:00.-119|INFO|feed_model.php|post() feedid=239 updatetime=1664879460 feedtime=1664879460 value=3681.4890332031 arg=join
2022-10-04 10:31:00.-114|INFO|emoncms_mqtt.php|emon/emontx2/T1 0
2022-10-04 10:31:00.-106|INFO|emoncms_mqtt.php|emon/emontx2/T2 0
2022-10-04 10:31:00.-91|INFO|emoncms_mqtt.php|emon/emontx2/T3 0
2022-10-04 10:31:00.-82|INFO|emoncms_mqtt.php|emon/emontx2/pulse 0
2022-10-04 10:31:00.-11|INFO|emoncms_mqtt.php|emon/openevse/divert_update 0
2022-10-04 10:31:00.-03|INFO|emoncms_mqtt.php|emon/openevse/grid_ie 949
2022-10-04 10:31:01.003|INFO|feed_model.php|post() feedid=197 updatetime=1664879460 feedtime=1664879460 value=949 arg=
2022-10-04 10:31:01.006|INFO|emoncms_mqtt.php|emon/openevse/charge_rate 0
2022-10-04 10:31:01.014|INFO|feed_model.php|post() feedid=198 updatetime=1664879461 feedtime=1664879461 value=0 arg=
2022-10-04 10:31:01.017|INFO|emoncms_mqtt.php|emon/openevse/voltage 246.18
2022-10-04 10:31:01.024|INFO|emoncms_mqtt.php|emon/openevse/available_current 0
2022-10-04 10:31:01.032|INFO|feed_model.php|post() feedid=199 updatetime=1664879461 feedtime=1664879461 value=0 arg=
2022-10-04 10:31:01.036|INFO|emoncms_mqtt.php|emon/openevse/smoothed_available_current 3.046689e-6
2022-10-04 10:31:01.044|INFO|feed_model.php|post() feedid=200 updatetime=1664879461 feedtime=1664879461 value=3.046689e-6 arg=
2022-10-04 10:31:01.047|INFO|emoncms_mqtt.php|emon/openevse/pilot 32
2022-10-04 10:31:01.055|INFO|feed_model.php|post() feedid=157 updatetime=1664879461 feedtime=1664879461 value=32 arg=
2022-10-04 10:31:01.460|INFO|emoncms_mqtt.php|emon/emontx1/MSG 565
2022-10-04 10:31:01.467|INFO|feed_model.php|post() feedid=244 updatetime=1664879461 feedtime=1664879461 value=565 arg=
2022-10-04 10:31:01.472|INFO|emoncms_mqtt.php|emon/emontx1/Vrms 245.95000000000002
2022-10-04 10:31:01.480|INFO|feed_model.php|post() feedid=222 updatetime=1664879461 feedtime=1664879461 value=245.95000000000002 arg=
2022-10-04 10:31:01.486|INFO|feed_model.php|post() feedid=221 updatetime=1664879461 feedtime=1664879461 value=245.95000000000002 arg=
2022-10-04 10:31:01.-476|INFO|emoncms_mqtt.php|emon/emontx1/P1 -4
2022-10-04 10:31:01.-465|INFO|feed_model.php|post() feedid=83 updatetime=1664879461 feedtime=1664879461 value=-4 arg=
2022-10-04 10:31:01.-458|INFO|feed_model.php|post() feedid=84 updatetime=1664879461 feedtime=1664879461 value=635.42893006633 arg=join
2022-10-04 10:31:01.-442|INFO|emoncms_mqtt.php|emon/emontx1/P2 181
2022-10-04 10:31:01.-431|INFO|feed_model.php|post() feedid=160 updatetime=1664879461 feedtime=1664879461 value=181 arg=
2022-10-04 10:31:01.-424|INFO|feed_model.php|post() feedid=161 updatetime=1664879461 feedtime=1664879461 value=3276.8966573434 arg=join
2022-10-04 10:31:01.-417|INFO|emoncms_mqtt.php|emon/emontx1/P3 18
2022-10-04 10:31:01.-406|INFO|feed_model.php|post() feedid=164 updatetime=1664879461 feedtime=1664879461 value=18 arg=
2022-10-04 10:31:01.-398|INFO|feed_model.php|post() feedid=165 updatetime=1664879461 feedtime=1664879461 value=361.16799683047 arg=join
2022-10-04 10:31:01.-392|INFO|emoncms_mqtt.php|emon/emontx1/P4 4
2022-10-04 10:31:01.-382|INFO|feed_model.php|post() feedid=205 updatetime=1664879461 feedtime=1664879461 value=4 arg=
2022-10-04 10:31:01.-374|INFO|feed_model.php|post() feedid=82 updatetime=1664879461 feedtime=1664879461 value=3567.9225020104 arg=join
2022-10-04 10:31:01.-369|INFO|emoncms_mqtt.php|emon/emontx1/E1 -3
2022-10-04 10:31:01.-355|INFO|feed_model.php|post() feedid=233 updatetime=1664879461 feedtime=1664879461 value=29.905000747681 arg=join
2022-10-04 10:31:01.-349|INFO|emoncms_mqtt.php|emon/emontx1/E2 291
2022-10-04 10:31:01.-334|INFO|feed_model.php|post() feedid=232 updatetime=1664879461 feedtime=1664879461 value=178.00899279785 arg=join
2022-10-04 10:31:01.-328|INFO|emoncms_mqtt.php|emon/emontx1/E3 28
2022-10-04 10:31:01.-316|INFO|feed_model.php|post() feedid=234 updatetime=1664879461 feedtime=1664879461 value=16.506999420166 arg=join
2022-10-04 10:31:01.-312|INFO|emoncms_mqtt.php|emon/emontx1/E4 6
2022-10-04 10:31:01.-303|INFO|feed_model.php|post() feedid=235 updatetime=1664879461 feedtime=1664879461 value=1.4749999542236 arg=join
2022-10-04 10:31:01.-299|INFO|emoncms_mqtt.php|emon/emontx1/T1 0
2022-10-04 10:31:01.-291|INFO|emoncms_mqtt.php|emon/emontx1/T2 0
2022-10-04 10:31:01.-284|INFO|emoncms_mqtt.php|emon/emontx1/T3 0
2022-10-04 10:31:01.-276|INFO|emoncms_mqtt.php|emon/emontx1/pulse 0

Would anyone be able to suggest where to look next to diagnose please? Thanks!

a23452533 · 4 October 2022 19:54

Here’s emontx1 over the last 6 hours. The jumps are getting bigger - around 100 messages towards the right hand side of the chart.

Emontx2 on the other hand is correctly showing a straight line.

borpin · 4 October 2022 20:48

I have previously noticed that you can flood the MQTT receiver on an EmonPi if you send too many messages - it isn’t very efficient. I’m sure I have posted on this before.

Send the data as a single JSON rather than individual values (I created this method for precisely this reason). If you use a timestamp, that makes it even more precise (if your EmonPi clock syncs correctly) and all the values have the same timestamp (otherwise by the time it has processed all the individual values from one device, the timeseries window might have moved on).

The data should appear in the same place in the Inputs.

    [[[runtimesettings]]]
        subchannels = ToEmonCMS,

        timestamped = True
        node_JSON_enable = 1
        node_JSON_basetopic = emon/

If I send data from Node-RED, I throttle the message rate to avoid this as well.

The HTTP interfacer is more efficient as it buffers the messages (by default).

a23452533 · 4 October 2022 21:07

Thanks Brian. Trying that setting now, and will report back!

I don’t have any particular reason to use the MQTT interfacer for the emontxes. I do have water counters and Openevse coming in via MQTT, so thought I might as well move everything to MQTT.

Should I go back to using the original httpinterfacer or stick with MQTT?

borpin · 5 October 2022 07:16

I use MQTT because I pick up the published data from more than one place (HA and Emoncms for instance). It really is your choice

a23452533 · 5 October 2022 07:39

Oh that’s interesting. I use the Emoncms integration in HA to bring in the feed values for_use and _kwh which drive the energy dashboard and other automation.

How are you using the mqtt data?

a23452533 · 30 October 2022 22:45

I am still having a lag problem with emontx. Although the msg count isn’t jumping around, the inputs are showing an 11 minute delay.

Interestingly I also have OpenEVSE inputs coming in which are not showing a delay.

Any suggestions on what to do next please?

borpin · 31 October 2022 06:49

Is the time on the Pi correct?

Is this still the same base image? If so there were issues with the NTP sync at one point so that might be the problem.

See Ensuring emonPi / emonBase time is synchronised with an NTP server

a23452533 · 31 October 2022 07:57

Thanks for the reply.
Time looks ok on the pi.

Here’s a couple of admin page screenshots.

borpin · 31 October 2022 15:47

AIUI, the time on the Inputs page is calculated as the difference between now() on that computer and the date stamp on the data.

Either the EmonPi’s time or the Computer’s time is wrong.

Your smartphone has the most accurate time. If you open a GPS app, that will be even better.

a23452533 · 31 October 2022 21:50

I just rechecked. The emonpi and computer time are correct.

the emontx inputs are showing 11 minutes behind. I also have openevse feeds which are coming through correctly, and green and only a few seconds behind.

borpin · 1 November 2022 07:21

Just to check, you have 2 emonTXs communicating to an EmonBase (i.e a Pi with the RFM Board)?

data is received by emonhub, then passed to emoncms via MQTT.

Are you using the timestamp JSON Format?

Can you post the relevant section of the emonhub log (on DEBUG), please? Is the timestamp correct?
From receipt of data from the first TX to the sending of the second TX data, please?

TrystanLea · 1 November 2022 11:57

That looks like what you might see if you had two emonTx units posting on the same nodeid… any chance that there is another emontx? or is there any chance one set of readings is coming via WiFi and another via the rfm radio? not sure how that would cause the 11 minute delay though…

The only time Im aware of seeing local time delays is when the time is incorrect after a power cut. I then run:

sudo service systemd-timesyncd restart

to correct it.

a23452533 · 10 November 2022 21:44

Hi, Here’s an emonhub log excerpt showing data going to mqtt with no delay. THis is not the internal emoncms MQTT, it is a separate Mosquito instance running as a docker.

2022-11-10 21:37:40,190 DEBUG    RFM2Pi     171677 NEW FRAME : OK 11 178 100 4 0 36 91 251 255 68 29 251 255 22 0 227 105 0 0 230 190 5 0 221 102 0 0 103 34 0 0 0 0 0 0 0 0 0 0 0 0
2022-11-10 21:37:40,194 DEBUG    RFM2Pi     171677 Timestamp : 1668116260.190044
2022-11-10 21:37:40,195 DEBUG    RFM2Pi     171677 From Node : 11
2022-11-10 21:37:40,196 DEBUG    RFM2Pi     171677    Values : [287922, 233.32, -5, 7492, -5, 22, 27107, 376550, 26333, 8807, 0, 0, 0, 0]
2022-11-10 21:37:40,197 DEBUG    RFM2Pi     171677 Sent to channel(start)' : ToEmonCMS
2022-11-10 21:37:40,197 DEBUG    RFM2Pi     171677 Sent to channel(end)' : ToEmonCMS
2022-11-10 21:37:40,309 DEBUG    MQTT       Publishing: emon/emontx1 {"MSG": 287922, "Vrms": 233.32, "P1": -5, "P2": 7492, "P3": -5, "P4": 22, "E1": 27107, "E2": 376550, "E3": 26333, "E4": 8807, "T1": 0, "T2": 0, "T3": 0, "pulse": 0, "time": 1668116260.1900437}
2022-11-10 21:37:45,239 DEBUG    RFM2Pi     171678 NEW FRAME : OK 12 178 100 4 0 120 90 211 47 4 0 146 10 2 0 160 174 12 0 184 166 3 0 131 227 2 0 73 115 2 0 0 0 0 0 0 0 0 0 0 0
2022-11-10 21:37:45,242 DEBUG    RFM2Pi     171678 Timestamp : 1668116265.239381
2022-11-10 21:37:45,243 DEBUG    RFM2Pi     171678 From Node : 12
2022-11-10 21:37:45,244 DEBUG    RFM2Pi     171678    Values : [287922, 231.6, 12243, 4, 2706, 2, 831136, 239288, 189315, 160585, 0, 0, 0, 0]
2022-11-10 21:37:45,244 DEBUG    RFM2Pi     171678 Sent to channel(start)' : ToEmonCMS
2022-11-10 21:37:45,245 DEBUG    RFM2Pi     171678 Sent to channel(end)' : ToEmonCMS
2022-11-10 21:37:45,445 DEBUG    MQTT       Publishing: emon/emontx2 {"MSG": 287922, "Vrms": 231.6, "P1": 12243, "P2": 4, "P3": 2706, "P4": 2, "E1": 831136, "E2": 239288, "E3": 189315, "E4": 160585, "T1": 0, "T2": 0, "T3": 0, "pulse": 0, "time": 1668116265.239381}
2022-11-10 21:37:50,189 DEBUG    RFM2Pi     171679 NEW FRAME : OK 11 179 100 4 0 249 90 251 255 44 29 251 255 21 0 227 105 0 0 251 190 5 0 221 102 0 0 103 34 0 0 0 0 0 0 0 0 0 0 0 0
2022-11-10 21:37:50,193 DEBUG    RFM2Pi     171679 Timestamp : 1668116270.188793
2022-11-10 21:37:50,195 DEBUG    RFM2Pi     171679 From Node : 11
2022-11-10 21:37:50,195 DEBUG    RFM2Pi     171679    Values : [287923, 232.89000000000001, -5, 7468, -5, 21, 27107, 376571, 26333, 8807, 0, 0, 0, 0]
2022-11-10 21:37:50,196 DEBUG    RFM2Pi     171679 Sent to channel(start)' : ToEmonCMS
2022-11-10 21:37:50,197 DEBUG    RFM2Pi     171679 Sent to channel(end)' : ToEmonCMS
2022-11-10 21:37:50,295 DEBUG    MQTT       Publishing: emon/emontx1 {"MSG": 287923, "Vrms": 232.89000000000001, "P1": -5, "P2": 7468, "P3": -5, "P4": 21, "E1": 27107, "E2": 376571, "E3": 26333, "E4": 8807, "T1": 0, "T2": 0, "T3": 0, "pulse": 0, "time": 1668116270.1887934}
2022-11-10 21:37:55,236 DEBUG    RFM2Pi     171680 NEW FRAME : OK 12 179 100 4 0 53 90 135 47 4 0 132 10 2 0 194 174 12 0 184 166 3 0 139 227 2 0 73 115 2 0 0 0 0 0 0 0 0 0 0 0
2022-11-10 21:37:55,239 DEBUG    RFM2Pi     171680 Timestamp : 1668116275.236220
2022-11-10 21:37:55,239 DEBUG    RFM2Pi     171680 From Node : 12
2022-11-10 21:37:55,240 DEBUG    RFM2Pi     171680    Values : [287923, 230.93, 12167, 4, 2692, 2, 831170, 239288, 189323, 160585, 0, 0, 0, 0]
2022-11-10 21:37:55,241 DEBUG    RFM2Pi     171680 Sent to channel(start)' : ToEmonCMS
2022-11-10 21:37:55,242 DEBUG    RFM2Pi     171680 Sent to channel(end)' : ToEmonCMS
2022-11-10 21:37:55,432 DEBUG    MQTT       Publishing: emon/emontx2 {"MSG": 287923, "Vrms": 230.93, "P1": 12167, "P2": 4, "P3": 2692, "P4": 2, "E1": 831170, "E2": 239288, "E3": 189323, "E4": 160585, "T1": 0, "T2": 0, "T3": 0, "pulse": 0, "time": 1668116275.23622}

Here’s the realtime visualisation showing 3 minutes behind on emonpi.

Here’s the feed screen showing the feeds delayed by 3 minutes

borpin · 11 November 2022 07:31

Can you screenshot the Inputs page.

[edit]
When looking at the emonhub log scrolling, the times shown there, matches the time on the PC?

a23452533 · 11 November 2022 10:53

Here’s the inputs page from this morning. Yes the emonhub
log matches the PC time.

In MQTT explorer, the messages also match emonhub-There is no delay.

If I reboot emonpi, the inputs start off coming through ok with no delay, but then deteriorate gradually over the day.

borpin · 11 November 2022 11:44

Can you adjust the emonhub config so it only sends one of the formats and then post emonhub log and emoncms log (preferably aligned), please?

It is very odd.

a23452533 · 11 November 2022 13:12

Will do. What should I comment out?
Thanks.

#######################################################################
#######################      emonhub.conf     #########################
#######################################################################
### emonHub configuration file, for info see documentation:
### http://github.com/openenergymonitor/emonhub/blob/emon-pi/configuration.md
#######################################################################
#######################    emonHub  settings    #######################
#######################################################################

[hub]
### loglevel must be one of DEBUG, DEBUG, DEBUG, ERROR, and CRITICAL
loglevel = DEBUG
### Uncomment this to also send to syslog
# use_syslog = yes
#######################################################################
#######################       Interfacers       #######################
#######################################################################

[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 = 868
        baseid = 15                              # emonPi / emonBase nodeID
        quiet = true                            # Report incomplete RF packets (no implemented on emonPi)
        calibration = 230V                      # (UK/EU: 230V, US: 110V)
        # interval =  0                         # Interval to transmit time to emonGLCD (seconds)

[[MQTT]]

    Type = EmonHubMqttInterfacer
    [[[init_settings]]]
        mqtt_host = mqtt.lan
        mqtt_port = 1883
        mqtt_user = mqtt
        mqtt_passwd = xxxxxxx
#        mqtt_host = 127.0.0.1
#       mqtt_port = 1883
#      mqtt_user = emonpi
#        mqtt_passwd = emonpimqtt2016

    [[[runtimesettings]]]
        pubchannels = ToRFM12,
        subchannels = ToEmonCMS,

        # emonhub/rx/10/values format
        # Use with emoncms Nodes module
        node_format_enable = 0
        node_format_basetopic = emonhub/

        # emon/emontx/power1 format - use with Emoncms MQTT input
        # http://github.com/emoncms/emoncms/blob/master/docs/RaspberryPi/MQTT.md
        nodevar_format_enable = 0
        nodevar_format_basetopic = emon/

        timestamped = True
        node_JSON_enable = 1
        node_JSON_basetopic = emon/

#[[emoncmsorg]]
#   Type = EmonHubEmoncmsHTTPInterfacer
#  [[[init_settings]]]
#   [[[runtimesettings]]]
#      pubchannels = ToRFM12,
#     subchannels = ToEmonCMS,
#        url = https://emoncms.org
#       apikey = xxxxxxx
#      senddata = 1                    # Enable sending data to Emoncms.org
#        sendstatus = 0                  # Enable sending WAN IP to Emoncms.org MyIP > https://emoncms.org/myip/list
#        sendinterval= 30                # Bulk send interval to Emoncms.org in seconds

#[[emoncmslocal]]
#   Type = EmonHubEmoncmsHTTPInterfacer
#    [[[init_settings]]]
#    [[[runtimesettings]]]
#        pubchannels = ToRFM12,
#        subchannels = ToEmonCMS,
#        url = http://localhost/emoncms
#        apikey = xxxxxxx
#        senddata = 0                    # Enable sending data to Emoncms.org
#        sendstatus = 0                  # Enable sending WAN IP to Emoncms.org MyIP > https://emoncms.org/myip/list
#        sendinterval= 10                # Bulk send interval to Emoncms.org in seconds

#[[emoncmsunraid]]
#    Type = EmonHubEmoncmsHTTPInterfacer
#    [[[init_settings]]]
#    [[[runtimesettings]]]
#        pubchannels = ToRFM12,
#        subchannels = ToEmonCMS,
#        url = http://192.168.27.3:8998
#        apikey = xxxxxxxxx
#        senddata = 1                    # Enable sending data to Emoncms.org
#        sendstatus = 0                  # Enable sending WAN IP to Emoncms.org MyIP > https://emoncms.org/myip/list
#        sendinterval= 5                # Bulk send interval to Emoncms.org in seconds

[Edit] removed API Keys and passwords - remember to do this when posting - Mod

borpin · 11 November 2022 14:10

According to this log, you already have removed the individual MQTT topics so you should only be publishing the JSON version (i.e. enable is 1).

Need to see the Emoncms log, preferably a snippet aligned with the emonhub log.

You could run these as a tail of the each log file in 2 separate SSH windows.(one log tail in each).

[edit]

tail -f /var/log/emonhub/emonhub.log | grep -e "Publishing"
tail -f /var/log/emoncms/emoncms.log | grep -e "emoncms_mqtt.php"

a23452533 · 11 November 2022 22:05

Thank you for persisting with me, Sorted now - user error, but not entirely sure of the cause.

Here’s what the 2 tails showed.

The MQTT connection error looked odd. Then I remembered that I’d started setting up a docker version of emoncms on my unRAID NAS. I had connected it to the same MQTT instance as emonpi because I wanted the docker to consume the same emonhub messages as emonpi. This was partially working because I could see all the inputs from MQTT in the docker instance. I didn’t finish setting it up because I couldn’t get the admin interface working properly.

I’d left that docker running. As soon as I shut it down, the inputs on emonpi started working properly again, with no delay, and the mqtt connection error on emonpi stopped appearing in the log.

Started the docker back up. Emonpi straight away showed 9 minutes delay.

I don’t know why the docker emoncms would conflict with the emonpi when consuming the same MQTT topics.