Skip to content

Make LogExceptionHandler log again - #389

Merged
lahma merged 3 commits into
mainfrom
4x/log-exception-handler
Nov 3, 2026
Merged

lahma merged 3 commits into
mainfrom
4x/log-exception-handler

Conversation

@lahma

@lahma lahma commented Nov 3, 2026

Copy link
Copy Markdown
Collaborator

LogExceptionHandler, the log action of the exception-handler advice, hasn't logged anything since logging moved to Microsoft.Extensions.Logging in 3.0.3 (fda46d9). PR #346 named this as a follow-up.

The bug. The handler wrapped its expression as #log.<Level>(<expression>[, #e]) and evaluated it with #log bound to an ILogger. ILogger has no Information/Fatal/… instance methods, only LogXxx extension methods. So every evaluation threw, the catch reduced it to a warning, and the handler returned "logged" without writing anything.

The fix.

  • ActionExpressionText is the message expression. HandleException evaluates it against the call context (#method, #args, #target, #e). It then calls ILogger.Log(LogLevel, LogMessageOnly ? null : #e, "{Message}", message), so the template stays constant.
  • LogName, LogLevel (default Trace) and LogMessageOnly keep their meaning.
  • If the expression fails, the handler logs a warning, as before. A legacy #log.Fatal(...) expression gets a specific warning that says how to rewrite it.
  • If the logging provider itself fails, the handler logs a separate warning, and the exception the advised method threw still propagates.
  • The log entry in the call context is now assigned, not added. Before, a second log handler on the same call threw ArgumentException and replaced the user's exception.
  • The set-once guard on ActionExpressionText is removed. It had frozen the first statement's expression, level and LogMessageOnly on a shared keyed handler.

BreakingChanges item 10.

  • The getter now returns the expression as set, not the #log.<Level>(...) wrapper.
  • A handler configured as #log.Fatal('msg', #e) doesn't log. That form worked on 3.0.2 and earlier only by accident of nesting, and nothing has logged since 3.0.3. Migrate to ActionExpressionText="'msg'" with LogLevel="Critical".
  • We decided against a compatibility shim. It would bring back a Common.Logging-shaped #log, which we'd have to maintain.

Tests.

  • New LogExceptionHandlerTests, with 17 cases. They use a recording logger factory to check level, category, message text and whether the exception is attached. They also cover:
    • legacy level names through LogLevelConverter;
    • property order;
    • the failure warnings;
    • a null message;
    • a throwing provider;
    • end-to-end runs through ExceptionHandlerAdvice with the DSL, the constraint DSL, keyed handlers and handler lists.
  • ExceptionHandlerAspectIntegrationTests actually test something now. Before, they matched a substring anywhere in the log, so the failure warning satisfied them, and some asserted nothing if no exception was thrown. Six of them fail against the old source. ExecuteSpelAction never ran its action, because the type name in its expression couldn't be resolved; it now uses T(type, assembly) and asserts the action ran.
  • Spring.Aop.Tests on net10.0: 505 passed, 6 skipped. On net472: 523 passed, 6 skipped. The skips were already there.
  • The new tests and the six integration tests fail on the unfixed source.
  • spring-reviewer accepted the change with follow-ups, and those follow-ups are in this PR.

Known, not changed here. ExceptionHandlerAdvice reuses one keyed handler instance (log, translate, wrap) for every statement that names it, and each statement overwrites its expressions. This was already the case before this PR.

🤖 Generated with Claude Code

https://claude.ai/code/session_01LGkLQuAuUjvRjrU1AcTsmk

lahma and others added 3 commits November 4, 2026 00:04
Since the move to Microsoft.Extensions.Logging the handler built the SpEL
text "#log.<Level>(<expr>, #e)" and evaluated it against an ILogger, which
has no such instance methods. The evaluation threw, the catch swallowed it
with a warning, and nothing was logged.

ActionExpressionText is now the message expression. HandleException
evaluates it against the call context and logs the result directly with
the constant "{Message}" template at LogLevel, in the LogName category,
attaching the exception from #e unless LogMessageOnly is set. A failing
expression still logs a warning through the handler's own logger and the
handler still returns "logged". The set-once guard is gone, the getter
returns the expression as assigned, and the "log" context variable is
assigned rather than added so several log handlers can share a context.

Adds LogExceptionHandlerTests (direct and through ExceptionHandlerAdvice)
and replaces the legacy #log.Fatal(...) action in an existing test.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01LGkLQuAuUjvRjrU1AcTsmk
Signed-off-by: Marko Lahma <marko.lahma@gmail.com>
- BreakingChanges.txt item 10: LogExceptionHandler.ActionExpressionText is
  now the message expression only.
- Fix the history note in the XML doc.
- When the expression fails and starts with "#log.", warn that the form is
  no longer supported instead of the generic message.
- Log the message outside the try, so a failing logging provider is not
  reported as an expression failure; test a null-valued expression.
- ExceptionHandlerAspectIntegrationTests: assert exact message, level and
  category instead of substrings that the failure warning could satisfy, and
  use Assert.Throws instead of try/catch helpers that asserted nothing when
  no exception was thrown. This also exposed that ExecuteSpelAction never
  executed its action (unresolvable type name); it now uses T(type, assembly).

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01LGkLQuAuUjvRjrU1AcTsmk
Signed-off-by: Marko Lahma <marko.lahma@gmail.com>
…eption

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01LGkLQuAuUjvRjrU1AcTsmk
Signed-off-by: Marko Lahma <marko.lahma@gmail.com>
@lahma
lahma merged commit 5da8d70 into main Nov 3, 2026
3 checks passed
@lahma
lahma deleted the 4x/log-exception-handler branch November 3, 2026 22:25
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