From 50b975584a3ea8057b2f896378ae28aa2f14d845 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. - 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. - 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) ``` As this completely redefines the recording output, tests fail miserably. --- mreg_cli/cli.py | 7 +- mreg_cli/log.py | 22 ++---- mreg_cli/outputmanager.py | 147 ++++++++++++++++++++------------------ 3 files changed, 87 insertions(+), 89 deletions(-) diff --git a/mreg_cli/cli.py b/mreg_cli/cli.py index a2eb2f60..44dfae81 100644 --- a/mreg_cli/cli.py +++ b/mreg_cli/cli.py @@ -167,7 +167,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: @@ -246,7 +246,6 @@ def complete(self, cur: str, words: str) -> Generator[Union[Completion, Any], An 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() @@ -279,7 +278,7 @@ def _start_recording(args: argparse.Namespace) -> None: def _stop_recording(args: argparse.Namespace): """Stop recording commands and output to the given file.""" - OutputManager().save_recording() + OutputManager().stop_recording() # Always need a quit command @@ -374,7 +373,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 ea946090..0d8aedb0 100644 --- a/mreg_cli/log.py +++ b/mreg_cli/log.py @@ -46,14 +46,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 @@ -70,13 +66,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 @@ -91,11 +84,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 53ac8c52..97454787 100644 --- a/mreg_cli/outputmanager.py +++ b/mreg_cli/outputmanager.py @@ -115,26 +115,32 @@ def __new__(cls): """Create a new instance of the class, or return the existing one.""" 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: """Clear 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. @@ -153,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. """ @@ -181,7 +176,46 @@ 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: """Return True if recording is active.""" @@ -196,45 +230,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 @@ -259,7 +266,7 @@ 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: """Return True if there is output to display.""" @@ -274,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: """Add 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: """Format and add a key-value pair as a line. @@ -382,7 +391,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 @@ -391,13 +400,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)] @@ -405,7 +414,7 @@ def lines(self) -> List[str]: def render(self) -> None: """Print 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: