Chore!: configure logging before loading config to log errors properly (#4509)

Co-authored-by: Iaroslav Zeigerman <zeigerman.ia@gmail.com>

Author: georgesittas

sqlmesh/__init__.py

@@ -166,11 +166,24 @@ def format(self, record: logging.LogRecord) -> str:
         return formatter.format(record)
 
 
+def remove_excess_logs(
+    log_file_dir: t.Optional[t.Union[str, Path]] = None,
+    log_limit: int = c.DEFAULT_LOG_LIMIT,
+) -> None:
+    if log_limit <= 0:
+        return
+
+    log_file_dir = log_file_dir or c.DEFAULT_LOG_FILE_DIR
+    log_path_prefix = Path(log_file_dir) / LOG_FILENAME_PREFIX
+
+    for path in list(sorted(glob.glob(f"{log_path_prefix}*.log"), reverse=True))[log_limit:]:
+        os.remove(path)
+
+
 def configure_logging(
     force_debug: bool = False,
     write_to_stdout: bool = False,
     write_to_file: bool = True,
-    log_limit: int = c.DEFAULT_LOG_LIMIT,
     log_file_dir: t.Optional[t.Union[str, Path]] = None,
     ignore_warnings: bool = False,
 ) -> None:
@@ -192,20 +205,18 @@ def configure_logging(
 
     log_file_dir = log_file_dir or c.DEFAULT_LOG_FILE_DIR
     log_path_prefix = Path(log_file_dir) / LOG_FILENAME_PREFIX
+
     if write_to_file:
         os.makedirs(str(log_file_dir), exist_ok=True)
         filename = f"{log_path_prefix}{datetime.now().strftime('%Y_%m_%d_%H_%M_%S')}.log"
         file_handler = logging.FileHandler(filename, mode="w", encoding="utf-8")
+
         # the log files should always log at least info so that users will always have
         # minimal info for debugging even if they specify "ignore_warnings"
         file_handler.setLevel(level)
         file_handler.setFormatter(logging.Formatter(LOG_FORMAT))
         logger.addHandler(file_handler)
 
-    if log_limit > 0:
-        for path in list(sorted(glob.glob(f"{log_path_prefix}*.log"), reverse=True))[log_limit:]:
-            os.remove(path)
-
     if debug:
         import faulthandler
 

sqlmesh/cli/main.py

@@ -7,7 +7,7 @@
 
 import click
 
-from sqlmesh import configure_logging
+from sqlmesh import configure_logging, remove_excess_logs
 from sqlmesh.cli import error_handler
 from sqlmesh.cli import options as opt
 from sqlmesh.cli.example_project import ProjectTemplate, init_example_project
@@ -100,17 +100,19 @@ def cli(
         if ctx.invoked_subcommand in SKIP_LOAD_COMMANDS:
             load = False
 
-    configs = load_configs(config, Context.CONFIG_TYPE, paths)
-    log_limit = list(configs.values())[0].log_limit
     configure_logging(
         debug,
         log_to_stdout,
-        log_limit=log_limit,
         log_file_dir=log_file_dir,
         ignore_warnings=ignore_warnings,
     )
     configure_console(ignore_warnings=ignore_warnings)
 
+    configs = load_configs(config, Context.CONFIG_TYPE, paths)
+    log_limit = list(configs.values())[0].log_limit
+
+    remove_excess_logs(log_file_dir, log_limit)
+
     try:
         context = Context(
             paths=paths,

sqlmesh/core/config/connection.py

@@ -26,7 +26,7 @@
 )
 from sqlmesh.core.engine_adapter.shared import CatalogSupport
 from sqlmesh.core.engine_adapter import EngineAdapter
-from sqlmesh.utils import str_to_bool
+from sqlmesh.utils import debug_mode_enabled, str_to_bool
 from sqlmesh.utils.errors import ConfigError
 from sqlmesh.utils.pydantic import (
     ValidationInfo,
@@ -67,8 +67,16 @@ def validate(cls: t.Any, data: t.Any) -> t.Any:
         try:
             importlib.import_module(import_name)
         except ImportError:
+            if debug_mode_enabled():
+                raise
+
+            logger.exception("Failed to import the engine library")
+
             raise ConfigError(
-                f"Failed to import the '{engine_type}' engine library. Please run `pip install \"sqlmesh[{extra_name}]\"`."
+                f"Failed to import the '{engine_type}' engine library. This may be due to a missing "
+                "or incompatible installation. Please ensure the required dependency is installed by "
+                f'running: `pip install "sqlmesh[{extra_name}]"`. For more details, check the logs '
+                "in the 'logs/' folder, or rerun the command with the '--debug' flag."
             )
 
         return data

sqlmesh/core/context.py

@@ -35,7 +35,6 @@
 
 import abc
 import collections
-from itertools import chain
 import logging
 import sys
 import time
@@ -44,6 +43,7 @@
 import unittest.result
 from functools import cached_property
 from io import StringIO
+from itertools import chain
 from pathlib import Path
 from shutil import rmtree
 from types import MappingProxyType

sqlmesh/magics.py

@@ -129,25 +129,31 @@ def _shell(self) -> t.Any:
     @line_magic
     def context(self, line: str) -> None:
         """Sets the context in the user namespace."""
-        from sqlmesh import configure_logging
+        from sqlmesh import configure_logging, remove_excess_logs
 
         args = parse_argstring(self.context, line)
-        configs = load_configs(args.config, Context.CONFIG_TYPE, args.paths)
-        log_limit = list(configs.values())[0].log_limit
+        log_file_dir = args.log_file_dir
+
         configure_logging(
             args.debug,
-            log_limit=log_limit,
-            log_file_dir=args.log_file_dir,
+            log_file_dir=log_file_dir,
             ignore_warnings=args.ignore_warnings,
         )
         configure_console(ignore_warnings=args.ignore_warnings)
+
+        configs = load_configs(args.config, Context.CONFIG_TYPE, args.paths)
+        log_limit = list(configs.values())[0].log_limit
+
+        remove_excess_logs(log_file_dir, log_limit)
+
         try:
             context = Context(paths=args.paths, config=configs, gateway=args.gateway)
             self._shell.user_ns["context"] = context
         except Exception:
             if args.debug:
                 logger.exception("Failed to initialize SQLMesh context")
             raise
+
         context.console.log_success(f"SQLMesh project context set to: {', '.join(args.paths)}")
 
     @magic_arguments()

tests/core/test_connection_config.py

@@ -1016,7 +1016,10 @@ def test_engine_import_validator():
     with pytest.raises(
         ConfigError,
         match=re.escape(
-            """Failed to import the 'bigquery' engine library. Please run `pip install "sqlmesh[bigquery]"`."""
+            "Failed to import the 'bigquery' engine library. This may be due to a missing "
+            "or incompatible installation. Please ensure the required dependency is installed by "
+            'running: `pip install "sqlmesh[bigquery]"`. For more details, check the logs '
+            "in the 'logs/' folder, or rerun the command with the '--debug' flag."
         ),
     ):
 
@@ -1028,7 +1031,10 @@ class TestConfigA(PydanticModel):
     with pytest.raises(
         ConfigError,
         match=re.escape(
-            """Failed to import the 'bigquery' engine library. Please run `pip install "sqlmesh[bigquery_extra]"`."""
+            "Failed to import the 'bigquery' engine library. This may be due to a missing "
+            "or incompatible installation. Please ensure the required dependency is installed by "
+            'running: `pip install "sqlmesh[bigquery_extra]"`. For more details, check the logs '
+            "in the 'logs/' folder, or rerun the command with the '--debug' flag."
         ),
     ):