emonTxV3 stops and requires reboot (emonhub)

Hardware emonTx
,
1

Hello,

I have recently setup a house power monitoring system (USA) with the following:
emonTXV3 + AC/AC power, RFM69Pi_433 (purchased July 2017)
RPI 3 loaded with flashed OEM software on 32 GB sd
2 x SCT023R on 220 mains

All seems to be working correctly most of the time, however, the emonTX shuts down (no blinking LEDs) unexpectedly every 5 to 10 days. After cycling the power, everything seems to restart normally.

The emonBase seems to be working continuously as it is also receiving data from my weather station (VP2 + weewx software) on a remote linux server. Only the emonTX feed stops receiving. Everything is linked via Ethernet.

For some reason, all my log files are overwritten when I reboot the RPI3. Not sure why this is happening as I must have something set incorrectly.

I’ll be happy to send more information but this is the basic setup I am using.

Thanks in advance for any suggestions.

Bob

2

The log files are only held in RAM as the OS is configured read-only to reduce disk wear etc so they get wiped at every reboot.

Do you have a usb-serial programmer to check the emonTx serial output for FW version and possible debugging?

Can you attach a short excerprt of emonhub.log from when it is working ok so we can see what sort of value range and rssi you’re getting?

The no blinking LED sounds a lot like either a PSU issue or possibly a poor connection (dry joint?) to the RFM module on the emonTx, but they are just guesses at this stage so whilst it is definitely worth having a close look for anything obvious, we can’t assume this is the fault without further info/debugging.

3

Paul,
Thanks for the quick reply. Yes, I do have a usb-serial programmer I purchased from OEM. Not very experienced with using it, however.

Here is the start of my present emonhub.log
emonhub_log.txt (6.7 KB)

Thanks.
Bob

4

Can you post another emonhub.log when you get a chance and can you confirm you haven’t edited it or used any filters or search terms etc? The logs seem incomplete and do not make any sense, they consist mainly of MQTT publishing, but what is it publishing? there is no evidence of it receiving anything for it to publish.

5

Paul,

Here are two files. A screen shot of my inputs and more emonhub.log with no filters or edits (first one I sent was the same).
I have also listed the node config excerpt I have setup in emonhub.conf.emonhub_log.txt (11.4 KB)
inputs.pdf (116.6 KB)

Power 1 & 2 are my mains. Powers 3 & 4 are just individual circuits in my breaker panel.

Thanks and let me know if I can send you any additional information.

Bob

6

Can you also attach a full emonhub.conf file? redact any sensitive urls/apikeys before post publicly or PM me the unredacted file if preferred. Those emonhub logs really make no sense, somethings definitely amiss there.

Also when did you last update the emonPi via the emoncms admin page (or reinstall from a downloaded image)?

7

Paul,

See attached, unredacted–emonhub.conf. Don’t think there is anything to redact.

I update the emonPi via admin page at least once a week so latest was probably a few days ago.

Thanks,
Bob

emonhub_conf.txt (7.5 KB)

8

Ahh!

loglevel is set to info, can you set that to debug, then let it run awhile and post the emonhub.log again. Sorry this was supposed to be just a quick check to see if there was anything obvious, I doubt there will be whilst it is running ok, but at least now it happens again the log will have some useful info if set to debug.

9

Paul,

Here’s the first few minutes of debug. It’s filling up quickly. Everything has been running ok since I restarted the emonTX yesterday, about 24 hours ago. I’ve also included the update file in case it shows anything important. Thanks.
Bob
emonhub_log_debug.txt (937.9 KB)
emonpiupdate_log.txt (8.8 KB)

10

Holy cow! That is filling up pretty quick, It looks like there is an issue with the way the error logging is working with the recent changes to include a buffered http output. You should never have several thousand consecutive “adding frame to buffer” entries, It looks like any failed deliveries result in the every entry in the buffer being reprinted to the logfile.

