mostovik-backend/tests/apps/core/test_logging.py

"""Tests for core logging utilities"""

import json
import logging
from io import StringIO

from apps.core.logging import (
    ContextLogger,
    JSONFormatter,
    get_json_logging_config,
    log_request,
)
from apps.core.middleware import RequestIDMiddleware, get_request_id
from django.http import HttpResponse
from django.test import RequestFactory
from django.test import TestCase


class JSONFormatterTest(TestCase):
    """Tests for JSONFormatter"""

    def setUp(self):
        self.formatter = JSONFormatter()
        self.logger = logging.getLogger("test_json")
        self.logger.setLevel(logging.DEBUG)

        # Remove existing handlers
        self.logger.handlers = []

        # Add handler with JSONFormatter
        self.stream = StringIO()
        handler = logging.StreamHandler(self.stream)
        handler.setFormatter(self.formatter)
        self.logger.addHandler(handler)

    def test_output_is_valid_json(self):
        """Test that output is valid JSON"""
        self.logger.info("Test message")
        output = self.stream.getvalue()

        # Should not raise
        parsed = json.loads(output)
        self.assertIsInstance(parsed, dict)

    def test_contains_required_fields(self):
        """Test that output contains required fields"""
        self.logger.info("Test message")
        output = self.stream.getvalue()
        parsed = json.loads(output)

        self.assertIn("timestamp", parsed)
        self.assertIn("level", parsed)
        self.assertIn("logger", parsed)
        self.assertIn("message", parsed)

    def test_level_is_correct(self):
        """Test that log level is correct"""
        self.logger.warning("Warning message")
        output = self.stream.getvalue()
        parsed = json.loads(output)

        self.assertEqual(parsed["level"], "WARNING")

    def test_message_is_correct(self):
        """Test that message is correct"""
        self.logger.info("My test message")
        output = self.stream.getvalue()
        parsed = json.loads(output)

        self.assertEqual(parsed["message"], "My test message")

    def test_extra_fields_included(self):
        """Test that extra fields are included"""
        self.logger.info("Test message", extra={"user_id": 42, "action": "login"})
        output = self.stream.getvalue()
        parsed = json.loads(output)

        self.assertIn("extra", parsed)
        self.assertEqual(parsed["extra"]["user_id"], 42)
        self.assertEqual(parsed["extra"]["action"], "login")

    def test_exception_info_included(self):
        """Test that exception info is included"""
        try:
            raise ValueError("Test error")
        except ValueError:
            self.logger.exception("An error occurred")

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

        self.assertIn("exception", parsed)
        self.assertEqual(parsed["exception"]["type"], "ValueError")
        self.assertIn("Test error", parsed["exception"]["message"])

    def test_request_id_included(self):
        request = RequestFactory().get("/health/")
        middleware = RequestIDMiddleware(lambda req: None)
        middleware.process_request(request)

        self.logger.info("Message with request id")
        output = self.stream.getvalue()
        parsed = json.loads(output)
        self.assertIn("request_id", parsed)

        response = HttpResponse()
        middleware.process_response(request, response)
        self.assertIsNone(get_request_id())


class ContextLoggerTest(TestCase):
    """Tests for ContextLogger"""

    def setUp(self):
        self.context_logger = ContextLogger("test_context")

    def test_set_context(self):
        """Test context is stored"""
        self.context_logger.set_context(user_id=42, action="test")

        self.assertEqual(self.context_logger._context["user_id"], 42)
        self.assertEqual(self.context_logger._context["action"], "test")

    def test_clear_context(self):
        """Test context is cleared"""
        self.context_logger.set_context(user_id=42)
        self.context_logger.clear_context()

        self.assertEqual(self.context_logger._context, {})

    def test_context_updated_not_replaced(self):
        """Test that set_context updates rather than replaces"""
        self.context_logger.set_context(user_id=42)
        self.context_logger.set_context(action="test")

        self.assertEqual(self.context_logger._context["user_id"], 42)
        self.assertEqual(self.context_logger._context["action"], "test")

    def test_context_logger_emits_messages(self):
        stream = StringIO()
        handler = logging.StreamHandler(stream)
        logger = logging.getLogger("test_context_output")
        logger.handlers = []
        logger.addHandler(handler)
        logger.setLevel(logging.INFO)
        self.context_logger._logger = logger

        self.context_logger.set_context(request_id="req-1")
        self.context_logger.info("hello")
        self.context_logger.warning("warn")
        self.context_logger.error("err")
        try:
            raise ValueError("boom")
        except ValueError:
            self.context_logger.exception("exc")

        output = stream.getvalue()
        self.assertIn("hello", output)


class GetJsonLoggingConfigTest(TestCase):
    """Tests for get_json_logging_config function"""

    def test_returns_dict(self):
        """Test function returns a dictionary"""
        config = get_json_logging_config()
        self.assertIsInstance(config, dict)

    def test_has_required_keys(self):
        """Test config has required keys"""
        config = get_json_logging_config()

        self.assertIn("version", config)
        self.assertIn("formatters", config)
        self.assertIn("handlers", config)
        self.assertIn("loggers", config)

    def test_json_formatter_configured(self):
        """Test JSON formatter is configured"""
        config = get_json_logging_config()

        self.assertIn("json", config["formatters"])
        self.assertEqual(
            config["formatters"]["json"]["()"],
            "apps.core.logging.JSONFormatter",
        )

    def test_log_level_applied(self):
        """Test log level is applied"""
        config = get_json_logging_config(log_level="DEBUG")

        self.assertEqual(config["root"]["level"], "DEBUG")

    def test_file_handler_added_when_path_provided(self):
        """Test file handler is added when path is provided"""
        config = get_json_logging_config(log_file="/var/log/test.log")

        self.assertIn("file", config["handlers"])
        self.assertEqual(
            config["handlers"]["file"]["filename"],
            "/var/log/test.log",
        )


class LogRequestTest(TestCase):
    def setUp(self):
        self.logger = logging.getLogger("test_request_logger")
        self.logger.setLevel(logging.INFO)
        self.stream = StringIO()
        handler = logging.StreamHandler(self.stream)
        self.logger.handlers = []
        self.logger.addHandler(handler)

    def test_log_request_success(self):
        request = RequestFactory().get("/health/")
        response = HttpResponse(status=200)
        log_request(self.logger, request, response, duration_ms=12.34)
        output = self.stream.getvalue()
        self.assertIn("200", output)
        self.assertIn("/health/", output)

    def test_log_request_client_error(self):
        request = RequestFactory().get("/health/")
        response = HttpResponse(status=404)
        log_request(self.logger, request, response, duration_ms=5)
        output = self.stream.getvalue()
        self.assertIn("404", output)

    def test_log_request_server_error(self):
        request = RequestFactory().get("/health/")
        response = HttpResponse(status=500)
        log_request(self.logger, request, response, duration_ms=5)
        output = self.stream.getvalue()
        self.assertIn("500", output)