feat: observability / logging

JesperDramsch · JesperDramsch · commit d2346964b1cb · 2025-08-11T23:24:38.000+02:00
diff --git a/utils/import_python_official.py b/utils/import_python_official.py
@@ -7,7 +7,7 @@
 import pandas as pd
 import requests
 from icalendar import Calendar
-from logging_config import get_logger
+from logging_config import get_tqdm_logger
 from tidy_conf import fuzzy_match
 from tidy_conf import load_conferences
 from tidy_conf import merge_conferences
@@ -18,7 +18,7 @@
 from tidy_conf.yaml import load_title_mappings
 from tidy_conf.yaml import write_df_yaml
 
-logger = get_logger(__name__)
+logger = get_tqdm_logger(__name__)
 
 
 def ics_to_dataframe() -> pd.DataFrame:
diff --git a/utils/logging_config.py b/utils/logging_config.py
@@ -3,6 +3,10 @@
 import logging
 import sys
 from pathlib import Path
+from typing import TYPE_CHECKING
+
+if TYPE_CHECKING:
+    pass
 
 
 def setup_logging(level: str = "INFO", log_file: str | None = None, include_timestamp: bool = True) -> logging.Logger:
@@ -50,6 +54,75 @@ def setup_logging(level: str = "INFO", log_file: str | None = None, include_time
     return logger
 
 
+class TqdmLoggingHandler(logging.Handler):
+    """Custom logging handler that uses tqdm.write() for tqdm-compatible output."""
+
+    def __init__(self, level=logging.NOTSET):
+        super().__init__(level)
+
+    def emit(self, record):
+        try:
+            msg = self.format(record)
+            # Try to import and use tqdm.write, fallback to print
+            try:
+                from tqdm import tqdm
+
+                tqdm.write(msg)
+            except ImportError:
+                print(msg)
+        except Exception:
+            self.handleError(record)
+
+
+def setup_tqdm_logging(
+    level: str = "INFO",
+    log_file: str | None = None,
+    include_timestamp: bool = True,
+) -> logging.Logger:
+    """Set up tqdm-compatible logging configuration for the project.
+
+    Args:
+        level: Logging level (DEBUG, INFO, WARNING, ERROR, CRITICAL)
+        log_file: Optional log file path
+        include_timestamp: Whether to include timestamps in log messages
+
+    Returns
+    -------
+        logging.Logger: Configured logger instance with tqdm-compatible output
+    """
+    # Create logger
+    logger = logging.getLogger("python_deadlines")
+    logger.setLevel(getattr(logging, level.upper()))
+
+    # Clear existing handlers to avoid duplicates
+    logger.handlers.clear()
+
+    # Create formatter
+    if include_timestamp:
+        formatter = logging.Formatter(
+            "%(asctime)s - %(name)s - %(levelname)s - %(message)s",
+            datefmt="%Y-%m-%d %H:%M:%S",
+        )
+    else:
+        formatter = logging.Formatter("%(levelname)s - %(message)s")
+
+    # Tqdm-compatible console handler
+    tqdm_handler = TqdmLoggingHandler()
+    tqdm_handler.setFormatter(formatter)
+    logger.addHandler(tqdm_handler)
+
+    # File handler (optional)
+    if log_file:
+        log_path = Path(log_file)
+        log_path.parent.mkdir(parents=True, exist_ok=True)
+
+        file_handler = logging.FileHandler(log_path, encoding="utf-8")
+        file_handler.setFormatter(formatter)
+        logger.addHandler(file_handler)
+
+    return logger
+
+
 def get_logger(name: str | None = None) -> logging.Logger:
     """Get a logger instance with the project configuration.
 
@@ -67,6 +140,29 @@ def get_logger(name: str | None = None) -> logging.Logger:
 
     # Set up basic configuration if not already configured
     if not logger.handlers:
-        return setup_logging()
+        return setup_tqdm_logging()
+
+    return logger
+
+
+def get_tqdm_logger(name: str | None = None, level: str = "INFO") -> logging.Logger:
+    """Get a tqdm-compatible logger instance.
+
+    Args:
+        name: Logger name (defaults to calling module)
+        level: Logging level
+
+    Returns
+    -------
+        logging.Logger: Tqdm-compatible logger instance
+    """
+    if name is None:
+        name = "python_deadlines"
+
+    logger = logging.getLogger(name)
+
+    # Set up tqdm-compatible configuration if not already configured
+    if not logger.handlers:
+        return setup_tqdm_logging(level=level)
 
     return logger
diff --git a/utils/main.py b/utils/main.py
@@ -1,12 +1,52 @@
 import sys
+import time
 
 sys.path.append(".")
 from import_python_official import main as official_updater
 from import_python_organizers import main as organizer_updater
+from logging_config import get_tqdm_logger
 from sort_yaml import sort_data
 
+
+def main():
+    """Main data processing pipeline with comprehensive logging."""
+    logger = get_tqdm_logger(__name__)
+
+    logger.info("🚀 Starting Python Deadlines data processing pipeline")
+    start_time = time.time()
+
+    try:
+        # Step 1: Import from Python official calendar
+        logger.info("📅 Step 1: Importing from Python official calendar")
+        step_start = time.time()
+        official_updater()
+        logger.info(f"✅ Official calendar import completed in {time.time() - step_start:.2f}s")
+
+        # Step 2: Sort and validate data
+        logger.info("🔄 Step 2: Sorting and validating data")
+        step_start = time.time()
+        sort_data(skip_links=True)
+        logger.info(f"✅ Data sorting completed in {time.time() - step_start:.2f}s")
+
+        # Step 3: Import from Python organizers
+        logger.info("👥 Step 3: Importing from Python organizers")
+        step_start = time.time()
+        organizer_updater()
+        logger.info(f"✅ Organizers import completed in {time.time() - step_start:.2f}s")
+
+        # Step 4: Final sort and validation
+        logger.info("🔄 Step 4: Final sorting and validation")
+        step_start = time.time()
+        sort_data(skip_links=True)
+        logger.info(f"✅ Final sorting completed in {time.time() - step_start:.2f}s")
+
+        total_time = time.time() - start_time
+        logger.info(f"🎉 Data processing pipeline completed successfully in {total_time:.2f}s")
+
+    except Exception as e:
+        logger.error(f"❌ Pipeline failed with error: {e}", exc_info=True)
+        sys.exit(1)
+
+
 if __name__ == "__main__":
-    official_updater()
-    sort_data(skip_links=True)
-    organizer_updater()
-    sort_data(skip_links=True)
+    main()
diff --git a/utils/sort_yaml.py b/utils/sort_yaml.py
@@ -12,6 +12,7 @@
 import pydantic
 import pytz
 import yaml
+from logging_config import get_tqdm_logger
 from tidy_conf import auto_add_sub
 from tidy_conf import write_conference_yaml
 from tidy_conf.date import clean_dates
@@ -156,6 +157,8 @@ def check_links(data):
 # Sort:
 def sort_data(base="", prefix="", skip_links=False):
     """Sort and clean the conference data."""
+    logger = get_tqdm_logger(__name__)
+
     # Load different data files
     current = Path(base, "_data", "conferences.yml")
     out_current = Path(base, "_data", f"{prefix}conferences.yml")
@@ -164,73 +167,101 @@ def sort_data(base="", prefix="", skip_links=False):
     legacy = Path(base, "_data", "legacy.yml")
     out_legacy = Path(base, "_data", f"{prefix}legacy.yml")
 
+    logger.info("📊 Loading conference data files")
     data = []
+    files_loaded = 0
 
     for url in (current, archive, legacy):
-        with url.open(encoding="utf-8") as stream, contextlib.suppress(yaml.YAMLError):
-            if stream:
-                data += yaml.load(stream, Loader=Loader)  # nosec B506 # noqa: S506
+        if url.exists():
+            with url.open(encoding="utf-8") as stream, contextlib.suppress(yaml.YAMLError):
+                if stream:
+                    file_data = yaml.load(stream, Loader=Loader)  # nosec B506 # noqa: S506
+                    if file_data:
+                        data += file_data
+                        files_loaded += 1
+                        logger.debug(f"Loaded {len(file_data)} entries from {url.name}")
+
+    logger.info(f"📋 Loaded {len(data)} conferences from {files_loaded} files")
 
     from tidy_conf.schema import Conference
 
+    logger.debug("🔧 Ordering keywords")
     for i, q in enumerate(data.copy()):
         data[i] = order_keywords(q)
 
     # Clean Dates
+    logger.info("📅 Cleaning dates")
     data = tidy_dates(data)
 
     # Clean Titles
+    logger.info("🏷️  Cleaning titles")
     data = tidy_titles(data)
 
     # Add Sub
+    logger.info("🏢 Adding submission types")
     data = auto_add_sub(data)
 
     # Geocode Data
+    logger.info("🗺️  Adding geolocation data")
     data = add_latlon(data)
 
     # Merge duplicates
+    logger.info("🔄 Merging duplicates")
     data = merge_duplicates(data)
 
     # Check Links
     if not skip_links:
+        logger.info("🔗 Checking link availability")
         data = check_links(data)
+    else:
+        logger.info("⏭️  Skipping link checking")
 
     for i, q in enumerate(data.copy()):
         data[i] = order_keywords(q)
 
+    logger.info("✅ Validating conference data with Pydantic schema")
     new_data = []
+    validation_errors = 0
+
     for q in data:
         try:
             new_data.append(Conference(**q))
         except pydantic.ValidationError as e:  # noqa: PERF203
-            print(f"Error: {e}")
-            print(f"Data: \n{yaml.dump(q, default_flow_style=False)}")
-            print("\n\n")
+            validation_errors += 1
+            logger.error(f"❌ Validation error in conference: {e}")
+            logger.debug(f"Invalid data: \n{yaml.dump(q, default_flow_style=False)}")
             continue
+
+    if validation_errors > 0:
+        logger.warning(f"⚠️  {validation_errors} conferences failed validation and were skipped")
+
     data = new_data
+    logger.info(f"✅ {len(data)} conferences passed validation")
 
     # Split data by cfp
+    logger.info("📂 Splitting data by CFP status")
     conf, tba, expired, legacy = split_data(data)
+    logger.info(f"📊 Split results: {len(conf)} active, {len(tba)} TBA, {len(expired)} expired, {len(legacy)} legacy")
 
-    # just sort:
+    # Sort data
+    logger.info("🔄 Sorting conferences by CFP date")
     conf.sort(key=sort_by_cfp, reverse=True)
-    # pretty_print("Date Sorting:", conf, tba, expired, legacy)
     conf.sort(key=sort_by_date_passed)
-    # pretty_print("Date and Passed Deadline Sorting with tba:", conf, tba, expired)
     tba.sort(key=sort_by_date, reverse=True)
 
+    logger.info(f"💾 Writing {len(conf + tba)} active conferences to {out_current.name}")
     write_conference_yaml(conf + tba, out_current)
 
     expired.sort(key=sort_by_date, reverse=True)
-
-    # pretty_print("New archive:", data)
+    logger.info(f"📦 Writing {len(expired)} expired conferences to {out_archive.name}")
     write_conference_yaml(expired, out_archive)
 
     legacy.sort(key=sort_by_name, reverse=True)
-
-    # pretty_print("New legacy:", data)
+    logger.info(f"🗂️  Writing {len(legacy)} legacy conferences to {out_legacy.name}")
     write_conference_yaml(legacy, out_legacy)
 
+    logger.info("🎉 Conference data sorting and cleaning completed successfully")
+
 
 if __name__ == "__main__":
     import argparse
diff --git a/utils/tidy_conf/latlon.py b/utils/tidy_conf/latlon.py
@@ -1,17 +1,25 @@
+import sys
 import time
 import urllib
 
 import requests
 from tqdm import tqdm
 
+sys.path.append("..")
+from logging_config import get_tqdm_logger
+
 
 def add_latlon(data):
     """Add latitude and longitude to the data."""
+    logger = get_tqdm_logger(__name__)
+
     # Cache for locations
     cache = {}
     # Copy of data for unlocated conferences
     data_copy = []
 
+    logger.debug(f"Processing geolocation for {len(data)} conferences")
+
     # Go through the data and check if the location is already in the cache
     for i, q in tqdm(enumerate(data), total=len(data)):
         if ("place" not in q) or ("online" in q["place"].lower()):
@@ -31,7 +39,7 @@ def add_latlon(data):
         try:
             q["place"] = q["place"].split(",")[0].strip() + ", " + q["place"].split(",")[-1].strip()
         except IndexError:
-            tqdm.write(f"IndexError: {q['place']}")
+            logger.error(f"IndexError processing place: {q['place']}")
 
         # Check if the location is already in the cache
         places = [q["place"]]
@@ -69,11 +77,11 @@ def add_latlon(data):
                         cache[place] = new_location[-1]
                     except IndexError:
                         cache[place] = None
-                        tqdm.write(f"No response from Openstreetmaps for {q['place']}")
+                        logger.warning(f"No response from OpenStreetMap for {q['place']}")
                     time.sleep(2)
                 else:
                     cache[place] = None
-                    tqdm.write(f"No response from Openstreetmaps for {q['place']}")
+                    logger.warning(f"No response from OpenStreetMap for {q['place']}")
         else:
             if new_location:
                 data[i]["location"] = new_location
diff --git a/utils/tidy_conf/links.py b/utils/tidy_conf/links.py
@@ -1,3 +1,4 @@
+import sys
 from datetime import datetime
 from datetime import timedelta
 from datetime import timezone
@@ -7,6 +8,8 @@
 import requests
 from tqdm import tqdm
 
+sys.path.append("..")
+
 
 def get_cache_location():
     # Check if the URL is cached
