search

microsoft / clrmd

Microsoft.Diagnostics.Runtime is a set of APIs for introspecting processes and dumps.
MIT License
1.05k stars 255 forks source link

ClrMd floods syslog with stackwalk messages #1222

Closed loop-evgeny closed 12 months ago

loop-evgeny commented 12 months ago

We have a tool running on Ubuntu 22.04 that periodically attaches to .NET processes on the server (most of them .NET 6) and does something like this (simplified):

var dataTarget = DataTarget.AttachToProcess(pid, false);
var runtime = dataTarget.ClrVersions[0].CreateRuntime();

if (runtime.ThreadPool != null)
   (Log ThreadPool properties)

foreach (var thread in runtime.Threads)
{
    (Log thread properties)

    if (thread.CurrentException != null)
    {
        (Log exception)
    }

    foreach (var frame in thread.EnumerateStackTrace().Take(1000))
        (Log stack frame)
}

We recently upgraded the Microsoft.Diagnostics.Runtime NuGet package in it from 2.0.142701 to 3.0.442202 and now it logs a LOT of messages to syslog, like this ("ThreadDumper" is the name of our EXE):

Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: BEGIN STACKWALK - X64
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: STACKWALK - hr:S_OK
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: STACKWALK - hr:S_OK
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: STACKWALK - hr:S_OK
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: STACKWALK - hr:S_OK
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: STACKWALK - hr:S_OK
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: STACKWALK - hr:S_OK
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: STACKWALK - hr:S_OK
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: STACKWALK - hr:S_OK
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: END STACKWALK - hr:S_FALSE
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: BEGIN STACKWALK - X64
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: STACKWALK - hr:S_OK
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: END STACKWALK - hr:S_FALSE
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: BEGIN STACKWALK - X64
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: STACKWALK - hr:S_OK
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: STACKWALK - hr:S_OK
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: STACKWALK - hr:S_OK
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: STACKWALK - hr:S_OK
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: STACKWALK - hr:S_OK
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: STACKWALK - hr:S_OK
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: STACKWALK - hr:S_OK
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: STACKWALK - hr:S_OK
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: STACKWALK - hr:S_OK
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: STACKWALK - hr:S_OK
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: END STACKWALK - hr:S_FALSE
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: BEGIN STACKWALK - X64
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: STACKWALK - hr:S_OK
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: STACKWALK - hr:S_OK
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: STACKWALK - hr:S_OK
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: STACKWALK - hr:S_OK
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: STACKWALK - hr:S_OK
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: STACKWALK - hr:S_OK
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: STACKWALK - hr:S_OK
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: STACKWALK - hr:S_OK
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: STACKWALK - hr:S_OK
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: STACKWALK - hr:S_OK
Nov 12 05:43:21 glomgold ThreadDumper: ThreadDumper Information: 0 : 
Nov 12 05:43:21 glomgold ThreadDumper: END STACKWALK - hr:S_FALSE
...

How do we stop it from flooding the log with this useless info?

leculver commented 12 months ago

What version of ClrMD are you on? These were fixed in 3.1, so let me know if you are seeing this on the most recen builds and I'll reopen this. Thanks!