From bb3acbb8ad907cc7bab64b66dce95ec14d361e92 Mon Sep 17 00:00:00 2001 From: Hao Liu <44379968+TheRealHaoLiu@users.noreply.github.com> Date: Wed, 27 Sep 2023 09:46:55 -0400 Subject: [PATCH] Debug log for scheduler commit duration (#14035) Co-authored-by: Alan Rominger --- awx/main/scheduler/task_manager.py | 13 ++++++++++++- 1 file changed, 12 insertions(+), 1 deletion(-) diff --git a/awx/main/scheduler/task_manager.py b/awx/main/scheduler/task_manager.py index 95d47b04c343..ba7427c03bc8 100644 --- a/awx/main/scheduler/task_manager.py +++ b/awx/main/scheduler/task_manager.py @@ -124,6 +124,13 @@ def record_aggregate_metrics_and_exit(self, *args): self.record_aggregate_metrics() sys.exit(1) + def get_local_metrics(self): + data = {} + for k, metric in self.subsystem_metrics.METRICS.items(): + if k.startswith(self.prefix) and metric.metric_has_changed: + data[k[len(self.prefix) + 1 :]] = metric.current_value + return data + def schedule(self): # Always be able to restore the original signal handler if we finish original_sigusr1 = signal.getsignal(signal.SIGUSR1) @@ -146,10 +153,14 @@ def schedule(self): signal.signal(signal.SIGUSR1, original_sigusr1) commit_start = time.time() + logger.debug(f"Commiting {self.prefix} Scheduler changes") + if self.prefix == "task_manager": self.subsystem_metrics.set(f"{self.prefix}_commit_seconds", time.time() - commit_start) + local_metrics = self.get_local_metrics() self.record_aggregate_metrics() - logger.debug(f"Finishing {self.prefix} Scheduler") + + logger.debug(f"Finished {self.prefix} Scheduler, timing data:\n{local_metrics}") class WorkflowManager(TaskBase):