diff --git a/components/clp-mcp-server/uv.lock b/components/clp-mcp-server/uv.lock index 9a121b8915..1bd602cc6f 100644 --- a/components/clp-mcp-server/uv.lock +++ b/components/clp-mcp-server/uv.lock @@ -396,6 +396,7 @@ dependencies = [ { name = "result" }, { name = "sqlalchemy" }, { name = "strenum" }, + { name = "structlog" }, ] [package.metadata] @@ -412,6 +413,7 @@ requires-dist = [ { name = "result", specifier = ">=0.17.0" }, { name = "sqlalchemy", specifier = ">=2.0.46" }, { name = "strenum", specifier = ">=0.4.15" }, + { name = "structlog", specifier = ">=26.1.0" }, ] [package.metadata.requires-dev] @@ -2557,6 +2559,18 @@ wheels = [ { url = "https://files.pythonhosted.org/packages/81/69/297302c5f5f59c862faa31e6cb9a4cd74721cd1e052b38e464c5b402df8b/StrEnum-0.4.15-py3-none-any.whl", hash = "sha256:a30cda4af7cc6b5bf52c8055bc4bf4b2b6b14a93b574626da33df53cf7740659", size = 8851, upload-time = "2023-06-29T22:02:56.947Z" }, ] +[[package]] +name = "structlog" +version = "26.1.0" +source = { registry = "https://pypi.org/simple" } +dependencies = [ + { name = "typing-extensions", marker = "python_full_version < '3.11'" }, +] +sdist = { url = "https://files.pythonhosted.org/packages/5e/89/b4a0bcfdf4f71a3dea31379f095929613d7e4528a0996bca6aa964cd0dca/structlog-26.1.0.tar.gz", hash = "sha256:f63a716cbd1b1291cf7661de7794b455acfa4c43c5bcf1630e6ad5ddc1adb3b7", size = 1459881, upload-time = "2026-06-06T07:33:39.348Z" } +wheels = [ + { url = "https://files.pythonhosted.org/packages/a9/18/489c97b834dfff9cf2fc2507cede4bcd4b11e67f84bc462acd1992496f86/structlog-26.1.0-py3-none-any.whl", hash = "sha256:e081a26d6c373e6d201eca24eede26d8ffab07f88f477822e679183428d3d91e", size = 73764, upload-time = "2026-06-06T07:33:38.046Z" }, +] + [[package]] name = "tomli" version = "2.4.0" diff --git a/components/clp-package-utils/uv.lock b/components/clp-package-utils/uv.lock index 91b222dace..6536c8a305 100644 --- a/components/clp-package-utils/uv.lock +++ b/components/clp-package-utils/uv.lock @@ -380,6 +380,7 @@ dependencies = [ { name = "result" }, { name = "sqlalchemy" }, { name = "strenum" }, + { name = "structlog" }, ] [package.metadata] @@ -396,6 +397,7 @@ requires-dist = [ { name = "result", specifier = ">=0.17.0" }, { name = "sqlalchemy", specifier = ">=2.0.46" }, { name = "strenum", specifier = ">=0.4.15" }, + { name = "structlog", specifier = ">=26.1.0" }, ] [package.metadata.requires-dev] @@ -1644,6 +1646,18 @@ wheels = [ { url = "https://files.pythonhosted.org/packages/81/69/297302c5f5f59c862faa31e6cb9a4cd74721cd1e052b38e464c5b402df8b/StrEnum-0.4.15-py3-none-any.whl", hash = "sha256:a30cda4af7cc6b5bf52c8055bc4bf4b2b6b14a93b574626da33df53cf7740659", size = 8851, upload-time = "2023-06-29T22:02:56.947Z" }, ] +[[package]] +name = "structlog" +version = "26.1.0" +source = { registry = "https://pypi.org/simple" } +dependencies = [ + { name = "typing-extensions", marker = "python_full_version < '3.11'" }, +] +sdist = { url = "https://files.pythonhosted.org/packages/5e/89/b4a0bcfdf4f71a3dea31379f095929613d7e4528a0996bca6aa964cd0dca/structlog-26.1.0.tar.gz", hash = "sha256:f63a716cbd1b1291cf7661de7794b455acfa4c43c5bcf1630e6ad5ddc1adb3b7", size = 1459881, upload-time = "2026-06-06T07:33:39.348Z" } +wheels = [ + { url = "https://files.pythonhosted.org/packages/a9/18/489c97b834dfff9cf2fc2507cede4bcd4b11e67f84bc462acd1992496f86/structlog-26.1.0-py3-none-any.whl", hash = "sha256:e081a26d6c373e6d201eca24eede26d8ffab07f88f477822e679183428d3d91e", size = 73764, upload-time = "2026-06-06T07:33:38.046Z" }, +] + [[package]] name = "tomli" version = "2.4.0" diff --git a/components/clp-py-utils/clp_py_utils/clp_logging.py b/components/clp-py-utils/clp_py_utils/clp_logging.py index 353ac89d9c..cd66152029 100644 --- a/components/clp-py-utils/clp_py_utils/clp_logging.py +++ b/components/clp-py-utils/clp_py_utils/clp_logging.py @@ -1,8 +1,14 @@ +"""Shared logging helpers for CLP Python components.""" + import logging import os import pathlib from typing import get_args, Literal +import structlog +from structlog.stdlib import BoundLogger +from structlog.typing import Processor + LoggingLevel = Literal[ "INFO", "DEBUG", @@ -12,12 +18,107 @@ "CRITICAL", ] +# Processor chain for events emitted through structlog loggers before they reach +# `ProcessorFormatter`. +_STRUCTLOG_PROCESSORS: tuple[Processor, ...] = ( + structlog.stdlib.filter_by_level, + structlog.contextvars.merge_contextvars, + structlog.stdlib.add_logger_name, + structlog.stdlib.add_log_level, + structlog.stdlib.PositionalArgumentsFormatter(), + structlog.processors.TimeStamper(fmt="iso", utc=True, key="timestamp"), + structlog.processors.StackInfoRenderer(), + structlog.processors.format_exc_info, + structlog.processors.UnicodeDecoder(), + structlog.processors.CallsiteParameterAdder( + { + structlog.processors.CallsiteParameter.FILENAME, + structlog.processors.CallsiteParameter.FUNC_NAME, + structlog.processors.CallsiteParameter.LINENO, + } + ), +) + +# Processor chain for stdlib `LogRecord` objects that did not originate from structlog. +_FOREIGN_PRE_CHAIN: tuple[Processor, ...] = ( + structlog.contextvars.merge_contextvars, + structlog.stdlib.add_logger_name, + structlog.stdlib.add_log_level, + structlog.stdlib.ExtraAdder(), + structlog.stdlib.PositionalArgumentsFormatter(), + structlog.processors.TimeStamper(fmt="iso", utc=True, key="timestamp"), + structlog.processors.StackInfoRenderer(), + structlog.processors.format_exc_info, + structlog.processors.UnicodeDecoder(), + structlog.processors.CallsiteParameterAdder( + { + structlog.processors.CallsiteParameter.FILENAME, + structlog.processors.CallsiteParameter.FUNC_NAME, + structlog.processors.CallsiteParameter.LINENO, + } + ), +) + + +def configure_structlog() -> None: + """Configure structlog with CLP's default processor chain if it is not already configured.""" + if not structlog.is_configured(): + structlog.configure( + processors=[ + *_STRUCTLOG_PROCESSORS, + structlog.stdlib.ProcessorFormatter.wrap_for_formatter, + ], + logger_factory=structlog.stdlib.LoggerFactory(), + wrapper_class=BoundLogger, + cache_logger_on_first_use=True, + ) + + +def get_structlog_logger(name: str) -> BoundLogger: + """ + Configure CLP's structured logging defaults and return a structlog logger for a component. + + CLP uses structlog's stdlib integration, so this first configures the stdlib logger's + handlers with structlog's `ProcessorFormatter`. Use the returned structlog logger for log calls. + + :param name: Name of the logger to create or retrieve. + :return: A structlog logger configured to emit through CLP's JSON formatter. + """ + configure_structlog() + stdlib_logger = get_logger(name) + configure_logging(stdlib_logger, name) + return structlog.stdlib.get_logger(name) + + +def get_logging_formatter() -> logging.Formatter: + """:return: A JSON log formatter configured with CLP's structlog processors.""" + return structlog.stdlib.ProcessorFormatter( + # foreign_pre_chain is run for stdlib LogRecord objects that do not go through + # structlog's processor chain. + foreign_pre_chain=_FOREIGN_PRE_CHAIN, + processors=[ + structlog.stdlib.ProcessorFormatter.remove_processors_meta, + structlog.processors.JSONRenderer(), + ], + ) + -def get_logging_formatter(): - return logging.Formatter("%(asctime)s %(name)s [%(levelname)s] %(message)s") +def set_json_formatter_on_handlers(logger: logging.Logger) -> None: + """ + Set CLP's JSON log formatter on all handlers currently attached to the logger. + + :param logger: Logger whose handlers should use CLP's JSON formatter. + """ + formatter = get_logging_formatter() + for handler in logger.handlers: + handler.setFormatter(formatter) -def get_logger(name: str): +def get_logger(name: str) -> logging.Logger: + """ + :param name: Name of the logger to create or retrieve. + :return: A logger configured with CLP's JSON console formatter. + """ logger = logging.getLogger(name) # Setup console logging logging_console_handler = logging.StreamHandler() @@ -28,12 +129,19 @@ def get_logger(name: str): return logger -def set_logging_level(logger: logging.Logger, level: str | None): +def set_logging_level(logger: logging.Logger, level: str | None) -> None: + """ + Set a logger to the requested logging level, defaulting to INFO when the level is unset or + invalid. + + :param logger: Logger whose level should be updated. + :param level: Requested logging level, or `None` to use INFO. + """ if level is None: logger.setLevel(logging.INFO) return if level not in get_args(LoggingLevel): - logger.warning(f"Invalid logging level: {level}, using INFO as default") + logger.warning("Invalid logging level: %s, using INFO as default", level) logger.setLevel(logging.INFO) return @@ -43,7 +151,7 @@ def set_logging_level(logger: logging.Logger, level: str | None): def configure_logging( logger: logging.Logger, component_name: str, -): +) -> None: """ Configures file logging and the logging level for a logger using environment variables. diff --git a/components/clp-py-utils/pyproject.toml b/components/clp-py-utils/pyproject.toml index c6c70ed34d..9b5dc77dcd 100644 --- a/components/clp-py-utils/pyproject.toml +++ b/components/clp-py-utils/pyproject.toml @@ -18,6 +18,7 @@ dependencies = [ "result>=0.17.0", "sqlalchemy>=2.0.46", "StrEnum>=0.4.15", + "structlog>=26.1.0", ] [build-system] diff --git a/components/clp-py-utils/uv.lock b/components/clp-py-utils/uv.lock index 78e5172551..f43b9d77fa 100644 --- a/components/clp-py-utils/uv.lock +++ b/components/clp-py-utils/uv.lock @@ -370,6 +370,7 @@ dependencies = [ { name = "result" }, { name = "sqlalchemy" }, { name = "strenum" }, + { name = "structlog" }, ] [package.dev-dependencies] @@ -396,6 +397,7 @@ requires-dist = [ { name = "result", specifier = ">=0.17.0" }, { name = "sqlalchemy", specifier = ">=2.0.46" }, { name = "strenum", specifier = ">=0.4.15" }, + { name = "structlog", specifier = ">=26.1.0" }, ] [package.metadata.requires-dev] @@ -1644,6 +1646,18 @@ wheels = [ { url = "https://files.pythonhosted.org/packages/81/69/297302c5f5f59c862faa31e6cb9a4cd74721cd1e052b38e464c5b402df8b/StrEnum-0.4.15-py3-none-any.whl", hash = "sha256:a30cda4af7cc6b5bf52c8055bc4bf4b2b6b14a93b574626da33df53cf7740659", size = 8851, upload-time = "2023-06-29T22:02:56.947Z" }, ] +[[package]] +name = "structlog" +version = "26.1.0" +source = { registry = "https://pypi.org/simple" } +dependencies = [ + { name = "typing-extensions", marker = "python_full_version < '3.11'" }, +] +sdist = { url = "https://files.pythonhosted.org/packages/5e/89/b4a0bcfdf4f71a3dea31379f095929613d7e4528a0996bca6aa964cd0dca/structlog-26.1.0.tar.gz", hash = "sha256:f63a716cbd1b1291cf7661de7794b455acfa4c43c5bcf1630e6ad5ddc1adb3b7", size = 1459881, upload-time = "2026-06-06T07:33:39.348Z" } +wheels = [ + { url = "https://files.pythonhosted.org/packages/a9/18/489c97b834dfff9cf2fc2507cede4bcd4b11e67f84bc462acd1992496f86/structlog-26.1.0-py3-none-any.whl", hash = "sha256:e081a26d6c373e6d201eca24eede26d8ffab07f88f477822e679183428d3d91e", size = 73764, upload-time = "2026-06-06T07:33:38.046Z" }, +] + [[package]] name = "tomli" version = "2.4.0" diff --git a/components/job-orchestration/job_orchestration/executor/compress/celery.py b/components/job-orchestration/job_orchestration/executor/compress/celery.py index e47358a05b..1bbb84bcd1 100644 --- a/components/job-orchestration/job_orchestration/executor/compress/celery.py +++ b/components/job-orchestration/job_orchestration/executor/compress/celery.py @@ -1,5 +1,9 @@ -from celery import Celery -from celery.signals import worker_process_init, worker_process_shutdown +"""Celery app configuration for compression task execution.""" + +import logging + +from celery import Celery, signals +from clp_py_utils.clp_logging import set_json_formatter_on_handlers from clp_py_utils.telemetry import init_telemetry, shutdown_telemetry from job_orchestration.executor.compress import celeryconfig @@ -8,12 +12,25 @@ app.config_from_object(celeryconfig) -@worker_process_init.connect +@signals.after_setup_logger.connect +@signals.after_setup_task_logger.connect +def setup_json_logging(logger: logging.Logger | None = None, **_: object) -> None: + """ + Use CLP's JSON formatter for loggers configured by Celery. + + :param logger: Logger configured by Celery, if one was provided by the signal. + :param _: Additional Celery signal keyword arguments. Unused. + """ + if logger is not None: + set_json_formatter_on_handlers(logger) + + +@signals.worker_process_init.connect def setup_telemetry(**kwargs) -> None: init_telemetry() -@worker_process_shutdown.connect +@signals.worker_process_shutdown.connect def teardown_telemetry(**kwargs) -> None: shutdown_telemetry() diff --git a/components/job-orchestration/job_orchestration/executor/query/celery.py b/components/job-orchestration/job_orchestration/executor/query/celery.py index d0a0f239d2..e624c97fba 100644 --- a/components/job-orchestration/job_orchestration/executor/query/celery.py +++ b/components/job-orchestration/job_orchestration/executor/query/celery.py @@ -1,9 +1,28 @@ -from celery import Celery +"""Celery app configuration for query task execution.""" + +import logging + +from celery import Celery, signals +from clp_py_utils.clp_logging import set_json_formatter_on_handlers from job_orchestration.executor.query import celeryconfig app = Celery("query") app.config_from_object(celeryconfig) + +@signals.after_setup_logger.connect +@signals.after_setup_task_logger.connect +def setup_json_logging(logger: logging.Logger | None = None, **_: object) -> None: + """ + Use CLP's JSON formatter for loggers configured by Celery. + + :param logger: Logger configured by Celery, if one was provided by the signal. + :param _: Additional Celery signal keyword arguments. Unused. + """ + if logger is not None: + set_json_formatter_on_handlers(logger) + + if "__main__" == __name__: app.start() diff --git a/components/job-orchestration/uv.lock b/components/job-orchestration/uv.lock index c80691080d..57bbb36822 100644 --- a/components/job-orchestration/uv.lock +++ b/components/job-orchestration/uv.lock @@ -370,6 +370,7 @@ dependencies = [ { name = "result" }, { name = "sqlalchemy" }, { name = "strenum" }, + { name = "structlog" }, ] [package.metadata] @@ -386,6 +387,7 @@ requires-dist = [ { name = "result", specifier = ">=0.17.0" }, { name = "sqlalchemy", specifier = ">=2.0.46" }, { name = "strenum", specifier = ">=0.4.15" }, + { name = "structlog", specifier = ">=26.1.0" }, ] [package.metadata.requires-dev] @@ -1644,6 +1646,18 @@ wheels = [ { url = "https://files.pythonhosted.org/packages/81/69/297302c5f5f59c862faa31e6cb9a4cd74721cd1e052b38e464c5b402df8b/StrEnum-0.4.15-py3-none-any.whl", hash = "sha256:a30cda4af7cc6b5bf52c8055bc4bf4b2b6b14a93b574626da33df53cf7740659", size = 8851, upload-time = "2023-06-29T22:02:56.947Z" }, ] +[[package]] +name = "structlog" +version = "26.1.0" +source = { registry = "https://pypi.org/simple" } +dependencies = [ + { name = "typing-extensions", marker = "python_full_version < '3.11'" }, +] +sdist = { url = "https://files.pythonhosted.org/packages/5e/89/b4a0bcfdf4f71a3dea31379f095929613d7e4528a0996bca6aa964cd0dca/structlog-26.1.0.tar.gz", hash = "sha256:f63a716cbd1b1291cf7661de7794b455acfa4c43c5bcf1630e6ad5ddc1adb3b7", size = 1459881, upload-time = "2026-06-06T07:33:39.348Z" } +wheels = [ + { url = "https://files.pythonhosted.org/packages/a9/18/489c97b834dfff9cf2fc2507cede4bcd4b11e67f84bc462acd1992496f86/structlog-26.1.0-py3-none-any.whl", hash = "sha256:e081a26d6c373e6d201eca24eede26d8ffab07f88f477822e679183428d3d91e", size = 73764, upload-time = "2026-06-06T07:33:38.046Z" }, +] + [[package]] name = "tomli" version = "2.4.0" diff --git a/docs/src/dev-docs/index.md b/docs/src/dev-docs/index.md index c9146763b1..f22ae29f37 100644 --- a/docs/src/dev-docs/index.md +++ b/docs/src/dev-docs/index.md @@ -96,6 +96,7 @@ tooling-gh-workflows design-project-structure design-deployment-orchestration +logging design-kv-ir-streams/index design-metadata-db diff --git a/docs/src/dev-docs/logging-developer-guide.md b/docs/src/dev-docs/logging-developer-guide.md new file mode 100644 index 0000000000..f12af53db2 --- /dev/null +++ b/docs/src/dev-docs/logging-developer-guide.md @@ -0,0 +1,70 @@ +# Developer guide: writing logs + +This guide provides language-specific setup instructions and standards for initializing loggers and +emitting diagnostic logs when developing or modifying CLP components. + +:::{note} +Always prefer UTC service timestamps. Time zone conversions should be handled downstream in log +viewers or aggregation systems. +::: + +## Python + +Python orchestration services should use `structlog` for structured JSON logging and bind +context variables where appropriate. + +```python +from clp_py_utils.clp_logging import get_structlog_logger + +log = get_structlog_logger("service_name") +log.info("hello, %s!", "world") +``` + +:::{note} +Existing Python services use stdlib loggers whose handlers are configured with structlog's +`ProcessorFormatter`. Follow the established convention when modifying those services. +::: + +## Rust + +Rust HTTP services should initialize `tracing` at process startup using +[`clp_rust_utils::logging::set_up_logging`][clp-rust-logging] and keep the returned guard alive +for the lifetime of the process: + +```rust +let _guard = clp_rust_utils::logging::set_up_logging("service_name.log"); + +// Choose structured logging over formatting values directly into the message field. +tracing::info!(job_id = compression_job_id, "Compression job completed."); +``` + +## WebUI + +WebUI server code should use Fastify's Pino logger. Use `request.log` for request-scoped logs and +`app.log` for startup, shutdown, and application-level logs: + +```typescript +// Request-scoped +request.log.info({searchJobId}, "Search submitted"); +request.log.error(err, "Failed to submit search"); + +// Application-scoped +app.log.info("WebUI server listening on port 3000"); +``` + +WebUI client code should use `console.*` for browser diagnostics: + +```typescript +console.error("Failed to submit query:", err); +``` + +## Core and setup tools + +* Native core binaries (`clp`, `clp-s`, `glt`, native `reducer_server`) should continue using + [`spdlog`][spdlog] and the `spdlog` initialization already defined in each binary's startup code. +* Package/setup tools (DB initialization scripts, package controllers) should use the + [standard Python logger][std-logger]. + +[clp-rust-logging]: https://github.com/y-scope/clp/blob/DOCS_VAR_CLP_GIT_REF/components/clp-rust-utils/src/logging.rs +[spdlog]: https://github.com/gabime/spdlog +[std-logger]: https://docs.python.org/3/library/logging.html diff --git a/docs/src/dev-docs/logging-operator-guide.md b/docs/src/dev-docs/logging-operator-guide.md new file mode 100644 index 0000000000..4a61a8bb84 --- /dev/null +++ b/docs/src/dev-docs/logging-operator-guide.md @@ -0,0 +1,186 @@ +# Operator guide: consuming CLP logs + +This guide details how to configure internal log levels, capture service logs, and understand the +component-specific log structures emitted by a running CLP deployment. The table below provides a +high-level overview of the logging behaviors across all component families: + +| Component family | Components | Logger | Format | Level control | +|-------------------------------|--------------------------------------------------------------------------------------------------------------------------------|-----------------------------------------------------------------|------------------------|----------------------------| +| Python orchestration services | `compression_scheduler`, `query_scheduler`, `compression_worker`, `query_worker`, `reducer`, `garbage_collector`, `mcp_server` | [`structlog` with stdlib logging compatibility][clp-py-logging] | JSON | `CLP_LOGGING_LEVEL` | +| Rust HTTP services | `api_server`, `log_ingestor` | [`clp_rust_utils::logging`][clp-rust-logging] / `tracing` | JSON | `RUST_LOG` | +| WebUI server | Fastify server | [Fastify/Pino][pino] | JSON or pretty text | `LOG_LEVEL` | +| WebUI client | Browser app | Browser console | Browser console output | Browser/devtools dependent | +| Native core binaries | `clp`, `clp-s`, `glt`, native `reducer_server` | `spdlog` | Text | Binary-specific | +| Package/setup tools | Package controller, DB initialization scripts | Python stdlib logging | Text | Script-specific | + +## Log level configuration + +This section covers how to modify logging verbosity for different components. Use the following +environment variables and settings to filter logs for each component family: + +* **Python orchestration services**: `CLP_LOGGING_LEVEL` supports `DEBUG`, `INFO`, `WARN`, + `WARNING`, `ERROR`, and `CRITICAL`. Missing or invalid values default to `INFO`. +* **Rust HTTP services**: Configure log filtering with [tracing_subscriber::EnvFilter][EnvFilter]. + Filter directives are read from the `RUST_LOG` environment variable to determine which spans and + events are enabled. + * *`log-ingestor`*: Log level is exposed via `CLP_LOG_INGESTOR_LOGGING_LEVEL` (Docker Compose) + or `clpConfig.log_ingestor.logging_level` (Helm), which is then passed to `RUST_LOG`. + * *`api-server`*: Log level is hardcoded to `INFO` and does not expose a deployment variable + for configuration. +* **WebUI**: `LOG_LEVEL` controls the Pino server log level (defaults to `info`). + + :::{warning} + `LOG_LEVEL` is a generic environment variable. Be mindful of environment + variable collisions with other tools or container settings. + ::: + +## Log routing and collection + +Access to the CLP Package logs is entirely dependent on where the component is executed. + +### Containerized services + +For continuously running deployed services such as Python orchestration services, Rust HTTP services, and WebUI server, log routing depends on the orchestrator: + +* **Docker Compose**: Logs are available using `docker compose logs`. If `CLP_LOGS_DIR` is set, +logs are additionally written to `/.log`. This directory mounts to the host via `CLP_LOGS_DIR_HOST` (defaults to `./var/log`). + :::{note} + For Rust services, setting `CLP_LOGS_DIR` enables file logging with hourly log rotation and a + non-blocking file writer. + ::: +* **Kubernetes/Helm**: Logs are accessible using `kubectl logs` or a cluster log collector (e.g., Fluent Bit). File + logging is only enabled for templates that set `CLP_LOGS_DIR` and mount a log volume. + +### Standalone tools + +* **Core binaries**: Running standalone binaries (`clp`, `clp-s`, etc.) emits + unstructured `spdlog` text to `stdout`. + :::{note} + *When deployed*, Python orchestration services invoke these binaries as subprocesses. + Consequently, the core binaries' unstructured log text is captured and written to the Python + logger's output stream as a single multi-line JSON record. These appear alongside normal container + logs in Docker or Kubernetes. + ::: +* **WebUI client**: WebUI client (`console.*`) logs remain local to the user's browser devtools + and are *not* captured by any backend telemetry service. They should be treated purely as local + diagnostics. +* **Package scripts**: Package controller commands and one-shot setup scripts emit unstructured + Python stdlib logs to `stdout`. + +## Component-specific log schemas + +There is no single project-wide JSON schema. Python, Rust, and Pino logs are all line-delimited JSON +in packaged non-interactive service runtimes, but each component family uses its own field names. +The following sections describe the log schema for each component family. + +### Python orchestration services + +These services use [`clp_py_utils.clp_logging`][clp-py-logging] and emit one JSON object per log +record. Each record includes the following fields: + +| Field | Description | +|-------------------|----------------------------------------------------------------------| +| `timestamp` | ISO-8601 UTC timestamp. | +| `event` | Formatted log message. | +| `logger` | Logger name. | +| `level` | Log level, emitted as values such as `info`, `warning`, and `error`. | +| `filename` | Source filename for the log call. | +| `func_name` | Source function name for the log call. | +| `lineno` | Source line number for the log call. | +| `exception` | Present when `exc_info` is logged. | +| `stack` | Present when `stack_info` is logged. | +| Context variables | Fields bound through structlog context variables. | +| Extra fields | Fields passed through stdlib logging's `extra` argument. | + +Example: + +```json +{ + "timestamp": "2026-06-22T17:03:21.123456Z", + "event": "Compression job 1 submitted.", + "logger": "compression_scheduler", + "level": "info", + "filename": "compression_scheduler.py", + "func_name": "main", + "lineno": 616 +} +``` + +### Rust HTTP services + +These services use [`clp_rust_utils::logging::set_up_logging`][clp-rust-logging], which configures +`tracing_subscriber` to emit one JSON object per log record. Each record includes the following +fields: + +| Field | Description | +|---------------|-------------------------------------------------------------------| +| `timestamp` | Timestamp emitted by `tracing_subscriber`. | +| `level` | Log level, emitted as values such as `INFO`, `WARN`, and `ERROR`. | +| `fields` | Structured `tracing` fields, including the log message. | +| `filename` | Source filename for the log call. | +| `line_number` | Source line number for the log call. | + +Example: + +```json +{ + "timestamp": "2026-06-26T13:06:48.621307", + "level": "INFO", + "fields": { + "message": "Spawned SQS listener task.", + "job_id": "3", + "task_id": "0" + }, + "filename": "components/log-ingestor/src/ingestion_job/sqs_listener.rs", + "line_number": 320 +} +``` + +### WebUI server + +The WebUI server uses Fastify's Pino logger. When the server runs without an interactive terminal, +such as in Docker Compose or Kubernetes, it emits one JSON object per log record. When `stdout` is +an interactive terminal, it uses `pino-pretty` for human-readable output. + +Each JSON record includes the following fields: + +| Field | Description | +|----------------|---------------------------------------------------------| +| `level` | Numeric Pino log level. | +| `time` | Unix timestamp in milliseconds. | +| `pid` | Process ID. | +| `hostname` | Hostname of the process emitting the log. | +| `reqId` | Fastify request ID, when the record is request-scoped. | +| `req`, `res` | Request and response metadata, when available. | +| `responseTime` | Request duration in milliseconds, when available. | +| `msg` | Log message. | +| Extra fields | Structured fields passed to the Pino log call. | + +Example: + +```json +{ + "level": 30, + "time": 1782480774533, + "pid": 1, + "hostname": "webui", + "reqId": "req-1h", + "res": { + "statusCode": 200 + }, + "responseTime": 1.0457000732421875, + "msg": "request completed" +} +``` + +### Core and package tools + +Native core binaries emit unstructured `spdlog` text logs. Package controller commands and one-shot +setup scripts also emit unstructured Python stdlib logs. These tools do not follow the JSON log +formats described for Python orchestration services, Rust HTTP services, or the WebUI server. + + +[clp-py-logging]: https://github.com/y-scope/clp/blob/DOCS_VAR_CLP_GIT_REF/components/clp-py-utils/clp_py_utils/clp_logging.py +[clp-rust-logging]: https://github.com/y-scope/clp/blob/DOCS_VAR_CLP_GIT_REF/components/clp-rust-utils/src/logging.rs +[pino]: https://fastify.dev/docs/v2.15.x/Documentation/Logging/ +[EnvFilter]: https://docs.rs/tracing-subscriber/latest/tracing_subscriber/filter/struct.EnvFilter.html diff --git a/docs/src/dev-docs/logging.md b/docs/src/dev-docs/logging.md new file mode 100644 index 0000000000..f3ac0f2c31 --- /dev/null +++ b/docs/src/dev-docs/logging.md @@ -0,0 +1,18 @@ +# CLP Package logging + +The CLP Package utilizes a polyglot architecture, meaning each component manages its own +logging stack. There is **no single project-wide JSON schema**. + +This document is divided into two sections: + +* [Developer guide](logging-developer-guide.md): How to set up and write logs when modifying CLP + components. +* [Operator guide](logging-operator-guide.md): How to configure log levels, capture service logs, + and understand the component-specific log structures when deploying CLP package services. + +:::{toctree} +:hidden: + +logging-developer-guide +logging-operator-guide +::: diff --git a/integration-tests/uv.lock b/integration-tests/uv.lock index 2e981d996e..1e3ad7a97f 100644 --- a/integration-tests/uv.lock +++ b/integration-tests/uv.lock @@ -553,6 +553,7 @@ dependencies = [ { name = "result" }, { name = "sqlalchemy" }, { name = "strenum" }, + { name = "structlog" }, ] [package.metadata] @@ -569,6 +570,7 @@ requires-dist = [ { name = "result", specifier = ">=0.17.0" }, { name = "sqlalchemy", specifier = ">=2.0.46" }, { name = "strenum", specifier = ">=0.4.15" }, + { name = "structlog", specifier = ">=26.1.0" }, ] [package.metadata.requires-dev] @@ -2868,6 +2870,18 @@ wheels = [ { url = "https://files.pythonhosted.org/packages/81/69/297302c5f5f59c862faa31e6cb9a4cd74721cd1e052b38e464c5b402df8b/StrEnum-0.4.15-py3-none-any.whl", hash = "sha256:a30cda4af7cc6b5bf52c8055bc4bf4b2b6b14a93b574626da33df53cf7740659", size = 8851, upload-time = "2023-06-29T22:02:56.947Z" }, ] +[[package]] +name = "structlog" +version = "26.1.0" +source = { registry = "https://pypi.org/simple" } +dependencies = [ + { name = "typing-extensions", marker = "python_full_version < '3.11'" }, +] +sdist = { url = "https://files.pythonhosted.org/packages/5e/89/b4a0bcfdf4f71a3dea31379f095929613d7e4528a0996bca6aa964cd0dca/structlog-26.1.0.tar.gz", hash = "sha256:f63a716cbd1b1291cf7661de7794b455acfa4c43c5bcf1630e6ad5ddc1adb3b7", size = 1459881, upload-time = "2026-06-06T07:33:39.348Z" } +wheels = [ + { url = "https://files.pythonhosted.org/packages/a9/18/489c97b834dfff9cf2fc2507cede4bcd4b11e67f84bc462acd1992496f86/structlog-26.1.0-py3-none-any.whl", hash = "sha256:e081a26d6c373e6d201eca24eede26d8ffab07f88f477822e679183428d3d91e", size = 73764, upload-time = "2026-06-06T07:33:38.046Z" }, +] + [[package]] name = "tomli" version = "2.4.0"