# Feature: llm-batch-matching, Property 7: Logging-Konsistenz """Property-based test for logging consistency in batch matching. For every execution of ``match_capacities`` with at least one candidate, the INFO-level log messages (start and end) must contain the correct candidate count, the configured concurrency limit, the number of successful categorizations, and the number of errors. The sum of successes and errors in the end log must equal the input count. The fake LLM is driven by a Hypothesis-generated boolean mask: position ``i`` decides whether the call for capacity ``i+1`` raises ``AzureAPIError`` (``True``) or returns a valid JSON payload (``False``). **Validates: Requirements 6.1, 6.2** """ from __future__ import annotations import asyncio import json import logging from contextlib import contextmanager from typing import Any, Generator from hypothesis import given, settings from hypothesis import strategies as st from teamlandkarte_mcp.azure.openai_client import AzureAPIError from teamlandkarte_mcp.matching.llm_fulltext_matcher import LlmFulltextMatcher from teamlandkarte_mcp.matching.profiles import TaskProfile from teamlandkarte_mcp.models import Capacity _LOGGER_NAME = "teamlandkarte_mcp.matching.llm_fulltext_matcher" # --------------------------------------------------------------------------- # Test doubles # --------------------------------------------------------------------------- class _MaskLlm: """Returns valid JSON for mask[i] is False; raises AzureAPIError for True.""" def __init__(self, mask: list[bool]) -> None: self._mask = mask self._call_index = 0 async def chat_completion(self, system: str, user: str) -> str: idx = self._call_index self._call_index += 1 if self._mask[idx]: raise AzureAPIError("simulated") return json.dumps({"category": "Top", "rationale": "ok"}) class _StubDb: """Minimal DBClient double returning empty extras for every id.""" def batch_get_capacity_descriptions( self, capacity_ids: list[Any] ) -> dict[str, str | None]: return {str(i): None for i in capacity_ids} def batch_get_capacity_certificates( self, capacity_ids: list[Any] ) -> dict[str, list[str]]: return {str(i): [] for i in capacity_ids} def batch_get_capacity_references( self, capacity_ids: list[Any] ) -> dict[str, list[dict]]: return {str(i): [] for i in capacity_ids} def _make_capacities(n: int) -> list[Capacity]: return [ Capacity( id=i + 1, owner_name=f"o{i + 1}", role_name="R", role_level=None, begin_date=None, end_date=None, competences=[], ) for i in range(n) ] # --------------------------------------------------------------------------- # Log capture context manager (hypothesis doesn't support pytest fixtures) # --------------------------------------------------------------------------- class _ListHandler(logging.Handler): """Simple handler that appends records to a list.""" def __init__(self, records: list[logging.LogRecord]) -> None: super().__init__() self._records = records def emit(self, record: logging.LogRecord) -> None: self._records.append(record) @contextmanager def _capture_logs( logger_name: str, level: int ) -> Generator[list[logging.LogRecord], None, None]: """Capture log records from a named logger for the duration of the block.""" logger = logging.getLogger(logger_name) records: list[logging.LogRecord] = [] handler = _ListHandler(records) handler.setLevel(level) logger.addHandler(handler) old_level = logger.level logger.setLevel(level) try: yield records finally: logger.removeHandler(handler) logger.setLevel(old_level) # --------------------------------------------------------------------------- # Property test # --------------------------------------------------------------------------- @settings(max_examples=100, deadline=None) @given( mask=st.lists(st.booleans(), min_size=1, max_size=15), max_concurrency=st.integers(min_value=1, max_value=5), ) def test_batch_logging_consistency(mask: list[bool], max_concurrency: int) -> None: """Property 7: log messages contain correct counts. Start log must contain the candidate count and max_concurrency. End log must contain the number of categorized items and errors. The sum of categorized + errors must equal the total candidates. """ tracker_client = _MaskLlm(mask) matcher = LlmFulltextMatcher( db=_StubDb(), client=tracker_client, max_concurrency=max_concurrency, ) capacities = _make_capacities(len(mask)) task_profile = TaskProfile(id="t", title="T", description="D", skills=[]) with _capture_logs(_LOGGER_NAME, logging.INFO) as records: asyncio.run( matcher.match_capacities( task_profile=task_profile, capacities=capacities ) ) # Find start and end log messages start_msgs = [r for r in records if "gestartet" in r.getMessage()] end_msgs = [r for r in records if "abgeschlossen" in r.getMessage()] assert len(start_msgs) == 1, f"Expected 1 start log, got {len(start_msgs)}" assert len(end_msgs) == 1, f"Expected 1 end log, got {len(end_msgs)}" start_msg = start_msgs[0].getMessage() end_msg = end_msgs[0].getMessage() # --- Start log: correct candidate count and max_concurrency --- assert str(len(mask)) in start_msg, ( f"Expected candidate count {len(mask)} in start log: {start_msg}" ) assert str(max_concurrency) in start_msg, ( f"Expected max_concurrency {max_concurrency} in start log: {start_msg}" ) # --- End log: correct categorized and error counts --- expected_errors = sum(1 for m in mask if m) expected_success = sum(1 for m in mask if not m) assert str(expected_success) in end_msg, ( f"Expected {expected_success} categorized in end log: {end_msg}" ) assert str(expected_errors) in end_msg, ( f"Expected {expected_errors} errors in end log: {end_msg}" ) # --- Consistency: categorized + errors == total candidates --- # Parse the numbers from the end log message format: # "Batch-Matching abgeschlossen: %.1fs, %d kategorisiert, %d Fehler" # We verify the sum property by checking the actual values assert expected_success + expected_errors == len(mask), ( f"Sum mismatch: {expected_success} + {expected_errors} != {len(mask)}" )