File size: 9,839 Bytes
6613cd9
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
fdc056d
6613cd9
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
"""Tests for structured logger functionality."""

import pytest
import json
import logging
from unittest.mock import Mock, patch

from src.application.error_handling.structured_logger import (
    StructuredLogger, LogContext, JsonFormatter, ContextFormatter,
    get_structured_logger, set_correlation_id, get_correlation_id,
    generate_correlation_id
)


class TestLogContext:
    """Test cases for LogContext."""

    def test_log_context_creation(self):
        """Test creating log context."""
        context = LogContext(
            correlation_id="test-123",
            operation="test_operation",
            component="test_component"
        )

        assert context.correlation_id == "test-123"
        assert context.operation == "test_operation"
        assert context.component == "test_component"

    def test_log_context_to_dict(self):
        """Test converting log context to dictionary."""
        context = LogContext(
            correlation_id="test-123",
            operation="test_operation",
            metadata={"key": "value"}
        )

        context_dict = context.to_dict()

        assert context_dict["correlation_id"] == "test-123"
        assert context_dict["operation"] == "test_operation"
        assert context_dict["metadata"] == {"key": "value"}
        assert "user_id" not in context_dict  # None values should be excluded


class TestStructuredLogger:
    """Test cases for StructuredLogger."""

    def setup_method(self):
        """Set up test fixtures."""
        self.logger = StructuredLogger("test_logger", enable_json_logging=False)

    def test_logger_creation(self):
        """Test creating structured logger."""
        assert self.logger.logger.name == "test_logger"
        assert not self.logger.enable_json_logging

    def test_debug_logging(self):
        """Test debug logging."""
        context = LogContext(correlation_id="test-123", operation="test_op")

        with patch.object(self.logger.logger, 'debug') as mock_debug:
            self.logger.info("Test debug message", context=context)

            mock_debug.assert_called_once()
            args, kwargs = mock_debug.call_args
            assert "Test debug message" in args[0]
            assert "extra" in kwargs

    def test_info_logging(self):
        """Test info logging."""
        context = LogContext(correlation_id="test-123")
        extra = {"key": "value"}

        with patch.object(self.logger.logger, 'info') as mock_info:
            self.logger.info("Test info message", context=context, extra=extra)

            mock_info.assert_called_once()
            args, kwargs = mock_info.call_args
            assert "Test info message" in args[0]
            assert kwargs["extra"]["extra"] == extra

    def test_error_logging_with_exception(self):
        """Test error logging with exception."""
        context = LogContext(correlation_id="test-123")
        exception = ValueError("Test error")

        with patch.object(self.logger.logger, 'error') as mock_error:
            self.logger.error("Test error message", context=context, exception=exception)

            mock_error.assert_called_once()
            args, kwargs = mock_error.call_args
            assert "Test error message" in args[0]
            assert kwargs["extra"]["exception"]["type"] == "ValueError"
            assert kwargs["extra"]["exception"]["message"] == "Test error"

    def test_log_operation_start(self):
        """Test logging operation start."""
        extra = {"param": "value"}

        with patch.object(self.logger.logger, 'info') as mock_info:
            correlation_id = self.logger.log_operation_start("test_operation", extra=extra)

            assert correlation_id is not None
            mock_info.assert_called_once()
            args, kwargs = mock_info.call_args
            assert "Operation started: test_operation" in args[0]

    def test_log_operation_end_success(self):
        """Test logging successful operation end."""
        correlation_id = "test-123"

        with patch.object(self.logger.logger, 'info') as mock_info:
            self.logger.log_operation_end(
                "test_operation",
                correlation_id,
                success=True,
                duration=1.5
            )

            mock_info.assert_called_once()
            args, kwargs = mock_info.call_args
            assert "completed successfully" in args[0]
            assert kwargs["extra"]["extra"]["success"] is True
            assert kwargs["extra"]["extra"]["duration_seconds"] == 1.5

    def test_log_operation_end_failure(self):
        """Test logging failed operation end."""
        correlation_id = "test-123"

        with patch.object(self.logger.logger, 'error') as mock_error:
            self.logger.log_operation_end(
                "test_operation",
                correlation_id,
                success=False
            )

            mock_error.assert_called_once()
            args, kwargs = mock_error.call_args
            assert "failed" in args[0]
            assert kwargs["extra"]["extra"]["success"] is False

    def test_log_performance_metric(self):
        """Test logging performance metric."""
        context = LogContext(correlation_id="test-123")

        with patch.object(self.logger.logger, 'info') as mock_info:
            self.logger.log_performance_metric(
                "response_time",
                150.5,
                "ms",
                context=context
            )

            mock_info.assert_called_once()
            args, kwargs = mock_info.call_args
            assert "Performance metric: response_time=150.5 ms" in args[0]
            assert kwargs["extra"]["extra"]["metric"]["name"] == "response_time"
            assert kwargs["extra"]["extra"]["metric"]["value"] == 150.5
            assert kwargs["extra"]["extra"]["metric"]["unit"] == "ms"


