Posted on December 3, 2015 5:52 pm
 |  Asked by Mike Mike
 |  3582 views
RESOLVED
0
0
Print Friendly, PDF & Email

I’ve noticed the timezone shown in syslog entries does not change when summer time starts or ends.  Whatever value was correct at the time the timezone was configured remains forever (apparently).

If you drop into BASH, the value is correctly reflected.  It’s only in the syslog display that the value is not correct.

I’ve tried both EST5EDT and US/Eastern settings for timezone.  They both behave the same.

Here’s a sample:
2015 Dec 2 18:17:33 EDT {switch-name} Rib: bgp_recv: peer {IP address} (AS {ASN}): received unexpected EOF

Any clues?

0
Posted by Alexis Dacquay
Answered on December 3, 2015 8:59 pm

Hello Mike,

Could you please provide your  ”show version ”, ”show clock”  and ”sh run section clock”  outputs ? (omit any private NTP server IP/hostname/etc)

 

Regards,

0
Posted by Mike Mike
Answered on December 4, 2015 4:03 pm

Here is the requested output.  This is on a similar switch to the one originally cited, but this one is in our dev environment which means I have access to it right now.

I’ve included the last two lines of syslog which includes the timezone notation ”CDT” whereas it should be ”CST”.


2015 Dec 4 01:38:29 CDT dev-57-2 Mlag: %MLAG-6-INTF_ACTIVE: Local interface Port-Channel811 and peer interface Port-Channel811 are link up. MLAG 811 is active.
2015 Dec 4 01:38:29 CDT dev-57-2 Ebra: %LINEPROTO-5-UPDOWN: Line protocol on Interface Port-Channel811 (perf6bc2bb-new STT7692), changed state to up
dev-57-2(s1)#show version
Arista DCS-7508
Hardware version: 06.00
Serial number: HSH13345258
System MAC address: 001c.7344.5938

Software image version: 4.12.7
Architecture: i386
Internal build version: 4.12.7-1692483.EOS4127.1
Internal build ID: aae7a01c-f862-4897-aac7-5b9f890f5f1f

Uptime: 21 weeks, 6 days, 3 hours and 20 minutes
Total memory: 16023172 kB
Free memory: 12217264 kB

dev-57-2(s1)#show clock
Fri Dec 4 09:57:41 2015
Timezone: CST6CDT
Clock source: NTP server (170.137.4.35)
dev-57-2(s1)#show running-config section clock
clock timezone CST6CDT
dev-57-2(s1)#

Mike,
Could you clarify what time zone you want to be in ? your output shows CST6CDT. If you want to be on Eastern time with summer time influence when needed then you should just need to set EST5EDT.

If this is indeed what you did, then just an idea: could you swap to a different time zone (e.g. western time), check the logs (generate simply by going to config mode and out) in EOS CLI just temporarily before return to your timezone ?

Normally, EOS should automatically change with the summer / daylight saving time:

Arista#
Arista#bash zdump -v US/Eastern | grep 2015
US/Eastern Sun Mar 8 06:59:59 2015 UTC = Sun Mar 8 01:59:59 2015 EST isdst=0 gmtoff=-18000
US/Eastern Sun Mar 8 07:00:00 2015 UTC = Sun Mar 8 03:00:00 2015 EDT isdst=1 gmtoff=-14400
US/Eastern Sun Nov 1 05:59:59 2015 UTC = Sun Nov 1 01:59:59 2015 EDT isdst=1 gmtoff=-14400
US/Eastern Sun Nov 1 06:00:00 2015 UTC = Sun Nov 1 01:00:00 2015 EST isdst=0 gmtoff=-18000
Arista#
Arista#bash zdump -v US/Eastern | grep 2016
US/Eastern Sun Mar 13 06:59:59 2016 UTC = Sun Mar 13 01:59:59 2016 EST isdst=0 gmtoff=-18000
US/Eastern Sun Mar 13 07:00:00 2016 UTC = Sun Mar 13 03:00:00 2016 EDT isdst=1 gmtoff=-14400
US/Eastern Sun Nov 6 05:59:59 2016 UTC = Sun Nov 6 01:59:59 2016 EDT isdst=1 gmtoff=-14400
US/Eastern Sun Nov 6 06:00:00 2016 UTC = Sun Nov 6 01:00:00 2016 EST isdst=0 gmtoff=-18000
Arista#

