diff --git a/src/dockerflow/django/views.py b/src/dockerflow/django/views.py index 3cc16e3..5164bc2 100644 --- a/src/dockerflow/django/views.py +++ b/src/dockerflow/django/views.py @@ -1,6 +1,8 @@ # This Source Code Form is subject to the terms of the Mozilla Public # License, v. 2.0. If a copy of the MPL was not distributed with this # file, you can obtain one at http://mozilla.org/MPL/2.0/. +import logging + from django.conf import settings from django.core import checks from django.http import HttpResponse, HttpResponseNotFound, JsonResponse @@ -14,6 +16,9 @@ ) +logger = logging.getLogger("dockerflow.django") + + def version(request): """ Returns the contents of version.json or a 404. @@ -51,11 +56,18 @@ def heartbeat(request): level = 0 for check in all_checks: - detail = heartbeat_check_detail(check) - statuses[check.__name__] = detail["status"] - level = max(level, detail["level"]) - if detail["level"] > 0: - details[check.__name__] = detail + check_level, check_errors = heartbeat_check_detail(check) + level_text = level_to_text(check_level) + statuses[check.__name__] = level_text + level = max(level, check_level) + if level > 0: + for error in check_errors: + logger.log(error.level, "%s: %s", error.id, error.msg) + details[check.__name__] = { + "status": level_text, + "level": level, + "messages": {e.id: e.msg for e in check_errors}, + } if level < checks.messages.ERROR: status_code = 200 @@ -75,9 +87,4 @@ def heartbeat_check_detail(check): errors = check(app_configs=None) errors = list(filter(lambda e: e.id not in settings.SILENCED_SYSTEM_CHECKS, errors)) level = max([0] + [e.level for e in errors]) - - return { - "status": level_to_text(level), - "level": level, - "messages": {e.id: e.msg for e in errors}, - } + return level, errors diff --git a/src/dockerflow/flask/app.py b/src/dockerflow/flask/app.py index 25d467b..0e027ba 100644 --- a/src/dockerflow/flask/app.py +++ b/src/dockerflow/flask/app.py @@ -306,12 +306,7 @@ def _lbheartbeat_view(self): def _heartbeat_check_detail(self, check): errors = list(filter(lambda e: e.id not in self.silenced_checks, check())) level = max([0] + [e.level for e in errors]) - - return { - "status": checks.level_to_text(level), - "level": level, - "messages": {e.id: e.msg for e in errors}, - } + return level, errors def _heartbeat_view(self): """ @@ -326,11 +321,18 @@ def _heartbeat_view(self): level = 0 for name, check in self.checks.items(): - detail = self._heartbeat_check_detail(check) - statuses[name] = detail["status"] - level = max(level, detail["level"]) - if detail["level"] > 0: - details[name] = detail + check_level, check_errors = self._heartbeat_check_detail(check) + level_text = checks.level_to_text(check_level) + statuses[name] = level_text + level = max(level, check_level) + if check_level > 0: + for error in check_errors: + self.logger.log(error.level, "%s: %s", error.id, error.msg) + details[name] = { + "status": level_text, + "level": level, + "messages": {e.id: e.msg for e in check_errors}, + } payload = { "status": checks.level_to_text(level), diff --git a/src/dockerflow/sanic/app.py b/src/dockerflow/sanic/app.py index 5457c0c..7016963 100644 --- a/src/dockerflow/sanic/app.py +++ b/src/dockerflow/sanic/app.py @@ -214,12 +214,7 @@ async def _heartbeat_check_detail(self, check): result = await result errors = [e for e in result if e.id not in self.silenced_checks] level = max([0] + [e.level for e in errors]) - - return { - "status": checks.level_to_text(level), - "level": level, - "messages": {e.id: e.msg for e in errors}, - } + return level, errors async def _heartbeat_view(self, request): """ @@ -234,11 +229,18 @@ async def _heartbeat_view(self, request): level = 0 for name, check in self.checks.items(): - detail = await self._heartbeat_check_detail(check) - statuses[name] = detail["status"] - level = max(level, detail["level"]) - if detail["level"] > 0: - details[name] = detail + check_level, check_errors = await self._heartbeat_check_detail(check) + level_text = checks.level_to_text(check_level) + statuses[name] = level_text + level = max(level, check_level) + if check_level > 0: + for error in check_errors: + self.logger.log(error.level, "%s: %s", error.id, error.msg) + details[name] = { + "status": level_text, + "level": check_level, + "messages": {e.id: e.msg for e in check_errors}, + } payload = { "status": checks.level_to_text(level), diff --git a/tests/django/test_django.py b/tests/django/test_django.py index 6270f3e..9bd435d 100644 --- a/tests/django/test_django.py +++ b/tests/django/test_django.py @@ -68,6 +68,22 @@ def test_heartbeat(dockerflow_middleware, reset_checks, rf, settings): assert response.status_code == 500 +@pytest.mark.django_db +def test_heartbeat_logging(dockerflow_middleware, reset_checks, rf, settings, caplog): + request = rf.get("/__heartbeat__") + settings.DOCKERFLOW_CHECKS = [ + "tests.django.django_checks.warning", + "tests.django.django_checks.error", + ] + checks.register() + + with caplog.at_level(logging.INFO, logger="dockerflow.django"): + dockerflow_middleware.process_request(request) + logged = [(record.levelname, record.message) for record in caplog.records] + assert ("ERROR", "tests.checks.E001: some error") in logged + assert ("WARNING", "tests.checks.W001: some warning") in logged + + @pytest.mark.django_db def test_lbheartbeat_makes_no_db_queries(dockerflow_middleware, rf): queries = CaptureQueriesContext(connection) diff --git a/tests/flask/test_flask.py b/tests/flask/test_flask.py index 7b345a9..e9ccf26 100644 --- a/tests/flask/test_flask.py +++ b/tests/flask/test_flask.py @@ -139,6 +139,25 @@ def warning_check2(): assert "warning-check-two" in defaults +def test_heartbeat_logging(app, dockerflow, caplog): + dockerflow.checks.clear() + + @dockerflow.check + def error_check(): + return [checks.Error("some error", id="tests.checks.E001")] + + @dockerflow.check() + def warning_check(): + return [checks.Warning("some warning", id="tests.checks.W001")] + + with caplog.at_level(logging.INFO, logger="dockerflow.django"): + app.test_client().get("/__heartbeat__") + + logged = [(record.levelname, record.message) for record in caplog.records] + assert ("ERROR", "tests.checks.E001: some error") in logged + assert ("WARNING", "tests.checks.W001: some warning") in logged + + def test_lbheartbeat_makes_no_db_queries(dockerflow, app): with app.app_context(): assert len(get_debug_queries()) == 0 diff --git a/tests/sanic/test_sanic.py b/tests/sanic/test_sanic.py index 745052f..5d997be 100644 --- a/tests/sanic/test_sanic.py +++ b/tests/sanic/test_sanic.py @@ -162,6 +162,25 @@ async def warning_check2(): assert "warning-check-two" in details +def test_heartbeat_logging(dockerflow, test_client, caplog): + dockerflow.checks.clear() + + @dockerflow.check + def error_check(): + return [checks.Error("some error", id="tests.checks.E001")] + + @dockerflow.check() + def warning_check(): + return [checks.Warning("some warning", id="tests.checks.W001")] + + with caplog.at_level(logging.INFO, logger="dockerflow.sanic"): + _, response = test_client.get("/__heartbeat__") + + logged = [(record.levelname, record.message) for record in caplog.records] + assert ("ERROR", "tests.checks.E001: some error") in logged + assert ("WARNING", "tests.checks.W001: some warning") in logged + + def test_redis_check(dockerflow_redis, mocker, test_client): assert "check_redis_connected" in dockerflow_redis.checks mocker.patch.object(sanic_redis.core, "from_url", fake_redis)