transcode.py: add logging

transcode.py

@@ -10,6 +10,7 @@ import time
 import sys
 import subprocess
 import os
+import logging
 from pathlib import Path
 from watchdog.observers import Observer
 from watchdog.events import FileSystemEventHandler
@@ -17,13 +18,45 @@ from watchdog.events import FileSystemEventHandler
 # Supported video extensions to monitor
 VIDEO_EXTENSIONS = {'.mkv', '.mp4', '.avi', '.mov', '.wmv', '.flv', '.webm', '.m4v', '.ts'}
 
+def setup_logging():
+    """
+    Sets up logging to both console (INFO) and file (DEBUG/Verbose).
+    Log file is stored in $XDG_CONFIG_HOME/transcoder/transcoder.log
+    """
+    # Determine config directory
+    xdg_config = os.environ.get('XDG_CONFIG_HOME', os.path.expanduser('~/.config'))
+    log_dir = Path(xdg_config) / "transcoder"
+    log_dir.mkdir(parents=True, exist_ok=True)
+    log_file = log_dir / "transcoder.log"
+
+    # Create logger
+    logger = logging.getLogger()
+    logger.setLevel(logging.DEBUG) # Capture everything
+
+    # formatter
+    formatter = logging.Formatter('%(asctime)s - %(levelname)s - %(message)s')
+
+    # File Handler (Verbose)
+    file_handler = logging.FileHandler(log_file)
+    file_handler.setLevel(logging.DEBUG)
+    file_handler.setFormatter(formatter)
+    logger.addHandler(file_handler)
+
+    # Console Handler (Concise)
+    console_handler = logging.StreamHandler(sys.stdout)
+    console_handler.setLevel(logging.INFO)
+    console_handler.setFormatter(logging.Formatter('[%(levelname)s] %(message)s'))
+    logger.addHandler(console_handler)
+
+    logging.info(f"Logging started. Verbose logs at: {log_file}")
+
 def get_ffmpeg_command(input_path, output_path):
     """
     Constructs the FFmpeg command based on the Handbrake preset requirements.
     """