(Alexis Dacquay at December 7, 2015 9:42 pm)

I have not tested with the 4.12.7 version that you run, but in my test the clock and syslog show correct timestamp:

Dec 8 04:44:23 s7011 Cli: %SYS-5-CONFIG_E: Enter configuration mode from console by admin on vty3 (192.168.1.250)
Dec 8 04:44:24 s7011 Cli: %SYS-5-CONFIG_I: Configured from console by admin on vty3 (192.168.1.250)

Arista#sh clock
Tue Dec 8 04:44:31 2015
Timezone: EST5EDT
Clock source: local

Arista#sh ver
Arista DCS-7010T-48
Hardware version: 00.01
Serial number: HSH14280184
System MAC address: 001c.738c.3eed

Software image version: 4.15.2F

(Alexis Dacquay at December 8, 2015 9:47 am)
0
Posted by Mike Mike
Answered on December 8, 2015 3:06 pm

Sorry, I was a little unclear about what I was posting.  The original issue was noted in one of our east-coast switches (and later confirmed with a number of others in the same location).  That is a ’production’ facility, though, and I have limited access during weekdays.  When I was requested to provide more information, I went to our ’dev’ site which is in the Central time zone.  I first confirmed the same issue was present there, then provided the requested displays.

To further clarify what I’m seeing, the system DOES reflect the correct time zone.  Only the syslog does not.  The syslog reflects whatever time zone was active at the time the timezone was configured; so if I were to change it right now, everything would be correct but next spring when summer time kicks back in it would be wrong.  I confirmed that behavior on a dev switch by changing the date; system time reflected the updated timezone, syslog did not.

One further clarification:  the TIME is correct, only the TIMEZONE displayed is incorrect, and thus misleading.

And, a low-priority side question: Is there any way to have this forum send an e-mail notification when there has been an update posted to my question?

0
Posted by Mike Mike
Answered on December 9, 2015 1:20 pm

For some reason my response didn’t post, I’ll try again.

The original post was from a production switch located out east.  Because it’s in the prod environment I only have weekend access to it.  The ’show’ commands were performed on a similar platform in our dev environment, to which I have full access.  The issue was confirmed on that switch as well.

The issue isn’t the time-of-day used by the machine, only the way it displays the timezone in syslog.  As far as I’m able to determine, all other processes present the timezone properly but syslog uses whatever value was in play at the time the timezone was last changed.  I can change the timezone, it will then display correctly, but when summer time kicks in again next spring the timezone will be incorrectly displayed although the time will be correct.  (I manually changed the date on the dev machine to verify that was the case.)

I also ran the ’bash zdump’ and received similar results.  But for some reason the syslog is being recalcitrant.


dev-switch(s1)#bash zdump -v US/Central | grep 201[56]
US/Central Sun Mar 8 07:59:59 2015 UTC = Sun Mar 8 01:59:59 2015 CST isdst=0 gmtoff=-21600
US/Central Sun Mar 8 08:00:00 2015 UTC = Sun Mar 8 03:00:00 2015 CDT isdst=1 gmtoff=-18000
US/Central Sun Nov 1 06:59:59 2015 UTC = Sun Nov 1 01:59:59 2015 CDT isdst=1 gmtoff=-18000
US/Central Sun Nov 1 07:00:00 2015 UTC = Sun Nov 1 01:00:00 2015 CST isdst=0 gmtoff=-21600
US/Central Sun Mar 13 07:59:59 2016 UTC = Sun Mar 13 01:59:59 2016 CST isdst=0 gmtoff=-21600
US/Central Sun Mar 13 08:00:00 2016 UTC = Sun Mar 13 03:00:00 2016 CDT isdst=1 gmtoff=-18000
US/Central Sun Nov 6 06:59:59 2016 UTC = Sun Nov 6 01:59:59 2016 CDT isdst=1 gmtoff=-18000
US/Central Sun Nov 6 07:00:00 2016 UTC = Sun Nov 6 01:00:00 2016 CST isdst=0 gmtoff=-21600
dev-switch(s1)#

