Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
6 changes: 5 additions & 1 deletion compute_modules/logging/common.py
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,7 @@

import json
import logging
import os
import threading
from datetime import datetime, timezone
from typing import TYPE_CHECKING, Any, Dict, MutableMapping, Optional, Tuple, Union
Expand All @@ -29,7 +30,7 @@
else:
_LoggerAdapter = logging.LoggerAdapter

DEFAULT_LOG_FORMAT = "PID: %(process_id)-6s JOB: %(job_id)-36s - %(message)s"
DEFAULT_LOG_FORMAT = "%(message)s"
DEFAULT_LOG_STRING_FORMATTER = logging.Formatter(DEFAULT_LOG_FORMAT)


Expand All @@ -51,6 +52,7 @@ def format(self, record: Any) -> str:
"origin": f"{record.filename}:{record.lineno}",
"safe": True,
"thread": threading.current_thread().name,
"params": getattr(record, "params", {}),
"message": formatted_message,
}
return json.dumps(log_entry)
Expand Down Expand Up @@ -118,9 +120,11 @@ def process(self, msg: Any, kwargs: MutableMapping[str, Any]) -> Tuple[Any, Muta
custom_data = {
"process_id": str(get_thread_local_data("process_id", "-1")),
"job_id": str(get_thread_local_data("job_id", "")),
"session_id": os.environ.get("COMPUTE_SESSION_ID", ""),
}
kwargs["extra"] = kwargs.get("extra", {})
kwargs["extra"].update(custom_data)
kwargs["extra"]["params"] = custom_data

return msg, kwargs

Expand Down
17 changes: 11 additions & 6 deletions tests/logging/test_log_context.py
Original file line number Diff line number Diff line change
Expand Up @@ -40,8 +40,13 @@ def logger_fixtures() -> tuple[ComputeModulesLoggerAdapter, ComputeModulesLogger
return (internal_logger, logger_1, logger_2)


def format_log_context(pid: int, job_id: str) -> str:
return f"PID: {pid:<6} JOB: {job_id:<37}"
def assert_log_params(log: str, process_id: int, job_id: str, session_id: str = "") -> None:
"""Parse log JSON and verify params field contains expected values"""
log_json = json.loads(log)
params = log_json["params"]
assert params["process_id"] == str(process_id), f"Expected process_id {process_id}, got {params['process_id']}"
assert params["job_id"] == job_id, f"Expected job_id {job_id}, got {params['job_id']}"
assert params["session_id"] == session_id, f"Expected session_id {session_id}, got {params['session_id']}"


def test_log_format(capsys: pytest.CaptureFixture[str], custom_formatter: JsonFormatter) -> None:
Expand All @@ -54,7 +59,7 @@ def test_log_format(capsys: pytest.CaptureFixture[str], custom_formatter: JsonFo
parsed_out = list(filter(lambda x: x, captured.err.split("\n")))
assert len(parsed_out) == 3
for log in parsed_out:
assert format_log_context(pid=-1, job_id="") in log
assert_log_params(log, process_id=-1, job_id="")

COMPUTE_MODULES_ADAPTER_MANAGER.update_process_id(process_id=PROCESS_ID)
internal_logger.info(INFO_STR)
Expand All @@ -64,7 +69,7 @@ def test_log_format(capsys: pytest.CaptureFixture[str], custom_formatter: JsonFo
parsed_out = list(filter(lambda x: x, captured.err.split("\n")))
assert len(parsed_out) == 3
for log in parsed_out:
assert format_log_context(pid=PROCESS_ID, job_id="") in log
assert_log_params(log, process_id=PROCESS_ID, job_id="")

job_id = str(uuid.uuid4())
COMPUTE_MODULES_ADAPTER_MANAGER.update_job_id(job_id=job_id)
Expand All @@ -75,7 +80,7 @@ def test_log_format(capsys: pytest.CaptureFixture[str], custom_formatter: JsonFo
parsed_out = list(filter(lambda x: x, captured.err.split("\n")))
assert len(parsed_out) == 3
for log in parsed_out:
assert format_log_context(pid=PROCESS_ID, job_id=job_id) in log
assert_log_params(log, process_id=PROCESS_ID, job_id=job_id)

# Test clearing now
COMPUTE_MODULES_ADAPTER_MANAGER.update_job_id(job_id="")
Expand All @@ -86,7 +91,7 @@ def test_log_format(capsys: pytest.CaptureFixture[str], custom_formatter: JsonFo
parsed_out = list(filter(lambda x: x, captured.err.split("\n")))
assert len(parsed_out) == 3
for log in parsed_out:
assert format_log_context(pid=PROCESS_ID, job_id="") in log
assert_log_params(log, process_id=PROCESS_ID, job_id="")

# Test Custom Formatting
# TODO split out into custom test once ComputeModuleLoggingAdapter made fixture to avoid capsys errors
Expand Down