Delay after TSF:TRI:TSB

Yveaux

@fausti are you using an amplified nrf24 pa+lna module by any chance?

mfalkvidd

@fausti interesting that the sleep and the nack has the same value. Maybe something gets overwritten in memory.

tekka

@mfalkvidd @fausti no, this is normal the smartsleep log:

6047 MCO:SLP:MS=20864000,SMS=1,I1=1,M1=1,I2=255,M2=255

==> smart sleep enabled, IRQ on pin 1 set, going to sleep for 20864000 ms

6125 TSF:MSG:SEND,9-9-0-0,s=255,c=3,t=32,pt=5,l=4,sg=0,ft=0,st=OK:500

==> I_PRE_SLEEP_NOTIFICATION, 500ms to process any incoming message before going to seep

6199 TSF:MSG:READ,0-0-9,s=2,c=1,t=23,pt=5,l=4,sg=0:5
6254 TSF:MSG:ACK
6699 TSF:TDI:TSL
6717 MCO:SLP:WUP=1
6735 TSF:TRI:TSB

==> sleep interrupted by IRQ 1

8437 !TSF:MSG:SEND,9-9-0-0,s=255,c=3,t=33,pt=5,l=4,sg=0,ft=0,st=NACK:20864000

==> I_POST_SLEEP_NOTIFICATION, node was sleeping for 20864000ms (but sleep was interrupted)

tekka

...but, the delay between TSB and SEND is a bit odd;

9480 TSF:TRI:TSB
11180 !TSF:MSG:SEND,9-9-0-0,s=255,c=3,t=33,pt=5,l=4,sg=0,ft=0,st=NACK:20864000

Enabling MY_DEBUG_VERBOSE_RF24 could eventually give some hints.

tekka

FYI: I tried with both, 2.3.0 and 2.3.1-beta (incl. CE fix), on non-amplified and PA+LNA modules - I do not see any delay between TSB and SEND

6973 MCO:SLP:MS=5000,SMS=1,I1=1,M1=1,I2=255,M2=255
6979 TSF:MSG:SEND,100-100-0-0,s=255,c=3,t=32,pt=5,l=4,sg=0,ft=0,st=OK:500
7486 TSF:TDI:TSL
7487 MCO:SLP:WUP=1
7489 TSF:TRI:TSB
7492 TSF:MSG:SEND,100-100-0-0,s=255,c=3,t=33,pt=5,l=4,sg=0,ft=0,st=OK:5000

I assume you have a power issue, a bad module - or an artifact originating from the nodemanager?

fausti

