Add proper logging

generate_gallery.py

@@ -17,12 +17,15 @@ import subprocess
 import shutil
 import os
 import sys
+import argparse
+import time
 from pathlib import Path
 from typing import Dict, Any, Optional
 from datetime import datetime
 from jinja2 import Environment, FileSystemLoader
 
 from orchestration.config import Config
+from orchestration.logger import GalleryLogger
 from orchestration.metadata import (
     load_folder_metadata,
     merge_metadata,
@@ -51,7 +54,7 @@ env.filters['strftime'] = strftime_filter
 template = env.get_template("templates/gallery.html")
 
 
-def convert_pdf_to_png(pdf_path: Path) -> None:
+def convert_pdf_to_png(pdf_path: Path, logger: GalleryLogger) -> None:
     """
     Convert a PDF file to PNG format using ImageMagick.
 
@@ -60,28 +63,42 @@ def convert_pdf_to_png(pdf_path: Path) -> None:
 
     Args:
         pdf_path: Path to the source PDF file
+        logger: Logger instance for output
 
     Raises:
         subprocess.CalledProcessError: If ImageMagick conversion fails
     """
     png_path = pdf_path.with_suffix(".png")
 
+    # Check if conversion is needed
     if png_path.exists():
         pdf_mtime = pdf_path.stat().st_mtime
         png_mtime = png_path.stat().st_mtime
         if png_mtime >= (pdf_mtime + 30):
+            logger.skipped_pdf(pdf_path.name)
             return
         else:
-            print(f"PDF {pdf_path.name} is newer than PNG, reconverting...")
+            logger.debug(f"PDF {pdf_path.name} is newer than PNG, reconverting...")
 
-    print(f"Converting\n\t{pdf_path}\n  → {png_path}")
-    subprocess.run([
-        "convert",
-        "-density", str(CONFIG.png_dpi),
-        str(pdf_path),
-        "-quality", "95",
-        str(png_path)
-    ], check=True)
+    # Perform conversion
+    start_time = time.time()
+    logger.debug(f"Converting {pdf_path} → {png_path}")
+    
+    try:
+        subprocess.run([
+            "convert",
+            "-density", str(CONFIG.png_dpi),
+            str(pdf_path),
+            "-quality", "95",
+            str(png_path)
+        ], check=True)
+        
+        duration = time.time() - start_time
+        logger.converted_pdf(pdf_path.name, duration)
+        
+    except subprocess.CalledProcessError as e:
+        logger.error(f"Failed to convert {pdf_path.name}: {e}")
+        raise
 
 
 def needs_update(source_file: Path, target_file: Path) -> bool:
@@ -106,7 +123,8 @@ def needs_update(source_file: Path, target_file: Path) -> bool:
 
 def build_gallery(source_dir: Path, web_dir: Path,
                   relative_path: Path = None,
-                  inherited_metadata: Optional[Dict[str, Any]] = None) -> None:
+                  inherited_metadata: Optional[Dict[str, Any]] = None,
+                  logger: Optional[GalleryLogger] = None) -> None:
     """
     Recursively build gallery structure from source directory.
 
@@ -119,21 +137,39 @@ def build_gallery(source_dir: Path, web_dir: Path,
         web_dir: Target web directory for gallery output
         relative_path: Relative path from gallery root (for navigation)
         inherited_metadata: Metadata inherited from parent directories
+        logger: Logger instance for output
     """
     if relative_path is None:
         relative_path = Path(".")
     
     if inherited_metadata is None:
         inherited_metadata = {}
+        
+    if logger is None:
+        logger = GalleryLogger()
 
     # Load folder-level metadata and merge with inherited metadata
     folder_metadata = load_folder_metadata(source_dir)
     current_metadata = merge_metadata(inherited_metadata, folder_metadata)
+    
+    # Log metadata discovery
+    if folder_metadata:
+        metadata_file_path = get_metadata_file_path(source_dir)
+        metadata_path = Path(metadata_file_path)
+        if metadata_path.exists():
+            logger.found_metadata(metadata_path.name, len(folder_metadata))
 
     pdf_files = list(source_dir.glob("*.pdf"))
-
     subdirs = [d for d in source_dir.iterdir() if d.is_dir()]
 
+    # Log directory discovery
+    if pdf_files:
+        logger.found_directory(source_dir.name if source_dir.name else "root", len(pdf_files))
+    
+    # Log individual PDF discovery in verbose mode
+    for pdf_file in pdf_files:
+        logger.found_pdf(pdf_file.name)
+
     items = []
     plot_metadata_cache = {}
 
