From 39df9e6d99d1aa0d6974b938e6e4c01c3aacde86 Mon Sep 17 00:00:00 2001 From: Terje Kvernes Date: Wed, 6 Dec 2023 22:17:23 +0100 Subject: [PATCH] Reformat and redesign the recording output. ## Changes - Formats command events into properly related JSON. - Properly record status responses (ok, warning, errors). - Record API requests as a chain related to each command. - Record the raw command issued, the actual command executed, and the command filter applied (if any). - Moves comment handling to OutputManager. - Consolidates stop_recording and save_recording. - Renamed some variables and methods for consistency. ## Issues - We want timestamps in the logs, but they will differ for CI runs and thus fail. There needs to be a configuration option to disable logging timestamps... - The stack details for errors and warnings is bugged. See https://github.com/unioslo/mreg-cli/issues/185 - We buffer the entire recording blob in memory until we stop recording (or we exit). This is to ensure valid JSON for the output, as writing (valid) JSON streams to a file is non-trivial. A solution is to write after each command, reload the file and append the data, then write again. This may or may not be a good idea, and it would look something like: ```python existing_data = [] # Read the existing data from the file try: with open(self._filename, "r") as rec_file: existing_data = json.load(rec_file) except (FileNotFoundError, json.JSONDecodeError): pass existing_data.append(recording_entry) # Write the updated data back to the file with open(self._filename, "w") as rec_file: json.dump(existing_data, rec_file, indent=2) ``` ## Failing tests As this completely redefines the recording output, tests fail miserably. --- mreg_cli/cli.py | 7 +- mreg_cli/log.py | 22 ++---- mreg_cli/outputmanager.py | 153 ++++++++++++++++++++------------------ 3 files changed, 91 insertions(+), 91 deletions(-) diff --git a/mreg_cli/cli.py b/mreg_cli/cli.py index daffecbc..e0745180 100644 --- a/mreg_cli/cli.py +++ b/mreg_cli/cli.py @@ -147,7 +147,7 @@ def parse(self, command: str) -> None: except CliExit: # If we have active recordings going on, save them before exiting - OutputManager().save_recording() + OutputManager().stop_recording() sys.exit(0) else: @@ -212,7 +212,6 @@ def complete(self, cur, words): def process_command_line(self, line: str) -> None: """Process a line containing a command.""" - line = remove_comments(line) # OutputManager is a singleton class so we # need to clear it before each command. output = OutputManager() @@ -245,7 +244,7 @@ def _start_recording(args) -> None: def _stop_recording(args): """Stop recording commands and output to the given file.""" - OutputManager().save_recording() + OutputManager().stop_recording() # Always need a quit command @@ -339,7 +338,7 @@ def source(files: List[str], ignore_errors: bool, verbose: bool) -> Generator[st ) ) ) - OutputManager().record_extra_output(f"{filename}: Error on line {i + 1}") + OutputManager().add_error(f"{filename}: Error on line {i + 1}") if not ignore_errors: return except FileNotFoundError: diff --git a/mreg_cli/log.py b/mreg_cli/log.py index 9f150c47..5fda2e44 100644 --- a/mreg_cli/log.py +++ b/mreg_cli/log.py @@ -42,14 +42,10 @@ def cli_error( msg, ) _write_log(s) + msg = "ERROR: {}: {}".format(pre, msg) + OutputManager().add_error(msg) if raise_exception: # A simplified message for console - msg = "ERROR: {}: {}".format(pre, msg) - manager = OutputManager() - if manager.is_recording(): - # If recording traffic, also record the console output - manager.record_extra_output(msg) - # Raise the exception raise exception(msg) return None @@ -66,13 +62,10 @@ def cli_warning( msg, ) _write_log(s) + msg = "WARNING: {}: {}".format(pre, msg) + OutputManager().add_warning(msg) if raise_exception: # A simplified message for console - msg = "WARNING: {}: {}".format(pre, msg) - manager = OutputManager() - if manager.is_recording(): - # If recording traffic, also record the console output - manager.record_extra_output(msg) raise exception(msg) return None @@ -87,11 +80,8 @@ def cli_info(msg: str, print_msg: bool = False) -> None: msg, ) _write_log(s) + msg = "OK: {}: {}".format(pre, msg) + OutputManager().add_ok(msg) if print_msg: # A simplified message for console - msg = "OK: {}: {}".format(pre, msg) print(msg) - manager = OutputManager() - if manager.is_recording(): - # If recording traffic, also record the console output - manager.record_extra_output(msg) diff --git a/mreg_cli/outputmanager.py b/mreg_cli/outputmanager.py index ee3bec16..19232169 100644 --- a/mreg_cli/outputmanager.py +++ b/mreg_cli/outputmanager.py @@ -6,6 +6,7 @@ """ import atexit +import datetime import json import os import re @@ -114,26 +115,32 @@ class OutputManager: def __new__(cls): if cls._instance is None: cls._instance = super().__new__(cls) - - # Recording related attributes. These must come first as they may - # be encountered when calling clear(). Note that these attributes are - # not reset between commands, which is why they are not themselves - # manipulated in clear(). - cls._recording: bool = False - cls._filename: str = None - cls._recorded_data: List[str] = [] - cls._instance.clear() + cls._instance.clear_recording() return cls._instance def clear(self) -> None: """Clears the object.""" - self._lines = [] + self._output: [str] = [] self._filter_re = None - self._negate = False - self._command = None - self.command = None + self._filter_negate = False + self._command_executed = None + self._command_issued = None + + self._ok: [str] = [] # This is typically commands that went OK but returned no content + self._warnings: [str] = [] + self._errors: [str] = [] + + self._api_requests: [str] = [] + + self._exceptions: [Exception] = [] + + def clear_recording(self) -> None: + """Clears the recording data.""" + self._recorded_data = [] + self._recording = False + self._filename = None def start_recording(self, filename: str) -> None: """Declare intent to start recording to the given filename. @@ -152,25 +159,14 @@ def start_recording(self, filename: str) -> None: self._recording = True self._filename = filename - atexit.register(self.save_recording) + atexit.register(self.stop_recording) try: os.remove(filename) except OSError: pass def stop_recording(self) -> None: - """Declare intent to stop recording. - - This will delete the recorded data if it has not been saved. - - Note: This does not save the recording, use save_recording() for that. - """ - self._recorded_data = [] - self._recording = False - self._filename = None - - def save_recording(self) -> None: - """Save the recording to the file. + """Stop the recording and save the recording to the file. Returns gracefully if recording is not active. """ @@ -180,7 +176,47 @@ def save_recording(self) -> None: with open(self._filename, "w") as rec_file: json.dump(self._recorded_data, rec_file, indent=2) - self.stop_recording() + self.clear_recording() + + def create_recording_entry(self) -> Dict[str, Any]: + """Create a recording entry.""" + + return { + "command": self._command_executed, + "command_filter": self._filter_re.pattern if self._filter_re else None, + "command_issued": self._command_issued, + "ok": self._ok, + "warning": self._warnings, + "error": self._errors, + "output": self.filtered_output(), + # We probably want timestamps in the recording, but we need to disable + # this for CI runs as they will obviously fail if the timestamp changes. + # TODO: Make this configurable + # "timestamp": datetime.datetime.now().isoformat(sep=" ", timespec="seconds"), + # "timestamp_as_epoch": int(datetime.datetime.now().timestamp()), + "api_requests": self._api_requests, + } + + def add_warning(self, msg: str) -> None: + """Add a warning event to the output. + + :param msg: The warning message. + """ + self._warnings.append(msg) + + def add_error(self, msg: str) -> None: + """Add an error event to the output. + + :param msg: The error message. + """ + self._errors.append(msg) + + def add_ok(self, msg: str) -> None: + """Add an OK event to the output. + + :param msg: The ok message. + """ + self._ok.append(msg) def is_recording(self) -> bool: """Returns True if recording is active.""" @@ -195,45 +231,18 @@ def recording_filename(self) -> Optional[str]: return None return self._filename - def record_command(self, command: str) -> None: - """Record a command, if recording is active. - - :param command: The command to record. - """ - if not self.is_recording() or not command: - return - - # Do not record commands starting with any of the commands in - # COMMANDS_NOT_TO_RECORD - if any(command.startswith(cmd) for cmd in self.COMMANDS_NOT_TO_RECORD): - return - - # Do not record empty commands - if command and command != "\n": - self._recorded_data.append({"command": command}) - - def record_extra_output(self, output: str) -> None: - """Record extra output, if recording is active. - - :param output: The output to record. - """ - if not self.is_recording() or not output: - return - - self._recorded_data.append({"output": output}) - def record_output(self) -> None: """Record the output, if recording is active.""" - # Don't record if we're not recording, and don't record - # output as the empty output - if not self.is_recording() or not self._recorded_data: + command = self._command_executed + # Note that we may record commands without output as they may have + # warnings or errors. + if not command or not self.is_recording(): return - if not self.lines(): + if any(command.startswith(cmd) for cmd in self.COMMANDS_NOT_TO_RECORD): return - output = "\n".join(self.lines()) - self._recorded_data.append({"output": output}) + self._recorded_data.append(self.create_recording_entry()) def record_request( self, method: str, url: str, params: str, data: Dict[str, Any], result: requests.Response @@ -257,11 +266,11 @@ def record_request( # false-like values (0, False, etc) if s != "": ret_dict["response"] = s - self._recorded_data.append(ret_dict) + self._api_requests.append(ret_dict) def has_output(self) -> bool: """Returns True if there is output to display.""" - return len(self._lines) > 0 + return len(self._output) > 0 def from_command(self, command: str) -> str: """Adds the command that generated the output. @@ -272,16 +281,18 @@ def from_command(self, command: str) -> str: :raises CliError: If the command is invalid. :return: The cleaned command, devoid of filters and other noise. """ - self._command, self._filter_re, self._negate = self.get_filter(command) - self.record_command(command) - return self._command + self._command_issued = command.rstrip() + self._command_executed, self._filter_re, self._filter_negate = self.get_filter( + remove_comments(self._command_issued) + ) + return self._command_executed def add_line(self, line: str) -> None: """Adds a line to the output. :param line: The line to add. """ - self._lines.append(line) + self._output.append(line) def add_formatted_line(self, key: str, value: str, padding: int = 14) -> None: """Formats and adds a key-value pair as a line. @@ -373,7 +384,7 @@ def add_formatted_table( for d in data: self.add_line(raw_format.format(*[d[key] for key in keys])) - def lines(self) -> List[str]: + def filtered_output(self) -> List[str]: """Return the lines of output. If the command is set, and it has a filter, the lines will @@ -382,13 +393,13 @@ def lines(self) -> List[str]: Note: This filtering is not cached, so repeated calls will re-filter the output (to the same result, presumably). """ - lines = self._lines + lines = self._output filter_re = self._filter_re if filter_re is None: return lines - if self._negate: + if self._filter_negate: return [line for line in lines if not filter_re.search(line)] return [line for line in lines if filter_re.search(line)] @@ -396,9 +407,9 @@ def lines(self) -> List[str]: def render(self) -> None: """Prints the output to stdout, and records it if recording is active.""" self.record_output() - for line in self.lines(): + for line in self.filtered_output(): print(line) def __str__(self) -> str: """Returns the formatted output as a single string.""" - return "\n".join(self._lines) + return "\n".join(self._output)