Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Negative LLDP time #29

Open
wants to merge 3 commits into
base: master
Choose a base branch
from

Conversation

vasant17
Copy link

@vasant17 vasant17 commented Sep 11, 2020

If the passed in time string is negative, return 0 as delta time in lldp_syncd daemon.
This can happen when the system time is set to backwards.

If not handled the time.strptime() throws valueError exception

Traceback before the fix:

#12 -- #012Traceback (most recent call last):#12
File "/usr/local/lib/python2.7/dist-packages/lldp_syncd/daemon.py", line 249, in parse_update#012 str(parse_time(if_attributes.get('age')))})#12
File "/usr/local/lib/python2.7/dist-packages/lldp_syncd/daemon.py", line 45, in parse_time#012 struct_time = time.strptime(hour_min_secs, LLDPD_TIME_FORMAT)#12
File "/usr/lib/python2.7/_strptime.py", line 467, in _strptime_time#012 return _strptime(data_string, format)[0]#12
File "/usr/lib/python2.7/_strptime.py", line 325, in _strptime#012 (data_string, format))#012ValueError: time data u'-23:-41:-48' does not match format '%H:%M:%S'

Test failed before fix:

======================================================================
FAIL: test_timeparse (tests.test_lldpSyncDaemon.TestLldpSyncDaemon)

Traceback (most recent call last):
File "/sonic/src/sonic-dbsyncd/tests/test_lldpSyncDaemon.py", line 99, in test_timeparse
self.assertEquals(lldp_syncd.daemon.parse_time("2 days, -05:59:02"), make_seconds(2, 5, 59, 2))
AssertionError: 0 != 194342


After Fix:

Sep 10 01:45:45.000286 INFO systemd[1]: Time has been changed
Sep 10 01:45:45.001181 INFO systemd[1]: apt-daily.timer: Adding 3h 53min 53.818632s random time.
Sep 10 01:45:45.001855 INFO systemd[1]: apt-daily-upgrade.timer: Adding 3min 14.136467s random time.
Sep 10 01:45:45.178592 WARNING lldp#lldp-syncd [lldp_syncd] WARNING: Incorrect time -1:-44:-21, may be due to system time change?
Sep 10 02:30:35.864675 INFO systemd[1]: Time has been changed
Sep 10 02:30:35.865502 INFO systemd[1]: apt-daily.timer: Adding 10h 45min 44.371210s random time.
Sep 10 02:30:35.866817 INFO systemd[1]: apt-daily-upgrade.timer: Adding 38min 17.812520s random time.
Sep 10 02:30:37.251209 NOTICE syncd#syncd: :- threadFunction: span < 0 = -785 at 207544241993
Sep 10 02:30:37.251209 NOTICE syncd#syncd: :- threadFunction: new span = 635
Sep 10 02:30:40.054358 WARNING lldp#lldp-syncd [lldp_syncd] WARNING: Incorrect time 00:-59:-26, may be due to system time change?
Sep 10 02:55:35.866298 INFO systemd[1]: Time has been changed
Sep 10 02:55:35.867502 INFO systemd[1]: apt-daily.timer: Adding 1h 25min 48.243993s random time.
Sep 10 02:55:35.868579 INFO systemd[1]: apt-daily-upgrade.timer: Adding 39min 31.599616s random time.
Sep 10 02:55:37.226104 NOTICE syncd#syncd: :- threadFunction: span < 0 = -633 at 207554243085
Sep 10 02:55:37.226104 NOTICE syncd#syncd: :- threadFunction: new span = 352
Sep 10 02:55:40.064093 WARNING lldp#lldp-syncd [lldp_syncd] WARNING: Incorrect time 00:-34:-26, may be due to system time change?
Sep 10 03:10:35.864580 INFO systemd[1]: Time has been changed
Sep 10 03:10:35.865445 INFO systemd[1]: apt-daily.timer: Adding 10h 52min 1.501755s random time.
Sep 10 03:10:35.867558 INFO systemd[1]: apt-daily-upgrade.timer: Adding 17.350214s random time.

Test pass after fix:

vapatil@513367bce931:/sonic/src/sonic-dbsyncd/tests$ pytest -v
================================================================================= test session starts =================================================================================
platform linux2 -- Python 2.7.13, pytest-3.0.6, py-1.4.32, pluggy-0.4.0 -- /usr/bin/python
cachedir: ../.cache
rootdir: /sonic/src/sonic-dbsyncd, inifile:
plugins: cov-2.4.0
collected 9 items

test_lldpSyncDaemon.py::TestLldpSyncDaemon::test_loc_chassis PASSED
test_lldpSyncDaemon.py::TestLldpSyncDaemon::test_multiple_mgmt_ip PASSED
test_lldpSyncDaemon.py::TestLldpSyncDaemon::test_parse_json PASSED
test_lldpSyncDaemon.py::TestLldpSyncDaemon::test_parse_short PASSED
test_lldpSyncDaemon.py::TestLldpSyncDaemon::test_parse_short_short PASSED
test_lldpSyncDaemon.py::TestLldpSyncDaemon::test_remote_sys_capability_list PASSED
test_lldpSyncDaemon.py::TestLldpSyncDaemon::test_single_mgmt_ip PASSED
test_lldpSyncDaemon.py::TestLldpSyncDaemon::test_sync_roundtrip PASSED
test_lldpSyncDaemon.py::TestLldpSyncDaemon::test_timeparse PASSED

============================================================================== 9 passed in 0.25 seconds ===============================================================================
vapatil@513367bce931:/sonic/src/sonic-dbsyncd/tests$ pytest

Copy link
Contributor

@pavel-shirshov pavel-shirshov left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

As comments also can you please update tests for this function?

@@ -43,9 +43,18 @@ def parse_time(time_str):
return sage;
}
:return: parsed age in time ticks (or seconds)
0 in case passed in string has negative time
due to setting system clock backwards
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can you please change this to
0 when invalid string was found in time_str

try:
struct_time = time.strptime(hour_min_secs, LLDPD_TIME_FORMAT)
except ValueError:
logger.warning("Incorrect time {}, did you change system time?".format(hour_min_secs))
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'd change the message to "Invalid time '{}'"

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sure, but I would like to to keep the possible cause of system time modification as that will be a pretty good hint to the debugger. Please suggest

Copy link
Author

@vasant17 vasant17 Sep 11, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

But I can change "did you change system time?", to "possibly system time changed?"

@pavel-shirshov pavel-shirshov self-assigned this Sep 11, 2020
@liushilongbuaa
Copy link
Contributor

/azp run Azure.sonic-dbsyncd

@azure-pipelines
Copy link

Commenter does not have sufficient privileges for PR 29 in repo sonic-net/sonic-dbsyncd

@liushilongbuaa
Copy link
Contributor

/azpw run Azure.sonic-dbsyncd

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

3 participants