From 166e44da9c3bcaf22ce1896ff829bbbc9819614a Mon Sep 17 00:00:00 2001
From: Kirill Sosnovskikh <k.sosnovskikh@yadro.com>
Date: Thu, 18 Jul 2024 19:48:38 +0300
Subject: [PATCH] [#266] Remove duplicate messages in logs

Signed-off-by: Kirill Sosnovskikh <k.sosnovskikh@yadro.com>
---
 src/frostfs_testlib/shell/local_shell.py   | 49 ++++++++++------------
 src/frostfs_testlib/steps/cli/container.py |  1 -
 src/frostfs_testlib/utils/cli_utils.py     |  5 +--
 3 files changed, 23 insertions(+), 32 deletions(-)

diff --git a/src/frostfs_testlib/shell/local_shell.py b/src/frostfs_testlib/shell/local_shell.py
index acf01ff..2fb6631 100644
--- a/src/frostfs_testlib/shell/local_shell.py
+++ b/src/frostfs_testlib/shell/local_shell.py
@@ -28,10 +28,10 @@ class LocalShell(Shell):
         for inspector in [*self.command_inspectors, *extra_inspectors]:
             command = inspector.inspect(original_command, command)
 
-        logger.info(f"Executing command: {command}")
-        if options.interactive_inputs:
-            return self._exec_interactive(command, options)
-        return self._exec_non_interactive(command, options)
+        with reporter.step(f"Executing command: {command}"):
+            if options.interactive_inputs:
+                return self._exec_interactive(command, options)
+            return self._exec_non_interactive(command, options)
 
     def _exec_interactive(self, command: str, options: CommandOptions) -> CommandResult:
         start_time = datetime.utcnow()
@@ -60,9 +60,7 @@ class LocalShell(Shell):
 
         if options.check and result.return_code != 0:
             raise RuntimeError(
-                f"Command: {command}\nreturn code: {result.return_code}\n"
-                f"Output: {result.stdout}\n"
-                f"Stderr: {result.stderr}\n"
+                f"Command: {command}\nreturn code: {result.return_code}\n" f"Output: {result.stdout}\n" f"Stderr: {result.stderr}\n"
             )
         return result
 
@@ -93,9 +91,7 @@ class LocalShell(Shell):
                 stderr="",
                 return_code=exc.returncode,
             )
-            raise RuntimeError(
-                f"Command: {command}\nError:\n" f"return code: {exc.returncode}\n" f"output: {exc.output}"
-            ) from exc
+            raise RuntimeError(f"Command: {command}\nError with retcode: {exc.returncode}\n Output: {exc.output}") from exc
         except OSError as exc:
             raise RuntimeError(f"Command: {command}\nOutput: {exc.strerror}") from exc
         finally:
@@ -129,22 +125,19 @@ class LocalShell(Shell):
         end_time: datetime,
         result: Optional[CommandResult],
     ) -> None:
-        # TODO: increase logging level if return code is non 0, should be warning at least
-        logger.info(
-            f"Command: {command}\n"
-            f"{'Success:' if result and result.return_code == 0 else 'Error:'}\n"
-            f"return code: {result.return_code if result else ''} "
-            f"\nOutput: {result.stdout if result else ''}"
-        )
+        if not result:
+            logger.warning(f"Command: {command}\n" f"Error: result is None")
+            return
 
-        if result:
-            elapsed_time = end_time - start_time
-            command_attachment = (
-                f"COMMAND: {command}\n"
-                f"RETCODE: {result.return_code}\n\n"
-                f"STDOUT:\n{result.stdout}\n"
-                f"STDERR:\n{result.stderr}\n"
-                f"Start / End / Elapsed\t {start_time.time()} / {end_time.time()} / {elapsed_time}"
-            )
-            with reporter.step(f"COMMAND: {command}"):
-                reporter.attach(command_attachment, "Command execution.txt")
+        status, log_method = ("Success", logger.info) if result.return_code == 0 else ("Error", logger.warning)
+        log_method(f"Command: {command}\n" f"{status} with retcode {result.return_code}\n" f"Output: \n{result.stdout}")
+
+        elapsed_time = end_time - start_time
+        command_attachment = (
+            f"COMMAND: {command}\n"
+            f"RETCODE: {result.return_code}\n\n"
+            f"STDOUT:\n{result.stdout}\n"
+            f"STDERR:\n{result.stderr}\n"
+            f"Start / End / Elapsed\t {start_time.time()} / {end_time.time()} / {elapsed_time}"
+        )
+        reporter.attach(command_attachment, "Command execution.txt")
diff --git a/src/frostfs_testlib/steps/cli/container.py b/src/frostfs_testlib/steps/cli/container.py
index fa739a8..641b321 100644
--- a/src/frostfs_testlib/steps/cli/container.py
+++ b/src/frostfs_testlib/steps/cli/container.py
@@ -200,7 +200,6 @@ def list_containers(wallet: WalletInfo, shell: Shell, endpoint: str, timeout: Op
     """
     cli = FrostfsCli(shell, FROSTFS_CLI_EXEC, wallet.config_path)
     result = cli.container.list(rpc_endpoint=endpoint, timeout=timeout)
-    logger.info(f"Containers: \n{result}")
     return result.stdout.split()
 
 
diff --git a/src/frostfs_testlib/utils/cli_utils.py b/src/frostfs_testlib/utils/cli_utils.py
index d22f5c1..8e019ea 100644
--- a/src/frostfs_testlib/utils/cli_utils.py
+++ b/src/frostfs_testlib/utils/cli_utils.py
@@ -75,7 +75,7 @@ def _attach_allure_log(cmd: str, output: str, return_code: int, start_time: date
         reporter.attach(command_attachment, "Command execution")
 
 
-def log_command_execution(url: str, cmd: str, output: Union[str, TypedDict], params: Optional[dict] = None) -> None:
+def log_command_execution(url: str, cmd: str, output: Union[str, dict], params: Optional[dict] = None) -> None:
     logger.info(f"{cmd}: {output}")
 
     with suppress(Exception):
@@ -90,8 +90,7 @@ def log_command_execution(url: str, cmd: str, output: Union[str, TypedDict], par
         params = json_params
 
     command_attachment = f"COMMAND: '{cmd}'\n" f"URL: {url}\n" f"PARAMS:\n{params}\n" f"OUTPUT:\n{output}\n"
-    with reporter.step(f'COMMAND: {shorten(cmd, width=60, placeholder="...")}'):
-        reporter.attach(command_attachment, "Command execution")
+    reporter.attach(command_attachment, "Command execution")
 
 
 def parse_netmap_output(output: str) -> list[NodeNetmapInfo]: