This is an automated email from the ASF dual-hosted git repository. eschutho pushed a commit to branch fix-import-validation-log-level in repository https://gitbox.apache.org/repos/asf/superset.git
commit aa92f20964c4d78976e81ebdf5d505f431df12a8 Author: Elizabeth Thompson <[email protected]> AuthorDate: Fri Sep 25 15:16:03 2026 +0000 fix(import): downgrade expected validation-failure logs from error to warning (SC-122372) Chart, dashboard, database, dataset and saved-query imports validate every uploaded YAML file in ImportModelsCommand.validate() / load_configs(). A file that fails validation (missing required field, invalid UUID, bad masked_encrypted_extra JSON, missing key, or "already exists and `overwrite=true` was not passed") is collected into a ValidationError and raised as CommandInvalidError, which the app-level CommandException error handler renders with its status of 422. The client already gets a correct 4xx response for these expected, user-input-driven conditions. Along the way, however, five logger.error() calls reported each failure at ERROR severity. Because the messages interpolate the uploaded file name, error-tracking integrations that capture ERROR logs turned each one into its own low-count "error" issue, fragmenting and hiding the real volume. Log these five call sites at WARNING instead. This is a pure log-level change: the raised exception, HTTP status and response body are unchanged, and the messages remain in application logs for support and debugging. The unrelated tag-association logger.error() calls in utils.py (genuinely unexpected parse/DB failures) are left at ERROR. Fixes SUPERSET-PYTHON-17BW Fixes SUPERSET-PYTHON-17BV Fixes SUPERSET-PYTHON-17BT Fixes SUPERSET-PYTHON-17BS Fixes SUPERSET-PYTHON-17CZ Fixes SUPERSET-PYTHON-16GB Co-Authored-By: Claude Opus 5.5 <[email protected]> --- superset/commands/importers/v1/__init__.py | 6 +- superset/commands/importers/v1/utils.py | 6 +- .../commands/importers/v1/import_models_test.py | 93 +++++++++++++++++++ .../unit_tests/commands/importers/v1/utils_test.py | 100 ++++++++++++++++++++- 4 files changed, 199 insertions(+), 6 deletions(-) diff --git a/superset/commands/importers/v1/__init__.py b/superset/commands/importers/v1/__init__.py index 0583e9c3b04..6c304981bef 100644 --- a/superset/commands/importers/v1/__init__.py +++ b/superset/commands/importers/v1/__init__.py @@ -137,10 +137,12 @@ class ImportModelsCommand(BaseCommand): # Extract detailed error information if hasattr(ex, "messages") and isinstance(ex.messages, dict): for file_name, errors in ex.messages.items(): - logger.error("Validation failed for %s: %s", file_name, errors) + logger.warning( + "Validation failed for %s: %s", file_name, errors + ) detailed_errors.append(f"{file_name}: {errors}") else: - logger.error("Import validation error: %s", ex) + logger.warning("Import validation error: %s", ex) detailed_errors.append(str(ex)) error_summary = "; ".join(detailed_errors) diff --git a/superset/commands/importers/v1/utils.py b/superset/commands/importers/v1/utils.py index a2dc34ddd37..b6fad70f3df 100644 --- a/superset/commands/importers/v1/utils.py +++ b/superset/commands/importers/v1/utils.py @@ -303,7 +303,7 @@ def load_configs( schema.load(config) configs[file_name] = config except ValidationError as exc: - logger.error( + logger.warning( "Schema validation failed for %s (prefix: %s): %s", file_name, prefix, @@ -332,7 +332,7 @@ def load_configs( # the raw decode error into a ValidationError so it flows into # the aggregated CommandInvalidError like every other per-file # validation failure, instead of escaping as an opaque 500. - logger.error( + logger.warning( "Invalid JSON in masked_encrypted_extra for %s: %s", file_name, exc, @@ -348,7 +348,7 @@ def load_configs( # per-file error. Convert it into a ValidationError so it flows # into the same aggregated error path. field = str(exc).strip("'\"") - logger.error( + logger.warning( "Missing required key %s in config for %s (prefix: %s)", exc, file_name, diff --git a/tests/unit_tests/commands/importers/v1/import_models_test.py b/tests/unit_tests/commands/importers/v1/import_models_test.py new file mode 100644 index 00000000000..37a0ed11553 --- /dev/null +++ b/tests/unit_tests/commands/importers/v1/import_models_test.py @@ -0,0 +1,93 @@ +# Licensed to the Apache Software Foundation (ASF) under one +# or more contributor license agreements. See the NOTICE file +# distributed with this work for additional information +# regarding copyright ownership. The ASF licenses this file +# to you under the Apache License, Version 2.0 (the +# "License"); you may not use this file except in compliance +# with the License. You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, +# software distributed under the License is distributed on an +# "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY +# KIND, either express or implied. See the License for the +# specific language governing permissions and limitations +# under the License. +"""Tests for ImportModelsCommand.validate() in superset/commands/importers/v1.""" + +import logging +from typing import Any +from unittest.mock import patch + +import pytest +from marshmallow import fields, Schema +from marshmallow.exceptions import ValidationError + +from superset.commands.exceptions import CommandInvalidError +from superset.commands.importers.v1 import ImportModelsCommand + +METADATA = "version: 1.0.0\ntype: Thing\ntimestamp: '2021-01-01T00:00:00+00:00'\n" + + +class _ThingSchema(Schema): + uuid = fields.UUID(required=True) + name = fields.String(required=True) + + +class _ImportThingsCommand(ImportModelsCommand): + model_name = "thing" + prefix = "things/" + schemas = {"things/": _ThingSchema()} + + +def _assert_only_warnings(caplog: pytest.LogCaptureFixture, fragment: str) -> None: + matching = [r for r in caplog.records if fragment in r.getMessage()] + assert matching, f"no log record containing {fragment!r}" + assert all(r.levelno == logging.WARNING for r in matching) + assert not [r for r in caplog.records if r.levelno >= logging.ERROR] + + [email protected](_ImportThingsCommand, "_get_uuids", return_value=set()) +@patch("superset.commands.importers.v1.utils.db") +def test_validate_logs_per_file_failures_as_warning( + mock_db: Any, mock_get_uuids: Any, caplog: pytest.LogCaptureFixture +) -> None: + """Per-file validation failures are returned to the client as a 422 + (CommandInvalidError), so logging them is informational: WARNING, not + ERROR.""" + mock_db.session.query.return_value.all.return_value = [] + contents = { + "metadata.yaml": METADATA, + "things/thing.yaml": "uuid: 6ff1d5b3-4b0f-4c6a-9d2f-9c8b7a6e5d4c\n", + } + + caplog.set_level(logging.WARNING) + with pytest.raises(CommandInvalidError) as excinfo: + _ImportThingsCommand(contents).validate() + + assert excinfo.value.status == 422 + _assert_only_warnings(caplog, "Validation failed for things/thing.yaml") + + [email protected](_ImportThingsCommand, "_get_uuids", return_value=set()) +@patch("superset.commands.importers.v1.load_configs") +def test_validate_logs_non_mapping_errors_as_warning( + mock_load_configs: Any, mock_get_uuids: Any, caplog: pytest.LogCaptureFixture +) -> None: + """ValidationErrors whose messages are not keyed by file name take the + fallback branch, which is also logged at WARNING.""" + + def _load_configs( + contents: Any, schemas: Any, passwords: Any, exceptions: Any, *args: Any + ) -> dict[str, Any]: + exceptions.append(ValidationError("something is wrong")) + return {} + + mock_load_configs.side_effect = _load_configs + + caplog.set_level(logging.WARNING) + with pytest.raises(CommandInvalidError): + _ImportThingsCommand({"metadata.yaml": METADATA}).validate() + + _assert_only_warnings(caplog, "Import validation error") diff --git a/tests/unit_tests/commands/importers/v1/utils_test.py b/tests/unit_tests/commands/importers/v1/utils_test.py index 3a2a52586e6..ee4beaa5fa0 100644 --- a/tests/unit_tests/commands/importers/v1/utils_test.py +++ b/tests/unit_tests/commands/importers/v1/utils_test.py @@ -18,6 +18,7 @@ import gzip import io +import logging from unittest.mock import MagicMock, patch import pandas as pd @@ -166,6 +167,16 @@ class TestLoadYaml: load_yaml("test.yaml", 'key: "unterminated string') +def _assert_logged_as_warning(caplog: pytest.LogCaptureFixture, fragment: str) -> None: + """Expected, user-input validation failures are already surfaced to the + client as a 422; they must be logged at WARNING, never ERROR, so they do + not show up as error events in log-based alerting.""" + matching = [r for r in caplog.records if fragment in r.getMessage()] + assert matching, f"no log record containing {fragment!r}" + assert all(r.levelno == logging.WARNING for r in matching) + assert not [r for r in caplog.records if r.levelno >= logging.ERROR] + + class TestLoadConfigs: """ Per-file failures inside load_configs() must be collected as @@ -201,7 +212,7 @@ class TestLoadConfigs: @patch("superset.commands.importers.v1.utils.db") def test_invalid_json_in_masked_encrypted_extra_is_collected( - self, mock_db: object + self, mock_db: object, caplog: pytest.LogCaptureFixture ) -> None: """A non-JSON ``masked_encrypted_extra`` is converted into a ValidationError appended to ``exceptions`` rather than raising.""" @@ -222,6 +233,7 @@ class TestLoadConfigs: } exceptions: list[ValidationError] = [] + caplog.set_level(logging.WARNING) configs = load_configs( contents=contents, schemas={"databases/": self._trivial_schema()}, @@ -240,6 +252,7 @@ class TestLoadConfigs: assert isinstance(exceptions[0], ValidationError) assert file_name in exceptions[0].messages assert "masked_encrypted_extra" in exceptions[0].messages[file_name] + _assert_logged_as_warning(caplog, "Invalid JSON in masked_encrypted_extra") @patch("superset.commands.importers.v1.utils.db") def test_valid_json_in_masked_encrypted_extra_still_merges( @@ -316,6 +329,91 @@ class TestLoadConfigs: assert isinstance(exceptions[0], ValidationError) assert "databases/bad.yaml" in exceptions[0].messages + @patch("superset.commands.importers.v1.utils.db") + def test_missing_key_read_before_validation_logged_as_warning( + self, mock_db: MagicMock, caplog: pytest.LogCaptureFixture + ) -> None: + """An SSH tunnel password supplied for a config that has no + ``ssh_tunnel`` section hits a raw KeyError before schema validation; + it is collected as a ValidationError and logged at WARNING.""" + from marshmallow.exceptions import ValidationError + + from superset.commands.importers.v1.utils import load_configs + + mock_db.session.query.return_value.all.return_value = [] + + file_name = "databases/no_tunnel.yaml" + contents = { + file_name: ( + "uuid: 6ff1d5b3-4b0f-4c6a-9d2f-9c8b7a6e5d4c\n" + "database_name: no_tunnel\n" + "sqlalchemy_uri: postgres://localhost\n" + "password: secret\n" + ), + } + exceptions: list[ValidationError] = [] + + caplog.set_level(logging.WARNING) + configs = load_configs( + contents, + self._database_schemas(), + {}, + exceptions, + {file_name: "tunnel_secret"}, + {}, + {}, + {}, + ) + + assert file_name not in configs + assert len(exceptions) == 1 + assert exceptions[0].messages == { + file_name: {"ssh_tunnel": ["Missing data for required field."]} + } + _assert_logged_as_warning(caplog, "Missing required key") + + @patch("superset.commands.importers.v1.utils.db") + def test_schema_validation_failure_logged_as_warning( + self, mock_db: MagicMock, caplog: pytest.LogCaptureFixture + ) -> None: + """A config failing marshmallow schema validation (e.g. a missing + required field) is collected and logged at WARNING, not ERROR.""" + from marshmallow.exceptions import ValidationError + + from superset.commands.importers.v1.utils import load_configs + + mock_db.session.query.return_value.all.return_value = [] + + contents = { + "databases/incomplete.yaml": ( + "uuid: 6ff1d5b3-4b0f-4c6a-9d2f-9c8b7a6e5d4c\n" + "database_name: incomplete\n" + "password: secret\n" + ), + } + exceptions: list[ValidationError] = [] + + caplog.set_level(logging.WARNING) + configs = load_configs( + contents, + self._database_schemas(), + {}, + exceptions, + {}, + {}, + {}, + {}, + ) + + assert "databases/incomplete.yaml" not in configs + assert len(exceptions) == 1 + assert exceptions[0].messages == { + "databases/incomplete.yaml": { + "sqlalchemy_uri": ["Missing data for required field."] + } + } + _assert_logged_as_warning(caplog, "Schema validation failed") + @patch("superset.commands.importers.v1.utils.db") def test_uuid_present_loads_successfully(self, mock_db: MagicMock) -> None: """Control: a well-formed databases config loads with no exceptions."""
