RTC clock sync breaks async loop timer

[zzfjean]

Hey guys - love the work on this, been transitioning to Async code for the last 6 months and loving the stability vs. multithreading on Pycom G01.

I'm having a really strange issue though with pretty simple async code that has only recently popped up. Following is my test function - start a async loop and run a function forever.

import uasyncio as asyncio
from _connections import Connections
connect = Connections(None)
loop = asyncio.get_event_loop()
loop.create_task(connect.pybytes_sender(1000)) #data sending, interval in seconds 
loop.run_forever()  

In this function I connect to LTE or Wifi (either has same behaviour). Once connected I call a function to sync with ntp:

  async def time_sync(self,conmode):
      timer = time.ticks_ms()
      while not self.rtc.synced():
          self.rtc.ntp_sync('time.google.com')
          print("Syncing clock")
          if time.ticks_ms() - timer > timeout: break
          await asyncio.sleep(3)
      if self.rtc.synced(): 
          self.isconnected = True
          log.info('RTC Sync: ' + str(self.rtc.now()))
      return

The issue is that as soon as the clock syncs from rtc.ntp_sync the asyncio.sleep line hangs forever and all other loops also stop.

I've worked through this many different ways - using ntptime.py (micropython) has the same effect, as soon as I update the internal clock the async.sleep calls either hang forever or are completely ignored. I've updated from V2 to V3 with no difference.

I'm guessing there may be a time reference change when the clock is synced - i.e. we jump far into the past or future and the timer doesn't adjust with this time change? Its the only thing I can think would explain the behaviour.

All my code runs as expected without syncing the internal clock.

Any ideas? Help would be greatly appreciated.

[peterhinch]

You haven't mentioned which hardware platform you are using. Both V2 and V3 of uasyncio get their time reference from the utime module. So if, on your platform, utime.localtime() changes when you set the RTC, then uasyncio will have its timing thrown out. An option would be to set the RTC using synchronous code before starting uasyncio.

[kevinkk525]

Micropython uasyncio uses utime.ticks_ms() for timing and is therefore unaffected by changes in utime.localtime() as this is a hardware counter: https://github.com/micropython/micropython/blob/7408ca1d7857df5ea348da35c9ee12f70a024478/extmod/uasyncio/core.py#L4

Therefore, I have never seen such behaviour (on eps32,esp8266,pyboard-D). What platform are you using?

[peterhinch]

@kevinkk525 You are right - as confirmed by experiment on a Pyboard. Odd that utime uses different references for ticks_ms and localtime.

[zzfjean]

Micropython uasyncio uses utime.ticks_ms() for timing and is therefore unaffected by changes in utime.localtime() as this is a hardware counter: https://github.com/micropython/micropython/blob/7408ca1d7857df5ea348da35c9ee12f70a024478/extmod/uasyncio/core.py#L4

Therefore, I have never seen such behaviour (on eps32,esp8266,pyboard-D). What platform are you using?

Thanks for the ideas, I'm running the Pycom G01 (GPY) ESP32 core. I'm going to try @peterhinch's idea of syncing time before I start uasyncio and report back.

The strange thing is - I can swear I had this working and it has only recently become an issue (Pycom 1.20.4). However if I remove all other code and only execute the single coro its now consistently replicable. When I first moved from uasyncio V2 to V3 I thought it resolved the issue, however it had only changed the behaviour from ignoring the asyncio.sleep to breaking other coro's or hanging.

[peterhinch]

I didn't realise you're running PyCom firmware. I have no knowledge of this. It is possible that PyCom are using a different timing mechanism, and that this aspect may have changed between releases.

If you can produce a simple test case I would suggest raising an issue against their firmware.

As a general point, it's better for everyone if issues like this are raised in the forum. GitHub is a bug tracker, and this issue doesn't represent a bug in my code or an error in my docs. From your point of view, a query in the forum will be seen by more people and perhaps elicit a more knowledgeable response.