From ca54bd0b210e83298470d156f1e9b15586ff86dd Mon Sep 17 00:00:00 2001 From: Richard Kuo Date: Sun, 5 Jan 2025 20:02:05 -0800 Subject: [PATCH] add logging --- backend/onyx/background/celery/apps/primary.py | 4 ++-- backend/onyx/background/celery/tasks/vespa/tasks.py | 5 ++++- 2 files changed, 6 insertions(+), 3 deletions(-) diff --git a/backend/onyx/background/celery/apps/primary.py b/backend/onyx/background/celery/apps/primary.py index 62ea96658..caa697f88 100644 --- a/backend/onyx/background/celery/apps/primary.py +++ b/backend/onyx/background/celery/apps/primary.py @@ -89,12 +89,12 @@ def on_worker_init(sender: Any, **kwargs: Any) -> None: app_base.wait_for_db(sender, **kwargs) app_base.wait_for_vespa(sender, **kwargs) + logger.info("Running as the primary celery worker.") + # Less startup checks in multi-tenant case if MULTI_TENANT: return - logger.info("Running as the primary celery worker.") - # This is singleton work that should be done on startup exactly once # by the primary worker. This is unnecessary in the multi tenant scenario r = get_redis_client(tenant_id=None) diff --git a/backend/onyx/background/celery/tasks/vespa/tasks.py b/backend/onyx/background/celery/tasks/vespa/tasks.py index ff7b0b93f..c3c8c42ab 100644 --- a/backend/onyx/background/celery/tasks/vespa/tasks.py +++ b/backend/onyx/background/celery/tasks/vespa/tasks.py @@ -760,6 +760,8 @@ def monitor_vespa_sync(self: Task, tenant_id: str | None) -> bool: Returns True if the task actually did work, False if it exited early to prevent overlap """ + task_logger.info(f"monitor_vespa_sync starting: tenant={tenant_id}") + time_start = time.monotonic() timings: dict[str, float] = {} @@ -775,6 +777,7 @@ def monitor_vespa_sync(self: Task, tenant_id: str | None) -> bool: try: # prevent overlapping tasks if not lock_beat.acquire(blocking=False): + task_logger.info("monitor_vespa_sync exiting due to overlap") return False # print current queue lengths @@ -894,7 +897,7 @@ def monitor_vespa_sync(self: Task, tenant_id: str | None) -> bool: redis_lock_dump(lock_beat, r) time_elapsed = time.monotonic() - time_start - task_logger.debug(f"monitor_vespa_sync finished: elapsed={time_elapsed:.2f}") + task_logger.info(f"monitor_vespa_sync finished: elapsed={time_elapsed:.2f}") return True