diff --git a/app/celery/tasks.py b/app/celery/tasks.py index 37c17e0f3..fc50e4e0c 100644 --- a/app/celery/tasks.py +++ b/app/celery/tasks.py @@ -83,6 +83,8 @@ def process_job(job_id): ) if template.template_type == LETTER_TYPE: build_dvla_file.apply_async([str(job.id)], queue='process-job') + # temporary logging + current_app.logger.info("send job {} to build-dvla-file in the process-job queue".format(job_id)) def process_row(row_number, recipient, personalisation, template, job, service): @@ -277,6 +279,7 @@ def build_dvla_file(self, job_id): bucket_name=current_app.config['DVLA_UPLOAD_BUCKET_NAME'], file_location="{}-dvla-job.text".format(job_id)) else: + current_app.logger.info("All notifications for job {} are not persisted".format(job_id)) self.retry(queue="retry", exc="All notifications for job {} are not persisted".format(job_id)) diff --git a/app/statsd_decorators.py b/app/statsd_decorators.py index 2f83f13b6..bb21a0562 100644 --- a/app/statsd_decorators.py +++ b/app/statsd_decorators.py @@ -10,20 +10,30 @@ def statsd(namespace): @functools.wraps(func) def wrapper(*args, **kwargs): start_time = monotonic() - res = func(*args, **kwargs) - elapsed_time = monotonic() - start_time - current_app.logger.info( - "{namespace} call {func} took {time}".format( - namespace=namespace, func=func.__name__, time="{0:.4f}".format(elapsed_time) + try: + res = func(*args, **kwargs) + elapsed_time = monotonic() - start_time + statsd_client.incr('{namespace}.{func}'.format( + namespace=namespace, func=func.__name__) ) - ) - statsd_client.incr('{namespace}.{func}'.format( - namespace=namespace, func=func.__name__) - ) - statsd_client.timing('{namespace}.{func}'.format( - namespace=namespace, func=func.__name__), elapsed_time - ) - return res + statsd_client.timing('{namespace}.{func}'.format( + namespace=namespace, func=func.__name__), elapsed_time + ) + + except Exception as e: + current_app.logger.error( + "{namespace} call {func} failed".format( + namespace=namespace, func=func.__name__ + ) + ) + raise e + else: + current_app.logger.info( + "{namespace} call {func} took {time}".format( + namespace=namespace, func=func.__name__, time="{0:.4f}".format(elapsed_time) + ) + ) + return res wrapper.__wrapped__.__name__ = func.__name__ return wrapper