class TestJsonFormatter:
    """Test cases for JsonFormatter."""

    def setup_method(self):
        """Set up test fixtures."""
        self.formatter = JsonFormatter()

    def test_format_log_record(self):
        """Test formatting log record as JSON."""
        record = logging.LogRecord(
            name="test_logger",
            level=logging.INFO,
            pathname="test.py",
            lineno=10,
            msg="Test message",
            args=(),
            exc_info=None
        )

        # Add extra data
        record.extra = {
            "correlation_id": "test-123",
            "operation": "test_op"
        }

        formatted = self.formatter.format(record)

        # Should be valid JSON
        log_data = json.loads(formatted)
        assert log_data["message"] == "Test message"
        assert log_data["level"] == "INFO"
        assert log_data["correlation_id"] == "test-123"
        assert log_data["operation"] == "test_op"

    def test_format_error_handling(self):
        """Test formatter error handling."""
        record = logging.LogRecord(
            name="test_logger",
            level=logging.INFO,
            pathname="test.py",
            lineno=10,
            msg="Test message",
            args=(),
            exc_info=None
        )

        # Add problematic extra data that can't be JSON serialized
        record.extra = {
            "correlation_id": "test-123",
            "problematic_data": object()  # Can't be JSON serialized
        }

        formatted = self.formatter.format(record)

        # Should still work and include error message
        assert "Test message" in formatted


class TestContextFormatter:
    """Test cases for ContextFormatter."""

    def setup_method(self):
        """Set up test fixtures."""
        self.formatter = ContextFormatter()

    def test_format_with_correlation_id(self):
        """Test formatting with correlation ID."""
        record = logging.LogRecord(
            name="test_logger",
            level=logging.INFO,
            pathname="test.py",
            lineno=10,
            msg="Test message",
            args=(),
            exc_info=None
        )

        record.extra = {"correlation_id": "test-123"}

        formatted = self.formatter.format(record)

        assert "[test-123]" in formatted
        assert "Test message" in formatted

    def test_format_with_operation(self):
        """Test formatting with operation context."""
        record = logging.LogRecord(
            name="test_logger",
            level=logging.INFO,
            pathname="test.py",
            lineno=10,
            msg="Test message",
            args=(),
            exc_info=None
        )

        record.extra = {
            "correlation_id": "test-123",
            "operation": "test_operation"
        }

        formatted = self.formatter.format(record)

        assert "[test_operation]" in formatted
        assert "Test message" in formatted


class TestUtilityFunctions:
    """Test cases for utility functions."""

    def test_get_structured_logger(self):
        """Test getting structured logger."""
        logger = get_structured_logger("test_logger")

        assert isinstance(logger, StructuredLogger)
        assert logger.logger.name == "test_logger"

    def test_correlation_id_context(self):
        """Test correlation ID context management."""
        # Initially should be None
        assert get_correlation_id() is None

        # Set correlation ID
        set_correlation_id("test-123")
        assert get_correlation_id() == "test-123"

    def test_generate_correlation_id(self):
        """Test generating correlation ID."""
        correlation_id = generate_correlation_id()

        assert correlation_id is not None
        assert len(correlation_id) > 0

        # Should generate different IDs
        another_id = generate_correlation_id()
        assert correlation_id != another_id