From 19be4faf4517f17100fb1c58ca318cbbb9fc6b65 Mon Sep 17 00:00:00 2001 From: Ben Thorner Date: Wed, 7 Apr 2021 13:56:10 +0100 Subject: [PATCH] Switch to monotonic time for task logs This matches the approach we take in utils [1]. Monotonic time is better because it avoids weird negative results due to clock shift. [1]: https://github.com/alphagov/notifications-utils/blob/5d18ebd79623e7d16bd48fbfe78ae632c0c0aaf1/notifications_utils/statsd_decorators.py#L14 --- app/celery/celery.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/app/celery/celery.py b/app/celery/celery.py index 9729391a3..7a1eceb45 100644 --- a/app/celery/celery.py +++ b/app/celery/celery.py @@ -24,7 +24,7 @@ def make_task(app): start = None def on_success(self, retval, task_id, args, kwargs): - elapsed_time = time.time() - self.start + elapsed_time = time.monotonic() - self.start app.logger.info( "{task_name} took {time}".format( task_name=self.name, time="{0:.4f}".format(elapsed_time) @@ -39,7 +39,7 @@ def make_task(app): def __call__(self, *args, **kwargs): # ensure task has flask context to access config, logger, etc with app.app_context(): - self.start = time.time() + self.start = time.monotonic() # Remove 'request_id' from the kwargs (so the task doesn't get an unexpected kwarg), then add it to g # so that it gets logged g.request_id = kwargs.pop('request_id', None)