It’s worth a great deal, thank you. what we normally get to see here on the forums is just a long
2017-05-02 15:56:37,030 WARNING MainThread RFM2Pi thread is dead
2017-05-02 15:56:37,031 WARNING MainThread MQTT thread is dead
2017-05-02 15:56:37,232 WARNING MainThread RFM2Pi thread is dead
2017-05-02 15:56:37,232 WARNING MainThread MQTT thread is dead
so thank you for taking the time to hunt out the point it crashed.
I have been looking at your log and not yet found any specific reason for the crash such as a malformed packet etc.
Can you tell us a bit more about your system?
What is node 8?
Is it really sending packets over the RFM network at a rate of 1 or more per second?
What else is on the network?
What is the “pulsecount” at the end of node 8? is it just a coincidence it increments by 1 per payload or is it a transmission counter?
I am heading out now for the evening so I will post some inconclusive notes I’ve made on here for now and hopefully comeback to it over the weekend.
2017-05-02 15:56:33,715 DEBUG RFM2Pi 287873 adding frame to buffer => [1493740593.691949, 5, 0, 0, 0, 233.86, 0, 0, 0, 0, 0, 0, 0]
2017-05-02 15:56:33,716 DEBUG RFM2Pi 287873 Sent to channel(end)' : ToEmonCMS
# FRAME 287874 gets passed succesfully
2017-05-02 15:56:33,829 DEBUG RFM2Pi 287874 NEW FRAME : OK 8 245 24 41 12 0 0 0 0 142 1 184 11 184 11 184 11 184 11 184 11 184 11 232 101 36 0 (-46)
2017-05-02 15:56:33,833 DEBUG RFM2Pi 287874 Timestamp : 1493740593.83
2017-05-02 15:56:33,839 DEBUG RFM2Pi 287874 From Node : 8
2017-05-02 15:56:33,842 DEBUG RFM2Pi 287874 Values : [6389, 3113, 0, 0, 3.98, 300, 300, 300, 300, 300, 300, 2385384]
2017-05-02 15:56:33,843 DEBUG RFM2Pi 287874 RSSI : -46
2017-05-02 15:56:33,846 DEBUG RFM2Pi 287874 Sent to channel(start)' : ToEmonCMS
2017-05-02 15:56:33,848 INFO RFM2Pi Publishing: emon/emontx3/power1 6389
# this is the relative point at which the next frame processed trips up.
2017-05-02 15:56:33,850 INFO RFM2Pi Publishing: emon/emontx3/power2 3113
2017-05-02 15:56:33,851 INFO RFM2Pi Publishing: emon/emontx3/power3 0
2017-05-02 15:56:33,853 INFO RFM2Pi Publishing: emon/emontx3/power4 0
2017-05-02 15:56:33,854 INFO RFM2Pi Publishing: emon/emontx3/vrms 3.98
2017-05-02 15:56:33,856 INFO RFM2Pi Publishing: emon/emontx3/temp1 300
2017-05-02 15:56:33,858 INFO RFM2Pi Publishing: emon/emontx3/temp2 300
2017-05-02 15:56:33,859 INFO RFM2Pi Publishing: emon/emontx3/temp3 300
2017-05-02 15:56:33,860 INFO RFM2Pi Publishing: emon/emontx3/temp4 300
2017-05-02 15:56:33,862 INFO RFM2Pi Publishing: emon/emontx3/temp5 300
2017-05-02 15:56:33,863 INFO RFM2Pi Publishing: emon/emontx3/temp6 300
2017-05-02 15:56:33,865 INFO RFM2Pi Publishing: emon/emontx3/pulse 2385384
2017-05-02 15:56:33,866 INFO RFM2Pi Publishing: emon/emontx3/rssi -46
2017-05-02 15:56:33,868 INFO RFM2Pi Publishing: emonhub/rx/8/values 6389,3113,0,0,3.98,300,300,300,300,300,300,2385384
2017-05-02 15:56:33,869 INFO RFM2Pi Publishing: emonhub/rx/8/rssi -46
2017-05-02 15:56:33,871 DEBUG RFM2Pi 287874 adding frame to buffer => [1493740593.82888, 8, 6389, 3113, 0, 0, 3.98, 300, 300, 300, 300, 300, 300, 2385384, -46]
2017-05-02 15:56:33,872 DEBUG RFM2Pi 287874 Sent to channel(end)' : ToEmonCMS
2017-05-02 15:56:34,278 DEBUG RFM2Pi Discarding RX frame 'unreliable content'? 16 0 0 0 0 0 0 32 0 0 0 0 32 4 144 102 0 128 0 0 0 (-104)
# only 0.656 seconds later than FRAME 287874, this frame appears to have nothing wrong with it but JeeLib says it failed the CRC check
2017-05-02 15:56:34,485 DEBUG RFM2Pi Discarding RX frame 'unreliable content'? 8 255 24 12 0 0 0 0 135 1 184 11 184 11 184 11 184 11 184 11 184 (-44)
# FRAME 287875 1.111 seconds after dropped packet
2017-05-02 15:56:35,596 DEBUG RFM2Pi 287875 NEW FRAME : OK 8 252 24 30 12 0 0 0 0 141 1 184 11 184 11 184 11 184 11 184 11 184 11 234 101 36 0 (-45)
2017-05-02 15:56:35,599 DEBUG RFM2Pi 287875 Timestamp : 1493740595.6
2017-05-02 15:56:35,599 DEBUG RFM2Pi 287875 From Node : 8
2017-05-02 15:56:35,600 DEBUG RFM2Pi 287875 Values : [6396, 3102, 0, 0, 3.97, 300, 300, 300, 300, 300, 300, 2385386]
2017-05-02 15:56:35,600 DEBUG RFM2Pi 287875 RSSI : -45
2017-05-02 15:56:35,601 DEBUG RFM2Pi 287875 Sent to channel(start)' : ToEmonCMS
2017-05-02 15:56:35,602 INFO RFM2Pi Publishing: emon/emontx3/power1 6396
# 0.166 seconds later it crashes, the next iteration of the publish loop is usually only 0.002 Seconds later so should have happened comfortably in this time
2017-05-02 15:56:35,768 WARNING MainThread RFM2Pi thread is dead
2017-05-02 15:56:35,994 WARNING MainThread RFM2Pi thread is dead
2017-05-02 15:56:35,995 WARNING MainThread MQTT thread is dead
2017-05-02 15:56:36,196 WARNING MainThread RFM2Pi thread is dead
2017-05-02 15:56:36,197 WARNING MainThread MQTT thread is dead
2017-05-02 15:56:36,397 WARNING MainThread RFM2Pi thread is dead
2017-05-02 15:56:36,398 WARNING MainThread MQTT thread is dead
2017-05-02 15:56:36,599 WARNING MainThread RFM2Pi thread is dead
2017-05-02 15:56:36,600 WARNING MainThread MQTT thread is dead
2017-05-02 15:56:36,801 WARNING MainThread RFM2Pi thread is dead
2017-05-02 15:56:36,802 WARNING MainThread MQTT thread is dead
2017-05-02 15:56:37,030 WARNING MainThread RFM2Pi thread is dead
2017-05-02 15:56:37,031 WARNING MainThread MQTT thread is dead
2017-05-02 15:56:37,232 WARNING MainThread RFM2Pi thread is dead
2017-05-02 15:56:37,232 WARNING MainThread MQTT thread is dead
2017-05-02 15:56:37,433 WARNING MainThread RFM2Pi thread is dead
2017-05-02 15:56:37,434 WARNING MainThread MQTT thread is dead
2017-05-02 15:56:37,635 WARNING MainThread RFM2Pi thread is dead
2017-05-02 15:56:37,636 WARNING MainThread MQTT thread is dead
2017-05-02 15:56:37,837 WARNING MainThread RFM2Pi thread is dead
2017-05-02 15:56:37,838 WARNING MainThread MQTT thread is dead
2017-05-02 15:56:38,064 WARNING MainThread RFM2Pi thread is dead
2017-05-02 15:56:38,064 WARNING MainThread MQTT thread is dead
2017-05-02 15:56:38,265 WARNING MainThread RFM2Pi thread is dead
It is in this loop when it stops
It prints the log for the first value of the payload (on line 125) and fails to reach the same point for the second value.
varid = 1
for value in cargo.realdata:
# Variable id or variable name if given
varstr = str(varid)
if (varid-1)<len(cargo.names):
varstr = str(cargo.names[varid-1])
# Construct topic
topic = self._settings["nodevar_format_basetopic"]+nodestr+"/"+varstr
payload = str(value)
# SUCCESSFULLY GETS HERE FOR FIRST VALUE IN FRAME 287875 - BUT FAILS TO REACH HERE FORE THE SECOND VALUE.
self._log.info("Publishing: "+topic+" "+payload)
result =self._mqttc.publish(topic, payload=payload, qos=2, retain=False)
if result[0]==4:
self._log.info("Publishing error? returned 4")
varid += 1