pycom / pycom-micropython-sigfox

A fork of MicroPython with the ESP32 port customized to run on Pycom's IoT multi-network modules.
MIT License
197 stars 167 forks source link

RTC.ntp_sync() bug introduced in 1.20.2.rc11 #478

Closed dl2080 closed 3 years ago

dl2080 commented 3 years ago

Hi, moving from rc10 to rc11, the ntp_sync function delivers a wrong timestamp to the rtc on WiPy 3.0 / W01.

(1) with rc10

>>> import time
>>> from os import uname
>>> from machine import RTC
>>> uname()
(sysname='WiPy', nodename='WiPy', release='1.20.2.rc10', version='v1.20.1.r2-174-ga159dee1-dirty on 2020-06-30', machine='WiPy with ESP32')
>>> rtc=RTC()
>>> rtc.ntp_sync("pool.ntp.org")
>>> rtc.synced()
True
>>> time.time()
1599559325
>>> time.localtime()
(2020, 9, 8, 10, 2, 9, 1, 252)

(2) with rc11

>>> import time
>>> from os import uname
>>> from machine import RTC
>>> uname()
(sysname='WiPy', nodename='WiPy', release='1.20.2.rc11', version='v1.20.1.r2-306-gd574024b-dirty on 2020-09-07', machine='WiPy with ESP32')
>>> rtc=RTC()
>>> rtc.ntp_sync("pool.ntp.org")
>>> rtc.synced()
True
>>> time.time()
3199119028
>>> time.localtime()
(2071, 5, 17, 20, 10, 29, 6, 137)
>>> time.time()//2
1599559514
>>> time.localtime(time.time()//2)
(2020, 9, 8, 10, 5, 34, 1, 252)

The timestamp is wrong by a factor of 2.

(3) back to rc10

>>> import time
>>> from os import uname
>>> from machine import RTC
>>> uname()
(sysname='WiPy', nodename='WiPy', release='1.20.2.rc10', version='v1.20.1.r2-174-ga159dee1-dirty on 2020-06-30', machine='WiPy with ESP32')
>>> rtc=RTC()
>>> rtc.ntp_sync("pool.ntp.org")
>>> rtc.synced()
True
>>> time.time()
1599559835
>>> time.localtime()
(2020, 9, 8, 10, 10, 35, 1, 252)

Fully reversible.

peter-pycom commented 3 years ago

Are you always getting a wrong value with rc11 (r2)? Is it always the same value / offset from real time? I'm trying to reproduce this. Once I think I have seen a tuple that was off some dozens of years, but I can't reproduce it anymore

dl2080 commented 3 years ago

Hi Peter it is still wrong by a factor of 2 in r3:

(1) with rc10

>>> import time
>>> from os import uname
>>> from machine import RTC
>>> uname()
(sysname='WiPy', nodename='WiPy', release='1.20.2.rc10', version='v1.20.1.r2-174-ga159dee1-dirty on 2020-06-30', machine='WiPy with ESP32')
>>> rtc=RTC()
>>> rtc.ntp_sync("pool.ntp.org")
>>> rtc.synced()
True
>>> time.time()
1609928685
>>> time.localtime()
(2021, 1, 6, 10, 24, 49, 2, 6)

(2) with r3

>>> import time
>>> from os import uname
>>> from machine import RTC
>>> uname()
(sysname='WiPy', nodename='WiPy', release='1.20.2.r3', version='v1.20.1.r2-349-g044dfea1-dirty on 2020-12-30', machine='WiPy with ESP32')
>>> rtc=RTC()
>>> rtc.ntp_sync("pool.ntp.org")
>>> rtc.synced()
True
>>> time.time()
3219857677
>>> time.localtime()
(2072, 1, 12, 20, 54, 40, 1, 12)
>>> time.time()//2
1609928841
>>> time.localtime(time.time()//2)
(2021, 1, 6, 10, 27, 23, 2, 6)

(3) The workaround using rtc.init(rtc.now()) proposed in https://github.com/pycom/pycom-micropython-sigfox/issues/500 works for r3

>>> import time
>>> from os import uname
>>> from machine import RTC
>>> uname()
(sysname='WiPy', nodename='WiPy', release='1.20.2.r3', version='v1.20.1.r2-349-g044dfea1-dirty on 2020-12-30', machine='WiPy with ESP32')
>>> rtc=RTC()
>>> rtc.init(rtc.now())
>>> rtc.ntp_sync("pool.ntp.org")
>>> rtc.synced()
True
>>> time.time()
1609929185
>>> time.localtime()
(2021, 1, 6, 10, 33, 9, 2, 6)
dl2080 commented 3 years ago

The workaround using rtc.init(rtc.now()) only works in the above special case. When the clock is initialized with an external source as rtc.init((2021, 1, 7, 11, 36, 57, 3, 0)) before, the workaround is not working. There is another bug (or maybe the same?) in r3 with respect to rc10 which doesn't allow the RTC clock time to be changed after initialization:

(1) RTC init in rc10 with a time; change to other time works

>>> rtc.init((2021, 1, 7, 11, 36, 57, 3, 0))
>>> rtc.now()
(2021, 1, 7, 11, 36, 58, 533913, None)
>>> rtc.init((2023, 1, 7, 11, 36, 57, 3, 0))
>>> rtc.now()
(2023, 1, 7, 11, 36, 58, 751604, None)

(2) RTC init in r3 with a time; change to other time DOES NOT work

>>> rtc.init((2021, 1, 7, 12, 13, 37, 3, 0))
>>> rtc.now()
(2021, 1, 7, 12, 13, 38, 881184, None)
>>> rtc.init((2023, 1, 7, 12, 13, 37, 3, 0))
>>> rtc.now()
(2021, 1, 7, 12, 13, 44, 814870, None)

(The year is changed from 2021 to 2023 in the examples)

amotl commented 3 years ago

Hi there,

within the release v.1.20.2.r4 (#514), which just happened, the problem described here may have been fixed. See also 120f929b. Thanks, @gijsio and @peter-pycom!

With kind regards, Andreas.

cc @didilamken

robert-hh commented 3 years ago

Yup. Looks better now.

peter-pycom commented 3 years ago

Indeed, it should be fixed with latest release 1.20.2.r4 - please retest.

dl2080 commented 3 years ago

I confirm the issue is solved. Great work! Thank you!