Reduce ntttcp performance log volume

Expose the existing no_debug_log process option through the ntttcp and lagscope tool wrappers so noisy long-running performance commands can suppress per-line stdout logging without losing captured output.

Enable the option in perf_ntttcp for the ntttcp server/client and lagscope latency sidecar commands. This keeps result parsing intact while reducing DEBUG file log growth during high-connection retry loops.

Author: vyadavmsft

lisa/microsoft/testsuites/performance/common.py

@@ -514,7 +514,8 @@ def perf_ntttcp(  # noqa: C901
                             lagscope_server_ip
                             if lagscope_server_ip is not None
                             else server.internal_address
-                        )
+                        ),
+                        no_debug_log=True,
                     )
 
                     # Start ntttcp server asynchronously to accept incoming
@@ -530,6 +531,7 @@ def perf_ntttcp(  # noqa: C901
                         buffer_size=buffer_size,
                         dev_differentiator=dev_differentiator,
                         udp_mode=udp_mode,
+                        no_debug_log=True,
                     )
 
                     # Start lagscope client to measure latency during the
@@ -544,6 +546,7 @@ def perf_ntttcp(  # noqa: C901
                         length_of_histogram_intervals=0,
                         count_of_histogram_intervals=0,
                         dump_csv=False,
+                        no_debug_log=True,
                     )
 
                     # Run ntttcp client and monitor for hangs
@@ -556,6 +559,7 @@ def perf_ntttcp(  # noqa: C901
                         ports_count=num_threads_p,
                         dev_differentiator=dev_differentiator,
                         udp_mode=udp_mode,
+                        no_debug_log=True,
                     )
 
                     # Stop the server and collect results from both client

lisa/tools/lagscope.py

@@ -136,15 +136,17 @@ def restore_busy_poll(self) -> None:
         for key in self._busy_pool_keys:
             sysctl.write(key, self._original_settings[key])
 
-    def run_as_server_async(self, ip: str = "") -> Process:
+    def run_as_server_async(self, ip: str = "", no_debug_log: bool = False) -> Process:
         # -r: run as a receiver
         # -rip: run as server mode with specified ip address
         cmd = ""
         if ip:
             cmd += f" -r{ip}"
         else:
             cmd += " -r"
-        process = self.run_async(cmd, sudo=True, shell=True, force_run=True)
+        process = self.run_async(
+            cmd, sudo=True, shell=True, force_run=True, no_debug_log=no_debug_log
+        )
         if not process.is_running():
             raise LisaException("lagscope server failed to start")
         if not self.node.tools[Lsof].is_port_opened_per_process_name(self.command):
@@ -164,6 +166,7 @@ def run_as_client_async(
         count_of_histogram_intervals: int = 30,
         dump_csv: bool = True,
         daemon: bool = False,
+        no_debug_log: bool = False,
     ) -> Process:
         # -s: run as a sender
         # -i: test interval
