Skip to content

fix(logging): stop noisy LocalProxy-not-mapped warning for guest users - #42306

Merged
aminghadersohi merged 2 commits into
apache:masterfrom
aminghadersohi:aminghadersohi/fix-noisy-guest-user-log-warning
Jul 24, 2026
Merged

aminghadersohi merged 2 commits into
apache:masterfrom
aminghadersohi:aminghadersohi/fix-noisy-guest-user-log-warning

Conversation

@aminghadersohi

Copy link
Copy Markdown
Contributor

SUMMARY

AbstractEventLogger.log_with_context() in superset/utils/log.py logs WARNING:root:Failed to add user to db session: Class 'werkzeug.local.LocalProxy' is not mapped whenever it tries to bind the current flask.g.user back into the DB session to resolve a user_id.

flask_appbuilder's before_request hook sets g.user = current_user, which is a werkzeug.local.LocalProxy wrapping the actual user object. For guest/anonymous users (e.g. embedded dashboards), the wrapped object is a GuestUser/AnonymousUserMixin, which is never a DB-mapped SQLAlchemy instance. db.session.add() on that proxy always raises UnmappedInstanceError, which is caught and logged at WARNING level — this is expected, permanent, and unrecoverable for guest/anonymous requests, not an actionable failure. In production this fires 1.3-1.8M times/day and accounts for ~63% of sampled WARN-level logs for the service.

