Quieter logs, better port allocation, improve output capture

classes/commands/IgorRunTestsCommand.py

@@ -416,18 +416,23 @@ def change_directory(self, path: Path):
             LOGGER.error(f'Failed to change directory: {e}')
 
     def download_and_extract(self, url, extract_path: Path):
-        # Download the file
+        # Download the file to a temp file to avoid loading entire zip into memory
         LOGGER.info('Downloading file from URL: %s', url)
-        response = requests.get(url)
+        tmp_path = extract_path / '_download.zip'
+        extract_path.mkdir(parents=True, exist_ok=True)
+        with requests.get(url, stream=True, timeout=60) as response:
+            response.raise_for_status()
+            with open(tmp_path, 'wb') as f:
+                shutil.copyfileobj(response.raw, f)
         LOGGER.info('Download complete')
 
-        # Open the file in memory
-        with zipfile.ZipFile(io.BytesIO(response.content)) as zf:
-            # Extract the file to the specified path
+        with zipfile.ZipFile(tmp_path) as zf:
             LOGGER.info('Extracting file to: %s', extract_path)
             zf.extractall(extract_path)
             LOGGER.info('Extraction complete')
 
+        tmp_path.unlink()
+
     def accepts_no_build_param(self, version):
         # Split version string into major, minor, rev, build
         try:
@@ -685,13 +690,17 @@ def start_android_emulator(self, sdk_path: Path) -> str:
 
         # Wait for the emulator to appear in the adb devices list
         LOGGER.info('Waiting for emulator to connect to ADB')
-        while True:
+        max_adb_wait = 120
+        for _ in range(max_adb_wait):
             result = subprocess.run([adb_path, 'devices'], capture_output=True, text=True)
             lines = result.stdout.strip().split("\n")[1:]
             emulators = [line.split("\t")[0] for line in lines if "emulator" in line]
             if len(emulators) > 0:
                 break
             time.sleep(1)
+        else:
+            LOGGER.error('Timeout waiting for emulator to connect to ADB')
+            return None
 
         emulator_id = emulators[0]
         LOGGER.info(f'Connected emulator id: {emulator_id}')

classes/commands/RunTestsCommand.py

@@ -1,6 +1,5 @@
 import argparse
 import asyncio
-import logging
 import os
 import requests
 import shutil
@@ -12,6 +11,7 @@
 from classes.commands.BaseCommand import DEFAULT_CONFIG, HTTP_PORT, TCP_PORT, BaseCommand
 from classes.server.TestFrameworkServer import manage_server
 from utils import async_utils, file_utils
+from utils.logging_utils import LOGGER
 from utils.path_utils import ROOT_DIR
 
 PROJECTS_DIR = ROOT_DIR / 'projects'
@@ -76,22 +76,22 @@ async def execute(self) -> None:
 
         try:
             build_job, run_job = self.get_argument("build_jobs").split(";")
-        except:
-            logging.error(f"Invalid build jobs format: {self.get_argument('build_jobs')}. Expected format: <build_job>;<run_job>")
+        except ValueError:
+            LOGGER.error(f"Invalid build jobs format: {self.get_argument('build_jobs')}. Expected format: <build_job>;<run_job>")
             return
 
         if Path(self.get_argument("output_folder")).exists() and any(Path(self.get_argument("output_folder")).iterdir()):
-            logging.warning(f"Output folder '{self.get_argument('output_folder')}' is not empty. Previous results may affect the test run.")
-            logging.warning("Consider cleaning the output folder before running tests or specifying a different folder.")
+            LOGGER.warning(f"Output folder '{self.get_argument('output_folder')}' is not empty. Previous results may affect the test run.")
+            LOGGER.warning("Consider cleaning the output folder before running tests or specifying a different folder.")
 
         # Build the project first
         build_args = self._build_gmrt_arguments(build_job, project_tool_path)
         build_process = await async_utils.run_exe(gmrt_exe, build_args)
         build_output = await async_utils.capture_output(build_process, asyncio.Event())
         await build_process.wait()
         if build_process.returncode != 0:
-            logging.error(f"Build job failed (exit code {build_process.returncode}). Aborting test run.")
-            logging.error(f"Build output:\n{build_output}")
+            LOGGER.error(f"Build job failed (exit code {build_process.returncode}). Aborting test run.")
+            LOGGER.error(f"Build output:\n{build_output}")
             return
 
         # Now we can start the remote control server to run tests.
