instrument logging directly when logging is setup

Author: bisgaard-itis

packages/service-library/src/servicelib/logging_utils.py

@@ -16,6 +16,9 @@
 from pathlib import Path
 from typing import Any, NotRequired, TypeAlias, TypedDict, TypeVar
 
+from servicelib.tracing import setup_log_tracing
+from settings_library.tracing import TracingSettings
+
 from .logging_utils_filtering import GeneralLogFilter, LoggerName, MessageSubstring
 from .utils_secrets import mask_sensitive_data
 
@@ -80,12 +83,8 @@ def format(self, record) -> str:
 
 
 # SEE https://docs.python.org/3/library/logging.html#logrecord-attributes
-DEFAULT_FORMATTING = (
-    "log_level=%(levelname)s | log_timestamp=%(asctime)s | log_source=%(name)s:%(funcName)s(%(lineno)d) | log_uid=%(log_uid)s "
-    "| trace_id=%(otelTraceID)s | span_id=%(otelSpanID)s | resource.service.name=%(otelServiceName)s | trace_sampled=%(otelTraceSampled)s] "
-    "| log_msg=%(message)s"
-)
-LOCAL_FORMATTING = "%(levelname)s: [%(asctime)s/%(processName)s] [trace_id=%(otelTraceID)s span_id=%(otelSpanID)s resource.service.name=%(otelServiceName)s trace_sampled=%(otelTraceSampled)s] [%(name)s:%(funcName)s(%(lineno)d)] -  %(message)s"
+DEFAULT_FORMATTING = "log_level=%(levelname)s | log_timestamp=%(asctime)s | log_source=%(name)s:%(funcName)s(%(lineno)d) | log_uid=%(log_uid)s | log_msg=%(message)s"
+LOCAL_FORMATTING = "%(levelname)s: [%(asctime)s/%(processName)s] [%(name)s:%(funcName)s(%(lineno)d)]  -  %(message)s"
 
 # Graylog Grok pattern extractor:
 # log_level=%{WORD:log_level} \| log_timestamp=%{TIMESTAMP_ISO8601:log_timestamp} \| log_source=%{DATA:log_source} \| log_msg=%{GREEDYDATA:log_msg}
@@ -95,20 +94,30 @@ def config_all_loggers(
     *,
     log_format_local_dev_enabled: bool,
     logger_filter_mapping: dict[LoggerName, list[MessageSubstring]],
+    tracing_settings: TracingSettings | None,
 ) -> None:
     """
     Applies common configuration to ALL registered loggers
     """
-    fmt = DEFAULT_FORMATTING
     the_manager: logging.Manager = logging.Logger.manager
     root_logger = logging.getLogger()
 
     loggers = [root_logger] + [
         logging.getLogger(name) for name in the_manager.loggerDict
     ]
 
+    fmt = DEFAULT_FORMATTING
+    if tracing_settings is not None:
+        fmt = (
+            "log_level=%(levelname)s | log_timestamp=%(asctime)s | log_source=%(name)s:%(funcName)s(%(lineno)d) | log_uid=%(log_uid)s "
+            "| trace_id=%(otelTraceID)s | span_id=%(otelSpanID)s | resource.service.name=%(otelServiceName)s | trace_sampled=%(otelTraceSampled)s] "
+            "| log_msg=%(message)s"
+        )
+        setup_log_tracing(tracing_settings=tracing_settings)
     if log_format_local_dev_enabled:
         fmt = LOCAL_FORMATTING