@@ -197,7 +200,7 @@ def run_as_client_async(
             cmd += " -P "
         if dump_csv:
             cmd += f" -RLatency-{get_datetime_path()}.csv "
-        process = self.node.execute_async(cmd, shell=True)
+        process = self.node.execute_async(cmd, shell=True, no_debug_log=no_debug_log)
         return process
 
     def run_as_client(
@@ -213,6 +216,7 @@ def run_as_client(
         count_of_histogram_intervals: int = 30,
         dump_csv: bool = True,
         daemon: bool = False,
+        no_debug_log: bool = False,
     ) -> ExecutableResult:
         process = self.run_as_client_async(
             server_ip,
@@ -226,6 +230,7 @@ def run_as_client(
             count_of_histogram_intervals,
             dump_csv,
             daemon,
+            no_debug_log,
         )
 
         result = process.wait_result()
@@ -533,7 +538,7 @@ def restore_busy_poll(self) -> None:
         # This is not supported on FreeBSD.
         return
 
-    def run_as_server_async(self, ip: str = "") -> Process:
+    def run_as_server_async(self, ip: str = "", no_debug_log: bool = False) -> Process:
         return self.node.tools[Sockperf].start_server_async("tcp")
 
     def run_as_client_async(
@@ -549,6 +554,7 @@ def run_as_client_async(
         count_of_histogram_intervals: int = 30,
         dump_csv: bool = True,
         daemon: bool = False,
+        no_debug_log: bool = False,
     ) -> Process:
         return self.node.tools[Sockperf].run_client_async("tcp", server_ip)
 
@@ -565,6 +571,7 @@ def run_as_client(
         count_of_histogram_intervals: int = 30,
         dump_csv: bool = True,
         daemon: bool = False,
+        no_debug_log: bool = False,
     ) -> ExecutableResult:
         process = self.run_as_client_async(
             server_ip,
@@ -578,6 +585,7 @@ def run_as_client(
             count_of_histogram_intervals,
             dump_csv,
             daemon,
+            no_debug_log,
         )
         result = process.wait_result()
         return result

lisa/tools/ntttcp.py

@@ -214,6 +214,7 @@ def run_as_server_async(
         dev_differentiator: str = "Hypervisor callback interrupts",
         run_as_daemon: bool = False,
         udp_mode: bool = False,
+        no_debug_log: bool = False,
     ) -> Process:
         cmd = ""
         if server_ip:
@@ -236,6 +237,7 @@ def run_as_server_async(
             f"ulimit -n 204800 && {self.pre_command}{self.command} {cmd}",
             shell=True,
             sudo=True,
+            no_debug_log=no_debug_log,
         )
         # NTTTCP for Linux 1.4.0
         # ---------------------------------------------------------
@@ -258,6 +260,7 @@ def run_as_server(
         dev_differentiator: str = "Hypervisor callback interrupts",
         run_as_daemon: bool = False,
         udp_mode: bool = False,
+        no_debug_log: bool = False,
     ) -> ExecutableResult:
         # -rserver_ip: run as a receiver with specified server ip address
         # -P: Number of ports listening on receiver side [default: 16] [max: 512]
@@ -286,6 +289,7 @@ def run_as_server(
             dev_differentiator,
             run_as_daemon,
             udp_mode,
+            no_debug_log,
         )
 
         return self.wait_server_result(process)
@@ -309,6 +313,7 @@ def run_as_client_async(
         dev_differentiator: str = "Hypervisor callback interrupts",
         run_as_daemon: bool = False,
         udp_mode: bool = False,
+        no_debug_log: bool = False,
     ) -> Process:
         cmd = (
             f" -s{server_ip} -P {ports_count} -n {threads_count} -t {run_time_seconds} "
@@ -325,6 +330,7 @@ def run_as_client_async(
             f"ulimit -n 204800 && {self.pre_command}{self.command} {cmd}",
             shell=True,
             sudo=True,
+            no_debug_log=no_debug_log,
         )
         return process
 
@@ -342,6 +348,7 @@ def run_as_client(
         run_as_daemon: bool = False,
         udp_mode: bool = False,
         tolerance_seconds: int = 60,
+        no_debug_log: bool = False,
     ) -> ExecutableResult:
         # -sserver_ip: run as a sender with server ip address
         # -P: Number of ports listening on receiver side [default: 16] [max: 512]
@@ -373,6 +380,7 @@ def run_as_client(
             dev_differentiator,
             run_as_daemon,
             udp_mode,
+            no_debug_log,
         )
         return process.wait_result(
             expected_exit_code=0,
@@ -868,6 +876,7 @@ def run_as_server_async(
         dev_differentiator: str = "Hypervisor callback interrupts",
         run_as_daemon: bool = False,
         udp_mode: bool = False,
+        no_debug_log: bool = False,
     ) -> Process:
         assert server_ip, "server ip is required for ntttcp server"
         self._log.debug(
@@ -889,6 +898,7 @@ def run_as_server_async(
             f"ulimit -n 204800 && {self.pre_command}{self.command} {cmd}",
             shell=True,
             sudo=True,
+            no_debug_log=no_debug_log,
         )
         time.sleep(5)
 
@@ -908,6 +918,7 @@ def run_as_client(
         run_as_daemon: bool = False,
         udp_mode: bool = False,
         tolerance_seconds: int = 60,
+        no_debug_log: bool = False,
     ) -> ExecutableResult:
         self._log.debug(
             "Paramers nic_name, cool_down_time_seconds, warm_up_time_seconds, "
@@ -928,6 +939,7 @@ def run_as_client(
             expected_exit_code=0,
             expected_exit_code_failure_message=f"fail to run {self.command} {cmd}",
             timeout=run_time_seconds + tolerance_seconds,
+            no_debug_log=no_debug_log,
         )
         return result
 

lisa/util/logger.py

@@ -99,11 +99,17 @@ def _filter_secrets(self, value: Any) -> Any:
 
 
 class LogWriter(object):
-    def __init__(self, logger: Logger, level: int):
+    def __init__(
+        self,
+        logger: Logger,
+        level: int,
+        capture_stream: Optional[TextIO] = None,
+    ):
         self._level = level
         self._log = logger
         self._buffer: str = ""
         self._flushing: bool = False
+        self._capture_stream = capture_stream
 
     def write(self, message: str) -> None:
         if not self._flushing:
@@ -117,7 +123,10 @@ def flush(self) -> None:
             try:
                 buffer = self._buffer
                 self._buffer = ""
-                self._log.lines(self._level, buffer)
+                if self._capture_stream:
+                    self._capture_stream.write(buffer)
+                if self._level != logging.NOTSET:
+                    self._log.lines(self._level, buffer)
             finally:
                 self._flushing = False
 

lisa/util/process.py

@@ -257,10 +257,25 @@ def start(
         if no_error_log:
             stderr_level = stdout_level
 
+        stdout_capture_stream = (
+            self.log_buffer if stdout_level == logging.NOTSET else None
+        )
+        stderr_capture_stream = (
+            self.log_buffer if stderr_level == logging.NOTSET else None
+        )
+
         self.stdout_logger = get_logger("stdout", parent=self._log)
         self.stderr_logger = get_logger("stderr", parent=self._log)
-        self._stdout_writer = LogWriter(logger=self.stdout_logger, level=stdout_level)
-        self._stderr_writer = LogWriter(logger=self.stderr_logger, level=stderr_level)
+        self._stdout_writer = LogWriter(
+            logger=self.stdout_logger,
+            level=stdout_level,
+            capture_stream=stdout_capture_stream,
+        )
+        self._stderr_writer = LogWriter(
+            logger=self.stderr_logger,
+            level=stderr_level,
+            capture_stream=stderr_capture_stream,
+        )
 
         self._log_handler = logging.StreamHandler(self.log_buffer)
         msg_only_format = logging.Formatter(fmt="%(message)s", datefmt="")