@@ -129,7 +129,7 @@ async def _install_and_prepare_project_tool(self) -> Path:
         project_tool_package_url = f'{GMPM_REGISTRY_URL}/{PROJECT_TOOL_PACKAGE}'
 
         # Fetch the JSON metadata
-        response = requests.get(project_tool_package_url)
+        response = requests.get(project_tool_package_url, timeout=30)
         response.raise_for_status()
 
         data = response.json()
@@ -145,12 +145,12 @@ async def _install_and_prepare_project_tool(self) -> Path:
 
         # 4. Download the tarball
         tarball_filename = WORKSPACE_DIR /f"project-tool-win-x64-{latest_version}.tgz"
-        with requests.get(tarball_url, stream=True) as tarball_response:
+        with requests.get(tarball_url, stream=True, timeout=30) as tarball_response:
             tarball_response.raise_for_status()
             with open(tarball_filename, "wb") as f:
                 shutil.copyfileobj(tarball_response.raw, f)
 
-        logging.info(f"Downloaded ProjectTool tarball: {tarball_filename}")
+        LOGGER.info(f"Downloaded ProjectTool tarball: {tarball_filename}")
 
         import tarfile
         with tarfile.open(tarball_filename) as tf:

utils/async_utils.py

@@ -101,31 +101,29 @@ async def run_and_monitor_exe(exe_path: str, args: list[str], stop_event: asynci
 
     LOGGER.info("Monitoring loop terminated.")
 
-async def capture_output(process: asyncio.subprocess.Process, stop_event: asyncio.Event):
-    stdout_output = ''
+async def capture_output(process: asyncio.subprocess.Process, stop_event: asyncio.Event, collect: bool = False):
+    chunks = [] if collect else None
 
     while True:
         try:
-            # Read a chunk of data (e.g., 4096 bytes)
             stdout_chunk = await process.stdout.read(4096)
             if not stdout_chunk:
                 break
 
-            # Decode and handle the chunk of output
             decoded_output = stdout_chunk.decode('utf-8')
-            stdout_output += decoded_output
+            if chunks is not None:
+                chunks.append(decoded_output)
             print(decoded_output, end='')
-            sys.stdout.flush()  # Ensure the output is flushed immediately
+            sys.stdout.flush()
 
-            # Check if the stop event is set and break the loop if so
             if stop_event.is_set():
                 break
 
         except Exception as e:
             LOGGER.error(f"Error while capturing output: {e}")
             break
 
-    return stdout_output
+    return ''.join(chunks) if chunks is not None else ''
 
 async def wait_for_space_key(stop_event: asyncio.Event = None):
     async def check_keypress_unix():
@@ -177,7 +175,7 @@ async def run_and_capture(exe_path: str, args: list[str], extra_env: dict[str, s
     process = await run_exe(exe_path, args, extra_env=extra_env)
 
     # Capture the output
-    stdout_output = await capture_output(process, stop_event)
+    stdout_output = await capture_output(process, stop_event, collect=True)
 
     # Wait for the subprocess to exit
     await process.wait()

utils/logging_utils.py

@@ -35,8 +35,9 @@ def filter(self, record):
     console_handler = logging.StreamHandler()
     LOGGER.addHandler(console_handler)
 
-    # Set the log level
+    # Set the log level and prevent duplicate output via root logger
     LOGGER.setLevel(level)
+    LOGGER.propagate = False
 
     # Apply settings
     formatter = logging.Formatter(format, TIMESTAMP_FORMAT)

utils/network_utils.py

@@ -1,18 +1,12 @@
-import random
 import socket
 import requests
 
 from utils.logging_utils import LOGGER
 
 def get_random_available_port():
-    while True:
-        port = random.randint(49152, 65535)
-        with socket.socket(socket.AF_INET, socket.SOCK_STREAM) as s:
-            try:
-                s.bind(("", port))
-                return port  # Return the port if it is available
-            except OSError:
-                continue  # If the port is in use, try another one
+    with socket.socket(socket.AF_INET, socket.SOCK_STREAM) as s:
+        s.bind(("", 0))
+        return s.getsockname()[1]
 
 def get_local_ip() -> str:
     try:
@@ -29,7 +23,7 @@ def get_local_ip() -> str:
 def query_url(url: str) -> str:
     LOGGER.info(f'Querying URL: {url}')
     try:
-        response = requests.get(url)
+        response = requests.get(url, timeout=30)
         if response.status_code == 200:
             return response.text
         else: