From ac5b5be323188570c881d06c7aa0338e7b2f1336 Mon Sep 17 00:00:00 2001 From: Sidartha-CT Date: Wed, 22 Jul 2026 10:46:34 +0000 Subject: [PATCH 01/18] LFRequest.py : Capture response code and diagnostics summary for each request Signed-off-by: Sidartha-CT --- py-json/LANforge/LFRequest.py | 76 ++++++++++++++++++++++++----------- 1 file changed, 53 insertions(+), 23 deletions(-) diff --git a/py-json/LANforge/LFRequest.py b/py-json/LANforge/LFRequest.py index 981453541..df02f4e45 100644 --- a/py-json/LANforge/LFRequest.py +++ b/py-json/LANforge/LFRequest.py @@ -41,6 +41,8 @@ def __init__(self, url=None, self.debug = debug_ self.die_on_error = die_on_error_ self.error_list = [] + self.last_response_code = None + self.last_diagnostics = None # please see this discussion on ProxyHandlers: # https://docs.python.org/3/library/urllib.request.html#urllib.request.ProxyHandler @@ -185,6 +187,7 @@ def json_post(self, show_error=True, debug=False, die_on_error_=False, response_ try: resp = urllib.request.urlopen(myrequest) + self.last_response_code = getattr(resp, 'status', None) resp_data = resp.read().decode('utf-8') if debug or die_on_error_: self.logger.debug("----- LFRequest::json_post:128 debug: --------------------------------------------") @@ -208,18 +211,19 @@ def json_post(self, show_error=True, debug=False, die_on_error_=False, response_ return responses[0] except urllib.error.HTTPError as error: - print_diagnostics(url_=self.requested_url, - request_=myrequest, - responses_=responses, - error_=error, - debug_=debug) + self.last_response_code = error.code + self.last_diagnostics = print_diagnostics(url_=self.requested_url, + request_=myrequest, + responses_=responses, + error_=error, + debug_=debug) except urllib.error.URLError as uerror: - print_diagnostics(url_=self.requested_url, - request_=myrequest, - responses_=responses, - error_=uerror, - debug_=debug) + self.last_diagnostics = print_diagnostics(url_=self.requested_url, + request_=myrequest, + responses_=responses, + error_=uerror, + debug_=debug) if die_on_error_: exit(1) @@ -254,20 +258,21 @@ def get(self, method_='GET'): return myresponses[0] except urllib.error.HTTPError as error: - print_diagnostics(url_=self.requested_url, - request_=myrequest, - responses_=myresponses, - error_=error, - error_list_=self.error_list, - debug_=self.debug) + self.last_response_code = error.code + self.last_diagnostics = print_diagnostics(url_=self.requested_url, + request_=myrequest, + responses_=myresponses, + error_=error, + error_list_=self.error_list, + debug_=self.debug) except urllib.error.URLError as uerror: - print_diagnostics(url_=self.requested_url, - request_=myrequest, - responses_=myresponses, - error_=uerror, - error_list_=self.error_list, - debug_=self.debug) + self.last_diagnostics = print_diagnostics(url_=self.requested_url, + request_=myrequest, + responses_=myresponses, + error_=uerror, + error_list_=self.error_list, + debug_=self.debug) if self.die_on_error: exit(1) @@ -279,6 +284,10 @@ def getAsJson(self): def get_as_json(self, method_='GET'): responses = list() responses.append(self.get(method_=method_)) + # get() already stashes last_response_code from error.code on HTTPError; + # only overwrite it here when we actually have a response to read a status from + if responses[0]: + self.last_response_code = getattr(responses[0], 'status', None) if len(responses) < 1: if self.debug and self.has_errors(): self.print_errors() @@ -350,6 +359,21 @@ def plain_get(url_=None, debug_=False, die_on_error_=False, proxies_=None): def print_diagnostics(url_=None, request_=None, responses_=None, error_=None, error_list_=None, debug_=False): + """ + Log a diagnostic report for a failed request and return a one-line summary of it. + + Args: + url_: Requested url. + request_: The urllib Request object that was sent. + responses_: Responses collected so far for this request, if any. + error_: The caught urllib.error.HTTPError or URLError. + error_list_: Optional list to append LANforge X-Error-* messages to. + debug_: When True, log at debug level; error level otherwise. + + Returns: + A short one-line summary of the error (code/reason/X-Error-* headers), for callers + (like LFRequest._log_api_call plumbing) that want it in a lightweight log. + """ logger = logging.getLogger(__name__) # logger.error("LFRequest::print_diagnostics: error_.__class__: %s"%error_.__class__) # logger.error(pformat(error_)) @@ -395,6 +419,10 @@ def print_diagnostics(url_=None, request_=None, responses_=None, error_=None, er errors_list.append(" = = = = = = = = = = = = = = = =") logger.error("\n".join(errors_list)) + summary = "%s <%s> HTTP %s: %s" % (method, err_full_url, err_code, err_reason) + if xerrors and err_code != 404: + summary += " | " + "; ".join(xerrors) + if error_.__class__ is urllib.error.HTTPError: debug_list = [] debug_list.append("\n----- LFRequest: HTTPError: --------------------------------------------") @@ -425,11 +453,13 @@ def print_diagnostics(url_=None, request_=None, responses_=None, error_=None, er debug_list.append("------------------------------------------------------------------------") logger.debug("\n".join(debug_list)) - return + return summary if error_.__class__ is urllib.error.URLError: errors_list.append("\n----- LFRequest: URLError: ---------------------------------------------") errors_list.append("%s <%s> HTTP %s: %s" % (method, err_full_url, err_code, err_reason)) errors_list.append("------------------------------------------------------------------------") logger.error("\n".join(errors_list)) + + return summary # ~LFRequest From 70a81600cbc00c30663d6f49119058c7749401cd Mon Sep 17 00:00:00 2001 From: Sidartha-CT Date: Wed, 22 Jul 2026 10:46:34 +0000 Subject: [PATCH 02/18] api_logger.py : Add process-wide API call CSV logger Signed-off-by: Sidartha-CT --- lanforge_client/api_logger.py | 108 ++++++++++++++++++++++++++++++++++ 1 file changed, 108 insertions(+) create mode 100644 lanforge_client/api_logger.py diff --git a/lanforge_client/api_logger.py b/lanforge_client/api_logger.py new file mode 100644 index 000000000..6653b42a3 --- /dev/null +++ b/lanforge_client/api_logger.py @@ -0,0 +1,108 @@ +""" +Process-wide, opt-in CSV logging of LANforge API calls (GET/POST/PUT/DELETE), for +debugging a particular test run. + +Call configure_api_call_logging() once, near the start of a script; every API call +made afterward in the same process is then recorded automatically. +""" +import csv +import datetime +import json +import logging +import os +from typing import Any, Optional + +logger = logging.getLogger(__name__) + +# CSV header for API call logs with prefixed column names to avoid ambiguity across reports. +CSV_FIELDS = ['api_timestamp', 'api_method', 'api_url', 'api_status', 'api_response_code', + 'api_payload', 'api_error', 'api_diagnostics'] + +_logging_enabled = False +_log_filename = None + + +def configure_api_call_logging(enabled: bool, log_filename: Optional[str] = None) -> None: + """ + Enable or disable process-wide API-call logging. + + Args: + enabled: True to turn logging on, False to turn it off. + log_filename: Path to the CSV log file; defaults to ~/lf_api_calls.csv when not set. + + Returns: + None. + """ + global _logging_enabled, _log_filename + _logging_enabled = bool(enabled) + if not _logging_enabled: + return + _log_filename = log_filename or os.path.join(os.path.expanduser('~'), 'lf_api_calls.csv') + # start each run with a clean log file + try: + with open(_log_filename, 'w', newline='') as csv_file: + csv.writer(csv_file).writerow(CSV_FIELDS) + except Exception as x: + logger.debug("api_logger: unable to reset %s: %s" % (_log_filename, x)) + + +def is_enabled() -> bool: + """ + Check whether API-call logging is currently enabled. + + Returns: + True if logging is enabled, False otherwise. + """ + return _logging_enabled + + +def get_log_filename() -> Optional[str]: + """ + Get the path of the API-call log CSV file. + + Returns: + The log file path, or None if logging has not been configured. + """ + return _log_filename + + +def record_api_call(method: str, url: str, data: Optional[Any] = None, response_code: Optional[int] = None, + error: Optional[Exception] = None, diagnostics: Optional[str] = None) -> None: + """ + Append one CSV row for a json_get/json_post/json_put/json_delete call. No-op unless + configure_api_call_logging(enabled=True) was called first. + + Args: + method: "GET" | "POST" | "PUT" | "DELETE". + url: Requested url. + data: Payload sent (POST/PUT only). + response_code: HTTP status code returned by the call, if any. + error: Exception raised by the call, if any -- marks the entry as ERROR. + diagnostics: One-line summary from LFRequest.print_diagnostics(), if the call + went through a caught HTTPError/URLError (reason, X-Error-* headers, etc.) + + Returns: + None. + """ + if not _logging_enabled: + return + if error: + status = "ERROR" + elif response_code: + status = "OK" if 200 <= response_code < 300 else "ERROR" + else: + status = "UNKNOWN" + try: + with open(_log_filename, 'a', newline='') as csv_file: + csv.writer(csv_file).writerow([ + datetime.datetime.now().isoformat(), + method, + url, + status, + response_code if response_code is not None else 'No response_code', + json.dumps(data, default=str) if data is not None else 'No payload', + error, + diagnostics if diagnostics is not None else 'No diagnostics', + ]) + except Exception as x: + logger.debug("api_logger: unable to write %s: %s" % (_log_filename, x)) From 91b141994ee20e0ee79a8fdf900df693bf4e7a43 Mon Sep 17 00:00:00 2001 From: Sidartha-CT Date: Wed, 22 Jul 2026 10:46:34 +0000 Subject: [PATCH 03/18] lfcli_base.py : Record json_get/post/put/delete calls via api_logger Signed-off-by: Sidartha-CT --- py-json/LANforge/lfcli_base.py | 57 ++++++++++++++++++++++++++++++++++ 1 file changed, 57 insertions(+) diff --git a/py-json/LANforge/lfcli_base.py b/py-json/LANforge/lfcli_base.py index 34d4085a8..4982bf954 100644 --- a/py-json/LANforge/lfcli_base.py +++ b/py-json/LANforge/lfcli_base.py @@ -14,6 +14,7 @@ import re import logging import math +from typing import Any, Optional if sys.version_info[0] != 3: print("This script requires Python 3") @@ -25,6 +26,7 @@ LFRequest = importlib.import_module("py-json.LANforge.LFRequest") LFUtils = importlib.import_module("py-json.LANforge.LFUtils") Logg = importlib.import_module("lanforge_client.logg") +api_logger = importlib.import_module("lanforge_client.api_logger") logger = logging.getLogger(__name__) """ @@ -216,6 +218,25 @@ def log_set_filename(filename=None): # - END LOGGING - + def _log_api_call(self, method: str, url: str, data: Optional[Any] = None, response_code: Optional[int] = None, + error: Optional[Exception] = None, diagnostics: Optional[str] = None) -> None: + """ + Record one json_get/json_post/json_put/json_delete call via lanforge_client.api_logger. + + Args: + method: "GET" | "POST" | "PUT" | "DELETE". + url: Requested url. + data: Payload sent (POST/PUT only). + response_code: HTTP status code returned by the call, if any. + error: Exception raised by the call, if any. + diagnostics: One-line diagnostics summary, if the call went through a caught error. + + Returns: + None. + """ + api_logger.record_api_call(method=method, url=url, data=data, response_code=response_code, + error=error, diagnostics=diagnostics) + def json_post(self, _req_url, _data, debug_=False, suppress_related_commands_=None, response_json_list_=None): """ send json to the LANforge client @@ -227,6 +248,8 @@ def json_post(self, _req_url, _data, debug_=False, suppress_related_commands_=No :return: http response object """ json_response = None + _api_error = None + lf_r = None debug_ |= self.debug try: lf_r = LFRequest.LFRequest(url=self.lfclient_url, @@ -264,13 +287,20 @@ def json_post(self, _req_url, _data, debug_=False, suppress_related_commands_=No if debug_ and (response_json_list_ is not None): logger.debug(pprint.pformat(response_json_list_)) except Exception as x: + _api_error = x if debug_ or self.exit_on_error: logger.debug("json_post posted to %s" % _req_url) logger.debug(pprint.pformat(_data)) logger.debug("Exception %s:" % x) logger.debug(traceback.format_exception(Exception, x, x.__traceback__, chain=True)) if self.exit_on_error: + self._log_api_call("POST", _req_url, data=_data, + response_code=getattr(json_response, 'status', None) or getattr(lf_r, 'last_response_code', None), + error=_api_error, diagnostics=getattr(lf_r, 'last_diagnostics', None)) exit(1) + self._log_api_call("POST", _req_url, data=_data, + response_code=getattr(json_response, 'status', None) or getattr(lf_r, 'last_response_code', None), + error=_api_error, diagnostics=getattr(lf_r, 'last_diagnostics', None)) return json_response def json_put(self, _req_url, _data, debug_=False, response_json_list_=None): @@ -286,6 +316,8 @@ def json_put(self, _req_url, _data, debug_=False, response_json_list_=None): """ debug_ |= self.debug json_response = None + _api_error = None + lf_r = None try: lf_r = LFRequest.LFRequest(url=self.lfclient_url, uri=_req_url, @@ -302,13 +334,20 @@ def json_put(self, _req_url, _data, debug_=False, response_json_list_=None): if debug_ and (response_json_list_ is not None): pprint.pprint(response_json_list_) except Exception as x: + _api_error = x if debug_ or self.exit_on_error: logger.debug("json_put submitted to %s" % _req_url) logger.debug(pprint.pformat(_data)) logger.debug("Exception %s:" % x) logger.debug(traceback.format_exception(Exception, x, x.__traceback__, chain=True)) if self.exit_on_error: + self._log_api_call("PUT", _req_url, data=_data, + response_code=getattr(json_response, 'status', None) or getattr(lf_r, 'last_response_code', None), + error=_api_error, diagnostics=getattr(lf_r, 'last_diagnostics', None)) exit(1) + self._log_api_call("PUT", _req_url, data=_data, + response_code=getattr(json_response, 'status', None) or getattr(lf_r, 'last_response_code', None), + error=_api_error, diagnostics=getattr(lf_r, 'last_diagnostics', None)) return json_response def json_get(self, _req_url, debug_=None): @@ -319,6 +358,8 @@ def json_get(self, _req_url, debug_=None): if debug_ is None: debug_ = self.debug json_response = None + _api_error = None + lf_r = None try: lf_r = LFRequest.LFRequest(url=self.lfclient_url, uri=_req_url, @@ -334,15 +375,22 @@ def json_get(self, _req_url, debug_=None): else: logger.debug("LFCliBase.json_get: no entity/response, check other errors") time.sleep(10) + self._log_api_call("GET", _req_url, response_code=getattr(lf_r, 'last_response_code', None), + diagnostics=getattr(lf_r, 'last_diagnostics', None)) return None except ValueError as ve: + _api_error = ve if debug_ or self.exit_on_error: logger.debug("jsonGet asked for {_req_url} ".format(_req_url=_req_url)) logger.debug("Exception %s:" % ve) logger.debug(traceback.format_exception(ValueError, ve, ve.__traceback__, chain=True)) if self.exit_on_error: + self._log_api_call("GET", _req_url, response_code=getattr(lf_r, 'last_response_code', None), error=_api_error, + diagnostics=getattr(lf_r, 'last_diagnostics', None)) sys.exit(1) + self._log_api_call("GET", _req_url, response_code=getattr(lf_r, 'last_response_code', None), error=_api_error, + diagnostics=getattr(lf_r, 'last_diagnostics', None)) return json_response def json_delete(self, _req_url, debug_=False): @@ -350,6 +398,8 @@ def json_delete(self, _req_url, debug_=False): if debug_: logger.debug("DELETE: {_req_url}".format(_req_url=_req_url)) json_response = None + _api_error = None + lf_r = None try: # logger.info("----- DELETE ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ") lf_r = LFRequest.LFRequest(url=self.lfclient_url, @@ -362,15 +412,22 @@ def json_delete(self, _req_url, debug_=False): # logger.debug(debug_printer.pformat(json_response)) if (json_response is None) and debug_: logger.debug("LFCliBase.json_delete: no entity/response, probabily status 404") + self._log_api_call("DELETE", _req_url, response_code=getattr(lf_r, 'last_response_code', None), + diagnostics=getattr(lf_r, 'last_diagnostics', None)) return None except ValueError as ve: + _api_error = ve if debug_ or self.exit_on_error: logger.debug("json_delete asked for {_req_url}".format(_req_url=_req_url)) logger.debug("Exception %s:" % ve) logger.debug(traceback.format_exception(ValueError, ve, ve.__traceback__, chain=True)) if self.exit_on_error: + self._log_api_call("DELETE", _req_url, response_code=getattr(lf_r, 'last_response_code', None), error=_api_error, + diagnostics=getattr(lf_r, 'last_diagnostics', None)) sys.exit(1) # print("----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ") + self._log_api_call("DELETE", _req_url, response_code=getattr(lf_r, 'last_response_code', None), error=_api_error, + diagnostics=getattr(lf_r, 'last_diagnostics', None)) return json_response @staticmethod From 94919aae811f33eca87ad5d2e8fe939f8f024e2f Mon Sep 17 00:00:00 2001 From: Sidartha-CT Date: Wed, 22 Jul 2026 10:46:34 +0000 Subject: [PATCH 04/18] lanforge_api.py : Record json_get/post/put/delete calls via api_logger Signed-off-by: Sidartha-CT --- lanforge_client/lanforge_api.py | 40 +++++++++++++++++++++++++-------- 1 file changed, 31 insertions(+), 9 deletions(-) diff --git a/lanforge_client/lanforge_api.py b/lanforge_client/lanforge_api.py index e655336a6..137d2c039 100644 --- a/lanforge_client/lanforge_api.py +++ b/lanforge_client/lanforge_api.py @@ -101,6 +101,7 @@ class which appends subclasses to it. # - - - - deployed import references - - - - - from .strutil import nott, iss +from . import api_logger SESSION_HEADER = 'X-LFJson-Session' # LOGGER = Logger('json_api') @@ -173,6 +174,10 @@ def print_diagnostics(url_: str = None, error_list_.append(xerr) LOGGER.error(" = = = = = = = = = = = = = = = =") + summary = "%s <%s> HTTP %s: %s" % (method, err_full_url, err_code, err_reason) + if xerrors and err_code != 404: + summary += " | " + "; ".join(xerrors) + if error_.__class__ is urllib.error.HTTPError: LOGGER.debug("----- HTTPError: ------------------------------------ print_diagnostics:") LOGGER.debug("%s <%s> HTTP %s: %s" % (method, err_full_url, err_code, err_reason)) @@ -203,7 +208,7 @@ def print_diagnostics(url_: str = None, LOGGER.warning("------------------------------------------------------------------------") if die_on_error_: exit(1) - return + return summary if error_.__class__ is urllib.error.URLError: LOGGER.error("----- URLError: ---------------------------------------------") @@ -212,6 +217,8 @@ def print_diagnostics(url_: str = None, if die_on_error_: exit(1) + return summary + class BaseLFJsonRequest: """----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- @@ -635,6 +642,7 @@ def json_post(self, self.logger.debug("----------------- BAD STATUS --------------------------------") if die_on_error: sys.exit(1) + api_logger.record_api_call(method=method_, url=url, data=post_data, response_code=response.status) return responses[0] except urllib.error.HTTPError as herror: @@ -642,12 +650,16 @@ def json_post(self, # and retrying them is never going to succeed if herror.code in (400, 410, 411, 412, 413, 414, 415, 416, 417, 428, 429, 431, 451): die_on_error = True - print_diagnostics(url_=url, + # die_on_error_=False here: we want to log the call before exiting, so the + # sys.exit(1) below (not print_diagnostics' own) is what actually exits + diagnostics = print_diagnostics(url_=url, request_=myrequest, responses_=responses, error_=herror, debug_=debug, - die_on_error_=die_on_error) + die_on_error_=False) + api_logger.record_api_call(method=method_, url=url, data=post_data, response_code=herror.code, + error=herror, diagnostics=diagnostics) if die_on_error: sys.exit(1) @@ -656,16 +668,20 @@ def json_post(self, die_on_error = True if (url.endswith("endsession")): logging.info("lfclient closed connection before script exit") + api_logger.record_api_call(method=method_, url=url, data=post_data, error=uerror, + diagnostics="session ended") die_on_error = True break else: logging.error("Connection refused: "+url) - print_diagnostics(url_=url, + diagnostics = print_diagnostics(url_=url, request_=myrequest, responses_=responses, error_=uerror, debug_=debug, - die_on_error_=die_on_error) + die_on_error_=False) + api_logger.record_api_call(method=method_, url=url, data=post_data, error=uerror, + diagnostics=diagnostics) if die_on_error: sys.exit(1) # ~while @@ -800,26 +816,32 @@ def get(self, myresponses: list = [] # list[HTTPResponse] try: myresponses.append(request.urlopen(myrequest)) + api_logger.record_api_call(method=method_, url=requested_url, response_code=myresponses[0].status) return myresponses[0] except urllib.error.HTTPError as herror: - print_diagnostics(url_=requested_url, + # die_on_error_=False here: we want to log the call before exiting, so the + # sys.exit(1) below (not print_diagnostics' own) is what actually exits + diagnostics = print_diagnostics(url_=requested_url, request_=myrequest, responses_=myresponses, error_=herror, error_list_=self.error_list, debug_=debug, - die_on_error_=die_on_error) + die_on_error_=False) + api_logger.record_api_call(method=method_, url=requested_url, response_code=herror.code, + error=herror, diagnostics=diagnostics) if die_on_error: sys.exit(1) except urllib.error.URLError as uerror: - print_diagnostics(url_=requested_url, + diagnostics = print_diagnostics(url_=requested_url, request_=myrequest, responses_=myresponses, error_=uerror, error_list_=self.error_list, debug_=debug, - die_on_error_=die_on_error) + die_on_error_=False) + api_logger.record_api_call(method=method_, url=requested_url, error=uerror, diagnostics=diagnostics) if die_on_error: sys.exit(1) if die_on_error: From dfb2931b535387f67285e58ce7bc429555537cef Mon Sep 17 00:00:00 2001 From: Sidartha-CT Date: Wed, 22 Jul 2026 10:46:34 +0000 Subject: [PATCH 05/18] lf_webpage.py : Add --save_api and --api_log_file_name to enable API call logging Signed-off-by: Sidartha-CT --- py-scripts/lf_webpage.py | 13 +++++++++++++ 1 file changed, 13 insertions(+) diff --git a/py-scripts/lf_webpage.py b/py-scripts/lf_webpage.py index 212c6b106..626651b7c 100755 --- a/py-scripts/lf_webpage.py +++ b/py-scripts/lf_webpage.py @@ -131,6 +131,7 @@ realm = importlib.import_module("py-json.realm") Realm = realm.Realm PortUtils = realm.PortUtils +api_logger = importlib.import_module("lanforge_client.api_logger") lf_report = importlib.import_module("py-scripts.lf_report") lf_graph = importlib.import_module("py-scripts.lf_graph") lf_kpi_csv = importlib.import_module("py-scripts.lf_kpi_csv") @@ -1644,6 +1645,12 @@ def generate_report(self, date, num_stations, duration, test_setup_info, dataset # To store http_datavalues.csv in report folder report_path_date_time = report.get_path_date_time() + # Copy the api log csv file (json_get/post/put/delete calls) into the report folder, if enabled + if api_logger.is_enabled(): + try: + shutil.copy(api_logger.get_log_filename(), report_path_date_time) + except Exception: + logging.info("failed to copy api log file %s to report dir" % api_logger.get_log_filename()) # It ensures no blocker for virtual clients if self.client_type == 'Real': shutil.move('http_datavalues.csv', report_path_date_time) @@ -2838,6 +2845,10 @@ def main(): optional.add_argument("--test_priority", default="", help="dut model for kpi.csv, test-priority is arbitrary number") optional.add_argument("--test_id", default="lf_webpage", help="test-id for kpi.csv, script or test name") optional.add_argument('--csv_outfile', help="--csv_outfile ", default="") + optional.add_argument('--save_api', help="save json_get/json_post/json_put/json_delete calls to a lightweight csv log file", + action="store_true", default=False) + optional.add_argument('--api_log_file_name', help="path to the api log csv file used when --save_api is set (default: ~/lf_api_calls.csv)", + default=None) # ARGS for webGUI required.add_argument('--dowebgui', help="If true will execute script for webgui", default=False) # FOR WEBGUI optional.add_argument('--result_dir', @@ -2938,6 +2949,8 @@ def main(): print(help_summary) exit(0) + api_logger.configure_api_call_logging(enabled=args.save_api, log_filename=args.api_log_file_name) + args.bands.sort() # Error checking to prevent case issues From ae7916915bb54ddd9ecd4553d09d01587aa80942 Mon Sep 17 00:00:00 2001 From: Sidartha-CT Date: Wed, 22 Jul 2026 11:20:00 +0000 Subject: [PATCH 06/18] api_logger.py : Add pause/resume to temporarily suppress recording Signed-off-by: Sidartha-CT --- lanforge_client/api_logger.py | 30 +++++++++++++++++++++++++++--- 1 file changed, 27 insertions(+), 3 deletions(-) diff --git a/lanforge_client/api_logger.py b/lanforge_client/api_logger.py index 6653b42a3..621da1b8f 100644 --- a/lanforge_client/api_logger.py +++ b/lanforge_client/api_logger.py @@ -19,6 +19,7 @@ 'api_payload', 'api_error', 'api_diagnostics'] _logging_enabled = False +_logging_paused = False _log_filename = None @@ -33,8 +34,9 @@ def configure_api_call_logging(enabled: bool, log_filename: Optional[str] = None Returns: None. """ - global _logging_enabled, _log_filename + global _logging_enabled, _log_filename, _logging_paused _logging_enabled = bool(enabled) + _logging_paused = False if not _logging_enabled: return _log_filename = log_filename or os.path.join(os.path.expanduser('~'), 'lf_api_calls.csv') @@ -46,6 +48,28 @@ def configure_api_call_logging(enabled: bool, log_filename: Optional[str] = None logger.debug("api_logger: unable to reset %s: %s" % (_log_filename, x)) +def pause() -> None: + """ + Temporarily stop recording API calls until resume() is called. + + Returns: + None. + """ + global _logging_paused + _logging_paused = True + + +def resume() -> None: + """ + Resume recording API calls after pause(). + + Returns: + None. + """ + global _logging_paused + _logging_paused = False + + def is_enabled() -> bool: """ Check whether API-call logging is currently enabled. @@ -70,7 +94,7 @@ def record_api_call(method: str, url: str, data: Optional[Any] = None, response_ error: Optional[Exception] = None, diagnostics: Optional[str] = None) -> None: """ Append one CSV row for a json_get/json_post/json_put/json_delete call. No-op unless - configure_api_call_logging(enabled=True) was called first. + configure_api_call_logging(enabled=True) was called first, or while paused (see pause()/resume()). Args: method: "GET" | "POST" | "PUT" | "DELETE". @@ -84,7 +108,7 @@ def record_api_call(method: str, url: str, data: Optional[Any] = None, response_ Returns: None. """ - if not _logging_enabled: + if not _logging_enabled or _logging_paused: return if error: status = "ERROR" From 36fdbec8afdbdf9eb4491a7b6c5c997e3c33922e Mon Sep 17 00:00:00 2001 From: Sidartha-CT Date: Wed, 22 Jul 2026 11:20:00 +0000 Subject: [PATCH 07/18] lf_webpage.py : Pause API logging during runtime-CSV monitor loop by default Verified CLI : python3 lf_webpage.py --ap_name "Cisco" --mgr 192.168.207.75 --ssid Cisco-5g --security wpa2 --passwd sharedsecret --upstream_port eth1 --duration 20s --bands 5G --client_type Real --file_size 2MB --save_api Signed-off-by: Sidartha-CT --- py-scripts/lf_webpage.py | 14 +++++++++++++- 1 file changed, 13 insertions(+), 1 deletion(-) diff --git a/py-scripts/lf_webpage.py b/py-scripts/lf_webpage.py index 626651b7c..da7644274 100755 --- a/py-scripts/lf_webpage.py +++ b/py-scripts/lf_webpage.py @@ -155,7 +155,8 @@ def __init__(self, lfclient_host, lfclient_port, upstream, num_sta, security, ss device_list=None, get_url_from_file=None, file_path=None, device_csv_name='', expected_passfail_value=None, file_name=None, group_name=None, profile_name=None, eap_method=None, eap_identity=None, ieee80211=None, ieee80211u=None, ieee80211w=None, enable_pkc=None, bss_transition=None, power_save=None, disable_ofdma=None, roam_ft_ds=None, key_management=None, pairwise=None, private_key=None, ca_cert=None, client_cert=None, pk_passwd=None, pac_file=None, config=False, wait_time=60, get_live_view=False, total_floors=0, robot_test=False, - robot_ip=None, coordinate=None, rotation=None, duration=None, do_bandsteering=False, cycles=None, bssids=None, duration_to_skip=None): + robot_ip=None, coordinate=None, rotation=None, duration=None, do_bandsteering=False, cycles=None, bssids=None, duration_to_skip=None, + log_monitor_api_calls=False): # super().__init__(lfclient_host=lfclient_host, # lfclient_port=lfclient_port) self.ssid_list = [] @@ -191,6 +192,7 @@ def __init__(self, lfclient_host, lfclient_port, upstream, num_sta, security, ss self.ap_name = ap_name self.windows_ports = [] self.windows_eids = [] + self.log_monitor_api_calls = log_monitor_api_calls self.local_realm = realm.Realm(lfclient_host=self.host, lfclient_port=self.port) self.station_profile = self.local_realm.new_station_profile() self.http_profile = self.local_realm.new_http_profile() @@ -911,6 +913,10 @@ def monitor_for_runtime_csv(self, duration): self.monitor_start_time = datetime.now() else: self.monitor_start_time = datetime.now() + # exclude this loop's polling calls from the API log by default -- they're noisy + # and rarely what you're debugging; pass --log_monitor_api_calls to keep them + if not self.log_monitor_api_calls: + api_logger.pause() time_now = datetime.now() starttime = time_now.strftime("%d/%m %I:%M:%S %p") # duration = self.traffic_duration @@ -1127,6 +1133,8 @@ def monitor_for_runtime_csv(self, duration): except Exception: logger.error("All l4 data not found") self.actual_monitor_duration += (datetime.now() - self.monitor_start_time).total_seconds() + if not self.log_monitor_api_calls: + api_logger.resume() return test_stopped_by_user def get_all_l4_data(self): @@ -2849,6 +2857,9 @@ def main(): action="store_true", default=False) optional.add_argument('--api_log_file_name', help="path to the api log csv file used when --save_api is set (default: ~/lf_api_calls.csv)", default=None) + optional.add_argument('--log_monitor_api_calls', help="also record API calls made during the runtime-CSV monitor loop " + "(off by default to keep --save_api's log focused on setup/teardown calls)", + action="store_true", default=False) # ARGS for webGUI required.add_argument('--dowebgui', help="If true will execute script for webgui", default=False) # FOR WEBGUI optional.add_argument('--result_dir', @@ -3037,6 +3048,7 @@ def main(): ssid = [args.twog_ssid, args.fiveg_ssid] passwd = [args.twog_passwd, args.fiveg_passwd] http = HttpDownload(lfclient_host=args.mgr, lfclient_port=args.mgr_port, + log_monitor_api_calls=args.log_monitor_api_calls, upstream=args.upstream_port, num_sta=args.num_stations, security=security, ap_name=args.ap_name, ssid=ssid, password=passwd, From a2ad137c7420875ae1d9a122d457feb1d9528e8c Mon Sep 17 00:00:00 2001 From: Sidartha-CT Date: Mon, 3 Aug 2026 10:09:08 +0000 Subject: [PATCH 08/18] api_logger.py : Accept caller-supplied sent_at for accurate call timestamps record_api_call() previously stamped datetime.now() at CSV-write time, which is after the request/response cycle completes. Accept an optional sent_at param and use it instead when the caller provides it. Signed-off-by: Sidartha-CT --- lanforge_client/api_logger.py | 8 ++++++-- 1 file changed, 6 insertions(+), 2 deletions(-) diff --git a/lanforge_client/api_logger.py b/lanforge_client/api_logger.py index 621da1b8f..75a857282 100644 --- a/lanforge_client/api_logger.py +++ b/lanforge_client/api_logger.py @@ -91,7 +91,8 @@ def get_log_filename() -> Optional[str]: def record_api_call(method: str, url: str, data: Optional[Any] = None, response_code: Optional[int] = None, - error: Optional[Exception] = None, diagnostics: Optional[str] = None) -> None: + error: Optional[Exception] = None, diagnostics: Optional[str] = None, + sent_at: Optional[datetime.datetime] = None) -> None: """ Append one CSV row for a json_get/json_post/json_put/json_delete call. No-op unless configure_api_call_logging(enabled=True) was called first, or while paused (see pause()/resume()). @@ -104,6 +105,9 @@ def record_api_call(method: str, url: str, data: Optional[Any] = None, response_ error: Exception raised by the call, if any -- marks the entry as ERROR. diagnostics: One-line summary from LFRequest.print_diagnostics(), if the call went through a caught HTTPError/URLError (reason, X-Error-* headers, etc.) + sent_at: Timestamp captured by the caller right before the request was issued. + Falls back to datetime.now() (this function's call time) when not provided, + which is captured well after the request completed and is less accurate. Returns: None. @@ -119,7 +123,7 @@ def record_api_call(method: str, url: str, data: Optional[Any] = None, response_ try: with open(_log_filename, 'a', newline='') as csv_file: csv.writer(csv_file).writerow([ - datetime.datetime.now().isoformat(), + (sent_at or datetime.datetime.now()).isoformat(), method, url, status, From 7017195ee6b7ed798a08f8aab163530241c111ba Mon Sep 17 00:00:00 2001 From: Sidartha-CT Date: Mon, 3 Aug 2026 10:09:19 +0000 Subject: [PATCH 09/18] lanforge_api.py : Capture request timestamp before urlopen, not after json_post() and get() now record sent_at right before the request is issued and pass it through to api_logger.record_api_call() on every success/error path, instead of letting it default to log-write time. Signed-off-by: Sidartha-CT --- lanforge_client/lanforge_api.py | 19 ++++++++++++------- 1 file changed, 12 insertions(+), 7 deletions(-) diff --git a/lanforge_client/lanforge_api.py b/lanforge_client/lanforge_api.py index 137d2c039..0af948a3a 100644 --- a/lanforge_client/lanforge_api.py +++ b/lanforge_client/lanforge_api.py @@ -580,6 +580,7 @@ def json_post(self, finish_time_ms = (max_timeout_sec * 1000) + begin_time_ms attempt = 1 while (time.time() * 1000) < finish_time_ms: + sent_at = datetime.now() try: response = urllib.request.urlopen(myrequest) resp_data = response.read().decode('utf-8') @@ -642,7 +643,8 @@ def json_post(self, self.logger.debug("----------------- BAD STATUS --------------------------------") if die_on_error: sys.exit(1) - api_logger.record_api_call(method=method_, url=url, data=post_data, response_code=response.status) + api_logger.record_api_call(method=method_, url=url, data=post_data, response_code=response.status, + sent_at=sent_at) return responses[0] except urllib.error.HTTPError as herror: @@ -659,7 +661,7 @@ def json_post(self, debug_=debug, die_on_error_=False) api_logger.record_api_call(method=method_, url=url, data=post_data, response_code=herror.code, - error=herror, diagnostics=diagnostics) + error=herror, diagnostics=diagnostics, sent_at=sent_at) if die_on_error: sys.exit(1) @@ -669,7 +671,7 @@ def json_post(self, if (url.endswith("endsession")): logging.info("lfclient closed connection before script exit") api_logger.record_api_call(method=method_, url=url, data=post_data, error=uerror, - diagnostics="session ended") + diagnostics="session ended", sent_at=sent_at) die_on_error = True break else: @@ -681,7 +683,7 @@ def json_post(self, debug_=debug, die_on_error_=False) api_logger.record_api_call(method=method_, url=url, data=post_data, error=uerror, - diagnostics=diagnostics) + diagnostics=diagnostics, sent_at=sent_at) if die_on_error: sys.exit(1) # ~while @@ -814,9 +816,11 @@ def get(self, myrequest.timeout = connection_timeout_sec myresponses: list = [] # list[HTTPResponse] + sent_at = datetime.now() try: myresponses.append(request.urlopen(myrequest)) - api_logger.record_api_call(method=method_, url=requested_url, response_code=myresponses[0].status) + api_logger.record_api_call(method=method_, url=requested_url, response_code=myresponses[0].status, + sent_at=sent_at) return myresponses[0] except urllib.error.HTTPError as herror: @@ -830,7 +834,7 @@ def get(self, debug_=debug, die_on_error_=False) api_logger.record_api_call(method=method_, url=requested_url, response_code=herror.code, - error=herror, diagnostics=diagnostics) + error=herror, diagnostics=diagnostics, sent_at=sent_at) if die_on_error: sys.exit(1) except urllib.error.URLError as uerror: @@ -841,7 +845,8 @@ def get(self, error_list_=self.error_list, debug_=debug, die_on_error_=False) - api_logger.record_api_call(method=method_, url=requested_url, error=uerror, diagnostics=diagnostics) + api_logger.record_api_call(method=method_, url=requested_url, error=uerror, diagnostics=diagnostics, + sent_at=sent_at) if die_on_error: sys.exit(1) if die_on_error: From a789c771e5ae60f2e9a51d694e6eb37b3ad389a7 Mon Sep 17 00:00:00 2001 From: Sidartha-CT Date: Mon, 3 Aug 2026 10:09:33 +0000 Subject: [PATCH 10/18] LFRequest.py : Track last_sent_at right before request is issued Adds a last_sent_at attribute, set immediately before urlopen() in json_post() and get(), so callers can log the actual send time rather than the time the call happened to finish. Signed-off-by: Sidartha-CT --- py-json/LANforge/LFRequest.py | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/py-json/LANforge/LFRequest.py b/py-json/LANforge/LFRequest.py index df02f4e45..74e6b315c 100644 --- a/py-json/LANforge/LFRequest.py +++ b/py-json/LANforge/LFRequest.py @@ -7,6 +7,7 @@ import logging import sys import os +from datetime import datetime from pprint import pformat, PrettyPrinter import urllib from urllib import request @@ -43,6 +44,7 @@ def __init__(self, url=None, self.error_list = [] self.last_response_code = None self.last_diagnostics = None + self.last_sent_at = None # please see this discussion on ProxyHandlers: # https://docs.python.org/3/library/urllib.request.html#urllib.request.ProxyHandler @@ -185,6 +187,7 @@ def json_post(self, show_error=True, debug=False, die_on_error_=False, response_ # https://stackoverflow.com/a/59635684/11014343 + self.last_sent_at = datetime.now() try: resp = urllib.request.urlopen(myrequest) self.last_response_code = getattr(resp, 'status', None) @@ -253,6 +256,7 @@ def get(self, method_='GET'): headers=self.default_headers, method=method_) myresponses = [] + self.last_sent_at = datetime.now() try: myresponses.append(request.urlopen(myrequest)) return myresponses[0] From 08e6674debe42669ce5785d25c820ab5e773f437 Mon Sep 17 00:00:00 2001 From: Sidartha-CT Date: Mon, 3 Aug 2026 10:09:42 +0000 Subject: [PATCH 11/18] lfcli_base.py : Forward LFRequest.last_sent_at through to the API logger _log_api_call() now accepts sent_at and forwards it to api_logger.record_api_call(); json_post/json_put/json_get/json_delete pass lf_r.last_sent_at so the CSV timestamp reflects send time. Signed-off-by: Sidartha-CT --- py-json/LANforge/lfcli_base.py | 38 +++++++++++++++++++++++----------- 1 file changed, 26 insertions(+), 12 deletions(-) diff --git a/py-json/LANforge/lfcli_base.py b/py-json/LANforge/lfcli_base.py index 4982bf954..a6b99dd84 100644 --- a/py-json/LANforge/lfcli_base.py +++ b/py-json/LANforge/lfcli_base.py @@ -219,7 +219,8 @@ def log_set_filename(filename=None): # - END LOGGING - def _log_api_call(self, method: str, url: str, data: Optional[Any] = None, response_code: Optional[int] = None, - error: Optional[Exception] = None, diagnostics: Optional[str] = None) -> None: + error: Optional[Exception] = None, diagnostics: Optional[str] = None, + sent_at: Optional[datetime.datetime] = None) -> None: """ Record one json_get/json_post/json_put/json_delete call via lanforge_client.api_logger. @@ -230,12 +231,15 @@ def _log_api_call(self, method: str, url: str, data: Optional[Any] = None, respo response_code: HTTP status code returned by the call, if any. error: Exception raised by the call, if any. diagnostics: One-line diagnostics summary, if the call went through a caught error. + sent_at: Timestamp captured by LFRequest right before the request was issued + (its last_sent_at attribute); falls back to record_api_call's own call time + when not available. Returns: None. """ api_logger.record_api_call(method=method, url=url, data=data, response_code=response_code, - error=error, diagnostics=diagnostics) + error=error, diagnostics=diagnostics, sent_at=sent_at) def json_post(self, _req_url, _data, debug_=False, suppress_related_commands_=None, response_json_list_=None): """ @@ -296,11 +300,13 @@ def json_post(self, _req_url, _data, debug_=False, suppress_related_commands_=No if self.exit_on_error: self._log_api_call("POST", _req_url, data=_data, response_code=getattr(json_response, 'status', None) or getattr(lf_r, 'last_response_code', None), - error=_api_error, diagnostics=getattr(lf_r, 'last_diagnostics', None)) + error=_api_error, diagnostics=getattr(lf_r, 'last_diagnostics', None), + sent_at=getattr(lf_r, 'last_sent_at', None)) exit(1) self._log_api_call("POST", _req_url, data=_data, response_code=getattr(json_response, 'status', None) or getattr(lf_r, 'last_response_code', None), - error=_api_error, diagnostics=getattr(lf_r, 'last_diagnostics', None)) + error=_api_error, diagnostics=getattr(lf_r, 'last_diagnostics', None), + sent_at=getattr(lf_r, 'last_sent_at', None)) return json_response def json_put(self, _req_url, _data, debug_=False, response_json_list_=None): @@ -343,11 +349,13 @@ def json_put(self, _req_url, _data, debug_=False, response_json_list_=None): if self.exit_on_error: self._log_api_call("PUT", _req_url, data=_data, response_code=getattr(json_response, 'status', None) or getattr(lf_r, 'last_response_code', None), - error=_api_error, diagnostics=getattr(lf_r, 'last_diagnostics', None)) + error=_api_error, diagnostics=getattr(lf_r, 'last_diagnostics', None), + sent_at=getattr(lf_r, 'last_sent_at', None)) exit(1) self._log_api_call("PUT", _req_url, data=_data, response_code=getattr(json_response, 'status', None) or getattr(lf_r, 'last_response_code', None), - error=_api_error, diagnostics=getattr(lf_r, 'last_diagnostics', None)) + error=_api_error, diagnostics=getattr(lf_r, 'last_diagnostics', None), + sent_at=getattr(lf_r, 'last_sent_at', None)) return json_response def json_get(self, _req_url, debug_=None): @@ -376,7 +384,8 @@ def json_get(self, _req_url, debug_=None): logger.debug("LFCliBase.json_get: no entity/response, check other errors") time.sleep(10) self._log_api_call("GET", _req_url, response_code=getattr(lf_r, 'last_response_code', None), - diagnostics=getattr(lf_r, 'last_diagnostics', None)) + diagnostics=getattr(lf_r, 'last_diagnostics', None), + sent_at=getattr(lf_r, 'last_sent_at', None)) return None except ValueError as ve: _api_error = ve @@ -386,11 +395,13 @@ def json_get(self, _req_url, debug_=None): logger.debug(traceback.format_exception(ValueError, ve, ve.__traceback__, chain=True)) if self.exit_on_error: self._log_api_call("GET", _req_url, response_code=getattr(lf_r, 'last_response_code', None), error=_api_error, - diagnostics=getattr(lf_r, 'last_diagnostics', None)) + diagnostics=getattr(lf_r, 'last_diagnostics', None), + sent_at=getattr(lf_r, 'last_sent_at', None)) sys.exit(1) self._log_api_call("GET", _req_url, response_code=getattr(lf_r, 'last_response_code', None), error=_api_error, - diagnostics=getattr(lf_r, 'last_diagnostics', None)) + diagnostics=getattr(lf_r, 'last_diagnostics', None), + sent_at=getattr(lf_r, 'last_sent_at', None)) return json_response def json_delete(self, _req_url, debug_=False): @@ -413,7 +424,8 @@ def json_delete(self, _req_url, debug_=False): if (json_response is None) and debug_: logger.debug("LFCliBase.json_delete: no entity/response, probabily status 404") self._log_api_call("DELETE", _req_url, response_code=getattr(lf_r, 'last_response_code', None), - diagnostics=getattr(lf_r, 'last_diagnostics', None)) + diagnostics=getattr(lf_r, 'last_diagnostics', None), + sent_at=getattr(lf_r, 'last_sent_at', None)) return None except ValueError as ve: _api_error = ve @@ -423,11 +435,13 @@ def json_delete(self, _req_url, debug_=False): logger.debug(traceback.format_exception(ValueError, ve, ve.__traceback__, chain=True)) if self.exit_on_error: self._log_api_call("DELETE", _req_url, response_code=getattr(lf_r, 'last_response_code', None), error=_api_error, - diagnostics=getattr(lf_r, 'last_diagnostics', None)) + diagnostics=getattr(lf_r, 'last_diagnostics', None), + sent_at=getattr(lf_r, 'last_sent_at', None)) sys.exit(1) # print("----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ") self._log_api_call("DELETE", _req_url, response_code=getattr(lf_r, 'last_response_code', None), error=_api_error, - diagnostics=getattr(lf_r, 'last_diagnostics', None)) + diagnostics=getattr(lf_r, 'last_diagnostics', None), + sent_at=getattr(lf_r, 'last_sent_at', None)) return json_response @staticmethod From c57846c7c51d64f3bea946cba5ad4e551bf2262d Mon Sep 17 00:00:00 2001 From: Sidartha-CT Date: Mon, 3 Aug 2026 10:37:11 +0000 Subject: [PATCH 12/18] api_logger.py : Add api_elapsed_ms column for per-call duration record_api_call() now accepts an optional elapsed_ms param, measured by the caller with time.perf_counter() around just the request itself (excludes diagnostics/logging overhead), and writes it to a new api_elapsed_ms CSV column so slow calls can be spotted at a glance. Signed-off-by: Sidartha-CT --- lanforge_client/api_logger.py | 9 +++++++-- 1 file changed, 7 insertions(+), 2 deletions(-) diff --git a/lanforge_client/api_logger.py b/lanforge_client/api_logger.py index 75a857282..81c876845 100644 --- a/lanforge_client/api_logger.py +++ b/lanforge_client/api_logger.py @@ -16,7 +16,7 @@ # CSV header for API call logs with prefixed column names to avoid ambiguity across reports. CSV_FIELDS = ['api_timestamp', 'api_method', 'api_url', 'api_status', 'api_response_code', - 'api_payload', 'api_error', 'api_diagnostics'] + 'api_elapsed_ms', 'api_payload', 'api_error', 'api_diagnostics'] _logging_enabled = False _logging_paused = False @@ -92,7 +92,8 @@ def get_log_filename() -> Optional[str]: def record_api_call(method: str, url: str, data: Optional[Any] = None, response_code: Optional[int] = None, error: Optional[Exception] = None, diagnostics: Optional[str] = None, - sent_at: Optional[datetime.datetime] = None) -> None: + sent_at: Optional[datetime.datetime] = None, + elapsed_ms: Optional[float] = None) -> None: """ Append one CSV row for a json_get/json_post/json_put/json_delete call. No-op unless configure_api_call_logging(enabled=True) was called first, or while paused (see pause()/resume()). @@ -108,6 +109,9 @@ def record_api_call(method: str, url: str, data: Optional[Any] = None, response_ sent_at: Timestamp captured by the caller right before the request was issued. Falls back to datetime.now() (this function's call time) when not provided, which is captured well after the request completed and is less accurate. + elapsed_ms: Wall-clock duration of the underlying urlopen() call in milliseconds, + measured by the caller with time.perf_counter() around just the request itself + (excludes diagnostics/logging overhead). None when not measured. Returns: None. @@ -128,6 +132,7 @@ def record_api_call(method: str, url: str, data: Optional[Any] = None, response_ url, status, response_code if response_code is not None else 'No response_code', + round(elapsed_ms, 3) if elapsed_ms is not None else 'Unknown', json.dumps(data, default=str) if data is not None else 'No payload', error, diagnostics if diagnostics is not None else 'No diagnostics', From 883dadd558d1bdd097ab5effb888ee742e375012 Mon Sep 17 00:00:00 2001 From: Sidartha-CT Date: Mon, 3 Aug 2026 10:37:16 +0000 Subject: [PATCH 13/18] lanforge_api.py : Measure request duration with time.perf_counter() json_post() and get_as_json() now wrap the urlopen()/read() call with time.perf_counter() and pass the resulting elapsed_ms through to api_logger.record_api_call() on every success/error path, so the CSV log reflects the actual network call time rather than a timestamp delta that includes diagnostics overhead. Signed-off-by: Sidartha-CT --- lanforge_client/lanforge_api.py | 26 +++++++++++++++++++------- 1 file changed, 19 insertions(+), 7 deletions(-) diff --git a/lanforge_client/lanforge_api.py b/lanforge_client/lanforge_api.py index 0af948a3a..d7033c732 100644 --- a/lanforge_client/lanforge_api.py +++ b/lanforge_client/lanforge_api.py @@ -581,9 +581,11 @@ def json_post(self, attempt = 1 while (time.time() * 1000) < finish_time_ms: sent_at = datetime.now() + _t0 = time.perf_counter() try: response = urllib.request.urlopen(myrequest) resp_data = response.read().decode('utf-8') + elapsed_ms = (time.perf_counter() - _t0) * 1000 if self.receives_async_feedback and (response_json_list is None and resp_data): self.logger.warning("json_post: POST to URL has data: " + url) raise ValueError("json_post: not returning post data, no response_json_list provided") @@ -644,10 +646,11 @@ def json_post(self, if die_on_error: sys.exit(1) api_logger.record_api_call(method=method_, url=url, data=post_data, response_code=response.status, - sent_at=sent_at) + sent_at=sent_at, elapsed_ms=elapsed_ms) return responses[0] except urllib.error.HTTPError as herror: + elapsed_ms = (time.perf_counter() - _t0) * 1000 # these error codes illustrate an error on the client that requires debugging # and retrying them is never going to succeed if herror.code in (400, 410, 411, 412, 413, 414, 415, 416, 417, 428, 429, 431, 451): @@ -661,17 +664,20 @@ def json_post(self, debug_=debug, die_on_error_=False) api_logger.record_api_call(method=method_, url=url, data=post_data, response_code=herror.code, - error=herror, diagnostics=diagnostics, sent_at=sent_at) + error=herror, diagnostics=diagnostics, sent_at=sent_at, + elapsed_ms=elapsed_ms) if die_on_error: sys.exit(1) except urllib.error.URLError as uerror: + elapsed_ms = (time.perf_counter() - _t0) * 1000 # this is a misformatted URL die_on_error = True if (url.endswith("endsession")): logging.info("lfclient closed connection before script exit") api_logger.record_api_call(method=method_, url=url, data=post_data, error=uerror, - diagnostics="session ended", sent_at=sent_at) + diagnostics="session ended", sent_at=sent_at, + elapsed_ms=elapsed_ms) die_on_error = True break else: @@ -683,7 +689,8 @@ def json_post(self, debug_=debug, die_on_error_=False) api_logger.record_api_call(method=method_, url=url, data=post_data, error=uerror, - diagnostics=diagnostics, sent_at=sent_at) + diagnostics=diagnostics, sent_at=sent_at, + elapsed_ms=elapsed_ms) if die_on_error: sys.exit(1) # ~while @@ -817,13 +824,16 @@ def get(self, myresponses: list = [] # list[HTTPResponse] sent_at = datetime.now() + _t0 = time.perf_counter() try: myresponses.append(request.urlopen(myrequest)) + elapsed_ms = (time.perf_counter() - _t0) * 1000 api_logger.record_api_call(method=method_, url=requested_url, response_code=myresponses[0].status, - sent_at=sent_at) + sent_at=sent_at, elapsed_ms=elapsed_ms) return myresponses[0] except urllib.error.HTTPError as herror: + elapsed_ms = (time.perf_counter() - _t0) * 1000 # die_on_error_=False here: we want to log the call before exiting, so the # sys.exit(1) below (not print_diagnostics' own) is what actually exits diagnostics = print_diagnostics(url_=requested_url, @@ -834,10 +844,12 @@ def get(self, debug_=debug, die_on_error_=False) api_logger.record_api_call(method=method_, url=requested_url, response_code=herror.code, - error=herror, diagnostics=diagnostics, sent_at=sent_at) + error=herror, diagnostics=diagnostics, sent_at=sent_at, + elapsed_ms=elapsed_ms) if die_on_error: sys.exit(1) except urllib.error.URLError as uerror: + elapsed_ms = (time.perf_counter() - _t0) * 1000 diagnostics = print_diagnostics(url_=requested_url, request_=myrequest, responses_=myresponses, @@ -846,7 +858,7 @@ def get(self, debug_=debug, die_on_error_=False) api_logger.record_api_call(method=method_, url=requested_url, error=uerror, diagnostics=diagnostics, - sent_at=sent_at) + sent_at=sent_at, elapsed_ms=elapsed_ms) if die_on_error: sys.exit(1) if die_on_error: From 30f334d896e3d89f7267f19d13f8bb125836c757 Mon Sep 17 00:00:00 2001 From: Sidartha-CT Date: Mon, 3 Aug 2026 10:39:13 +0000 Subject: [PATCH 14/18] api_logger.py : Use "-" placeholder for empty payload Match the terser placeholder style rather than the verbose "No payload" string in the api_payload column. Signed-off-by: Sidartha-CT --- lanforge_client/api_logger.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lanforge_client/api_logger.py b/lanforge_client/api_logger.py index 81c876845..f19a75eb7 100644 --- a/lanforge_client/api_logger.py +++ b/lanforge_client/api_logger.py @@ -133,7 +133,7 @@ def record_api_call(method: str, url: str, data: Optional[Any] = None, response_ status, response_code if response_code is not None else 'No response_code', round(elapsed_ms, 3) if elapsed_ms is not None else 'Unknown', - json.dumps(data, default=str) if data is not None else 'No payload', + json.dumps(data, default=str) if data is not None else '-', error, diagnostics if diagnostics is not None else 'No diagnostics', ]) From 99bf6975481051ac574b1159ccca04490347dcf3 Mon Sep 17 00:00:00 2001 From: Sidartha-CT Date: Mon, 3 Aug 2026 14:58:22 +0000 Subject: [PATCH 15/18] lf_webpage.py : Rename --save_api to --enable_api_logging Signed-off-by: Sidartha-CT --- py-scripts/lf_webpage.py | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/py-scripts/lf_webpage.py b/py-scripts/lf_webpage.py index da7644274..ca9cb8a19 100755 --- a/py-scripts/lf_webpage.py +++ b/py-scripts/lf_webpage.py @@ -2853,12 +2853,12 @@ def main(): optional.add_argument("--test_priority", default="", help="dut model for kpi.csv, test-priority is arbitrary number") optional.add_argument("--test_id", default="lf_webpage", help="test-id for kpi.csv, script or test name") optional.add_argument('--csv_outfile', help="--csv_outfile ", default="") - optional.add_argument('--save_api', help="save json_get/json_post/json_put/json_delete calls to a lightweight csv log file", + optional.add_argument('--enable_api_logging', help="save json_get/json_post/json_put/json_delete calls to a lightweight csv log file", action="store_true", default=False) - optional.add_argument('--api_log_file_name', help="path to the api log csv file used when --save_api is set (default: ~/lf_api_calls.csv)", + optional.add_argument('--api_log_file_name', help="path to the api log csv file used when --enable_api_logging is set (default: ~/lf_api_calls.csv)", default=None) optional.add_argument('--log_monitor_api_calls', help="also record API calls made during the runtime-CSV monitor loop " - "(off by default to keep --save_api's log focused on setup/teardown calls)", + "(off by default to keep --enable_api_logging's log focused on setup/teardown calls)", action="store_true", default=False) # ARGS for webGUI required.add_argument('--dowebgui', help="If true will execute script for webgui", default=False) # FOR WEBGUI @@ -2960,7 +2960,7 @@ def main(): print(help_summary) exit(0) - api_logger.configure_api_call_logging(enabled=args.save_api, log_filename=args.api_log_file_name) + api_logger.configure_api_call_logging(enabled=args.enable_api_logging, log_filename=args.api_log_file_name) args.bands.sort() From bdfd95b04141f4ace2fe411244b7d7e66386598e Mon Sep 17 00:00:00 2001 From: Sidartha-CT Date: Mon, 3 Aug 2026 15:11:43 +0000 Subject: [PATCH 16/18] LFRequest.py : Track last_elapsed_ms around urlopen() for API call duration Signed-off-by: Sidartha-CT --- py-json/LANforge/LFRequest.py | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/py-json/LANforge/LFRequest.py b/py-json/LANforge/LFRequest.py index 74e6b315c..30b85625a 100644 --- a/py-json/LANforge/LFRequest.py +++ b/py-json/LANforge/LFRequest.py @@ -7,6 +7,7 @@ import logging import sys import os +import time from datetime import datetime from pprint import pformat, PrettyPrinter import urllib @@ -45,6 +46,7 @@ def __init__(self, url=None, self.last_response_code = None self.last_diagnostics = None self.last_sent_at = None + self.last_elapsed_ms = None # please see this discussion on ProxyHandlers: # https://docs.python.org/3/library/urllib.request.html#urllib.request.ProxyHandler @@ -188,8 +190,10 @@ def json_post(self, show_error=True, debug=False, die_on_error_=False, response_ # https://stackoverflow.com/a/59635684/11014343 self.last_sent_at = datetime.now() + _t0 = time.perf_counter() try: resp = urllib.request.urlopen(myrequest) + self.last_elapsed_ms = (time.perf_counter() - _t0) * 1000 self.last_response_code = getattr(resp, 'status', None) resp_data = resp.read().decode('utf-8') if debug or die_on_error_: @@ -214,6 +218,7 @@ def json_post(self, show_error=True, debug=False, die_on_error_=False, response_ return responses[0] except urllib.error.HTTPError as error: + self.last_elapsed_ms = (time.perf_counter() - _t0) * 1000 self.last_response_code = error.code self.last_diagnostics = print_diagnostics(url_=self.requested_url, request_=myrequest, @@ -222,6 +227,7 @@ def json_post(self, show_error=True, debug=False, die_on_error_=False, response_ debug_=debug) except urllib.error.URLError as uerror: + self.last_elapsed_ms = (time.perf_counter() - _t0) * 1000 self.last_diagnostics = print_diagnostics(url_=self.requested_url, request_=myrequest, responses_=responses, @@ -257,11 +263,14 @@ def get(self, method_='GET'): method=method_) myresponses = [] self.last_sent_at = datetime.now() + _t0 = time.perf_counter() try: myresponses.append(request.urlopen(myrequest)) + self.last_elapsed_ms = (time.perf_counter() - _t0) * 1000 return myresponses[0] except urllib.error.HTTPError as error: + self.last_elapsed_ms = (time.perf_counter() - _t0) * 1000 self.last_response_code = error.code self.last_diagnostics = print_diagnostics(url_=self.requested_url, request_=myrequest, @@ -271,6 +280,7 @@ def get(self, method_='GET'): debug_=self.debug) except urllib.error.URLError as uerror: + self.last_elapsed_ms = (time.perf_counter() - _t0) * 1000 self.last_diagnostics = print_diagnostics(url_=self.requested_url, request_=myrequest, responses_=myresponses, From 11a1c8d66903d7888bb830130b4fe57bf59a2fb4 Mon Sep 17 00:00:00 2001 From: Sidartha-CT Date: Mon, 3 Aug 2026 15:12:05 +0000 Subject: [PATCH 17/18] lfcli_base.py : Forward LFRequest.last_elapsed_ms through to the API logger Signed-off-by: Sidartha-CT --- py-json/LANforge/lfcli_base.py | 38 +++++++++++++++++++++++----------- 1 file changed, 26 insertions(+), 12 deletions(-) diff --git a/py-json/LANforge/lfcli_base.py b/py-json/LANforge/lfcli_base.py index a6b99dd84..e2fcfee53 100644 --- a/py-json/LANforge/lfcli_base.py +++ b/py-json/LANforge/lfcli_base.py @@ -220,7 +220,8 @@ def log_set_filename(filename=None): def _log_api_call(self, method: str, url: str, data: Optional[Any] = None, response_code: Optional[int] = None, error: Optional[Exception] = None, diagnostics: Optional[str] = None, - sent_at: Optional[datetime.datetime] = None) -> None: + sent_at: Optional[datetime.datetime] = None, + elapsed_ms: Optional[float] = None) -> None: """ Record one json_get/json_post/json_put/json_delete call via lanforge_client.api_logger. @@ -234,12 +235,15 @@ def _log_api_call(self, method: str, url: str, data: Optional[Any] = None, respo sent_at: Timestamp captured by LFRequest right before the request was issued (its last_sent_at attribute); falls back to record_api_call's own call time when not available. + elapsed_ms: Wall-clock duration of the underlying urlopen() call in milliseconds + (LFRequest's last_elapsed_ms attribute). None when not measured. Returns: None. """ api_logger.record_api_call(method=method, url=url, data=data, response_code=response_code, - error=error, diagnostics=diagnostics, sent_at=sent_at) + error=error, diagnostics=diagnostics, sent_at=sent_at, + elapsed_ms=elapsed_ms) def json_post(self, _req_url, _data, debug_=False, suppress_related_commands_=None, response_json_list_=None): """ @@ -301,12 +305,14 @@ def json_post(self, _req_url, _data, debug_=False, suppress_related_commands_=No self._log_api_call("POST", _req_url, data=_data, response_code=getattr(json_response, 'status', None) or getattr(lf_r, 'last_response_code', None), error=_api_error, diagnostics=getattr(lf_r, 'last_diagnostics', None), - sent_at=getattr(lf_r, 'last_sent_at', None)) + sent_at=getattr(lf_r, 'last_sent_at', None), + elapsed_ms=getattr(lf_r, 'last_elapsed_ms', None)) exit(1) self._log_api_call("POST", _req_url, data=_data, response_code=getattr(json_response, 'status', None) or getattr(lf_r, 'last_response_code', None), error=_api_error, diagnostics=getattr(lf_r, 'last_diagnostics', None), - sent_at=getattr(lf_r, 'last_sent_at', None)) + sent_at=getattr(lf_r, 'last_sent_at', None), + elapsed_ms=getattr(lf_r, 'last_elapsed_ms', None)) return json_response def json_put(self, _req_url, _data, debug_=False, response_json_list_=None): @@ -350,12 +356,14 @@ def json_put(self, _req_url, _data, debug_=False, response_json_list_=None): self._log_api_call("PUT", _req_url, data=_data, response_code=getattr(json_response, 'status', None) or getattr(lf_r, 'last_response_code', None), error=_api_error, diagnostics=getattr(lf_r, 'last_diagnostics', None), - sent_at=getattr(lf_r, 'last_sent_at', None)) + sent_at=getattr(lf_r, 'last_sent_at', None), + elapsed_ms=getattr(lf_r, 'last_elapsed_ms', None)) exit(1) self._log_api_call("PUT", _req_url, data=_data, response_code=getattr(json_response, 'status', None) or getattr(lf_r, 'last_response_code', None), error=_api_error, diagnostics=getattr(lf_r, 'last_diagnostics', None), - sent_at=getattr(lf_r, 'last_sent_at', None)) + sent_at=getattr(lf_r, 'last_sent_at', None), + elapsed_ms=getattr(lf_r, 'last_elapsed_ms', None)) return json_response def json_get(self, _req_url, debug_=None): @@ -385,7 +393,8 @@ def json_get(self, _req_url, debug_=None): time.sleep(10) self._log_api_call("GET", _req_url, response_code=getattr(lf_r, 'last_response_code', None), diagnostics=getattr(lf_r, 'last_diagnostics', None), - sent_at=getattr(lf_r, 'last_sent_at', None)) + sent_at=getattr(lf_r, 'last_sent_at', None), + elapsed_ms=getattr(lf_r, 'last_elapsed_ms', None)) return None except ValueError as ve: _api_error = ve @@ -396,12 +405,14 @@ def json_get(self, _req_url, debug_=None): if self.exit_on_error: self._log_api_call("GET", _req_url, response_code=getattr(lf_r, 'last_response_code', None), error=_api_error, diagnostics=getattr(lf_r, 'last_diagnostics', None), - sent_at=getattr(lf_r, 'last_sent_at', None)) + sent_at=getattr(lf_r, 'last_sent_at', None), + elapsed_ms=getattr(lf_r, 'last_elapsed_ms', None)) sys.exit(1) self._log_api_call("GET", _req_url, response_code=getattr(lf_r, 'last_response_code', None), error=_api_error, diagnostics=getattr(lf_r, 'last_diagnostics', None), - sent_at=getattr(lf_r, 'last_sent_at', None)) + sent_at=getattr(lf_r, 'last_sent_at', None), + elapsed_ms=getattr(lf_r, 'last_elapsed_ms', None)) return json_response def json_delete(self, _req_url, debug_=False): @@ -425,7 +436,8 @@ def json_delete(self, _req_url, debug_=False): logger.debug("LFCliBase.json_delete: no entity/response, probabily status 404") self._log_api_call("DELETE", _req_url, response_code=getattr(lf_r, 'last_response_code', None), diagnostics=getattr(lf_r, 'last_diagnostics', None), - sent_at=getattr(lf_r, 'last_sent_at', None)) + sent_at=getattr(lf_r, 'last_sent_at', None), + elapsed_ms=getattr(lf_r, 'last_elapsed_ms', None)) return None except ValueError as ve: _api_error = ve @@ -436,12 +448,14 @@ def json_delete(self, _req_url, debug_=False): if self.exit_on_error: self._log_api_call("DELETE", _req_url, response_code=getattr(lf_r, 'last_response_code', None), error=_api_error, diagnostics=getattr(lf_r, 'last_diagnostics', None), - sent_at=getattr(lf_r, 'last_sent_at', None)) + sent_at=getattr(lf_r, 'last_sent_at', None), + elapsed_ms=getattr(lf_r, 'last_elapsed_ms', None)) sys.exit(1) # print("----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ") self._log_api_call("DELETE", _req_url, response_code=getattr(lf_r, 'last_response_code', None), error=_api_error, diagnostics=getattr(lf_r, 'last_diagnostics', None), - sent_at=getattr(lf_r, 'last_sent_at', None)) + sent_at=getattr(lf_r, 'last_sent_at', None), + elapsed_ms=getattr(lf_r, 'last_elapsed_ms', None)) return json_response @staticmethod From ddd8b8ed600d07f5e98186279556faee986ff37f Mon Sep 17 00:00:00 2001 From: Sidartha-CT Date: Mon, 3 Aug 2026 15:42:19 +0000 Subject: [PATCH 18/18] api_logger.py : Use pathlib.Path.home() instead of os.path.expanduser Signed-off-by: Sidartha-CT --- lanforge_client/api_logger.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/lanforge_client/api_logger.py b/lanforge_client/api_logger.py index f19a75eb7..7a03e3528 100644 --- a/lanforge_client/api_logger.py +++ b/lanforge_client/api_logger.py @@ -9,7 +9,7 @@ import datetime import json import logging -import os +from pathlib import Path from typing import Any, Optional logger = logging.getLogger(__name__) @@ -39,7 +39,7 @@ def configure_api_call_logging(enabled: bool, log_filename: Optional[str] = None _logging_paused = False if not _logging_enabled: return - _log_filename = log_filename or os.path.join(os.path.expanduser('~'), 'lf_api_calls.csv') + _log_filename = log_filename or str(Path.home() / 'lf_api_calls.csv') # start each run with a clean log file try: with open(_log_filename, 'w', newline='') as csv_file: