Raspberry Pi as MySensors gateway crash/hung after ~1hour.

[macieiks]

Hello,

I am using MySensors since 2 years. To this day I was using UNO with W5100 shield as Ethernet gateway for my nodes (beta branch). Today I migrated to Raspberry Pi gateway solution with nrf24l01+ PA option. Everything went smooth, I have installed development branch etc, radio has been initialised and all the sensors/nodes were replaced with the new ones. I have tested this for few hours and I can see that after some time (approx 1-2h) MySensors data reporting is hung/stuck. The only way to fix it is reboot of the system.

Could you please take a look on below and advise what can be wrong? As you can see MySensors logs are being sent/received till Dec 29 22:01:37. After this timestamp only "ping" is working, no new data in the channel. I was using similar solution on 2nd Pi (same config) and this runs for a weeks without any problems. I would like to avoid migrating back to W5100 solution because I need to have ability to check MySensors logs remotely.

Thank you for the help.
Maciek

For the reference:

## CONFIGURATION
pi@raspberrypi ~/MySensors $ ./configure --my-debug=enable --my-transport=nrf24 --my-gateway=ethernet --my-port=5003 --my-rf24-pa-level=RF24_PA_LOW --my-rf24-irq-pin=15 --my-leds-err-pin=12 --my-leds-rx-pin=16 --my-leds-tx-pin=18
[SECTION] Detecting target machine.
  [OK] machine detected: SoC=BCM2836, Type=rpi2, CPU=armv7l.
[SECTION] Detecting SPI driver.
  [OK] SPI driver detected:BCM.
[SECTION] Detecting init system.
  [OK] init system detected: systemd.
[SECTION] Saving configuration.
[SECTION] Cleaning previous builds.
[OK] Finished.

## DEBUG ENABLED in /etc/systemd/system/mysgw.service
[Service]
ExecStart=/usr/local/bin/mysgw -d

## VERIFICATION
pi@raspberrypi ~/MySensors $ sudo ./bin/mysgw -d
mysgw: Starting gateway...
mysgw: Protocol version - 2.2.0-rc.2
mysgw: MCO:BGN:INIT GW,CP=RNNGL-Q-,VER=2.2.0-rc.2
mysgw: TSF:LRT:OK
mysgw: TSM:INIT
mysgw: TSF:WUR:MS=0
mysgw: TSM:INIT:TSP OK
mysgw: TSM:INIT:GW MODE
mysgw: TSM:READY:ID=0,PAR=0,DIS=0
mysgw: MCO:REG:NOT NEEDED
mysgw: Listening for connections on 0.0.0.0:5003
mysgw: MCO:BGN:STP
mysgw: MCO:BGN:INIT OK,TSP=1
mysgw: TSF:MSG:READ,49-49-255,s=255,c=3,t=7,pt=0,l=0,sg=0:
mysgw: TSF:MSG:BC
mysgw: TSF:MSG:FPAR REQ,ID=49
mysgw: TSF:CKU:OK,FCTRL
mysgw: TSF:MSG:GWL OK
mysgw: TSF:MSG:SEND,0-0-49-49,s=255,c=3,t=8,pt=1,l=1,sg=0,ft=0,st=OK:0
mysgw: TSF:MSG:READ,49-49-0,s=255,c=3,t=24,pt=1,l=1,sg=0:1
mysgw: TSF:MSG:PINGED,ID=49,HP=1
mysgw: TSF:MSG:SEND,0-0-49-49,s=255,c=3,t=25,pt=1,l=1,sg=0,ft=0,st=OK:1
mysgw: TSF:MSG:READ,4-4-0,s=0,c=1,t=37,pt=2,l=2,sg=0:209
mysgw: TSF:MSG:READ,4-4-0,s=2,c=1,t=0,pt=7,l=5,sg=0:-0.4
mysgw: TSF:MSG:READ,4-4-0,s=1,c=1,t=1,pt=7,l=5,sg=0:99.9


