Controller not recognizing message rerouting?

[Dwalt]

I have been experiencing problems with nodes going dark (not updating). This occurs at random intervals so I assumed the nodes were locked-up and a simple reset usually brought them back online. I am not much of a programmer so I figured the problem came from my coding and have been tweaking my sketches to isolate the problem but they still go dark at random intervals. I decided to connect one of these troublesome nodes to a FTDI adapter and monitor the serial log until it went offline. After two days of monitoring, I caught the node "going dark", it didn't lock up like I originally thought. It seems to keep transmitting but the messages were being rerouted through a repeater (or at least I think...). I left the node alone while I scratched my head and two hours later the data resumed updating in Vera. Below is the serial log from the node at the beginning and end of the outage. The node being monitored (node #7) is a battery powered SenseBender with a PIR and LDR. Node #3 is a mains-powered repeater. I am running MySensors 1.4 with serial GW on Vera UI5. During this test, the node was about the same distance from both the repeater and GW (10-12m).

This is the serial log from immediately before the node goes offline:

send: 7-7-0-0 s=1,c=1,t=0,pt=7,l=5,st=ok:77.0
send: 7-7-0-0 s=2,c=1,t=1,pt=2,l=2,st=ok:44
read: 7-1-0 s=255,c=3,t=0,pt=1,l=1:81
Light: 83
send: 7-7-0-0 s=255,c=3,t=0,pt=1,l=1,st=ok:83
read: 7-1-0 s=255,c=3,t=0,pt=1,l=1:83
Light: 83
send: 7-7-0-0 s=255,c=3,t=0,pt=1,l=1,st=fail:81
T: 77.09
H: 44
send: 7-7-0-0 s=1,c=1,t=0,pt=7,l=5,st=fail:77.1
send: 7-7-0-0 s=2,c=1,t=1,pt=2,l=2,st=fail:44
Light: 83
send: 7-7-0-0 s=255,c=3,t=0,pt=1,l=1,st=fail:83
T: 77.12
H: 44
send: 7-7-0-0 s=1,c=1,t=0,pt=7,l=5,st=fail:77.1
send: 7-7-0-0 s=2,c=1,t=1,pt=2,l=2,st=fail:44
Light: 83
send: 7-7-0-0 s=3,c=1,t=16,pt=0,l=1,st=fail:0
send: 7-7-255-255 s=255,c=3,t=7,pt=0,l=0,st=fail:
read: 3-3-7 s=255,c=3,t=8,pt=1,l=1:1
new parent=3, d=2
send: 7-7-3-0 s=255,c=3,t=0,pt=1,l=1,st=ok:81
read: 7-1-0 s=255,c=3,t=0,pt=1,l=1:81
T: 77.16
H: 44
send: 7-7-3-0 s=1,c=1,t=0,pt=7,l=5,st=ok:77.2
send: 7-7-3-0 s=2,c=1,t=1,pt=2,l=2,st=ok:44
Light: 83
tripped
send: 7-7-3-0 s=3,c=1,t=16,pt=0,l=1,st=ok:1
T: 77.09
H: 44
send: 7-7-3-0 s=1,c=1,t=0,pt=7,l=5,st=fail:77.1
send: 7-7-3-0 s=2,c=1,t=1,pt=2,l=2,st=ok:44
read: 7-1-0 s=255,c=3,t=0,pt=1,l=1:81

2 hours later…

send: 7-7-3-0 s=1,c=1,t=0,pt=7,l=5,st=ok:80.8
send: 7-7-3-0 s=2,c=1,t=1,pt=2,l=2,st=fail:41
Light: 84
send: 7-7-3-0 s=255,c=3,t=0,pt=1,l=1,st=fail:81
T: 80.70
H: 41
send: 7-7-3-0 s=1,c=1,t=0,pt=7,l=5,st=fail:80.7
send: 7-7-3-0 s=2,c=1,t=1,pt=2,l=2,st=fail:41
Light: 84
send: 7-7-3-0 s=4,c=1,t=23,pt=2,l=2,st=fail:85
Light: 85
send: 7-7-3-0 s=255,c=3,t=0,pt=1,l=1,st=fail:81
T: 80.83
H: 41
send: 7-7-3-0 s=1,c=1,t=0,pt=7,l=5,st=fail:80.8
send: 7-7-255-255 s=255,c=3,t=7,pt=0,l=0,st=fail:
read: 0-0-7 s=255,c=3,t=8,pt=1,l=1:0
new parent=0, d=1
read: 3-3-7 s=255,c=3,t=8,pt=1,l=1:1
send: 7-7-0-0 s=2,c=1,t=1,pt=2,l=2,st=ok:41
read: 3-1-7 s=255,c=3,t=8,pt=1,l=1:1
send: 7-7-0-0 s=4,c=1,t=23,pt=2,l=2,st=ok:85
read: 3-1-7 s=255,c=3,t=8,pt=1,l=1:1
Light: 85
not tripped

