From 7a77cb8444343ae897f580dd65fc487bbebeb63d Mon Sep 17 00:00:00 2001 From: matthewswspence Date: Wed, 4 Sep 2024 12:37:01 -0500 Subject: [PATCH 01/14] initial stab at a new json formatter --- src/registrar/config/settings.py | 43 ++++++++++++++++++++++++++------ 1 file changed, 35 insertions(+), 8 deletions(-) diff --git a/src/registrar/config/settings.py b/src/registrar/config/settings.py index 73aecad7a..016dda4d9 100644 --- a/src/registrar/config/settings.py +++ b/src/registrar/config/settings.py @@ -23,6 +23,8 @@ from cfenv import AppEnv # type: ignore from pathlib import Path from typing import Final from botocore.config import Config +import json +from django.utils.log import ServerFormatter # # # ### # Setup code goes here # @@ -192,7 +194,7 @@ MIDDLEWARE = [ "registrar.registrar_middleware.CheckPortfolioMiddleware", ] -# application object used by Django’s built-in servers (e.g. `runserver`) +# application object used by Django's built-in servers (e.g. `runserver`) WSGI_APPLICATION = "registrar.config.wsgi.application" # endregion @@ -410,7 +412,7 @@ LANGUAGE_COOKIE_SECURE = True # and to interpret datetimes entered in forms TIME_ZONE = "UTC" -# enable Django’s translation system +# enable Django's translation system USE_I18N = True # enable localized formatting of numbers and dates @@ -445,6 +447,30 @@ PHONENUMBER_DEFAULT_REGION = "US" # logger.error("Can't do this important task. Something is very wrong.") # logger.critical("Going to crash now.") +class JsonFormatter(logging.Formatter): + def __init__(self): + super().__init__(datefmt="%d/%b/%Y %H:%M:%S") + + def format(self, record): + log_record = { + "timestamp": self.formatTime(record, self.datefmt), + "level": record.levelname, + "name": record.name, + "lineno": record.lineno, + "message": record.getMessage(), + } + return json.dumps(log_record) + +class JsonServerFormatter(ServerFormatter): + def format(self, record): + formatted_record = super().format(record) + log_entry = { + "server_time": record.server_time, + "level": record.levelname, + "message": formatted_record + } + return json.dumps(log_entry) + LOGGING = { "version": 1, # Don't import Django's existing loggers @@ -459,10 +485,11 @@ LOGGING = { "simple": { "format": "%(levelname)s %(message)s", }, - "django.server": { - "()": "django.utils.log.ServerFormatter", - "format": "[{server_time}] {message}", - "style": "{", + "json.server": { + "()": JsonServerFormatter, + }, + "json": { + "()": JsonFormatter, }, }, # define where log messages will be sent; @@ -471,12 +498,12 @@ LOGGING = { "console": { "level": env_log_level, "class": "logging.StreamHandler", - "formatter": "verbose", + "formatter": "json", }, "django.server": { "level": "INFO", "class": "logging.StreamHandler", - "formatter": "django.server", + "formatter": "json.server", }, # No file logger is configured, # because containerized apps From e2fde1f96808f0c00899e483905e6da4a7ee4dbe Mon Sep 17 00:00:00 2001 From: matthewswspence Date: Wed, 4 Sep 2024 12:59:18 -0500 Subject: [PATCH 02/14] fix imports --- src/registrar/config/settings.py | 1 + 1 file changed, 1 insertion(+) diff --git a/src/registrar/config/settings.py b/src/registrar/config/settings.py index 016dda4d9..0b68a1574 100644 --- a/src/registrar/config/settings.py +++ b/src/registrar/config/settings.py @@ -24,6 +24,7 @@ from pathlib import Path from typing import Final from botocore.config import Config import json +import logging from django.utils.log import ServerFormatter # # # ### From afd941e27ffa7db39cf179255fb25edd5ec7b6c0 Mon Sep 17 00:00:00 2001 From: matthewswspence Date: Wed, 4 Sep 2024 15:26:54 -0500 Subject: [PATCH 03/14] temp: add error message to test logs --- src/registrar/models/domain_request.py | 3 +++ 1 file changed, 3 insertions(+) diff --git a/src/registrar/models/domain_request.py b/src/registrar/models/domain_request.py index b80e063cd..9cee17b18 100644 --- a/src/registrar/models/domain_request.py +++ b/src/registrar/models/domain_request.py @@ -1,4 +1,5 @@ from __future__ import annotations +import traceback from typing import Union import logging from django.apps import apps @@ -644,6 +645,8 @@ class DomainRequest(TimeStampedModel): self.sync_organization_type() self.sync_yes_no_form_fields() + logger.error(traceback.print_stack()) + if self._cached_status != self.status: self.last_status_update = timezone.now().date() From a61e8a16707466afee92af9ac35211f17fc162e2 Mon Sep 17 00:00:00 2001 From: matthewswspence Date: Wed, 4 Sep 2024 15:42:31 -0500 Subject: [PATCH 04/14] more temp changes --- src/registrar/models/domain_request.py | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/src/registrar/models/domain_request.py b/src/registrar/models/domain_request.py index 9cee17b18..f6e215a27 100644 --- a/src/registrar/models/domain_request.py +++ b/src/registrar/models/domain_request.py @@ -644,8 +644,10 @@ class DomainRequest(TimeStampedModel): """Save override for custom properties""" self.sync_organization_type() self.sync_yes_no_form_fields() - - logger.error(traceback.print_stack()) + try: + raise ValueError("TEST TEST TEST") + except Exception as e: + logger.error(e) if self._cached_status != self.status: self.last_status_update = timezone.now().date() From d9898e3af2643985e091f3d72904643749e09458 Mon Sep 17 00:00:00 2001 From: matthewswspence Date: Wed, 4 Sep 2024 15:52:13 -0500 Subject: [PATCH 05/14] moar testing!!! --- src/registrar/models/domain_request.py | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/src/registrar/models/domain_request.py b/src/registrar/models/domain_request.py index f6e215a27..95a20d4cd 100644 --- a/src/registrar/models/domain_request.py +++ b/src/registrar/models/domain_request.py @@ -645,9 +645,9 @@ class DomainRequest(TimeStampedModel): self.sync_organization_type() self.sync_yes_no_form_fields() try: - raise ValueError("TEST TEST TEST") - except Exception as e: - logger.error(e) + raise Exception("TEST TEST TEST") + except Exception: + logger.error(traceback.format_exc) if self._cached_status != self.status: self.last_status_update = timezone.now().date() From bdec43e2f349ac52dbac79ef0abeaf5ebe7ac5d5 Mon Sep 17 00:00:00 2001 From: matthewswspence Date: Wed, 4 Sep 2024 15:57:58 -0500 Subject: [PATCH 06/14] forgot parentheses :( --- src/registrar/models/domain_request.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/registrar/models/domain_request.py b/src/registrar/models/domain_request.py index 95a20d4cd..af8d22b5f 100644 --- a/src/registrar/models/domain_request.py +++ b/src/registrar/models/domain_request.py @@ -647,7 +647,7 @@ class DomainRequest(TimeStampedModel): try: raise Exception("TEST TEST TEST") except Exception: - logger.error(traceback.format_exc) + logger.error(traceback.format_exc()) if self._cached_status != self.status: self.last_status_update = timezone.now().date() From eb3cb1e3d821d7e181c7b32e8784c3715101a633 Mon Sep 17 00:00:00 2001 From: matthewswspence Date: Wed, 11 Sep 2024 10:34:32 -0500 Subject: [PATCH 07/14] Don't use json locally, plus review changes --- src/registrar/config/settings.py | 20 ++------------------ 1 file changed, 2 insertions(+), 18 deletions(-) diff --git a/src/registrar/config/settings.py b/src/registrar/config/settings.py index 0b68a1574..886f2df50 100644 --- a/src/registrar/config/settings.py +++ b/src/registrar/config/settings.py @@ -448,21 +448,8 @@ PHONENUMBER_DEFAULT_REGION = "US" # logger.error("Can't do this important task. Something is very wrong.") # logger.critical("Going to crash now.") -class JsonFormatter(logging.Formatter): - def __init__(self): - super().__init__(datefmt="%d/%b/%Y %H:%M:%S") - - def format(self, record): - log_record = { - "timestamp": self.formatTime(record, self.datefmt), - "level": record.levelname, - "name": record.name, - "lineno": record.lineno, - "message": record.getMessage(), - } - return json.dumps(log_record) - class JsonServerFormatter(ServerFormatter): + """Formats logs into JSON for easier and more accurate processing.""" def format(self, record): formatted_record = super().format(record) log_entry = { @@ -489,9 +476,6 @@ LOGGING = { "json.server": { "()": JsonServerFormatter, }, - "json": { - "()": JsonFormatter, - }, }, # define where log messages will be sent; # each logger can have one or more handlers @@ -499,7 +483,7 @@ LOGGING = { "console": { "level": env_log_level, "class": "logging.StreamHandler", - "formatter": "json", + "formatter": "verbose", }, "django.server": { "level": "INFO", From ed4eeb469f4f7f8c3d8e9b324cb10ab147a9b673 Mon Sep 17 00:00:00 2001 From: matthewswspence Date: Wed, 11 Sep 2024 10:42:26 -0500 Subject: [PATCH 08/14] linter fixes --- src/registrar/config/settings.py | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/src/registrar/config/settings.py b/src/registrar/config/settings.py index 886f2df50..75881ab3f 100644 --- a/src/registrar/config/settings.py +++ b/src/registrar/config/settings.py @@ -24,7 +24,6 @@ from pathlib import Path from typing import Final from botocore.config import Config import json -import logging from django.utils.log import ServerFormatter # # # ### @@ -448,6 +447,7 @@ PHONENUMBER_DEFAULT_REGION = "US" # logger.error("Can't do this important task. Something is very wrong.") # logger.critical("Going to crash now.") + class JsonServerFormatter(ServerFormatter): """Formats logs into JSON for easier and more accurate processing.""" def format(self, record): @@ -459,6 +459,7 @@ class JsonServerFormatter(ServerFormatter): } return json.dumps(log_entry) + LOGGING = { "version": 1, # Don't import Django's existing loggers From 0488b452735bf2de99d9581e9fc1dbceccff17cf Mon Sep 17 00:00:00 2001 From: matthewswspence Date: Wed, 11 Sep 2024 10:49:27 -0500 Subject: [PATCH 09/14] remove test log --- src/registrar/models/domain_request.py | 4 ---- 1 file changed, 4 deletions(-) diff --git a/src/registrar/models/domain_request.py b/src/registrar/models/domain_request.py index af8d22b5f..b4a988165 100644 --- a/src/registrar/models/domain_request.py +++ b/src/registrar/models/domain_request.py @@ -644,10 +644,6 @@ class DomainRequest(TimeStampedModel): """Save override for custom properties""" self.sync_organization_type() self.sync_yes_no_form_fields() - try: - raise Exception("TEST TEST TEST") - except Exception: - logger.error(traceback.format_exc()) if self._cached_status != self.status: self.last_status_update = timezone.now().date() From 635d8480f17a4380abfb2bd3ebc125c90bbe0565 Mon Sep 17 00:00:00 2001 From: matthewswspence Date: Wed, 11 Sep 2024 10:50:10 -0500 Subject: [PATCH 10/14] remove unused import --- src/registrar/models/domain_request.py | 1 - 1 file changed, 1 deletion(-) diff --git a/src/registrar/models/domain_request.py b/src/registrar/models/domain_request.py index b4a988165..b80e063cd 100644 --- a/src/registrar/models/domain_request.py +++ b/src/registrar/models/domain_request.py @@ -1,5 +1,4 @@ from __future__ import annotations -import traceback from typing import Union import logging from django.apps import apps From 180a0240e52d75e359854b2da5d7d3d64dccdd49 Mon Sep 17 00:00:00 2001 From: matthewswspence Date: Wed, 11 Sep 2024 13:09:48 -0500 Subject: [PATCH 11/14] conditionally set log format --- src/registrar/config/settings.py | 39 ++++++++++++++++++++++++++++---- 1 file changed, 35 insertions(+), 4 deletions(-) diff --git a/src/registrar/config/settings.py b/src/registrar/config/settings.py index 75881ab3f..40d4f6933 100644 --- a/src/registrar/config/settings.py +++ b/src/registrar/config/settings.py @@ -24,6 +24,7 @@ from pathlib import Path from typing import Final from botocore.config import Config import json +import logging from django.utils.log import ServerFormatter # # # ### @@ -59,7 +60,7 @@ env_db_url = env.dj_db_url("DATABASE_URL") env_debug = env.bool("DJANGO_DEBUG", default=False) env_is_production = env.bool("IS_PRODUCTION", default=False) env_log_level = env.str("DJANGO_LOG_LEVEL", "DEBUG") -env_base_url = env.str("DJANGO_BASE_URL") +env_base_url: str = env.str("DJANGO_BASE_URL") env_getgov_public_site_url = env.str("GETGOV_PUBLIC_SITE_URL", "") env_oidc_active_provider = env.str("OIDC_ACTIVE_PROVIDER", "identity sandbox") @@ -448,8 +449,24 @@ PHONENUMBER_DEFAULT_REGION = "US" # logger.critical("Going to crash now.") +class JsonFormatter(logging.Formatter): + """Formats logs into JSON for better parsing""" + def __init__(self): + super().__init__(datefmt="%d/%b/%Y %H:%M:%S") + + def format(self, record): + log_record = { + "timestamp": self.formatTime(record, self.datefmt), + "level": record.levelname, + "name": record.name, + "lineno": record.lineno, + "message": record.getMessage(), + } + return json.dumps(log_record) + + class JsonServerFormatter(ServerFormatter): - """Formats logs into JSON for easier and more accurate processing.""" + """Formats server logs into JSON for better parsing""" def format(self, record): formatted_record = super().format(record) log_entry = { @@ -459,6 +476,12 @@ class JsonServerFormatter(ServerFormatter): } return json.dumps(log_entry) +# default to json formatted logs +server_formatter, console_formatter = 'json.server', 'json' + +# don't use json format locally, it makes logs hard to read in console +if "localhost" in env_base_url: + server_formatter, console_formatter = 'django.server', 'verbose' LOGGING = { "version": 1, @@ -474,9 +497,17 @@ LOGGING = { "simple": { "format": "%(levelname)s %(message)s", }, + "django.server": { + "()": "django.utils.log.ServerFormatter", + "format": "[{server_time}] {message}", + "style": "{", + }, "json.server": { "()": JsonServerFormatter, }, + "json": { + "()": JsonFormatter, + }, }, # define where log messages will be sent; # each logger can have one or more handlers @@ -484,12 +515,12 @@ LOGGING = { "console": { "level": env_log_level, "class": "logging.StreamHandler", - "formatter": "verbose", + "formatter": console_formatter, }, "django.server": { "level": "INFO", "class": "logging.StreamHandler", - "formatter": "json.server", + "formatter": server_formatter, }, # No file logger is configured, # because containerized apps From d33f9ae8e2c7a966a7d61230387136eb85352f37 Mon Sep 17 00:00:00 2001 From: matthewswspence Date: Wed, 11 Sep 2024 13:34:19 -0500 Subject: [PATCH 12/14] linter errors --- src/registrar/config/settings.py | 13 ++++++------- 1 file changed, 6 insertions(+), 7 deletions(-) diff --git a/src/registrar/config/settings.py b/src/registrar/config/settings.py index 40d4f6933..b2a65fe23 100644 --- a/src/registrar/config/settings.py +++ b/src/registrar/config/settings.py @@ -451,6 +451,7 @@ PHONENUMBER_DEFAULT_REGION = "US" class JsonFormatter(logging.Formatter): """Formats logs into JSON for better parsing""" + def __init__(self): super().__init__(datefmt="%d/%b/%Y %H:%M:%S") @@ -467,21 +468,19 @@ class JsonFormatter(logging.Formatter): class JsonServerFormatter(ServerFormatter): """Formats server logs into JSON for better parsing""" + def format(self, record): formatted_record = super().format(record) - log_entry = { - "server_time": record.server_time, - "level": record.levelname, - "message": formatted_record - } + log_entry = {"server_time": record.server_time, "level": record.levelname, "message": formatted_record} return json.dumps(log_entry) + # default to json formatted logs -server_formatter, console_formatter = 'json.server', 'json' +server_formatter, console_formatter = "json.server", "json" # don't use json format locally, it makes logs hard to read in console if "localhost" in env_base_url: - server_formatter, console_formatter = 'django.server', 'verbose' + server_formatter, console_formatter = "django.server", "verbose" LOGGING = { "version": 1, From 519ca82ee304cd4486f38a1982c645cb45001bb7 Mon Sep 17 00:00:00 2001 From: matthewswspence Date: Thu, 12 Sep 2024 10:21:30 -0500 Subject: [PATCH 13/14] Remove type checking that was causing linter issues --- src/epplibwrapper/cert.py | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/src/epplibwrapper/cert.py b/src/epplibwrapper/cert.py index 15ff16c06..9abcbee35 100644 --- a/src/epplibwrapper/cert.py +++ b/src/epplibwrapper/cert.py @@ -1,7 +1,7 @@ import os import tempfile -from django.conf import settings +from django.conf import settings # type: ignore class Cert: @@ -12,7 +12,7 @@ class Cert: variable but Python's ssl library requires a file. """ - def __init__(self, data=settings.SECRET_REGISTRY_CERT) -> None: + def __init__(self, data = settings.SECRET_REGISTRY_CERT) -> None: # type: ignore self.filename = self._write(data) def __del__(self): @@ -31,4 +31,4 @@ class Key(Cert): """Location of private key as written to disk.""" def __init__(self) -> None: - super().__init__(data=settings.SECRET_REGISTRY_KEY) + super().__init__(data=settings.SECRET_REGISTRY_KEY) # type: ignore From 529178cd84b272182587620a5b6d8047c4beeeb1 Mon Sep 17 00:00:00 2001 From: matthewswspence Date: Thu, 12 Sep 2024 12:55:12 -0500 Subject: [PATCH 14/14] linter error fixes --- src/epplibwrapper/cert.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/epplibwrapper/cert.py b/src/epplibwrapper/cert.py index 9abcbee35..589736a04 100644 --- a/src/epplibwrapper/cert.py +++ b/src/epplibwrapper/cert.py @@ -12,7 +12,7 @@ class Cert: variable but Python's ssl library requires a file. """ - def __init__(self, data = settings.SECRET_REGISTRY_CERT) -> None: # type: ignore + def __init__(self, data=settings.SECRET_REGISTRY_CERT) -> None: # type: ignore self.filename = self._write(data) def __del__(self):