From 96eb7e330f094fafb77160ce051cc7bc6c63b9b1 Mon Sep 17 00:00:00 2001 From: suryaiyer95 Date: Tue, 28 Jul 2026 14:35:01 -0700 Subject: [PATCH] feat: add `--debug` flag and `DATAPILOT_DEBUG` env var for verbose logging API failures were reported as a one-line summary such as `Error in uploading the manifest.` with no way to see why. `APIClient` already recorded the HTTP status and error body via `logger.debug`, but `dbt/cli/cli.py` pinned the root logger at `INFO` at import time, so every `DEBUG` record was discarded and there was no flag or env var to change it. Verbose output is now opt-in two ways, both resolving to the same click parameter: the `--debug` flag, and the `DATAPILOT_DEBUG` environment variable for CI/CD pipelines where the command line is generated and hard to edit. * Add `datapilot/utils/logging_utils.py` with `configure_logging()`, `is_debug_enabled()` and `redact_url()`. * Add a `debug_option` decorator and wire it into `dbt project-health` and `dbt onboard`. * Replace the import-time `logging.basicConfig(level=logging.INFO)` in `dbt/cli/cli.py` and `mcp.py` with `configure_logging()`, so `DATAPILOT_DEBUG` is honoured even on paths that never reach a command callback. * Debug is sticky, so an import-time call at `INFO` cannot undo `--debug`. * `configure_logging()` only installs a handler when the root logger has none, leaving handlers owned by embedding applications intact. Redact credentials, since debug output is meant to be shared with support: * Presigned upload URLs carry an AWS key and signature in the query string. `redact_url()` strips it in both the `put()` request log and the `Received signed URL` log, keeping the object path. * Hold `urllib3` at `INFO` in debug mode; it logs each request line verbatim, presigned query string included. * Log the `GET` request params instead, which identify the integration id, environment and file type without exposing secrets. Verified against `api.myaltimate.com`: the API token never appears in debug output, and a successful upload logs no `AWSAccessKeyId` or `Signature`. Co-Authored-By: Claude Opus 5 (1M context) --- README.md | 29 ++++++ src/datapilot/cli/decorators.py | 21 ++++ src/datapilot/clients/altimate/client.py | 7 +- src/datapilot/clients/altimate/utils.py | 3 +- src/datapilot/core/mcp_utils/mcp.py | 5 +- src/datapilot/core/platforms/dbt/cli/cli.py | 9 +- src/datapilot/utils/logging_utils.py | 79 +++++++++++++++ tests/cli/__init__.py | 0 tests/cli/test_debug_option.py | 65 ++++++++++++ .../clients/altimate/test_client_redaction.py | 66 +++++++++++++ tests/utils/test_logging_utils.py | 99 +++++++++++++++++++ 11 files changed, 376 insertions(+), 7 deletions(-) create mode 100644 src/datapilot/utils/logging_utils.py create mode 100644 tests/cli/__init__.py create mode 100644 tests/cli/test_debug_option.py create mode 100644 tests/clients/altimate/test_client_redaction.py create mode 100644 tests/utils/test_logging_utils.py diff --git a/README.md b/README.md index 149b6d6b..a4cf29d1 100644 --- a/README.md +++ b/README.md @@ -42,6 +42,35 @@ The [--catalog-path] is an optional argument. If you don't specify a catalog pat The [--config-path] is an optional argument. You can provide a yaml file with overrides for the default behavior of the insights. +#### Verbose / Debug Logging + +By default, API failures are reported as a short summary such as `Error in uploading the manifest.` +To see the underlying HTTP status codes and the error bodies returned by the API, enable debug +logging with either the `--debug` flag or the `DATAPILOT_DEBUG` environment variable: + +```shell +datapilot dbt onboard --debug ... + +# Or, for CI/CD pipelines where the command line is generated: +export DATAPILOT_DEBUG=1 +datapilot dbt onboard ... +``` + +This turns the generic message into an actionable one: + +``` +DEBUG:APIClient:Sending GET request for tenant acme at url: https://api.myaltimate.com/dbt/v1/signed_url +DEBUG:APIClient:Request params: {'dbt_core_integration_id': '2', 'dbt_core_integration_environment_type': 'DEV', 'file_type': 'manifest'} +DEBUG:APIClient:HTTP Error: {'detail': 'dbt_core_integration with id:2 and env:DEV not found'} - Status code: 400 +Error in uploading the manifest. +``` + +Note that `--dbt_core_integration_environment` is matched exactly, including case, against the +environments configured for your integration. + +Debug output is safe to share: the API token is never logged, and the credentials in presigned +upload URLs are redacted to `?`. + #### Generating Manifest and Catalog Files for dbt Projects 1. Generate Manifest File (manifest.json). Open your dbt project's root directory in a terminal or command prompt. Run `dbt compile`. This command generates manifest.json in the target folder under your dbt project directory structure. diff --git a/src/datapilot/cli/decorators.py b/src/datapilot/cli/decorators.py index 631b1a0e..67a976ba 100644 --- a/src/datapilot/cli/decorators.py +++ b/src/datapilot/cli/decorators.py @@ -9,6 +9,27 @@ import click from dotenv import load_dotenv +from datapilot.utils.logging_utils import DEBUG_ENV_VAR +from datapilot.utils.logging_utils import configure_logging + + +def debug_option(f): + """Decorator adding a --debug flag, also settable via DATAPILOT_DEBUG.""" + + @click.option( + "--debug", + is_flag=True, + default=False, + envvar=DEBUG_ENV_VAR, + help=f"Enable verbose debug logging, including API status codes and error responses. Can also be set with {DEBUG_ENV_VAR}=1.", + ) + @wraps(f) + def wrapper(*args, **kwargs): + configure_logging(debug=kwargs.pop("debug", False)) + return f(*args, **kwargs) + + return wrapper + def load_config_from_file() -> Optional[Dict]: """Load configuration from ~/.altimate/altimate.json if it exists.""" diff --git a/src/datapilot/clients/altimate/client.py b/src/datapilot/clients/altimate/client.py index fca8faca..d246c05a 100644 --- a/src/datapilot/clients/altimate/client.py +++ b/src/datapilot/clients/altimate/client.py @@ -6,6 +6,8 @@ from requests.exceptions import RequestException from requests.exceptions import Timeout +from datapilot.utils.logging_utils import redact_url + class APIClient: def __init__(self, api_token="", base_url="", tenant=""): @@ -36,6 +38,8 @@ def get(self, endpoint, params=None, timeout=None): try: self.logger.debug(f"Sending GET request for tenant {self.tenant} at url: {url}") + if params: + self.logger.debug(f"Request params: {params}") response = requests.get(url, headers=headers, params=params, timeout=timeout) # Check if the response was successful @@ -67,7 +71,8 @@ def post(self, endpoint, data=None, timeout=None): def put(self, endpoint, data, timeout=None): url = f"{self.base_url}{endpoint}" - self.logger.debug(f"Sending PUT request for tenant {self.tenant} at url: {url}") + # Presigned upload URLs carry AWS credentials in the query string. + self.logger.debug(f"Sending PUT request for tenant {self.tenant} at url: {redact_url(url)}") response = requests.put(url, data=data, timeout=timeout) self.logger.debug(f"Received PUT response with status: {response.status_code}") return response diff --git a/src/datapilot/clients/altimate/utils.py b/src/datapilot/clients/altimate/utils.py index ecce6069..aaa2cb08 100644 --- a/src/datapilot/clients/altimate/utils.py +++ b/src/datapilot/clients/altimate/utils.py @@ -8,6 +8,7 @@ from datapilot.clients.altimate.client import APIClient from datapilot.clients.altimate.constants import SUPPORTED_ARTIFACT_TYPES +from datapilot.utils.logging_utils import redact_url def check_token_and_instance( @@ -89,7 +90,7 @@ def onboard_file(api_token, tenant, dbt_core_integration_id, dbt_core_integratio if signed_url_data: signed_url = signed_url_data.get("url") file_id = signed_url_data.get("dbt_core_integration_file_id") - api_client.log(f"Received signed URL: {signed_url}") + api_client.log(f"Received signed URL: {redact_url(signed_url)}") api_client.log(f"Received File ID: {file_id}") upload_response = upload_content_to_signed_url(file_path, signed_url) diff --git a/src/datapilot/core/mcp_utils/mcp.py b/src/datapilot/core/mcp_utils/mcp.py index 7c2481a7..2b093c86 100644 --- a/src/datapilot/core/mcp_utils/mcp.py +++ b/src/datapilot/core/mcp_utils/mcp.py @@ -1,6 +1,5 @@ import asyncio import json -import logging import shutil from dataclasses import dataclass @@ -10,7 +9,9 @@ from mcp import StdioServerParameters from mcp.client.stdio import stdio_client -logging.basicConfig(level=logging.INFO) +from datapilot.utils.logging_utils import configure_logging + +configure_logging() @dataclass diff --git a/src/datapilot/core/platforms/dbt/cli/cli.py b/src/datapilot/core/platforms/dbt/cli/cli.py index e286e798..c33c2cbb 100644 --- a/src/datapilot/core/platforms/dbt/cli/cli.py +++ b/src/datapilot/core/platforms/dbt/cli/cli.py @@ -1,8 +1,7 @@ -import logging - import click from datapilot.cli.decorators import auth_options +from datapilot.cli.decorators import debug_option from datapilot.clients.altimate.utils import check_token_and_instance from datapilot.clients.altimate.utils import get_all_dbt_configs from datapilot.clients.altimate.utils import onboard_file @@ -21,9 +20,11 @@ from datapilot.core.platforms.dbt.utils import load_run_results from datapilot.core.platforms.dbt.utils import load_sources from datapilot.utils.formatting.utils import tabulate_data +from datapilot.utils.logging_utils import configure_logging from datapilot.utils.utils import map_url_to_instance -logging.basicConfig(level=logging.INFO) +# Honour DATAPILOT_DEBUG even for code paths that never reach a command callback. +configure_logging() # New dbt group @@ -33,6 +34,7 @@ def dbt(): @dbt.command("project-health") +@debug_option @auth_options @click.option( "--manifest-path", @@ -134,6 +136,7 @@ def project_health( @dbt.command("onboard") +@debug_option @auth_options @click.option( "--dbt_core_integration_id", diff --git a/src/datapilot/utils/logging_utils.py b/src/datapilot/utils/logging_utils.py new file mode 100644 index 00000000..07f2de26 --- /dev/null +++ b/src/datapilot/utils/logging_utils.py @@ -0,0 +1,79 @@ +"""Logging configuration for the datapilot CLI. + +Verbose output is opt-in and can be turned on two ways: + +- the ``DATAPILOT_DEBUG`` environment variable, which is the option to reach for + in CI/CD pipelines where the command line is generated and hard to edit +- the ``--debug`` flag on individual commands + +Both raise the root logger to ``DEBUG``, which surfaces the HTTP status codes and +API error bodies that ``APIClient`` already records but normally discards. +""" + +import logging +import os +from typing import Optional +from urllib.parse import urlsplit +from urllib.parse import urlunsplit + +DEBUG_ENV_VAR = "DATAPILOT_DEBUG" + +# Values that count as "on" for DATAPILOT_DEBUG. Anything else (including "0", +# "false" and the empty string) leaves debug logging off. +_TRUTHY_VALUES = frozenset({"1", "true", "yes", "on"}) + +# Debug mode is sticky: a command-level `--debug` must not be undone by a later +# call that happens to default to False. +_debug_enabled = False + + +def debug_enabled_via_env() -> bool: + """Return True when DATAPILOT_DEBUG is set to a truthy value.""" + return os.environ.get(DEBUG_ENV_VAR, "").strip().lower() in _TRUTHY_VALUES + + +def configure_logging(debug: bool = False) -> bool: + """Configure root logging for the CLI and return whether debug mode is on. + + Safe to call more than once; the group callback and the command callback both + call it, and the more verbose of the two wins. + """ + global _debug_enabled + _debug_enabled = _debug_enabled or debug or debug_enabled_via_env() + level = logging.DEBUG if _debug_enabled else logging.INFO + + root = logging.getLogger() + # Only install a handler when nothing else has, so embedding applications + # (and pytest's caplog) keep theirs. Setting the level is what actually + # decides whether the DEBUG records get through. + if not root.handlers: + logging.basicConfig(level=level) + root.setLevel(level) + + # urllib3 logs each request line in full, which for a presigned S3 upload means + # the AWS key and signature. Our own client logs the status codes and request + # params, so nothing diagnostic is lost by holding urllib3 at INFO. + logging.getLogger("urllib3").setLevel(logging.INFO) + + return _debug_enabled + + +def is_debug_enabled() -> bool: + """Return whether debug logging is currently enabled.""" + return _debug_enabled + + +def redact_url(url: Optional[str]) -> str: + """Strip a URL's query string so it is safe to log. + + Presigned upload URLs carry AWS credentials and a signature in the query + string, and debug output routinely gets pasted into support tickets. + """ + if not url: + return "" + + parts = urlsplit(url) + if not parts.query: + return url + + return urlunsplit((parts.scheme, parts.netloc, parts.path, "", "")) diff --git a/tests/cli/__init__.py b/tests/cli/__init__.py new file mode 100644 index 00000000..e69de29b diff --git a/tests/cli/test_debug_option.py b/tests/cli/test_debug_option.py new file mode 100644 index 00000000..b56397b1 --- /dev/null +++ b/tests/cli/test_debug_option.py @@ -0,0 +1,65 @@ +import logging + +import pytest +from click.testing import CliRunner + +from datapilot.cli.main import datapilot +from datapilot.utils import logging_utils +from datapilot.utils.logging_utils import DEBUG_ENV_VAR + + +@pytest.fixture(autouse=True) +def _reset_logging_state(monkeypatch): + monkeypatch.setattr(logging_utils, "_debug_enabled", False) + monkeypatch.delenv(DEBUG_ENV_VAR, raising=False) + original_level = logging.getLogger().level + yield + logging.getLogger().setLevel(original_level) + + +def invoke_project_health(env=None, extra_args=()): + """project-health runs fully offline, so it exercises the flag without network access.""" + return CliRunner().invoke( + datapilot, + ["dbt", "project-health", "--manifest-path", "tests/data/manifest_v11.json", *extra_args], + env=env or {}, + ) + + +class TestDebugFlag: + def test_flag_is_advertised_in_help(self): + result = CliRunner().invoke(datapilot, ["dbt", "onboard", "--help"]) + + assert result.exit_code == 0 + assert "--debug" in result.output + assert DEBUG_ENV_VAR in result.output + + def test_flag_enables_debug_logging(self): + result = invoke_project_health(extra_args=["--debug"]) + + assert result.exit_code == 0 + assert logging_utils.is_debug_enabled() is True + assert logging.getLogger().level == logging.DEBUG + + def test_without_flag_stays_at_info(self): + result = invoke_project_health() + + assert result.exit_code == 0 + assert logging_utils.is_debug_enabled() is False + assert logging.getLogger().level == logging.INFO + + +class TestDebugEnvVar: + def test_env_var_enables_debug_logging(self): + result = invoke_project_health(env={DEBUG_ENV_VAR: "1"}) + + assert result.exit_code == 0 + assert logging_utils.is_debug_enabled() is True + assert logging.getLogger().level == logging.DEBUG + + def test_env_var_off_stays_at_info(self): + result = invoke_project_health(env={DEBUG_ENV_VAR: "0"}) + + assert result.exit_code == 0 + assert logging_utils.is_debug_enabled() is False + assert logging.getLogger().level == logging.INFO diff --git a/tests/clients/altimate/test_client_redaction.py b/tests/clients/altimate/test_client_redaction.py new file mode 100644 index 00000000..0bb9b8d9 --- /dev/null +++ b/tests/clients/altimate/test_client_redaction.py @@ -0,0 +1,66 @@ +import logging +from unittest.mock import patch + +import pytest +from requests import Response + +from datapilot.clients.altimate.client import APIClient +from datapilot.utils import logging_utils +from datapilot.utils.logging_utils import DEBUG_ENV_VAR +from datapilot.utils.logging_utils import configure_logging + +PRESIGNED_URL = ( + "https://altimate-datapilot-freemium-prod.s3.amazonaws.com/prd/tenant%3Delastic/manifest.json" + "?AWSAccessKeyId=AKIAVXVSOK5H3JQFSSU4&Signature=2LV9nU5JHPVOFz&Expires=1785271367" +) + + +@pytest.fixture(autouse=True) +def _reset_logging_state(monkeypatch): + monkeypatch.setattr(logging_utils, "_debug_enabled", False) + monkeypatch.delenv(DEBUG_ENV_VAR, raising=False) + original_level = logging.getLogger().level + yield + logging.getLogger().setLevel(original_level) + + +def make_response(status_code=200): + response = Response() + response.status_code = status_code + response._content = b"" + return response + + +class TestPresignedUrlRedaction: + def test_put_does_not_log_aws_credentials(self, caplog): + client = APIClient() + + with caplog.at_level(logging.DEBUG), patch("requests.put", return_value=make_response()): + client.put(PRESIGNED_URL, data=b"{}") + + assert "AKIAVXVSOK5H3JQFSSU4" not in caplog.text + assert "2LV9nU5JHPVOFz" not in caplog.text + # The object path is still logged, which is the part that aids debugging. + assert "manifest.json" in caplog.text + assert "" in caplog.text + + def test_get_logs_request_params(self, caplog): + """Params identify the integration id/env, and contain no secrets.""" + client = APIClient(api_token="secret-token", base_url="https://api.myaltimate.com", tenant="elastic") # noqa: S106 + params = {"dbt_core_integration_id": "2", "dbt_core_integration_environment_type": "PROD"} + + with caplog.at_level(logging.DEBUG), patch("requests.get", return_value=make_response()): + client.get("/dbt/v1/signed_url", params=params) + + assert "dbt_core_integration_environment_type" in caplog.text + assert "PROD" in caplog.text + assert "secret-token" not in caplog.text + + +class TestUrllib3Silencing: + def test_urllib3_is_held_at_info_in_debug_mode(self): + """urllib3 logs whole request lines, presigned query string included.""" + configure_logging(debug=True) + + assert logging.getLogger().level == logging.DEBUG + assert logging.getLogger("urllib3").level == logging.INFO diff --git a/tests/utils/test_logging_utils.py b/tests/utils/test_logging_utils.py new file mode 100644 index 00000000..d95b8722 --- /dev/null +++ b/tests/utils/test_logging_utils.py @@ -0,0 +1,99 @@ +import logging + +import pytest + +from datapilot.utils import logging_utils +from datapilot.utils.logging_utils import DEBUG_ENV_VAR +from datapilot.utils.logging_utils import configure_logging +from datapilot.utils.logging_utils import debug_enabled_via_env +from datapilot.utils.logging_utils import is_debug_enabled +from datapilot.utils.logging_utils import redact_url + + +@pytest.fixture(autouse=True) +def _reset_logging_state(monkeypatch): + """Debug mode is sticky by design, so reset it between tests.""" + monkeypatch.setattr(logging_utils, "_debug_enabled", False) + monkeypatch.delenv(DEBUG_ENV_VAR, raising=False) + original_level = logging.getLogger().level + yield + logging.getLogger().setLevel(original_level) + + +class TestDebugEnabledViaEnv: + @pytest.mark.parametrize("value", ["1", "true", "TRUE", "yes", "on", " True "]) + def test_truthy_values(self, monkeypatch, value): + monkeypatch.setenv(DEBUG_ENV_VAR, value) + + assert debug_enabled_via_env() is True + + @pytest.mark.parametrize("value", ["0", "false", "no", "off", "", " "]) + def test_falsy_values(self, monkeypatch, value): + monkeypatch.setenv(DEBUG_ENV_VAR, value) + + assert debug_enabled_via_env() is False + + def test_unset(self): + assert debug_enabled_via_env() is False + + +class TestConfigureLogging: + def test_default_is_info(self): + assert configure_logging() is False + assert is_debug_enabled() is False + assert logging.getLogger().level == logging.INFO + + def test_debug_argument_sets_debug_level(self): + assert configure_logging(debug=True) is True + assert logging.getLogger().level == logging.DEBUG + + def test_env_var_sets_debug_level(self, monkeypatch): + monkeypatch.setenv(DEBUG_ENV_VAR, "1") + + assert configure_logging() is True + assert logging.getLogger().level == logging.DEBUG + + def test_env_var_off_stays_at_info(self, monkeypatch): + monkeypatch.setenv(DEBUG_ENV_VAR, "0") + + assert configure_logging() is False + assert logging.getLogger().level == logging.INFO + + def test_debug_is_sticky_across_calls(self): + """An import-time configure_logging() must not undo a --debug flag, or vice versa.""" + configure_logging(debug=True) + configure_logging(debug=False) + + assert is_debug_enabled() is True + assert logging.getLogger().level == logging.DEBUG + + def test_debug_records_reach_a_handler(self, caplog): + configure_logging(debug=True) + + with caplog.at_level(logging.DEBUG): + logging.getLogger("APIClient").debug("HTTP Error: boom") + + assert "HTTP Error: boom" in caplog.text + + +class TestRedactUrl: + def test_url_without_query_is_unchanged(self): + url = "https://api.myaltimate.com/dbt/v1/signed_url" + + assert redact_url(url) == url + + def test_presigned_url_credentials_are_removed(self): + url = ( + "https://altimate-datapilot-freemium-prod.s3.amazonaws.com/prd/tenant%3Delastic/manifest.json" + "?AWSAccessKeyId=AKIAVXVSOK5H3JQFSSU4&Signature=2LV9nU5JHPVOFz&Expires=1785271367" + ) + + redacted = redact_url(url) + + assert "AKIAVXVSOK5H3JQFSSU4" not in redacted + assert "2LV9nU5JHPVOFz" not in redacted + assert redacted == ("https://altimate-datapilot-freemium-prod.s3.amazonaws.com/prd/tenant%3Delastic/manifest.json?") + + def test_empty_values(self): + assert redact_url("") == "" + assert redact_url(None) == ""