Scheduler - Nano ESP32 time and zone settings

[jonclow]

Hello. I am working at setting up a basic relay control that leverages a Scheduler, consumed on the hardware side by a Arduino Nano ESP32. I am having an issue with an incorrect offset being applied to the set time, and I am not sure where I am going wrong.

My understanding is that the board will sync with IoT Cloud on start, and set the internal RTC with relevant time information configured on my associated Thing - so no need to manually set time, offset, daylight changes etc.

Somehow the board is starting up with an initial setting of NZST (UTC +12), then applying a further +12 offset pushing its local time forward again. The end result seems to be that the Scheduler value is being set incorrectly.

Details:

• Scheduler configured for my local timezone Pacific/Auckland, currently +12
• Start time set for 2100 local
  
  

Expected that this would set the underlying CloudSchedule variable latest value to the same, given that other time values are displayed in local in the UI, however it is shown in UTC:

Having looked at some very similar posts, (in particular: Arduino Cloud Scheduler responding to UTC time instead of Local Time) it makes this seem like an issue with the time and offset configured on device start and sync with IoT Cloud. That issue solution resulted in the patch being merged and the board is different, so I have not tried to use the custom lib that was used there when debugging.

Looking at my Nano ESP32 and logging the times that were at issue in the linked thread, it looks as though the RTC is initially being set with NZST and not UTC, and then once connected and synced with IoT Cloud the (correct) received offset is applied again taking the local time forward to NZST +12 / UTC +24

setup and loop:

void setup() {
  Serial.begin(9600);
  delay(1500); 
  
  // thingProperties.h
  initProperties();
  // Connect to Arduino IoT Cloud
  ArduinoCloud.begin(ArduinoIoTPreferredConnection);
  setDebugMessageLevel(3);
  ArduinoCloud.printDebugInfo();
}

void loop() {
  ArduinoCloud.update();
  
  if(ArduinoCloud.connected()){
    Serial.print("Cloud Internal Time: ");
    Serial.println(ArduinoCloud.getInternalTime());
    Serial.print("Cloud Local Time: ");
    Serial.println(ArduinoCloud.getLocalTime());
  }
  
  delay(10000);
}

Output - run started 10 Sept, 2248 NZST

Connection to "IOT" failed
Retrying in "4000" milliseconds
Connected to "IOT"
TimeServiceClass::sync Drift: 0 RTC value: 1694342886

Cloud Internal Time: 1694342937
Cloud Local Time: 0

Cloud Internal Time: 1694342947
Cloud Local Time: 0

Cloud Internal Time: 1694342958
Cloud Local Time: 0

ArduinoIoTCloudTCP::handle_WaitDeviceConfig device waiting for valid thing_id
Cloud Internal Time: 1694342968
Cloud Local Time: 0

Cloud Internal Time: 1694342979
Cloud Local Time: 0

Cloud Internal Time: 1694342989
Cloud Local Time: 0

Cloud Internal Time: 1694342999
Cloud Local Time: 0

Connected to Arduino IoT Cloud
Thing ID: QWERTY
Cloud Internal Time: 1694343010
Cloud Local Time: 0

Cloud Internal Time: 1694343020
Cloud Local Time: 0

TimeServiceClass::setTimeZoneData offset: 43200 dst_unitl 1695477600
Cloud Internal Time: 1694343030
Cloud Local Time: 1694386230

If anyone can offer advice, that would be appreciated.

[pennam]

@jonclow thanks for the heads up, looking at your log i agree that the RTC is wrongly initialized with NZST and not UTC. I'll make some tests with my nano ESP32 and get back to you

[pennam]

@jonclow wait, i think i've messed up

The RTC is configured with 1694343030 that is Sun Sep 10 2023 10:50:30

the resulting local time is 1694386230 that is Sun Sep 10 2023 22:50:30

So the RTC configuration and offsets looks correct to me. I will check with the team why Last Value is in UTC.

[jonclow]

@pennam

1694386230

Thanks @pennam for taking a look at this, I really appreciate it.

I agree about the internal and local unix timestamps if we convert them both with zero offset, however I am not sure this is correct - the latter does not represent the same moment in time? And my appologies that I am making an assumption here that they should represent the same moment in time, could be way off track here:

• Cloud Internal Time: 1694343030 = Sun Sep 10 2023 10:50:30 GMT+0000 = Sun Sep 10 2023 22:50:30 GMT+1200 (New Zealand Standard Time)

That is a correct

• Cloud Local Time: 1694386230 = Sun Sep 10 2023 22:50:30 GMT+0000 = Mon Sep 11 2023 10:50:30 GMT+1200 (New Zealand Standard Time)

That is incorrect - it is the correct internal (UTC) time with the offset (TimeServiceClass::setTimeZoneData offset: 43200 dst_unitl 1695477600) added to it - making it a different point in time.

