Add option to save API URLs and response code , which called in particular script.

lanforge_client/api_call_logger.py

@@ -0,0 +1,82 @@
+#!/usr/bin/env python3
+"""
+Shared, lightweight API call logger.
+
+This exists so any code path that talks to a LANforge GUI -- the legacy
+py-json/LANforge/LFRequest.py request layer (used via LFCliBase/Realm), or
+lanforge_api.py's own request layer -- can record the same kind of entry
+(url, payload, response code, session id) to the same kind of rotating log
+file, without each path reimplementing rotation/formatting itself.
+"""
+import os
+import json
+import logging
+import logging.handlers
+import datetime
+
+_api_loggers = {}
+
+
+def get_api_logger(filename, max_bytes=10 * 1024 * 1024, backup_count=10):
+    """
+    Return a cached, rotating file logger for `filename`. Callers that pass the same
+    filename (even from different LFCliBase/Realm instances, or a different request layer
+    entirely) share one logger/handler, so log lines are never duplicated and the file
+    rotates once instead of racing multiple independent handlers against each other.
+    :param filename: path to the api log file
+    :param max_bytes: rotate once the active file reaches this size
+    :param backup_count: number of rotated backups to keep
+    :return: a logging.Logger configured with a RotatingFileHandler
+    """
+    key = os.path.abspath(filename)
+    if key in _api_loggers:
+        return _api_loggers[key]
+    api_logger = logging.getLogger("lanforge_client.api_call_logger.%s" % key)
+    api_logger.setLevel(logging.INFO)
+    api_logger.propagate = False
+    handler = logging.handlers.RotatingFileHandler(filename, maxBytes=max_bytes, backupCount=backup_count)
+    handler.setFormatter(logging.Formatter("%(message)s"))
+    api_logger.addHandler(handler)
+    _api_loggers[key] = api_logger
+    return api_logger
+
+
+def log_api_call(api_logger, method, url, session_id=None, data=None, response_code=None, error=None,
+                 diagnostics=None):
+    """
+    Format and emit one lightweight record of an API call via api_logger. No-op if
+    api_logger is None, so callers can pass through a possibly-absent logger without
+    guarding every call site themselves.
+    :param api_logger: a logger from get_api_logger(), or None to skip silently
+    :param method: "GET" | "POST" | "PUT" | "DELETE"
+    :param url: requested url
+    :param session_id: the lanforge_api session id ("cookie") tying this call to the
+    LANforge GUI's own request logs, if available
+    :param data: payload sent (POST/PUT only)
+    :param response_code: HTTP status code returned by the call, if any
+    :param error: exception raised by the call, if any -- marks the entry as ERROR
+    :param diagnostics: one-line summary of a caught HTTPError/URLError (reason,
+    X-Error-* headers, etc.)
+    """
+    if api_logger is None:
+        return
+    if error is not None:
+        status = "ERROR"
+    elif response_code is not None:
+        status = "OK" if 200 <= response_code < 300 else "ERROR"
+    else:
+        status = "UNKNOWN"
+    lines = ["%s session=%s %s %s [%s]" %
+            (datetime.datetime.now().isoformat(), session_id or '-', method, url, status)]
+    if data is not None:
+        lines.append("  payload: %s" % json.dumps(data, default=str))
+    if error is not None:
+        lines.append("  error: %s" % error)
+    if response_code is not None:
+        lines.append("  response_code: %s" % response_code)
+    if diagnostics is not None:
+        lines.append("  diagnostics: %s" % diagnostics)
+    try:
+        api_logger.info("\n".join(lines))
+    except Exception:
+        logging.getLogger(__name__).debug("log_api_call: unable to emit log line", exc_info=True)

lanforge_client/lanforge_api.py

@@ -101,6 +101,7 @@ class which appends subclasses to it.
 
 # - - - - deployed import references - - - - -
 from .strutil import nott, iss
+from .api_call_logger import get_api_logger, log_api_call
 
 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,14 +208,15 @@ 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: ---------------------------------------------")
         LOGGER.error("%s <%s> HTTP %s: %s" % (method, err_full_url, err_code, err_reason))
         LOGGER.error("------------------------------------------------------------------------")
     if die_on_error_:
         exit(1)
+    return summary
 
 
 class BaseLFJsonRequest:
