Author
Message
johnnyNobody999 DD-WRT Guru Joined: 10 Jan 2014 Posts: 504
Posted: Sat Jun 27, 2020 15:22 Post subject: syslog question about time stamps
Why does my router log some actions in UTC and some in local time? For example, I'll get log entries in UTC and then get log entries that are 6 hours earlier (local time) and then resume logging in UTC and at some point start logging in local time and back to UTC. This has been happening over multiple firmware and I'm just getting around to asking about it since a web search hasn't produced an answer. Router is an R7800 but I've seen this happen on the WRT1900ACS and WRT3200ACM also.
Back to top
Sponsor
Per Yngve Berg DD-WRT Guru Joined: 13 Aug 2013 Posts: 6870 Location: Romerike, Norway
Posted: Sat Jun 27, 2020 17:49 Post subject:
The only shift I see is the "Jan 01" until the clock is set and then the correct time.
Are you updating time from different NTP servers with different local time?
Back to top
mrjcd DD-WRT Guru Joined: 31 Jan 2015 Posts: 6291 Location: Texas
Posted: Sat Jun 27, 2020 18:53 Post subject: Re: syslog question about time stamps
johnnyNobody999 wrote: router log some actions in UTC and some in local time?
all good on EA8500 ...you must be doing sompin weird... Code: Dec 31 18:00:33 Citadel-Station-Homeworld user.info wsdd2[3609]: starting.
Dec 31 18:00:33 Citadel-Station-Homeworld user.info : smbd : samba started
Dec 31 18:00:33 Citadel-Station-Homeworld local5.info ksmbd: [ksmbd-manager/3614]: INFO: Unlink orphaned '/tmp/ksmbd.lock'
Dec 31 18:00:33 Citadel-Station-Homeworld daemon.info mstpd[739]: MSTP_OUT_set_ageing_time: br1:ath0.1 Setting new ageing time to 300
Dec 31 18:00:33 Citadel-Station-Homeworld user.info wsdd2[3656]: starting.
Dec 31 18:00:33 Citadel-Station-Homeworld user.info : smbd : samba started
Dec 31 18:00:33 Citadel-Station-Homeworld local5.info ksmbd: [ksmbd-manager/3660]: INFO: File '/tmp/ksmbd.lock' belongs to pid 3614
Dec 31 18:00:33 Citadel-Station-Homeworld local5.err ksmbd: [ksmbd-manager/3660]: ERROR: Failed to create lock file: File exists
Dec 31 18:00:33 Citadel-Station-Homeworld daemon.err ntpclient[3197]: Failed resolving address to hostname 2.pool.ntp.org: Try again
Dec 31 18:00:33 Citadel-Station-Homeworld daemon.err ntpclient[3197]: Failed resolving server 2.pool.ntp.org: Network is down
Dec 31 18:00:33 Citadel-Station-Homeworld daemon.notice ntpclient[3197]: Network up, resolved address to hostname 212.18.3.19
Dec 31 18:00:33 Citadel-Station-Homeworld daemon.debug ntpclient[3197]: Connecting to 212.18.3.19 [212.18.3.19] ...
Jun 27 07:10:53 Citadel-Station-Homeworld daemon.info ntpclient[3197]: Time set from 212.18.3.19 [212.18.3.19].
Jun 27 07:10:53 Citadel-Station-Homeworld daemon.info process_monitor[3194]: cyclic NTP Update success (servers 2.pool.ntp.org 212.18.3.19 88.99.174.22)
Jun 27 07:10:53 Citadel-Station-Homeworld daemon.info hostapd: ath1.1: STA 04:d3:95:8e:de:90 IEEE 802.11: deauthenticated due to local deauth request
Jun 27 07:10:53 Citadel-Station-Homeworld daemon.info hostapd: ath0: STA 1c:3e:84:8d:15:99 WPA: group key handshake completed (RSN)
Jun 27 07:10:54 Citadel-Station-Homeworld daemon.info hostapd: ath0.1: STA a4:77:33:80:1a:ec MLME: auth request, signal -28 (Accepted)
Jun 27 07:10:54 Citadel-Station-Homeworld daemon.info hostapd: ath0.1: STA a4:77:33:80:1a:ec IEEE 802.11: authenticated
Jun 27 07:10:54 Citadel-Station-Homeworld daemon.info hostapd: ath0.1: STA a4:77:33:80:1a:ec MLME: assoc request, signal -28 (Accepted)
Jun 27 07:10:54 Citadel-Station-Homeworld daemon.info hostapd: ath0.1: STA a4:77:33:80:1a:ec IEEE 802.11: associated (aid 1)
Jun 27 07:10:54 Citadel-Station-Homeworld daemon.debug process_monitor[3194]: Restarting cron (time sync change)
Jun 27 07:10:54 Citadel-Station-Homeworld user.info : cron : daemon successfully stopped
Jun 27 07:10:54 Citadel-Station-Homeworld cron.info cron[3755]: (CRON) STARTUP (fork ok)
Jun 27 07:10:54 Citadel-Station-Homeworld user.info : cron : daemon successfully started
Jun 27 07:10:54 Citadel-Station-Homeworld daemon.debug process_monitor[3194]: Restarting unbound (time sync change)
Jun 27 07:10:54 Citadel-Station-Homeworld daemon.info hostapd: ath0.1: STA 08:9e:08:48:4a:7f MLME: auth request, signal -45 (Accepted)
Jun 27 07:10:54 Citadel-Station-Homeworld daemon.info hostapd: ath0.1: STA 08:9e:08:48:4a:7f IEEE 802.11: authenticated
Jun 27 07:10:54 Citadel-Station-Homeworld daemon.info hostapd: ath0.1: STA 08:9e:08:48:4a:7f MLME: assoc request, signal -44 (Accepted)
Jun 27 07:10:54 Citadel-Station-Homeworld daemon.info hostapd: ath0.1: STA 08:9e:08:48:4a:7f IEEE 802.11: associated (aid 2)
Jun 27 07:10:54 Citadel-Station-Homeworld user.info : unbound : daemon successfully stopped
Jun 27 07:10:54 Citadel-Station-Homeworld user.info : unbound : recursive dns resolver daemon successfully started
Jun 27 07:10:54 Citadel-Station-Homeworld daemon.debug process_monitor[3194]: Restarting unbound (time sync change)
Jun 27 07:10:54 Citadel-Station-Homeworld user.info : unbound : daemon successfully stopped
Jun 27 07:10:54 Citadel-Station-Homeworld user.info : unbound : recursive dns resolver daemon successfully started
Jun 27 07:10:54 Citadel-Station-Homeworld user.info : process_monitor : daemon successfully stopped
Jun 27 07:10:54 Citadel-Station-Homeworld daemon.info process_monitor[3194]: process_monitor : cleanup timers
Jun 27 07:10:54 Citadel-Station-Homeworld user.info : process_monitor : successfully started
Jun 27 07:10:54 Citadel-Station-Homeworld daemon.debug process_monitor[3770]: We need to re-update after 3600 seconds
Jun 27 07:10:54 Citadel-Station-Homeworld daemon.info process_monitor[3770]: process_monitor : set timer: 3600 seconds, callback: ntp_main()
takes 'bout extra 1 second to get time cause I am using:
Recursive DNS Resolving (Unbound)
'Server IP/Name' is left blank of course
Back to top
johnnyNobody999 DD-WRT Guru Joined: 10 Jan 2014 Posts: 504
Posted: Sun Jun 28, 2020 0:53 Post subject:
Per Yngve Berg wrote: The only shift I see is the "Jan 01" until the clock is set and then the correct time.
Are you updating time from different NTP servers with different local time?
Nope.
Back to top
johnnyNobody999 DD-WRT Guru Joined: 10 Jan 2014 Posts: 504
Posted: Sun Jun 28, 2020 1:57 Post subject: Re: syslog question about time stamps
mrjcd wrote: johnnyNobody999 wrote: router log some actions in UTC and some in local time?
all good on EA8500 ...you must be doing sompin weird...
Comments not helpful. It has nothing to do with NTP.
Back to top
kernel-panic69 DD-WRT Guru Joined: 08 May 2018 Posts: 14246 Location: Texas, USA
Back to top
johnnyNobody999 DD-WRT Guru Joined: 10 Jan 2014 Posts: 504
Posted: Sun Jun 28, 2020 3:05 Post subject:
kernel-panic69 wrote: I have not seen such behavior in months... or was that last year... whenever it was that tatsuya46 was bitching about the syslog timestamps. Is this happening on 43516?
I'm running 43320.
Back to top