feat: Add comprehensive logging

- Add rotating file logging to /var/log/gatekeeper.log
- Log application events, MQTT, settings, and errors
- Include stack traces and improved error handling

backend/main.py

@@ -12,14 +12,42 @@ from typing import List, Optional
 import logging
 import json
 from mqtt_integration import HomeAssistantMQTT
-
+import sys
 
 # Configure logging
-logging.basicConfig(
+LOG_FILE = "/var/log/gatekeeper.log"
-    level=logging.INFO,
+logger = logging.getLogger("gatekeeper")
-    format='%(asctime)s - %(name)s - %(levelname)s - %(message)s'
+logger.setLevel(logging.INFO)
+
+# Create rotating file handler (10MB per file, keep 5 backup files)
+file_handler = RotatingFileHandler(
+    LOG_FILE,
+    maxBytes=10*1024*1024,  # 10MB
+    backupCount=5,
+    delay=True  # Only create log file when first record is written
 )
-logger = logging.getLogger(__name__)
+file_handler.setLevel(logging.INFO)
+
+# Create formatter and add it to the handler
+formatter = logging.Formatter(
+    '%(asctime)s - %(name)s - %(levelname)s - %(message)s',
+    datefmt='%Y-%m-%d %H:%M:%S'
+)
+file_handler.setFormatter(formatter)
+
+# Add the handler to the logger
+logger.addHandler(file_handler)
+
+# Log uncaught exceptions
+def handle_exception(exc_type, exc_value, exc_traceback):
+    if issubclass(exc_type, KeyboardInterrupt):
+        # Call the default handler for keyboard interrupt
+        sys.__excepthook__(exc_type, exc_value, exc_traceback)
+        return
+    logger.error("Uncaught exception", exc_info=(exc_type, exc_value, exc_traceback))
+
+# Install exception handler
+sys.excepthook = handle_exception
 
 # Initialize FastAPI
 app = FastAPI()
@@ -27,8 +55,9 @@ ha_mqtt = HomeAssistantMQTT()
 
 # Set up MQTT event logging
 async def log_mqtt_event(action: str, success: bool = True):
-    """Log MQTT events to the database"""
+    """Log MQTT events to the database and log file"""
-    async with aiosqlite.connect(DB_PATH) as db:
+    logger.info(f"MQTT Event - {action} (Success: {success})")
+    async with aiosqlite.connect("gate.db") as db:
         await db.execute(
             "INSERT INTO events (timestamp, action, source, success) VALUES (?, ?, ?, ?)",
             (datetime.utcnow().isoformat(), action, "MQTT", success)
@@ -402,36 +431,48 @@ app.mount("/", StaticFiles(directory="../public", html=True), name="static")
 @app.on_event("startup")
 async def startup_event():
     """Initialize the application on startup"""
-    # Initialize database
+    logger.info("Starting Gatekeeper application")
-    await init_db()
-    
-    # Setup GPIO
-    setup_gpio()
-    
-    # Start background tasks
-    app.state.status_task = asyncio.create_task(update_gate_status())
-    app.state.auto_close_task = asyncio.create_task(check_auto_close())
-    
-    # Initialize MQTT from settings
     try:
+        # Initialize database
+        await init_db()
+        logger.info("Database initialized successfully")
+
+        # Setup GPIO
+        setup_gpio()
+        logger.info("GPIO initialized successfully")
+
+        # Initialize MQTT from settings
         settings = await get_settings()
-        if settings["mqtt"].get("enabled"):
+        if settings.mqtt and settings.mqtt.get("enabled"):
-            ha_mqtt.enable(True)
+            logger.info("MQTT enabled in settings, initializing connection")
+            ha_mqtt.enable()
+        else:
+            logger.info("MQTT disabled in settings")
+
+        # Start background tasks
+        app.state.status_task = asyncio.create_task(update_gate_status())
+        app.state.auto_close_task = asyncio.create_task(check_auto_close())
     except Exception as e:
-        logger.error(f"Failed to initialize MQTT: {e}")
+        logger.error(f"Startup error: {str(e)}", exc_info=True)
+        raise
 
 @app.on_event("shutdown")
 async def shutdown_event():
-    """Clean up on shutdown"""
+    """Cleanup on shutdown"""
-    # Cancel background tasks
+    logger.info("Shutting down Gatekeeper application")
-    if hasattr(app.state, "status_task"):
+    try:
-        app.state.status_task.cancel()
+        # Cancel background tasks
-    if hasattr(app.state, "auto_close_task"):
+        if hasattr(app.state, "status_task"):
-        app.state.auto_close_task.cancel()
+            app.state.status_task.cancel()
+        if hasattr(app.state, "auto_close_task"):
+            app.state.auto_close_task.cancel()
         
-    # Disconnect MQTT
+        # Disconnect MQTT
-    await ha_mqtt.disconnect()
+        await ha_mqtt.disconnect()
         
-    # Cleanup GPIO
+        # Cleanup GPIO
-    GPIO.cleanup()
+        GPIO.cleanup()
-    logger.info("Application shutdown complete")
+        logger.info("Cleanup completed successfully")
+    except Exception as e:
+        logger.error(f"Shutdown error: {str(e)}", exc_info=True)
+        raise

backend/mqtt_integration.py

@@ -1,11 +1,12 @@
 import os
 import json
 import asyncio
-import logging
-from gmqtt import Client as MQTTClient
 from typing import Optional, Callable
+from gmqtt import Client as MQTTClient
+import logging
 
-logger = logging.getLogger(__name__)
+# Get logger
+logger = logging.getLogger("gatekeeper")
 
 class HomeAssistantMQTT:
     def __init__(self):
@@ -16,6 +17,8 @@ class HomeAssistantMQTT:
         self.password = os.getenv("MQTT_PASSWORD", None)
         self.client_id = os.getenv("MQTT_CLIENT_ID", "gatekeeper")
         
+        logger.info(f"Initializing MQTT client (broker: {self.broker}:{self.port}, client_id: {self.client_id})")
+        
         # Home Assistant MQTT topics
         self.node_id = "gatekeeper"
         self.object_id = "gate"
@@ -26,6 +29,8 @@ class HomeAssistantMQTT:
         self.config_topic = f"homeassistant/cover/{self.node_id}/{self.object_id}/config"
         self.availability_topic = f"homeassistant/cover/{self.node_id}/{self.object_id}/availability"
         
+        logger.debug(f"MQTT topics configured - State: {self.state_topic}, Command: {self.command_topic}")
+        
         self.client: Optional[MQTTClient] = None
         self.command_callback: Optional[Callable] = None
         self._connected = False
@@ -63,53 +68,77 @@ class HomeAssistantMQTT:
         while self._enabled:
             try:
                 if not self._connected:
+                    logger.info("Attempting to reconnect to MQTT broker...")
                     await self.connect()
-                await asyncio.sleep(5)  # Wait before checking connection again
+                await asyncio.sleep(5)
-            except asyncio.CancelledError:
-                break
             except Exception as e:
                 logger.error(f"Reconnection attempt failed: {e}")
-                await asyncio.sleep(5)  # Wait before retrying
+                await asyncio.sleep(5)
 
     def on_connect(self, client, flags, rc, properties):
         """Callback for when connection is established"""
-        logger.info("Connected to MQTT broker")
+        logger.info(f"Connected to MQTT broker (rc: {rc})")
         self._connected = True
-        asyncio.create_task(self._log_event("MQTT Connected"))
         asyncio.create_task(self._post_connect())
 
     def on_message(self, client, topic, payload, qos, properties):
         """Callback for when a message is received"""
-        if topic == self.command_topic and self.command_callback:
+        try:
-            try:
+            logger.debug(f"MQTT message received - Topic: {topic}, Payload: {payload}")
+            if topic == self.command_topic and self.command_callback:
                 command = payload.decode()
+                logger.info(f"MQTT command received: {command}")
                 asyncio.create_task(self.command_callback(command))
-            except Exception as e:
+        except Exception as e:
-                logger.error(f"Error processing command: {e}")
+            logger.error(f"Error processing MQTT message: {e}", exc_info=True)
 
     def on_disconnect(self, client, packet, exc=None):
         """Callback for when connection is lost"""
-        logger.info("Disconnected from MQTT broker")
+        logger.warning(f"Disconnected from MQTT broker{f': {exc}' if exc else ''}")
         self._connected = False
-        # Log disconnect event
-        asyncio.create_task(self._log_event("MQTT Disconnected"))
-        # Start reconnection if enabled
         if self._enabled and not self._reconnect_task:
             self._reconnect_task = asyncio.create_task(self._reconnect_loop())
 
     async def _post_connect(self):
-        """Tasks to run after connection is established"""
+        """Tasks to perform after connection is established"""
         try:
-            # Send Home Assistant discovery configuration
-            await self.publish_discovery_config()
-            
-            # Publish availability status
-            await self.publish(self.availability_topic, "online", retain=True)
-            
             # Subscribe to command topic
-            await self.subscribe(self.command_topic)
+            await self.client.subscribe([(self.command_topic, 1)])
+            logger.info(f"Subscribed to command topic: {self.command_topic}")
+            
+            # Publish discovery config
+            config = {
+                "name": "Gate",
+                "unique_id": f"{self.node_id}_{self.object_id}",
+                "device_class": "gate",
+                "command_topic": self.command_topic,
+                "state_topic": self.state_topic,
+                "availability_topic": self.availability_topic,
+                "payload_open": "OPEN",
+                "payload_close": "CLOSE",
+                "state_open": "open",
+                "state_closed": "closed"
+            }
+            
+            await self.client.publish(
+                self.config_topic,
+                json.dumps(config),
+                qos=1,
+                retain=True
+            )
+            logger.info("Published Home Assistant discovery config")
+            
+            # Publish initial availability
+            await self.client.publish(
+                self.availability_topic,
+                "online",
+                qos=1,
+                retain=True
+            )
+            logger.info("Published initial availability state")
+            
         except Exception as e:
-            logger.error(f"Error in post-connect tasks: {e}")
+            logger.error(f"Error in post-connect setup: {e}", exc_info=True)
 
     async def connect(self):
         """Connect to MQTT broker"""
@@ -137,7 +166,12 @@ class HomeAssistantMQTT:
         """Disconnect from MQTT broker"""
         if self.client and self._connected:
             try:
-                await self.publish(self.availability_topic, "offline", retain=True)
+                await self.client.publish(
+                    self.availability_topic,
+                    "offline",
+                    qos=1,
+                    retain=True
+                )
                 await self.client.disconnect()
             except Exception as e:
                 logger.error(f"Error during disconnect: {e}")
@@ -158,41 +192,10 @@ class HomeAssistantMQTT:
             except Exception as e:
                 logger.error(f"Failed to subscribe to topic: {e}")
 
-    async def publish_discovery_config(self):
+    async def publish_state(self, state: str):
-        """Publish Home Assistant MQTT discovery configuration"""
+        """Publish gate state"""
-        config = {
+        await self.publish(self.state_topic, state)
-            "name": "Gate",
-            "unique_id": f"{self.node_id}_{self.object_id}",
-            "device_class": "gate",
-            "command_topic": self.command_topic,
-            "state_topic": self.state_topic,
-            "availability_topic": self.availability_topic,
-            "payload_available": "online",
-            "payload_not_available": "offline",
-            "payload_open": "OPEN",
-            "payload_close": "CLOSE",
-            "payload_stop": "STOP",
-            "state_open": "open",
-            "state_closed": "closed",
-            "state_opening": "opening",
-            "state_closing": "closing",
-            "device": {
-                "identifiers": [self.node_id],
-                "name": "Gate Keeper",
-                "model": "DLB Gate Controller",
-                "manufacturer": "Athena Networks",
-            }
-        }
-        
-        try:
-            await self.publish(self.config_topic, json.dumps(config), retain=True)
-        except Exception as e:
-            logger.error(f"Failed to publish discovery config: {e}")
 
     def set_command_callback(self, callback: Callable):
         """Set callback for handling commands"""
         self.command_callback = callback
-
-    async def publish_state(self, state: str):
-        """Publish gate state"""
-        await self.publish(self.state_topic, state)