0
Posted by Shine
Answered on December 10, 2015 1:53 am

Hi Mike,
I don’t have some infos, like if you’re using a remote syslog, but let me note some points.
Most of *nix systems use UTC, this also to avoid Daylight Saving Time issues as well. Probably this is the simplest solution.
Syslog messages doesn’t have information about timezones, then you will need a tuning in your syslog server to reflect the correct timezone. In the other hand, seems syslog daemon would not pick the correct timezone without a SIGHUP or even a complete daemon restart. This would be annoying, specially if you start to handle multiple timezones.
Maybe in this case using syslog-ng would be more advisable as syslog-ng messages has timezone information, but it’ll be only supported in the case of messages generated in syslog-ng format, otherwise it will be interpreted as UTC timezone.

HTH

The syslog in question is the LOCAL logging buffer. The same messages get sent out to the syslog server, but my main concern is the local buffer.

We use local timezones procedurally in all our equipment, as that provides an additional level of sanity checking to make certain we are outside local business hours before making any changes. It wouldn’t make sense to only configure Arista gear differently.

Each time zone has its own syslog server, so we don’t have any confusion with reports in any case. Our only concern is the cosmetic display of a misleading time zone in the buffer ed log.

(Mike Mike at December 10, 2015 5:15 pm)
0
Posted by Presidio Network
Answered on April 1, 2021 1:19 pm

In what sense is this matter resolved?
I have the same problem today in Software image version: 4.21.9M.
bash date shows the correct timezone for this date, but log timestamps have the wrong timezone.

LA-WILSH-RKB2-WC1#show logging 1
2021 Apr 1 09:00:13 EST LA-WILSH-RKB2-WC1 Lldp: %LLDP-5-NEIGHBOR_NEW: LLDP neighbor with chassisId 0013.c608.3152 and portId "eth2" added on interface Management1
LA-WILSH-RKB2-WC1#
LA-WILSH-RKB2-WC1#show clock
Thu Apr 1 09:14:48 2021
Timezone: EST5EDT
Clock source: NTP server (172.22.132.30)
LA-WILSH-RKB2-WC1#
LA-WILSH-RKB2-WC1#bash date
Thu Apr 1 09:14:53 EDT 2021
LA-WILSH-RKB2-WC1#

0
Posted by Aswin Baalachandar
Answered on April 21, 2021 5:27 pm

I was able to reproduce the reported behaviour in the same EOS version you're using (4.21.9M).

Aristaswitch(config)#clock timezone EST5EDT
Aristaswitch(config)#
Aristaswitch(config)#show clock
Sat Mar 13 20:50:35 2021
Timezone: EST5EDT
Clock source: NTP server (10.90.20.122)
Aristaswitch(config)#
Aristaswitch(config)#
Aristaswitch(config)#clock set 01:50:00 14 March 2021
Sun Mar 14 01:50:01 2021
Timezone: EST5EDT
Clock source: NTP server (10.90.20.122)
Aristaswitch(config)#show clock
Sun Mar 14 01:50:04 2021
Timezone: EST5EDT
Clock source: NTP server (10.90.20.122)

