Emonpi stops recording inputs/feeds after about 36 hours

PerigVennetier · 2016-10-03T17:10:26.612Z

Hi,

I have an emonPi with latest firmware. I modified the config file to measure the power and Vref of an appliance in the USA. I may also have changed the TIME_BETWEEN_READINGS to 500 in the firmware.ino file to be able to sample more often (too many data points? Where are these stored?).

It all works great except that it seems that the system stops updating inputs and feeds after about 36 hours (not sure on the timing) in the local emoncms [http://emonpi/emoncms/] when I let it run for several days.

I still have access to the local emoncms pages and I can still connect to the pi but the inputs and feeds are not updated.

Is there any log file I could share here to try to find out what is happening?

Thanks.

PS: I had to install phpmyadmin manually to solve a feed issue (here). I mention it if that could be an issue.

PPS: here is screen capture of the inputs page:

Emoncms input view.png1079×538 26.8 KB

And the feeds page:

Emoncms feed list.png1099×191 11.3 KB

PerigVennetier · 2016-10-19T20:10:52.278Z

Anybody would have suggestions on steps I can take to help me find out what is going on here?

Thanks.

Jon · 2016-10-20T03:51:21.139Z

Perig - I’m not an expert and cannot comment on the items in your first paragraph.

Here is the log file I would suggest - /var/log/emonhub/emonhub.log. You may want to post the emonhub.log file here as a TEXT attachment (emonhub.log.txt).

Here is what I see in my emonhub.log file:

2016-10-19 22:45:55,465 DEBUG    RFM2Pi     21751 NEW FRAME : OK 5 184 1 231 0 159 2 30 48 0 0 0 0 0 0 0 0 0 0 0 0 221 65 0 0 (-0)
2016-10-19 22:45:55,468 DEBUG    RFM2Pi     21751 Timestamp : 1476935155.47
2016-10-19 22:45:55,468 DEBUG    RFM2Pi     21751 From Node : 5
2016-10-19 22:45:55,469 DEBUG    RFM2Pi     21751    Values : [440, 231, 671, 123.18, 0, 0, 0, 0, 0, 0, 16861]
2016-10-19 22:45:55,470 INFO     RFM2Pi     Publishing: emon/emonpi/power1 440
2016-10-19 22:45:55,471 INFO     RFM2Pi     Publishing: emon/emonpi/power2 231
2016-10-19 22:45:55,473 INFO     RFM2Pi     Publishing: emon/emonpi/power1pluspower2 671
2016-10-19 22:45:55,474 INFO     RFM2Pi     Publishing: emon/emonpi/vrms 123.18
2016-10-19 22:45:55,475 INFO     RFM2Pi     Publishing: emon/emonpi/t1 0
2016-10-19 22:45:55,476 INFO     RFM2Pi     Publishing: emon/emonpi/t2 0
2016-10-19 22:45:55,477 INFO     RFM2Pi     Publishing: emon/emonpi/t3 0
2016-10-19 22:45:55,479 INFO     RFM2Pi     Publishing: emon/emonpi/t4 0
2016-10-19 22:45:55,480 INFO     RFM2Pi     Publishing: emon/emonpi/t5 0
2016-10-19 22:45:55,481 INFO     RFM2Pi     Publishing: emon/emonpi/t6 0
2016-10-19 22:45:55,482 INFO     RFM2Pi     Publishing: emon/emonpi/pulsecount 16861
2016-10-19 22:45:55,483 INFO     RFM2Pi     Publishing: emon/emonpi/rssi 0
2016-10-19 22:45:55,485 INFO     RFM2Pi     Publishing: emonhub/rx/5/values 440,231,671,123.18,0,0,0,0,0,0,16861
2016-10-19 22:45:55,486 INFO     RFM2Pi     Publishing: emonhub/rx/5/rssi 0
2016-10-19 22:45:55,487 DEBUG    RFM2Pi     21751 adding frame to buffer => [1476935155, 5, 440, 231, 671, 123.18, 0, 0, 0, 0, 0, 0, 16861]
2016-10-19 22:45:55,488 DEBUG    RFM2Pi     21751 Sent to channel' : ToEmonCMS

EDIT: the above will update every 5 seconds.

PerigVennetier · 2016-10-20T16:56:04.558Z

OK thanks, I will make sure to post the log next time when the issue occurs.

PerigVennetier · 2016-10-25T17:21:33.183Z

So the issue came up again. Feeds and inputs stopped recording 3 days ago. I was not able to catch it when it stopped working. I will try to restart it and catch it faster when the issue comes up.

Note that I also pull data constantly (every 1 second) by reading the feeds via the API from an external application.

Emoncms feed list - ERROR 3.6days.png902×250 14.4 KB

Emoncms input view - ERROR 3.6days.png887×546 26.3 KB

In the meantime, the /var/log/emonhub/emonhub.log content is tens of thousands of lines as follows:

2016-10-25 16:17:02,125 WARNING  MainThread RFM2Pi thread is dead
2016-10-25 16:17:02,126 WARNING  MainThread MQTT thread is dead
2016-10-25 16:17:02,377 WARNING  MainThread RFM2Pi thread is dead
2016-10-25 16:17:02,379 WARNING  MainThread MQTT thread is dead
2016-10-25 16:17:02,614 WARNING  MainThread RFM2Pi thread is dead
2016-10-25 16:17:02,615 WARNING  MainThread MQTT thread is dead
2016-10-25 16:17:02,851 WARNING  MainThread RFM2Pi thread is dead
2016-10-25 16:17:02,852 WARNING  MainThread MQTT thread is dead
2016-10-25 16:17:03,088 WARNING  MainThread RFM2Pi thread is dead
2016-10-25 16:17:03,089 WARNING  MainThread MQTT thread is dead
2016-10-25 16:17:03,313 WARNING  MainThread RFM2Pi thread is dead
2016-10-25 16:17:03,314 WARNING  MainThread MQTT thread is dead

Could it be a problem similar to this thread.

I followed the thread around and reading this thread I tried a soft reboot. I did a ‘sudo reboot’ and it recovered. The inputs and feeds are now recording again. Any idea where the issue could be coming from to fix it?

Here is the log after reboot:

2016-10-25 17:10:53,818 INFO     MainThread EmonHub emonHub 'emon-pi' variant v1.1
2016-10-25 17:10:53,819 INFO     MainThread Opening hub...
2016-10-25 17:10:53,821 INFO     MainThread Logging level set to DEBUG
2016-10-25 17:10:53,823 INFO     MainThread Creating EmonHubJeeInterfacer 'RFM2Pi' 
2016-10-25 17:10:53,830 DEBUG    MainThread Opening serial port: /dev/ttyAMA0 @ 38400 bits/s
2016-10-25 17:10:55,835 WARNING  MainThread Device communication error - check settings
2016-10-25 17:10:55,837 INFO     MainThread Setting RFM2Pi frequency: 433 (4b)
2016-10-25 17:10:56,840 INFO     MainThread Setting RFM2Pi group: 210 (210g)
2016-10-25 17:10:57,842 INFO     MainThread Setting RFM2Pi quiet: 0 (0q)
2016-10-25 17:10:58,844 INFO     MainThread Setting RFM2Pi baseid: 5 (5i)
2016-10-25 17:10:59,847 INFO     MainThread Setting RFM2Pi calibration: 110V (2p)
2016-10-25 17:11:00,850 DEBUG    MainThread Setting RFM2Pi subchannels: ['ToRFM12']
2016-10-25 17:11:00,853 DEBUG    MainThread Interfacer: Subscribed to channel' : ToRFM12
2016-10-25 17:11:00,855 DEBUG    MainThread Setting RFM2Pi pubchannels: ['ToEmonCMS']
2016-10-25 17:11:00,856 DEBUG    MainThread Interfacer: Subscribed to channel' : ToRFM12
2016-10-25 17:11:00,860 INFO     MainThread Creating EmonHubMqttInterfacer 'MQTT' 
2016-10-25 17:11:00,862 INFO     MainThread MQTT Init mqtt_host=127.0.0.1 mqtt_port=1883 mqtt_user=emonpi
2016-10-25 17:11:00,888 DEBUG    RFM2Pi     1 NEW FRAME : OK 5 242 0 0 0 242 0 16 44 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 (-0)
2016-10-25 17:11:00,892 DEBUG    RFM2Pi     1 Timestamp : 1477415460.89
2016-10-25 17:11:00,893 DEBUG    RFM2Pi     1 From Node : 5
2016-10-25 17:11:00,908 DEBUG    MainThread MQTT Subscribed to channel' : ToEmonCMS
2016-10-25 17:11:00,911 DEBUG    RFM2Pi     1    Values : [242, 0, 242, 11280, 0, 0, 0, 0, 0, 0, 0, 0]
2016-10-25 17:11:00,922 DEBUG    RFM2Pi     1 Sent to channel' : ToEmonCMS
2016-10-25 17:11:00,926 INFO     MainThread Creating EmonHubEmoncmsHTTPInterfacer 'emoncmsorg' 
2016-10-25 17:11:00,930 DEBUG    MainThread emoncmsorg Subscribed to channel' : ToEmonCMS
2016-10-25 17:11:01,025 INFO     MQTT       Connecting to MQTT Server
2016-10-25 17:11:01,040 DEBUG    RFM2Pi     device settings updated: E i5 g211 @ 433 MHz USA 1
2016-10-25 17:11:01,146 DEBUG    RFM2Pi     device settings updated: [emonPi.2.60] E i5 g211 @ 433 MHz USA 1
2016-10-25 17:11:01,148 INFO     MQTT       Connecting to MQTT Server
2016-10-25 17:11:01,159 INFO     MQTT       connection status: Connection successful
2016-10-25 17:11:01,162 DEBUG    MQTT       CONACK => Return code: 0
2016-10-25 17:11:01,255 DEBUG    RFM2Pi     2 NEW FRAME : OK 5 243 0 0 0 243 0 51 44 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 (-0)
2016-10-25 17:11:01,292 INFO     MQTT       on_subscribe
2016-10-25 17:11:01,367 DEBUG    RFM2Pi     2 Timestamp : 1477415461.25
2016-10-25 17:11:01,369 DEBUG    RFM2Pi     2 From Node : 5
2016-10-25 17:11:01,371 DEBUG    RFM2Pi     2    Values : [243, 0, 243, 113.15, 0, 0, 0, 0, 0, 0, 0]
2016-10-25 17:11:01,373 INFO     RFM2Pi     Publishing: emon/emonpi/power1 243
2016-10-25 17:11:01,382 INFO     RFM2Pi     Publishing: emon/emonpi/power2 0
2016-10-25 17:11:01,386 INFO     RFM2Pi     Publishing: emon/emonpi/power1pluspower2 243
2016-10-25 17:11:01,389 INFO     RFM2Pi     Publishing: emon/emonpi/vrms 113.15
2016-10-25 17:11:01,393 INFO     RFM2Pi     Publishing: emon/emonpi/t1 0
2016-10-25 17:11:01,409 INFO     RFM2Pi     Publishing: emon/emonpi/t2 0
2016-10-25 17:11:01,412 INFO     RFM2Pi     Publishing: emon/emonpi/t3 0
2016-10-25 17:11:01,416 INFO     RFM2Pi     Publishing: emon/emonpi/t4 0
2016-10-25 17:11:01,419 INFO     RFM2Pi     Publishing: emon/emonpi/t5 0
2016-10-25 17:11:01,422 INFO     RFM2Pi     Publishing: emon/emonpi/t6 0
2016-10-25 17:11:01,425 INFO     RFM2Pi     Publishing: emon/emonpi/pulsecount 0
2016-10-25 17:11:01,428 INFO     RFM2Pi     Publishing: emon/emonpi/rssi 0
2016-10-25 17:11:01,430 INFO     RFM2Pi     Publishing: emonhub/rx/5/values 243,0,243,113.15,0,0,0,0,0,0,0
2016-10-25 17:11:01,433 INFO     RFM2Pi     Publishing: emonhub/rx/5/rssi 0
2016-10-25 17:11:01,436 DEBUG    RFM2Pi     2 adding frame to buffer => [1477415461, 5, 243, 0, 243, 113.15, 0, 0, 0, 0, 0, 0, 0]
2016-10-25 17:11:01,438 DEBUG    RFM2Pi     2 Sent to channel' : ToEmonCMS
2016-10-25 17:11:01,547 DEBUG    RFM2Pi     device settings updated: E i5 g211 @ 433 MHz USA 1
2016-10-25 17:11:01,702 DEBUG    RFM2Pi     3 NEW FRAME : OK 5 244 0 0 0 244 0 50 44 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 (-0)
2016-10-25 17:11:01,715 DEBUG    RFM2Pi     3 Timestamp : 1477415461.7
2016-10-25 17:11:01,717 DEBUG    RFM2Pi     3 From Node : 5
2016-10-25 17:11:01,718 DEBUG    RFM2Pi     3    Values : [244, 0, 244, 113.14, 0, 0, 0, 0, 0, 0, 0]
2016-10-25 17:11:01,721 INFO     RFM2Pi     Publishing: emon/emonpi/power1 244
2016-10-25 17:11:01,725 INFO     RFM2Pi     Publishing: emon/emonpi/power2 0
2016-10-25 17:11:01,729 INFO     RFM2Pi     Publishing: emon/emonpi/power1pluspower2 244
2016-10-25 17:11:01,733 INFO     RFM2Pi     Publishing: emon/emonpi/vrms 113.14
2016-10-25 17:11:01,740 INFO     RFM2Pi     Publishing: emon/emonpi/t1 0
2016-10-25 17:11:01,755 INFO     RFM2Pi     Publishing: emon/emonpi/t2 0
2016-10-25 17:11:01,775 INFO     RFM2Pi     Publishing: emon/emonpi/t3 0
2016-10-25 17:11:01,782 INFO     RFM2Pi     Publishing: emon/emonpi/t4 0
2016-10-25 17:11:01,788 INFO     RFM2Pi     Publishing: emon/emonpi/t5 0
2016-10-25 17:11:01,793 INFO     RFM2Pi     Publishing: emon/emonpi/t6 0
2016-10-25 17:11:01,802 INFO     RFM2Pi     Publishing: emon/emonpi/pulsecount 0
2016-10-25 17:11:01,812 INFO     RFM2Pi     Publishing: emon/emonpi/rssi 0
2016-10-25 17:11:01,816 INFO     RFM2Pi     Publishing: emonhub/rx/5/values 244,0,244,113.14,0,0,0,0,0,0,0
2016-10-25 17:11:01,820 INFO     RFM2Pi     Publishing: emonhub/rx/5/rssi 0
2016-10-25 17:11:01,827 DEBUG    RFM2Pi     3 adding frame to buffer => [1477415461, 5, 244, 0, 244, 113.14, 0, 0, 0, 0, 0, 0, 0]

Jon · 2016-10-25T17:28:40.258Z

PerigVennetier:

Note that I also pull data constantly (every 1 second) by reading the feeds via the API from an external application.

Can you post this command (delete your API KEY)?

PerigVennetier · 2016-10-25T17:40:41.852Z

Here are the two commands I run to pull both feeds:

http://emonpi/emoncms/feed/aget.json?id=3&apikey=

http://emonpi/emoncms/feed/aget.json?id=6&apikey=

My code block in c# to get the full set of data is as follow:

Uri uri = new Uri("http://emonpi/emoncms/feed/aget.json?id=3&apikey=XXXXXXXX");
HttpWebRequest request = (HttpWebRequest)HttpWebRequest.Create(uri);
request.Method = WebRequestMethods.Http.Get;
HttpWebResponse response = (HttpWebResponse)request.GetResponse();
StreamReader reader = new StreamReader(response.GetResponseStream());
string output = reader.ReadToEnd();
response.Close();
dynamic dataArray = JsonConvert.DeserializeObject(output);
tmpData.watts = dataArray.value;

Jon · 2016-10-25T17:47:54.534Z

So there is another device on your local network that grabs data from your emonPi every one second?

To me that seems too often (too fast) since the emonPi feeds update every 5 seconds. Can your c# code be turned off for a few days to determine if that is the issue?

PerigVennetier · 2016-10-25T18:04:19.921Z

I can definitely turn it off for a while.

I set the data to be refreshed in the .ino firware every 500ms and it seems to be returning the data OK. But maybe it get the system stuck after a while.

I’ll let it run like this without the c# data pull first and see what happens.

I can then test by reverting the data refresh rate in the .ino firmware to the default 5000ms and run another test.

Jon · 2016-10-25T18:41:46.584Z

PerigVennetier:

I set the data to be refreshed in the .ino firware every 500ms and it seems to be returning the data OK. But maybe it get the system stuck after a while.

Can you post this code also? I am guessing this is the issue.

PerigVennetier · 2016-10-25T18:50:49.052Z

It’s one line in the firmware.ino file:

const int TIME_BETWEEN_READINGS=  500;

Original was

const int TIME_BETWEEN_READINGS=  5000;

Jon · 2016-10-25T19:01:24.666Z

PerigVennetier:

I can then test by reverting the data refresh rate in the .ino firmware to the default 5000ms and run another test.

This sounds like an excellent idea.

You’ll need to ask one of the emonPi experts for their option on how fast this can be refreshed. I am guessing 500ms is way too fast.

PerigVennetier · 2016-10-25T19:09:49.244Z

Well, let’s see if someone chimes in here.

I get the data OK from the API every 1000ms for several days but it hangs at some point so I may be borderline on the timing if that is the issue.

Let’s see what the tests tell us.

pb66 · 2016-10-25T22:09:59.713Z

While it’s true to say if you run something harder or faster it is more likely to break, and the speed you are running may strain or be indirectly responsible for the frequency of the fails. What you are seeing there has been reported before and as far as I know, not been diagnosed.

Search for “thread is dead” on the old forum and you will find a few references to it.

@Jon - although yours isn’t failing it is also faulty. Look at that centre column that reports the thread name, why is the RFM2Pi interfacer apparently publishing to MQTT? that should be the MQTT thread. Could you try restarting emonhub (sudo service emonhub restart) and recheck the log, see if it is correct from boot?

Jon · 2016-10-25T23:31:25.051Z

2 posts were split to a new topic: RFM2Pi interfacer apparently publishing to MQTT?

PerigVennetier · 2016-10-27T15:57:48.554Z

OK, so the system crashed without me using it, when it was idle with no API requests.

I will revert the time between readings to 5000ms and let it run for a few days to see if it crashes again.