@@ -242,6 +248,10 @@ def __init__(self,
         self.session_instance = None
         self.stream_errors: bool = True
         self.stream_warnings: bool = False
+        # set by get()/json_post() so _log_api_call() can report the outcome of the last
+        # attempt even when it ended in a caught HTTPError/URLError
+        self.last_response_code = None
+        self.last_diagnostics = None
 
         if not session_obj:
             logging.getLogger(__name__).warning("BaseLFJsonRequest: no session instance")
@@ -320,6 +330,18 @@ def add_warning(self, message: str = None):
     def get_errors(self) -> list:
         return self.error_list
 
+    def _log_api_call(self, method, url, data=None, response_code=None, diagnostics=None):
+        """
+        Record one json_get/json_post/json_put/json_delete call via the shared
+        lanforge_client.api_call_logger, tagged with this session's id. No-op unless
+        self.session_instance.save_api is True.
+        """
+        if not getattr(self.session_instance, 'save_api', False):
+            return
+        log_api_call(getattr(self.session_instance, '_api_logger', None), method, url,
+                     session_id=self.session_instance.get_session_id(),
+                     data=data, response_code=response_code, diagnostics=diagnostics)
+
     def get_warnings(self) -> list:
         return self.warnings
 
@@ -635,20 +657,25 @@ def json_post(self,
                     self.logger.debug("----------------- BAD STATUS --------------------------------")
                     if die_on_error:
                         sys.exit(1)
+                self.last_response_code = response.status
+                self._log_api_call(method_, url, data=post_data, response_code=self.last_response_code)
                 return responses[0]
 
             except urllib.error.HTTPError as herror:
                 # 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):
                     die_on_error = True
-                print_diagnostics(url_=url,
-                                  request_=myrequest,
-                                  responses_=responses,
-                                  error_=herror,
-                                  debug_=debug,
-                                  die_on_error_=die_on_error)
+                self.last_response_code = herror.code
+                self.last_diagnostics = print_diagnostics(url_=url,
+                                                          request_=myrequest,
+                                                          responses_=responses,
+                                                          error_=herror,
+                                                          debug_=debug,
+                                                          die_on_error_=die_on_error)
                 if die_on_error:
+                    self._log_api_call(method_, url, data=post_data, response_code=self.last_response_code,
+                                       diagnostics=self.last_diagnostics)
                     sys.exit(1)
 
             except urllib.error.URLError as uerror:
@@ -660,17 +687,21 @@ def json_post(self,
                     break
                 else:
                     logging.error("Connection refused: "+url)
-                    print_diagnostics(url_=url,
-                                      request_=myrequest,
-                                      responses_=responses,
-                                      error_=uerror,
-                                      debug_=debug,
-                                      die_on_error_=die_on_error)
+                    self.last_diagnostics = print_diagnostics(url_=url,
+                                                              request_=myrequest,
+                                                              responses_=responses,
+                                                              error_=uerror,
+                                                              debug_=debug,
+                                                              die_on_error_=die_on_error)
                 if die_on_error:
+                    self._log_api_call(method_, url, data=post_data, response_code=self.last_response_code,
+                                       diagnostics=self.last_diagnostics)
                     sys.exit(1)
             # ~while
             LOGGER.error("json_post: request will try again in 2 sec")
             time.sleep(2)
+        self._log_api_call(method_, url, data=post_data, response_code=self.last_response_code,
+                           diagnostics=self.last_diagnostics)
         if die_on_error:
             sys.exit(1)
         return None
@@ -800,26 +831,28 @@ def get(self,
         myresponses: list = []  # list[HTTPResponse]
         try:
             myresponses.append(request.urlopen(myrequest))
+            self.last_response_code = getattr(myresponses[0], 'status', None)
             return myresponses[0]
 
         except urllib.error.HTTPError as herror:
-            print_diagnostics(url_=requested_url,
-                              request_=myrequest,
-                              responses_=myresponses,
-                              error_=herror,
-                              error_list_=self.error_list,
-                              debug_=debug,
-                              die_on_error_=die_on_error)
+            self.last_response_code = herror.code
+            self.last_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)
             if die_on_error:
                 sys.exit(1)
         except urllib.error.URLError as uerror:
-            print_diagnostics(url_=requested_url,
-                              request_=myrequest,
-                              responses_=myresponses,
-                              error_=uerror,
-                              error_list_=self.error_list,
-                              debug_=debug,
-                              die_on_error_=die_on_error)
+            self.last_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)
             if die_on_error:
                 sys.exit(1)
         if die_on_error:
@@ -863,6 +896,8 @@ def get_as_json(self,
         if responses[0] is None:
             if debug:
                 self.logger.debug(msg="No response from " + url)
+            self._log_api_call(method_, url, response_code=self.last_response_code,
+                               diagnostics=self.last_diagnostics)
             return None
 
         json_data = json.loads(responses[0].read().decode('utf-8'))
@@ -872,6 +907,8 @@ def get_as_json(self,
             if "warnings" in responses[0]:
                 errors_warnings.extend(json_data["warnings"])
 
+        self._log_api_call(method_, url, response_code=self.last_response_code,
+                           diagnostics=self.last_diagnostics)
         return json_data
 
     def json_get(self,
@@ -1179,10 +1216,26 @@ def __init__(self, lfclient_url: str = 'http://localhost:8080',
                  retry_sec: float = Default_Retry_Sec,
                  stream_errors: bool = True,
                  stream_warnings: bool = False,
-                 exit_on_error: bool = False):
+                 exit_on_error: bool = False,
+                 save_api: bool = False,
+                 api_log_file_name: str = None,
+                 api_log_max_bytes: int = 10 * 1024 * 1024,
+                 api_log_backup_count: int = 10):
         self.debug_on = debug
         # self.logger = Logg(name='json_api_session')
         self.logger = logging.getLogger(__name__)
+        # when True, json_get/json_post/json_put/json_delete append a lightweight record of
+        # each call (url, payload, response_code/error) to api_log_filename, tagged with this
+        # session's id -- see lanforge_client/api_call_logger.py. The file rotates instead of
+        # growing unbounded, so it's safe to leave enabled indefinitely.
+        self.save_api = save_api
+        self.api_log_filename = api_log_file_name or os.path.join(os.path.expanduser('~'), 'lf_api_calls.log')
+        self._api_logger = None
+        if self.save_api:
+            try:
+                self._api_logger = get_api_logger(self.api_log_filename, api_log_max_bytes, api_log_backup_count)
+            except Exception as x:
+                self.logger.debug("BaseSession: unable to set up api logger for %s: %s" % (self.api_log_filename, x))
 
         if debug:
             self.logger.level = logging.DEBUG
@@ -25531,7 +25584,11 @@ def __init__(self, lfclient_url: str = 'http://localhost:8080',
                  stream_errors: bool = True,
                  stream_warnings: bool = False,
                  require_session: bool = False,
-                 exit_on_error: bool = False):
+                 exit_on_error: bool = False,
+                 save_api: bool = False,
+                 api_log_file_name: str = None,
+                 api_log_max_bytes: int = 10 * 1024 * 1024,
+                 api_log_backup_count: int = 10):
         """
         :param debug: turn on diagnostic information
         :param proxy_map: a dict with addresses of proxies to route requests through.
@@ -25544,14 +25601,25 @@ def __init__(self, lfclient_url: str = 'http://localhost:8080',
         :param require_session: exit(1) if unable to establish a session_id
         :param exit_on_error: on requests failing HTTP requests on besides error 404,
         exit(1). This does not include failing to establish a session_id
+        :param save_api: when True, append a lightweight record of every json_get/json_post/
+        json_put/json_delete call (url, payload, response_code/error) to api_log_file_name,
+        tagged with this session's id
+        :param api_log_file_name: path to the api log file used when save_api is True
+        (default: ~/lf_api_calls.log)
+        :param api_log_max_bytes: rotate the api log once it reaches this size
+        :param api_log_backup_count: number of rotated api log backups to keep
         """
         super().__init__(lfclient_url=lfclient_url,
                          debug=debug,
                          proxy_map=proxy_map,
                          connection_timeout_sec=connection_timeout_sec,
                          stream_errors=stream_errors,
                          stream_warnings=stream_warnings,
-                         exit_on_error=exit_on_error)
+                         exit_on_error=exit_on_error,
+                         save_api=save_api,
+                         api_log_file_name=api_log_file_name,
+                         api_log_max_bytes=api_log_max_bytes,
+                         api_log_backup_count=api_log_backup_count)
         self.command_instance = LFJsonCommand(session_obj=self, debug=debug, exit_on_error=exit_on_error)
         self.session_connection_check = \
             self.command_instance.start_session(debug=debug,