From 6598816feb9e2ecf5e6f7561d4b049bb21cd2fd9 Mon Sep 17 00:00:00 2001
From: Bernhard Mallinger <bernhard.mallinger@eox.at>
Date: Mon, 21 Feb 2022 16:11:21 +0100
Subject: [PATCH] Make use of structlog logging
---
registrar/backend/eoxserver.py | 64 ++++++++++++++++++----------------
registrar/cli.py | 20 +++++++++++
registrar/daemon.py | 8 ++---
registrar/post_handlers.py | 6 ++--
registrar/registrar.py | 61 +++++++++++++++++---------------
registrar/source.py | 11 +++---
registrar/xml.py | 4 +--
7 files changed, 101 insertions(+), 73 deletions(-)
diff --git a/registrar/backend/eoxserver.py b/registrar/backend/eoxserver.py
index 2a1f0aa..1de1f9d 100644
--- a/registrar/backend/eoxserver.py
+++ b/registrar/backend/eoxserver.py
@@ -7,7 +7,7 @@ Contains implementations for different backends where data may be registered
"""
import os
import sys
-import logging
+import structlog
from typing import List, TYPE_CHECKING, Optional, TypedDict, cast
import json
from urllib.parse import urlparse
@@ -26,7 +26,7 @@ from ..source import Source, LocalSource, S3Source, SwiftSource
from .abc import ItemBackend
-logger = logging.getLogger(__name__)
+logger = structlog.getLogger(__name__)
class AssetsToCoverageMapping(TypedDict):
@@ -207,9 +207,9 @@ class EOxServerBackend(ItemBackend):
storage_name = storage.name
if created_storage_auth:
- logger.info(f"Created storage auth for {source.name}")
+ logger.info("Created storage auth", source=source.name)
if created_storage:
- logger.info(f"Created storage for {source.name}")
+ logger.info("Created storage for", source=source.name)
return [storage_name] if storage_name else []
@@ -266,9 +266,9 @@ class EOxServerBackend(ItemBackend):
product_type_obj = models.ProductType.objects.get(name=product_type["name"])
if created:
- logger.info(f"Created Product Type {product_type_obj}")
+ logger.info("Created Product Type" , product_type_obj=product_type_obj)
else:
- logger.info(f"Using existing Product Type {product_type_obj}")
+ logger.info(f"Using existing Product Type", product_type_obj=product_type_obj)
# resolve storage object
if storage:
@@ -317,8 +317,8 @@ class EOxServerBackend(ItemBackend):
service_visibility.save()
logger.info(
- f"Successfully {'replaced' if replaced else 'registered'} "
- f"Product {product.identifier}"
+ f"Successfully {'replaced' if replaced else 'registered'} Product",
+ product=product.identifier,
)
return product
@@ -362,7 +362,7 @@ class EOxServerBackend(ItemBackend):
break
if product_type_found:
- logger.info(f"Registering into EOxServer for type '{product_type['name']}'")
+ logger.info("Registering into EOxServer", type=product_type['name'])
product = self._register_with_stac(
source, item, replace, storage, product_type
)
@@ -393,27 +393,29 @@ class EOxServerBackend(ItemBackend):
# ugly, ugly hack
from eoxserver.resources.coverages import models
- try:
- logger.info(f"Deregistering product '{identifier}'")
- product = models.Product.objects.get(identifier=identifier)
- grids = list(models.Grid.objects.filter(coverage__parent_product=product))
- product.delete()
-
- # clean up grids
- for grid in grids:
- grid_used = models.EOObject.objects.filter(
- Q(coverage__grid=grid) | Q(mosaic__grid=grid),
- ).exists()
- # clean up grid as well, if it is not referenced
- # anymore but saving named (user defined) grids
- if grid and not grid.name and not grid_used:
- grid.delete()
- except models.Product.DoesNotExist:
- logger.info(f"No product with identifier '{identifier}' found")
- # no product found with that id
- # return empty list
- return None
-
- logger.info(f"Deregistered product with identifier '{identifier}'")
+ with structlog.contextvars.bound_contextvars(indentifier=identifier):
+
+ try:
+ logger.info("Deregistering product")
+ product = models.Product.objects.get(identifier=identifier)
+ grids = list(models.Grid.objects.filter(coverage__parent_product=product))
+ product.delete()
+
+ # clean up grids
+ for grid in grids:
+ grid_used = models.EOObject.objects.filter(
+ Q(coverage__grid=grid) | Q(mosaic__grid=grid),
+ ).exists()
+ # clean up grid as well, if it is not referenced
+ # anymore but saving named (user defined) grids
+ if grid and not grid.name and not grid_used:
+ grid.delete()
+ except models.Product.DoesNotExist:
+ logger.info("No product with identifier found")
+ # no product found with that id
+ # return empty list
+ return None
+
+ logger.info("Deregistered product")
# return the deleted identifier
return identifier
diff --git a/registrar/cli.py b/registrar/cli.py
index 208136e..1a98573 100644
--- a/registrar/cli.py
+++ b/registrar/cli.py
@@ -3,6 +3,7 @@ import logging.config
import click
import structlog
+import structlog.contextvars
import yaml
import jsonschema
@@ -45,6 +46,25 @@ def setup_logging(debug=False):
}
)
+ structlog.configure(
+ processors=[
+ structlog.contextvars.merge_contextvars,
+ structlog.stdlib.filter_by_level,
+ structlog.processors.TimeStamper(fmt="iso"),
+ structlog.stdlib.add_logger_name,
+ structlog.stdlib.add_log_level,
+ structlog.stdlib.PositionalArgumentsFormatter(),
+ structlog.processors.StackInfoRenderer(),
+ structlog.processors.format_exc_info,
+ structlog.processors.UnicodeDecoder(),
+ structlog.stdlib.ProcessorFormatter.wrap_for_formatter,
+ ],
+ context_class=structlog.threadlocal.wrap_dict(dict),
+ logger_factory=structlog.stdlib.LoggerFactory(),
+ wrapper_class=structlog.stdlib.BoundLogger,
+ cache_logger_on_first_use=True,
+ )
+
def validate_config(config):
with open(join(dirname(__file__), "config-schema.yaml")) as f:
diff --git a/registrar/daemon.py b/registrar/daemon.py
index 1ee95e6..d0239e5 100644
--- a/registrar/daemon.py
+++ b/registrar/daemon.py
@@ -6,13 +6,13 @@ Contains the daemon functions for the registrar
"""
-import logging
+import structlog
from typing import Callable, Dict
import redis
-logger = logging.getLogger(__name__)
+logger = structlog.getLogger(__name__)
# callback declaration: callable with 'config', item and replace
@@ -52,8 +52,8 @@ def run_daemon(
queue_names = list(handlers.keys())
logger.debug(
f"waiting on items on redis "
- f"queue{'s' if len(queue_names) > 1 else ''} "
- f"{', '.join(queue_names)}..."
+ f"queue{'s' if len(queue_names) > 1 else ''}",
+ queues=queue_names,
)
while True:
diff --git a/registrar/post_handlers.py b/registrar/post_handlers.py
index ab8d1b2..b5da0fd 100644
--- a/registrar/post_handlers.py
+++ b/registrar/post_handlers.py
@@ -8,7 +8,7 @@ Contains different handlers that trigger post registration
import os.path
import textwrap
from datetime import datetime
-import logging
+import structlog
from typing import TYPE_CHECKING
from xml.sax.saxutils import escape
@@ -17,7 +17,7 @@ if TYPE_CHECKING:
from .utils import isoformat
-logger = logging.getLogger(__name__)
+logger = structlog.getLogger(__name__)
class ReportingPostHandler:
@@ -36,7 +36,7 @@ class ReportingPostHandler:
timestamp = inserted.strftime("%Y%m%dT%H%M%S")
sanitized_filename = self.sanitize_path(f"item_{timestamp}_{item.id}.xml")
filename = os.path.join(self.reporting_dir, sanitized_filename)
- logger.info(f"Generating report for product {item.id} at {filename}")
+ logger.info("Generating report", product=item.id, filename=filename)
identifier = escape(item.id)
availability_time = escape(isoformat(inserted))
diff --git a/registrar/registrar.py b/registrar/registrar.py
index a266563..3c94ba8 100644
--- a/registrar/registrar.py
+++ b/registrar/registrar.py
@@ -5,10 +5,11 @@ registrar.py
Contains all functions relevant for registration
"""
-import logging
from typing import Optional
import json
+import structlog
+import structlog.contextvars
from pystac import Item
from .source import get_source, get_source_from_path
@@ -16,7 +17,7 @@ from .backend import get_backends, get_path_backends
from .exceptions import RegistrationError
from .utils import import_by_path
-logger = logging.getLogger(__name__)
+logger = structlog.getLogger(__name__)
def register_item(config: dict, value: str, replace: bool = False):
@@ -33,34 +34,36 @@ def register_item(config: dict, value: str, replace: bool = False):
not turned on
"""
item = Item.from_dict(json.loads(value))
- source = get_source(config, item)
- logger.info(f"Handling '{item!r}'.")
-
- for pre_handler in get_pre_handlers(config):
- pre_handler(config, item)
-
- try:
- for backend in get_backends(config):
- if backend.item_exists(source, item):
- if replace:
- logger.info(f"Replacing '{item!r}'.")
- backend.register_item(source, item, replace=True)
+ with structlog.contextvars.bound_contextvars(item=item):
+ logger.info("Handling item")
+
+ source = get_source(config, item)
+
+ for pre_handler in get_pre_handlers(config):
+ pre_handler(config, item)
+
+ try:
+ for backend in get_backends(config):
+ if backend.item_exists(source, item):
+ if replace:
+ logger.info("Replacing item")
+ backend.register_item(source, item, replace=True)
+ else:
+ raise RegistrationError(f"Object {item!r} is already registered")
else:
- raise RegistrationError(f"Object {item!r} is already registered")
- else:
- logger.info(f"Registering '{item!r}'.")
- backend.register_item(source, item, replace=False)
- except Exception as e:
- for error_handler in get_error_handlers(config):
- error_handler(config, item, e)
- raise
- else:
- for post_handler in get_post_handlers(config):
- post_handler(config, item)
-
- logger.info(
- f"Successfully {'replaced' if replace else 'registered'} " f"'{item!r}'"
- )
+ logger.info("Registering item")
+ backend.register_item(source, item, replace=False)
+ except Exception as e:
+ for error_handler in get_error_handlers(config):
+ error_handler(config, item, e)
+ raise
+ else:
+ for post_handler in get_post_handlers(config):
+ post_handler(config, item)
+
+ logger.info(
+ f"Successfully {'replaced' if replace else 'registered'}"
+ )
def register_path(config: dict, path: str, replace: bool = False):
diff --git a/registrar/source.py b/registrar/source.py
index cc5d96e..c4a68b9 100644
--- a/registrar/source.py
+++ b/registrar/source.py
@@ -11,7 +11,7 @@ from os.path import normpath, join, isabs
import shutil
from glob import glob
from fnmatch import fnmatch
-import logging
+import structlog
from typing import TYPE_CHECKING, Optional
from abc import ABC, abstractmethod
from urllib.parse import urlparse
@@ -29,7 +29,7 @@ if TYPE_CHECKING:
from swiftclient.service import SwiftService
-logger = logging.getLogger(__name__)
+logger = structlog.getLogger(__name__)
class RegistrationError(Exception):
@@ -293,7 +293,7 @@ class S3Source(Source):
glob_patterns = [glob_patterns]
bucket, key = self.get_container_and_path(path)
- logger.info(f"Listing S3 files for bucket {bucket} and prefix {key}")
+ logger.info("Listing S3 files", bucket=bucket, prefix=key)
response = self.client.list_objects_v2(
Bucket=bucket,
Prefix=key,
@@ -312,7 +312,10 @@ class S3Source(Source):
def get_file(self, path: str, target_path: str):
bucket, key = self.get_container_and_path(path)
logger.info(
- f"Retrieving file from S3 {bucket}/{key} to be stored at {target_path}"
+ "Retrieving file from S3",
+ bucket=bucket,
+ key=key,
+ target_path=target_path,
)
self.client.download_file(bucket, key, target_path)
diff --git a/registrar/xml.py b/registrar/xml.py
index e22fc2d..52351e7 100644
--- a/registrar/xml.py
+++ b/registrar/xml.py
@@ -3,7 +3,7 @@ from os.path import join, basename
from tempfile import gettempdir
from dataclasses import dataclass, field
from typing import Optional, Callable, Any
-import logging
+import structlog
import lxml.etree
@@ -11,7 +11,7 @@ from .source import Source
from .exceptions import RegistrationError
-logger = logging.getLogger(__name__)
+logger = structlog.getLogger(__name__)
def read_xml(source: Source, path: str) -> lxml.etree._ElementTree:
--
GitLab