rand256
commented
4 years ago Which firmware/valetudo version do you run?
Closed astrakid closed 4 years ago
rand256
commented
4 years ago Which firmware/valetudo version do you run?
astrakid
commented
4 years ago miio-client 3.3.9 Firmware Version 001898 valetudo 0.9.5.2
rand256
commented
4 years ago Works for me, though on 2020 fw.
Did you set timezone in Settings->Timers->Gear icon? It can be a bit confusing that applocale settings in Settings->Info shows base system timezone which is different from actual timezone manufacturer's software is using for cleaning.
astrakid
commented
4 years ago yes:
rand256
commented
4 years ago I'm running out of ideas. There was an issue with timezone before 0.9.5, but now it should work properly. And, as I've checked right now, it is: setting new schedule and waiting for it to run on the device working continuously as well as rebooting the device after setting the schedule - both run cleaning at the correct time for me with my non-GMT+0 timezone.
So, what else could I suggest?.. Is the correct time set on the device itself? It can be checked by logging on the device by SSH and running date command on the console.
astrakid
commented
4 years ago time and timezone on device are correct. scheduled cleaning today went fine (but issue appeared with scheduled zone cleaning). will keep an eye on it next week and give you an update. any way to have some logging enabled on the device?
rand256
commented
4 years ago It by default logs to /var/log/upstart/valetudo.log.
astrakid
commented
4 years ago tested today and it works. maybe it was necessary to set the timezone in zone-cleaning again (i set it to another timezone and then back to the correct one).
astrakid
commented
4 years ago thanks for your support.
astrakid
commented
4 years ago today the issue reappeared. timezone is still set correctly in settings/zome time schedule. on the device itself it is set correctly as well. log entries in upstart,log is 2 hours back:
root@rockrobo:/var/log/upstart# ls -l valetudo.log -rw-r----- 1 root root 374682 Jun 9 14:39 valetudo.log root@rockrobo:/var/log/upstart# tail -3 valetudo.log 2020-06-09T11:39:58.669Z Robot (re)connected 2020-06-09T12:09:58.669Z Robot (re)connected 2020-06-09T12:39:58.669Z Robot (re)connected root@rockrobo:/var/log/upstart#
rand256
commented
4 years ago Entries' dates in upstart log are always written in GMT regardless of chosen timezone. And upon starting scheduled zoned cleaning a new entry should be written to the log so you can check when exactly it happened.
astrakid
commented
4 years ago hm. yesterday the scheduled zone cleaning started again 2 hours too late. so i decided to change the scheduler to 2 hours earlier cleaning. and today it started 2 hours too early???
root@rockrobo:/var/log/upstart# grep -i schedul valetudo.log 2020-06-04T08:00:00.375Z scheduled zoned cleaning started [ 'ok' ] 2020-06-05T09:59:38.691Z scheduled zoned cleaning started [ 'ok' ] 2020-06-07T11:31:00.146Z scheduled zoned cleaning started [ 'ok' ] 2020-06-08T08:00:00.377Z scheduled zoned cleaning started [ 'ok' ] 2020-06-09T09:59:17.092Z scheduled zoned cleaning started [ 'ok' ] 2020-06-10T07:59:11.177Z scheduled zoned cleaning started [ 'ok' ] 2020-06-11T06:00:00.349Z scheduled zoned cleaning started [ 'ok' ] root@rockrobo:/var/log/upstart# date Thu Jun 11 11:31:28 CEST 2020
(now we have 11:34 - so correct timezone on device).
rand256
commented
4 years ago So it just randomly uses correct timezone and sometimes runs as it was plain GMT? Weird! Could you please try running this version of valetudo? It will write a bit more timers related debugging to the log.
astrakid
commented
4 years ago thanks, i have installed it and rebooted the device. will keep you informed about the results. thanks for your effort!
rand256
commented
4 years ago will keep you informed about the results
Any updates on this?
astrakid
commented
4 years ago yes.
today: scheduled ZONE cleaning, started 10.58 (???), planned for 09:00.
ESC[35m2020-06-16T08:52:49.663ZESC[39m Robot (re)connected ESC[35m2020-06-16T08:58:38.841ZESC[39m scheduled zoned cleaning started [ ESC[32m'ok'ESC[39m ]
rand256
commented
4 years ago Could you show the full valetudo.log from today?
astrakid
commented
4 years ago ESC[35m2020-06-16T01:35:00.627ZESC[39m Robot (re)connected
ESC[35m2020-06-15T23:54:01.320ZESC[39m Loading configuration file: /mnt/data/valetudo/config.json
ESC[35m2020-06-15T23:54:01.540ZESC[39m Dummycloud is spoofing 203.0.113.1:8053 on 127.0.0.1:8053
ESC[35m2020-06-15T23:54:01.544ZESC[39m Webserver running on port ESC[33m80ESC[39m
ESC[35m2020-06-15T23:54:06.479ZESC[39m Probed last id = 1001 using get_status (2 retries)
ESC[35m2020-06-15T23:54:06.578ZESC[39m scheduled zoned cleaning timezone set to Europe/Berlin
ESC[35m2020-06-15T23:54:06.689ZESC[39m created timer for scheduled zoned cleaning: K
astrakid
commented
4 years ago root@rockrobo:/var/log/upstart# cat /etc/timezone Europe/Berlin
rand256
commented
4 years ago Looks like in some unclear circumstances something's going terribly wrong in the cron module I've used. I replaced it with another one and made a new test build. Would it be better?
astrakid
commented
4 years ago will check that, thanks.
rand256
commented
4 years ago Nope, that won't help too. I think I found the cause of this issue: when the device reboots, at first it has wrong system time set, but it quickly synchronizes the time via NTP. The issue is that sometimes valetudo starts after the system had synced (results in schedule works ok), but sometimes it syncs later (which breaks the schedule).
It seems that both cron modules I've tried to use do fail when system time changes unexpectedly.
astrakid
commented
4 years ago ok,. i understand. but the recent version started exactly at the configured time, but wrong timezone:
35m2020-06-16T23:54:11.532ZESC[39m created timer for scheduled zoned cleaning: K
rand256
commented
4 years ago ESC[35m2020-06-16T23:54:11.532ZESC[39m created timer for scheduled zoned cleaning: Kche, WZ, Schlaf 0 9 1,2,3,4,5 Europe/Berlin ESC[35m2020-06-17T01:52:49.571ZESC[39m Robot (re)connected ESC[35m2020-06-17T01:52:50.424ZESC[39m tgBot: probeV6 finished with: v4
See, the timer was created at 2020-06-16T23:54, but telegram bot connected at 2020-06-17T01:52:50 like almost 2 hours later, but in fact there were less then a few minutes between these events. The only reason for this I think could be the change of system time after NTP synced it soon after the system nightly reboot. And I suppose this breaks available cron-like modules and make them run at the wrong time. Maybe they somehow can keep correct time but lose chosen timezone when system time changes... I don't know - it needs debugging those modules sources. Anyway I have no other ideas. Newer firmware with stripped down Ubuntu seems to be unaffected because it manages to sync time before valetudo starts, the older firmware has the issue from time to time - Internet connection quality may also matter...
The obvious fix for this is to add some delay before starting schedules, but it would be rather a workaround then a solution. So I decided to get rid completely of cron modules and replaced them with my own simple interval timer. Compared to those modules it works really dumb and straightforward, but due to the fact we have extremely simple schedules anyway then we probably don't need any complex approaches here. Here's a new test build. I really hope it would be the last for this issue.
astrakid
commented
4 years ago thanks a lot for another time! ;) i have just installed that release and will check that. will give you an update next week!
astrakid
commented
4 years ago looks quite good! thanks for your effort!
hi, i just switched from official valetudo to your fork. the timezone setting is set to "europe/berlin" (gmt+2) and i entered a new scheduled zone cleaning for 10am. it started two hours later, so i guess the timezone is not taken into account.