@Yveaux sensor is using standard NRF24L01+ (only the gw uses pa+lna - but I guess that won't be an issue?)

@tekka did you use the same sketch? You mentioned smartsleep, I haven't enabled that.. I'll try MY_DEBUG_VERBOSE_RF24 later, use a fresh NodeManager and will check all my hardware again and I still have to try that fix: https://forum.mysensors.org/topic/9598/smartsleep-wake-up-message-always-get-nack
I've build more than one sensor and all of them are showing that delay - using different power sources and I also tried different capacitor. Maybe after all it's the gw.. but can't think of a reason why sleeping would cause that behavior at gw.

I'll report later - Thanks for the quick help!!

tekka

@fausti the log indicates that smartsleep is enabled - that said, smartsleep may originate from the nodemanager

6047 MCO:SLP:MS=20864000,SMS=1

tekka

@fausti Can you re-test your setup with this patch (ideally, update GW and nodes): https://github.com/tekka007/MySensors/tree/RF24STDBYTiming - I've added a delay after setting the radio in standby mode.

fausti

@tekka WOW!! Your fix works like a dream - can't thank you enough! :pray: :tada:

For now I just used your patch at the sensor - but it allready runs perfectly - no lag/no NACK (see DEBUG below).
So the radio needs more time to settle? How long did you set the delay?

Many many thanks to @tekka and to you all for helping that fast and professional!!

[For so many hours I tried figuring out where the problem lies.. at least I know that library better now ^^ ]

0 MCO:BGN:INIT NODE,CP=RNNNA---,VER=2.3.1-beta
59 MCO:BGN:BFR
NodeManager v1.7
LIB V=2.3.1-beta R=N E=- T=N A=A S=- B=-
MOTION I=1 P=1 T=16
LDR I=2 P=16 T=23
RADIO...118 TSM:INIT
200 TSF:WUR:MS=0
223 TSM:INIT:TSP OK
245 TSF:SID:OK,ID=9
266 TSM:FPAR
315 TSF:MSG:SEND,9-9-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
1208 TSF:MSG:READ,0-0-9,s=255,c=3,t=8,pt=1,l=1,sg=0:0
1265 TSF:MSG:FPAR OK,ID=0,D=1
2390 TSM:FPAR:OK
2406 TSM:ID
2420 TSM:ID:OK
2435 TSM:UPL
2453 TSF:MSG:SEND,9-9-0-0,s=255,c=3,t=24,pt=1,l=1,sg=0,ft=0,st=OK:1
2525 TSF:MSG:READ,0-0-9,s=255,c=3,t=25,pt=1,l=1,sg=0:1
2582 TSF:MSG:PONG RECV,HP=1
2611 TSM:UPL:OK
2629 TSM:READY:ID=9,PAR=0,DIS=1
2666 TSF:MSG:SEND,9-9-0-0,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=OK:0100
2740 TSF:MSG:READ,0-0-9,s=255,c=3,t=15,pt=6,l=2,sg=0:0100
2805 TSF:MSG:SEND,9-9-0-0,s=255,c=0,t=17,pt=0,l=10,sg=0,ft=0,st=OK:2.3.1-beta
2891 TSF:MSG:SEND,9-9-0-0,s=255,c=3,t=6,pt=1,l=1,sg=0,ft=0,st=OK:0
2961 TSF:MSG:READ,0-0-9,s=255,c=3,t=6,pt=0,l=1,sg=0:M
OK
3022 TSF:MSG:SEND,9-9-0-0,s=255,c=3,t=11,pt=0,l=5,sg=0,ft=0,st=OK:Testo
3102 TSF:MSG:SEND,9-9-0-0,s=255,c=3,t=12,pt=0,l=3,sg=0,ft=0,st=OK:2.0
PRES I=1 T=1 D=MOTION
3180 TSF:MSG:SEND,9-9-0-0,s=1,c=0,t=1,pt=0,l=6,sg=0,ft=0,st=OK:MOTION
PRES I=2 T=16 D=LDR
3276 TSF:MSG:SEND,9-9-0-0,s=2,c=0,t=16,pt=0,l=3,sg=0,ft=0,st=OK:LDR
READY

3364 MCO:REG:REQ
3395 TSF:MSG:SEND,9-9-0-0,s=255,c=3,t=26,pt=1,l=1,sg=0,ft=0,st=OK:2
3467 TSF:MSG:READ,0-0-9,s=255,c=3,t=27,pt=1,l=1,sg=0:1
3524 MCO:PIM:NODE REG=1
3551 MCO:BGN:STP
MY I=9 M=1
INT P=3 M=1
INT P=2 M=255
3569 MCO:BGN:INIT OK,TSP=1
LDR I=2 V=302 %=29
SEND D=0 I=2 C=0 T=23 S= I=0 F=0.00
3645 TSF:MSG:SEND,9-9-0-0,s=2,c=1,t=23,pt=5,l=4,sg=0,ft=0,st=OK:29
SLEEP 20864s

3768 MCO:SLP:MS=20864000,SMS=1,I1=1,M1=1,I2=255,M2=255
3846 TSF:MSG:SEND,9-9-0-0,s=255,c=3,t=32,pt=5,l=4,sg=0,ft=0,st=OK:500
4419 TSF:TDI:TSL
4435 MCO:SLP:WUP=1
4456 TSF:TRI:TSB
4483 TSF:MSG:SEND,9-9-0-0,s=255,c=3,t=33,pt=5,l=4,sg=0,ft=0,st=OK:20864000
INT P=3, V=1
AWAKE
MOTION I=1 P=3 V=1
SEND D=0 I=1 C=0 T=16 S= I=0 F=0.00
4579 TSF:MSG:SEND,9-9-0-0,s=1,c=1,t=16,pt=5,l=4,sg=0,ft=0,st=OK:1
LDR I=2 V=284 %=27
SEND D=0 I=2 C=0 T=23 S= I=0 F=0.00
4718 TSF:MSG:SEND,9-9-0-0,s=2,c=1,t=23,pt=5,l=4,sg=0,ft=0,st=OK:27
SLEEP 20864s

4841 MCO:SLP:MS=20864000,SMS=1,I1=1,M1=1,I2=255,M2=255
4919 TSF:MSG:SEND,9-9-0-0,s=255,c=3,t=32,pt=5,l=4,sg=0,ft=0,st=OK:500
5494 TSF:TDI:TSL
5511 MCO:SLP:WUP=1
5531 TSF:TRI:TSB
5558 TSF:MSG:SEND,9-9-0-0,s=255,c=3,t=33,pt=5,l=4,sg=0,ft=0,st=OK:20864000
INT P=3, V=0
AWAKE
MOTION I=1 P=3 V=0
SEND D=0 I=1 C=0 T=16 S= I=0 F=0.00
5654 TSF:MSG:SEND,9-9-0-0,s=1,c=1,t=16,pt=5,l=4,sg=0,ft=0,st=OK:0
LDR I=2 V=295 %=28
SEND D=0 I=2 C=0 T=23 S= I=0 F=0.00
5793 TSF:MSG:SEND,9-9-0-0,s=2,c=1,t=23,pt=5,l=4,sg=0,ft=0,st=OK:28
SLEEP 20864s

5916 MCO:SLP:MS=20864000,SMS=1,I1=1,M1=1,I2=255,M2=255
5994 TSF:MSG:SEND,9-9-0-0,s=255,c=3,t=32,pt=5,l=4,sg=0,ft=0,st=OK:500
6569 TSF:TDI:TSL

Rayne

@tekka This patch is not compiling correctly for ESP8266Gateway when using Wemos D1 Mini in the board manager, nor does it compile when the NodeMCU 1.0 board is selected either.

mfalkvidd

@rayne it compiled fine when the change was merged into MySensors.
0_1542354237857_038A1FBE-BD1A-43E7-8A05-0736E4FB6D0A.png
Could you post the error message you're getting?

Rayne

@mfalkvidd Strange, when I compile for a arduino pro mini sensor, it compiles fine. However if I try to compile the esp8266gateway for a Wemos D1 Mini, the compiler complains about a file with no such directory.

0_1542355148552_e84b8175-aa7f-4992-a8d9-af1643efe87d-image.png

mfalkvidd

@rayne see https://forum.mysensors.org/topic/9563/esp8266-fatal-error-gdb_hooks-h-no-such-file-or-directory-solved

Rayne

@mfalkvidd Ahhhh, that was it. I was still on 2.3.0 of the esp8266 core. Once I upgraded to 2.4.2 it compiled fine and was able to find gdb_hooks.h. I think I was on the older version due to some compatibility issues I had when I was making a WiFi Jammer for a buddy of mine some time ago. Hey thanks for your help @mfalkvidd . You are the man!

Delay after TSF:TRI:TSB

12

11.7k

11.2k

113.1k