@@ -143,20 +179,22 @@ def build_gallery(source_dir: Path, web_dir: Path,
         web_pdf = web_dir / pdf_file.name
         web_png = web_dir / png_file.name
 
+        # Copy PDF if needed
         if needs_update(pdf_file, web_pdf):
-            print(f"Copying\n\t{pdf_file}\n  → {web_pdf}")
+            logger.debug(f"Copying {pdf_file} to {web_pdf}")
             shutil.copy2(pdf_file, web_pdf)
         else:
-            print(f"Skipping {pdf_file.name} (up to date)")
+            logger.debug(f"Skipping {pdf_file.name} (PDF up to date)")
 
+        # Convert PDF to PNG if needed
         if not png_file.exists():
-            convert_pdf_to_png(pdf_file)
+            convert_pdf_to_png(pdf_file, logger)
 
         if needs_update(png_file, web_png):
-            print(f"Copying {png_file} to {web_png}")
+            logger.debug(f"Copying {png_file} to {web_png}")
             shutil.copy2(png_file, web_png)
         else:
-            print(f"Skipping {png_file.name} (up to date)")
+            logger.debug(f"Skipping {png_file.name} (PNG up to date)")
 
         # Resolve metadata for this specific plot
         plot_metadata = resolve_metadata_for_plot(pdf_file, current_metadata)
@@ -181,8 +219,8 @@ def build_gallery(source_dir: Path, web_dir: Path,
         subdir_web = web_dir / subdir.name
         subdir_web.mkdir(exist_ok=True)
         subdir_relative = relative_path / subdir.name
-        # Pass current metadata to subdirectories
-        build_gallery(subdir, subdir_web, subdir_relative, current_metadata)
+        # Pass logger and current metadata to subdirectories
+        build_gallery(subdir, subdir_web, subdir_relative, current_metadata, logger)
         subdir_names.append(subdir.name)
 
     output_html = web_dir / "index.html"
@@ -195,7 +233,7 @@ def build_gallery(source_dir: Path, web_dir: Path,
         # Check if any subdirectory is newer than the HTML file
         for subdir in subdirs:
             if subdir.stat().st_mtime > html_mtime:
-                print(f"Subdirectory {subdir.name} is newer, forcing regeneration")
+                logger.debug(f"Subdirectory {subdir.name} is newer, forcing regeneration")
                 break
 
     if relative_path == Path("."):
@@ -236,7 +274,7 @@ def build_gallery(source_dir: Path, web_dir: Path,
         )
         f.write(rendered_html)
 
-    print(f"Generated {output_html}")
+    logger.generated_html(str(output_html), len(items))
 
 
 def calculate_directory_stats(directory: Path) -> dict:
@@ -324,10 +362,13 @@ def main(clean_first: bool = False) -> None:
     Processes all configured sources and generates the complete gallery
     structure in the web directory. Ensures assets are available.
     """
+    # Initialize the logger
+    logger = GalleryLogger()
+    
     gallery_root = Path(CONFIG.web_folder) / CONFIG.plot_root
 
     if clean_first and gallery_root.exists():
-        print(f"Cleaning gallery directory {gallery_root}...")
+        logger.info(f"Cleaning gallery directory {gallery_root}...")
         shutil.rmtree(gallery_root)
 
     # Ensure gallery root exists
@@ -345,9 +386,9 @@ def main(clean_first: bool = False) -> None:
             if assets_dst.exists():
                 shutil.rmtree(assets_dst)
             shutil.copytree(assets_src, assets_dst)
-            print(f"Updated assets from {assets_src} to {assets_dst}")
+            logger.assets_updated()
     else:
-        print(f"Warning: Assets directory {assets_src} not found")
+        logger.warning(f"Assets directory {assets_src} not found")
 
     for source in CONFIG.sources:
         source_path = Path(source.path)
@@ -364,19 +405,19 @@ def main(clean_first: bool = False) -> None:
             source_png_path = source_path.with_suffix('.png')
 
             if needs_update(source_path, web_pdf_path):
-                print(f"Copying {source_path} to {web_pdf_path}")
+                logger.info(f"Copying {source_path} to {web_pdf_path}")
                 shutil.copy2(source_path, web_pdf_path)
             else:
-                print(f"Skipping {source_path.name} (up to date)")
+                logger.debug(f"Skipping {source_path.name} (up to date)")
 
             if not source_png_path.exists():
-                convert_pdf_to_png(source_path)
+                convert_pdf_to_png(source_path, logger)
 
             if needs_update(source_png_path, web_png_path):
-                print(f"Copying {source_png_path} to {web_png_path}")
+                logger.info(f"Copying {source_png_path} to {web_png_path}")
                 shutil.copy2(source_png_path, web_png_path)
             else:
-                print(f"Skipping {source_png_path.name} (up to date)")
+                logger.debug(f"Skipping {source_png_path.name} (up to date)")
 
             # Get source file creation time for single file
             source_creation_time = int(source_path.stat().st_ctime)
@@ -417,27 +458,24 @@ def main(clean_first: bool = False) -> None:
                     metadata_file_path=get_metadata_file_path(source_path.parent)
                 ))
 
-            print(f"Generated {output_html}")
-            print(f"Processed {source.name}: {source.path}")
+            logger.generated_html(str(output_html), 1)
+            logger.info(f"Processed {source.name}: {source.path}")
 
         elif source_path.is_dir():
             source_web_dir = gallery_root / source.name
             source_web_dir.mkdir(parents=True, exist_ok=True)
-            build_gallery(source_path, source_web_dir, Path(source.name))
-            print(f"Processed {source.name}: {source.path}")
+            build_gallery(source_path, source_web_dir, Path(source.name), {}, logger)
+            logger.info(f"Processed {source.name}: {source.path}")
         else:
-            print(f"Warning: Source {source.path} is neither a "
-                  f"directory nor a PDF file")
+            logger.warning(f"Source {source.path} is neither a directory nor a PDF file")
 
-    print("Done")
+    logger.info("Gallery generation completed successfully")
 
 
 if __name__ == "__main__":
     if 'GATEWAY_INTERFACE' in os.environ:
         refresh_gallery_cgi()
     else:
-        import argparse
-
         parser = argparse.ArgumentParser(description='Generate gallery')
         parser.add_argument(
             '--clean',

orchestration/logger.py

@@ -0,0 +1,113 @@
+"""
+Gallery logging wrapper using Python's built-in logging module.
+"""
+
+import logging
+import sys
+
+
+class GalleryLogger:
+    """
+    Simple wrapper around Python's logging module for gallery generation.
+    Provides convenient methods for common logging patterns in the gallery app.
+    """
+    
+    def __init__(self, name: str = "gallery", level: int = logging.INFO, verbose: bool = False):
+        """
+        Initialize the gallery logger.
+        
+        Args:
+            name: Logger name
+            level: Logging level (default: INFO)
+            verbose: If True, enables DEBUG level logging
+        """
+        self.logger = logging.getLogger(name)
+        
+        # Set level based on verbose flag
+        if verbose:
+            self.logger.setLevel(logging.DEBUG)
+        else:
+            self.logger.setLevel(level)
+        
+        # Only add handler if logger doesn't have one already
+        if not self.logger.handlers:
+            handler = logging.StreamHandler(sys.stdout)
+            formatter = logging.Formatter(
+                '%(levelname)s: %(message)s'
+            )
+            handler.setFormatter(formatter)
+            self.logger.addHandler(handler)
+    
+    def info(self, message: str):
+        """Log an info message."""
+        self.logger.info(message)
+    
+    def debug(self, message: str):
+        """Log a debug message."""
+        self.logger.debug(message)
+    
+    def warning(self, message: str):
+        """Log a warning message."""
+        self.logger.warning(message)
+    
+    def error(self, message: str):
+        """Log an error message."""
+        self.logger.error(message)
+    
+    def success(self, message: str):
+        """Log a success message (as info with special prefix)."""
+        self.logger.info(f"✓ {message}")
+    
+    # Convenience methods for common gallery operations
+    def found_directory(self, dir_name: str, pdf_count: int):
+        """Log discovery of a directory with PDFs."""
+        if pdf_count > 0:
+            self.info(f"Found {pdf_count} PDF files in {dir_name}/")
+    
+    def found_pdf(self, pdf_name: str):
+        """Log discovery of a PDF file."""
+        self.debug(f"Found PDF: {pdf_name}")
+    
+    def found_metadata(self, metadata_file: str, field_count: int):
+        """Log discovery of a metadata file."""
+        self.info(f"Found metadata: {metadata_file} ({field_count} fields)")
+    
+    def converted_pdf(self, pdf_name: str, duration: float = None):
+        """Log successful PDF conversion."""
+        if duration is not None:
+            self.info(f"Converting {pdf_name} → {pdf_name.replace('.pdf', '.png')} ({duration:.2f}s)")
+        else:
+            self.info(f"Converting {pdf_name} → {pdf_name.replace('.pdf', '.png')}")
+    
+    def skipped_pdf(self, pdf_name: str, reason: str = "up-to-date"):
+        """Log skipped PDF conversion."""
+        self.debug(f"Skipping {pdf_name} ({reason})")
+    
+    def generated_html(self, html_path: str, plot_count: int):
+        """Log HTML page generation."""
+        self.info(f"Generated {html_path} ({plot_count} plots)")
+    
+    def assets_updated(self):
+        """Log assets update."""
+        self.info("Assets copied to target directory")
+
+
+def create_logger(verbose: bool = False, quiet: bool = False) -> GalleryLogger:
+    """
+    Create a configured logger for the gallery application.
+    
+    Args:
+        verbose: Enable debug-level logging
+        quiet: Suppress most output (only errors and warnings)
+    
+    Returns:
+        Configured GalleryLogger instance
+    """
+    if quiet:
+        level = logging.WARNING
+    elif verbose:
+        level = logging.DEBUG
+    else:
+        level = logging.INFO
+    
+    return GalleryLogger(level=level, verbose=verbose)