diff --git a/configure.sh b/configure.sh
index a2e8d17ee67b49d525617be89d07afd9c7f1e14a..1b42278b3595f0b383b4e6efbb738f5a9c6bdc7a 100755
--- a/configure.sh
+++ b/configure.sh
@@ -6,6 +6,7 @@
ENABLE_HTTP_ACCESS=${ENABLE_HTTP_ACCESS:="false"}
# Configure instance
sed -e "s/'disable_existing_loggers': True,/'disable_existing_loggers': False,/" -i pvs_instance/settings.py
+ sed -e "s/import os/import os\nimport structlog/" -i pvs_instance/settings.py
HANDLERS="'handlers': {\n
'null': {\n
'level':'DEBUG',\n
@@ -14,7 +15,7 @@
'console': {\n
'level': 'DEBUG' if DEBUG else 'INFO',\n
'class': 'logging.StreamHandler',\n
- 'formatter': 'verbose' if DEBUG else 'simple',\n
+ 'formatter': 'json',\n
'filters': [],\n
},\n
},"
@@ -25,8 +26,15 @@
'propagate': False,\n
},
}"
+ FORMATTERS="'formatters': {\n
+ 'json': {\n
+ '()': structlog.stdlib.ProcessorFormatter,\n
+ 'processor': structlog.dev.ConsoleRenderer() if DEBUG else structlog.processors.JSONRenderer(),
+ },
+ },"
sed -e "/^ 'handlers': {$/,/^ },$/c `echo ${HANDLERS}`" -i pvs_instance/settings.py
sed -e "/^ 'loggers': {$/,/^ }$/c `echo ${LOGGERS}`" -i pvs_instance/settings.py
+ sed -e "/^ 'formatters': {$/,/^ },$/c `echo ${FORMATTERS}`" -i pvs_instance/settings.py
sed -e "s,http_service_url=http://localhost:8000/ows,http_service_url=${APACHE_ALIAS}/ows," -i pvs_instance/conf/eoxserver.conf
sed -e "s/resampling_method=average/resampling_method=near/" -i pvs_instance/conf/eoxserver.conf
diff --git a/gunicorn.conf.py b/gunicorn.conf.py
index 1dcc784778b5a54a47c3d8650fbdcc4859f7ef8a..dd74d2855848ad3d671b69b64c0c729ccfe59a32 100644
--- a/gunicorn.conf.py
+++ b/gunicorn.conf.py
@@ -11,6 +11,12 @@ worker_class = 'sync'
# logging
accesslog = '-'
+access_log_format = '{"remote_address":"%(h)s",' \
+ '"response_code":"%(s)s","request_method":"%(m)s",' \
+ '"request_path":"%(U)s","request_querystring":"%(q)s",' \
+ '"request_time":"%(M)s","response_length":"%(B)s",' \
+ '"user":"%(u)s","status_line":"%(r)s","referer":"%(r)s",' \
+ '"user_agent":"%(a)s"}'
errorlog = '-'
loglevel = 'warning'
disable_redirect_access_to_syslog = True
diff --git a/registrar/backend/eoxserver.py b/registrar/backend/eoxserver.py
index 2a1f0aad1c79ef57b9075416e55965c5bdaa61e1..08c652f90561e558037a519605bbde6c4b97c330 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("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 edfd96e66b67feae55f6aab6b789c6f88439eec7..98698477092da4b3a9eb0911df8229b7bf0e175e 100644
--- a/registrar/cli.py
+++ b/registrar/cli.py
@@ -2,6 +2,8 @@ from os.path import join, dirname
import logging.config
import click
+import structlog
+import structlog.contextvars
import yaml
import jsonschema
@@ -22,13 +24,20 @@ def setup_logging(debug=False):
{
"version": 1,
"disable_existing_loggers": False,
- "formatters": {"brief": {"format": "%(levelname)s %(name)s: %(message)s"}},
+ "formatters": {
+ "json": {
+ "()": structlog.stdlib.ProcessorFormatter,
+ "processor": structlog.dev.ConsoleRenderer()
+ if debug
+ else structlog.processors.JSONRenderer(),
+ },
+ },
"handlers": {
"console": {
"class": "logging.StreamHandler",
"level": "DEBUG" if debug else "INFO",
- "formatter": "brief",
- }
+ "formatter": "json",
+ },
},
"root": {
"handlers": ["console"],
@@ -37,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 1ee95e616e7061579a4da33d0aea0cc7c19532a8..d0239e508451e2852fb9c3369a64507d1ee30270 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 ab8d1b258e813e1ec8b4c55c7a8efec3cad8dfa0..b5da0fd99865716a083101db8e9c0e828c451279 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 a266563f958f8f723e0577ee0bdcae1b8264554a..3c94ba8524d9c04b1226e83b1b08be63da80e298 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 cc5d96e507ab160117339b98f34a1a888ce58a40..c4a68b9bd7c995a6ea9298735b701438c1113b36 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 e22fc2ddfc6da59aaebec6b97a93ef8e393435cf..52351e79d88d200f3ee6acd18e0c055137525d9c 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:
diff --git a/requirements.txt b/requirements.txt
index 643596764c373cac4bb97e2e6587980f9c321854..14305ff0fcd9715337d2b6ab4a90e16a9130aab1 100644
--- a/requirements.txt
+++ b/requirements.txt
@@ -6,5 +6,6 @@ pyyaml<6.0
jsonschema<5.0
boto3<2.0
django-cors-headers<4.0
+django-structlog==2.2.0
pystac<2.0
http-access==0.1.3