CIA/e-voting-system/LOGGING_GUIDE.md
Alexis Bruneteau 7b9d6d0407 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
2025-11-07 03:07:05 +01:00

390 lines
9.9 KiB
Markdown
Raw Blame History

This file contains invisible Unicode characters

This file contains invisible Unicode characters that are indistinguishable to humans but may be processed differently by a computer. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.

This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.

# 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