Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Ability to filter thread pool thread events in a nettrace #102326

Open
verdie-g opened this issue May 16, 2024 · 12 comments
Open

Ability to filter thread pool thread events in a nettrace #102326

verdie-g opened this issue May 16, 2024 · 12 comments
Labels
area-System.Threading untriaged New issue has not been triaged by the area owner

Comments

@verdie-g
Copy link
Contributor

When debugging a thread pool starvation issue, I can collect the WaitHandleWait event introduced in .NET 9 with #94737. Though, if my sum-up the time spent waiting using this event, I'll often get such result:

image
In the screenshot from (.NET Events Viewer :)), we can see that most of the time is spent on non-thread-pool threads which is fine and not relevant to my issue. I would like to be able to filter them out as they can be misleading, especially to someone unexperienced with this kind of investigation.

What do you think about, whenever a trace is started, events are sent about the current managed threads. Something like that

ManagedThreadId: 2337
IsThreadPoolThread: false

and also, I can't find it anymore, but I think there is a ThreadCreated event that could be amended to also include the IsThreadPoolThread field.

cc @kouvel @noahfalk

@dotnet-policy-service dotnet-policy-service bot added the untriaged New issue has not been triaged by the area owner label May 16, 2024
Copy link
Contributor

Tagging subscribers to this area: @mangod9
See info in area-owners.md if you want to be subscribed.

@noahfalk
Copy link
Member

Having rundown events that enumerate which threads are in the threadpool seems reasonable to me. We already have a thread enumeration there, but not a threadpool enumeration.
Curious to hear what @brianrob and @kouvel think on it.

I think there is a ThreadCreated event that could be amended to also include the IsThreadPoolThread field.

Do you mean the ThreadCreatedRundown event on the rundown provider or the ThreadCreated event on the normal CLR provider? For the normal provider ThreadCreated event you won't be guaranteed to see it if your trace starts after the thread started. If you only care about traces that do start early enough to see that event there is also a ThreadpoolWorkerThreadStart event that identifies worker threads.

@verdie-g
Copy link
Contributor Author

there is also a ThreadpoolWorkerThreadStart event that identifies worker threads.

Great! So yes in that case I would only be interested in an enumeration of the thread pool threads.

@brianrob
Copy link
Member

This seems do-able, but I wonder if a more generic way to do this would be to use the thread name. Thread pool worker threads get a unique name that gets set on thread start-up. This gets emitted in rundown for ETW by the kernel, but I don't see it exposed in the nettrace. We have some precedent for using the thread name in other places such as GC tooling where we detect GC threads by their name.

@verdie-g
Copy link
Contributor Author

So when a nettrace starts, a new event would be sent for each running thread with their name. Then, we can use ThreadpoolWorkerThreadStart to monitor the change of threads?

@brianrob
Copy link
Member

I think that would be the idea. Though, I am thinking that you might also need thread lifetime events to make sure that you know when a thread is created/destroyed more generically to ensure that if/when a thread ID gets re-used, that you don't assume an old value for the name.

@noahfalk
Copy link
Member

This gets emitted in rundown for ETW by the kernel, but I don't see it exposed in the nettrace

You can use the SequenceNumber on events to infer when a thread ID has been recycled almost always (https://github.com/microsoft/perfview/blob/main/src/TraceEvent/EventPipe/EventCache.cs#L150). It wasn't designed for that purpose originally and I'd be happy to get a better mechanism but if you need something now it works.

@verdie-g
Copy link
Contributor Author

We already have a thread enumeration there

What event is that? Should I add ThreadName to that event?

@kouvel
Copy link
Member

kouvel commented May 29, 2024

I like the idea of using the thread name. I'm not sure about using the ThreadPoolWorkerThreadStart event though. There are several threads that are not TP worker threads and spend most of their time waiting, some of which don't run any user code, like the TP gate and wait threads, the timer thread, and IO poller threads. There could also be other app-specific threads that spend most of their time waiting and not doing much else.

Maybe a new event would work better? The Thread.Name property can be set lazily but it can only be set once so when the name is set the event can be raised. Also when a Thread object is created for a thread the name can be checked and sent in the event if it has one (or when an external thread enters the runtime for the first time). Then on trace start the event can be sent for each thread in the thread store that has a name.

There is a ThreadCreated event that could also be used to identify new threads. There is also a ThreadTerminated event that is currently not sent for most threads, not sure if it's necessary for this case though.

@kouvel
Copy link
Member

kouvel commented May 31, 2024

Then on trace start the event can be sent for each thread in the thread store that has a name.

And maybe also a rundown event at the end of a tracing session, for cases where long-duration circular buffer tracing is done, where the initial events may be discarded.

@brianrob
Copy link
Member

Agreed with @kouvel's comments here. I suspect that this is data that we'd like to have specifically for non-ETW cases, so I would probably put it under a new keyword so that we don't enable it when the kernel already provides such data (via ETW).

@kouvel
Copy link
Member

kouvel commented May 31, 2024

I'm thinking it could just be under the Threading keyword. Are there kernel events that provide the thread name? I'm not familiar with it, and since the thread name can be set after the thread has started I'm not sure if that would provide similar info.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area-System.Threading untriaged New issue has not been triaged by the area owner
Projects
None yet
Development

No branches or pull requests

4 participants