Merge pull request #49 from NYPL/main

Merging to prod

Author: yossariano

CHANGELOG.md

@@ -1,4 +1,7 @@
 # Changelog
+## v1.8.0 8/19/25
+- Add optional JSON structured logging
+
 ## v1.7.0 6/13/25
 - Use fastavro for avro encoding/decoding
 

pyproject.toml

@@ -4,7 +4,7 @@ build-backend = "hatchling.build"
 
 [project]
 name = "nypl_py_utils"
-version = "1.7.0"
+version = "1.8.0"
 authors = [
   { name="Aaron Friedman", email="aaronfriedman@nypl.org" },
 ]
@@ -38,6 +38,9 @@ kms-client = [
     "boto3>=1.26.5",
     "botocore>=1.29.5"
 ]
+log_helper = [
+    "structlog>=25.4.0"
+]
 mysql-client = [
     "mysql-connector-python>=8.0.32"
 ]
@@ -78,7 +81,7 @@ research-catalog-identifier-helper = [
     "requests>=2.28.1"
 ]
 development = [
-    "nypl_py_utils[avro-client,kinesis-client,kms-client,mysql-client,oauth2-api-client,postgresql-client,redshift-client,s3-client,secrets-manager-client,sftp-client,config-helper,obfuscation-helper,patron-data-helper,research-catalog-identifier-helper]",
+    "nypl_py_utils[avro-client,kinesis-client,kms-client,mysql-client,oauth2-api-client,postgresql-client,redshift-client,s3-client,secrets-manager-client,sftp-client,config-helper,obfuscation-helper,patron-data-helper,research-catalog-identifier-helper,log_helper]",
     "flake8>=6.0.0",
     "freezegun>=1.2.2",
     "mock>=4.0.3",

src/nypl_py_utils/functions/log_helper.py

@@ -1,3 +1,5 @@
+import structlog
+
 import logging
 import os
 import sys
@@ -11,7 +13,31 @@
 }
 
 
-def create_log(module):
+# Configure structlog to be machine-readable first and foremost
+# while still making it easy for humans to parse
+# End result (without additional bindings) is JSON like this:
+#
+# { "logger": "module param"
+#   "message": "this is a test log event",
+#  "level": "info",
+#  "timestamp": "2023-11-01 18:50:47"}
+#
+def get_structlog(module):
+    structlog.configure(
+        processors=[
+            structlog.processors.add_log_level,
+            structlog.processors.TimeStamper(fmt="iso"),
+            structlog.processors.EventRenamer("message"),
+            structlog.processors.JSONRenderer(),
+        ],
+        context_class=dict,
+        logger_factory=structlog.PrintLoggerFactory(),
+    )
+
+    return structlog.get_logger(module)
+
+
+def standard_logger(module):
     logger = logging.getLogger(module)
     if logger.hasHandlers():
         logger.handlers = []
@@ -28,5 +54,11 @@ def create_log(module):
     console_log.setFormatter(formatter)
 
     logger.addHandler(console_log)
-
     return logger
+
+
+def create_log(module, json=False):
+    if (json):
+        return get_structlog(module)
+    else:
+        return standard_logger(module)

tests/test_log_helper.py

@@ -1,13 +1,23 @@
+import json
 import logging
 import os
 import time
 
 from freezegun import freeze_time
+
 from nypl_py_utils.functions.log_helper import create_log
 
 
 @freeze_time('2023-01-01 19:00:00')
 class TestLogHelper:
+    def test_json_logging(self, capsys):
+        logger = create_log('test_log', json=True)
+        logger.info('test', some="json")
+        output = json.loads(capsys.readouterr().out)
+        assert output.get("message") == 'test'
+        assert output.get("some") == 'json'
+        assert output.get('level') == 'info'
+        assert output.get('timestamp') == '2023-01-01T19:00:00Z'
 
     def test_default_logging(self, caplog):
         logger = create_log('test_log')

tests/test_oauth2_api_client.py

@@ -2,6 +2,7 @@
 import time
 import json
 import pytest
+from oauthlib.oauth2 import OAuth2Token
 from requests_oauthlib import OAuth2Session
 from requests import HTTPError, JSONDecodeError, Response
 
@@ -110,7 +111,7 @@ def test_token_expiration(self, requests_mock, test_instance,
             .headers['Authorization'] == 'Bearer super-secret-token'
 
         # The token obtained above expires in 1s, so wait out expiration:
-        time.sleep(1.1)
+        time.sleep(2)
 
         # Register new token response:
         second_token_response = dict(_TOKEN_RESPONSE)
@@ -138,7 +139,7 @@ def test_error_status_raises_error(self, requests_mock, test_instance,
             test_instance._do_http_method('GET', 'foo')
 
     def test_token_refresh_failure_raises_error(
-            self, requests_mock, test_instance, token_server_post):
+            self, requests_mock, test_instance, token_server_post, mocker):
         """
         Failure to fetch a token can raise a number of errors including:
          - requests.exceptions.HTTPError for invalid access_token
@@ -150,12 +151,25 @@ def test_token_refresh_failure_raises_error(
         a new valid token in response to token expiration. This test asserts
         that the client will not allow more than successive 3 retries.
         """
-        requests_mock.get(f'{BASE_URL}/foo', json={'foo': 'bar'})
+        test_instance._create_oauth_client()
+
+        def set_token(*args, scope):
+            test_instance.oauth_client.token = OAuth2Token(
+                json.loads(args[0]))
+            test_instance.oauth_client._client.populate_token_attributes(
+                json.loads(args[0]))
 
+        requests_mock.get(f'{BASE_URL}/foo', json={'foo': 'bar'})
         token_response = dict(_TOKEN_RESPONSE)
-        token_response['expires_in'] = 0
-        token_server_post = requests_mock\
-            .post(TOKEN_URL, text=json.dumps(token_response))
+        token_response["expires_in"] = 0
+        token_response["expires_at"] = 1000000000
+        token_server_post = requests_mock.post(
+            TOKEN_URL, text=json.dumps(token_response))
+
+        test_instance.oauth_client._client.parse_request_body_response = (
+            mocker.MagicMock(name="method", side_effect=set_token)
+        )
+        test_instance._generate_access_token()
 
         with pytest.raises(Oauth2ApiClientError):
             test_instance._do_http_method('GET', 'foo')