Merge pull request #494 from alphagov/ris-status-log-status-errors

get_app_status: log check failures

dmutils/__init__.py

@@ -2,4 +2,4 @@
 from .flask_init import init_app, init_manager
 
 
-__version__ = '46.1.1'
+__version__ = '46.1.2'

dmutils/status.py

@@ -1,8 +1,12 @@
 import math
 import os
+import sys
 from flask import jsonify, current_app
 
 
+from dmutils.timing import logged_duration
+
+
 def get_version_label(path):
     try:
         path = os.path.join(path, 'version_label')
@@ -39,7 +43,18 @@ def __init__(self, message):
 def _perform_additional_checks(additional_checks, response_data, error_messages):
     for additional_check in additional_checks:
         try:
-            response_data.update(additional_check())
+            with logged_duration(
+                logger=current_app.logger,
+                message=(
+                    lambda log_context: logged_duration.default_message(log_context) + " ({check_function})"
+                ),
+                condition=(
+                    lambda log_context: logged_duration.default_condition(log_context) or sys.exc_info()[0] is not None
+                ),
+            ) as log_context:
+                log_context["check_function"] = str(additional_check)
+                check_result = additional_check()
+            response_data.update(check_result)
         except StatusError as e:
             error_messages.append(e.message)
 
@@ -95,6 +110,10 @@ def get_app_status(
         _perform_additional_checks(additional_checks_internal, response_data, error_messages)
 
     if error_messages:
+        current_app.logger.error(
+            "Request completed with error_messages = {error_messages}",
+            extra={"error_messages": error_messages},
+        )
         response_data['status'] = 'error'
         response_data['message'] = error_messages