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

Add ContentionStart_V2 and LockCreated events #1731

Merged
merged 3 commits into from
May 30, 2023

Conversation

kouvel
Copy link
Member

@kouvel kouvel commented Oct 19, 2022

@kouvel
Copy link
Member Author

kouvel commented Oct 19, 2022

For some reason the LockCreated event is showing up like this:

Event Name                                	Time MSec	Process Name          	Rest  
Microsoft-Windows-DotNETRuntime/Contention	5,172.485	Process(27972) (27972)	HasStack="True" ThreadID="9,656" ProcessorNumber="7" LockID="0x1da800c2a88" AssociatedObjectID="0x1db02916e80" ClrInstanceID="5" 

Any idea why the event name is not showing up? [Edit] Looks like it's because of TraceEvent.EventName's default behavior.

@kouvel
Copy link
Member Author

kouvel commented Oct 24, 2022

CC @brianrob

@brianrob
Copy link
Member

For some reason the LockCreated event is showing up like this:

Event Name                                	Time MSec	Process Name          	Rest  
Microsoft-Windows-DotNETRuntime/Contention	5,172.485	Process(27972) (27972)	HasStack="True" ThreadID="9,656" ProcessorNumber="7" LockID="0x1da800c2a88" AssociatedObjectID="0x1db02916e80" ClrInstanceID="5" 

Any idea why the event name is not showing up? [Edit] Looks like it's because of TraceEvent.EventName's default behavior.

Yes, this is because of how events get named. Can you update the runtime to use a new task called LockCreated? That should do it.

@kouvel
Copy link
Member Author

kouvel commented Oct 26, 2022

Yes, this is because of how events get named. Can you update the runtime to use a new task called LockCreated? That should do it.

It seems to be working fine now after the latest commit, where the name is overridden.

Why does using the win:Info opcode cause the name to be different? It seems to be PerfView-specific logic.

From only one perspective, I'd actually like to see the event shown as Contention/LockCreated since it's relevant to the Contention keyword (and under the Contention task, which I think is correct). The pattern for that for all other opcodes seems to be that for PerfView the event should be named ContentionLockCreated, which is also awkward. Anyway, showing the event as LockCreated on its own without the task/keyword is probably ok for now, perhaps some fixes can be made to PerfView in the future to make it easier for events to show up as intended.

@brianrob
Copy link
Member

Why does using the win:Info opcode cause the name to be different? It seems to be PerfView-specific logic.

Names are usually a combination of Task + Opcode when possible. There are a few different versions of ETW providers, and so this isn't always the case, but often it is. Each tool has to build its own logic as event names aren't encoded into the manifest directly.

From only one perspective, I'd actually like to see the event shown as Contention/LockCreated since it's relevant to the Contention keyword (and under the Contention task, which I think is correct). The pattern for that for all other opcodes seems to be that for PerfView the event should be named ContentionLockCreated, which is also awkward. Anyway, showing the event as LockCreated on its own without the task/keyword is probably ok for now, perhaps some fixes can be made to PerfView in the future to make it easier for events to show up as intended.

It seems reasonable to have it show up as Contention/LockCreated - the right way to do this is to create a LockCreated opcode, and then have the LockCreated event use the Contention task + LockCreated opcode. It's always possible to update PerfView to change things, but from a consistency POV, I would rather see us stick to the convention and change the event definition, especially for new events. If you'd like to change to this, I completely support that.

@kouvel
Copy link
Member Author

kouvel commented Oct 27, 2022

I see, sounds good

@brianrob
Copy link
Member

brianrob commented Nov 7, 2022

@kouvel, wanted to check back in on this. Are you planning to change this to be Contention/LockCreated, or should we merge as is?

@kouvel
Copy link
Member Author

kouvel commented Nov 7, 2022

Yea I'm planning to change it, haven't found the time yet, it's on my list

@brianrob
Copy link
Member

brianrob commented Nov 7, 2022

Sounds good. Just wanted to make sure. Thanks.

@kouvel
Copy link
Member Author

kouvel commented May 26, 2023

Rebased to latest and added one commit to update the event name based on dotnet/runtime#86817 and to not override it. After dotnet/runtime#86817 and the latest commit, the event is showing up as Contention/LockCreated in PerfView as expected. This should be ready to review after dotnet/runtime#86817.

Copy link
Member

@brianrob brianrob left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks good - just one thing that I think we should change.

@@ -2162,13 +2174,17 @@ static private ThreadPoolMinMaxThreadsTraceData ThreadPoolMinMaxThreadsTemplate(
{ // action, eventid, taskid, taskName, taskGuid, opcode, opcodeName, providerGuid, providerName
return new ThreadPoolMinMaxThreadsTraceData(action, 59, 38, "ThreadPoolMinMaxThreads", ThreadPoolMinMaxThreadsTaskGuid, 0, "Info", ProviderGuid, ProviderName);
}
static private ContentionLockCreatedTraceData ContentionLockCreatedTemplate(Action<ContentionLockCreatedTraceData> action)
{ // action, eventid, taskid, taskName, taskGuid, opcode, opcodeName, providerGuid, providerName
return new ContentionLockCreatedTraceData(action, 90, 8, "Contention", ContentionTaskGuid, 11, "LockCreated", ProviderGuid, ProviderName);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It looks like this will show up as a Contention/Info event and not a LockCreated event. To fix this, you will want to create LockCreated opcode, and use that. Unless I've missed something, this is the event definition, using the win:Info opcode:

                    <event value="90" version="0" level="win:Informational"  template="LockCreated"
                           keywords ="ContentionKeyword"  opcode="win:Info"
                           task="Contention"
                           symbol="LockCreated" message="$(string.RuntimePublisher.LockCreatedEventMessage)"/>

Copy link
Member

@brianrob brianrob left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I stand corrected - I missed your pending change in dotnet/runtime: dotnet/runtime#86817. Once the change in dotnet/runtime is merged, I will merge this change as well.

kouvel added a commit to dotnet/runtime that referenced this pull request May 30, 2023
- The event was added in .NET 8, I have updated the event name based on the suggestion in microsoft/perfview#1731 (comment).
- The name now matches the convention used for most other events, and shows up as Contention/LockCreated as expected in PerfView
@kouvel
Copy link
Member Author

kouvel commented May 30, 2023

Thanks, I have merged dotnet/runtime#86817

@brianrob brianrob merged commit c73119d into microsoft:main May 30, 2023
@kouvel kouvel deleted the Contention branch May 30, 2023 15:57
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.

2 participants