Cron tasks triggering on UTC time, not local time
Cron tasks trigger on UTC time, not local time, on FreeNAS-9.10-STABLE, updated from 9.3.1-STABLE. This is a change in behaviour from 9.3.1, where they would trigger on local time.
The time zone is correctly set, and the time shows correctly in the GUI and in the CLI via the date command.
#5 Updated by Kevin Horton over 4 years ago
Sean Fagan wrote:
If you run date in the console, is it local or UTC?
In the console, date is local.
The difference between my situation and Chris Torek's test, as described, is that I updated from FN 9.3.1-STABLE, rather than stating with a new installation of FN-9.10.
I experimented a few minutes ago with two tasks to email me pool status and SMART info, and confirmed that the tasks are triggering at UTC time.
The lines in /etc/crontab for my two latest tests are:
15 09 * * * root PATH="/bin:/sbin:/usr/bin:/usr/sbin:/usr/local/bin:/usr/local/sbin:/root/bin" /root/bin/zpool_email.sh > /dev/null 16 09 * * * root PATH="/bin:/sbin:/usr/bin:/usr/sbin:/usr/local/bin:/usr/local/sbin:/root/bin" /root/bin/smart_email.sh > /dev/null
The email from those two tasks were received at 05:15 and 05:16 EST, but they show in the GUI and crontab as being defined at 09:15 and 09:16.
#6 Updated by Kevin Horton over 4 years ago
This may or may not be related, but on my system the time stamps in /var/log/messages have a mix of local and UTC time. E.g. shortly after the reboot following the update to FreeNAS-9.10-STABLE-201603252134:
Mar 26 15:19:40 freenas kernel: epair1b: link state changed to UP Mar 26 15:19:40 freenas kernel: epair1a: promiscuous mode enabled Mar 26 19:19:40 freenas devd: Executing '/etc/pccard_ether epair1b start' Mar 26 15:19:40 freenas rtsold: <rtsock_input_ifannounce> interface epair1b removed Mar 26 19:19:41 freenas devd: Executing '/etc/rc.d/dhclient quietstart epair1a' Mar 26 15:19:41 freenas kernel: ng_ether_ifnet_arrival_event: can't re-name node epair1b
I'm in North America, 4 hours west of UTC - the local time when that log sample was grabbed was 15:19. UTC was 19:19.
#7 Updated by Kevin Horton over 4 years ago
And now, after updating to FreeNAS-9.10-STABLE-201603252134 (and rebooting as required by the update), cron tasks are working on local time, as expected.
/var/log/messages and /var/log/debug.log have settled out to have all entries in local time for the last few hours. The last log entries in UTC time were roughly 90 minutes after the reboot.
#9 Updated by Chris Torek over 4 years ago
I bet something went wrong with one of those updates, during the time we had
/usr/local/etc kind of messed-up. Apparently the second update fixed it. It might have been interesting to see what
rcorder was spitting out while things were messed-up: I'm guessing that some daemons fired up before
/etc/localtime got created, and hence were running in UTC (and hence the mismatched syslog date stamps).
#10 Updated by Kevin Horton over 4 years ago
I still get the very occasional UTC date stamp in debug.log. devd is logging in UTC:
Mar 27 05:15:35 freenas alert.py: [middleware.notifier:214] Popen()ing: zpool get -H -o value version pool Mar 27 09:17:19 freenas devd: Pushing table Mar 27 09:17:19 freenas devd: Processing notify event Mar 27 09:17:19 freenas devd: Popping table Mar 27 05:20:36 freenas alert.py: [middleware.notifier:214] Popen()ing: zpool get -H -o value version pool
Perhaps cron was affected only until the reboot, but now devd is the problem child.
#12 Updated by Maarten Vanraes almost 4 years ago
I'm running "FreeNAS-9.10-STABLE-201606270534 (dd17351)". I have the same? (possibly different) issue?
I was setting up cron tasks to run at 00h 02m; but i found out this morning that the task is starting at 09:02 instead of 00:02. (the idea was something taking a few hours wasn't running during local daylight hours; but i confirmed it still running too. the logs show a date command which means it actually starts at 09:02).
These local times are all CEST (timezone is set correctly, and everything).
Since the server is at CEST (UTC+2), and it's a 9h difference, this would mean cron is running at UTC-7 ...
I wonder if it's dependant the timezone setting of the machine compiling cron...
perhaps when compiling the cron package, there's a setting that it uses the local time of the compiling machine instead of the local time of the machine running cron... either that, or when cron starts its UTC-7 ? and it's dependant on freenas timesettings at boot time before ntp and/or timezone settings?
#13 Updated by Maarten Vanraes almost 4 years ago
i'll note that i found (at the top of /var/log/messages)
sounds like time is reset at this time... is this during boot time?
I restarted cron service and will check if this "fixes" the problem (probably until next reboot)