Skip to content

fix(log): avoid deadlock when a structured logger serializes the Task argument - #11649

Open
KoakiMiku wants to merge 2 commits into
dotnet:mainfrom
KoakiMiku:fix-task-log
Open

KoakiMiku wants to merge 2 commits into
dotnet:mainfrom
KoakiMiku:fix-task-log

Conversation

@KoakiMiku

@KoakiMiku KoakiMiku commented Oct 30, 2026 •

Copy link
Copy Markdown

Fixes #11621

Problem

WorkItemGroup passes live Task instances as [LoggerMessage] arguments: the long-running turn
warning logs task.AsyncState ?? task, and the DEBUG-only trace messages log task directly.

A provider that serializes structured parameters by reflection — for example NLog JsonLayout with
IncludeEventProperties=true — enumerates the object's public properties. Task<T> exposes Result,
and reading Result on an incomplete task blocks in Task.InternalWait/Monitor.Wait.

The warning is written inline in Execute's finally block on the activation's scheduler thread,
before _currentTask = null. When the log call blocks there, the thread never returns: the
activation stops consuming its queue, NonReentrancyQueueSize grows, every call to that activation
times out, and MaxRequestProcessingTime cannot recover it because no request is marked as
executing.

The captured stack confirms the path:

WorkItemGroup.LogWarningLongRunningTurn
  -> NLog JsonLayout.RenderJsonFormattedMessage
  -> DefaultJsonSerializer.SerializeObjectWithReflection
  -> ObjectReflectionCache.PropertyValue..ctor (reflects into Task<VoidTaskResult>.Result)
  -> Task.InternalWait
  -> Monitor.Wait

Change

Every Task-typed [LoggerMessage] parameter in WorkItemGroup becomes a string, and each call
site passes task.ToString():

  • LogWarningLongRunningTurn keeps its existing argument expression: task.AsyncState ?? task is
    now rendered with .ToString(), so the warning still reports the async state object when one is
    set, and the task otherwise.
  • The DEBUG-only LogTraceEnqueueWorkItem, LogTraceAddToRunQueue and LogTraceAboutToExecuteTask
    messages do the same for task.

Message templates, event IDs and log levels are unchanged; only the parameter types change
(object/Task to string). There is no behavioral change to scheduling, and no public API change.

Rationale

  • Log content stays the same for text layouts. The value logged is ToString() of the same
    object as before, and text-based layouts (simple console, NLog ${message}) already rendered
    parameters through ToString(). Task does not override ToString() (checked on .NET 8 and
    .NET 10), so that text is the runtime type name; for an async turn it is the async state machine
    type, which still identifies the async method.
  • No provider can reach Task.Result. The arguments are plain strings, so a reflection-based
    serializer has nothing to introspect.
  • No cost on the normal path. The string is only built where the code already checked the level
    (the trace messages) or already decided to emit the warning (turn duration above
    TurnWarningLengthThreshold).

Structured sinks now record a string instead of an object graph for these parameters. That object
graph was exactly what could deadlock the scheduler.

Microsoft Reviewers: Open in CodeFlow

@KoakiMiku
KoakiMiku requested a review from ReubenBond as a code owner October 30, 2026 03:59
@KoakiMiku

Copy link
Copy Markdown
Author

@dotnet-policy-service agree

@ReubenBond
ReubenBond enabled auto-merge October 31, 2026 01:02
auto-merge was automatically disabled October 31, 2026 06:12

Head branch was pushed to by a user without write access

This branch has not been deployed

No deployments
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.

Long-running turn warning can deadlock the activation scheduler when a structured logger serializes the Task argument

2 participants