microsoft / microsoft/vs-threading

Low priority: ETW event ArgsMismatches

Open
#224 0 comments 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

Dominant language
C#
Stars
1k
Forks
160
Avg merge
1d 12h
Merged PRs (30d)
28

Description

not a problem when ETW trace is not enabled.

But when I turn it on to investigate potential lock contentions, I notice contentions in the AsyncReaderWriterLock, but further investigating shows it is more artificial when I turn on ETW events.

It seems that ReaderWriterLockIssued event will run into some logic in EventSource to write args mismatches messages, and it runs into other lock contentions to get the resource string.

not sure why this logic is triggered, but some ETW function converts enum to int, but one doesn't. Can this possibly related?

Name Inc % Inc Inc Ct Exc % Exc Exc Ct Fold Fold Ct When
  • Microsoft.VisualStudio.Threading!ThreadingEventSource.ReaderWriterLockIssued | 1.7 | 26.736 | 4 | 0.0 | 0 | 0 | 0 | 0 | AAAAAAAAAAAAAAAAAAAAAo2_________
    |+ mscorlib.ni!EventSource.WriteEventVarargs | 1.7 | 26.736 | 4 | 0.0 | 0 | 0 | 0 | 0 | AAAAAAAAAAAAAAAAAAAAAo2_________
    | + mscorlib.ni!EventSource.LogEventArgsMismatches | 1.7 | 26.736 | 4 | 0.0 | 0 | 0 | 0 | 0 | AAAAAAAAAAAAAAAAAAAAAo2_________
    |  + clr!GetResourceFromDefault | 1.7 | 26.736 | 4 | 0.0 | 0 | 0 | 0 | 0 | AAAAAAAAAAAAAAAAAAAAAo2_________
    |   + clr!GetResourceStringFromManaged | 1.7 | 26.736 | 4 | 0.0 | 0 | 0 | 0 | 0 | AAAAAAAAAAAAAAAAAAAAAo2_________
    |    + clr!MethodDescCallSite::CallTargetWorker | 1.7 | 26.393 | 2 | 0.0 | 0 | 0 | 0 | 0 | AAAAAAAAAAAAAAAAAAAAAo__________
    |    |+ clr!CallDescrWorkerWithHandler | 1.7 | 26.393 | 2 | 0.0 | 0 | 0 | 0 | 0 | AAAAAAAAAAAAAAAAAAAAAo__________
    |    | + clr!CallDescrWorkerInternal | 1.7 | 26.393 | 2 | 0.0 | 0 | 0 | 0 | 0 | AAAAAAAAAAAAAAAAAAAAAo__________
    |    |  + mscorlib.ni!Environment.GetResourceStringLocal | 1.7 | 26.393 | 2 | 0.0 | 0 | 0 | 0 | 0 | AAAAAAAAAAAAAAAAAAAAAo__________
    |    |   + mscorlib.ni!System.Environment+ResourceHelper.GetResourceString(System.String) | 1.7 | 26.393 | 2 | 0.0 | 0 | 0 | 0 | 0 | AAAAAAAAAAAAAAAAAAAAAo__________
    |    |    + mscorlib.ni!System.Environment+ResourceHelper.GetResourceString(System.String, System.Globalization.CultureInfo) | 1.7 | 26.393 | 2 | 0.0 | 0 | 0 | 0 | 0 | AAAAAAAAAAAAAAAAAAAAAo__________
    |    |     + clr!ReflectionInvocation::ExecuteCodeWithGuaranteedCleanup | 1.7 | 26.393 | 2 | 0.0 | 0 | 0 | 0 | 0 | AAAAAAAAAAAAAAAAAAAAAo__________
    |    |      + clr!ExecuteCodeWithGuaranteedCleanupHelper | 1.7 | 26.393 | 2 | 0.0 | 0 | 0 | 0 | 0 | AAAAAAAAAAAAAAAAAAAAAo__________
    |    |       + clr!DispatchCallSimple | 1.7 | 26.393 | 2 | 0.0 | 0 | 0 | 0 | 0 | AAAAAAAAAAAAAAAAAAAAAo__________
    |    |        + clr!CallDescrWorkerWithHandler | 1.7 | 26.393 | 2 | 0.0 | 0 | 0 | 0 | 0 | AAAAAAAAAAAAAAAAAAAAAo__________
    |    |         + clr!CallDescrWorkerInternal | 1.7 | 26.393 | 2 | 0.0 | 0 | 0 | 0 | 0 | AAAAAAAAAAAAAAAAAAAAAo__________
    |    |          + mscorlib.ni!System.Environment+ResourceHelper.GetResourceStringCode(System.Object) | 1.7 | 26.393 | 2 | 0.0 | 0 | 0 | 0 | 0 | AAAAAAAAAAAAAAAAAAAAAo__________
    |    |           + mscorlib.ni!RuntimeResourceSet.GetString | 1.7 | 26.393 | 2 | 0.0 | 0 | 0 | 0 | 0 | AAAAAAAAAAAAAAAAAAAAAo__________
    |    |            + mscorlib.ni!RuntimeResourceSet.GetObject | 1.7 | 26.393 | 2 | 0.0 | 0 | 0 | 0 | 0 | AAAAAAAAAAAAAAAAAAAAAo__________
    |    |             + mscorlib.ni!System.Collections.Generic.Dictionary2[System.__Canon,System.Resources.ResourceLocator].TryGetValue(System.__Canon, System.Resources.ResourceLocator ByRef) | 1.7 | 26.393 | 2 | 0.0 | 0 | 0 | 0 | 0 | AAAAAAAAAAAAAAAAAAAAAo__________ \|    \|              + mscorlib.ni!System.Collections.Generic.Dictionary2[System.Canon,System.Resources.ResourceLocator].FindEntry(System.Canon) | 1.7 | 26.393 | 2 | 0.0 | 0 | 0 | 0 | 0 | AAAAAAAAAAAAAAAAAAAAAo______
    |    |               + ntoskrnl!? | 1.7 | 26.393 | 2 | 0.0 | 0 | 0 | 0 | 0 | AAAAAAAAAAAAAAAAAAAAAo__________
    |    |                + BLOCKED_TIME | 1.7 | 26.205 | 1 | 1.7 | 26.205 | 1 | 0 | 0 | AAAAAAAAAAAAAAAAAAAA8___________
    |    |                + CPU_TIME | 0.0 | 0.188 | 1 | 0.0 | 0.188 | 1 | 0 | 0 | __________1o

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start by reproducing the contention with ETW enabled and trace the ReaderWriterLockIssued path through EventSource.WriteEventVarargs and LogEventArgsMismatches. Compare the enum argument handling and confirm whether resource-string lookup causes the observed contention; done means the mismatch path no longer adds the reported contention.

Written by the indexing model from the issue text.

Assessment

Tech stack
csharp
Domain
observability
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Needs clarification
Newbie friendliness
30/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.