Check_reload_status syslog timestamps wrong (UTC)

doktornotor

As referenced here:
http://forum.pfsense.org/index.php?topic=62911.0
http://forum.pfsense.org/index.php?topic=50212.0

the timestamps are persistently two hours behind - the timezone is CEST (GMT+2), these log entries are UTC. (No, I have not changed timezone at all and this happens always, even after days of uptime, not just on boot.)

EDIT: Another one, the other way round: http://forum.pfsense.org/index.php/topic,65773.msg357904.html#msg357904 (check_reload_status correct local time, all the rest wrong UTC).

Slam

Thanks for confirming this issue & preempting silly questions!

jimp

Curious that I can never seem to reproduce this one no matter what I do. My timestamps are always correct from check_reload_status and such.

My BIOS clock is set to local time, though, not UTC.

For example:

Aug 26 13:24:35 	php: rc.newwanipv6: ROUTING: setting IPv6 default route to fe80::200:24ff:xxxx:xxxx%xx1
Aug 26 13:24:37 	check_reload_status: Reloading filter
Aug 26 13:24:38 	dhcp6c[20382]: update_ia: T1(2250) and/or T2(3600) is locally determined

My ALIX doesn't have an RTC battery so it gets/sets its clock via NTP at boot each time, so it isn't like it needs to boot up with the right clock time either.

Which exact time zone choice did you use? If you used one that actually says CEST, choose instead one that is geographically named for a city in the time zone you're after.

We have seen problems like with with the GMT offset zones and with some of the "plain" zones such as EST now and then.

doktornotor

The timezone is Europe/Prague.

jimp

I set my ALIX to Europe/Prague, rebooted, and it seems fine for me…

Aug 27 03:28:34 	kernel: glxsb0: <amd geode="" lx="" security="" block="" (aes-128-cbc,="" rng)="">mem 0xefff4000-0xefff7fff irq 9 at device 1.2 on pci0
Aug 27 03:28:34 	check_reload_status: Linkup starting vr1
Aug 27 03:28:35 	kernel: vr1: link state changed to DOWN
...
Aug 27 03:29:09 	php: rc.start_packages: Restarting/Starting all packages.
Aug 27 03:29:09 	check_reload_status: Reloading filter</amd>

So kernel, PHP, and check_reload_status all agree on the timestamps here. Not sure why it would be off by that much for you.

athurdent

Same problem here:

Aug 27 00:00:30 vpn php: rc.newwanip: pfSense package system has detected an ip change 92.x.x.x ->  78.x.x.x ... Restarting packages.
Aug 26 22:00:30 vpn check_reload_status: Starting packages
Aug 26 22:00:30 vpn check_reload_status: Reloading filter
Aug 27 00:00:32 vpn php: rc.newipsecdns: IPSEC: One or more IPsec tunnel endpoints has changed its IP. Refreshing.

It's a NanoBSD install, not on an ALIX though (Lanner device).
Timezone is Europe/Berlin and it uses de.pool.ntp.org as NTP server.
Last reboot was when I upgraded to a newer RC1 release.

Slam

@jimp:

I set my ALIX to Europe/Prague, rebooted, and it seems fine for me…

Please test it by doing a firmware upgrade then have a look at the time stamp after it boots up, this problem doesnt affect subsequent boots afterwards, at least for me.

edit: btw my timezone is London/Europe….pfsense 2.1 i386 4Gb on Alix 2c2 (no RTC clock).

jimp

OK I was able to reproduce it that way. I'm still not sure why it never happened to me on my local timezone.

I checked in a fix, hopefully the next update that includes the fix will behave better.

Slam

Thanks for looking in to this, your fix seems to have done the job with latest firmware upgrade!

jimp

My ALIX seems to be OK post-update now also. Hopefully that solves it for everyone.

doktornotor

Yay, fixed now!