krahabb / meross_lan

Home Assistant integration for Meross devices
MIT License
443 stars 47 forks source link

Incorrect timestamp: -196 seconds behind HA #397

Closed frabar55 closed 7 months ago

frabar55 commented 8 months ago

Hi Team, after the upgrade to last version I received, for all the devices, the following error:

"Questo errore ha avuto origine da un'integrazione personalizzata.

Logger: custom_components.merosslan.mss310###############################7 Source: custom_components/meross_lan/helpers/init.py:246 Integration: Meross LAN (documentation, issues) First occurred: 10:04:21 (1 occurrences) Last logged: 10:04:21

Incorrect timestamp: -196 seconds behind HA"

-->

Version of the custom_component

component ver. 5.0.0 HA ver: 2024.2.4

Thanks & Regards

krahabb commented 8 months ago

Hello @frabar55, This shouldn't be related to Moonlight since the check (and logging) was done in previous versions too. Since devices have their 'own' time epoch (which they usually read from a public NTP server) this warning log is just an hint for something which is unexpected (in fact it is only logged when the difference between HA time and device time is more than 5 seconds). Keep in mind the wrong time might be the HA one (which itself, as a computer, gets its time from the internet). So it might be due to a transient failure in reading the internet time. We'll see if it needs more attention: so far it doesn't look like being a real bug in meross_lan. Further logs (this check is done at start and then after a pretty long timeout) might tell us if this 'soft failure' persists or not since both HA and the device should periodically refresh their time.

purcell-lab commented 8 months ago

I am also starting to see these which then get reported as repairs regarding timezones for my various Meross devices.

This error originated from a custom integration.

Logger: custom_components.meross_lan.mss310_###############################2
Source: custom_components/meross_lan/helpers/__init__.py:246
integration: Meross LAN (documentation, issues)
First occurred: 5:30:51 AM (3 occurrences)
Last logged: 6:14:56 AM

Incorrect timestamp: 1709235048 seconds behind HA
Error('AEST') while using pytz to build timezone(AEST)
Error('No time zone found with key AEST') while building timezone(AEST) info for Appliance.System.Time
This error originated from a custom integration.

Logger: custom_components.meross_lan.mss310_###############################3
Source: custom_components/meross_lan/helpers/__init__.py:246
integration: Meross LAN (documentation, issues)
First occurred: 5:30:12 AM (5 occurrences)
Last logged: 5:33:32 AM

Unable to load timezone info for AEST - check your python environment
Appliance.Control.Multiple failed with no response: requests=4 expected size=3290
Appliance.Control.Multiple failed with no response: requests=4 expected size=3083
Appliance.Control.Multiple failed with no response: requests=3 expected size=2218
nicknol commented 7 months ago

I face a similar issue:

Logger: custom_components.meross_lan
Source: custom_components/meross_lan/helpers.py:166

MerossDevice(Garage Restra): incorrect timestamp: 6 seconds behind HA

Time on HA is the same as e.g. my desktop computer and my mobile phone. => any idea how to edit the time on the Meross device? (Till now I only found how/where to change the timezone)

krahabb commented 7 months ago

Devices get the time autonomously through querying an internally configured NTP server. It looks as though this 'desynchronization' is hitting strongly lately so either some of these NTP servers are 'falling apart' (which I really doubt) or there's something in meross_lan/HA leading to this warning. I'll give it a check but the only actually meaningful reason for this to happen (provided both HA and device time are correct) is that message processing is being delayed for about the delay reported (i.e. 6 seconds)

In other words, the device time was correct but when meross_lan did the check against HA time, 6 seconds were already passed since message generation at the device (which seems like the instance running HA is a bit 'overwhelmed' to say the least)

nicknol commented 7 months ago

@krahabb you mentioned, that you check the time difference only during startup. And the HA instance or the host system might be pretty busy during startup. In my case there are a lot of integrations to be started, but during normal times my system has a CPU load between 2 and 3%.

What about checking the time difference some time after the start of HA?

krahabb commented 7 months ago

I don't remember stating that this check is done only at boot (but I'm pretty confused lately ;) If I did it, that's an error since the check is done on every incoming message from the device.

Nevertheless, having a sort of 'grace period' and moreover, averaging the time difference among multiple messages might be helpful in order to not log transient misalignments.

nicknol commented 7 months ago

You mentioned a bit above:

Further logs (this check is done at start and then after a pretty long timeout) might tell us

hence , I thought you do the checks during boot time.

Anyways, overall it should not be a big issue as long as the devices react on commands quickly :)

krahabb commented 7 months ago

yep..I confirm my state of confusion ;) Indeed, the check is done on every message but the log is only emitted now and then