better logging resolves #6

Dockerfile

@@ -34,6 +34,8 @@ ENV PYTHONUNBUFFERED=1
 ENV NVIDIA_VISIBLE_DEVICES=GPU-25f5d0be-15d5-fcff-be10-c1afca13d69a
 ENV NVIDIA_DRIVER_CAPABILITIES=all
 ENV DATA_DIRECTORY=/app/data
+ENV LOG_LEVEL=INFO
+ENV VERBOSE=false
 
 # Create data directory and set permissions
 RUN mkdir -p $DATA_DIRECTORY && \

backend/app/common/download_helper.py

@@ -1,8 +1,13 @@
 import aiohttp
-import logging
 import os
-
-logger = logging.getLogger(__name__)
+from app.common.logger import Logger
+
+logger = Logger(
+    "ISeeTV-DownloadHelper",
+    os.environ.get("VERBOSE", "false"),
+    os.environ.get("LOG_LEVEL", "INFO"),
+    color="LIGHT_BLUE",
+)
 
 
 async def stream_download(url: str, expected_size: int, output_file: str):

backend/app/common/logger.py

@@ -0,0 +1,80 @@
+import os
+import sys
+import logging
+
+
+class ColorFormatter(logging.Formatter):
+    COLORS = {
+        "GREY": "38;5;241m",  # Darker grey
+        "YELLOW": "38;5;130m",  # Darker yellow
+        "RED": "38;5;124m",  # Darker red
+        "LIGHT_GREEN": "38;5;118m",  # Light green
+        "GREEN": "38;5;28m",  # Darker green
+        "LIGHT_BLUE": "38;5;117m",  # Light blue
+        "BLUE": "38;5;25m",  # Darker blue
+    }
+
+    START = "\x1b["
+    END = "\x1b[0m"
+
+    def __init__(self, fmt, color, log_level):
+        super().__init__()
+        self.fmt = fmt
+        self.color = self.COLORS[color]
+
+        # use red color
+        if log_level in ["WARNING", "ERROR", "CRITICAL"]:
+            self.color = self.START + self.COLORS["RED"] + self.fmt + self.END
+        else:
+            self.color = self.START + self.color + self.fmt + self.END
+
+    def format(self, record):
+        formatter = logging.Formatter(self.color, datefmt="%Y-%m-%d %H:%M:%S")
+        return formatter.format(record)
+
+
+class Logger:
+    COLORS = ColorFormatter.COLORS
+
+    def __init__(
+        self,
+        name: str,
+        verbose: bool,
+        log_level: str,
+        color: str = "GREY",
+    ):
+        self.logger = logging.getLogger(name)
+        self.verbose = verbose.lower() == "true"
+        self.log_level = log_level.upper()
+        self.name = name
+
+        formatter = ColorFormatter(
+            fmt=self.message_format(), color=color, log_level=log_level
+        )
+
+        handler = logging.StreamHandler(sys.stdout)
+        handler.setFormatter(formatter)
+
+        self.logger.setLevel(log_level)
+        self.logger.addHandler(handler)
+
+    def message_format(self):
+        if self.verbose:
+            return "%(name)s | %(levelname)s: %(asctime)s - %(filename)s:%(module)s:%(lineno)d - %(message)s"
+        else:
+            return "%(name)s | %(levelname)s: %(asctime)s - %(message)s"
+
+    def debug(self, message: str):
+        self.logger.debug(message)
+
+    def info(self, message: str):
+        self.logger.info(message)
+
+    def warning(self, message: str):
+        self.logger.warning(message)
+
+    def error(self, message: str):
+        self.logger.error(message)
+
+    def critical(self, message: str):
+        self.logger.critical(message)

backend/app/common/utils.py

@@ -1,4 +1,3 @@
-import hashlib
 import re
 
 

backend/app/main.py

@@ -7,7 +7,7 @@
 from app import models, database
 from typing import Optional, Dict, Tuple
 from pydantic import BaseModel
