Diagnostics: dotnet trace collect only outputs single thread

[jmezach]

With the new preview 6 bits (also see #331) it seems that dotnet trace collect only outputs a single thread, while the preview 5 bits would write more to the output. At least this seems to be the case with the speedscope format (not sure about the netperf file since I don't have perfview since I'm doing this on a Mac). Was this a deliberate choice, or is it a regression?

[sywhang]

cc @josalem on the speedscope format

[josalem]

I was able to just repro this, and it appears to happen for both PerfView and Speedscope with preview6 coreclr. It would seem that we are or effectively are missing all stacks. I'm guessing this is related to dotnet/coreclr#25046. Note: this has been fixed in master already!

CC @tommcdon

[sywhang]

@jmezach You can try to use the daily builds that we publish out of CoreCLR to see the stacks. (note: you'll also have to use the daily build of diagnostics tools in that case due to breaking changes from preview to preview).

[josalem]

@jmezach You can try to use the daily builds that we publish out of CoreCLR to see the stacks. (note: you'll also have to use the daily build of diagnostics tools in that case due to breaking changes from preview to preview).

You can use the script documented here to install the latest bits. Just use master for the channel parameter!

[jmezach]

Ok, this is getting a little bit to unstable for my preference so I think I'll go back to preview 5 bits for my upcoming demo (it's next week ;)). I had some issues with preview 5 which I hoped would be fixed in preview 6, but I think I have a workaround that works with preview 5 as well so I can at least do my demo.

Thanks for the quick reply though and glad you found and fixed it :).

[josalem]

Closing as this issue has been fixed in master per comments dotnet/coreclr#25046.

[baronfel]

I believe I'm still seeing this on .netcore 3.0 preview 7. I've created a sample repository (where I was diagnosing the memory usage of prometheus-net.DotNetRuntime) which has a reproduction + instructions in a docker container. Specifically to illustrate the issue you can follow the instructions in the tracing section of the README.

Relevant version numbers are:

dotnet --info output for my local machine

.NET Core SDK (reflecting any global.json):
 Version:   3.0.100-preview7-012821
 Commit:    6348f1068a

Runtime Environment:
 OS Name:     Mac OS X
 OS Version:  10.14
 OS Platform: Darwin
 RID:         osx.10.14-x64
 Base Path:   /usr/local/share/dotnet/sdk/3.0.100-preview7-012821/

Host (useful for support):
  Version: 3.0.0-preview7-27912-14
  Commit:  4da6ee6450

.NET Core SDKs installed:
  1.0.4 [/usr/local/share/dotnet/sdk]
  2.0.0 [/usr/local/share/dotnet/sdk]
  2.1.4 [/usr/local/share/dotnet/sdk]
  2.1.101 [/usr/local/share/dotnet/sdk]
  2.1.200 [/usr/local/share/dotnet/sdk]
  2.1.300 [/usr/local/share/dotnet/sdk]
  2.1.302 [/usr/local/share/dotnet/sdk]
  2.1.401 [/usr/local/share/dotnet/sdk]
  2.1.403 [/usr/local/share/dotnet/sdk]
  2.1.503 [/usr/local/share/dotnet/sdk]
  2.1.504 [/usr/local/share/dotnet/sdk]
  2.1.508 [/usr/local/share/dotnet/sdk]
  2.1.600-preview-009426 [/usr/local/share/dotnet/sdk]
  2.1.603 [/usr/local/share/dotnet/sdk]
  2.2.101 [/usr/local/share/dotnet/sdk]
  2.2.104 [/usr/local/share/dotnet/sdk]
  2.2.203 [/usr/local/share/dotnet/sdk]
  3.0.100-preview-010184 [/usr/local/share/dotnet/sdk]
  3.0.100-preview5-011568 [/usr/local/share/dotnet/sdk]
  3.0.100-preview7-012821 [/usr/local/share/dotnet/sdk]

