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
This commit is contained in:
Ben Thorner
2021-04-08 13:00:24 +01:00
parent 054205835b
commit 19be4faf45
+2 -2
View File
@@ -24,7 +24,7 @@ def make_task(app):
start = None start = None
def on_success(self, retval, task_id, args, kwargs): def on_success(self, retval, task_id, args, kwargs):
elapsed_time = time.time() - self.start elapsed_time = time.monotonic() - self.start
app.logger.info( app.logger.info(
"{task_name} took {time}".format( "{task_name} took {time}".format(
task_name=self.name, time="{0:.4f}".format(elapsed_time) task_name=self.name, time="{0:.4f}".format(elapsed_time)
@@ -39,7 +39,7 @@ def make_task(app):
def __call__(self, *args, **kwargs): def __call__(self, *args, **kwargs):
# ensure task has flask context to access config, logger, etc # ensure task has flask context to access config, logger, etc
with app.app_context(): 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 # 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 # so that it gets logged
g.request_id = kwargs.pop('request_id', None) g.request_id = kwargs.pop('request_id', None)