✨Computational backend: add helpful tracing log (#5218)

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

@@ -160,8 +160,10 @@ async def _publish_sidecar_log(
     async def run(self, command: list[str]) -> TaskOutputData:
         # ensure we pass the initial logs and progress
         await self._publish_sidecar_log(
-            f"Starting task for {self.task_parameters.image}:{self.task_parameters.tag} on {socket.gethostname()}..."
+            f"Starting task {self.task_parameters.image}:{self.task_parameters.tag} on {socket.gethostname()}..."
         )
+        # NOTE: this is for tracing purpose
+        _logger.info("Running task owner: %s", self.task_parameters.task_owner)
 
         settings = Settings.create_from_envs()
         run_id = f"{uuid4()}"

tests/e2e-playwright/Makefile

@@ -39,7 +39,7 @@ define _transfer-images-to-registry
 endef
 
 define _give_service_access_rights
-@docker exec \
+docker exec \
 	$$(docker ps -q --filter="name=postgres") \
 	psql --user scu --dbname simcoredb --command \
 "INSERT INTO services_access_rights (key, version, gid, execute_access, write_access, product_name) \
@@ -60,12 +60,24 @@ install-dev install-prod install-ci: _check_venv_active ## install app in develo
 	# installing playwright dependencies
 	@playwright install
 
+
+RETRY_DURATION_SECONDS := 30
+RETRY_INTERVAL_SECONDS := 1
+
 install-ci-up-simcore: install-ci
 	@$(MAKE_C) $(REPO_BASE_DIR) local-registry
+	@$(_transfer-images-to-registry)
 	@$(_up_simcore)
 	@$(VENV_DIR)/bin/python utils/wait_for_services.py
-	@$(_transfer-images-to-registry)
-	@$(_give_service_access_rights)
+
+	# giving access rights to images (this might take some time until the catalog is ready)
+	@for ((i=0; i<$(RETRY_DURATION_SECONDS); i+=$(RETRY_INTERVAL_SECONDS))); do \
+		$(_give_service_access_rights) && echo "Access rights granted successfully" && break || true; \
+		echo "catalog not ready yet, retrying in ${RETRY_INTERVAL_SECONDS}..."; \
+		sleep $(RETRY_INTERVAL_SECONDS); \
+	done
+
+
 
 
 get_my_ip := $(shell hostname --all-ip-addresses | cut --delimiter=" " --fields=1)

tests/e2e-playwright/requirements/_test.in

@@ -1,3 +1,4 @@
+arrow
 docker
 faker
 pydantic[email]

tests/e2e-playwright/requirements/_test.txt

@@ -6,6 +6,8 @@
 #
 annotated-types==0.6.0
     # via pydantic
+arrow==1.3.0
+    # via -r requirements/_test.in
 certifi==2023.11.17
     # via requests
 charset-normalizer==3.3.2
@@ -70,7 +72,9 @@ pytest-runner==6.0.1
 pytest-sugar==0.9.7
     # via -r requirements/_test.in
 python-dateutil==2.8.2
-    # via faker
+    # via
+    #   arrow
+    #   faker
 python-slugify==8.0.1
     # via pytest-playwright
 pyyaml==6.0.1
@@ -89,6 +93,8 @@ text-unidecode==1.3
     # via python-slugify
 tomli==2.0.1
     # via pytest
+types-python-dateutil==2.8.19.20240106
+    # via arrow
 typing-extensions==4.9.0
     # via
     #   pydantic

tests/e2e-playwright/utils/wait_for_services.py

@@ -5,6 +5,7 @@
 from datetime import datetime
 from pathlib import Path
 
+import arrow
 import docker
 import yaml
 from tenacity import RetryError, Retrying
@@ -92,20 +93,20 @@ def ops_services() -> list[str]:
         return list(dc_specs["services"].keys())
 
 
-def to_datetime(datetime_str: str) -> datetime:
-    # datetime_str is typically '2020-10-09T12:28:14.771034099Z'
-    #  - The T separates the date portion from the time-of-day portion
-    #  - The Z on the end means UTC, that is, an offset-from-UTC
-    # The 099 before the Z is not clear, therefore we will truncate the last part
-    N = len("2020-10-09T12:28:14.7710")
-    if len(datetime_str) > N:
-        datetime_str = datetime_str[:N]
-    return datetime.strptime(datetime_str, "%Y-%m-%dT%H:%M:%S.%f")
+def _to_datetime(docker_timestamp: str) -> datetime:
+    # docker follows RFC3339Nano timestamp which is based on ISO 8601
+    # https://medium.easyread.co/understanding-about-rfc-3339-for-datetime-formatting-in-software-engineering-940aa5d5f68a
+    # This is acceptable in ISO 8601 and RFC 3339 (with T)
+    # 2019-10-12T07:20:50.52Z
+    # This is only accepted in RFC 3339 (without T)
+    # 2019-10-12 07:20:50.52Z
+    dt: datetime = arrow.get(docker_timestamp).datetime
+    return dt
 
 
-def by_service_creation(service):
+def _by_service_creation(service) -> datetime:
     datetime_str = service.attrs["CreatedAt"]
-    return to_datetime(datetime_str)
+    return _to_datetime(datetime_str)
 
 
 def wait_for_services() -> int:
@@ -125,7 +126,7 @@ def wait_for_services() -> int:
                         for s in client.services.list()
                         if s.name.split("_")[-1] in expected_services
                     ),
-                    key=by_service_creation,
+                    key=_by_service_creation,
                 )
 
                 assert len(started_services), "no services started!"
@@ -141,11 +142,14 @@ def wait_for_services() -> int:
         return os.EX_SOFTWARE
 
     for service in started_services:
+        assert service
+        assert service.attrs
         expected_replicas = (
             service.attrs["Spec"]["Mode"]["Replicated"]["Replicas"]
             if "Replicated" in service.attrs["Spec"]["Mode"]
             else len(client.nodes.list())  # we are in global mode
         )
+        assert hasattr(service, "name")
         print(f"Service: {service.name} expects {expected_replicas} replicas", "-" * 10)
 
         try: