diff --git a/UPDATING.md b/UPDATING.md index 38d0c040b7e..64787158583 100644 --- a/UPDATING.md +++ b/UPDATING.md @@ -24,6 +24,13 @@ assists people when migrating to a new version. ## Next +### OAuth2 database callback metrics include their outcome + +The unqualified `DatabaseRestApi.oauth2` StatsD counter has been replaced with +`DatabaseRestApi.oauth2.success`, `DatabaseRestApi.oauth2.warning`, and +`DatabaseRestApi.oauth2.error`. Update monitoring rules and dashboards that consume +the old counter to use the outcome-specific replacements. + - [42935](https://github.com/apache/superset/pull/42935): The MCP service now refuses to start (`MCPAuthConfigError`) when `MCP_JWT_ISSUER` trusts more than one issuer and no `MCP_USER_RESOLVER` is configured, instead of only logging a warning. This was already a documented misconfiguration (the default resolver isn't issuer-scoped, so distinct trusted issuers minting the same username/email would resolve to the same Superset user); deployments trusting multiple issuers must configure an `MCP_USER_RESOLVER` that derives its identity from the token's `iss` claim before upgrading. Single-issuer deployments are unaffected. - [42393](https://github.com/apache/superset/pull/42393): Exported dataset YAML now carries a `uuid` for each metric and column so that custom folder assignments (which reference metrics/columns by UUID) survive an import into another workspace. This affects any export bundle that contains datasets, not just a dataset export: chart, dashboard, database and full-asset exports all embed the same dataset YAML, so a dashboard exported from this release also fails to import into an older one even though no dataset was exported directly. As with `folders` and `currency_code_column`, the affected `datasets/` files fail schema validation (`Unknown field: uuid`) when imported into Superset releases that predate this change; regenerate or hand-edit exports for older targets in mixed-version fleets. - [42300](https://github.com/apache/superset/pull/42300): Timeseries charts (line/area/bar) with a Y-axis bound in effect — either an explicit `yAxisBounds` or one derived from `truncateYAxis` — now clamp out-of-range data points to that bound instead of letting ECharts drop the point (and the line segments around it) entirely. Any existing chart with a configured Y-axis bound and data outside it will look different after upgrading: a gap becomes a point pinned to the boundary. The clamp also rewrites the value ECharts reads for that point's tooltip and data label, so the displayed value is the bound rather than the true observation. diff --git a/superset/commands/database/oauth2.py b/superset/commands/database/oauth2.py index 8355bc0098e..7b8d116f2c3 100644 --- a/superset/commands/database/oauth2.py +++ b/superset/commands/database/oauth2.py @@ -15,6 +15,7 @@ # specific language governing permissions and limitations # under the License. +import logging from datetime import datetime, timedelta from functools import partial from typing import cast @@ -32,6 +33,8 @@ from superset.superset_typing import OAuth2State from superset.utils.decorators import on_error, transaction from superset.utils.oauth2 import decode_oauth2_state +logger = logging.getLogger(__name__) + class OAuth2StoreTokenCommand(BaseCommand): """ @@ -71,11 +74,21 @@ class OAuth2StoreTokenCommand(BaseCommand): code_verifier = kv_value.get("code_verifier") KeyValueDAO.delete_entry(KeyValueResource.PKCE_CODE_VERIFIER, tab_uuid) - token_response = self._database.db_engine_spec.get_oauth2_token( - oauth2_config, - self._parameters["code"], - code_verifier=code_verifier, - ) + engine_spec = self._database.db_engine_spec + try: + token_response = engine_spec.get_oauth2_token( + oauth2_config, + self._parameters["code"], + code_verifier=code_verifier, + ) + except Exception as ex: + logger.error( + "OAuth2 token exchange failed: database_id=%s engine=%s error_type=%s", + self._database.id, + engine_spec.engine, + type(ex).__name__, + ) + raise OAuth2Error("Token exchange failed") from None # delete old tokens if existing := DatabaseUserOAuth2TokensDAO.find_one_or_none( diff --git a/superset/databases/api.py b/superset/databases/api.py index 7791adaae8a..55b3ba502cd 100644 --- a/superset/databases/api.py +++ b/superset/databases/api.py @@ -1454,11 +1454,14 @@ class DatabaseRestApi(BaseSupersetModelRestApi): return self.response_404() @expose("/oauth2/", methods=["GET"]) - @transaction() + @statsd_metrics(best_effort=True) @event_logger.log_this_with_context( action=lambda self, *args, **kwargs: f"{self.__class__.__name__}.oauth2", - log_to_statsd=True, + log_to_statsd=False, + include_request_data=False, + best_effort=True, ) + @transaction() def oauth2(self) -> FlaskResponse: """ --- diff --git a/superset/db_engine_specs/base.py b/superset/db_engine_specs/base.py index 6a3feb9d5af..2340a593b8a 100644 --- a/superset/db_engine_specs/base.py +++ b/superset/db_engine_specs/base.py @@ -923,7 +923,7 @@ class BaseEngineSpec: # pylint: disable=too-many-public-methods else requests.post(uri, json=req_body, timeout=timeout) ) if response.status_code in (400, 401, 403): - raise OAuth2TokenRefreshError(response.text) + raise OAuth2TokenRefreshError() response.raise_for_status() return response.json() diff --git a/superset/exceptions.py b/superset/exceptions.py index 2fe5b9aad68..fc309f9756e 100644 --- a/superset/exceptions.py +++ b/superset/exceptions.py @@ -383,18 +383,23 @@ class OAuth2TokenRefreshError(OAuth2RedirectError): Raised when an OAuth2 refresh token request fails with a 400/401/403 error. The stored token is no longer valid and the user must re-authenticate. - Subclasses OAuth2RedirectError so that existing oauth2_exception checks - match it automatically, triggering start_oauth2_dance() via check_for_oauth2. + Subclasses OAuth2RedirectError as a sanitized re-authentication marker. + ``check_for_oauth2`` recognizes it independently of vendor-specific exception + classifiers and calls ``start_oauth2_dance`` to attach the authorization metadata. + The optional provider response is accepted for compatibility but discarded so + provider payloads cannot reach logs or API responses through the exception. """ - def __init__(self, response_text: str) -> None: + def __init__( # pylint: disable=unused-argument + self, + response_text: str | None = None, + ) -> None: SupersetErrorException.__init__( self, SupersetError( message="OAuth2 token refresh failed, re-authentication required.", error_type=SupersetErrorType.OAUTH2_REDIRECT, level=ErrorLevel.WARNING, - extra={"error": response_text}, ), ) diff --git a/superset/utils/log.py b/superset/utils/log.py index c5ae88f3366..58051600fbe 100644 --- a/superset/utils/log.py +++ b/superset/utils/log.py @@ -38,21 +38,21 @@ from superset.utils.core import get_user_id, LoggerLevel, to_int logger = logging.getLogger(__name__) -def collect_request_payload() -> dict[str, Any]: +def collect_request_payload(include_request_data: bool = True) -> dict[str, Any]: """Collect log payload identifiable from request context""" if not request: return {} - payload: dict[str, Any] = { - "path": request.path, - **request.form.to_dict(), - # url search params can overwrite POST body - **request.args.to_dict(), - } + payload: dict[str, Any] = {"path": request.path} - if request.is_json: - json_payload = request.get_json(cache=True, silent=True) or {} - payload.update(json_payload) + if include_request_data: + payload.update(request.form.to_dict()) + # URL search params can overwrite POST body. + payload.update(request.args.to_dict()) + + if request.is_json: + json_payload = request.get_json(cache=True, silent=True) or {} + payload.update(json_payload) # save URL match pattern in addition to the request path url_rule = str(request.url_rule) @@ -120,7 +120,7 @@ class AbstractEventLogger(ABC): object_ref: str | None = None, log_to_statsd: bool = True, duration: timedelta | None = None, - **payload_override: dict[str, Any], + **payload_override: object, ) -> object: # pylint: disable=W0201 self.action = action @@ -140,7 +140,7 @@ class AbstractEventLogger(ABC): object_ref=self.object_ref, log_to_statsd=self.log_to_statsd, duration=datetime.now() - self.start, - **self.payload_override, + **cast(dict[str, Any], self.payload_override), ) @classmethod @@ -176,13 +176,18 @@ class AbstractEventLogger(ABC): object_ref: str | None = None, log_to_statsd: bool = True, database: Any | None = None, - **payload_override: dict[str, Any] | None, + include_request_data: bool = True, + **payload_override: object, ) -> None: # pylint: disable=import-outside-toplevel from superset import db from superset.views.core import get_form_data - referrer = request.referrer[:1000] if request and request.referrer else None + referrer = ( + request.referrer[:1000] + if include_request_data and request and request.referrer + else None + ) duration_ms = int(duration.total_seconds() * 1000) if duration else None @@ -203,7 +208,7 @@ class AbstractEventLogger(ABC): except Exception as ex: logger.debug("Failed to add user to db session: %s", ex) user_id = None - payload = collect_request_payload() + payload = collect_request_payload(include_request_data) if object_ref: payload["object_ref"] = object_ref if payload_override: @@ -258,6 +263,8 @@ class AbstractEventLogger(ABC): action: str, object_ref: str | None = None, log_to_statsd: bool = True, + include_request_data: bool = True, + best_effort: bool = False, **kwargs: Any, ) -> Iterator[Callable[..., None]]: """ @@ -265,6 +272,9 @@ class AbstractEventLogger(ABC): :param action: a name to identify the event :param object_ref: reference to the Python object that triggered this action :param log_to_statsd: whether to update statsd counter for the action + :param include_request_data: whether to include form, query, JSON, and referrer + data + :param best_effort: whether event logger failures should be logged and ignored """ payload_override = kwargs.copy() start = datetime.now() @@ -274,9 +284,23 @@ class AbstractEventLogger(ABC): # take the action from payload_override else take the function param action action_str = payload_override.pop("action", action) - self.log_with_context( - action_str, duration, object_ref, log_to_statsd, **payload_override - ) + try: + self.log_with_context( + action_str, + duration, + object_ref, + log_to_statsd, + include_request_data=include_request_data, + **payload_override, + ) + except Exception as ex: # pylint: disable=broad-except + if not best_effort: + raise + logger.warning( + "Event logging failed: action=%s error_type=%s", + action_str, + type(ex).__name__, + ) def _wrapper( self, diff --git a/superset/utils/oauth2.py b/superset/utils/oauth2.py index 020f5397b3c..c173e5a579c 100644 --- a/superset/utils/oauth2.py +++ b/superset/utils/oauth2.py @@ -33,7 +33,11 @@ from werkzeug.routing import BuildError from superset import db from superset.distributed_lock import DistributedLock -from superset.exceptions import AcquireDistributedLockFailedException, OAuth2Error +from superset.exceptions import ( + AcquireDistributedLockFailedException, + OAuth2Error, + OAuth2TokenRefreshError, +) from superset.superset_typing import OAuth2ClientConfig, OAuth2State if TYPE_CHECKING: @@ -164,23 +168,26 @@ def refresh_oauth2_token( except db_engine_spec.oauth2_exception as ex: # OAuth token is no longer valid, delete it and start OAuth2 dance logger.warning( - "OAuth2 token refresh failed for user=%s db=%s, " - "deleting token. Error: %s", - user_id, + "OAuth2 token refresh failed: database_id=%s engine=%s error_type=%s; " + "deleting token", database_id, - ex, + db_engine_spec.engine, + type(ex).__name__, ) db.session.delete(token) db.session.flush() - raise - except Exception: - # non-OAuth related failure, log the exception - logger.warning( - "OAuth2 token refresh failed for user=%s db=%s", - user_id, + raise OAuth2TokenRefreshError() from None + # Engine specs can delegate to arbitrary provider clients that do not share an + # exception base class. Sanitize every other provider-boundary failure while + # preserving the refresh token for a later retry. + except Exception as ex: # pylint: disable=broad-except + logger.error( + "OAuth2 token refresh failed: database_id=%s engine=%s error_type=%s", database_id, + db_engine_spec.engine, + type(ex).__name__, ) - raise + raise OAuth2Error("Token refresh failed") from None # store new access token; note that the refresh token might be revoked, in which # case there would be no access token in the response @@ -315,6 +322,9 @@ def check_for_oauth2(database: Database) -> Iterator[None]: try: yield except Exception as ex: - if database.is_oauth2_enabled() and database.db_engine_spec.needs_oauth2(ex): + if database.is_oauth2_enabled() and ( + isinstance(ex, OAuth2TokenRefreshError) + or database.db_engine_spec.needs_oauth2(ex) + ): database.db_engine_spec.start_oauth2_dance(database) raise diff --git a/superset/views/base_api.py b/superset/views/base_api.py index d556654c58b..28fe984af3b 100644 --- a/superset/views/base_api.py +++ b/superset/views/base_api.py @@ -18,7 +18,7 @@ from __future__ import annotations import functools import logging -from typing import Any, Callable, cast, Optional +from typing import Any, Callable, cast, Optional, overload from flask import request, Response from flask_appbuilder import Model, ModelRestApi @@ -116,26 +116,67 @@ def requires_form_data(f: Callable[..., Any]) -> Callable[..., Any]: return functools.update_wrapper(wraps, f) -def statsd_metrics(f: Callable[..., Any]) -> Callable[..., Any]: +@overload +def statsd_metrics( + f: Callable[..., Any], + *, + best_effort: bool = False, +) -> Callable[..., Any]: ... + + +@overload +def statsd_metrics( + f: None = None, + *, + best_effort: bool = False, +) -> Callable[[Callable[..., Any]], Callable[..., Any]]: ... + + +def statsd_metrics( + f: Callable[..., Any] | None = None, + *, + best_effort: bool = False, +) -> Callable[..., Any]: """ - Handle sending all statsd metrics from the REST API + Handle sending all StatsD metrics from the REST API. + + When ``best_effort`` is true, a metrics backend failure is logged and ignored so + it cannot replace the endpoint response or exception. """ - def wraps(self: BaseSupersetApiMixin, *args: Any, **kwargs: Any) -> Response: - func_name = f.__name__ - try: - duration, response = time_function(f, self, *args, **kwargs) - except Exception as ex: - if hasattr(ex, "status") and ex.status < 500: # pylint: disable=no-member - self.incr_stats("warning", func_name) - else: - self.incr_stats("error", func_name) - raise + def decorate(func: Callable[..., Any]) -> Callable[..., Any]: + def wraps(self: BaseSupersetApiMixin, *args: Any, **kwargs: Any) -> Response: + func_name = func.__name__ - self.send_stats_metrics(response, func_name, duration) - return response + def emit_metrics(callback: Callable[[], None]) -> None: + try: + callback() + except Exception as ex: # pylint: disable=broad-except + if not best_effort: + raise + logger.warning( + "REST API metrics emission failed: endpoint=%s error_type=%s", + func.__qualname__, + type(ex).__name__, + ) - return functools.update_wrapper(wraps, f) + try: + duration, response = time_function(func, self, *args, **kwargs) + except Exception as ex: + action = ( + "warning" + if hasattr(ex, "status") and ex.status < 500 # pylint: disable=no-member + else "error" + ) + emit_metrics(lambda: self.incr_stats(action, func_name)) + raise + + emit_metrics(lambda: self.send_stats_metrics(response, func_name, duration)) + return response + + return functools.update_wrapper(wraps, func) + + return decorate(f) if f is not None else decorate def validate_feature_flags( diff --git a/tests/unit_tests/commands/databases/oauth2_test.py b/tests/unit_tests/commands/databases/oauth2_test.py index 0fbe2035d29..c0c11dcdcc2 100644 --- a/tests/unit_tests/commands/databases/oauth2_test.py +++ b/tests/unit_tests/commands/databases/oauth2_test.py @@ -15,11 +15,14 @@ # specific language governing permissions and limitations # under the License. +import logging +import traceback from typing import Any from unittest.mock import MagicMock import pytest from pytest_mock import MockerFixture +from requests.exceptions import HTTPError from superset.commands.database.exceptions import DatabaseNotFoundError from superset.commands.database.oauth2 import OAuth2StoreTokenCommand @@ -33,6 +36,8 @@ from superset.utils.oauth2 import decode_oauth2_state, encode_oauth2_state @pytest.fixture def mock_database(mocker: MockerFixture) -> MagicMock: database = mocker.MagicMock(spec=Database) + database.id = 123 + database.db_engine_spec.engine = "postgresql" database.get_oauth2_config.return_value = { "client_id": "test", "client_secret": "secret", @@ -135,6 +140,43 @@ def test_run_success( mock_create.assert_called_once() +def test_run_logs_token_exchange_failure( + mocker: MockerFixture, + caplog: pytest.LogCaptureFixture, + mock_database: MagicMock, + mock_parameters: OAuth2ProviderResponseSchema, +) -> None: + mock_parameters["code"] = "oauth-code-sentinel" + mock_database.get_oauth2_config.return_value["client_secret"] = ( + "client-secret-sentinel" # noqa: S105 + ) + mocker.patch.object( + DatabaseUserOAuth2TokensDAO, + "get_database", + return_value=mock_database, + ) + mock_database.db_engine_spec.get_oauth2_token.side_effect = HTTPError( + "provider-payload-sentinel" + ) + + with ( + caplog.at_level(logging.ERROR, logger="superset.commands.database.oauth2"), + pytest.raises(OAuth2Error) as exc_info, + ): + OAuth2StoreTokenCommand(mock_parameters).run() + + assert ( + "OAuth2 token exchange failed: database_id=123 engine=postgresql " + "error_type=HTTPError" + ) in caplog.messages + assert "oauth-code-sentinel" not in caplog.text + assert "client-secret-sentinel" not in caplog.text + assert "provider-payload-sentinel" not in caplog.text + assert "provider-payload-sentinel" not in "".join( + traceback.format_exception(exc_info.value) + ) + + def test_run_existing_token( mocker: MockerFixture, mock_database: MagicMock, diff --git a/tests/unit_tests/databases/oauth2_api_test.py b/tests/unit_tests/databases/oauth2_api_test.py new file mode 100644 index 00000000000..3b6c074f2f9 --- /dev/null +++ b/tests/unit_tests/databases/oauth2_api_test.py @@ -0,0 +1,275 @@ +# 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. + +import logging +from typing import Any +from unittest.mock import MagicMock + +import pytest +from pytest_mock import MockerFixture +from requests.exceptions import HTTPError + +from superset import db +from superset.commands.database.exceptions import DatabaseNotFoundError +from superset.daos.database import DatabaseUserOAuth2TokensDAO +from superset.exceptions import OAuth2Error +from superset.extensions import event_logger, stats_logger_manager +from superset.models.core import Database, Log +from superset.superset_typing import OAuth2State +from superset.utils.oauth2 import encode_oauth2_state + + +@pytest.fixture +def oauth2_command(mocker: MockerFixture) -> MagicMock: + command = mocker.patch("superset.databases.api.OAuth2StoreTokenCommand") + mocker.patch("superset.databases.api.render_template", return_value="OK") + return command + + +def callback_state() -> str: + state: OAuth2State = { + "user_id": 1, + "database_id": 1, + "tab_id": "42", + "default_redirect_uri": "http://localhost:8088/api/v1/oauth2/", + } + return encode_oauth2_state(state) + + +@pytest.mark.parametrize( + ("exchange_error", "expected_status", "expected_outcome", "transaction_method"), + [ + (None, 200, "success", "commit"), + (DatabaseNotFoundError(), 404, "warning", "rollback"), + (OAuth2Error("Token exchange failed"), 500, "error", "rollback"), + ], +) +def test_oauth2_callback_emits_one_outcome_metric_after_transaction( + mocker: MockerFixture, + client: Any, + full_api_access: None, + oauth2_command: MagicMock, + exchange_error: Exception | None, + expected_status: int, + expected_outcome: str, + transaction_method: str, +) -> None: + oauth2_command.return_value.run.side_effect = exchange_error + + calls = mocker.MagicMock() + transaction_complete = mocker.patch.object(db.session, transaction_method) + event_log = mocker.patch.object(event_logger, "log") + metric = mocker.patch.object(stats_logger_manager.instance, "incr") + calls.attach_mock(transaction_complete, "transaction_complete") + calls.attach_mock(event_log, "event_log") + calls.attach_mock(metric, "metric") + + response = client.get( + "/api/v1/database/oauth2/", + query_string={ + "state": callback_state(), + "code": "XXX", + }, + ) + + assert response.status_code == expected_status + expected_calls = ["transaction_complete"] + if exchange_error is None: + expected_calls.append("event_log") + expected_calls.append("metric") + assert [mock_call[0] for mock_call in calls.mock_calls] == expected_calls + metric.assert_called_once_with(f"DatabaseRestApi.oauth2.{expected_outcome}") + + +def test_oauth2_callback_excludes_provider_data_from_event_log( + mocker: MockerFixture, + client: Any, + full_api_access: None, + oauth2_command: MagicMock, +) -> None: + event_log = mocker.patch.object(event_logger, "log") + + response = client.get( + "/api/v1/database/oauth2/", + query_string={ + "state": callback_state(), + "code": "oauth-code-sentinel", + "scope": "oauth-scope-sentinel", + "error_description": "provider-error-sentinel", + "provider_payload": "provider-payload-sentinel", + }, + headers={ + "Referer": "https://idp.example/authorize?code=referrer-code-sentinel" + }, + ) + + assert response.status_code == 200 + record = event_log.call_args.kwargs["records"][0] + assert record["path"] == "/api/v1/database/oauth2/" + assert { + "state", + "code", + "scope", + "error_description", + "provider_payload", + }.isdisjoint(record) + assert event_log.call_args.kwargs["referrer"] is None + + +def test_oauth2_callback_redacts_exchange_exception_from_all_logs( + mocker: MockerFixture, + caplog: pytest.LogCaptureFixture, + client: Any, + full_api_access: None, +) -> None: + database = mocker.MagicMock(spec=Database) + database.id = 1 + database.db_engine_spec.engine = "postgresql" + database.get_oauth2_config.return_value = { + "client_id": "client-id", + "client_secret": "client-secret", + } + database.db_engine_spec.get_oauth2_token.side_effect = HTTPError( + "provider-payload-sentinel" + ) + mocker.patch.object( + DatabaseUserOAuth2TokensDAO, + "get_database", + return_value=database, + ) + mocker.patch.object(event_logger, "log") + + with caplog.at_level(logging.DEBUG): + response = client.get( + "/api/v1/database/oauth2/", + query_string={ + "state": callback_state(), + "code": "oauth-code-sentinel", + }, + ) + + assert response.status_code == 500 + assert "provider-payload-sentinel" not in caplog.text + assert "oauth-code-sentinel" not in caplog.text + assert "provider-payload-sentinel" not in response.get_data(as_text=True) + assert "oauth-code-sentinel" not in response.get_data(as_text=True) + + +def test_oauth2_callback_event_log_failure_preserves_business_write( + mocker: MockerFixture, + caplog: pytest.LogCaptureFixture, + client: Any, + full_api_access: None, + oauth2_command: MagicMock, +) -> None: + action = "oauth2_business_write_test" + db.session.query(Log).filter_by(action=action).delete() + db.session.commit() + oauth2_command.return_value.run.side_effect = lambda: db.session.add( + Log(action=action) + ) + event_log = mocker.patch.object( + event_logger, + "log", + side_effect=RuntimeError("event-log-payload-sentinel"), + ) + metric = mocker.patch.object(stats_logger_manager.instance, "incr") + + try: + with caplog.at_level(logging.WARNING, logger="superset.utils.log"): + response = client.get( + "/api/v1/database/oauth2/", + query_string={ + "state": callback_state(), + "code": "XXX", + }, + ) + + assert response.status_code == 200 + assert db.session.query(Log).filter_by(action=action).one() + event_log.assert_called_once() + metric.assert_called_once_with("DatabaseRestApi.oauth2.success") + assert ( + "Event logging failed: action=DatabaseRestApi.oauth2 " + "error_type=RuntimeError" + ) in caplog.messages + assert "event-log-payload-sentinel" not in caplog.text + finally: + db.session.query(Log).filter_by(action=action).delete() + db.session.commit() + + +def test_oauth2_callback_metric_failure_preserves_success_response( + mocker: MockerFixture, + caplog: pytest.LogCaptureFixture, + client: Any, + full_api_access: None, + oauth2_command: MagicMock, +) -> None: + mocker.patch.object(event_logger, "log") + metric = mocker.patch.object( + stats_logger_manager.instance, + "incr", + side_effect=RuntimeError("metrics-payload-sentinel"), + ) + + with caplog.at_level(logging.WARNING, logger="superset.views.base_api"): + response = client.get( + "/api/v1/database/oauth2/", + query_string={"state": callback_state(), "code": "XXX"}, + ) + + assert response.status_code == 200 + oauth2_command.return_value.run.assert_called_once() + metric.assert_called_once_with("DatabaseRestApi.oauth2.success") + assert ( + "REST API metrics emission failed: endpoint=DatabaseRestApi.oauth2 " + "error_type=RuntimeError" + ) in caplog.messages + assert "metrics-payload-sentinel" not in caplog.text + + +def test_oauth2_callback_metric_failure_preserves_oauth_error( + mocker: MockerFixture, + caplog: pytest.LogCaptureFixture, + client: Any, + full_api_access: None, + oauth2_command: MagicMock, +) -> None: + oauth2_command.return_value.run.side_effect = OAuth2Error("Token exchange failed") + mocker.patch.object(event_logger, "log") + metric = mocker.patch.object( + stats_logger_manager.instance, + "incr", + side_effect=RuntimeError("metrics-payload-sentinel"), + ) + + with caplog.at_level(logging.WARNING, logger="superset.views.base_api"): + response = client.get( + "/api/v1/database/oauth2/", + query_string={"state": callback_state(), "code": "XXX"}, + ) + + assert response.status_code == 500 + assert response.json["errors"][0]["extra"] == {"error": "Token exchange failed"} + metric.assert_called_once_with("DatabaseRestApi.oauth2.error") + assert ( + "REST API metrics emission failed: endpoint=DatabaseRestApi.oauth2 " + "error_type=RuntimeError" + ) in caplog.messages + assert "metrics-payload-sentinel" not in caplog.text + assert "metrics-payload-sentinel" not in response.get_data(as_text=True) diff --git a/tests/unit_tests/db_engine_specs/test_base.py b/tests/unit_tests/db_engine_specs/test_base.py index 2b121853bc5..dfd221dcf08 100644 --- a/tests/unit_tests/db_engine_specs/test_base.py +++ b/tests/unit_tests/db_engine_specs/test_base.py @@ -1162,7 +1162,7 @@ def test_get_oauth2_fresh_token_raises_on_auth_error( mock_post = mocker.patch("superset.db_engine_specs.base.requests.post") mock_post.return_value.status_code = status_code - mock_post.return_value.text = '{"error": "invalid_grant"}' + mock_post.return_value.text = '{"error": "provider-payload-sentinel"}' config: OAuth2ClientConfig = { "id": "client-id", @@ -1177,7 +1177,7 @@ def test_get_oauth2_fresh_token_raises_on_auth_error( with pytest.raises(OAuth2TokenRefreshError) as exc_info: BaseEngineSpec.get_oauth2_fresh_token(config, "refresh-token") - assert exc_info.value.error.extra["error"] == '{"error": "invalid_grant"}' + assert "provider-payload-sentinel" not in str(exc_info.value.to_dict()) @with_config({"DATABASE_OAUTH2_TIMEOUT": timedelta(seconds=30)}) diff --git a/tests/unit_tests/utils/oauth2_tests.py b/tests/unit_tests/utils/oauth2_tests.py index ac788ce66e5..4584a71fc74 100644 --- a/tests/unit_tests/utils/oauth2_tests.py +++ b/tests/unit_tests/utils/oauth2_tests.py @@ -19,6 +19,8 @@ import base64 import hashlib +import logging +import traceback from datetime import datetime from typing import cast @@ -26,8 +28,15 @@ import pytest from freezegun import freeze_time from pytest_mock import MockerFixture +from superset.db_engine_specs.base import BaseEngineSpec +from superset.exceptions import ( + OAuth2Error, + OAuth2RedirectError, + OAuth2TokenRefreshError, +) from superset.superset_typing import OAuth2ClientConfig from superset.utils.oauth2 import ( + check_for_oauth2, decode_oauth2_state, encode_oauth2_state, generate_code_challenge, @@ -112,6 +121,7 @@ def test_get_oauth2_access_token_base_no_refresh(mocker: MockerFixture) -> None: def test_refresh_oauth2_token_deletes_token_on_oauth2_exception( mocker: MockerFixture, + caplog: pytest.LogCaptureFixture, ) -> None: """ Test that refresh_oauth2_token deletes the token on OAuth2-specific exception. @@ -126,24 +136,91 @@ def test_refresh_oauth2_token_deletes_token_on_oauth2_exception( pass db_engine_spec = mocker.MagicMock() + db_engine_spec.engine = "postgresql" db_engine_spec.oauth2_exception = OAuth2ExceptionError db_engine_spec.get_oauth2_fresh_token.side_effect = OAuth2ExceptionError( - "Token revoked" + "provider-error-sentinel" ) token = mocker.MagicMock() token.access_token = None - token.refresh_token = "refresh-token" # noqa: S105 + token.refresh_token = "refresh-token-sentinel" # noqa: S105 db.session.query().filter_by().one_or_none.return_value = token - with pytest.raises(OAuth2ExceptionError): + with ( + caplog.at_level(logging.WARNING, logger="superset.utils.oauth2"), + pytest.raises(OAuth2TokenRefreshError) as exc_info, + ): refresh_oauth2_token(DUMMY_OAUTH2_CONFIG, 1, 1, db_engine_spec) db.session.delete.assert_called_with(token) db.session.flush.assert_called_once() + assert ( + "OAuth2 token refresh failed: database_id=1 engine=postgresql " + "error_type=OAuth2ExceptionError; deleting token" + ) in caplog.messages + assert "refresh-token-sentinel" not in caplog.text + assert "provider-error-sentinel" not in caplog.text + assert "provider-error-sentinel" not in "".join( + traceback.format_exception(exc_info.value) + ) + + +def test_refresh_oauth2_token_starts_dance_for_vendor_exception( + mocker: MockerFixture, +) -> None: + """A sanitized vendor refresh failure must still start re-authentication.""" + db = mocker.patch("superset.utils.oauth2.db") + mocker.patch("superset.utils.oauth2.DistributedLock") + + class VendorOAuthError(Exception): + pass + + class VendorEngineSpec(BaseEngineSpec): + engine = "vendor" + oauth2_exception = VendorOAuthError + + mocker.patch.object( + VendorEngineSpec, + "get_oauth2_fresh_token", + side_effect=VendorOAuthError("provider-payload-sentinel"), + ) + needs_oauth2 = mocker.patch.object( + VendorEngineSpec, + "needs_oauth2", + return_value=False, + ) + redirect = OAuth2RedirectError( + "https://provider.example/authorize", + "tab-id", + "https://superset.example/oauth2/", + ) + start_oauth2_dance = mocker.patch.object( + VendorEngineSpec, + "start_oauth2_dance", + side_effect=redirect, + ) + database = mocker.MagicMock() + database.is_oauth2_enabled.return_value = True + database.db_engine_spec = VendorEngineSpec + token = mocker.MagicMock() + token.access_token = None + token.refresh_token = "refresh-token-sentinel" # noqa: S105 + db.session.query().filter_by().one_or_none.return_value = token + + with pytest.raises(OAuth2RedirectError) as exc_info: + with check_for_oauth2(database): + refresh_oauth2_token(DUMMY_OAUTH2_CONFIG, 1, 1, VendorEngineSpec) + + assert exc_info.value is redirect + db.session.delete.assert_called_once_with(token) + db.session.flush.assert_called_once() + start_oauth2_dance.assert_called_once_with(database) + needs_oauth2.assert_not_called() def test_refresh_oauth2_token_keeps_token_on_other_exception( mocker: MockerFixture, + caplog: pytest.LogCaptureFixture, ) -> None: """ Test that refresh_oauth2_token keeps the token on non-OAuth2 exceptions. @@ -159,17 +236,32 @@ def test_refresh_oauth2_token_keeps_token_on_other_exception( pass db_engine_spec = mocker.MagicMock() + db_engine_spec.engine = "postgresql" db_engine_spec.oauth2_exception = OAuth2ExceptionError - db_engine_spec.get_oauth2_fresh_token.side_effect = Exception("Network error") + db_engine_spec.get_oauth2_fresh_token.side_effect = Exception( + "Network error: provider-payload-sentinel" + ) token = mocker.MagicMock() token.access_token = None - token.refresh_token = "refresh-token" # noqa: S105 + token.refresh_token = "refresh-token-sentinel" # noqa: S105 db.session.query().filter_by().one_or_none.return_value = token - with pytest.raises(Exception, match="Network error"): + with ( + caplog.at_level(logging.ERROR, logger="superset.utils.oauth2"), + pytest.raises(OAuth2Error) as exc_info, + ): refresh_oauth2_token(DUMMY_OAUTH2_CONFIG, 1, 1, db_engine_spec) db.session.delete.assert_not_called() + assert ( + "OAuth2 token refresh failed: database_id=1 engine=postgresql " + "error_type=Exception" + ) in caplog.messages + assert "refresh-token-sentinel" not in caplog.text + assert "provider-payload-sentinel" not in caplog.text + assert "provider-payload-sentinel" not in "".join( + traceback.format_exception(exc_info.value) + ) def test_refresh_oauth2_token_no_access_token_in_response(