report long runtimes (120s) of Copr Start/End to sentry

this only accounts for the longer code paths

Maja observed in our Grafana dashboards these can take up to 6
minutes which is truly weird when we only do a few network requests and
some DB operations.

On average, they shouldn't take more than 10 seconds.

Thank you @majamassarini for consultation.

Signed-off-by: Tomas Tomecek <[email protected]>
Assisted-by: Cursor(Claude)

Author: TomasTomecek

packit_service/worker/handlers/copr.py

@@ -139,6 +139,15 @@ def get_checkers() -> tuple[type[Checker], ...]:
         return (AreOwnerAndProjectMatchingJob, IsPackageMatchingJobView)
 
 
+def report_long_runtime(method: str, length: int, start_time: datetime):
+    end_time = datetime.now(timezone.utc)
+    run_time = elapsed_seconds(start_time, end_time)
+    if run_time > length:
+        m = f"{method} run time takes {run_time} seconds."
+        logger.info(m)
+        sentry_integration.send_to_sentry(RuntimeWarning(m))
+
+
 @configured_as(job_type=JobType.copr_build)
 @reacts_to(event=copr.Start)
 class CoprBuildStartHandler(AbstractCoprBuildReportHandler):
@@ -165,6 +174,7 @@ def set_logs_url(self):
         self.build.set_build_logs_url(copr_build_logs)
 
     def run(self):
+        run_start_time = datetime.now(timezone.utc)
         if not self.build:
             model = "SRPMBuildDB" if self.copr_event.chroot == COPR_SRPM_CHROOT else "CoprBuildDB"
             msg = f"Copr build {self.copr_event.build_id} not in {model}."
@@ -201,6 +211,7 @@ def run(self):
             )
             msg = "SRPM build in Copr has started..."
             self.set_start_time()
+            report_long_runtime("SRPM build start", 120, run_start_time)
             return TaskResults(success=True, details={"msg": msg})
 
         self.pushgateway.copr_builds_started.inc()
@@ -220,6 +231,7 @@ def run(self):
         )
         msg = f"Build on {self.copr_event.chroot} in copr has started..."
         self.set_start_time()
+        report_long_runtime("Copr build start", 120, run_start_time)
         return TaskResults(success=True, details={"msg": msg})
 
 
@@ -285,6 +297,7 @@ def set_built_packages(self):
         self.build.set_built_packages(built_packages)
 
     def run(self):
+        run_start_time = datetime.now(timezone.utc)
         if not self.build:
             # TODO: how could this happen?
             model = "SRPMBuildDB" if self.copr_event.chroot == COPR_SRPM_CHROOT else "CoprBuildDB"
@@ -338,6 +351,7 @@ def run(self):
                     logs_url=self.build.build_logs_url,
                 )
             self.build.set_status(BuildStatus.failure)
+            report_long_runtime("Copr build failed end", 120, run_start_time)
             return TaskResults(success=False, details={"msg": failed_msg})
 
         self.report_successful_build()
@@ -365,6 +379,7 @@ def run(self):
                     f"as this is only experimental functionality for now.",
                 )
 
+        report_long_runtime("Copr build end", 120, run_start_time)
         return TaskResults(success=True, details={})
 
     def report_successful_build(self):