From 5093fdf623976d4e45e42333a1bef8cda483db62 Mon Sep 17 00:00:00 2001 From: Mackenzie Grimes - NOAA Affiliate Date: Fri, 20 Oct 2023 16:46:28 -0600 Subject: [PATCH] add test_log_util.py --- python/idsse_common/idsse/common/log_util.py | 15 +-- python/idsse_common/test/test_json_message.py | 3 +- python/idsse_common/test/test_log_util.py | 96 +++++++++++++++++++ 3 files changed, 106 insertions(+), 8 deletions(-) create mode 100644 python/idsse_common/test/test_log_util.py diff --git a/python/idsse_common/idsse/common/log_util.py b/python/idsse_common/idsse/common/log_util.py index bbe45f3e..f32211ae 100644 --- a/python/idsse_common/idsse/common/log_util.py +++ b/python/idsse_common/idsse/common/log_util.py @@ -17,7 +17,7 @@ import uuid from contextvars import ContextVar from datetime import datetime -from typing import Union, Optional +from typing import Union, Optional, List from .utils import to_iso @@ -51,21 +51,24 @@ def set_corr_id_context_var( corr_id_context_var.set(f'{originator};{key};_') -def get_corr_id_context_var_str(): +def get_corr_id_context_var_str() -> str: """Getter for correlation ID ContextVar name""" return corr_id_context_var.get() -def get_corr_id_context_var_parts(): +def get_corr_id_context_var_parts() -> List[str]: """Split correlation ID ContextVar into its parts, such as [originator, key, issue_datetime]""" return corr_id_context_var.get().split(';') class AddCorrelationIdFilter(logging.Filter): """"Provides correlation id parameter for the logger""" - def filter(self, record): - record.corr_id = corr_id_context_var.get() - return True + def filter(self, record: logging.LogRecord): + try: + record.corr_id = corr_id_context_var.get() + return True + except (AttributeError, LookupError): + return False class CorrIdFilter(logging.Filter): diff --git a/python/idsse_common/test/test_json_message.py b/python/idsse_common/test/test_json_message.py index 55769cb3..83bb9fa0 100644 --- a/python/idsse_common/test/test_json_message.py +++ b/python/idsse_common/test/test_json_message.py @@ -9,8 +9,7 @@ # Mackenzie Grimes (2) # # ---------------------------------------------------------------------------------- -# pylint: disable=missing-function-docstring,redefined-outer-name,invalid-name,protected-access -# pylint: disable=too-few-public-methods,unused-argument +# pylint: disable=missing-function-docstring import json from datetime import datetime, UTC diff --git a/python/idsse_common/test/test_log_util.py b/python/idsse_common/test/test_log_util.py new file mode 100644 index 00000000..7920d0fb --- /dev/null +++ b/python/idsse_common/test/test_log_util.py @@ -0,0 +1,96 @@ +"""Test suite for json_message.py""" +# ---------------------------------------------------------------------------------- +# Created on Fri Oct 20 2023 +# +# Copyright (c) 2023 Regents of the University of Colorado. All rights reserved. (1) +# Copyright (c) 2023 Colorado State University. All rights reserved. (2) +# +# Contributors: +# Mackenzie Grimes (2) +# +# ---------------------------------------------------------------------------------- +# pylint: disable=missing-function-docstring,redefined-outer-name,invalid-name,unused-argument + +import logging +import logging.config +from datetime import datetime, UTC +from uuid import uuid4 as uuid + +from idsse.common.log_util import ( + set_corr_id_context_var, + get_corr_id_context_var_parts, + get_corr_id_context_var_str, + get_default_log_config, + AddCorrelationIdFilter +) +from idsse.common.utils import to_iso + +logger = logging.getLogger(__name__) + +# test data +EXAMPLE_ORIGINATOR = 'idsse' +EXAMPLE_UUID = uuid() +EXAMPLE_ISSUE_DT = datetime.now(UTC) +EXAMPLE_ISSUE_STR = to_iso(EXAMPLE_ISSUE_DT) +EXAMPLE_LOG_MESSAGE = 'hello world' + + +def test_add_correlation_id_filter(): + filter_object = AddCorrelationIdFilter() + test_record = logging.LogRecord( + name=EXAMPLE_ORIGINATOR, + level=logging.INFO, + pathname='./some/path/to/file.py', + lineno=123, + msg='hello world', + args=None, + exc_info=(None, None, None) + ) + + # corr_id does not exist yet, so filter fails + assert not filter_object.filter(test_record) + + # set corr_id so filter does match + set_corr_id_context_var(EXAMPLE_ORIGINATOR) + assert filter_object.filter(test_record) + + +def test_set_corr_id(): + set_corr_id_context_var(EXAMPLE_ORIGINATOR, EXAMPLE_UUID, EXAMPLE_ISSUE_STR) + + expected_result = [EXAMPLE_ORIGINATOR, str(EXAMPLE_UUID), EXAMPLE_ISSUE_STR] + assert get_corr_id_context_var_parts() == expected_result + assert get_corr_id_context_var_str() == ';'.join(expected_result) + + +def test_set_corr_id_datetime(): + set_corr_id_context_var(EXAMPLE_ORIGINATOR, key=EXAMPLE_UUID, issue_dt=EXAMPLE_ISSUE_DT) + + assert get_corr_id_context_var_parts() == [ + EXAMPLE_ORIGINATOR, str(EXAMPLE_UUID), EXAMPLE_ISSUE_STR + ] + + +def test_get_default_log_config_with_corr_id(capsys): + logging.config.dictConfig(get_default_log_config('INFO')) + corr_id = get_corr_id_context_var_str() + + logger.debug(msg=EXAMPLE_LOG_MESSAGE) + stdout = capsys.readouterr().out # capture std output from test run + + # should not be logging DEBUG if default log config handled level correctly + assert stdout == '' + logger.info(msg=EXAMPLE_LOG_MESSAGE) + stdout = capsys.readouterr().out + + assert EXAMPLE_LOG_MESSAGE in stdout + assert corr_id in stdout + + +def test_get_default_log_config_no_corr_id(capsys): + logging.config.dictConfigClass(get_default_log_config('DEBUG', False)) + corr_id = get_corr_id_context_var_str() + + logger.debug('hello world') + stdout = capsys.readouterr().out + assert corr_id not in stdout