sntp.sync: callback esp crashes when there is no server after 2nd try

[NiklausS]

Hi all,

as already mentioned in 'SNTP success callback function runs when sync not successful #2622', this looks like a problem to me.
Sorry to bring this up again, but somehow this does not work for me either.

When i block the ntp address on my dsl, the esp crashes after 1000sec, after the 2nd try for ntp.

this is my code:

    print('start SNTP time sync')   
    local function sntpG(sec,usec,server,info)
        print(' good sntp')
    end

    local function sntpB(e)
        print(' bad sntp')
    end

    local function set_sntp1(tmsrv)
                sntp.sync( tmsrv, 
                    function(sec,usec,server,info) print("good sntp") end,
                    function(e) print ("bad sntp") end,
                    1 )
          end

    local function set_sntp2(tmsrv)
                sntp.sync( tmsrv, 
                    sntpG,
                    sntpB,
                    1 )
          end
            
    set_sntp2('168.1.23.122')

and this is the output:

NodeMCU 2.2.0.0 build unspecified powered by Lua 5.1.4 on SDK 2.2.1(6ab97e9)
start SNTP time sync
>  bad sntp
....
here it takes 1000sec...
....
PANIC: unprotected error in call to Lua API (bad argument #-1 (string expected, got nil))

 ets Jan  8 2013,rst cause:2, boot mode:(3,6)

load 0x40100000, len 28360, room 16 
tail 8
chksum 0x5e
load 0x3ffe8000, len 2280, room 0 
tail 8
chksum 0x73
load 0x3ffe88e8, len 136, room 0 
tail 8
chksum 0xb3
csum 0xb3



NodeMCU 2.2.0.0 build unspecified powered by Lua 5.1.4 on SDK 2.2.1(6ab97e9)
start SNTP time sync
>  bad sntp
... and it repeates after 1000 sec

is this only me having this problem, or doesn't this code work for others either?

Thanks & Regards
Nik

NodeMCU version

My last snapshot is from about october 2018.

Hardware

esp wroom

[nwf]

Other than being vaguely about SNTP, this appears unrelated to #2622.

It is possible that this is related to #2553. It's also possible that the lines https://github.com/nodemcu/nodemcu-firmware/blob/master/app/modules/sntp.c#L209 and 210 are reversed; I don't see any reason why we should be cleaning up before calling back into the Lua VM, but @TerryE might know more.

Failing either of the above, you may be able to get more information with a debug build.

[NiklausS]

It's me again.
tested it with the debug from sntp.c and here's the output:

NodeMCU 2.2.0.0 build unspecified powered by Lua 5.1.4 on SDK 2.2.1(6ab97e9)
start SNTP time sync
sntp: server 168.1.23.122 (0), attempt 0
sntp: send: -4
> sntp: timer
sntp: server 168.1.23.122 (0), attempt 1
sntp: send: -4
sntp: timer
sntp: server 168.1.23.122 (0), attempt 2
sntp: send: 0
sntp: timer
sntp: server 168.1.23.122 (0), attempt 3
sntp: send: 0
sntp: timer
sntp: server 168.1.23.122 (0), attempt 4
sntp: send: 0
sntp: timer
sntp: handle_error
 bad snmp
=node.heap()
38560
> =node.info()
2	2	0	11756680	1458415	4096	3	40000000
> =node.heap()
38560
_...
1000sec later 
..._
> sntp: long timer
PANIC: unprotected error in call to Lua API (bad argument #-1 (string expected, got nil))

does this help any further?

Thanks

Nik

[nwf]

I think I see what is going on. Sigh. I'll open a PR. In the interim, if you replace set_sntp2('168.1.23.122') with set_sntp2({'168.1.23.122'}) you will probably be happier.

[NiklausS]

Hi nwf,

uff, don't ask for how long i had these sporadic restarts and absolutely no clue what it could be. In the end i used a second esp to read the uart and send it to a logserver.

Thank you so much.

Nik

NodeMCU 2.2.0.0 build unspecified powered by Lua 5.1.4 on SDK 2.2.1(6ab97e9)
start SNTP time sync
sntp: server 168.1.23.122 (0), attempt 0
sntp: send: -4
> sntp: timer
sntp: server 168.1.23.122 (0), attempt 1
sntp: send: 0
sntp: timer
sntp: server 168.1.23.122 (0), attempt 2
sntp: send: 0
sntp: timer
sntp: server 168.1.23.122 (0), attempt 3
sntp: send: 0
sntp: timer
sntp: server 168.1.23.122 (0), attempt 4
sntp: send: 0
sntp: timer
sntp: handle_error
 bad snmp
=node.heap(2325)
38416
> sntp: long timer
sntp: server 168.1.23.122 (0), attempt 0
sntp: send: 0
sntp: timer
sntp: server 168.1.23.122 (0), attempt 1
sntp: send: 0
sntp: timer
sntp: server 168.1.23.122 (0), attempt 2
sntp: send: 0
sntp: timer
sntp: server 168.1.23.122 (0), attempt 3
sntp: send: 0
sntp: timer
sntp: server 168.1.23.122 (0), attempt 4
sntp: send: 0
sntp: timer
sntp: handle_error
 bad snmp

[cwrseck]

Checking SNTP autocall failures with set_sntp2('168.1.23.122')

NodeMCU 2.2.0.0 build March 2019 powered by Lua 5.1.4 on SDK 2.2.1(6ab97e9)
lua: cannot open init.lua
>
> dofile("sntp.lua")
start SNTP time sync, 1000 sec autodelay
>  bad sntp
PANIC: unprotected error in call to Lua API (bad argument #-1 (string expected, got nil))

 ets Jan  8 2013,rst cause:2, boot mode:(3,6)

load 0x40100000, len 26948, room 16 
tail 4
chksum 0x02
load 0x3ffe8000, len 2180, room 4 
tail 0
chksum 0xdd
load 0x3ffe8884, len 136, room 8 
tail 0
chksum 0x6d
csum 0x6d

Checking with set_sntp2({'168.1.23.122'})

> dofile("sntp.lua")
start SNTP time sync, 1000 sec autodelay
>  bad sntp
 bad sntp

If an otherwise unchanged NodeMCU build is updated with the sntp.c of Issue
#2700 set_sntp2('168.1.23.122') runs correctly (ie. prints "bad sntp") for
at least three cycles.

C W Rose