I appologise that I am making a few leaps and assumptions here as I have not taken the time to go and look at the IoTCloud libraries to see how these times and the offset are applied, and what exactly ArduinoCloud.getLocalTime() should be showing me - I am assuming that should just be a local representation of the internal time unix stamp, and perhaps that is what is skewing the Scheduler?

Thanks again for looking at this.

Jon

[pennam]

Hi @jonclow, if you take a look at this lines of code i'm sure you will get how CloudInternalTime and CloudLocalTime are intended.

• CloudinternalTime is the UTC time, it is readed from an NTP server and stored into the board RTC.

• CloudLocalTime is the CloudInternalTime + the configured timezone offset (12) + DST if any.

I agree with you that adding +12 to the CloudLocalTime makes it a different point in time, but you should not do it.

Regardless how the scheduler is represented in the last value, when you configure a scheduler in your dashboard the board will receive a point in time with the same logic of CloudInternalTime, (UTC+offset+dst). The board will compare this point in time with its CloudInternalTime. Doing so the offset and DST of you timezone are automatically taken in account.

Mattia

[jonclow]

Thanks for the links @pennam.

will receive a point in time with the same logic of CloudInternalTime, (UTC+offset+dst). The board will compare this point in time with its CloudInternalTime

Do you mean CloudLocalTime is used (offsets added)? In isActive(), the schedule active check comparison uses the instance frm without further addition of offsets, and local time (now), which has the offsets applied?

Grabbing the schedule value coming into the Dashboard GUI:

{
	"last_value": {
		"frm": 1694336400,
		"len": 3600,
		"msk": 3288334337,
		"to": 0
	}
}

{
	"thing_timezone": {
		"name": "Pacific/Auckland",
		"offset": 43200,
		"until": "2023-09-23T14:00:00Z"
	}
}

isActive() continues to return true 12 hours offset to the time set in the Scheduler widget. I checked that it is consistent by changing the set time to 0900NZST in the Dash and observing that the board reacted at 2100NZST.

Given there is not a lot of noise, I will go and look for where I may have broken my Thing config, try setting up in a different browser etc etc.

Any ideas you have will be greatly appreciated.

Jon

[pennam]

sorry @jonclow my previous explanation was wrong. This timezone stuff is making me crazy.

Regardless how the scheduler is represented in the last value, when you configure a scheduler in your dashboard the board will receive a point in time with the same logic of CloudLocalTime, (UTC+offset+dst). This value is stored in the frm field.

The scheduler will compare this point in time with its now value, that comes from TimeService.getLocalTime() and has again the logic of CloudLocalTime (UTC+offset+dst).

Doing so the offset and DST of you timezone are automatically taken in account.

I will also make some tests with my NANO ES32 and get back to you.

[pennam]

@jonclow i've done some tests a couple of days ago and everything is working as expected. Did you manage do re-test your thing?

[jonclow]

Hi @pennam, thanks for getting back to me. No luck on my side I am afraid, I checked the thing config but my schedule remains active 12 hours offset to the time set in the scheduler widget in the dashboard. I have been busy on other tasks lately, but will come back and go through setup again.

[pennam]

That is strange. I've done a small video to show how i'm testing things from my side. Hope that helps to spot the issue.

recording.zip (5.1 MB)

[jonclow]

Thanks for that. I have quickly setup a new thing, single cloud schedule var and a dash with scheduler widget as a bare bones repro (though I am re-using the same esp32 device), and screen recorded so its a close comparison.

You can see that in a daily schedule cycle, isActive() returns true 12 hours offset to my local. But a new discovery is that where I set the schedule cycle to hourly, isActive() returns true both in local and UTC.

jonclow_schedule_test_lr.zip (6.3 MB)

[pennam]

Thanks @jonclow i'll re- test with your settings and let you know

[xufengming]

I am working on my project with esp32c3 board in China, it has exactly same story.
ArduinoCloud.getInternalTime() shows Beijing time(GMT +0800) not UTC，ArduinoCloud.getLocalTime() shows 8 hours ealier than Beijing time (GMT +1600).

for example. after converted timestamp to date and time.
1, The time displayed on my computer is 15:30，Sept, 27th
2, ArduinoCloud.getInternalTime() value the same to above.
3, ArduinoCloud.getLocalTime() value is 23:30, Sept, 27th
4. Time zone in scheduler is Asia/Hongkong(GMT +0800).
Scheduler will be active when the time is the value of "ArduinoCloud.getLocalTime()".

BTW, I compiled sketch with Arduino IDE 2.2.1, not web editor.

[pennam]

@xufengming @jonclow we have reproduced the issue i will uodate you as soon as we release a fix.

[bigdingo]

Hi @pennam, @jonclow

This issue has re-appeared for me again but now the scheduler is responding 10 hours late, how can I best help you sort this out?

Best,

M

[pennam]

@xufengming @jonclow @bigdingo
we have released a fix, can you plese reconfigure your schedulers from the dashboard widget and check again?

Thanks

[simontandem]

As far for me it works!
Thank you very much

[jonclow]

Thanks @pennam - has solved the issue for me.

Jon