-    return [
+    cmd = [
         "ffmpeg",
-        "-n",                  # Never overwrite output files (extra safety)
+        "-n",                  # Never overwrite output files
         "-i", str(input_path), # Input file
         "-c:v", "av1_nvenc",   # Video Encoder
         "-pix_fmt", "p010le",  # 10-bit color
@@ -39,42 +72,58 @@ def get_ffmpeg_command(input_path, output_path):
         "-movflags", "+faststart", # Web optimization
         str(output_path)       # Output file
     ]
+    return cmd
 
 def transcode_file(input_file, output_file):
     input_path = Path(input_file)
     output_path = Path(output_file)
 
+    logging.debug(f"Processing request: {input_path} -> {output_path}")
+
     # 1. Check existence logic
     if output_path.exists():
-        print(f"[SKIP] Output file already exists: {output_path.name}")
+        logging.info(f"SKIP: Output file already exists: {output_path.name}")
         return
 
     # 2. Check if file is ready (simple size stability check)
-    # This prevents transcoding files that are still being copied into the folder
+    logging.info(f"WAIT: Ensuring file is ready: {input_path.name}...")
-    print(f"[WAIT] Ensuring file is ready: {input_path.name}...")
     try:
         historical_size = -1
         while True:
             current_size = input_path.stat().st_size
+            logging.debug(f"File stability check - Current: {current_size}, Previous: {historical_size}")
+            
             if current_size == historical_size and current_size > 0:
+                logging.debug("File size stable. Proceeding.")
                 break
+            
             historical_size = current_size
-            time.sleep(2) # Wait 2 seconds between checks
+            time.sleep(2) 
     except FileNotFoundError:
-        return # File was deleted before we could process it
+        logging.warning(f"File vanished during checks: {input_path.name}")
+        return
 
-    print(f"[START] Transcoding: {input_path.name} -> {output_path.name}")
+    logging.info(f"START: Transcoding {input_path.name}")
     
     cmd = get_ffmpeg_command(input_path, output_path)
+    logging.debug(f"Executing FFmpeg command: {' '.join(cmd)}")
     
     try:
         # Run FFmpeg
-        subprocess.run(cmd, check=True)
+        # We capture output to prevent FFmpeg spamming the console, but log it on error
-        print(f"[DONE] Successfully created: {output_path.name}")
+        result = subprocess.run(cmd, capture_output=True, text=True)
-    except subprocess.CalledProcessError as e:
+        
-        print(f"[ERROR] FFmpeg failed for {input_path.name}")
+        if result.returncode == 0:
+            logging.info(f"DONE: Successfully created {output_path.name}")
+            logging.debug(f"FFmpeg stdout: {result.stdout}")
+        else:
+            logging.error(f"FFmpeg failed for {input_path.name}")
+            logging.error(f"FFmpeg stderr: {result.stderr}")
+
+    except Exception as e:
+        logging.exception(f"Unexpected error during transcoding of {input_path.name}")
     except KeyboardInterrupt:
-        print("\n[STOP] Interrupted by user.")
+        logging.warning("Interrupted by user during transcoding.")
         sys.exit(0)
 
 class NewFileHandler(FileSystemEventHandler):
@@ -84,11 +133,13 @@ class NewFileHandler(FileSystemEventHandler):
     def on_created(self, event):
         if event.is_directory:
             return
+        logging.debug(f"Watchdog event (created): {event.src_path}")
         self.process(event.src_path)
 
     def on_moved(self, event):
         if event.is_directory:
             return
+        logging.debug(f"Watchdog event (moved): {event.dest_path}")
         self.process(event.dest_path)
 
     def process(self, file_path_str):
@@ -96,19 +147,19 @@ class NewFileHandler(FileSystemEventHandler):
         
         # Filter for video extensions
         if input_path.suffix.lower() not in VIDEO_EXTENSIONS:
+            logging.debug(f"Ignored non-video file: {input_path.name}")
             return
 
-        # Determine output path
-        # We rename the file to avoid conflicts if input/output dirs are same (though not recommended)
         new_filename = input_path.stem + ".mp4"
         output_path = self.output_dir / new_filename
 
         transcode_file(input_path, output_path)
 
 def main():
+    setup_logging()
+    
     parser = argparse.ArgumentParser(description="Nvidia AV1 Transcoder & Watcher")
     
-    # Mutually exclusive group for modes
     group = parser.add_mutually_exclusive_group(required=True)
     group.add_argument("--input", type=str, help="Single file to transcode")
     group.add_argument("--watch-dir", type=str, help="Directory to monitor for new files")
@@ -121,10 +172,9 @@ def main():
     if args.input:
         input_path = Path(args.input)
         if not input_path.exists():
-            print(f"Error: Input file '{args.input}' not found.")
+            logging.critical(f"Input file '{args.input}' not found.")
             sys.exit(1)
         
-        # If output dir provided, use it. Otherwise use source folder + _av1 suffix
         if args.output_dir:
             out_dir = Path(args.output_dir)
             out_dir.mkdir(parents=True, exist_ok=True)
@@ -137,22 +187,21 @@ def main():
     # --- Mode 2: Watch Directory ---
     elif args.watch_dir:
         if not args.output_dir:
-            print("Error: --output-dir is required when using --watch-dir")
+            logging.critical("--output-dir is required when using --watch-dir")
             sys.exit(1)
 
         watch_dir = Path(args.watch_dir)
         output_dir = Path(args.output_dir)
 
         if not watch_dir.exists():
-            print(f"Error: Watch directory '{watch_dir}' does not exist.")
+            logging.critical(f"Watch directory '{watch_dir}' does not exist.")
             sys.exit(1)
         
-        # Create output dir if it doesn't exist
         output_dir.mkdir(parents=True, exist_ok=True)
 
-        print(f"Monitoring {watch_dir}...")
+        logging.info(f"Monitoring {watch_dir}...")
-        print(f"Outputting to {output_dir}")
+        logging.info(f"Outputting to {output_dir}")
-        print("Press Ctrl+C to stop.")
+        logging.info("Press Ctrl+C to stop.")
 
         event_handler = NewFileHandler(output_dir)
         observer = Observer()
@@ -163,6 +212,7 @@ def main():
             while True:
                 time.sleep(1)
         except KeyboardInterrupt:
+            logging.info("Stopping observer...")
             observer.stop()
         observer.join()