docs: Add comprehensive logging guide for backend debugging
Guide covers: - What's logged at each stage - Log levels and emoji indicators - Common log patterns - Docker log commands - Debugging with logs - Performance monitoring - Troubleshooting checklist - Real-time monitoring - Example analysis Helps users understand: - Backend startup sequence - Blockchain operations - Error detection - System health - Performance tracking
This commit is contained in:
Alexis Bruneteau
parent
7af375f8c0
commit
7b9d6d0407
389
e-voting-system/LOGGING_GUIDE.md
Normal file
389
e-voting-system/LOGGING_GUIDE.md
Normal file
@ -0,0 +1,389 @@
|
|||||||
|
# Backend Logging Guide
|
||||||
|
|
||||||
|
## Overview
|
||||||
|
|
||||||
|
The E-Voting backend now includes comprehensive structured logging to help debug issues and understand the system's behavior.
|
||||||
|
|
||||||
|
## What's Logged
|
||||||
|
|
||||||
|
### Startup Sequence
|
||||||
|
```
|
||||||
|
🚀 Starting E-Voting Backend
|
||||||
|
📦 Initializing database...
|
||||||
|
✓ Database initialized successfully
|
||||||
|
⛓️ Initializing blockchain...
|
||||||
|
✓ Recorded election 1 (Election Présidentielle 2025)
|
||||||
|
Block #0, Hash: 7f3e9c2b1d4f..., Candidates: 4
|
||||||
|
✓ Blockchain initialization completed
|
||||||
|
✓ Backend initialization complete, starting FastAPI app
|
||||||
|
```
|
||||||
|
|
||||||
|
### Blockchain Operations
|
||||||
|
```
|
||||||
|
Blockchain Initialization Started
|
||||||
|
Found 1 elections in database
|
||||||
|
Blockchain currently has 0 elections
|
||||||
|
✓ Recorded election 1 (Election Présidentielle 2025)
|
||||||
|
Block #0, Hash: 7f3e9c2b..., Candidates: 4
|
||||||
|
Recording summary: 1 new, 0 skipped
|
||||||
|
Verifying blockchain integrity (1 blocks)...
|
||||||
|
✓ Blockchain integrity verified successfully
|
||||||
|
Blockchain Initialization Complete
|
||||||
|
Total blocks: 1
|
||||||
|
Chain valid: true
|
||||||
|
```
|
||||||
|
|
||||||
|
### Election Creation
|
||||||
|
```
|
||||||
|
✓ Election 1 recorded to blockchain (Block #0, Hash: 7f3e9c2b...)
|
||||||
|
```
|
||||||
|
|
||||||
|
### Errors and Warnings
|
||||||
|
```
|
||||||
|
❌ Failed to record election 1 to blockchain: [error details]
|
||||||
|
⚠️ Blockchain initialization failed (non-fatal): [error details]
|
||||||
|
🔥 Critical failure: [error details]
|
||||||
|
```
|
||||||
|
|
||||||
|
## Logging Levels
|
||||||
|
|
||||||
|
| Level | Emoji | Use Case |
|
||||||
|
|-------|-------|----------|
|
||||||
|
| DEBUG | 🔍 | Detailed diagnostic information, variable states |
|
||||||
|
| INFO | ℹ️ | General informational messages, success confirmations |
|
||||||
|
| WARNING | ⚠️ | Warning messages, potential issues (non-fatal) |
|
||||||
|
| ERROR | ❌ | Error messages, failures that need attention |
|
||||||
|
| CRITICAL | 🔥 | Critical failures that may prevent operation |
|
||||||
|
|
||||||
|
## Reading Log Output
|
||||||
|
|
||||||
|
### Example Log Entry
|
||||||
|
```
|
||||||
|
ℹ️ 2025-11-07 02:03:15 - backend.init_blockchain - INFO - ✓ Recorded election 1 (Election Présidentielle 2025)
|
||||||
|
Block #0, Hash: 7f3e9c2b1d4f..., Candidates: 4
|
||||||
|
```
|
||||||
|
|
||||||
|
Parts:
|
||||||
|
- `ℹ️` - Log level emoji
|
||||||
|
- `2025-11-07 02:03:15` - Timestamp
|
||||||
|
- `backend.init_blockchain` - Module that logged it
|
||||||
|
- `INFO` - Log level
|
||||||
|
- Rest is the message
|
||||||
|
|
||||||
|
## Common Log Patterns
|
||||||
|
|
||||||
|
### Successful Blockchain Initialization
|
||||||
|
```
|
||||||
|
Blockchain Initialization Started
|
||||||
|
Found 1 elections in database
|
||||||
|
Blockchain currently has 0 elections
|
||||||
|
✓ Recorded election 1 (Election Présidentielle 2025)
|
||||||
|
Block #0, Hash: 7f3e9c2b..., Candidates: 4
|
||||||
|
Recording summary: 1 new, 0 skipped
|
||||||
|
✓ Blockchain integrity verified successfully
|
||||||
|
Blockchain Initialization Complete
|
||||||
|
```
|
||||||
|
✓ **Status**: Backend is working correctly
|
||||||
|
|
||||||
|
### Election Already on Blockchain
|
||||||
|
```
|
||||||
|
⊘ Election 1 (Election Présidentielle 2025) already on blockchain
|
||||||
|
Recording summary: 0 new, 1 skipped
|
||||||
|
```
|
||||||
|
✓ **Status**: Restart is safe, election already recorded
|
||||||
|
|
||||||
|
### Database Connection Error
|
||||||
|
```
|
||||||
|
❌ Database initialization failed: [error details]
|
||||||
|
```
|
||||||
|
✗ **Status**: Database isn't accessible, check connection settings
|
||||||
|
|
||||||
|
### Blockchain Corruption Detected
|
||||||
|
```
|
||||||
|
✗ Blockchain integrity check FAILED - possible corruption!
|
||||||
|
```
|
||||||
|
✗ **Status**: Blockchain data is corrupted, investigate immediately
|
||||||
|
|
||||||
|
## Docker Logs
|
||||||
|
|
||||||
|
### View All Logs
|
||||||
|
```bash
|
||||||
|
docker compose -f docker-compose.multinode.yml logs -f
|
||||||
|
```
|
||||||
|
|
||||||
|
### View Backend Logs Only
|
||||||
|
```bash
|
||||||
|
docker compose -f docker-compose.multinode.yml logs -f backend-node-1
|
||||||
|
docker compose -f docker-compose.multinode.yml logs -f backend-node-2
|
||||||
|
docker compose -f docker-compose.multinode.yml logs -f backend-node-3
|
||||||
|
```
|
||||||
|
|
||||||
|
### View Database Logs
|
||||||
|
```bash
|
||||||
|
docker compose -f docker-compose.multinode.yml logs -f mariadb
|
||||||
|
```
|
||||||
|
|
||||||
|
### View Frontend Logs
|
||||||
|
```bash
|
||||||
|
docker compose -f docker-compose.multinode.yml logs -f frontend
|
||||||
|
```
|
||||||
|
|
||||||
|
### View Nginx Load Balancer Logs
|
||||||
|
```bash
|
||||||
|
docker compose -f docker-compose.multinode.yml logs -f nginx
|
||||||
|
```
|
||||||
|
|
||||||
|
## Debugging with Logs
|
||||||
|
|
||||||
|
### Problem: 502 Bad Gateway
|
||||||
|
|
||||||
|
**Check logs:**
|
||||||
|
```bash
|
||||||
|
docker compose logs backend-node-1 2>&1 | tail -100
|
||||||
|
```
|
||||||
|
|
||||||
|
**Look for:**
|
||||||
|
- `❌ Database initialization failed` - Database won't connect
|
||||||
|
- `⚠️ Blockchain initialization failed` - Blockchain error (non-fatal)
|
||||||
|
- `Exception` with full traceback - What specifically failed
|
||||||
|
- Module import errors - Missing or broken imports
|
||||||
|
|
||||||
|
### Problem: No Elections on Blockchain
|
||||||
|
|
||||||
|
**Check logs:**
|
||||||
|
```bash
|
||||||
|
docker compose logs backend-node-1 | grep -i blockchain
|
||||||
|
```
|
||||||
|
|
||||||
|
**Look for:**
|
||||||
|
- `Found X elections in database` - Are there elections?
|
||||||
|
- `✓ Recorded election` - Did recording succeed?
|
||||||
|
- `Recording summary` - How many were recorded vs skipped?
|
||||||
|
- `✓ Blockchain integrity verified` - Is blockchain valid?
|
||||||
|
|
||||||
|
### Problem: Slow Startup
|
||||||
|
|
||||||
|
**Check logs:**
|
||||||
|
```bash
|
||||||
|
docker compose logs backend-node-1 | grep -i "started\|initialized\|complete"
|
||||||
|
```
|
||||||
|
|
||||||
|
**Look for:**
|
||||||
|
- How long between "Starting" and "initialized successfully"
|
||||||
|
- Any pauses or long operations
|
||||||
|
- Database queries taking time
|
||||||
|
|
||||||
|
## Logging Configuration
|
||||||
|
|
||||||
|
**File:** `backend/logging_config.py`
|
||||||
|
|
||||||
|
Controls:
|
||||||
|
- Log levels per module
|
||||||
|
- Output format (colors, emojis, timestamps)
|
||||||
|
- Which third-party loggers to suppress (SQLAlchemy, Uvicorn, etc.)
|
||||||
|
|
||||||
|
### Modify Log Levels
|
||||||
|
|
||||||
|
To change log levels at runtime:
|
||||||
|
|
||||||
|
```python
|
||||||
|
# In backend code
|
||||||
|
import logging
|
||||||
|
|
||||||
|
# Get a logger
|
||||||
|
logger = logging.getLogger('backend.blockchain_elections')
|
||||||
|
|
||||||
|
# Change level
|
||||||
|
logger.setLevel(logging.DEBUG) # More verbose
|
||||||
|
logger.setLevel(logging.WARNING) # Less verbose
|
||||||
|
```
|
||||||
|
|
||||||
|
Or in `logging_config.py`:
|
||||||
|
|
||||||
|
```python
|
||||||
|
def setup_logging(level=logging.INFO):
|
||||||
|
# Change specific module levels
|
||||||
|
logging.getLogger('backend.blockchain_elections').setLevel(logging.DEBUG)
|
||||||
|
logging.getLogger('backend.services').setLevel(logging.WARNING)
|
||||||
|
```
|
||||||
|
|
||||||
|
## Modules and Their Log Output
|
||||||
|
|
||||||
|
### `backend.main`
|
||||||
|
- Backend startup sequence
|
||||||
|
- Initialization status
|
||||||
|
- Fatal errors
|
||||||
|
|
||||||
|
### `backend.init_blockchain`
|
||||||
|
- Blockchain initialization
|
||||||
|
- Election recording
|
||||||
|
- Integrity verification
|
||||||
|
- Startup profiling
|
||||||
|
|
||||||
|
### `backend.services`
|
||||||
|
- Election creation
|
||||||
|
- Voter operations
|
||||||
|
- Vote recording
|
||||||
|
- Database operations
|
||||||
|
|
||||||
|
### `backend.routes`
|
||||||
|
- API endpoint calls
|
||||||
|
- Request/response info
|
||||||
|
- Validation errors
|
||||||
|
|
||||||
|
### `backend.database`
|
||||||
|
- Database connection
|
||||||
|
- Migration status
|
||||||
|
- Connection pooling info
|
||||||
|
|
||||||
|
## Performance Monitoring with Logs
|
||||||
|
|
||||||
|
### Track Blockchain Initialization Time
|
||||||
|
|
||||||
|
```bash
|
||||||
|
docker compose logs backend-node-1 | grep "Blockchain Initialization"
|
||||||
|
```
|
||||||
|
|
||||||
|
Output shows:
|
||||||
|
- When it started
|
||||||
|
- When it completed
|
||||||
|
- How many elections processed
|
||||||
|
|
||||||
|
Calculate total time: `start_time` to `complete_time`
|
||||||
|
|
||||||
|
### Track Election Recording Time
|
||||||
|
|
||||||
|
```bash
|
||||||
|
docker compose logs backend-node-1 | grep "Recorded election"
|
||||||
|
```
|
||||||
|
|
||||||
|
Each line shows:
|
||||||
|
- Election ID and name
|
||||||
|
- Block number assigned
|
||||||
|
- Hash of the block
|
||||||
|
- Candidate count
|
||||||
|
|
||||||
|
### Track Request Processing
|
||||||
|
|
||||||
|
```bash
|
||||||
|
docker compose logs backend-node-1 | grep "API\|request"
|
||||||
|
```
|
||||||
|
|
||||||
|
Shows which endpoints were called and when
|
||||||
|
|
||||||
|
## Exporting Logs
|
||||||
|
|
||||||
|
### Save to File
|
||||||
|
```bash
|
||||||
|
docker compose logs backend-node-1 > backend_logs.txt
|
||||||
|
```
|
||||||
|
|
||||||
|
### Search Logs for Pattern
|
||||||
|
```bash
|
||||||
|
docker compose logs | grep "❌\|✗" # Errors and failures
|
||||||
|
docker compose logs | grep "✓" # Successes
|
||||||
|
docker compose logs | grep "⚠️" # Warnings
|
||||||
|
```
|
||||||
|
|
||||||
|
### Get Last N Lines
|
||||||
|
```bash
|
||||||
|
docker compose logs backend-node-1 --tail 50
|
||||||
|
```
|
||||||
|
|
||||||
|
### Get Logs Since Time
|
||||||
|
```bash
|
||||||
|
docker compose logs --since 2025-11-07T02:00:00
|
||||||
|
```
|
||||||
|
|
||||||
|
## Troubleshooting Checklist
|
||||||
|
|
||||||
|
When something goes wrong:
|
||||||
|
|
||||||
|
- [ ] Check backend logs for errors: `docker compose logs backend-node-1`
|
||||||
|
- [ ] Look for stack traces with `Exception` or `Error`
|
||||||
|
- [ ] Check database logs: `docker compose logs mariadb`
|
||||||
|
- [ ] Check if database initialized successfully
|
||||||
|
- [ ] Check if blockchain recorded elections
|
||||||
|
- [ ] Verify blockchain integrity status
|
||||||
|
- [ ] Check Nginx load balancer logs: `docker compose logs nginx`
|
||||||
|
- [ ] Verify all containers are healthy: `docker compose ps`
|
||||||
|
|
||||||
|
## Example Log Analysis
|
||||||
|
|
||||||
|
**Scenario**: Getting 502 errors but frontend loads
|
||||||
|
|
||||||
|
**Log search:**
|
||||||
|
```bash
|
||||||
|
docker compose logs backend-node-1 | head -100
|
||||||
|
```
|
||||||
|
|
||||||
|
**Expected healthy logs:**
|
||||||
|
```
|
||||||
|
🚀 Starting E-Voting Backend
|
||||||
|
📦 Initializing database...
|
||||||
|
✓ Database initialized successfully
|
||||||
|
⛓️ Initializing blockchain...
|
||||||
|
✓ Blockchain initialization completed
|
||||||
|
✓ Backend initialization complete, starting FastAPI app
|
||||||
|
```
|
||||||
|
|
||||||
|
**Red flags:**
|
||||||
|
```
|
||||||
|
❌ Database initialization failed <- Backend can't connect to DB
|
||||||
|
⚠️ Blockchain initialization failed <- Blockchain issue (non-fatal)
|
||||||
|
Exception in... <- Python error
|
||||||
|
Traceback... <- Stack trace
|
||||||
|
```
|
||||||
|
|
||||||
|
**Next steps:**
|
||||||
|
- If database failed: check MariaDB is running
|
||||||
|
- If blockchain failed: check elections table has data
|
||||||
|
- If exception: read the full traceback for details
|
||||||
|
|
||||||
|
## Real-Time Monitoring
|
||||||
|
|
||||||
|
### Watch Logs as Backend Starts
|
||||||
|
```bash
|
||||||
|
docker compose logs -f backend-node-1
|
||||||
|
```
|
||||||
|
|
||||||
|
Press Ctrl+C to stop. Useful for:
|
||||||
|
- Watching initialization progress
|
||||||
|
- Seeing exactly when things complete
|
||||||
|
- Catching errors as they happen
|
||||||
|
|
||||||
|
### Monitor Multiple Services
|
||||||
|
```bash
|
||||||
|
docker compose logs -f
|
||||||
|
```
|
||||||
|
|
||||||
|
Shows all logs from all services in real-time
|
||||||
|
|
||||||
|
## Questions the Logs Answer
|
||||||
|
|
||||||
|
| Question | Where to Look |
|
||||||
|
|----------|---------------|
|
||||||
|
| Why can't the backend connect to DB? | `backend.main` logs for `Database initialization failed` |
|
||||||
|
| Are elections being recorded to blockchain? | `backend.init_blockchain` logs for `Recorded election` |
|
||||||
|
| Is the blockchain valid? | `backend.init_blockchain` logs for `Blockchain integrity verified` |
|
||||||
|
| How long does startup take? | Timestamps between `Starting` and `complete` |
|
||||||
|
| What happened to my election creation? | `backend.services` logs for `Election recorded to blockchain` |
|
||||||
|
| Why are API requests failing? | `backend.routes` logs and `nginx` logs |
|
||||||
|
| Is the database healthy? | `mariadb` logs and connection messages in `backend.main` |
|
||||||
|
|
||||||
|
## Summary
|
||||||
|
|
||||||
|
The enhanced logging provides:
|
||||||
|
- ✓ Clear visibility into system state
|
||||||
|
- ✓ Colored output for easy scanning
|
||||||
|
- ✓ Emoji prefixes for quick identification
|
||||||
|
- ✓ Timestamp and module information
|
||||||
|
- ✓ Full exception details for debugging
|
||||||
|
- ✓ Separate concerns for different modules
|
||||||
|
|
||||||
|
Use the logs to:
|
||||||
|
1. Understand what's happening
|
||||||
|
2. Identify where failures occur
|
||||||
|
3. Debug issues quickly
|
||||||
|
4. Monitor system health
|
||||||
|
5. Track performance
|
||||||
Loading…
x
Reference in New Issue
Block a user