.NET Core runtimes installed:
  Microsoft.AspNetCore.All 2.1.0-preview2-final [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.All 2.1.0-rc1-final [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.All 2.1.0 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.All 2.1.2 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.All 2.1.3 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.All 2.1.5 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.All 2.1.6 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.All 2.1.7 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.All 2.1.8 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.All 2.1.10 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.All 2.1.12 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.All 2.2.0 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.All 2.2.2 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.All 2.2.4 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.App 2.1.0-preview2-final [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 2.1.0-rc1-final [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 2.1.0 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 2.1.2 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 2.1.3 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 2.1.5 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 2.1.6 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 2.1.7 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 2.1.8 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 2.1.10 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 2.1.12 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 2.2.0 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 2.2.2 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 2.2.4 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 3.0.0-preview-19075-0444 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 3.0.0-preview5-19227-01 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 3.0.0-preview7.19365.7 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.NETCore.App 1.0.5 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 1.1.2 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.0.0 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.0.5 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.0.6 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.0.7 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.1.0-preview2-26406-04 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.1.0-rc1 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.1.0 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.1.2 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.1.3 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.1.5 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.1.6 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.1.7 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.1.8 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.1.10 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.1.12 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.2.0 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.2.2 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.2.4 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 3.0.0-preview-27324-5 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 3.0.0-preview5-27626-15 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 3.0.0-preview7-27912-14 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]

To install additional .NET Core runtimes or SDKs:
  https://aka.ms/dotnet-download

Docker container dotnet --info

root@a3458653515d:/app# dotnet --info
.NET Core SDK (reflecting any global.json):
 Version:   3.0.100-preview7-012821
 Commit:    6348f1068a

Runtime Environment:
 OS Name:     debian
 OS Version:  10
 OS Platform: Linux
 RID:         debian.10-x64
 Base Path:   /usr/share/dotnet/sdk/3.0.100-preview7-012821/

Host (useful for support):
  Version: 3.0.0-preview7-27912-14
  Commit:  4da6ee6450

.NET Core SDKs installed:
  3.0.100-preview7-012821 [/usr/share/dotnet/sdk]

.NET Core runtimes installed:
  Microsoft.AspNetCore.App 3.0.0-preview7.19365.7 [/usr/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.NETCore.App 3.0.0-preview7-27912-14 [/usr/share/dotnet/shared/Microsoft.NETCore.App]

To install additional .NET Core runtimes or SDKs:
  https://aka.ms/dotnet-download

dotnet trace is version 3.0.0-preview7.19365.2, and the output speedscope json file is attached (as a zip because of github's content upload policies).
trace.speedscope.json.zip

Is there anything I'm missing here or obviously doing wrong?

[tommcdon]

@sywhang

[sywhang]

Thanks for reporting the issue @baronfel. Could you please upload the .nettrace file that was produced alongside the trace.speedscope.json file? It would help us investigate whether the issue is in the runtime or the event parser library. The trace name should be trace.nettrace by default.

[baronfel]

of course! here it is, again in zip because of upload restrictions.

trace.nettrace.zip

[baronfel]

Is there anything I can do here to help out? I'm aware that there's a big rush going on to stabilize/prepare for .net core 3, so if I can help out I'd like to.

[sywhang]

Thanks @baronfel for the trace and offering to help -- and sorry for the delayed response. We've been cramming several 3.0 fixes recently as you said so it took a while to come back to this.

I took a look at your trace and it seems like you're not getting any rundown events and that's why your trace is showing up as a single threaded trace.

I just tried to repro this on my local machine using your repo but I wasn't able to repro it. I am using preview 8 build of the runtime though (which was made public a few days ago I believe), so the first thing you could try is to update your runtime.. I am happy to spend the rest of the day looking at this issue so please let me know if that does/doesn't fix that issue and we can take a deeper look.

You should be able to see if you are getting rundown events directly by looking at the file size that's being reported by dotnet-trace: if it suddenly makes a somewhat big jump (i.e. from < 1MB to > 2MB) at the end of your tracing session, it means it received a chunk of rundown events at the end. If it doesn't, it means it never did.

[baronfel]

I'll give that a try, the entire repro is dockerized so it should be pretty quick to test.

[baronfel]

So I updated the dockerfile in the test repo, reran my tests (10s execution of a simple asp.net core webserver with prometheus.net metrics exported) and here is the nettrace and speedscope json for that run.

While I did see many more symbols on the stacks (which are great!) I'm not sure I'm seeing the multiple threads I expect. Is there an example speedscope json I can view to make sure I'm interpreting things correctly?

prom-sample-preview8.zip

[josalem]

I'm seeing multiple threads:

If you press the n (next) and p (previous) keys, you can switch between threads, and there are arrows at the top of the UI as well, granted they are super tiny.

[sywhang]

Great! You are getting multiple threads. This is a screenshot from your speedscope file:

You can see there are more than one thread (red box)

And you can click through the arrow to see the stack for each thread.

[baronfel]

Oh my god I'm a dummy that can't read docs. This is great and you both are wonderful human beings.

[sywhang]

No worries! Thanks for being patient with us - Please let us know if you run across any other weird behaviors while using the tools.