@TrystanLea will probably need to take a look at that as his recent implementation is nothing like the original implementation that was removed for the emonpi version so I do not know my way around it.

However emonhub caps it’s own log files to 2x 5mb so the logs cannot grow to more than 10Mb.

[EDIT] actually logrotate is active on the emonSD and that will rotate every hour if the files are over 1Mb so it should take up significantly less room.

[EDIT2] however! just noticed that logrotate is set up to rotate up to 3 files, so in a race condition it could swap out a near 5mb file before emonhub and result in up to 3x5mb files, so 15mb max I guess.

11

Looking at the logs while 9000 buffer items looks like a problem, I think this might just be a day’s worth of data queued up as it seems to be failing to post and get a confirmation of posting from the emoncms.org server. The timing on each frame looks ok at 10s.

@bgrattan do you wish to send data to emoncms.org? are your emoncms.org details, server and apikey correct?

If you do not wish to send data to emoncms.org you can turn it off by setting

senddata = 0

or the ‘apikey = xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx’, 32 ‘x’ characters are important here as emonhub string matches to this exact number of x’s so that users who start with default emonhub configuration dont have emonhub posting to emoncms.org by default

in emonhub.conf

[[emoncmsorg]]
    Type = EmonHubEmoncmsHTTPInterfacer
    [[[init_settings]]]
    [[[runtimesettings]]]
        pubchannels = ToRFM12,
        subchannels = ToEmonCMS,
        url = https://emoncms.org
        apikey = xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
        senddata = 0                    # 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
12

Correct(ish), Whilst having 9000 frames in the buffer may not be a big problem, ie a network outage etc. The fact it is reprinting every single frame to the log following each connection fail (at 30s in the case) is way too much logging, Look at these 2 excerpts

