Skip to content

Commit f044219

Browse files
Add logging for deserialization errors
- Add ERROR-level logging in BasePydanticAdapter._validate_model() when validation fails - Add ERROR-level logging in ElasticsearchStore._get_managed_entries() for batch deserialization failures - Include structured context in logs: model type, error details, value preview, collection, document ID - Add tests to verify logging behavior using pytest's caplog fixture - Benefits both PydanticAdapter and DataclassAdapter (shared base class) Fixes #154 Co-authored-by: William Easton <strawgate@users.noreply.github.com>
1 parent e2d9143 commit f044219

File tree

3 files changed

+92
-1
lines changed

3 files changed

+92
-1
lines changed

key-value/key-value-aio/src/key_value/aio/adapters/pydantic/base.py

Lines changed: 29 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,3 +1,4 @@
1+
import logging
12
from abc import ABC, abstractmethod
23
from collections.abc import Sequence
34
from typing import Any, Generic, SupportsFloat, TypeVar, overload
@@ -9,6 +10,8 @@
910

1011
from key_value.aio.protocols.key_value import AsyncKeyValue
1112

13+
logger = logging.getLogger(__name__)
14+
1215
T = TypeVar("T")
1316

1417

@@ -57,6 +60,18 @@ def _validate_model(self, value: dict[str, Any]) -> T | None:
5760
if self._raise_on_validation_error:
5861
msg = f"Invalid {self._get_model_type_name()} payload: missing 'items' wrapper"
5962
raise DeserializationError(msg)
63+
64+
# Log the missing 'items' wrapper when not raising
65+
logger.error(
66+
"Missing 'items' wrapper for list %s",
67+
self._get_model_type_name(),
68+
extra={
69+
"model_type": self._get_model_type_name(),
70+
"error": "missing 'items' wrapper",
71+
"value_preview": str(value)[:200],
72+
},
73+
exc_info=False,
74+
)
6075
return None
6176
return self._type_adapter.validate_python(value["items"])
6277

@@ -66,6 +81,20 @@ def _validate_model(self, value: dict[str, Any]) -> T | None:
6681
details = e.errors(include_input=False)
6782
msg = f"Invalid {self._get_model_type_name()}: {details}"
6883
raise DeserializationError(msg) from e
84+
85+
# Log the validation error when not raising
86+
error_details = e.errors(include_input=False)
87+
logger.error(
88+
"Validation failed for %s",
89+
self._get_model_type_name(),
90+
extra={
91+
"model_type": self._get_model_type_name(),
92+
"error_count": len(error_details),
93+
"errors": error_details,
94+
"value_preview": str(value)[:200],
95+
},
96+
exc_info=True,
97+
)
6998
return None
7099

71100
def _serialize_model(self, value: T) -> dict[str, Any]:

key-value/key-value-aio/src/key_value/aio/stores/elasticsearch/store.py

Lines changed: 16 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,3 +1,4 @@
1+
import logging
12
from collections.abc import Sequence
23
from datetime import datetime
34
from typing import Any, overload
@@ -39,6 +40,8 @@
3940
raise ImportError(msg) from e
4041

4142

43+
logger = logging.getLogger(__name__)
44+
4245
DEFAULT_INDEX_PREFIX = "kv_store"
4346

4447
DEFAULT_MAPPING = {
@@ -289,7 +292,19 @@ async def _get_managed_entries(self, *, collection: str, keys: Sequence[str]) ->
289292
entries_by_id[doc_id] = None
290293
continue
291294

292-
entries_by_id[doc_id] = source_to_managed_entry(source=source)
295+
try:
296+
entries_by_id[doc_id] = source_to_managed_entry(source=source)
297+
except DeserializationError as e:
298+
logger.error(
299+
"Failed to deserialize Elasticsearch document in batch operation",
300+
extra={
301+
"collection": collection,
302+
"document_id": doc_id,
303+
"error": str(e),
304+
},
305+
exc_info=True,
306+
)
307+
entries_by_id[doc_id] = None
293308

294309
# Return entries in the same order as input keys
295310
return [entries_by_id.get(document_id) for document_id in document_ids]

key-value/key-value-aio/tests/adapters/test_pydantic.py

Lines changed: 47 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -145,3 +145,50 @@ async def test_complex_adapter_with_list(self, product_list_adapter: PydanticAda
145145

146146
assert await product_list_adapter.delete(collection=TEST_COLLECTION, key=TEST_KEY)
147147
assert await product_list_adapter.get(collection=TEST_COLLECTION, key=TEST_KEY) is None
148+
149+
async def test_validation_error_logging(
150+
self, user_adapter: PydanticAdapter[User], updated_user_adapter: PydanticAdapter[UpdatedUser], caplog: pytest.LogCaptureFixture
151+
):
152+
"""Test that validation errors are logged when raise_on_validation_error=False."""
153+
import logging
154+
155+
# Store a User, then try to retrieve as UpdatedUser (missing is_admin field)
156+
await user_adapter.put(collection=TEST_COLLECTION, key=TEST_KEY, value=SAMPLE_USER)
157+
158+
with caplog.at_level(logging.ERROR):
159+
updated_user = await updated_user_adapter.get(collection=TEST_COLLECTION, key=TEST_KEY)
160+
161+
# Should return None due to validation failure
162+
assert updated_user is None
163+
164+
# Check that an error was logged
165+
assert len(caplog.records) == 1
166+
record = caplog.records[0]
167+
assert record.levelname == "ERROR"
168+
assert "Validation failed" in record.message
169+
assert record.model_type == "Pydantic model"
170+
assert record.error_count == 1
171+
assert "is_admin" in str(record.errors)
172+
173+
async def test_list_validation_error_logging(
174+
self, product_list_adapter: PydanticAdapter[list[Product]], store: MemoryStore, caplog: pytest.LogCaptureFixture
175+
):
176+
"""Test that missing 'items' wrapper is logged for list models."""
177+
import logging
178+
179+
# Manually store invalid data (missing 'items' wrapper)
180+
await store.put(collection=TEST_COLLECTION, key=TEST_KEY, value={"invalid": "data"})
181+
182+
with caplog.at_level(logging.ERROR):
183+
result = await product_list_adapter.get(collection=TEST_COLLECTION, key=TEST_KEY)
184+
185+
# Should return None due to missing 'items' wrapper
186+
assert result is None
187+
188+
# Check that an error was logged
189+
assert len(caplog.records) == 1
190+
record = caplog.records[0]
191+
assert record.levelname == "ERROR"
192+
assert "Missing 'items' wrapper" in record.message
193+
assert record.model_type == "Pydantic model"
194+
assert "missing 'items' wrapper" in record.error

0 commit comments

Comments
 (0)