Fix JSON line logging (#3511)

Co-authored-by: Jan Klopper <[email protected]>

boefjes/boefjes/logging.json

@@ -3,8 +3,7 @@
   "disable_existing_loggers": 0,
   "formatters": {
     "default": {
-      "format": "%(asctime)s [%(process)d] [%(levelname)s] [%(module)s] %(message)s",
-      "datefmt": "[%Y-%m-%d %H:%M:%S %z]"
+      "format": "%(message)s"
     }
   },
   "handlers": {

bytes/dev.logging.conf

@@ -24,5 +24,4 @@ formatter=genericFormatter
 kwargs={"stream": sys.stdout}
 
 [formatter_genericFormatter]
-format=%(asctime)s [%(process)d] [%(levelname)s] [%(module)s] %(message)s
-datefmt=[%Y-%m-%d %H:%M:%S %z]
+format=%(message)s

bytes/logging.conf

@@ -31,5 +31,4 @@ formatter=genericFormatter
 kwargs={"stream": sys.stdout}
 
 [formatter_genericFormatter]
-format=%(asctime)s [%(process)d] [%(levelname)s] [%(module)s] %(message)s
-datefmt=[%Y-%m-%d %H:%M:%S %z]
+format=%(message)s

octopoes/bits/definitions.py

@@ -1,17 +1,17 @@
 import importlib
 import pkgutil
 from functools import cache
-from logging import getLogger
 from pathlib import Path
 from types import ModuleType
 
+import structlog
 from pydantic import BaseModel
 
 from octopoes.models.types import OOIType
 
 BITS_DIR = Path(__file__).parent
 BIT_ATTR_NAME = "BIT"
-logger = getLogger(__name__)
+logger = structlog.get_logger(__name__)
 
 
 class BitParameterDefinition(BaseModel):

octopoes/bits/disallowed_csp_hostnames/disallowed_csp_hostnames.py

@@ -1,4 +1,3 @@
-import logging
 from collections.abc import Iterator
 from typing import Any
 
@@ -10,8 +9,6 @@
 
 LINK_SHORTENERS = link_shorteners_list()
 
-logger = logging.getLogger(__name__)
-
 
 def get_disallowed_hostnames_from_config(config, config_key, default):
     disallowed_hostnames = config.get(config_key, None)

octopoes/logging.yml

@@ -3,8 +3,7 @@ disable_existing_loggers: 0
 
 formatters:
   default:
-    format: "%(asctime)s [%(process)d] [%(levelname)s] [%(module)s] %(message)s"
-    datefmt: "[%Y-%m-%d %H:%M:%S %z]"
+    format: "%(message)s"
 
 handlers:
   console:

octopoes/octopoes/api/router.py

@@ -3,10 +3,10 @@
 from collections import Counter
 from collections.abc import Generator
 from datetime import datetime
-from logging import getLogger
 from operator import itemgetter
 from typing import Any, Literal
 
+import structlog
 from asgiref.sync import sync_to_async
 from fastapi import APIRouter, Body, Depends, HTTPException, Path, Query, Request, status
 from httpx import HTTPError
@@ -41,7 +41,7 @@
 from octopoes.xtdb.query import Aliased
 from octopoes.xtdb.query import Query as XTDBQuery
 
-logger = getLogger(__name__)
+logger = structlog.get_logger(__name__)
 router = APIRouter(prefix="/{client}")
 
 

octopoes/octopoes/connector/octopoes.py

@@ -27,6 +27,7 @@
 from octopoes.models.transaction import TransactionRecord
 from octopoes.models.tree import ReferenceTree
 from octopoes.models.types import OOIType
+from octopoes.types import DECLARATION_CREATED, OBJECT_DELETED, OBSERVATION_CREATED, ORIGIN_DELETED
 
 
 class OctopoesAPIConnector:
@@ -176,14 +177,16 @@ def delete_origin(self, origin_id: str, valid_time: datetime) -> None:
 
         self.session.delete(f"/{self.client}/origins", params=params)
 
+        self.logger.info("Deleted origin", origin_id=origin_id, valid_time=valid_time, event_code=ORIGIN_DELETED)
+
     def save_observation(self, observation: Observation) -> None:
         self.session.post(
             f"/{self.client}/observations",
             headers={"Content-Type": "application/json"},
             content=observation.model_dump_json(),
         )
 
-        self.logger.info("Saved observation", observation=observation)
+        self.logger.info("Saved observation", observation=observation, event_code=OBSERVATION_CREATED)
 
     def save_declaration(self, declaration: Declaration) -> None:
         self.session.post(
@@ -192,7 +195,7 @@ def save_declaration(self, declaration: Declaration) -> None:
             content=declaration.model_dump_json(),
         )
 
-        self.logger.info("Saved declaration", declaration=declaration)
+        self.logger.info("Saved declaration", declaration=declaration, event_code=DECLARATION_CREATED)
 
     def save_affirmation(self, affirmation: Affirmation) -> None:
         self.session.post(
@@ -201,7 +204,7 @@ def save_affirmation(self, affirmation: Affirmation) -> None:
             content=affirmation.model_dump_json(),
         )
 
-        self.logger.info("Saved affirmation", affirmation=affirmation)
+        self.logger.info("Saved affirmation", affirmation=affirmation, event_code=DECLARATION_CREATED)
 
     def save_scan_profile(self, scan_profile: ScanProfile, valid_time: datetime):
         params = {"valid_time": str(valid_time)}
@@ -224,7 +227,7 @@ def delete(self, reference: Reference, valid_time: datetime) -> None:
         params = {"reference": str(reference), "valid_time": str(valid_time)}
         self.session.delete(f"/{self.client}/", params=params)
 
-        self.logger.info("Deleted object", reference=reference, valid_time=valid_time)
+        self.logger.info("Deleted object", reference=reference, valid_time=valid_time, event_code=OBJECT_DELETED)
 
     def delete_many(self, references: list[Reference], valid_time: datetime) -> None:
         params = {"valid_time": str(valid_time)}

octopoes/octopoes/core/service.py

@@ -2,10 +2,10 @@
 from collections import Counter
 from collections.abc import Callable, ValuesView
 from datetime import datetime, timezone
-from logging import getLogger
 from time import perf_counter
 from typing import Literal, overload
 
+import structlog
 from bits.definitions import get_bit_definitions
 from bits.runner import BitRunner
 from pydantic import TypeAdapter
@@ -47,7 +47,7 @@
 from octopoes.repositories.scan_profile_repository import ScanProfileRepository
 from octopoes.xtdb.client import Operation, OperationType, XTDBSession
 
-logger = getLogger(__name__)
+logger = structlog.get_logger("octopoes-core-service")
 settings = Settings()
 
 

octopoes/octopoes/repositories/origin_parameter_repository.py

@@ -1,6 +1,5 @@
 from datetime import datetime
 from http import HTTPStatus
-from logging import getLogger
 from typing import Any
 
 from httpx import HTTPStatusError
@@ -16,8 +15,6 @@
 from octopoes.xtdb.client import XTDBSession
 from octopoes.xtdb.query_builder import generate_pull_query
 
-logger = getLogger(__name__)
-
 
 class OriginParameterRepository(Repository):
     def __init__(self, event_manager: EventManager):

octopoes/octopoes/repositories/origin_repository.py

@@ -1,6 +1,5 @@
 from datetime import datetime
 from http import HTTPStatus
-from logging import getLogger
 from typing import Any
 from uuid import UUID
 
@@ -17,8 +16,6 @@
 from octopoes.xtdb.client import XTDBSession
 from octopoes.xtdb.query_builder import generate_pull_query
 
-logger = getLogger(__name__)
-
 
 class OriginRepository(Repository):
     def __init__(self, event_manager: EventManager):

octopoes/octopoes/repositories/scan_profile_repository.py

@@ -1,6 +1,5 @@
 from datetime import datetime
 from http import HTTPStatus
-from logging import getLogger
 from typing import Any
 
 from httpx import HTTPStatusError
@@ -16,8 +15,6 @@
 from octopoes.xtdb.client import XTDBSession
 from octopoes.xtdb.query_builder import generate_pull_query
 
-logger = getLogger(__name__)
-
 
 class ScanProfileRepository(Repository):
     def __init__(self, event_manager: EventManager):

octopoes/octopoes/types.py

@@ -0,0 +1,6 @@
+# Event codes for certain actions
+OBSERVATION_CREATED = 100101
+DECLARATION_CREATED = 100201
+AFFIRMATION_CREATED = 100301
+ORIGIN_DELETED = 100403
+OBJECT_DELETED = 100503

rocky/rocky/settings.py

@@ -527,11 +527,7 @@ def immutable_file_test(path, url):
         structlog.dev.set_exc_info,
         structlog.stdlib.PositionalArgumentsFormatter(),
         structlog.processors.TimeStamper("iso", utc=False),
-        (
-            structlog.processors.JSONRenderer()
-            if LOGGING_FORMAT == "json"
-            else structlog.dev.ConsoleRenderer(colors=True, pad_level=False)
-        ),
+        structlog.stdlib.ProcessorFormatter.wrap_for_formatter,
     ],
     context_class=dict,
     logger_factory=structlog.stdlib.LoggerFactory(),