Merge pull request #1020 from Aiven-Open/nosahama/EC-629/add-logging-…

…to-sr

logging: configure logging on SR

container/compose.yml

@@ -78,7 +78,7 @@ services:
       KARAPACE_GROUP_ID: karapace-schema-registry
       KARAPACE_MASTER_ELIGIBILITY: true
       KARAPACE_TOPIC_NAME: _schemas
-      KARAPACE_LOG_LEVEL: DEBUG
+      KARAPACE_LOG_LEVEL: INFO
       KARAPACE_COMPATIBILITY: FULL
       KARAPACE_STATSD_HOST: statsd-exporter
       KARAPACE_STATSD_PORT: 8125
@@ -118,7 +118,7 @@ services:
       KARAPACE_REGISTRY_HOST: karapace-schema-registry
       KARAPACE_REGISTRY_PORT: 8081
       KARAPACE_ADMIN_METADATA_MAX_AGE: 0
-      KARAPACE_LOG_LEVEL: DEBUG
+      KARAPACE_LOG_LEVEL: INFO
       KARAPACE_STATSD_HOST: statsd-exporter
       KARAPACE_STATSD_PORT: 8125
       KARAPACE_KAFKA_SCHEMA_READER_STRICT_MODE: false

src/karapace/config.py

@@ -24,14 +24,12 @@
 
 HOSTNAME = socket.gethostname()
 
-
-OTEL_VERSION = ""
 try:
     from opentelemetry import version as otel_version
 
     OTEL_VERSION = otel_version.__version__
 except Exception:
-    pass
+    OTEL_VERSION = ""
 
 
 class KarapaceTags(BaseModel):
@@ -58,7 +56,7 @@ class Config(BaseSettings):
     model_config = SettingsConfigDict(env_prefix="karapace_", env_ignore_empty=True, env_nested_delimiter="__")
 
     access_logs_debug: bool = False
-    access_log_class: ImportString = "karapace.utils.DebugAccessLogger"
+    access_log_class: ImportString = "aiohttp.web_log.AccessLogger"
     advertised_hostname: str | None = None
     advertised_port: int | None = None
     advertised_protocol: str = "http"

src/karapace/logging_setup.py

@@ -10,29 +10,28 @@
 
 
 def configure_logging(*, config: Config) -> None:
-    log_handler = config.log_handler
-
     root_handler: logging.Handler | None = None
-    if "systemd" == log_handler:
-        from systemd import journal
 
-        root_handler = journal.JournalHandler(SYSLOG_IDENTIFIER="karapace")
-    elif "stdout" == log_handler or log_handler is None:
-        root_handler = logging.StreamHandler(stream=sys.stdout)
-    else:
-        logging.basicConfig(level=config.log_level, format=config.log_format)
-        logging.getLogger().setLevel(config.log_level)
-        logging.warning("Log handler %s not recognized, root handler not set.", log_handler)
+    log_handler = config.log_handler
+    match log_handler:
+        case "stdout" | None:
+            root_handler = logging.StreamHandler(stream=sys.stdout)
+        case "systemd":
+            from systemd import journal
+
+            root_handler = journal.JournalHandler(SYSLOG_IDENTIFIER="karapace")
+        case _:
+            logging.basicConfig(level=config.log_level.upper(), format=config.log_format)
+            logging.getLogger().setLevel(config.log_level.upper())
+            logging.warning("Log handler %s not recognized, root handler not set.", log_handler)
 
     if root_handler is not None:
         root_handler.setFormatter(logging.Formatter(config.log_format))
-        root_handler.setLevel(config.log_level)
+        root_handler.setLevel(config.log_level.upper())
         root_handler.set_name(name="karapace")
         logging.root.addHandler(root_handler)
 
-    logging.root.setLevel(config.log_level)
-    logging.getLogger("aiohttp.access").setLevel(config.log_level)
-    logging.getLogger("uvicorn.error").setLevel(config.log_level)
+    logging.root.setLevel(config.log_level.upper())
 
 
 def log_config_without_secrets(config: Config) -> None:

src/schema_registry/__main__.py

@@ -63,4 +63,4 @@
 
     config = karapace_container.config()
     app = create_karapace_application(config=config, lifespan=karapace_schema_registry_lifespan)
-    uvicorn.run(app, host=config.host, port=config.port, log_level=config.log_level.lower())
+    uvicorn.run(app, host=config.host, port=config.port, log_level=config.log_level.lower(), log_config=None)

tests/unit/test_logging_setup.py

@@ -0,0 +1,72 @@
+"""
+Copyright (c) 2024 Aiven Ltd
+See LICENSE for details
+"""
+
+from _pytest.logging import LogCaptureFixture
+from karapace.container import KarapaceContainer
+from karapace.logging_setup import configure_logging
+from unittest.mock import patch, call
+
+import logging
+import pytest
+
+
+def test_configure_logging_stdout_handler(caplog: LogCaptureFixture, karapace_container: KarapaceContainer) -> None:
+    config = karapace_container.config().set_config_defaults(
+        {
+            "log_handler": "stdout",
+            "log_level": "WARNING",
+        }
+    )
+    with caplog.at_level(logging.WARNING, logger="karapace.logging_setup"):
+        with patch("karapace.logging_setup.logging") as mock_logging, patch("karapace.logging_setup.sys") as mock_sys:
+            configure_logging(config=config)
+            mock_logging.assert_has_calls(
+                [
+                    call.StreamHandler(stream=mock_sys.stdout),
+                    call.Formatter("%(name)-20s\t%(threadName)s\t%(levelname)-8s\t%(message)s"),
+                    call.StreamHandler().setFormatter(mock_logging.Formatter.return_value),
+                    call.StreamHandler().setLevel("WARNING"),
+                    call.StreamHandler().set_name(name="karapace"),
+                    call.root.addHandler(mock_logging.StreamHandler.return_value),
+                    call.root.setLevel("WARNING"),
+                ]
+            )
+
+
+def test_configure_logging_systemd_handler(karapace_container: KarapaceContainer) -> None:
+    config = karapace_container.config().set_config_defaults(
+        {
+            "log_handler": "systemd",
+            "log_level": "WARNING",
+        }
+    )
+    with pytest.raises(ModuleNotFoundError):
+        configure_logging(config=config)
+
+
+def test_configure_logging_unknown_handler(caplog: LogCaptureFixture, karapace_container: KarapaceContainer) -> None:
+    config = karapace_container.config().set_config_defaults(
+        {
+            "log_handler": "unknown",
+            "log_level": "DEBUG",
+        }
+    )
+    with caplog.at_level(logging.WARNING, logger="karapace.logging_setup"):
+        with patch("karapace.logging_setup.logging") as mock_logging:
+            configure_logging(config=config)
+
+            mock_logging.assert_has_calls(
+                [
+                    call.basicConfig(level="DEBUG", format="%(name)-20s\t%(threadName)s\t%(levelname)-8s\t%(message)s"),
+                    call.getLogger(),
+                    call.getLogger().setLevel("DEBUG"),
+                    call.warning("Log handler %s not recognized, root handler not set.", "unknown"),
+                    call.root.setLevel("DEBUG"),
+                ]
+            )
+            for log in caplog.records:
+                assert log.name == "karapace.logging_setup"
+                assert log.levelname == "WARNING"
+                assert log.message == "Log handler unknown not recognized, root handler not set."