2017-10-25 12:20:32,967 DEBUG    emoncmsorg 7 adding frame to buffer => [1508948104.9068, 8, 268.05240000000003, 270.1798, 151, 2, 121.9404224, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:20:32,968 DEBUG    emoncmsorg 8 adding frame to buffer => [1508948112.71224, 8, 272.3072, 263.79760000000005, 149, 2, 121.874336, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:20:32,970 DEBUG    emoncmsorg 9 adding frame to buffer => [1508948122.577907, 8, 268.05240000000003, 280.8168, 162, 2, 121.88535040000001, 300, 300, 300, 300, 300, 300, 0, -22]
2017-10-25 12:20:32,971 DEBUG    emoncmsorg 10 adding frame to buffer => [1508948132.495167, 8, 270.1798, 268.05240000000003, 152, 2, 121.874336, 300, 300, 300, 300, 300, 300, 0, -28]
2017-10-25 12:20:32,972 DEBUG    emoncmsorg 11 adding frame to buffer => [1508948142.394418, 8, 270.1798, 270.1798, 152, 2, 121.874336, 300, 300, 300, 300, 300, 300, 0, -28]
2017-10-25 12:20:32,974 DEBUG    emoncmsorg 12 adding frame to buffer => [1508948152.330079, 8, 270.1798, 268.05240000000003, 151, 2, 121.80824960000001, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:20:32,975 DEBUG    emoncmsorg 13 adding frame to buffer => [1508948162.218968, 8, 295.70860000000005, 268.05240000000003, 154, 2, 121.6760768, 300, 300, 300, 300, 300, 300, 0, -28]
2017-10-25 12:20:32,976 DEBUG    emoncmsorg 14 adding frame to buffer => [1508948172.110196, 8, 270.1798, 268.05240000000003, 152, 2, 121.7201344, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:20:32,978 DEBUG    emoncmsorg 15 adding frame to buffer => [1508948181.99857, 8, 278.68940000000003, 274.43460000000005, 153, 2, 121.68709120000001, 300, 300, 300, 300, 300, 300, 0, -28]
2017-10-25 12:20:32,979 DEBUG    emoncmsorg 16 adding frame to buffer => [1508948191.936033, 8, 268.05240000000003, 272.3072, 151, 2, 121.64303360000001, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:20:32,980 DEBUG    emoncmsorg 17 adding frame to buffer => [1508948201.870546, 8, 270.1798, 268.05240000000003, 153, 2, 121.66506240000001, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:20:32,981 DEBUG    emoncmsorg 18 adding frame to buffer => [1508948211.742361, 8, 270.1798, 274.43460000000005, 154, 2, 121.49984640000001, 300, 300, 300, 300, 300, 300, 0, -21]
2017-10-25 12:20:32,982 DEBUG    emoncmsorg 19 adding frame to buffer => [1508948221.640716, 8, 270.1798, 268.05240000000003, 153, 2, 121.49984640000001, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:20:32,984 DEBUG    emoncmsorg 20 adding frame to buffer => [1508948231.589884, 8, 272.3072, 268.05240000000003, 152, 2, 121.488832, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:20:32,985 DEBUG    emoncmsorg 21 adding frame to buffer => [1508948241.44829, 8, 268.05240000000003, 268.05240000000003, 152, 2, 121.4117312, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:20:32,986 DEBUG    emoncmsorg 22 adding frame to buffer => [1508948251.387498, 8, 270.1798, 272.3072, 154, 2, 121.47781760000001, 300, 300, 300, 300, 300, 300, 0, -28]
2017-10-25 12:20:32,987 DEBUG    emoncmsorg 23 adding frame to buffer => [1508948261.311877, 8, 270.1798, 270.1798, 152, 2, 121.2244864, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:20:32,989 DEBUG    emoncmsorg 24 adding frame to buffer => [1508948271.195006, 8, 268.05240000000003, 265.925, 152, 2, 121.2905728, 300, 300, 300, 300, 300, 300, 0, -28]
2017-10-25 12:20:32,990 DEBUG    emoncmsorg 25 adding frame to buffer => [1508948281.119016, 8, 265.925, 276.562, 153, 2, 121.268544, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:20:32,991 DEBUG    emoncmsorg 26 adding frame to buffer => [1508948291.016204, 8, 268.05240000000003, 272.3072, 153, 2, 121.4668032, 300, 300, 300, 300, 300, 300, 0, -28]
2017-10-25 12:20:32,993 DEBUG    emoncmsorg 27 adding frame to buffer => [1508948300.857662, 8, 280.8168, 272.3072, 151, 2, 121.40071680000001, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:20:32,994 DEBUG    emoncmsorg 28 adding frame to buffer => [1508948310.86893, 8, 268.05240000000003, 268.05240000000003, 152, 2, 121.323616, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:20:32,995 DEBUG    emoncmsorg 29 adding frame to buffer => [1508948320.761039, 8, 278.68940000000003, 270.1798, 152, 2, 121.31260160000001, 300, 300, 300, 300, 300, 300, 0, -28]
2017-10-25 12:20:32,997 DEBUG    emoncmsorg 30 adding frame to buffer => [1508948330.592253, 8, 268.05240000000003, 282.9442, 177, 2, 121.49984640000001, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:20:32,999 DEBUG    emoncmsorg 31 adding frame to buffer => [1508948340.500651, 8, 274.43460000000005, 270.1798, 151, 2, 121.25752960000001, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:20:33,000 DEBUG    emoncmsorg 32 adding frame to buffer => [1508948350.474229, 8, 268.05240000000003, 270.1798, 151, 2, 121.42274560000001, 300, 300, 300, 300, 300, 300, 0, -19]
2017-10-25 12:20:33,001 DEBUG    emoncmsorg 33 adding frame to buffer => [1508948360.309507, 8, 270.1798, 268.05240000000003, 152, 2, 121.21347200000001, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:20:33,003 DEBUG    emoncmsorg 34 adding frame to buffer => [1508948370.22416, 8, 272.3072, 268.05240000000003, 152, 2, 121.42274560000001, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:20:33,004 DEBUG    emoncmsorg 35 adding frame to buffer => [1508948380.120865, 8, 270.1798, 268.05240000000003, 151, 2, 121.45578880000001, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:20:33,005 DEBUG    emoncmsorg 36 adding frame to buffer => [1508948390.024671, 8, 272.3072, 272.3072, 151, 2, 121.59897600000001, 300, 300, 300, 300, 300, 300, 0, -28]
2017-10-25 12:20:33,006 DEBUG    emoncmsorg 37 adding frame to buffer => [1508948400.013285, 8, 270.1798, 268.05240000000003, 151, 2, 121.268544, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:20:33,008 DEBUG    emoncmsorg 38 adding frame to buffer => [1508948409.870501, 8, 287.199, 268.05240000000003, 152, 2, 121.323616, 300, 300, 300, 300, 300, 300, 0, -28]
2017-10-25 12:20:33,009 DEBUG    emoncmsorg 39 adding frame to buffer => [1508948419.792618, 8, 285.07160000000005, 265.925, 146, 2, 121.323616, 300, 300, 300, 300, 300, 300, 0, -28]
2017-10-25 12:20:33,010 DEBUG    emoncmsorg 40 adding frame to buffer => [1508948429.675722, 8, 282.9442, 270.1798, 152, 2, 121.1804288, 300, 300, 300, 300, 300, 300, 0, -22]
2017-10-25 12:20:33,011 DEBUG    emoncmsorg Sending bulkdata, length: 34
2017-10-25 12:20:33,012 DEBUG    emoncmsorg Sending bulkdata, success: False
2017-10-25 12:20:33,013 DEBUG    emoncmsorg New queue length: 34

2017-10-25 12:21:02,980 DEBUG    emoncmsorg 7 adding frame to buffer => [1508948104.9068, 8, 268.05240000000003, 270.1798, 151, 2, 121.9404224, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:21:02,982 DEBUG    emoncmsorg 8 adding frame to buffer => [1508948112.71224, 8, 272.3072, 263.79760000000005, 149, 2, 121.874336, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:21:02,983 DEBUG    emoncmsorg 9 adding frame to buffer => [1508948122.577907, 8, 268.05240000000003, 280.8168, 162, 2, 121.88535040000001, 300, 300, 300, 300, 300, 300, 0, -22]
2017-10-25 12:21:02,984 DEBUG    emoncmsorg 10 adding frame to buffer => [1508948132.495167, 8, 270.1798, 268.05240000000003, 152, 2, 121.874336, 300, 300, 300, 300, 300, 300, 0, -28]
2017-10-25 12:21:02,986 DEBUG    emoncmsorg 11 adding frame to buffer => [1508948142.394418, 8, 270.1798, 270.1798, 152, 2, 121.874336, 300, 300, 300, 300, 300, 300, 0, -28]
2017-10-25 12:21:02,987 DEBUG    emoncmsorg 12 adding frame to buffer => [1508948152.330079, 8, 270.1798, 268.05240000000003, 151, 2, 121.80824960000001, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:21:02,988 DEBUG    emoncmsorg 13 adding frame to buffer => [1508948162.218968, 8, 295.70860000000005, 268.05240000000003, 154, 2, 121.6760768, 300, 300, 300, 300, 300, 300, 0, -28]
2017-10-25 12:21:02,990 DEBUG    emoncmsorg 14 adding frame to buffer => [1508948172.110196, 8, 270.1798, 268.05240000000003, 152, 2, 121.7201344, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:21:02,991 DEBUG    emoncmsorg 15 adding frame to buffer => [1508948181.99857, 8, 278.68940000000003, 274.43460000000005, 153, 2, 121.68709120000001, 300, 300, 300, 300, 300, 300, 0, -28]
2017-10-25 12:21:02,992 DEBUG    emoncmsorg 16 adding frame to buffer => [1508948191.936033, 8, 268.05240000000003, 272.3072, 151, 2, 121.64303360000001, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:21:02,993 DEBUG    emoncmsorg 17 adding frame to buffer => [1508948201.870546, 8, 270.1798, 268.05240000000003, 153, 2, 121.66506240000001, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:21:02,995 DEBUG    emoncmsorg 18 adding frame to buffer => [1508948211.742361, 8, 270.1798, 274.43460000000005, 154, 2, 121.49984640000001, 300, 300, 300, 300, 300, 300, 0, -21]
2017-10-25 12:21:02,996 DEBUG    emoncmsorg 19 adding frame to buffer => [1508948221.640716, 8, 270.1798, 268.05240000000003, 153, 2, 121.49984640000001, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:21:02,997 DEBUG    emoncmsorg 20 adding frame to buffer => [1508948231.589884, 8, 272.3072, 268.05240000000003, 152, 2, 121.488832, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:21:02,999 DEBUG    emoncmsorg 21 adding frame to buffer => [1508948241.44829, 8, 268.05240000000003, 268.05240000000003, 152, 2, 121.4117312, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:21:03,000 DEBUG    emoncmsorg 22 adding frame to buffer => [1508948251.387498, 8, 270.1798, 272.3072, 154, 2, 121.47781760000001, 300, 300, 300, 300, 300, 300, 0, -28]
2017-10-25 12:21:03,001 DEBUG    emoncmsorg 23 adding frame to buffer => [1508948261.311877, 8, 270.1798, 270.1798, 152, 2, 121.2244864, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:21:03,002 DEBUG    emoncmsorg 24 adding frame to buffer => [1508948271.195006, 8, 268.05240000000003, 265.925, 152, 2, 121.2905728, 300, 300, 300, 300, 300, 300, 0, -28]
2017-10-25 12:21:03,004 DEBUG    emoncmsorg 25 adding frame to buffer => [1508948281.119016, 8, 265.925, 276.562, 153, 2, 121.268544, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:21:03,005 DEBUG    emoncmsorg 26 adding frame to buffer => [1508948291.016204, 8, 268.05240000000003, 272.3072, 153, 2, 121.4668032, 300, 300, 300, 300, 300, 300, 0, -28]
2017-10-25 12:21:03,007 DEBUG    emoncmsorg 27 adding frame to buffer => [1508948300.857662, 8, 280.8168, 272.3072, 151, 2, 121.40071680000001, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:21:03,009 DEBUG    emoncmsorg 28 adding frame to buffer => [1508948310.86893, 8, 268.05240000000003, 268.05240000000003, 152, 2, 121.323616, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:21:03,011 DEBUG    emoncmsorg 29 adding frame to buffer => [1508948320.761039, 8, 278.68940000000003, 270.1798, 152, 2, 121.31260160000001, 300, 300, 300, 300, 300, 300, 0, -28]
2017-10-25 12:21:03,012 DEBUG    emoncmsorg 30 adding frame to buffer => [1508948330.592253, 8, 268.05240000000003, 282.9442, 177, 2, 121.49984640000001, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:21:03,014 DEBUG    emoncmsorg 31 adding frame to buffer => [1508948340.500651, 8, 274.43460000000005, 270.1798, 151, 2, 121.25752960000001, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:21:03,015 DEBUG    emoncmsorg 32 adding frame to buffer => [1508948350.474229, 8, 268.05240000000003, 270.1798, 151, 2, 121.42274560000001, 300, 300, 300, 300, 300, 300, 0, -19]
2017-10-25 12:21:03,016 DEBUG    emoncmsorg 33 adding frame to buffer => [1508948360.309507, 8, 270.1798, 268.05240000000003, 152, 2, 121.21347200000001, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:21:03,018 DEBUG    emoncmsorg 34 adding frame to buffer => [1508948370.22416, 8, 272.3072, 268.05240000000003, 152, 2, 121.42274560000001, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:21:03,019 DEBUG    emoncmsorg 35 adding frame to buffer => [1508948380.120865, 8, 270.1798, 268.05240000000003, 151, 2, 121.45578880000001, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:21:03,020 DEBUG    emoncmsorg 36 adding frame to buffer => [1508948390.024671, 8, 272.3072, 272.3072, 151, 2, 121.59897600000001, 300, 300, 300, 300, 300, 300, 0, -28]
2017-10-25 12:21:03,021 DEBUG    emoncmsorg 37 adding frame to buffer => [1508948400.013285, 8, 270.1798, 268.05240000000003, 151, 2, 121.268544, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:21:03,023 DEBUG    emoncmsorg 38 adding frame to buffer => [1508948409.870501, 8, 287.199, 268.05240000000003, 152, 2, 121.323616, 300, 300, 300, 300, 300, 300, 0, -28]
2017-10-25 12:21:03,024 DEBUG    emoncmsorg 39 adding frame to buffer => [1508948419.792618, 8, 285.07160000000005, 265.925, 146, 2, 121.323616, 300, 300, 300, 300, 300, 300, 0, -28]
2017-10-25 12:21:03,025 DEBUG    emoncmsorg 40 adding frame to buffer => [1508948429.675722, 8, 282.9442, 270.1798, 152, 2, 121.1804288, 300, 300, 300, 300, 300, 300, 0, -22]
2017-10-25 12:21:03,026 DEBUG    emoncmsorg 41 adding frame to buffer => [1508948439.626809, 8, 270.1798, 270.1798, 151, 2, 121.1584, 300, 300, 300, 300, 300, 300, 0, -28]
2017-10-25 12:21:03,028 DEBUG    emoncmsorg 42 adding frame to buffer => [1508948449.449423, 8, 268.05240000000003, 268.05240000000003, 151, 2, 121.1804288, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:21:03,029 DEBUG    emoncmsorg 43 adding frame to buffer => [1508948459.431012, 8, 265.925, 268.05240000000003, 150, 2, 121.1804288, 300, 300, 300, 300, 300, 300, 0, -27]
2017-10-25 12:21:03,030 DEBUG    emoncmsorg Sending bulkdata, length: 37
2017-10-25 12:21:03,031 DEBUG    emoncmsorg Sending bulkdata, success: False
2017-10-25 12:21:03,032 DEBUG    emoncmsorg New queue length: 37

They are just 30secs apart and the queue has correctly increased by another 3 frames, but it is reprinting the whole buffer to the log every 30secs, to reach 9000 frames in the buffer it will have retried sending 3000 times and over that time it will have printed well over 13.5 MILLION “adding frame to buffer” lines which doesn’t include the 3000x3 sending and buffer status logs.

As for the cause (or logging) of the sending of data, the logs previously showed the make up of the url and the response received, none of that data seems to be printed to the log anymore [edit - Ok I see the code is still there it’s just not being used in this instance] so we cannot tell what happened. I also notice there is only 1uSec between sending and the “success false” message so are we sure a send was even attempted?

Aside from the over logging issue and the messages saying “sending” when it isn’t sending, this also raises 2 more important points. I cannot see any form of size restriction on the buffer, so in theory an unused emoncmsorg interfacer could grow it’s buffer in ram unrestricted until it effects performance or chokes. Also when a network comes on line after a prolonged outage how will emoncms.org cope with an unlimited number of frames arriving in one request? If the request is attempted but timeout reached before all packets are processed would that mean the data can never get uploaded?

Originally emonhub had a setting for the max number of frames and when the limit was reached it would delete the oldest to make room for the newest. I also had settings for the max number of frames that could be included in any one request so that emoncms.org didn’t get battered.

13

My idea is to get my system producing accurate and correct data before sending anything to emoncms.org. Thus I have tried to set emonhub.conf to only post on localhost. When I set senddata = 0 and sendstatus = 0, I get nothing posted on localhost. It seems to work the way I want when these parameters are set to “1”.
emonhub_conf.txt (7.5 KB)

As you can tell, I’m in the early stages of learning how all of this works. Any suggestions on my emonhub.conf (attached again) settings would be appreciated. Thanks for your help so far.
Bob

14

According to @pb66, senddata doesn’t do what you’d expect it to do; the way to stop it sending is to comment out the whole [[emoncmsorg]] section, or less intuitively, just comment out the section heading
[[emoncmsorg]]

15

Pretty much, but for the sake of accuracy, the way the senddata switch works seems to block data going into the interfacer (therefore it cannot send it so it’s sorta right) but it doesn’t stop the data being queued up for the interfacer not to send.

The way emonhub should be used is that the conf file only contains the stuff you actually want so deleting it is even better if you have no plans to use it, ever.

Almost, that would actually cause an error when loading the conf, I think what you are referring to is commenting out the Type= line, that will cause the interfacer to silently not be created, it is the best method to disable and enable interfacers, but yes not at all intuitive, it was more of a backdoor tool for quickly testing the creation and deletion of interfacers during development that works well and does no harm to stay in.

16

fair point, perhaps making this log entry info level would be better? or not logging the adding of the frame to the buffer, im not sure that its that useful anyway, certainly debug level is problematic given that its default on most systems, do you have any preferences?

Aha, yes thats all still in there I did not remove it, which indicates that what is actually happening is that its returning at this point

I can now see the issue!! for users who are not sending data to a remote server emonhub will buffer data indefinitely (if senddata is set to 1).

An attempt to send data at this point will return false where apikey is not set here but this is treated in the same way as a failed tx of data here.

I will look into a fix for this problem.

1 Like
17

The reason for the configuration options senddata and sendstatus is that the emoncms interfacer is used for two purposes:

  1. To send data to emoncms.org
  2. To send a periodic ping message to emoncms.org for use with the myip module which allows users to see the remote IP address of their emonpi’s if configured for remote access with port forwarding etc. (Accessible via emoncms > Extras > MyIP)

setting senddata = 0 and sendstatus = 1 allows for logging of ip address without sending data to emoncms.org.

18

Sorry setting the logging to info wont help of course as info messages are still logged when debug level is set

I’ve got a preliminary fix for the issue above so far that stops the creation of the buffered data array when the apikey is not set but items are still added to the queue which Im still working on https://github.com/openenergymonitor/emonhub/compare/emon-pi...openenergymonitor:fix-emoncmsorg-buffering?expand=1

19

It is useful when the data isn’t being sent as it’s the only record that something happened with the data. The one log message could also include a total buffer size to reduce the number of separate entries.

The problem lies with the interfacer working directly on the data in the queue so each failed send results in every queued frame being added to the buffer again. All the queue’s should, on a healthy system be at or close to zero most of the time. The data must be consumed by the interfacer, either sent, buffered (elsewhere) or discarded.

Yep, that is a big potential issue, I think the code should be written in a way to ensure the queues cannot grow and as a safety thing we add an overall max size based predominantly on how big we could go without breaking the system or loosing performance and then introduce a very low warning level so that even the lightest backup in the queues will result in a warning level log, but there is still plenty of headroom. These are just safety nets though, the intention must be to aim for near zero queue lengths.

20

If I’m following correctly, the easiest fix for me is to comment out the complete section of [[emoncmsorg]]. By doing this, the DEBUG logging quieted down quite a bit and, every 10 seconds, the INFO level gives me this:

2017-10-26 16:51:51,185 INFO MQTT Publishing: emon/emontx3/rssi -27
2017-10-26 16:51:51,187 INFO MQTT Publishing: emonhub/rx/8/values 525.8496,562.1888,154,2,121.7311488,300,300,300,300,300,300,0
2017-10-26 16:51:51,189 INFO MQTT Publishing: emonhub/rx/8/rssi -27

I’ll see if things are more stable from this point. Much appreciated to everyone for the help.
Bob

1 Like