+        if tracing_settings is not None:
+            fmt = "%(levelname)s: [%(asctime)s/%(processName)s] [trace_id=%(otelTraceID)s span_id=%(otelSpanID)s resource.service.name=%(otelServiceName)s trace_sampled=%(otelTraceSampled)s] [%(name)s:%(funcName)s(%(lineno)d)] -  %(message)s"
 
     for logger in loggers:
         _set_logging_handler(

services/agent/src/simcore_service_agent/core/application.py

@@ -33,6 +33,7 @@ def _setup_logger(settings: ApplicationSettings):
     config_all_loggers(
         log_format_local_dev_enabled=settings.AGENT_VOLUMES_LOG_FORMAT_LOCAL_DEV_ENABLED,
         logger_filter_mapping=settings.AGENT_VOLUMES_LOG_FILTER_MAPPING,
+        tracing_settings=settings.AGENT_TRACING,
     )
 
 

services/api-server/src/simcore_service_api_server/core/application.py

@@ -54,6 +54,7 @@ def init_app(settings: ApplicationSettings | None = None) -> FastAPI:
     config_all_loggers(
         log_format_local_dev_enabled=settings.API_SERVER_LOG_FORMAT_LOCAL_DEV_ENABLED,
         logger_filter_mapping=settings.API_SERVER_LOG_FILTER_MAPPING,
+        tracing_settings=settings.API_SERVER_TRACING,
     )
     _logger.debug("App settings:\n%s", settings.model_dump_json(indent=2))
 

services/autoscaling/src/simcore_service_autoscaling/main.py

@@ -15,6 +15,7 @@
 config_all_loggers(
     log_format_local_dev_enabled=the_settings.AUTOSCALING_LOG_FORMAT_LOCAL_DEV_ENABLED,
     logger_filter_mapping=the_settings.AUTOSCALING_LOG_FILTER_MAPPING,
+    tracing_settings=the_settings.AUTOSCALING_TRACING,
 )
 
 # SINGLETON FastAPI app

services/catalog/src/simcore_service_catalog/main.py

@@ -16,6 +16,7 @@
 config_all_loggers(
     log_format_local_dev_enabled=_the_settings.CATALOG_LOG_FORMAT_LOCAL_DEV_ENABLED,
     logger_filter_mapping=_the_settings.CATALOG_LOG_FILTER_MAPPING,
+    tracing_settings=_the_settings.CATALOG_TRACING,
 )
 
 

services/clusters-keeper/src/simcore_service_clusters_keeper/main.py

@@ -15,6 +15,7 @@
 config_all_loggers(
     log_format_local_dev_enabled=the_settings.CLUSTERS_KEEPER_LOG_FORMAT_LOCAL_DEV_ENABLED,
     logger_filter_mapping=the_settings.CLUSTERS_KEEPER_LOG_FILTER_MAPPING,
+    tracing_settings=the_settings.CLUSTERS_KEEPER_TRACING,
 )
 
 # SINGLETON FastAPI app

services/dask-sidecar/src/simcore_service_dask_sidecar/tasks.py

@@ -65,6 +65,7 @@ async def dask_setup(worker: distributed.Worker) -> None:
     config_all_loggers(
         log_format_local_dev_enabled=settings.DASK_LOG_FORMAT_LOCAL_DEV_ENABLED,
         logger_filter_mapping=settings.DASK_LOG_FILTER_MAPPING,
+        tracing_settings=None,  # no tracing for dask sidecar
     )
 
     logger.info("Setting up worker...")

services/datcore-adapter/src/simcore_service_datcore_adapter/core/application.py

@@ -42,6 +42,7 @@ def create_app(settings: ApplicationSettings | None = None) -> FastAPI:
     config_all_loggers(
         log_format_local_dev_enabled=settings.DATCORE_ADAPTER_LOG_FORMAT_LOCAL_DEV_ENABLED,
         logger_filter_mapping=settings.DATCORE_ADAPTER_LOG_FILTER_MAPPING,
+        tracing_settings=settings.DATCORE_ADAPTER_TRACING,
     )
 
     # keep mostly quiet noisy loggers

services/director-v2/src/simcore_service_director_v2/core/application.py

@@ -115,6 +115,7 @@ def create_base_app(settings: AppSettings | None = None) -> FastAPI:
     config_all_loggers(
         log_format_local_dev_enabled=settings.DIRECTOR_V2_LOG_FORMAT_LOCAL_DEV_ENABLED,
         logger_filter_mapping=settings.DIRECTOR_V2_LOG_FILTER_MAPPING,
+        tracing_settings=settings.DIRECTOR_V2_TRACING,
     )
     _logger.debug(settings.model_dump_json(indent=2))
 

services/director/src/simcore_service_director/main.py

@@ -17,6 +17,7 @@
 config_all_loggers(
     log_format_local_dev_enabled=_the_settings.DIRECTOR_LOG_FORMAT_LOCAL_DEV_ENABLED,
     logger_filter_mapping=_the_settings.DIRECTOR_LOG_FILTER_MAPPING,
+    tracing_settings=_the_settings.DIRECTOR_TRACING,
 )
 
 # SINGLETON FastAPI app