## DAILY,NORMAL OPERATION AFTER 1ST REBOOT
Dec 29 22:00:57 raspberrypi mysgw: Client 0: 0;0;3;0;18;PING
Dec 29 22:00:57 raspberrypi mysgw: TSF:MSG:READ,3-3-0,s=4,c=1,t=0,pt=7,l=5,sg=0:-0.5
Dec 29 22:00:58 raspberrypi mysgw: TSF:MSG:READ,8-3-0,s=1,c=1,t=34,pt=7,l=5,sg=0:0.00
Dec 29 22:00:58 raspberrypi mysgw: TSF:MSG:READ,8-3-0,s=1,c=1,t=24,pt=5,l=4,sg=0:498046
Dec 29 22:00:58 raspberrypi mysgw: TSF:MSG:READ,8-3-0,s=1,c=1,t=35,pt=7,l=5,sg=0:498.046
Dec 29 22:00:58 raspberrypi mysgw: TSF:MSG:READ,3-3-0,s=5,c=1,t=0,pt=7,l=5,sg=0:25.0
Dec 29 22:00:59 raspberrypi mysgw: TSF:MSG:READ,3-3-0,s=6,c=1,t=0,pt=7,l=5,sg=0:30.1
Dec 29 22:00:59 raspberrypi mysgw: TSF:MSG:READ,4-4-0,s=0,c=1,t=37,pt=2,l=2,sg=0:208
Dec 29 22:00:59 raspberrypi mysgw: TSF:MSG:READ,3-3-0,s=7,c=1,t=0,pt=7,l=5,sg=0:20.6
Dec 29 22:01:01 raspberrypi mysgw: TSF:MSG:READ,4-4-0,s=2,c=1,t=0,pt=7,l=5,sg=0:-0.4
Dec 29 22:01:01 raspberrypi mysgw: TSF:MSG:READ,4-4-0,s=1,c=1,t=1,pt=7,l=5,sg=0:99.9
Dec 29 22:01:01 raspberrypi CRON[3866]: (pi) CMD (sudo ~/domoticz/scripts/readapc.sh >/dev/null 2>&1)
Dec 29 22:01:01 raspberrypi CRON[3867]: (pi) CMD (sleep 20; sudo ~/domoticz/scripts/readapc.sh >/dev/null 2>&1)
Dec 29 22:01:01 raspberrypi CRON[3871]: (pi) CMD (sleep 40; sudo ~/domoticz/scripts/readapc.sh >/dev/null 2>&1)
Dec 29 22:01:02 raspberrypi mysgw: TSF:MSG:READ,49-49-0,s=1,c=1,t=0,pt=7,l=5,sg=0:20.0
Dec 29 22:01:02 raspberrypi mysgw: TSF:MSG:READ,49-49-0,s=0,c=1,t=4,pt=7,l=5,sg=0:1012
Dec 29 22:01:07 raspberrypi mysgw: Client 0: 0;0;3;0;18;PING
Dec 29 22:01:09 raspberrypi mysgw: TSF:MSG:READ,1-1-0,s=1,c=1,t=17,pt=5,l=4,sg=0:633
Dec 29 22:01:09 raspberrypi mysgw: TSF:MSG:READ,1-1-0,s=1,c=1,t=24,pt=5,l=4,sg=0:12879042
Dec 29 22:01:09 raspberrypi mysgw: TSF:MSG:READ,1-1-0,s=1,c=1,t=18,pt=7,l=5,sg=0:8586.0283
Dec 29 22:01:12 raspberrypi mysgw: TSF:MSG:READ,7-3-0,s=1,c=1,t=24,pt=5,l=4,sg=0:34590149
Dec 29 22:01:13 raspberrypi mysgw: TSF:MSG:READ,7-3-0,s=1,c=1,t=35,pt=7,l=5,sg=0:345901.469
Dec 29 22:01:13 raspberrypi mysgw: TSF:MSG:READ,3-3-0,s=199,c=1,t=17,pt=5,l=4,sg=0:136
Dec 29 22:01:14 raspberrypi mysgw: TSF:MSG:READ,3-3-0,s=199,c=1,t=24,pt=5,l=4,sg=0:1468990
Dec 29 22:01:14 raspberrypi mysgw: TSF:MSG:READ,3-3-0,s=199,c=1,t=18,pt=7,l=5,sg=0:1468.9900
Dec 29 22:01:15 raspberrypi mysgw: TSF:MSG:READ,3-3-0,s=0,c=1,t=0,pt=7,l=5,sg=0:26.9
Dec 29 22:01:15 raspberrypi mysgw: TSF:MSG:READ,7-3-0,s=3,c=1,t=0,pt=7,l=5,sg=0:21.5
Dec 29 22:01:16 raspberrypi mysgw: TSF:MSG:READ,7-3-0,s=2,c=1,t=1,pt=7,l=5,sg=0:44.1
Dec 29 22:01:16 raspberrypi mysgw: TSF:MSG:READ,3-3-0,s=1,c=1,t=0,pt=7,l=5,sg=0:12.0
Dec 29 22:01:16 raspberrypi mysgw: TSF:MSG:READ,3-3-0,s=2,c=1,t=0,pt=7,l=5,sg=0:50.6
Dec 29 22:01:16 raspberrypi mysgw: TSF:MSG:READ,2-49-0,s=1,c=1,t=0,pt=7,l=5,sg=0:9.1
Dec 29 22:01:16 raspberrypi mysgw: TSF:MSG:READ,2-49-0,s=0,c=1,t=1,pt=7,l=5,sg=0:52.3
Dec 29 22:01:16 raspberrypi mysgw: TSF:MSG:READ,2-49-0,s=0,c=1,t=1,pt=7,l=5,sg=0:52.3
Dec 29 22:01:17 raspberrypi mysgw: Client 0: 0;0;3;0;18;PING
Dec 29 22:01:17 raspberrypi mysgw: TSF:MSG:READ,3-3-0,s=3,c=1,t=0,pt=7,l=5,sg=0:21.5
Dec 29 22:01:17 raspberrypi mysgw: TSF:MSG:READ,3-3-0,s=4,c=1,t=0,pt=7,l=5,sg=0:-0.5
Dec 29 22:01:18 raspberrypi mysgw: TSF:MSG:READ,8-3-0,s=1,c=1,t=24,pt=5,l=4,sg=0:498046
Dec 29 22:01:18 raspberrypi mysgw: TSF:MSG:READ,3-3-0,s=5,c=1,t=0,pt=7,l=5,sg=0:25.0
Dec 29 22:01:19 raspberrypi mysgw: TSF:MSG:READ,3-3-0,s=6,c=1,t=0,pt=7,l=5,sg=0:30.1
Dec 29 22:01:19 raspberrypi mysgw: TSF:MSG:READ,4-4-0,s=0,c=1,t=37,pt=2,l=2,sg=0:213
Dec 29 22:01:19 raspberrypi mysgw: TSF:MSG:READ,3-3-0,s=7,c=1,t=0,pt=7,l=5,sg=0:20.6
Dec 29 22:01:21 raspberrypi mysgw: TSF:MSG:READ,4-4-0,s=2,c=1,t=0,pt=7,l=5,sg=0:-0.4
Dec 29 22:01:21 raspberrypi mysgw: TSF:MSG:READ,4-4-0,s=1,c=1,t=1,pt=7,l=5,sg=0:99.9
Dec 29 22:01:27 raspberrypi mysgw: Client 0: 0;0;3;0;18;PING
Dec 29 22:01:29 raspberrypi mysgw: TSF:MSG:READ,1-1-0,s=1,c=1,t=17,pt=5,l=4,sg=0:635
Dec 29 22:01:29 raspberrypi mysgw: TSF:MSG:READ,1-1-0,s=1,c=1,t=24,pt=5,l=4,sg=0:12879047
Dec 29 22:01:29 raspberrypi mysgw: TSF:MSG:READ,1-1-0,s=1,c=1,t=18,pt=7,l=5,sg=0:8586.0312
Dec 29 22:01:31 raspberrypi mysgw: TSF:MSG:READ,49-49-0,s=1,c=1,t=0,pt=7,l=5,sg=0:20.0
Dec 29 22:01:32 raspberrypi mysgw: TSF:MSG:READ,49-49-0,s=0,c=1,t=4,pt=7,l=5,sg=0:1012
Dec 29 22:01:32 raspberrypi mysgw: TSF:MSG:READ,7-3-0,s=1,c=1,t=34,pt=7,l=5,sg=0:15.98
Dec 29 22:01:33 raspberrypi mysgw: TSM:READY:NWD REQ
Dec 29 22:01:33 raspberrypi mysgw: TSF:MSG:SEND,0-0-255-255,s=255,c=3,t=20,pt=0,l=0,sg=0,ft=0,st=OK:
Dec 29 22:01:33 raspberrypi mysgw: TSF:MSG:READ,7-3-0,s=1,c=1,t=24,pt=5,l=4,sg=0:34590150
Dec 29 22:01:33 raspberrypi mysgw: TSF:MSG:READ,1-1-0,s=255,c=3,t=21,pt=1,l=1,sg=0:0
Dec 29 22:01:33 raspberrypi mysgw: TSF:MSG:READ,49-49-0,s=255,c=3,t=21,pt=1,l=1,sg=0:0
Dec 29 22:01:33 raspberrypi mysgw: TSF:MSG:READ,0-49-255,s=255,c=3,t=20,pt=0,l=0,sg=0:
Dec 29 22:01:33 raspberrypi mysgw: TSF:MSG:BC
Dec 29 22:01:33 raspberrypi mysgw: TSF:MSG:READ,7-3-0,s=1,c=1,t=35,pt=7,l=5,sg=0:345901.531
Dec 29 22:01:33 raspberrypi mysgw: TSF:MSG:READ,3-3-0,s=199,c=1,t=17,pt=5,l=4,sg=0:136
Dec 29 22:01:34 raspberrypi mysgw: TSF:MSG:READ,3-3-0,s=199,c=1,t=24,pt=5,l=4,sg=0:1468990
Dec 29 22:01:34 raspberrypi mysgw: TSF:MSG:READ,3-3-0,s=199,c=1,t=18,pt=7,l=5,sg=0:1468.9900
Dec 29 22:01:37 raspberrypi mysgw: Client 0: 0;0;3;0;18;PING
Dec 29 22:01:47 raspberrypi mysgw: Client 0: 0;0;3;0;18;PING
Dec 29 22:01:57 raspberrypi mysgw: Client 0: 0;0;3;0;18;PING
Dec 29 22:02:01 raspberrypi CRON[4013]: (pi) CMD (sleep 40; sudo ~/domoticz/scripts/readapc.sh >/dev/null 2>&1)
Dec 29 22:02:01 raspberrypi CRON[4019]: (pi) CMD (sleep 20; sudo ~/domoticz/scripts/readapc.sh >/dev/null 2>&1)
Dec 29 22:02:01 raspberrypi CRON[4021]: (pi) CMD (sudo ~/domoticz/scripts/readapc.sh >/dev/null 2>&1)
Dec 29 22:02:07 raspberrypi mysgw: Client 0: 0;0;3;0;18;PING
Dec 29 22:02:17 raspberrypi mysgw: Client 0: 0;0;3;0;18;PING
Dec 29 22:02:27 raspberrypi mysgw: Client 0: 0;0;3;0;18;PING
Dec 29 22:02:37 raspberrypi mysgw: Client 0: 0;0;3;0;18;PING
Dec 29 22:02:47 raspberrypi mysgw: Client 0: 0;0;3;0;18;PING
Dec 29 22:02:57 raspberrypi mysgw: Client 0: 0;0;3;0;18;PING
Dec 29 22:03:01 raspberrypi CRON[4164]: (pi) CMD (sleep 20; sudo ~/domoticz/scripts/readapc.sh >/dev/null 2>&1)
Dec 29 22:03:01 raspberrypi CRON[4163]: (pi) CMD (sudo ~/domoticz/scripts/readapc.sh >/dev/null 2>&1)
Dec 29 22:03:01 raspberrypi CRON[4165]: (pi) CMD (sleep 40; sudo ~/domoticz/scripts/readapc.sh >/dev/null 2>&1)
Dec 29 22:03:07 raspberrypi mysgw: Client 0: 0;0;3;0;18;PING
Dec 29 22:03:17 raspberrypi mysgw: Client 0: 0;0;3;0;18;PING
Dec 29 22:03:27 raspberrypi mysgw: Client 0: 0;0;3;0;18;PING
Dec 29 22:03:37 raspberrypi mysgw: Client 0: 0;0;3;0;18;PING

[Yveaux]

@macieiks Could be power and/or radio related. Could you try with a different, non-PA radio ?