⚗️Dask-sidecar: print file contents or partial contents (ITISFoundation#7834)

Author: sanderegg

.vscode/settings.template.json

@@ -1,7 +1,6 @@
 // This is a template. Clone and replace extension ".template.json" by ".json"
 {
   "autoDocstring.docstringFormat": "pep257",
-
   "editor.tabSize": 2,
   "editor.insertSpaces": true,
   "editor.detectIndentation": false,
@@ -34,6 +33,8 @@
   "python.analysis.typeCheckingMode": "basic",
   "python.analysis.extraPaths": [
     "./packages/aws-library/src",
+    "./packages/common-library/src",
+    "./packages/dask-task-models-library/src",
     "./packages/models-library/src",
     "./packages/postgres-database/src",
     "./packages/postgres-database/tests",

services/dask-sidecar/src/simcore_service_dask_sidecar/computational_sidecar/core.py

@@ -7,7 +7,7 @@
 from pathlib import Path
 from pprint import pformat
 from types import TracebackType
-from typing import Final, cast
+from typing import cast
 from uuid import uuid4
 
 from aiodocker import Docker
@@ -32,6 +32,7 @@
 from ..utils.dask import TaskPublisher
 from ..utils.files import (
     check_need_unzipping,
+    log_partial_file_content,
     pull_file_from_remote,
     push_file_to_remote,
 )
@@ -48,8 +49,8 @@
 from .task_shared_volume import TaskSharedVolumes
 
 _logger = logging.getLogger(__name__)
-CONTAINER_WAIT_TIME_SECS = 2
-_TASK_PROCESSING_PROGRESS_WEIGHT: Final[float] = 0.99
+_CONTAINER_WAIT_TIME_SECS = 2
+_MAX_LOGGED_FILE_CHARS = 40
 
 
 @dataclass(kw_only=True, frozen=True, slots=True)
@@ -147,11 +148,17 @@ async def _retrieve_output_data(
             upload_tasks = []
             for output_params in output_data.values():
                 if isinstance(output_params, FileUrl):
-                    assert (  # nosec
+                    assert (
                         output_params.file_mapping
                     ), f"{output_params.model_dump_json(indent=1)} expected resolved in TaskOutputData.from_task_output"
 
                     src_path = task_volumes.outputs_folder / output_params.file_mapping
+                    await log_partial_file_content(
+                        src_path,
+                        logger=_logger,
+                        log_level=logging.DEBUG,
+                        max_chars=_MAX_LOGGED_FILE_CHARS,
+                    )
                     upload_tasks.append(
                         push_file_to_remote(
                             src_path,
@@ -267,7 +274,7 @@ async def run(self, command: list[str]) -> TaskOutputData:
                 )
                 # wait until the container finished, either success or fail or timeout
                 while (container_data := await container.show())["State"]["Running"]:
-                    await asyncio.sleep(CONTAINER_WAIT_TIME_SECS)
+                    await asyncio.sleep(_CONTAINER_WAIT_TIME_SECS)
                 if container_data["State"]["ExitCode"] > os.EX_OK:
                     raise ServiceRuntimeError(
                         service_key=self.task_parameters.image,

services/dask-sidecar/src/simcore_service_dask_sidecar/utils/files.py

@@ -20,7 +20,7 @@
 from settings_library.s3 import S3Settings
 from yarl import URL
 
-logger = logging.getLogger(__name__)
+_logger = logging.getLogger(__name__)
 
 HTTP_FILE_SYSTEM_SCHEMES: Final = ["http", "https"]
 S3_FILE_SYSTEM_SCHEMES: Final = ["s3", "s3a"]
@@ -208,7 +208,7 @@ async def pull_file_from_remote(
             await log_publishing_cb(
                 f"Uncompressing '{download_dst_path.name}'...", logging.INFO
             )
-            logger.debug(
+            _logger.debug(
                 "%s is a zip file and will be now uncompressed", download_dst_path
             )
             with repro_zipfile.ReproducibleZipFile(download_dst_path, "r") as zip_obj:
@@ -258,7 +258,7 @@ async def _push_file_to_remote(
     log_publishing_cb: LogPublishingCB,
     s3_settings: S3Settings | None,
 ) -> None:
-    logger.debug("Uploading %s to %s...", file_to_upload, dst_url)
+    _logger.debug("Uploading %s to %s...", file_to_upload, dst_url)
     assert dst_url.path  # nosec
 
     storage_kwargs: S3FsSettingsDict | dict[str, Any] = {}
@@ -306,7 +306,7 @@ async def push_file_to_remote(
                 await asyncio.get_event_loop().run_in_executor(
                     None, zfp.write, src_path, src_path.name
                 )
-            logger.debug("%s created.", archive_file_path)
+            _logger.debug("%s created.", archive_file_path)
             assert archive_file_path.exists()  # nosec
             file_to_upload = archive_file_path
             await log_publishing_cb(
@@ -319,7 +319,7 @@ async def push_file_to_remote(
         )
 
         if dst_url.scheme in HTTP_FILE_SYSTEM_SCHEMES:
-            logger.debug("destination is a http presigned link")
+            _logger.debug("destination is a http presigned link")
             await _push_file_to_http_link(file_to_upload, dst_url, log_publishing_cb)
         else:
             await _push_file_to_remote(
@@ -330,3 +330,22 @@ async def push_file_to_remote(
         f"Upload of '{src_path.name}' to '{dst_url.path.strip('/')}' complete",
         logging.INFO,
     )
+
+
+async def log_partial_file_content(
+    src_path: Path, *, logger: logging.Logger, log_level: int, max_chars: int
+) -> None:
+    if max_chars < 0:
+        msg = "max_chars must be non-negative"
+        raise ValueError(msg)
+    if max_chars == 0:
+        return
+    if not src_path.exists():
+        logger.log(log_level, "file does not exist: %s", src_path)
+        return
+    async with aiofiles.open(src_path, encoding="utf-8") as f:
+        content = await f.read(max_chars + 1)
+    if len(content) > max_chars:
+        logger.log(log_level, "file content (truncated): %s...", content[:max_chars])
+    else:
+        logger.log(log_level, "file content: %s", content)

services/dask-sidecar/tests/unit/test_utils_files.py

@@ -4,6 +4,7 @@
 
 import asyncio
 import hashlib
+import logging
 import mimetypes
 import zipfile
 from collections.abc import AsyncIterable
@@ -21,6 +22,7 @@
 from settings_library.s3 import S3Settings
 from simcore_service_dask_sidecar.utils.files import (
     _s3fs_settings_from_s3_settings,
+    log_partial_file_content,
     pull_file_from_remote,
     push_file_to_remote,
 )
@@ -511,3 +513,48 @@ async def test_push_file_to_remote_creates_reproducible_zip_archive(
     assert dst_path2.exists()
 
     assert _compute_hash(dst_path1) == _compute_hash(dst_path2)
+
+
+async def test_log_partial_file_content(
+    tmp_path: Path, caplog: pytest.LogCaptureFixture
+):
+    # Create a file with known content
+    file_content = "abcdefghijklmnopqrstuvwxyz0123456789ABCDEFGHIJKLMNOPQRSTUVWXYZ"
+    file_path = tmp_path / "testfile.txt"
+    file_path.write_text(file_content)
+    logger = logging.getLogger("pytest.utils.files")
+
+    # Case 1: file longer than max_chars
+    with caplog.at_level(logging.DEBUG, logger=logger.name):
+        await log_partial_file_content(
+            file_path, logger=logger, log_level=logging.DEBUG, max_chars=10
+        )
+    assert any(
+        "file content (truncated): abcdefghij..." in record.getMessage()
+        for record in caplog.records
+    )
+
+    # Case 2: file shorter than max_chars
+    caplog.clear()
+    short_content = "short"
+    short_file = tmp_path / "short.txt"
+    short_file.write_text(short_content)
+    with caplog.at_level(logging.DEBUG, logger=logger.name):
+        await log_partial_file_content(
+            short_file, logger=logger, log_level=logging.DEBUG, max_chars=10
+        )
+    assert any(
+        "file content: short" in record.getMessage() for record in caplog.records
+    )
+
+    # Case 3: file does not exist
+    caplog.clear()
+    non_existent = tmp_path / "doesnotexist.txt"
+    with caplog.at_level(logging.DEBUG, logger=logger.name):
+        await log_partial_file_content(
+            non_existent, logger=logger, log_level=logging.DEBUG, max_chars=10
+        )
+    assert any(
+        f"file does not exist: {non_existent}" in record.getMessage()
+        for record in caplog.records
+    )