Aristaswitch(config)#logging format timestamp traditional year timezone
Aristaswitch(config)#
Aristaswitch(config)#
Aristaswitch(config)#show logging system 5
Mar 14 01:51:01 Aristaswitch CROND[6713]: (root) CMD (/usr/bin/archivecheck.py &> /dev/null)
Mar 14 01:51:28 Aristaswitch rsyslogd: [origin software="rsyslogd" swVersion="7.2.6" x-pid="3289" x-info="http://www.rsyslog.com"] exiting on signal 15.
2021 Mar 14 01:51:28 EST Aristaswitch rsyslogd: [origin software="rsyslogd" swVersion="7.2.6" x-pid="6778" x-info="http://www.rsyslog.com"] start
2021 Mar 14 01:51:28 EST Aristaswitch kernel: [ 2045.059645] systemd[1]: Starting System Logging Service...
2021 Mar 14 01:51:28 EST Aristaswitch kernel: [ 2045.060506] systemd[1]: Started System Logging Service.

Aristaswitch(config)#show logging system 5
2021 Mar 14 01:56:01 EST Aristaswitch CROND[7201]: (root) CMD (/usr/bin/archivecheck.py &> /dev/null)
2021 Mar 14 01:56:30 EST Aristaswitch xinetd[3801]: START: ssh pid=7272 from=10.83.13.12
2021 Mar 14 01:56:39 EST Aristaswitch xinetd[3801]: EXIT: ssh status=0 pid=7272 duration=9(sec)
2021 Mar 14 01:57:01 EST Aristaswitch CROND[7308]: (root) CMD (/usr/bin/archivecheck.py &> /dev/null)
2021 Mar 14 01:58:01 EST Aristaswitch CROND[7398]: (root) CMD (/usr/bin/archivecheck.py &> /dev/null)

Aristaswitch(config)#bash date
Sun Mar 14 01:58:55 EST 2021
Aristaswitch(config)#

Post change to EDT, log snippets still read EST (BUT shows the correct time though)

Aristaswitch(config)#show logging system 5
2021 Mar 14 03:00:01 EST Aristaswitch CROND[7572]: (root) CMD (sleep $[ ( $RANDOM % 1800 ) ]s && bash /mnt/flash/scripts/tftp-showtech)
2021 Mar 14 03:00:01 EST Aristaswitch CROND[7574]: (root) CMD (/usr/bin/archivecheck.py &> /dev/null)
2021 Mar 14 03:00:01 EST Aristaswitch CROND[7575]: (root) CMD (sleep $[ ( $RANDOM % 600 ) ]s && bash /mnt/flash/scripts/heartbeat)
2021 Mar 14 03:00:01 EST Aristaswitch CROND[7576]: (root) CMD (sleep $[ ( $RANDOM % 299 ) ]s && bash /mnt/flash/scripts/self-update)
2021 Mar 14 03:00:01 EST Aristaswitch CROND[7580]: (root) CMD (sleep $[ ( $RANDOM % 900 ) ]s && bash /mnt/flash/scripts/clibootstrap)

Workaround:

You can workaround this issue via either of the following ways.

1.) Setting the clock timezone to default, and reverting back to EST5EDT:

Aristaswitch(config)#show logging system 5
2021 Mar 14 03:04:25 EST Aristaswitch ntpd[8091]: Listening on routing socket on fd #20 for interface updates
2021 Mar 14 03:04:25 EST Aristaswitch ntpd[8091]: 0.0.0.0 c016 06 restart
2021 Mar 14 03:04:25 EST Aristaswitch ntpd[8091]: 0.0.0.0 c012 02 freq_set kernel 26.972 PPM
2021 Mar 14 03:04:34 EST Aristaswitch StpTxRx: %SPANTREE-4-RXDOT1QPKT: A non-standard IEEE BPDU packet was received and discarded on interface Ethernet34 (source mac 74:83:ef:6d:b8:b0). The packet was inconsistent with the IEEE standard, because it was encapsulated with an 802.1Q header. (message repeated 150 times in 302 secs)
2021 Mar 14 03:05:01 EST Aristaswitch CROND[8103]: (root) CMD (/usr/bin/archivecheck.py &> /dev/null)

Aristaswitch(config)#default clock timezone