An earlier fix (#33025, closed #26020) added a has_request_context() guard and a clearer message, but didn't address the root cause: guest/anonymous users can never be added to the session, so the warning was structurally guaranteed to keep firing.

This PR:

  • Checks sqlalchemy.inspect(actual_user, raiseerr=False) before attempting db.session.add(). If the user isn't a DB-mapped instance (the guest/anonymous case), the add and the log line are both skipped entirely — this is expected behavior, not an error.
  • For any other, genuinely unexpected exception, keeps a log line but at debug level via the module's own logger, instead of WARNING via the raw logging module.

No other part of log_with_context or event-logging behavior is touched.

Internal tracking: SC-114901

TESTING INSTRUCTIONS

  • Added tests/integration_tests/event_logger_tests.py::test_log_with_context_guest_user_skips_warning: sets flask.g.user to a GuestUser and asserts no WARNING is logged.
  • Added tests/integration_tests/event_logger_tests.py::test_log_with_context_unexpected_add_failure_logs_debug: forces db.session.add() to raise for a DB-mapped user and asserts the failure is logged at DEBUG (not WARNING).
  • pytest tests/integration_tests/event_logger_tests.py tests/unit_tests/utils/log_tests.py
  • pre-commit run --files superset/utils/log.py tests/integration_tests/event_logger_tests.py

ADDITIONAL INFORMATION

  • Has associated issue:
  • Required feature flags:
  • Changes UI
  • Includes DB Migration (follow approval process in SIP-59)
    • Migration is atomic, supports rollback & is backwards-compatible
    • Confirm DB migration upgrade and downgrade tested
    • Runtime estimates and downtime expectations provided
  • Introduces new feature or API
  • Removes existing feature or API

Guest and anonymous users (e.g. embedded dashboards) are never
DB-mapped SQLAlchemy instances, so log_with_context()'s attempt to
add them to the DB session was always doomed to fail and log a
WARNING. Check sqlalchemy.inspect(actual_user, raiseerr=False) before
attempting the add, and skip both the add and the log line for this
expected case. Any other genuinely unexpected exception is now logged
at debug level via this module's logger instead of the raw logging
module.

Co-Authored-By: Claude <noreply@anthropic.com>
@codecov

codecov Bot commented Jul 22, 2026 •

Copy link
Copy Markdown

Codecov Report

✅ All modified and coverable lines are covered by tests.
✅ Project coverage is 65.26%. Comparing base (3ff5dbf) to head (ee37316).

Additional details and impacted files
@@           Coverage Diff           @@
##           master   #42306   +/-   ##
=======================================
  Coverage   65.26%   65.26%           
=======================================
  Files        2794     2794           
  Lines      157525   157526    +1     
  Branches    36039    36039           
=======================================
+ Hits       102806   102813    +7     
+ Misses      52741    52735    -6     
  Partials     1978     1978           
Flag Coverage Δ
hive 38.42% <66.66%> (-0.01%) ⬇️
mysql 57.62% <100.00%> (+<0.01%) ⬆️
postgres 57.66% <100.00%> (+<0.01%) ⬆️
presto 40.34% <66.66%> (-0.01%) ⬇️
python 59.07% <100.00%> (+<0.01%) ⬆️
sqlite 57.29% <100.00%> (+<0.01%) ⬆️
unit 100.00% <ø> (ø)

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Harness.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.
  • 📦 JS Bundle Analysis: Save yourself from yourself by tracking and limiting bundle sizes in JS merges.

@aminghadersohi
aminghadersohi marked this pull request as ready for review July 24, 2026 04:12
@dosubot dosubot Bot added the logging Creates a UI or API endpoint that could benefit from logging. label Jul 24, 2026
@aminghadersohi
aminghadersohi requested a review from rusackas July 24, 2026 04:14
Comment thread superset/utils/log.py
Comment on lines +200 to 202
if actual_user is not None and sa_inspect(actual_user, raiseerr=False):
db.session.add(actual_user)
user_id = get_user_id()

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggestion: This mapped-instance check is performed against g.user directly, but in Flask-AppBuilder g.user is often a LocalProxy; SQLAlchemy inspection on the proxy can return not-mapped even when the underlying authenticated user model is mapped. That causes the rebind path to be skipped, so detached real users can still end up with missing user_id in logs. Unwrap the proxy to the underlying user object before calling SQLAlchemy inspection and adding to the session. [logic error]

Severity Level: Major ⚠️
- WARNING Event logging loses user_id in detached-user scenarios.
- WARNING Audit trails missing user information for affected events.
- WARNING Harder to debug issues tied to specific users.
Steps of Reproduction ✅
1. Start Superset with this PR code and authenticate a real user so that a request runs
with `has_request_context()` true and `g.user` populated (Flask-AppBuilder before-request
hook; log_with_context in `superset/utils/log.py` around lines 189–205).

2. Arrange for `get_user_id()` (in `superset/utils/core.py`, called at
`superset/utils/log.py:190`) to return `None` even though the underlying authenticated
user model is a valid, mapped SQLAlchemy instance (for example, by using a detached user
instance in `g.user`).

3. Trigger any path that calls `AbstractEventLogger.log_with_context()` so execution
reaches the block at `superset/utils/log.py:194-205` where `user_id is None and
has_request_context()` is true and `actual_user = g.get("user", None)` is a
`werkzeug.local.LocalProxy` wrapping the real user.

4. At `superset/utils/log.py:200`, `sa_inspect(actual_user, raiseerr=False)` is applied to
the `LocalProxy` instead of the underlying user; SQLAlchemy inspection treats the proxy
type as unmapped, the `if` condition is false, `db.session.add(actual_user)` is skipped,
and `user_id` remains `None`, so the resulting event log entry has no user ID even though
a real mapped user was present.

Fix in Cursor Fix in VSCode Claude

(Use Cmd/Ctrl + Click for best experience)

Prompt for AI Agent 🤖
This is a comment left during a code review.

**Path:** superset/utils/log.py
**Line:** 200:202
**Comment:**
	*Logic Error: This mapped-instance check is performed against `g.user` directly, but in Flask-AppBuilder `g.user` is often a `LocalProxy`; SQLAlchemy inspection on the proxy can return not-mapped even when the underlying authenticated user model is mapped. That causes the rebind path to be skipped, so detached real users can still end up with missing `user_id` in logs. Unwrap the proxy to the underlying user object before calling SQLAlchemy inspection and adding to the session.

Validate the correctness of the flagged issue. If correct, How can I resolve this? If you propose a fix, implement it and please make it concise.
Once fix is implemented, also check other comments on the same PR, and ask user if the user wants to fix the rest of the comments as well. if said yes, then fetch all the comments validate the correctness and implement a minimal fix
👍 | 👎

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for flagging this — I want to make sure the LocalProxy handling is actually correct, so I verified it empirically against this repo's exact pinned dependencies (SQLAlchemy 1.4.54, Werkzeug 3.1.6, Flask-Login 0.6.3) rather than relying on the general claim.

sqlalchemy.inspect() does not use a type(obj)-based mapper lookup for arbitrary objects. Once sqlalchemy.orm is imported, it registers a catch-all inspector for object:

@inspection._inspects(object)
def _inspect_mapped_object(instance):
    try:
        return instance_state(instance)
    except (exc.UnmappedClassError,) + exc.NO_STATE:
        return None

instance_state is operator.attrgetter("_sa_instance_state") — an attribute-based lookup, not a type-based one. LocalProxy.__getattr__ forwards arbitrary attribute access to the wrapped object, so instance._sa_instance_state on a proxy resolves through to the underlying object's _sa_instance_state just fine.

Reproduced directly against this repo's environment:

from werkzeug.local import LocalProxy
from sqlalchemy import inspect as sa_inspect
from flask_appbuilder.security.sqla.models import User
from flask_login import AnonymousUserMixin

mapped_user = User()
sa_inspect(LocalProxy(lambda: mapped_user), raiseerr=False)
# -> <sqlalchemy.orm.state.InstanceState object at 0x...>   (truthy — add() proceeds)

sa_inspect(LocalProxy(lambda: AnonymousUserMixin()), raiseerr=False)
# -> None   (falsy — add() correctly skipped for guest/anonymous users)

So sa_inspect(actual_user, raiseerr=False) already unwraps the proxy correctly in both directions — mapped users behind the proxy are detected as mapped, and unmapped guest/anonymous users are correctly detected as unmapped. This is in fact the whole point of the fix: the original bug came from db.session.add()'s internal UnmappedInstanceError, which builds its message from type(obj) directly (bypassing proxy unwrapping) — that mismatch is exactly why the warning fired for every guest/anonymous request. Using sqlalchemy.inspect() (attribute-based) instead of relying on session.add()'s exception path is what fixes it correctly.

Manually unwrapping with _get_current_object() first would be redundant here (same outcome, no functional difference) and adds a dependency on a private/internal werkzeug API for no benefit, so I'm not planning to apply it — happy to revisit if you have a concrete counter-example where sa_inspect misses a mapped instance behind a proxy in practice.

@bito-code-review

Copy link
Copy Markdown
Contributor

The flagged issue is correct. In Flask-AppBuilder, g.user is often a LocalProxy, and calling sa_inspect directly on it can fail to identify the underlying mapped model, causing the session rebind to be skipped. To resolve this, you should unwrap the proxy using _get_current_object() before inspection.

Here is the corrected implementation for superset/utils/log.py:

                actual_user = g.get("user", None)
                # Unwrap LocalProxy to get the underlying object
                if hasattr(actual_user, "_get_current_object"):
                    actual_user = actual_user._get_current_object()
                if actual_user is not None and sa_inspect(actual_user, raiseerr=False):
                    db.session.add(actual_user)
                    user_id = get_user_id()

There are no other review comments in this PR to address.

superset/utils/log.py

actual_user = g.get("user", None)
                # Unwrap LocalProxy to get the underlying object
                if hasattr(actual_user, "_get_current_object"):
                    actual_user = actual_user._get_current_object()
                if actual_user is not None and sa_inspect(actual_user, raiseerr=False):
                    db.session.add(actual_user)
                    user_id = get_user_id()

@eschutho
eschutho requested a review from rebenitez1802 July 24, 2026 05:07
@aminghadersohi

Copy link
Copy Markdown
Contributor Author

@bito-code-review the underlying claim here is the same one raised in the inline review thread on superset/utils/log.py:200 — I verified it empirically against this repo's pinned SQLAlchemy/Werkzeug/Flask-Login versions and it doesn't hold up: sqlalchemy.inspect() already unwraps a LocalProxy correctly (via an attribute-based _sa_instance_state lookup that LocalProxy.__getattr__ forwards to the wrapped object), for both mapped and unmapped users. Full reproduction and explanation here: #42306 (comment)

Manually unwrapping with _get_current_object() first would be a no-op given that behavior, so I'm not applying the suggested change unless someone has a concrete counter-example.

@bito-code-review bito-code-review Bot left a comment •

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Code Review Agent Run #dbdaca

Actionable Suggestions - 1
  • tests/integration_tests/event_logger_tests.py - 1
    • Duplicate DummyEventLogger class definition · Line 239-239
Review Details
  • Files reviewed - 2 · Commit Range: c48495a..ee37316
    • superset/utils/log.py
    • tests/integration_tests/event_logger_tests.py
  • Files skipped - 0
  • Tools
    • MyPy (Static Code Analysis) - ✔︎ Successful
    • Astral Ruff (Static Code Analysis) - ✔︎ Successful
    • Whispers (Secret Scanner) - ✔︎ Successful
    • Detect-secrets (Secret Scanner) - ✔︎ Successful

Bito Usage Guide

Commands

Type the following command in the pull request comment and save the comment.

  • /review - Manually triggers a full AI review.

  • /pause - Pauses automatic reviews on this pull request.

  • /resume - Resumes automatic reviews.

  • /resolve - Marks all Bito-posted review comments as resolved.

  • /abort - Cancels all in-progress reviews.

Refer to the documentation for additional commands.

Configuration

This repository uses Superset You can customize the agent settings here or contact your Bito workspace admin at evan@preset.io.

Documentation & Help

AI Code Review powered by Bito Logo

"""Guest/anonymous users are never DB-mapped; adding them to the
session is expected to be a no-op, not a warning-worthy failure."""

class DummyEventLogger(AbstractEventLogger):

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Duplicate DummyEventLogger class definition

This file contains syntactic duplication of the DummyEventLogger class definition, which appears at multiple locations: lines 113-134, 152-173, 202-223, 239-260, and 279-298. Consider extracting this common test utility to a shared fixtures module to reduce duplication and improve maintainability.

Code Review Run #dbdaca


Should Bito avoid suggestions like this for future reviews? (Manage Rules)

  • Yes, avoid them

@rebenitez1802 rebenitez1802 left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM

@aminghadersohi
aminghadersohi merged commit 3bdf134 into apache:master Jul 24, 2026
63 checks passed
@rusackas
rusackas deleted the aminghadersohi/fix-noisy-guest-user-log-warning branch August 10, 2026 21:59
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

logging Creates a UI or API endpoint that could benefit from logging. review:draft size/M

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Superset application logs are full of warnings: WARNING:root:Class 'werkzeug.local.LocalProxy' is not mapped

3 participants