Inspect-slo2-timing-2 (#2871)

Inspect-slo2-timing-2

Reviewed-by: gemini-code-assist[bot]
Reviewed-by: Tomas Tomecek <tomas@tomecek.net>

Author: softwarefactory-project-zuul[bot]

packit_service/worker/handlers/copr.py

@@ -301,6 +301,12 @@ def set_built_packages(self):
 
     def run(self):
         run_start_time = datetime.now(timezone.utc)
+        logger.info(
+            f"[CELERY_EXEC] CoprBuildEndHandler execution started for "
+            f"build_id={self.copr_event.build_id} "
+            f"chroot={self.copr_event.chroot} "
+            f"at {run_start_time.isoformat()}"
+        )
         if not self.build:
             # TODO: how could this happen?
             model = "SRPMBuildDB" if self.copr_event.chroot == COPR_SRPM_CHROOT else "CoprBuildDB"

packit_service/worker/helpers/build/babysit.py

@@ -57,6 +57,18 @@
 
 def celery_run_async(signatures: list[Signature]) -> None:
     logger.debug("Signatures are going to be sent to Celery (from babysit task).")
+    # Extract build_id from signatures for tracking
+    build_ids = [
+        str(build_id)
+        for sig in signatures
+        if sig.kwargs and (build_id := sig.kwargs.get("event", {}).get("build_id"))
+    ]
+    build_ids_str = ", ".join(build_ids) if build_ids else "unknown"
+    queued_time = datetime.now(timezone.utc)
+    logger.info(
+        f"[CELERY_QUEUE] Queuing {len(signatures)} task(s) for Copr build(s) {build_ids_str} "
+        f"at {queued_time.isoformat()}"
+    )
     # https://docs.celeryq.dev/en/stable/userguide/canvas.html#groups
     celery.group(signatures).apply_async()
     logger.debug("Signatures were sent to Celery.")

packit_service/worker/tasks.py

@@ -120,6 +120,7 @@ def setup_loggers(logger, *args, **kwargs):
     logging.getLogger("sandcastle").setLevel(logging.INFO)
     # easier debugging
     logging.getLogger("packit").setLevel(logging.DEBUG)
+    logging.getLogger("packit_service").setLevel(logging.DEBUG)
 
     class CustomFormatter(logging.Formatter):
         def format(self, record):
@@ -149,6 +150,11 @@ def format(self, record):
         project = getenv("PROJECT", "packit")
         handler.setFormatter(RFC5424Formatter(msgid=project))
         logger.addHandler(handler)
+        # Also add to root logger to ensure all loggers (including child loggers) inherit it
+        root_logger = logging.getLogger()
+        # Check if handler already exists to avoid duplicates
+        if not any(isinstance(h, logging.handlers.SysLogHandler) for h in root_logger.handlers):
+            root_logger.addHandler(handler)
 
     package_versions = [
         ("OGR", ogr_version),