-import logging
+from app.common.logger import Logger
 import sys
 import datetime
 from .services.m3u_service import M3UService
@@ -38,14 +38,13 @@
 from ffmpeg_streaming import Formats
 
 
-logging.basicConfig(
-    level=logging.INFO,
-    format="%(levelname)s: %(asctime)s - %(message)s",
-    handlers=[logging.StreamHandler(sys.stdout)],
+logger = Logger(
+    name="ISeeTV-Backend",
+    verbose=os.environ.get("VERBOSE", "false"),
+    log_level=os.environ.get("LOG_LEVEL", "INFO"),
+    color="YELLOW",
 )
 
-logger = logging.getLogger(__name__)
-
 DATA_DIRECTORY = os.environ.get("DATA_DIRECTORY")
 CONFIG_FILE = os.path.join(DATA_DIRECTORY, "config.json")
 
@@ -470,7 +469,7 @@ async def get_channel_groups(db: AsyncSession = Depends(get_db)):
 async def stream_channel(
     guide_id: str,
     db: AsyncSession = Depends(get_db),
-    timeout: int = 10,
+    timeout: int = 30,
 ):
     result = await db.execute(
         select(models.Channel).where(models.Channel.guide_id == guide_id)
@@ -508,12 +507,20 @@ async def stream_channel(
                 cleanup_channel_resources(existing_channel)
 
         # Wait for the manifest to be ready
+        # However, if the channel directory is deleted, this indicates that the stream was stopped
         x = 0
         while True:
             logger.info(
                 f"Waiting for manifest creation for channel {guide_id}{'.' * ((x%3) + 1)}"
             )
-            if os.path.exists(output_m3u8):
+            if not os.path.exists(channel_dir):
+                msg = "Channel directory not found, likely the stream was manually stopped"
+                logger.info(msg)
+                raise HTTPException(
+                    status_code=404,
+                    detail=msg,
+                )
+            elif os.path.exists(output_m3u8):
                 break
             else:
                 await asyncio.sleep(1)

backend/app/services/epg_service.py

@@ -1,4 +1,4 @@
-import logging
+from app.common.logger import Logger
 import sys
 import os
 from pathlib import Path
@@ -11,14 +11,13 @@
 import re
 import hashlib
 
-logging.basicConfig(
-    level=logging.INFO,
-    format="%(levelname)s: %(asctime)s - %(message)s",
-    handlers=[logging.StreamHandler(sys.stdout)],
+logger = Logger(
+    "ISeeTV-EPGService",
+    os.environ.get("VERBOSE", "false"),
+    os.environ.get("LOG_LEVEL", "INFO"),
+    color="LIGHT_GREEN",
 )
 
-logger = logging.getLogger(__name__)
-
 
 class EPGService:
     def __init__(self, config: dict):

backend/app/services/m3u_service.py

@@ -4,21 +4,20 @@
 import hashlib
 import sys
 import os
-import logging
+from app.common.logger import Logger
 from pathlib import Path
 from datetime import datetime
 import math
 from ..common.download_helper import stream_download
 from ..common.utils import generate_channel_id
 
-logging.basicConfig(
-    level=logging.INFO,
-    format="%(levelname)s: %(asctime)s - %(message)s",
-    handlers=[logging.StreamHandler(sys.stdout)],
+logger = Logger(
+    "ISeeTV-M3UService",
+    os.environ.get("VERBOSE", "false"),
+    os.environ.get("LOG_LEVEL", "INFO"),
+    color="GREEN",
 )
 
-logger = logging.getLogger(__name__)
-
 
 class M3UService:
     def __init__(self, config: dict):

backend/app/video_helpers.py

@@ -1,18 +1,17 @@
 import threading
-import logging
+from app.common.logger import Logger
 import sys
 import os
 import requests
 import subprocess
 
-logging.basicConfig(
-    level=logging.INFO,
-    format="%(levelname)s: %(asctime)s - %(message)s",
-    handlers=[logging.StreamHandler(sys.stdout)],
+logger = Logger(
+    "ISeeTV-VideoHelpers",
+    os.environ.get("VERBOSE", "false"),
+    os.environ.get("LOG_LEVEL", "INFO"),
+    color="LIGHT_BLUE",
 )
 
-logger = logging.getLogger(__name__)
-
 
 def dict_to_ffmpeg_command(params: dict) -> list:
     command = ["ffmpeg"]
@@ -33,14 +32,21 @@ def __init__(self, process: subprocess.Popen):
         self.process = process
         self.stop_flag = False
         self._thread = None
-        self.logger = logging.getLogger(__name__)
+        self.logger = Logger(
+            "ISeeTV-StreamMonitor",
+            os.environ.get("VERBOSE", "false"),
+            os.environ.get("LOG_LEVEL", "INFO"),
+            color="BLUE",
+        )
 
     def start(self):
+        self.logger.info("Starting stream monitor")
         self._thread = threading.Thread(target=self._monitor)
         self._thread.daemon = True
         self._thread.start()
 
     def stop(self):
+        self.logger.info("Stopping stream monitor")
         self.stop_flag = True
         if self.process:
             try:
@@ -103,6 +109,7 @@ async def process_video(
     }
 
     command_list = dict_to_ffmpeg_command(ffmpeg_params)
+    logger.debug(f"FFmpeg command: {command_list}")
 
     # Create process with full stderr logging
     process = subprocess.Popen(

data/init_db.py

@@ -1,25 +1,22 @@
 import sqlite3
+import os
 import logging
 
-# Configure logging
-logging.basicConfig(
-    level=logging.INFO,
-    format="%(levelname)s: %(asctime)s - %(message)s",
+logger = logging.getLogger("ISeeTV-InitDB")
+logger.setLevel(os.environ.get("LOG_LEVEL", "INFO"))
+logger.setFormatter(
+    logging.Formatter("%(name)s | %(levelname)s: %(asctime)s - %(message)s")
 )
-logger = logging.getLogger(__name__)
 
 try:
+    # # for development purposes, delete the  entire database
+    # logger.warning("Deleting database...")
+    # os.remove("/app/data/sql_app.db")
+
     logger.info("Connecting to database...")
     conn = sqlite3.connect("/app/data/sql_app.db")
     cursor = conn.cursor()
 
-    # # For development purposes, drop existing tables if they exist
-    # logger.info("Dropping existing tables...")
-    # cursor.execute("DROP TABLE IF EXISTS channels")
-    # cursor.execute("DROP TABLE IF EXISTS channel_streams")
-    # cursor.execute("DROP TABLE IF EXISTS epg_channels")
-    # cursor.execute("DROP TABLE IF EXISTS programs")
-
     logger.info("Creating channels table...")
     cursor.execute(
         """CREATE TABLE IF NOT EXISTS channels (

frontend/src/components/VideoPlayer.tsx

@@ -60,13 +60,16 @@ export const VideoPlayer: React.FC<VideoPlayerProps> = ({ url, channel }) => {
 
           const proxyUrl = `${API_URL}/stream/${channel.guide_id}`;
           const hls = new Hls({
+            // API reference: https://github.com/video-dev/hls.js/blob/master/docs/API.md
             maxBufferLength: Infinity,  // the maximum number of seconds to buffer
-            maxMaxBufferLength: Infinity,  // allow up to 120 seconds
+            maxMaxBufferLength: Infinity,
+            backBufferLength: 120, // allow up to 120 seconds
+            frontBufferFlushThreshold: 60, // in-memory buffer flush threshold in seconds
             manifestLoadingMaxRetry: 10,
             manifestLoadingRetryDelay: 500,  // retry every X milliseconds
             levelLoadingMaxRetry: 5,  // Retry level loading X times
             enableWorker: true,
-            liveDurationInfinity: true,  // Indicates it's a live stream
+            liveDurationInfinity: false,  // Indicates it's a live stream, but cannot go forward in the stream if we've ever paused
           });
 
           hlsRef.current = hls;