File size: 9,991 Bytes
a5784e9
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
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
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
# -*- coding: utf-8 -*-
"""
Tests for JSONFormatter in logging_utils/core/rendering.py

Coverage target: 80%+
"""

import json
import logging

import pytest

from logging_utils.core.rendering import JSONFormatter


class TestJSONFormatter:
    """Tests for JSONFormatter class."""

    @pytest.fixture(autouse=True)
    def clean_context(self):
        """Clear context variables before each test to prevent leakage."""
        from logging_utils.core.context import request_id_var, source_var

        # Get tokens for any existing values and reset them
        try:
            _old_req_id = request_id_var.get()
            token1 = request_id_var.set("")
        except LookupError:
            token1 = None

        try:
            _old_source = source_var.get()
            token2 = source_var.set("SYS")
        except LookupError:
            token2 = None

        yield

        # Cleanup
        if token1:
            request_id_var.reset(token1)
        if token2:
            source_var.reset(token2)

    @pytest.fixture
    def formatter(self):
        """Create JSONFormatter instance."""
        return JSONFormatter()

    @pytest.fixture
    def sample_record(self):
        """Create a sample log record."""
        record = logging.LogRecord(
            name="test_logger",
            level=logging.INFO,
            pathname="/test/path.py",
            lineno=42,
            msg="Test message",
            args=(),
            exc_info=None,
        )
        return record

    def test_format_basic_record(self, formatter, sample_record):
        """Test formatting a basic log record."""
        output = formatter.format(sample_record)

        # Should be valid JSON
        parsed = json.loads(output)

        assert "timestamp" in parsed
        assert parsed["level"] == "INFO"
        assert parsed["message"] == "Test message"
        assert parsed["logger"] == "test_logger"
        assert "source" in parsed  # Default source

    def test_format_with_request_id_context(self, formatter, sample_record):
        """Test formatting includes request_id from context."""
        from logging_utils.core.context import request_id_var

        token = request_id_var.set("req12345")
        try:
            output = formatter.format(sample_record)
            parsed = json.loads(output)

            assert parsed["request_id"] == "req12345"
        finally:
            request_id_var.reset(token)

    def test_format_with_source_context(self, formatter, sample_record):
        """Test formatting includes source from context."""
        from logging_utils.core.context import source_var

        token = source_var.set("API")
        try:
            output = formatter.format(sample_record)
            parsed = json.loads(output)

            assert "API" in parsed["source"]
        finally:
            source_var.reset(token)

    def test_format_without_context(self, formatter, sample_record):
        """Test formatting works without context variables set."""
        output = formatter.format(sample_record)
        parsed = json.loads(output)

        # Should have default values
        assert "source" in parsed
        assert "request_id" not in parsed or parsed.get("request_id") == ""

    def test_format_with_exception(self, formatter):
        """Test formatting includes exception info."""
        try:
            raise ValueError("Test error")
        except ValueError:
            import sys

            exc_info = sys.exc_info()

        record = logging.LogRecord(
            name="test_logger",
            level=logging.ERROR,
            pathname="/test/path.py",
            lineno=42,
            msg="Error occurred",
            args=(),
            exc_info=exc_info,
        )

        output = formatter.format(record)
        parsed = json.loads(output)

        assert "exception" in parsed
        assert parsed["exception"]["type"] == "ValueError"
        assert parsed["exception"]["message"] == "Test error"
        assert "traceback" in parsed["exception"]
        assert "ValueError: Test error" in parsed["exception"]["traceback"]

    def test_format_includes_extra_fields(self, formatter, sample_record):
        """Test formatting includes funcName, lineno, pathname."""
        sample_record.funcName = "test_function"
        sample_record.lineno = 123
        sample_record.pathname = "/test/module.py"

        output = formatter.format(sample_record)
        parsed = json.loads(output)

        assert parsed["funcName"] == "test_function"
        assert parsed["lineno"] == 123
        assert parsed["pathname"] == "/test/module.py"

    def test_format_timestamp_iso8601(self, formatter, sample_record):
        """Test timestamp is in ISO 8601 format."""
        output = formatter.format(sample_record)
        parsed = json.loads(output)

        timestamp = parsed["timestamp"]
        # Should be like: 2024-12-15T15:30:00.123Z
        assert "T" in timestamp
        assert timestamp.endswith("Z")
        assert len(timestamp) == 24  # YYYY-MM-DDTHH:MM:SS.mmmZ

    def test_format_different_log_levels(self, formatter):
        """Test formatting works for all log levels."""
        levels = [
            (logging.DEBUG, "DEBUG"),
            (logging.INFO, "INFO"),
            (logging.WARNING, "WARNING"),
            (logging.ERROR, "ERROR"),
            (logging.CRITICAL, "CRITICAL"),
        ]

        for level, level_name in levels:
            record = logging.LogRecord(
                name="test",
                level=level,
                pathname="",
                lineno=1,
                msg=f"Test {level_name}",
                args=(),
                exc_info=None,
            )

            output = formatter.format(record)
            parsed = json.loads(output)

            assert parsed["level"] == level_name
            assert parsed["message"] == f"Test {level_name}"

    def test_format_unicode_message(self, formatter):
        """Test formatting handles unicode characters."""
        record = logging.LogRecord(
            name="test",
            level=logging.INFO,
            pathname="",
            lineno=1,
            msg="Test message with unicode",
            args=(),
            exc_info=None,
        )

        output = formatter.format(record)
        parsed = json.loads(output)

        assert "Test message with unicode" in parsed["message"]

    def test_format_message_with_args(self, formatter):
        """Test formatting with format args."""
        record = logging.LogRecord(
            name="test",
            level=logging.INFO,
            pathname="",
            lineno=1,
            msg="User %s logged in with id %d",
            args=("john", 42),
            exc_info=None,
        )

        output = formatter.format(record)
        parsed = json.loads(output)

        assert "john" in parsed["message"]
        assert "42" in parsed["message"]

    def test_format_empty_message(self, formatter):
        """Test formatting empty message."""
        record = logging.LogRecord(
            name="test",
            level=logging.INFO,
            pathname="",
            lineno=1,
            msg="",
            args=(),
            exc_info=None,
        )

        output = formatter.format(record)
        parsed = json.loads(output)

        assert parsed["message"] == ""

    def test_format_strips_request_id_whitespace(self, formatter, sample_record):
        """Test formatting strips whitespace from request_id."""
        from logging_utils.core.context import request_id_var

        token = request_id_var.set("  abc123  ")
        try:
            output = formatter.format(sample_record)
            parsed = json.loads(output)

            assert parsed["request_id"] == "abc123"
        finally:
            request_id_var.reset(token)

    def test_format_empty_request_id_excluded(self, formatter, sample_record):
        """Test empty request_id is not included in output."""
        from logging_utils.core.context import request_id_var

        token = request_id_var.set("   ")  # All whitespace
        try:
            output = formatter.format(sample_record)
            parsed = json.loads(output)

            # Empty request_id should not be in output
            assert "request_id" not in parsed or parsed["request_id"] == ""
        finally:
            request_id_var.reset(token)


