Files
StarPunk/docs/design/v1.4.1/media-logging-design.md
Phil Skentelbery 07f351fef7 feat(media): Add comprehensive logging for media uploads - v1.4.1
Implements media upload logging per docs/design/v1.4.1/media-logging-design.md

Changes:
- Add logging to save_media() in starpunk/media.py:
  * INFO: Successful uploads with file details
  * WARNING: Validation/optimization/variant failures
  * ERROR: Unexpected system errors
- Remove duplicate logging in Micropub media endpoint
- Add 5 comprehensive logging tests in TestMediaLogging class
- Bump version to 1.4.1
- Update CHANGELOG.md

All media upload operations now logged for debugging and observability.
Validation errors, optimization failures, and variant generation issues
are tracked at appropriate log levels. Original functionality unchanged.

Test results: 28/28 media tests pass, 5 new logging tests pass

🤖 Generated with [Claude Code](https://claude.com/claude-code)

Co-Authored-By: Claude <noreply@anthropic.com>
2025-12-16 17:22:22 -07:00

323 lines
10 KiB
Markdown

# Media Upload Logging Design - v1.4.1
**Author**: Architect
**Date**: 2025-12-16
**Status**: Ready for Implementation
## Problem Statement
Media upload failures in StarPunk are currently invisible to operators:
1. Errors from the admin UI (`POST /admin/new`) are only shown as flash messages that disappear
2. Errors are NOT logged to server logs
3. The Micropub media endpoint logs generic errors but loses validation details
4. Debugging upload failures requires reproducing the issue
This makes production support and debugging effectively impossible.
## Scope
This is a **PATCH release** (v1.4.1). The scope is strictly limited to:
- Adding logging to media upload operations
- No new features
- No API changes
- No database changes
- No UI changes
## Design
### Logging Location
All media logging should occur in `starpunk/media.py` in the `save_media()` function. This is the single entry point for all media uploads (both admin UI and Micropub endpoint), ensuring:
1. No duplicate logging
2. Consistent log format
3. Single place to maintain
### Log Levels
Per Python logging conventions:
| Event | Level | Rationale |
|-------|-------|-----------|
| Successful upload | INFO | Normal operation, useful for auditing |
| Validation failure (user error) | WARNING | Expected errors (bad file type, too large) |
| Processing failure (system error) | ERROR | Unexpected errors requiring investigation |
### Log Messages
#### Success (INFO)
Log after successful save to database and before returning:
```
Media upload successful: filename="{original_filename}", stored="{stored_filename}", size={final_size_bytes}b, optimized={was_optimized}, variants={variant_count}
```
Fields:
- `original_filename`: User-provided filename (for correlation with user reports)
- `stored_filename`: UUID-based stored filename (for finding the file)
- `size`: Final file size in bytes after optimization
- `optimized`: Boolean indicating if optimization was applied
- `variants`: Number of variants generated
Example:
```
INFO Media upload successful: filename="vacation.jpg", stored="a1b2c3d4-e5f6-7890-abcd-ef1234567890.jpg", size=524288b, optimized=True, variants=4
```
#### Validation Failure (WARNING)
Log when `validate_image()` raises `ValueError`:
```
Media upload validation failed: filename="{original_filename}", size={input_size_bytes}b, error="{error_message}"
```
Fields:
- `original_filename`: User-provided filename
- `size`: Input file size in bytes (may be 0 if file was empty)
- `error`: The validation error message
Example:
```
WARNING Media upload validation failed: filename="document.pdf", size=2048576b, error="Invalid image format. Accepted: JPEG, PNG, GIF, WebP"
```
#### Optimization Failure (WARNING)
Log when `optimize_image()` raises `ValueError`:
```
Media upload optimization failed: filename="{original_filename}", size={input_size_bytes}b, error="{error_message}"
```
Example:
```
WARNING Media upload optimization failed: filename="huge-photo.jpg", size=52428800b, error="Image cannot be optimized to target size. Please use a smaller or lower-resolution image."
```
#### Variant Generation Failure (WARNING)
Log when `generate_all_variants()` fails but original was saved:
```
Media upload variant generation failed: filename="{original_filename}", media_id={id}, error="{error_message}"
```
Note: Variant generation failure should NOT fail the overall upload. The original image is still usable.
#### Unexpected Error (ERROR)
Log when any unexpected exception occurs:
```
Media upload failed unexpectedly: filename="{original_filename}", error_type="{exception_class}", error="{error_message}"
```
Example:
```
ERROR Media upload failed unexpectedly: filename="photo.jpg", error_type="OSError", error="[Errno 28] No space left on device"
```
### Implementation Location
Modify `save_media()` in `starpunk/media.py`:
```python
def save_media(file_data: bytes, filename: str) -> Dict:
"""
Save uploaded media file
...
"""
from starpunk.database import get_db
input_size = len(file_data)
try:
# Validate image
mime_type, orig_width, orig_height = validate_image(file_data, filename)
except ValueError as e:
current_app.logger.warning(
f'Media upload validation failed: filename="{filename}", '
f'size={input_size}b, error="{e}"'
)
raise
try:
# Optimize image
optimized_img, width, height, optimized_bytes = optimize_image(file_data, input_size)
except ValueError as e:
current_app.logger.warning(
f'Media upload optimization failed: filename="{filename}", '
f'size={input_size}b, error="{e}"'
)
raise
# ... existing save logic ...
# Generate variants (with isolated error handling)
variants = []
try:
variants = generate_all_variants(...)
except Exception as e:
current_app.logger.warning(
f'Media upload variant generation failed: filename="{filename}", '
f'media_id={media_id}, error="{e}"'
)
# Continue - original image is still usable
# Log success
was_optimized = len(optimized_bytes) < input_size
current_app.logger.info(
f'Media upload successful: filename="{filename}", '
f'stored="{stored_filename}", size={len(optimized_bytes)}b, '
f'optimized={was_optimized}, variants={len(variants)}'
)
return { ... }
```
#### Top-Level Exception Handler
Wrap the entire function body in a try/except to catch unexpected errors (disk full, database errors, etc.):
```python
def save_media(file_data: bytes, filename: str) -> Dict:
input_size = len(file_data)
try:
# All the logic above (validation, optimization, save, variants, success log)
...
return result
except ValueError:
# Already logged at WARNING level in validation/optimization blocks
raise
except Exception as e:
current_app.logger.error(
f'Media upload failed unexpectedly: filename="{filename}", '
f'error_type="{type(e).__name__}", error="{e}"'
)
raise
```
This ensures unexpected errors are logged at ERROR level before propagating to the caller.
### Caller-Side Changes
#### Admin Route (`starpunk/routes/admin.py`)
The admin route currently catches exceptions and builds flash messages. **Do not add logging here** - the logging in `save_media()` will capture all failures.
However, the current code has a gap: the generic `except Exception` clause loses error details:
```python
except Exception as e:
errors.append(f"{file.filename}: Upload failed") # Detail lost!
```
This should remain unchanged for the flash message (we don't want to expose internal errors to users), but the logging in `save_media()` will capture the full error before it's caught here.
#### Micropub Route (`starpunk/routes/micropub.py`)
The current code already logs at ERROR level:
```python
except Exception as e:
current_app.logger.error(f"Media upload failed: {e}")
return error_response("server_error", "Failed to process upload", 500)
```
**Remove this logging** since `save_media()` will now handle it. The route should only handle the response:
```python
except Exception as e:
return error_response("server_error", "Failed to process upload", 500)
```
### What NOT to Change
1. **Flash messages** - Keep them as-is for user feedback
2. **Error responses** - Keep HTTP error responses unchanged
3. **Exception propagation** - Continue to raise ValueError for validation errors
4. **Variant generation behavior** - Keep it non-fatal (original still usable)
## Testing Strategy
### Unit Tests
Add tests to `tests/test_media_upload.py`:
1. **test_save_media_logs_success**: Verify INFO log on successful upload
2. **test_save_media_logs_validation_failure**: Verify WARNING log on invalid file type
3. **test_save_media_logs_optimization_failure**: Verify WARNING log when optimization fails
4. **test_save_media_logs_variant_failure**: Verify WARNING log when variant generation fails
Use `caplog` fixture to capture and assert log messages:
```python
def test_save_media_logs_success(app, caplog):
with caplog.at_level(logging.INFO):
result = save_media(valid_image_data, "test.jpg")
assert "Media upload successful" in caplog.text
assert "test.jpg" in caplog.text
```
### Integration Tests
Existing integration tests in `tests/test_routes_admin.py` and `tests/test_micropub.py` should continue to pass. These tests verify:
1. Flash messages still appear correctly (admin route)
2. Error responses are unchanged (micropub route)
Note: Integration tests should NOT add `caplog` assertions for logging. Logging behavior is an implementation detail tested via unit tests. Integration tests should focus on HTTP-level behavior (status codes, response bodies, headers).
## Acceptance Criteria
1. [ ] Successful media uploads are logged at INFO level with filename, stored name, size, optimization status, and variant count
2. [ ] Validation failures are logged at WARNING level with filename, input size, and error message
3. [ ] Optimization failures are logged at WARNING level with filename, input size, and error message
4. [ ] Variant generation failures are logged at WARNING level with filename, media ID, and error message
5. [ ] Unexpected errors are logged at ERROR level with filename, exception type, and error message
6. [ ] Micropub endpoint duplicate logging is removed
7. [ ] Flash messages continue to work unchanged in admin UI
8. [ ] Error responses continue to work unchanged in Micropub endpoint
9. [ ] All new logging is tested with unit tests
10. [ ] CHANGELOG.md is updated
## Files to Modify
| File | Change |
|------|--------|
| `starpunk/media.py` | Add logging to `save_media()` |
| `starpunk/routes/micropub.py` | Remove duplicate logging in media endpoint |
| `tests/test_media_upload.py` | Add logging tests |
| `starpunk/__init__.py` | Bump version to 1.4.1 |
| `CHANGELOG.md` | Add v1.4.1 entry |
## CHANGELOG Entry
```markdown
## [1.4.1] - YYYY-MM-DD
### Fixed
- Media upload failures are now logged for debugging and observability
- Validation errors (invalid format, file too large) logged at WARNING level
- Successful uploads logged at INFO level with file details
- Removed duplicate logging in Micropub media endpoint
```
## Questions for Developer
None - this design is complete and ready for implementation.
## References
- Existing logging patterns: `starpunk/notes.py`, `starpunk/media.py:delete_media()`
- Flask logging: https://flask.palletsprojects.com/en/stable/logging/
- Python logging levels: https://docs.python.org/3/library/logging.html#logging-levels