From 07c087765df66a114f81d6e85b9df55a2c747444 Mon Sep 17 00:00:00 2001 From: Brian Summa Date: Mon, 19 May 2025 17:55:02 -0500 Subject: [PATCH] feat(logging): Implement centralized logging with loguru Add centralized logger configuration in _logger.py that: - Configures loguru as the logging system for the entire codebase - Removes default handlers and configures a stderr handler - Respects LOGURU_LEVEL environment variable with default level "INFO" - Standardizes logging across modules Replace print statements with structured logging in the Spec class: - Log request URLs at debug level with proper formatting - Log response data at debug level for successful requests - Update imports in affected modules to use the central logger Tests: - Added test_logger.py to verify core logger configuration - Added test_base_spec_logging.py to test logging in Spec base class - Added test_imports.py to verify correct logger imports - Added test_logger_integration.py for end-to-end tests This change improves debugging capabilities and provides a consistent approach to logging throughout the codebase. --- pythonik/_logger.py | 18 ++++ pythonik/specs/base.py | 5 +- pythonik/specs/metadata.py | 2 +- pythonik/tests/test_base_spec_logging.py | 74 +++++++++++++ pythonik/tests/test_imports.py | 60 +++++++++++ pythonik/tests/test_logger.py | 60 +++++++++++ pythonik/tests/test_logger_integration.py | 122 ++++++++++++++++++++++ pythonik/tests/test_metadata.py | 2 +- 8 files changed, 339 insertions(+), 4 deletions(-) create mode 100644 pythonik/_logger.py create mode 100644 pythonik/tests/test_base_spec_logging.py create mode 100644 pythonik/tests/test_imports.py create mode 100644 pythonik/tests/test_logger.py create mode 100644 pythonik/tests/test_logger_integration.py diff --git a/pythonik/_logger.py b/pythonik/_logger.py new file mode 100644 index 0000000..d9cd439 --- /dev/null +++ b/pythonik/_logger.py @@ -0,0 +1,18 @@ +import sys + +from loguru import ( + _defaults, + logger, +) + +__all__ = ["logger"] + +# Default values +DEFAULT_LOGURU_LEVEL = "INFO" + +# Safely remove the default handler +logger.remove() + +# Configure handler with LOGURU_LEVEL from environment or fallback to default +logger.add(sys.stderr, + level=_defaults.env("LOGURU_LEVEL", str, DEFAULT_LOGURU_LEVEL)) diff --git a/pythonik/specs/base.py b/pythonik/specs/base.py index de7b35b..8f24e95 100644 --- a/pythonik/specs/base.py +++ b/pythonik/specs/base.py @@ -1,3 +1,4 @@ +from pythonik._logger import logger from urllib.parse import urljoin from typing import Union, Type, Dict, Any, Optional @@ -48,7 +49,7 @@ def parse_response(response: Response, model: Optional[Type[BaseModel]] = None) """ # try to populate the model if response.ok: - print(response.text) + logger.debug(response.text) if model: data = response.json() model_instance = model.model_validate(data) @@ -68,7 +69,7 @@ def send_request(self, method, path, **kwargs) -> Response: """ url = self.gen_url(path) - print(url) + logger.debug("Sending {} request to {}", method, url) request = Request( method=method, url=url, headers=self.session.headers, **kwargs ) diff --git a/pythonik/specs/metadata.py b/pythonik/specs/metadata.py index 6c12b28..cfd1225 100644 --- a/pythonik/specs/metadata.py +++ b/pythonik/specs/metadata.py @@ -1,4 +1,4 @@ -from loguru import logger +from pythonik._logger import logger from pythonik.models.base import Response from pythonik.models.metadata.views import ( ViewMetadata, diff --git a/pythonik/tests/test_base_spec_logging.py b/pythonik/tests/test_base_spec_logging.py new file mode 100644 index 0000000..fcd713e --- /dev/null +++ b/pythonik/tests/test_base_spec_logging.py @@ -0,0 +1,74 @@ +# pythonik/tests/test_base_spec_logging.py +"""Tests for logging functionality in Spec base class.""" + +import unittest +from unittest.mock import ( + MagicMock, + call, + patch, +) + +from pythonik.specs.base import Spec + + +class TestBaseSpecLogging(unittest.TestCase): + """Test suite for the logging functionality in the Spec base class.""" + + def setUp(self): + """Set up test fixtures.""" + self.session = MagicMock() + self.spec = Spec(self.session, + timeout=5, + base_url="https://test.iconik.io") + + @patch("pythonik._logger.logger.debug") + def test_send_request_logs_url(self, mock_debug): + """Test that send_request logs the URL being requested.""" + # Mock the prepare_request and send methods + self.session.prepare_request.return_value = MagicMock() + self.session.send.return_value = MagicMock() + + # Call send_request + self.spec.send_request("GET", "test/path") + + # Verify debug was called with URL info + expected_call = call( + "Sending {} request to {}", + "GET", + "https://test.iconik.io/v1/test/path", + ) + self.assertEqual(mock_debug.call_args, expected_call) + + @patch("pythonik._logger.logger.debug") + def test_parse_response_logs_response_text(self, mock_debug): + """Test that parse_response logs the response text for successful responses.""" + # Create a mock response with ok=True + mock_response = MagicMock() + mock_response.ok = True + mock_response.text = '{"key": "value"}' + mock_response.json.return_value = {"key": "value"} + + # Call parse_response with a mock model + mock_model = MagicMock() + mock_model.model_validate.return_value = "model_instance" + self.spec.parse_response(mock_response, mock_model) + + # Verify debug was called with response text + mock_debug.assert_called_once_with(mock_response.text) + + @patch("pythonik._logger.logger.debug") + def test_parse_response_no_logging_for_failed_responses(self, mock_debug): + """Test that parse_response doesn't log for failed responses.""" + # Create a mock response with ok=False + mock_response = MagicMock() + mock_response.ok = False + + # Call parse_response + self.spec.parse_response(mock_response, MagicMock()) + + # Verify debug was not called + mock_debug.assert_not_called() + + +if __name__ == "__main__": + unittest.main() diff --git a/pythonik/tests/test_imports.py b/pythonik/tests/test_imports.py new file mode 100644 index 0000000..e804e8b --- /dev/null +++ b/pythonik/tests/test_imports.py @@ -0,0 +1,60 @@ +# pythonik/tests/test_imports.py +"""Tests to verify the correct logger imports in different modules.""" + +import unittest + + +class TestLoggerImports(unittest.TestCase): + """Test suite for verifying logger imports in various modules.""" + + def test_specs_base_imports_logger(self): + """Test that specs/base.py imports logger from the central module.""" + # First ensure our module is imported + import pythonik.specs.base + + # Check if the specs.base module imports from _logger + source = inspect_imports(pythonik.specs.base) + self.assertIn("from pythonik._logger import logger", source) + + def test_specs_metadata_imports_logger(self): + """Test that specs/metadata.py imports logger from the central module.""" + # First ensure our module is imported + import pythonik.specs.metadata + + # Check if the specs.metadata module imports from _logger + source = inspect_imports(pythonik.specs.metadata) + self.assertIn("from pythonik._logger import logger", source) + self.assertNotIn("from loguru import logger", source) + + def test_tests_metadata_imports_logger(self): + """Test that tests/test_metadata.py imports logger from the central module.""" + # First ensure our module is imported + import pythonik.tests.test_metadata + + # Check if the test_metadata module imports from _logger + source = inspect_imports(pythonik.tests.test_metadata) + self.assertIn("from pythonik._logger import logger", source) + self.assertNotIn("from loguru import logger", source) + + +def inspect_imports(module): + """ + Helper function to extract import statements from a module's source code. + + Args: + module: The module to inspect + + Returns: + str: The source code of the module + """ + try: + # Get the source of the module + import inspect + + return inspect.getsource(module) + except (TypeError, IOError): + return "" + + +if __name__ == "__main__": + unittest.main() diff --git a/pythonik/tests/test_logger.py b/pythonik/tests/test_logger.py new file mode 100644 index 0000000..a5e6936 --- /dev/null +++ b/pythonik/tests/test_logger.py @@ -0,0 +1,60 @@ +# pythonik/tests/test_logger.py +"""Tests for the centralized logger configuration.""" + +import os +import sys +import unittest +from unittest.mock import patch + +from pythonik._logger import logger + + +class TestLogger(unittest.TestCase): + """Test suite for the logger configuration.""" + + def test_logger_initialization(self): + """Test that the logger is correctly initialized.""" + # Check that the logger is a Loguru instance + self.assertEqual(str(type(logger).__module__), "loguru._logger") + + @patch.dict(os.environ, {}, clear=True) + @patch("loguru._defaults.env") + def test_default_log_level(self, mock_env): + """Test that the default log level is INFO when not specified.""" + # Mock the env function to simulate no environment variable + mock_env.return_value = "INFO" + + # Re-import to trigger logger configuration + import importlib + + importlib.reload(sys.modules["pythonik._logger"]) + + # Verify that env was called with the correct arguments + mock_env.assert_called_with("LOGURU_LEVEL", str, "INFO") + + @patch.dict(os.environ, {"LOGURU_LEVEL": "DEBUG"}) + @patch("loguru.logger.add") + def test_custom_log_level(self, mock_add): + """Test that the logger respects LOGURU_LEVEL environment variable.""" + # Re-import to trigger logger configuration with patched env + import importlib + + importlib.reload(sys.modules["pythonik._logger"]) + + # Verify that add was called with correct level + mock_add.assert_called_once() + _, kwargs = mock_add.call_args + self.assertEqual(kwargs.get("level"), "DEBUG") + + @patch("loguru.logger.debug") + def test_logger_output(self, mock_debug): + """Test that the logger outputs messages correctly.""" + # Log a message + logger.debug("Test message") + + # Verify that the debug method was called with the right message + mock_debug.assert_called_once_with("Test message") + + +if __name__ == "__main__": + unittest.main() diff --git a/pythonik/tests/test_logger_integration.py b/pythonik/tests/test_logger_integration.py new file mode 100644 index 0000000..e10aa16 --- /dev/null +++ b/pythonik/tests/test_logger_integration.py @@ -0,0 +1,122 @@ +# pythonik/tests/test_logger_integration.py +"""Tests for the integration of the logger in the Pythonik codebase.""" + +import importlib +import os +import tempfile +import unittest +from unittest.mock import ( + MagicMock, + patch, +) + +from pythonik._logger import logger +from pythonik.client import PythonikClient + + +class TestLoggerIntegration(unittest.TestCase): + """Test suite for logger integration in Pythonik client classes.""" + + def setUp(self): + """Set up test fixtures.""" + self.app_id = "test_app_id" + self.auth_token = "test_auth_token" + self.client = PythonikClient(app_id=self.app_id, + auth_token=self.auth_token, + timeout=3) + + @patch("requests.Session.send") + @patch("pythonik._logger.logger.debug") + def test_logs_in_api_calls(self, mock_debug, mock_send): + """Test that API calls log using the centralized logger.""" + # Setup mock response + mock_response = MagicMock() + mock_response.ok = True + mock_response.text = '{"id": "test-id"}' + mock_response.json.return_value = {"id": "test-id"} + mock_send.return_value = mock_response + + # Make API call + self.client.assets().get(asset_id="test-id") + + # Verify debug logs + self.assertGreaterEqual(mock_debug.call_count, 1) + # Look for specific log messages we expect + url_log_found = False + response_log_found = False + for call_args in mock_debug.call_args_list: + args, _ = call_args + if len(args) > 1 and args[0] == "Sending {} request to {}": + url_log_found = True + if args and '{"id": "test-id"}' in str(args): + response_log_found = True + + self.assertTrue(url_log_found, "URL log message not found") + self.assertTrue(response_log_found, "Response log message not found") + + @patch.dict(os.environ, {"LOGURU_LEVEL": "DEBUG"}) + def test_environment_var_affects_logger(self): + """Test that LOGURU_LEVEL environment variable affects the logger.""" + # Reload _logger module to pick up env var change + import pythonik._logger + + importlib.reload(pythonik._logger) + + # Setup a temp file for log output to verify level + temp_log = tempfile.NamedTemporaryFile(delete=False) + try: + # Add a handler to write to our temp file + log_id = logger.add(temp_log.name, level="DEBUG") + + # Log messages at different levels + logger.debug("Debug message") + logger.info("Info message") + logger.warning("Warning message") + + # Remove our handler + logger.remove(log_id) + + # Check log contents + with open(temp_log.name, "r") as f: + log_content = f.read() + + # Debug should be logged since LOGURU_LEVEL is set to DEBUG + self.assertIn("Debug message", log_content) + self.assertIn("Info message", log_content) + self.assertIn("Warning message", log_content) + finally: + # Clean up + os.unlink(temp_log.name) + + @patch("pythonik._logger.logger.debug") + def test_request_payload_logging(self, mock_debug): + """Test that request payloads are logged when making API calls.""" + with patch("requests.Session.send") as mock_send: + # Setup mock response + mock_response = MagicMock() + mock_response.ok = True + mock_response.json.return_value = {} + mock_send.return_value = mock_response + + # Make API call with a payload + from pythonik.models.assets.assets import AssetCreate + + asset = AssetCreate(title="Test Asset") + self.client.assets().create(body=asset) + + # Verify we log the URL properly + url_log_call = None + for call_args in mock_debug.call_args_list: + args, _ = call_args + if len(args) > 1 and args[0] == "Sending {} request to {}": + url_log_call = call_args + break + + self.assertIsNotNone(url_log_call, "URL log not found") + args, _ = url_log_call + self.assertEqual(args[1], "POST") # Should be a POST request + self.assertIn("assets", args[2]) # URL should contain 'assets' + + +if __name__ == "__main__": + unittest.main() diff --git a/pythonik/tests/test_metadata.py b/pythonik/tests/test_metadata.py index 8b541e2..1b612dc 100644 --- a/pythonik/tests/test_metadata.py +++ b/pythonik/tests/test_metadata.py @@ -3,7 +3,7 @@ from pythonik.client import PythonikClient from requests import HTTPError from pythonik.models.base import ObjectType -from loguru import logger +from pythonik._logger import logger import json from pythonik.models.metadata.views import (