class TestJSONFormatterIntegration:
    """Integration tests for JSONFormatter with logging handlers."""

    def test_with_stream_handler(self):
        """Test JSONFormatter works with StreamHandler."""
        import io

        stream = io.StringIO()
        handler = logging.StreamHandler(stream)
        handler.setFormatter(JSONFormatter())

        logger = logging.getLogger("test_json_integration")
        logger.handlers.clear()
        logger.addHandler(handler)
        logger.setLevel(logging.DEBUG)

        logger.info("Integration test message")

        output = stream.getvalue()
        parsed = json.loads(output.strip())

        assert parsed["message"] == "Integration test message"
        assert parsed["level"] == "INFO"

    def test_multiple_log_entries(self):
        """Test multiple log entries produce valid JSON lines."""
        import io

        stream = io.StringIO()
        handler = logging.StreamHandler(stream)
        handler.setFormatter(JSONFormatter())

        logger = logging.getLogger("test_json_multi")
        logger.handlers.clear()
        logger.addHandler(handler)
        logger.setLevel(logging.DEBUG)

        logger.info("First message")
        logger.warning("Second message")
        logger.error("Third message")

        output = stream.getvalue()
        lines = output.strip().split("\n")

        assert len(lines) == 3

        for line in lines:
            parsed = json.loads(line)
            assert "timestamp" in parsed
            assert "level" in parsed
            assert "message" in parsed