feat: Add comprehensive logging to backend for debugging blockchain and startup

Add structured logging throughout the backend:
- logging_config.py: Centralized logging configuration with colored output
- main.py: Enhanced startup logging showing initialization progress
- init_blockchain.py: Detailed blockchain initialization logging
- services.py: Election creation logging

Logging features:
- Emoji prefixes for different log levels (INFO, DEBUG, ERROR, etc.)
- Color-coded output for better visibility
- Timestamp and module information
- Exception stack traces on errors
- Separate loggers for different modules

This helps debug:
- Backend startup sequence
- Database initialization
- Blockchain election recording
- Service operations
- Configuration issues
This commit is contained in:
Alexis Bruneteau 2025-11-07 03:06:38 +01:00
parent d4ce64f097
commit 7af375f8c0
4 changed files with 219 additions and 49 deletions

View File

@ -5,12 +5,15 @@ This module ensures that when the backend starts, all elections in the database
are recorded to the blockchain if they aren't already.
"""
import logging
from sqlalchemy.orm import Session
from . import models
from .blockchain_elections import elections_blockchain, record_election_to_blockchain
from datetime import datetime
import json
logger = logging.getLogger(__name__)
def initialize_elections_blockchain(db: Session) -> None:
"""
@ -22,20 +25,31 @@ def initialize_elections_blockchain(db: Session) -> None:
Args:
db: Database session
"""
logger.info("-" * 60)
logger.info("Blockchain Initialization Started")
logger.info("-" * 60)
try:
# Get all elections from database
elections = db.query(models.Election).all()
logger.info(f"Found {len(elections)} elections in database")
if not elections:
print("No elections to record to blockchain")
logger.warning("No elections to record to blockchain")
return
# Check which elections are already on blockchain
existing_election_ids = {block.election_id for block in elections_blockchain.blocks}
logger.info(f"Blockchain currently has {len(existing_election_ids)} elections")
# Record each election that isn't already on blockchain
recorded_count = 0
skipped_count = 0
for election in elections:
if election.id in existing_election_ids:
print(f"Election {election.id} already on blockchain, skipping")
logger.debug(f" ⊘ Election {election.id} ({election.name}) already on blockchain")
skipped_count += 1
continue
try:
@ -44,6 +58,8 @@ def initialize_elections_blockchain(db: Session) -> None:
models.Candidate.election_id == election.id
).all()
logger.debug(f" Recording election {election.id} with {len(candidates)} candidates")
candidates_data = [
{
"id": c.id,
@ -55,7 +71,7 @@ def initialize_elections_blockchain(db: Session) -> None:
]
# Record to blockchain
record_election_to_blockchain(
block = record_election_to_blockchain(
election_id=election.id,
election_name=election.name,
election_description=election.description or "",
@ -65,12 +81,37 @@ def initialize_elections_blockchain(db: Session) -> None:
is_active=election.is_active,
creator_id=0 # Database creation, no specific admin
)
print(f"✓ Recorded election {election.id} ({election.name}) to blockchain")
logger.info(
f" ✓ Recorded election {election.id} ({election.name})\n"
f" Block #{block.index}, Hash: {block.block_hash[:16]}..., "
f"Candidates: {block.candidates_count}"
)
recorded_count += 1
except Exception as e:
print(f"✗ Failed to record election {election.id} to blockchain: {e}")
logger.error(
f" ✗ Failed to record election {election.id} ({election.name}): {e}",
exc_info=True
)
logger.info(f"Recording summary: {recorded_count} new, {skipped_count} skipped")
# Verify blockchain integrity
logger.info(f"Verifying blockchain integrity ({len(elections_blockchain.blocks)} blocks)...")
if elections_blockchain.verify_chain_integrity():
print(f"✓ Blockchain integrity verified - {len(elections_blockchain.blocks)} blocks")
logger.info(f"✓ Blockchain integrity verified successfully")
else:
print("✗ Blockchain integrity check failed!")
logger.error("✗ Blockchain integrity check FAILED - possible corruption!")
logger.info("-" * 60)
logger.info(f"Blockchain Initialization Complete")
logger.info(f" Total blocks: {len(elections_blockchain.blocks)}")
logger.info(f" Chain valid: {elections_blockchain.verify_chain_integrity()}")
logger.info("-" * 60)
except Exception as e:
logger.error(
f"Blockchain initialization failed with error: {e}",
exc_info=True
)
raise

View File

@ -0,0 +1,93 @@
"""
Logging configuration for E-Voting Backend.
Provides structured logging with appropriate levels for different modules.
"""
import logging
import sys
from datetime import datetime
# Create custom formatter with emojis and colors
class ColoredFormatter(logging.Formatter):
"""Custom formatter with colors and emojis for better visibility"""
# ANSI color codes
COLORS = {
'DEBUG': '\033[36m', # Cyan
'INFO': '\033[32m', # Green
'WARNING': '\033[33m', # Yellow
'ERROR': '\033[31m', # Red
'CRITICAL': '\033[35m', # Magenta
}
RESET = '\033[0m'
# Emoji prefixes
EMOJIS = {
'DEBUG': '🔍',
'INFO': ' ',
'WARNING': '⚠️ ',
'ERROR': '',
'CRITICAL': '🔥',
}
def format(self, record):
# Add color and emoji
levelname = record.levelname
emoji = self.EMOJIS.get(levelname, '')
color = self.COLORS.get(levelname, '')
# Format message
timestamp = datetime.now().strftime('%Y-%m-%d %H:%M:%S')
formatted = f"{color}{emoji} {timestamp} - {record.name} - {levelname} - {record.getMessage()}{self.RESET}"
# Add exception info if present
if record.exc_info:
formatted += f"\n{self.format_exception(record.exc_info)}"
return formatted
def format_exception(self, exc_info):
"""Format exception info"""
import traceback
return '\n'.join(traceback.format_exception(*exc_info))
def setup_logging(level=logging.INFO):
"""
Setup logging for the entire application.
Args:
level: Logging level (default: logging.INFO)
"""
# Remove existing handlers
root_logger = logging.getLogger()
for handler in root_logger.handlers[:]:
root_logger.removeHandler(handler)
# Create console handler with colored formatter
console_handler = logging.StreamHandler(sys.stdout)
console_handler.setLevel(level)
formatter = ColoredFormatter()
console_handler.setFormatter(formatter)
# Add handler to root logger
root_logger.addHandler(console_handler)
root_logger.setLevel(level)
# Set specific loggers
logging.getLogger('backend').setLevel(level)
logging.getLogger('backend.blockchain_elections').setLevel(logging.DEBUG)
logging.getLogger('backend.init_blockchain').setLevel(logging.INFO)
logging.getLogger('backend.services').setLevel(logging.INFO)
logging.getLogger('backend.main').setLevel(logging.INFO)
# Suppress verbose third-party logging
logging.getLogger('sqlalchemy.engine').setLevel(logging.WARNING)
logging.getLogger('sqlalchemy.pool').setLevel(logging.WARNING)
logging.getLogger('uvicorn').setLevel(logging.INFO)
logging.getLogger('uvicorn.access').setLevel(logging.WARNING)
# Setup logging on import
setup_logging()

View File

@ -2,23 +2,45 @@
Application FastAPI principale.
"""
import logging
from fastapi import FastAPI
from fastapi.middleware.cors import CORSMiddleware
from .config import settings
from .database import init_db, get_db
from .routes import router
from .init_blockchain import initialize_elections_blockchain
from .logging_config import setup_logging
# Setup logging for the entire application
setup_logging(level=logging.INFO)
logger = logging.getLogger(__name__)
logger.info("=" * 70)
logger.info("🚀 Starting E-Voting Backend")
logger.info("=" * 70)
# Initialiser la base de données
logger.info("📦 Initializing database...")
try:
init_db()
logger.info("✓ Database initialized successfully")
except Exception as e:
logger.error(f"✗ Database initialization failed: {e}", exc_info=True)
raise
# Initialiser la blockchain avec les élections existantes
logger.info("⛓️ Initializing blockchain...")
try:
db = next(get_db())
initialize_elections_blockchain(db)
db.close()
logger.info("✓ Blockchain initialization completed")
except Exception as e:
print(f"Warning: Failed to initialize blockchain on startup: {e}")
logger.error(f"⚠️ Blockchain initialization failed (non-fatal): {e}", exc_info=True)
logger.info("=" * 70)
logger.info("✓ Backend initialization complete, starting FastAPI app")
logger.info("=" * 70)
# Créer l'application FastAPI
app = FastAPI(

View File

@ -2,6 +2,7 @@
Service de base de données - Opérations CRUD.
"""
import logging
from sqlalchemy.orm import Session
from sqlalchemy import func
from . import models, schemas
@ -9,6 +10,8 @@ from .auth import hash_password, verify_password
from datetime import datetime
from .blockchain_elections import record_election_to_blockchain
logger = logging.getLogger(__name__)
class VoterService:
"""Service pour gérer les électeurs"""
@ -109,11 +112,15 @@ class ElectionService:
# Record to blockchain immediately after creation
try:
logger.debug(f"Recording election {db_election.id} ({name}) to blockchain")
# Get candidates for this election to include in blockchain record
candidates = db.query(models.Candidate).filter(
models.Candidate.election_id == db_election.id
).all()
logger.debug(f" Found {len(candidates)} candidates for election {db_election.id}")
candidates_data = [
{
"id": c.id,
@ -125,7 +132,7 @@ class ElectionService:
]
# Record election to blockchain
record_election_to_blockchain(
block = record_election_to_blockchain(
election_id=db_election.id,
election_name=name,
election_description=description,
@ -135,9 +142,16 @@ class ElectionService:
is_active=is_active,
creator_id=creator_id
)
logger.info(
f"✓ Election {db_election.id} recorded to blockchain "
f"(Block #{block.index}, Hash: {block.block_hash[:16]}...)"
)
except Exception as e:
# Log error but don't fail election creation
print(f"Warning: Could not record election {db_election.id} to blockchain: {e}")
logger.error(
f"Warning: Could not record election {db_election.id} to blockchain: {e}",
exc_info=True
)
return db_election