Add logging for deserialization errors #158
Conversation
- 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>
📝 WalkthroughWalkthroughAdds module-level loggers and emits ERROR logs for previously-silent failures: Pydantic adapter validation now logs validation details (including missing "items" wrapper) when not raising, and Elasticsearch stores log per-document deserialization errors during batch retrieval while returning None for failed items. Changes
Sequence Diagram(s)sequenceDiagram
participant Client
participant Store
participant Deserializer
participant Logger
Note over Store,Deserializer: Batch _get_managed_entries (per-document handling)
Client->>Store: fetch batch documents
loop for each document
Store->>Deserializer: source_to_managed_entry(source)
alt deserialization succeeds
Deserializer-->>Store: ManagedEntry
else DeserializationError
Deserializer--xStore: raises DeserializationError
Store->>Logger: log ERROR (collection, document_id, error)
Store-->>Client: include None for this item
end
end
Store-->>Client: return list (original order, None for failures)
sequenceDiagram
participant Caller
participant Adapter
participant Pydantic
participant Logger
Note over Adapter,Pydantic: _validate_model when raise_on_validation_error=False
Caller->>Adapter: validate(value)
Adapter->>Pydantic: parse/validate(value)
alt validation succeeds
Pydantic-->>Adapter: model instance
Adapter-->>Caller: return instance
else ValidationError
Pydantic--xAdapter: raises ValidationError
Adapter->>Logger: log ERROR ("Validation failed", model_type, error count, errors) with exc_info
Adapter-->>Caller: return None
end
Possibly related PRs
Pre-merge checks and finishing touches❌ Failed checks (1 warning)
✅ Passed checks (4 passed)
✨ Finishing touches
🧪 Generate unit tests (beta)
Comment |
![coderabbitai[bot]](https://avatars.githubusercontent.com/in/347564?s=60&v=4){kind=small}
There was a problem hiding this comment.
Actionable comments posted: 2
📜 Review details
Configuration used: CodeRabbit UI
Review profile: ASSERTIVE
Plan: Pro
📒 Files selected for processing (3)
key-value/key-value-aio/src/key_value/aio/adapters/pydantic/base.py(4 hunks)key-value/key-value-aio/src/key_value/aio/stores/elasticsearch/store.py(3 hunks)key-value/key-value-aio/tests/adapters/test_pydantic.py(1 hunks)
🧰 Additional context used
🧬 Code graph analysis (3)
key-value/key-value-aio/src/key_value/aio/stores/elasticsearch/store.py (2)
key-value/key-value-sync/src/key_value/sync/code_gen/stores/elasticsearch/store.py (1)
source_to_managed_entry(81-105)key-value/key-value-shared/src/key_value/shared/errors/key_value.py (1)
DeserializationError(14-15)
key-value/key-value-aio/tests/adapters/test_pydantic.py (3)
key-value/key-value-aio/src/key_value/aio/adapters/pydantic/adapter.py (1)
PydanticAdapter(14-55)key-value/key-value-aio/src/key_value/aio/adapters/pydantic/base.py (4)
put(200-209)get(127-127)get(130-130)get(132-159)key-value/key-value-aio/src/key_value/aio/stores/memory/store.py (3)
put(95-96)get(85-93)MemoryStore(106-218)
key-value/key-value-aio/src/key_value/aio/adapters/pydantic/base.py (5)
key-value/key-value-aio/src/key_value/aio/adapters/dataclass/adapter.py (1)
_get_model_type_name(69-71)key-value/key-value-aio/src/key_value/aio/adapters/pydantic/adapter.py (1)
_get_model_type_name(53-55)key-value/key-value-sync/src/key_value/sync/code_gen/adapters/dataclass/adapter.py (1)
_get_model_type_name(69-71)key-value/key-value-sync/src/key_value/sync/code_gen/adapters/pydantic/adapter.py (1)
_get_model_type_name(53-55)key-value/key-value-sync/src/key_value/sync/code_gen/adapters/pydantic/base.py (1)
_get_model_type_name(33-39)
🪛 GitHub Actions: Run Tests
key-value/key-value-aio/tests/adapters/test_pydantic.py
[error] 169-169: Type of "model_type" is unknown (reportUnknownMemberType)
🪛 GitHub Check: static_analysis (key-value/key-value-aio)
key-value/key-value-aio/tests/adapters/test_pydantic.py
[failure] 194-194:
Type of "error" is unknown (reportUnknownMemberType)
[failure] 193-193:
Cannot access attribute "model_type" for class "LogRecord"
Attribute "model_type" is unknown (reportAttributeAccessIssue)
[failure] 193-193:
Type of "model_type" is unknown (reportUnknownMemberType)
[failure] 171-171:
Cannot access attribute "errors" for class "LogRecord"
Attribute "errors" is unknown (reportAttributeAccessIssue)
[failure] 171-171:
Argument type is unknown
Argument corresponds to parameter "object" in function "new" (reportUnknownArgumentType)
[failure] 171-171:
Type of "errors" is unknown (reportUnknownMemberType)
[failure] 170-170:
Cannot access attribute "error_count" for class "LogRecord"
Attribute "error_count" is unknown (reportAttributeAccessIssue)
[failure] 170-170:
Type of "error_count" is unknown (reportUnknownMemberType)
[failure] 169-169:
Cannot access attribute "model_type" for class "LogRecord"
Attribute "model_type" is unknown (reportAttributeAccessIssue)
[failure] 169-169:
Type of "model_type" is unknown (reportUnknownMemberType)
🔇 Additional comments (5)
key-value/key-value-aio/src/key_value/aio/stores/elasticsearch/store.py (2)
1-1: LGTM! Logger initialization follows best practices.The logging import and module-level logger initialization follow the standard Python logging pattern.
Also applies to: 43-44
295-307: LGTM! Well-structured error handling with comprehensive logging.The try-catch block properly handles deserialization failures on a per-document basis, logging detailed context (collection, document_id, error) with full traceback before returning None for the problematic entry. This maintains input order consistency while providing excellent observability.
key-value/key-value-aio/src/key_value/aio/adapters/pydantic/base.py (3)
1-1: LGTM! Logger initialization follows best practices.The logging import and module-level logger initialization are consistent with the pattern used in the Elasticsearch store module.
Also applies to: 13-14
63-75: LGTM! Appropriate error logging for missing wrapper.The error logging for missing 'items' wrapper includes relevant context (model_type, error, value_preview) and appropriately uses
exc_info=Falsesince there's no exception to log. The value preview truncation to 200 characters prevents log bloat.
84-97: LGTM! Comprehensive validation error logging.The error logging for validation failures is well-structured:
- Extracts error details with
include_input=Falseto prevent potential PII leakage- Includes comprehensive context (model_type, error_count, errors, value_preview)
- Appropriately uses
exc_info=Trueto capture the full traceback- Truncates value preview consistently with other logging paths
There was a problem hiding this comment.
Actionable comments posted: 2
📜 Review details
Configuration used: CodeRabbit UI
Review profile: ASSERTIVE
Plan: Pro
📒 Files selected for processing (2)
key-value/key-value-aio/tests/adapters/test_pydantic.py(3 hunks)key-value/key-value-sync/tests/code_gen/adapters/test_pydantic.py(3 hunks)
🧰 Additional context used
🧬 Code graph analysis (2)
key-value/key-value-sync/tests/code_gen/adapters/test_pydantic.py (3)
key-value/key-value-aio/tests/adapters/test_pydantic.py (4)
model_type_from_log_record(51-55)error_from_log_record(58-62)errors_from_log_record(65-69)store(74-75)key-value/key-value-sync/src/key_value/sync/code_gen/adapters/pydantic/adapter.py (1)
PydanticAdapter(17-55)key-value/key-value-sync/src/key_value/sync/code_gen/stores/base.py (2)
put(270-279)get(181-202)
key-value/key-value-aio/tests/adapters/test_pydantic.py (2)
key-value/key-value-sync/tests/code_gen/adapters/test_pydantic.py (12)
model_type_from_log_record(54-58)error_from_log_record(61-65)errors_from_log_record(68-72)test_validation_error_logging(174-198)user_adapter(81-82)User(16-19)updated_user_adapter(85-86)UpdatedUser(22-23)test_list_validation_error_logging(200-222)product_list_adapter(93-94)Product(26-30)store(77-78)key-value/key-value-aio/src/key_value/aio/adapters/pydantic/base.py (4)
put(198-207)get(125-125)get(128-128)get(130-157)
🔇 Additional comments (4)
key-value/key-value-sync/tests/code_gen/adapters/test_pydantic.py (2)
54-72: LGTM! Helper functions correctly handle dynamic log attributes.The helper functions properly validate attribute existence and include appropriate type-checker suppressions for accessing dynamically-added log record attributes.
174-198: LGTM! Comprehensive test coverage for validation error logging.The test correctly verifies that validation failures are logged at ERROR level with appropriate context when
raise_on_validation_error=False.key-value/key-value-aio/tests/adapters/test_pydantic.py (2)
51-69: LGTM! Helper functions correctly handle dynamic log attributes.The helper functions properly validate attribute existence and include appropriate type-checker suppressions for accessing dynamically-added log record attributes.
171-195: LGTM! Comprehensive test coverage for validation error logging.The test correctly verifies that validation failures are logged at ERROR level with appropriate context when
raise_on_validation_error=False.
key-value/key-value-sync/tests/code_gen/adapters/test_pydantic.py
Outdated
Show resolved
Hide resolved
Co-authored-by: coderabbitai[bot] <136622811+coderabbitai[bot]@users.noreply.github.com>
|
There was a problem hiding this comment.
Actionable comments posted: 2
📜 Review details
Configuration used: CodeRabbit UI
Review profile: ASSERTIVE
Plan: Pro
📒 Files selected for processing (2)
key-value/key-value-aio/tests/adapters/test_pydantic.py(3 hunks)key-value/key-value-sync/tests/code_gen/adapters/test_pydantic.py(3 hunks)
🧰 Additional context used
🧬 Code graph analysis (2)
key-value/key-value-aio/tests/adapters/test_pydantic.py (1)
key-value/key-value-sync/tests/code_gen/adapters/test_pydantic.py (12)
model_type_from_log_record(54-58)error_from_log_record(61-65)errors_from_log_record(68-72)test_validation_error_logging(174-198)user_adapter(81-82)User(16-19)updated_user_adapter(85-86)UpdatedUser(22-23)test_list_validation_error_logging(200-222)product_list_adapter(93-94)Product(26-30)store(77-78)
key-value/key-value-sync/tests/code_gen/adapters/test_pydantic.py (1)
key-value/key-value-aio/tests/adapters/test_pydantic.py (12)
model_type_from_log_record(51-55)error_from_log_record(58-62)errors_from_log_record(65-69)test_validation_error_logging(171-195)user_adapter(78-79)User(13-16)updated_user_adapter(82-83)UpdatedUser(19-20)test_list_validation_error_logging(197-219)product_list_adapter(90-91)Product(23-27)store(74-75)
⏰ Context from checks skipped due to timeout of 90000ms. You can increase the timeout in your CodeRabbit configuration to a maximum of 15 minutes (900000ms). (8)
- GitHub Check: test_quick (3.10, windows-2022, key-value/key-value-sync)
- GitHub Check: test_quick (3.10, windows-latest, key-value/key-value-sync)
- GitHub Check: test_quick (3.10, windows-latest, key-value/key-value-aio)
- GitHub Check: test_quick (3.10, windows-2022, key-value/key-value-aio)
- GitHub Check: test_quick (3.10, ubuntu-latest, key-value/key-value-aio)
- GitHub Check: test_quick (3.10, ubuntu-22.04, key-value/key-value-sync)
- GitHub Check: test_quick (3.10, ubuntu-latest, key-value/key-value-sync)
- GitHub Check: test_quick (3.10, ubuntu-22.04, key-value/key-value-aio)
🔇 Additional comments (6)
key-value/key-value-sync/tests/code_gen/adapters/test_pydantic.py (4)
5-5: LGTM!The LogRecord import is necessary for type-annotating the helper functions and is properly placed with the other imports.
54-72: LGTM!The helper functions follow a consistent pattern with proper attribute validation, clear error messages, and appropriate type annotations. The pyright ignore comments are necessary for accessing dynamically-added LogRecord attributes.
174-198: LGTM!The test thoroughly validates the logging behavior for validation errors, including verification of the log level, message content, structured context (model_type), and error details. The defensive
str()call on line 198 is appropriate given the dynamic nature of LogRecord attributes.
200-222: LGTM!The test thoroughly validates the logging behavior for missing 'items' wrapper errors, with appropriate assertions for log level, message content, structured context, and error details. The defensive
str()call on line 222 is reasonable given the dynamic nature of LogRecord attributes.key-value/key-value-aio/tests/adapters/test_pydantic.py (2)
2-2: LGTM!The LogRecord import is necessary for the helper functions and is correctly placed with other imports.
51-69: Excellent helper functions for testing dynamic log attributes.The helper functions are well-designed with proper error handling and appropriate type ignore comments. They correctly handle the dynamic attributes added to LogRecord objects during logging and match the pattern used in the sync version.
| async def test_validation_error_logging( | ||
| self, user_adapter: PydanticAdapter[User], updated_user_adapter: PydanticAdapter[UpdatedUser], caplog: pytest.LogCaptureFixture | ||
| ): | ||
| """Test that validation errors are logged when raise_on_validation_error=False.""" | ||
| import logging | ||
|
|
||
| # Store a User, then try to retrieve as UpdatedUser (missing is_admin field) | ||
| await user_adapter.put(collection=TEST_COLLECTION, key=TEST_KEY, value=SAMPLE_USER) | ||
|
|
||
| with caplog.at_level(logging.ERROR): | ||
| updated_user = await updated_user_adapter.get(collection=TEST_COLLECTION, key=TEST_KEY) | ||
|
|
||
| # Should return None due to validation failure | ||
| assert updated_user is None | ||
|
|
||
| # Check that an error was logged | ||
| assert len(caplog.records) == 1 | ||
| record = caplog.records[0] | ||
| assert record.levelname == "ERROR" | ||
| assert "Validation failed" in record.message | ||
| assert model_type_from_log_record(record) == "Pydantic model" | ||
|
|
||
| errors = errors_from_log_record(record) | ||
| assert len(errors) == 1 | ||
| assert "is_admin" in str(errors[0]) | ||
|
|
There was a problem hiding this comment.
🧹 Nitpick | 🔵 Trivial
Comprehensive test for validation error logging.
The test correctly verifies that validation failures are logged at ERROR level with appropriate context. The test logic is sound, and assertions properly validate the logging behavior.
Consider moving the logging import (line 175) to the top of the file with other imports for consistency, though the current placement is acceptable:
import pytest
from inline_snapshot import snapshot
from key_value.shared.errors import DeserializationError
from pydantic import AnyHttpUrl, BaseModel
+import logging
from key_value.aio.adapters.pydantic import PydanticAdapterThen remove the inline import:
async def test_validation_error_logging(
self, user_adapter: PydanticAdapter[User], updated_user_adapter: PydanticAdapter[UpdatedUser], caplog: pytest.LogCaptureFixture
):
"""Test that validation errors are logged when raise_on_validation_error=False."""
- import logging
# Store a User, then try to retrieve as UpdatedUser (missing is_admin field)Committable suggestion skipped: line range outside the PR's diff.
🤖 Prompt for AI Agents
In key-value/key-value-aio/tests/adapters/test_pydantic.py around lines 171 to
196, there is an inline "import logging" at line 175; move that import to the
top of the file with the other imports and delete the inline import, ensuring no
other references are changed and tests still use caplog.at_level(logging.ERROR).
| async def test_list_validation_error_logging( | ||
| self, product_list_adapter: PydanticAdapter[list[Product]], store: MemoryStore, caplog: pytest.LogCaptureFixture | ||
| ): | ||
| """Test that missing 'items' wrapper is logged for list models.""" | ||
| import logging | ||
|
|
||
| # Manually store invalid data (missing 'items' wrapper) | ||
| await store.put(collection=TEST_COLLECTION, key=TEST_KEY, value={"invalid": "data"}) | ||
|
|
||
| with caplog.at_level(logging.ERROR): | ||
| result = await product_list_adapter.get(collection=TEST_COLLECTION, key=TEST_KEY) | ||
|
|
||
| # Should return None due to missing 'items' wrapper | ||
| assert result is None | ||
|
|
||
| # Check that an error was logged | ||
| assert len(caplog.records) == 1 | ||
| record = caplog.records[0] | ||
| assert record.levelname == "ERROR" | ||
| assert "Missing 'items' wrapper" in record.message | ||
| assert model_type_from_log_record(record) == "Pydantic model" | ||
| error = error_from_log_record(record) | ||
| assert "missing 'items' wrapper" in str(error) |
There was a problem hiding this comment.
🧹 Nitpick | 🔵 Trivial
Well-designed test for list validation error logging.
The test properly validates that missing 'items' wrapper errors are logged correctly. The use of error_from_log_record (singular) is appropriate here, and the variable naming is consistent.
Same optional suggestion as the previous test: consider moving the logging import to the module level for consistency:
import pytest
from inline_snapshot import snapshot
from key_value.shared.errors import DeserializationError
from pydantic import AnyHttpUrl, BaseModel
+import logging
from key_value.aio.adapters.pydantic import PydanticAdapterThen remove the inline import:
async def test_list_validation_error_logging(
self, product_list_adapter: PydanticAdapter[list[Product]], store: MemoryStore, caplog: pytest.LogCaptureFixture
):
"""Test that missing 'items' wrapper is logged for list models."""
- import logging
# Manually store invalid data (missing 'items' wrapper)Committable suggestion skipped: line range outside the PR's diff.
🤖 Prompt for AI Agents
In key-value/key-value-aio/tests/adapters/test_pydantic.py around lines 197 to
219, the test contains an inline "import logging"; move that import to the top
of the module with other imports and remove the inline import from the test body
so the test uses the module-level logging import for consistency with other
tests.
Summary
Adds logging for silent deserialization errors across adapters and stores, addressing issue #154.
Changes
BasePydanticAdapter._validate_model()when validation failsElasticsearchStore._get_managed_entries()for batch deserialization failuresTesting
Fixes #154
🤖 Generated with Claude Code
Summary by CodeRabbit
Tests
Chores