Could someone help interpret the serial log and confirm my suspicions? I assume that when the message header changes from 7-7-0-0 to 7-7-3-0, it is an indication that the message is now being sent through the repeater. And when the message header changed back to 7-7-0-0, it is sending directly to the GW. The problem I have is that the data is not being read by Vera during the timeframe where the message header was changed. Is this a known problem?

[Sparkman]

@Dwalt To me it looks like the transmissions are failing which is why it tries a new route. Then at some point the new route fails and it tries a different route directly back to the gateway. You'll need to figure out why the transmissions are failing prior to the route changes. Could be power related, temporary interference (microwave, someone closing and opening a door if they are in different rooms, etc.).

Cheers
Al

[Dwalt]

@Sparkman

Full Disclosure: I am using counterfeit nRFs from the store (Alice1101983 - chip marking 1242AF -> known counterfeit). I have put 4.7uF caps on them and have placed gw.wait (3) after all gw.send commands and the latter change drastically cut down on st=fail by about 99%.

For the most part, my sensor network works somewhat okay. The problem I am fighting is the occasional node going 'dark', which i initially attributed as the node locking up somehow, but the serial data leads me to think it has more to do with the controller not recognizing the message after a change in the message header ( I think this is the right term?) after rerouting through the repeater. I do not know if this is a problem with Vera, the gateway or the 1.4 plugin. I expect that I will always get the occasional st=fail but mesh networking should help address this, correct? If my controller can't recognize a rerouted message, what is the point of the mesh?

[Sparkman]

@Dwalt I don't think there are a lot of people using legitimate ones as they seem to be hard to find You may want to try a longer delay such as gw.wait(100). One other thing to try is putting a serial monitor on node 3 to see what happens when it's supposed to be relaying info from node 7. You can hard code node 7 during this time to use node 3 as its parent.

Cheers
Al

[hek]

There was a patch pushed to github (master) which fixed routing problems a couple of days ago.

https://github.com/mysensors/Arduino/commit/2f1df520abd935c9ff2186d71632b59751cb36ce

Please try using that and get back.

Regarding Vera: It does not know (or care) how the message was routed to the gateway.

[Dwalt]

I upgraded with the patch and updated my repeater sketch with MySensors 1.5 and reset the SenseBender node with FTDI adapter connected to begin serial monitoring.

@hek Do I need to update the GW to 1.5 or just the repeater?

@Sparkman I am limited by equipment to how many nodes I can monitor by serial simultaneously and do not want to alter too many variables at one time. I will watch the sensor node (it is easier to access) for now to catch any rerouting messages and then check the controller logs to determine if it received them. Now to wait.

[hek]

@Dwalt

Not sure it is necessary, but it wouldn't hurt.

[Dwalt]

1.5 appears to have fixed my repeater problem. I have monitored the serial output continuously from a single sensor node for the past 5 days after upgrading the sensor node and repeater node to 1.5...and finally, the node experienced the random 'st=fail' and searched for a 'new parent' (it seems to take 6 'st=fail' in a row to trigger rerouting). The node redirected traffic through the repeater node and the gateway successfully received and passed on the data. All is well.

No clue what causes the 'st=fail'. I live in an inner-city so RF interference is expected and unavoidable. Reviewing 120+ hours of serial data, it seems the node would experience an average of 3-4 'st=fail' per day at random intervals. The 6 sequential 'st=fail' occurred in the middle of the night. I have no idea what triggered the problem but the mesh networking worked and quickly eliminated the problem.

@hek Thank you for resolving this.