Skip to content

[DIAGNOSTIC] Log session state at PermissionResolver's user-reference boundary - #814

Closed
micszo wants to merge 1 commit into
5.0from
diagnostic/permission-resolver-session-logging
Closed

[DIAGNOSTIC] Log session state at PermissionResolver's user-reference boundary#814
micszo wants to merge 1 commit into
5.0from
diagnostic/permission-resolver-session-logging

Conversation

@micszo

@micszo micszo commented Aug 28, 2026

Copy link
Copy Markdown
Contributor

This is a diagnostic, not a proposed fix

Companion to ibexa/page-builder#592 and ibexa/behat#197, investigating the "Add first/second test catalog for Catalog block" failures on ibexa/experience's siteaccess-matcher CI shards, ongoing since Symfony 7.4.17 (2026-08-22). Background is in page-builder#592's description.

Why this instead of another delay value

Two prior runs tried closing a suspected session write/read race with a fixed wait (1s, then 3s) before the failing permission-gated click. The results didn't trend the way a simple race-window theory predicts - a job that fully passed at 1s failed again at 3s, and no delay value made all four matcher shards pass. Rather than keep guessing at sleep durations, this logs the actual session state directly at the two places that determine what PermissionResolver::canUser() sees as the current user.

What this PR does

  • getCurrentUserReference(): logs session_id(), session_status(), and the request's cookie names whenever it falls back to the anonymous user - i.e. nothing has called setCurrentUserReference() yet this request.
  • setCurrentUserReference(): logs the same, plus the user id being attached, every time a user gets set.
  • Both use error() level via a new optional $diagnosticLogger (wired to @logger in inner.yml), so entries land in the same log file ibexa/behat's DebuggingContext already captures and prints after a failed step. No new Behat step needed - this should just show up in the existing "Application logs:" section on the next failing run of setup.feature's Catalog-block scenarios.

What this should tell us

If the "Create" button failures are really caused by the current user resolving to anonymous at that point, we'll see a getCurrentUserReference falling back to anonymous line right before the failure, and can compare its session_id/cookie state against whatever setCurrentUserReference logged earlier in the same request lifecycle (the login). If the user is actually resolving correctly as admin at that point, this whole line of investigation is wrong and the real cause is elsewhere - which would be just as useful to know.

🤖 Generated with Claude Code

… boundary

Companion to ibexa/page-builder#592 and ibexa/behat#197 (diagnostic/session-race
hypothesis for the Catalog-block setup failures on ibexa/experience's
siteaccess-matcher shards since Symfony 7.4.17).

Delay-based diagnostics (1s, 3s) gave inconsistent results across runs -
not a clean "longer wait helps" trend. Rather than keep guessing at sleep
durations, this logs the actual session state at the two places that
determine what PermissionResolver::canUser() sees as the current user:

- getCurrentUserReference(): logs session_id(), session_status() and the
  cookies present whenever it falls back to the anonymous user (i.e.
  nothing has called setCurrentUserReference() yet this request).
- setCurrentUserReference(): logs the same, plus the user id being set,
  every time a user gets attached.

Uses error() level and the default '@logger' service so entries land in
the same log file ibexa/behat's DebuggingContext already captures and
prints after a failed step - no new Behat step needed, this should just
show up in the existing "Application logs:" section on the next failure.

Not a proposed change - purely to directly confirm or rule out whether
the "Create" button failures are actually caused by the current user
resolving to anonymous, and if so, what the session/cookie state looks
like at that exact moment.

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
@sonarqubecloud

Copy link
Copy Markdown

micszo added a commit to ibexa/experience that referenced this pull request Aug 28, 2026
- ibexa/page-builder branch already updated to drop the wait step
  (natural, unmodified failure timing again)
- ibexa/behat's TimeContext branch is no longer needed since the wait
  step is gone; removed
- Added ibexa/core#814's diagnostic branch, which logs session state at
  the point that determines what PermissionResolver sees as the current
  user - should surface directly in the failure's Application logs

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
micszo added a commit to ibexa/experience that referenced this pull request Aug 28, 2026
ibexa/core#814's session logging came back conclusive: the admin user is
correctly resolved throughout the Catalogs page render on every matcher
shard, ruling out the session-identity theory. Keeping that branch in
place for continued confirmation, and adding
ibexa/product-catalog#1581, which instruments the actual canCreate()
permission check one level closer to the symptom - should show directly
whether it returns false for the correctly-identified admin user, and why.

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
@micszo micszo closed this Aug 29, 2026
@micszo
micszo deleted the diagnostic/permission-resolver-session-logging branch August 29, 2026 12:51
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant