From 987100333aaf1c4a9900a2103c05c2a450b180eb Mon Sep 17 00:00:00 2001 From: Christian Hopps Date: Sat, 7 Sep 2024 07:09:27 -0400 Subject: [PATCH 1/2] tests: optionally pass `seconds_left` to retrying functions This allows retrying functions to possibly change their logging level for diagnostics. In order to maintain backward compatibility with this longstanding function we catch the specific exception of it not being handled by the retrying function and call again w/o the argument. Signed-off-by: Christian Hopps --- tests/topotests/lib/common_config.py | 10 ++++++++-- 1 file changed, 8 insertions(+), 2 deletions(-) diff --git a/tests/topotests/lib/common_config.py b/tests/topotests/lib/common_config.py index e856c23d36..540a627c65 100644 --- a/tests/topotests/lib/common_config.py +++ b/tests/topotests/lib/common_config.py @@ -1847,7 +1847,13 @@ def retry(retry_timeout, initial_wait=0, expected=True, diag_pct=0.75): while True: seconds_left = (retry_until - datetime.now()).total_seconds() try: - ret = func(*args, **kwargs) + try: + ret = func(*args, seconds_left=seconds_left, **kwargs) + except TypeError as error: + if "seconds_left" not in str(error): + raise + ret = func(*args, **kwargs) + logger.debug("Function returned %s", ret) negative_result = ret is False or is_string(ret) @@ -1868,7 +1874,7 @@ def retry(retry_timeout, initial_wait=0, expected=True, diag_pct=0.75): return saved_failure except Exception as error: - logger.info("Function raised exception: %s", str(error)) + logger.info('Function raised exception: "%s"', repr(error)) ret = error if seconds_left < 0 and saved_failure: From 956edf6fbf4956d8979bb8c18f784b2b509606bf Mon Sep 17 00:00:00 2001 From: Christian Hopps Date: Sat, 7 Sep 2024 07:12:05 -0400 Subject: [PATCH 2/2] tests: log json diff output at debug level while retrying Signed-off-by: Christian Hopps --- tests/topotests/mgmt_oper/oper.py | 20 +++++++++++--------- 1 file changed, 11 insertions(+), 9 deletions(-) diff --git a/tests/topotests/mgmt_oper/oper.py b/tests/topotests/mgmt_oper/oper.py index 9fc504569d..f54e64ae18 100644 --- a/tests/topotests/mgmt_oper/oper.py +++ b/tests/topotests/mgmt_oper/oper.py @@ -63,7 +63,7 @@ def disable_debug(router): @retry(retry_timeout=30, initial_wait=1) -def _do_oper_test(tgen, qr): +def _do_oper_test(tgen, qr, seconds_left=None): r1 = tgen.gears["r1"].net qcmd = ( @@ -80,6 +80,8 @@ def _do_oper_test(tgen, qr): expected = open(qr[1], encoding="ascii").read() output = r1.cmd_nostatus(qcmd.format(qr[0], qr[2] if len(qr) > 2 else "")) + diag = logging.debug if seconds_left else logging.warning + try: ojson = json.loads(output) except json.decoder.JSONDecodeError as error: @@ -92,31 +94,31 @@ def _do_oper_test(tgen, qr): logging.error( "Error decoding json exp result: %s\noutput:\n%s", error, expected ) - logging.warning("FILE: {}".format(qr[1])) + diag("FILE: {}".format(qr[1])) raise if dd_json_cmp: cmpout = json_cmp(ojson, ejson, exact_match=True) if cmpout: - logging.warning( + diag( "-------DIFF---------\n%s\n---------DIFF----------", pprint.pformat(cmpout), ) else: cmpout = tt_json_cmp(ojson, ejson, exact=True) if cmpout: - logging.warning( + diag( "-------EXPECT--------\n%s\n------END-EXPECT------", json.dumps(ejson, indent=4), ) - logging.warning( + diag( "--------GOT----------\n%s\n-------END-GOT--------", json.dumps(ojson, indent=4), ) - logging.warning("----diff---\n{}".format(cmpout)) - logging.warning("Command: {}".format(qcmd.format(qr[0], qr[2] if len(qr) > 2 else ""))) - logging.warning("File: {}".format(qr[1])) - assert cmpout is None + diag("----diff---\n{}".format(cmpout)) + diag("Command: {}".format(qcmd.format(qr[0], qr[2] if len(qr) > 2 else ""))) + diag("File: {}".format(qr[1])) + return cmpout def do_oper_test(tgen, query_results):