Setup Python logging with configurable verbosity

src/dab_project/cli.py

@@ -1,6 +1,8 @@
 import argparse
+import logging
 import sys
 
+from dab_project.logging_config import setup_logging
 from dab_project.tasks.base_task import Task
 
 
@@ -12,16 +14,23 @@ def main():
     parser.add_argument(
         "--catalog", type=str, default="lake_dev", help="The catalog to use (default: lake_dev)"
     )
+    parser.add_argument(
+        "-v", "--verbose", action="store_true", help="Enable verbose (DEBUG) logging"
+    )
 
     args = parser.parse_args()
 
+    # Setup logging based on verbose flag
+    setup_logging(verbose=args.verbose)
+    logger = logging.getLogger(__name__)
+
     for component in args.components:
         try:
             task = Task.create_task_factory(component)
             task.run(catalog_name=args.catalog)
         except ValueError as e:
-            print(f"Error with component '{component}': {e}")
+            logger.error(f"Error with component '{component}': {e}")
             sys.exit(1)
         except Exception as e:
-            print(f"An unexpected error occurred with component '{component}': {e}")
+            logger.error(f"An unexpected error occurred with component '{component}': {e}")
             sys.exit(1)

src/dab_project/logging_config.py

@@ -0,0 +1,44 @@
+"""Logging configuration for dab_project."""
+
+import logging
+import sys
+
+
+def setup_logging(verbose: bool = False) -> None:
+    """
+    Configure logging for the dab_project application.
+
+    Parameters
+    ----------
+    verbose : bool, optional
+        If True, set logging level to DEBUG. Otherwise, set to INFO (default: False)
+
+    Notes
+    -----
+    Log format: YYYY-MM-DD HH:MM:SS,mmm - LEVEL - module - message
+    Example: 2025-04-23 10:35:42,789 - INFO - auth - User login successful
+
+    Currently logs to console only, but can be extended to log to files in the future.
+    """
+    log_level = logging.DEBUG if verbose else logging.INFO
+
+    # Create formatter with the specified format
+    # Note: %(asctime)s defaults to 'YYYY-MM-DD HH:MM:SS,mmm' format
+    formatter = logging.Formatter(
+        fmt="%(asctime)s - %(levelname)s - %(name)s - %(message)s",
+    )
+
+    # Configure root logger
+    root_logger = logging.getLogger()
+    root_logger.setLevel(log_level)
+
+    # Remove any existing handlers to avoid duplicate logs
+    root_logger.handlers.clear()
+
+    # Create console handler
+    console_handler = logging.StreamHandler(sys.stdout)
+    console_handler.setLevel(log_level)
+    console_handler.setFormatter(formatter)
+
+    # Add handler to root logger
+    root_logger.addHandler(console_handler)

src/dab_project/tasks/base_task.py

@@ -72,6 +72,7 @@ def run(self, catalog_name: str) -> None:
 
     def _log_start(self) -> None:
         self.logger.info(f"Starting ETL task: {self.name}")
+        self.logger.debug(f"Task class: {self.__class__.__module__}.{self.__class__.__name__}")
 
     def _log_exit(self, success: bool, error: Optional[Exception] = None) -> None:
         if success:

tests/test_logging.py

@@ -0,0 +1,121 @@
+"""Tests for logging configuration."""
+
+import logging
+import re
+
+import pytest
+
+from dab_project.logging_config import setup_logging
+
+
+@pytest.fixture(autouse=True)
+def reset_logging():
+    """Reset logging configuration after each test."""
+    yield
+    # Clear all handlers after each test
+    root_logger = logging.getLogger()
+    root_logger.handlers.clear()
+    root_logger.setLevel(logging.WARNING)
+
+
+def test_setup_logging_default_level(capsys):
+    """Test that default logging level is INFO."""
+    setup_logging(verbose=False)
+
+    logger = logging.getLogger("test_module")
+    logger.debug("This is a debug message")
+    logger.info("This is an info message")
+    logger.warning("This is a warning message")
+
+    captured = capsys.readouterr()
+    # DEBUG should not be logged
+    assert "This is a debug message" not in captured.out
+    # INFO and higher should be logged
+    assert "This is an info message" in captured.out
+    assert "This is a warning message" in captured.out
+
+
+def test_setup_logging_verbose_level(capsys):
+    """Test that verbose flag enables DEBUG logging."""
+    setup_logging(verbose=True)
+
+    logger = logging.getLogger("test_module")
+    logger.debug("This is a debug message")
+    logger.info("This is an info message")
+
+    captured = capsys.readouterr()
+    # Both DEBUG and INFO should be logged
+    assert "This is a debug message" in captured.out
+    assert "This is an info message" in captured.out
+
+
+def test_logging_format(capsys):
+    """Test that log format matches expected pattern."""
+    setup_logging(verbose=False)
+
+    logger = logging.getLogger("test_module")
+    logger.info("Test message")
+
+    captured = capsys.readouterr()
+    # Expected format: YYYY-MM-DD HH:MM:SS,mmm - LEVEL - module - message
+    # Example: 2025-04-23 10:35:42,789 - INFO - test_module - Test message
+    log_pattern = r"\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2},\d{3} - INFO - test_module - Test message"
+
+    assert re.search(log_pattern, captured.out) is not None
+
+
+def test_logging_different_levels(capsys):
+    """Test logging at different levels."""
+    setup_logging(verbose=False)
+
+    logger = logging.getLogger("test_module")
+    logger.info("Info message")
+    logger.warning("Warning message")
+    logger.error("Error message")
+    logger.critical("Critical message")
+
+    captured = capsys.readouterr()
+    assert "Info message" in captured.out
+    assert "Warning message" in captured.out
+    assert "Error message" in captured.out
+    assert "Critical message" in captured.out
+    assert "- INFO -" in captured.out
+    assert "- WARNING -" in captured.out
+    assert "- ERROR -" in captured.out
+    assert "- CRITICAL -" in captured.out
+
+
+def test_logging_no_duplicate_handlers(capsys):
+    """Test that calling setup_logging multiple times doesn't create duplicate handlers."""
+    # Call setup_logging twice
+    setup_logging(verbose=False)
+    setup_logging(verbose=False)
+
+    logger = logging.getLogger("test_module")
+    logger.info("Test message")
+
+    captured = capsys.readouterr()
+    # Count occurrences - should appear only once
+    assert captured.out.count("Test message") == 1
+
+
+def test_setup_logging_root_logger_level():
+    """Test that root logger level is set correctly."""
+    setup_logging(verbose=False)
+    root_logger = logging.getLogger()
+    assert root_logger.level == logging.INFO
+
+    setup_logging(verbose=True)
+    root_logger = logging.getLogger()
+    assert root_logger.level == logging.DEBUG
+
+
+def test_setup_logging_handler_count():
+    """Test that setup_logging creates exactly one handler."""
+    setup_logging(verbose=False)
+    root_logger = logging.getLogger()
+    assert len(root_logger.handlers) == 1
+
+    # Calling again should still result in only one handler
+    setup_logging(verbose=False)
+    assert len(root_logger.handlers) == 1