Aristaswitch(config)#show logging system 5
2021 Mar 14 03:05:01 EST Aristaswitch CROND[8103]: (root) CMD (/usr/bin/archivecheck.py &> /dev/null)
2021 Mar 14 07:05:33 EST Aristaswitch rsyslogd: [origin software="rsyslogd" swVersion="7.2.6" x-pid="6778" x-info="http://www.rsyslog.com"] exiting on signal 15.
2021 Mar 14 07:05:33 UTC Aristaswitch rsyslogd: [origin software="rsyslogd" swVersion="7.2.6" x-pid="8194" x-info="http://www.rsyslog.com"] start
2021 Mar 14 07:05:33 UTC Aristaswitch kernel: [ 2890.340299] systemd[1]: Starting System Logging Service...
2021 Mar 14 07:05:33 UTC Aristaswitch kernel: [ 2890.341196] systemd[1]: Started System Logging Service.

Aristaswitch(config)#clock timezone EST5EDT

Aristaswitch(config)#show logging system 5
2021 Mar 14 07:05:33 UTC Aristaswitch kernel: [ 2890.341196] systemd[1]: Started System Logging Service.
2021 Mar 14 03:05:47 UTC Aristaswitch rsyslogd: [origin software="rsyslogd" swVersion="7.2.6" x-pid="8194" x-info="http://www.rsyslog.com"] exiting on signal 15.
2021 Mar 14 03:05:47 EDT Aristaswitch rsyslogd: [origin software="rsyslogd" swVersion="7.2.6" x-pid="8209" x-info="http://www.rsyslog.com"] start
2021 Mar 14 03:05:47 EDT Aristaswitch kernel: [ 2904.113700] systemd[1]: Starting System Logging Service...
2021 Mar 14 03:05:47 EDT Aristaswitch kernel: [ 2904.114522] systemd[1]: Started System Logging Service.

2.) Toggling the logging format command:

Aristaswitch(config)#show logging system 5
2021 Mar 14 03:00:01 EST Aristaswitch CROND[5658]: (root) CMD (/usr/bin/archivecheck.py &> /dev/null)
2021 Mar 14 03:00:01 EST Aristaswitch CROND[5660]: (root) CMD (sleep $[ ( $RANDOM % 299 ) ]s && bash /mnt/flash/scripts/self-update)
2021 Mar 14 03:00:01 EST Aristaswitch CROND[5662]: (root) CMD (sleep $[ ( $RANDOM % 1800 ) ]s && bash /mnt/flash/scripts/tftp-showtech)
2021 Mar 14 03:00:01 EST Aristaswitch CROND[5664]: (root) CMD (sleep $[ ( $RANDOM % 600 ) ]s && bash /mnt/flash/scripts/heartbeat)
2021 Mar 14 03:00:01 EST Aristaswitch CROND[5665]: (root) CMD (sleep $[ ( $RANDOM % 900 ) ]s && bash /mnt/flash/scripts/clibootstrap)

Aristaswitch(config)#no logging format timestamp traditional year timezone
Aristaswitch(config)#logging format timestamp traditional year timezone

Aristaswitch(config)#show logging system 5
2021 Mar 14 03:00:55 EDT Aristaswitch kernel: [ 708.322375] systemd[1]: Starting System Logging Service...
2021 Mar 14 03:00:55 EDT Aristaswitch rsyslogd: [origin software="rsyslogd" swVersion="8.2001.0" x-pid="5796" x-info="https://www.rsyslog.com"] exiting on signal 15.
2021 Mar 14 03:00:55 EDT Aristaswitch rsyslogd: imuxsock: Acquired UNIX socket '/dev/log' (fd 3) from systemd. [v8.2001.0]
2021 Mar 14 03:00:55 EDT Aristaswitch rsyslogd: [origin software="rsyslogd" swVersion="8.2001.0" x-pid="5824" x-info="https://www.rsyslog.com"] start
2021 Mar 14 03:00:55 EDT Aristaswitch kernel: [ 708.334210] systemd[1]: Started System Logging Service.

Note: We have created an internal bug (Bug ID: 578084) tracking this issue.

 

Post your Answer

You must be logged in to post an answer.