Stop reporting uvicorn.error in log file unless log it is an error

This commit is contained in:
Julian Stirling 2025-08-21 15:33:56 +01:00
parent 46be2c770e
commit 3529c96ec6
2 changed files with 53 additions and 1 deletions

View file

@ -53,7 +53,7 @@ def configure_logging(log_folder):
backupCount=10, backupCount=10,
) )
format_str = "[%(asctime)s] [%(levelname)s] <%(name)s> %(message)s" format_str = "[%(asctime)s] [%(levelname)s] <%(name)s> %(message)s"
handler.setFormatter(logging.Formatter(format_str)) handler.setFormatter(OFMLogFileFormatter(format_str))
handler.addFilter(UvicornAccessFilter()) handler.addFilter(UvicornAccessFilter())
root_logger.addHandler(handler) root_logger.addHandler(handler)
@ -100,6 +100,25 @@ def retrieve_log_from_file() -> PlainTextResponse:
) from e ) from e
class OFMLogFileFormatter(logging.Formatter):
"""The formatter used for the OpenFlexure Microscope Server log file."""
def format(self, record):
"""Adjust the logging formatting for uvicorn logs.
Any ``uvicorn.error`` logs that are at a lower
uvicorn has two loggers. Each API access is ``uvicorn.access`` which we filter
due to the noise the other is ``uvicorn.error`` for more important messages.
However, ``uvicorn.error`` is used for expected messages that are not errors,
such as server start up. This can lead to people erroneously thinking that
there is an error with their miroscope.
"""
if record.name == "uvicorn.error" and record.levelno < logging.ERROR:
record.name = "uvicorn"
return super().format(record)
class OFMHandler(logging.Handler): class OFMHandler(logging.Handler):
"""A logging.Handler that stores the most recent logs for access by the server.""" """A logging.Handler that stores the most recent logs for access by the server."""

View file

@ -155,3 +155,36 @@ def test_server_response_with_no_log_dir():
with pytest.raises(HTTPException) as excinfo: with pytest.raises(HTTPException) as excinfo:
ofm_logging.retrieve_log_from_file() ofm_logging.retrieve_log_from_file()
assert excinfo.value.status_code == 500 assert excinfo.value.status_code == 500
FAKE_UVICORN_LOGGER = logging.getLogger("uvicorn.error")
@pytest.mark.parametrize(
"log_command, names_in_log, names_not_in_log",
[
[FAKE_UVICORN_LOGGER.debug, [], ["<uvicorn>", "<uvicorn.error>"]],
[FAKE_UVICORN_LOGGER.info, ["<uvicorn>"], ["<uvicorn.error>"]],
[FAKE_UVICORN_LOGGER.warning, ["<uvicorn>"], ["<uvicorn.error>"]],
[FAKE_UVICORN_LOGGER.error, ["<uvicorn.error>"], ["<uvicorn>"]],
[FAKE_UVICORN_LOGGER.exception, ["<uvicorn.error>"], ["<uvicorn>"]],
],
)
def test_uvicorn_error_only_says_error_on_error(
log_command, names_in_log, names_not_in_log
):
"""Check that an HTTP exception is raised if the log file cannot be accessed.
Parametrised to check: debug doesn't log, info and warning log as <uvicorn>, and
error logs as <uvicorn.error>.
"""
ofm_logging.OFM_HANDLER = ofm_logging.OFMHandler()
with tempfile.TemporaryDirectory() as tmpdir:
ofm_logging.configure_logging(tmpdir)
log_command("Mockedy mock mock!")
with open(ofm_logging.OFM_LOG_FILE, "r", encoding="utf-8") as log_file:
log_txt = log_file.read()
for name in names_in_log:
assert name in log_txt
for name in names_not_in_log:
assert name not in log_txt