Add More Process Information to EventPipe Traces #17080

brianrob · 2018-03-20T23:25:59Z

Fixes #11725.

Adds the following EventPipe functionality:

A new EventPipeEventSource for EventPipe diagnostic events. The first event for this provider is ProcessInfo, which contains the command line.
An event metadata generator in native code. This is used by the EventPipeEventSource so that TraceEvent doesn't have to have a built-in parser for these events.
The RuntimeInformation event is fired right before EventPipe is disabled. This includes runtime version and path to the runtime.

This change also contains modifications to the WriteEvent path to remove an extra pointer indirection on the event arguments. The indirection is not needed and causes problems when we try to write events using this path from native code.

brianrob · 2018-03-20T23:26:52Z

Run EventSource tests:
@dotnet-bot test Windows_NT x64 Checked corefx_baseline
@dotnet-bot test Ubuntu x64 Checked corefx_baseline

…truct for Windows where unsigned long is 4 bytes (vs. 8 bytes on Unix).

brianrob · 2018-03-21T04:03:12Z

Run EventSource tests:
@dotnet-bot test Windows_NT x64 Checked corefx_baseline
@dotnet-bot test Ubuntu x64 Checked corefx_baseline

adamsitnik

@brianrob LGTM!

I like the idea of sending new event instead of changing the metadata!

The only thing I am not sure of is when is the best moment to send process info. I would send it in Enable

adamsitnik · 2018-03-21T17:41:10Z

src/vm/eventpipe.cpp

+    delete(s_pEventSource);
+    s_pEventSource = NULL;
+
+    // On Windows, this is just a pointer to the return value from


thanks for adding this comment! 👍

adamsitnik · 2018-03-21T17:43:52Z

src/vm/eventpipe.cpp

@@ -360,6 +378,12 @@ void EventPipe::Disable()
        // Disable the profiler.
        SampleProfiler::Disable();

+        // Log the process information event.
+        s_pEventSource->SendProcessInfo(s_pCommandLine);


Why wait with this until Disable? imho the sooner we have this information, the better (I would move it to Enable).

I am not sure who is going to call ProcessName and when (after processing all events or maybe in the meantime?)

I am waiting until Disable in case the circular buffer wraps. This guarantees that this event doesn't get discarded.

With respect to TraceEvent - TraceLog already does a pass over the data before you can use it, which means that users won't notice that this isn't part of the header. That's actually the point of TraceLog - to allow you to fill data structures with information that is only available after you need it. Thus, TraceLog does a single pass and then the user of the TraceLog does a second pass.

adamsitnik · 2018-03-21T17:53:38Z

src/vm/eventpipemetadatagenerator.h

+
+enum class EventPipeEventLevel;
+
+enum class EventPipeParameterType


could you add some comment about where these values come from? (sth like "this enum is TypeCode + Guid")

Yes, will do. Thanks for pointing this out.

nategraf · 2018-03-21T16:49:47Z

src/vm/eventpipeeventsource.h

+    EventPipeEventSource();
+    ~EventPipeEventSource();
+
+    void Enable(EventPipeSession *pSession);


I would have expected to see a diable function to mirror enable. I see that the logic is in the deconstructor, but is there a reason it is done that way rather than an explicit disable?

This is enabling the provider for a specific session. Sessions don't require explicit disable per provider - the session itself can be enabled/disabled. There isn't a way to disable a provider within an enabled session (or even a disabled session).

OK, cool. So once a provider is enabled in a session, it will always be a part of that session until the session dies?

Yes, that's right. @vancem had recommended changing this at some point so that could happen. If it does, we'd probably still leave this as is because we want this to always be on (at least the LogAlways events) because they are things we believe should exist in all traces.

nategraf · 2018-03-21T17:46:31Z

src/vm/eventpipeeventsource.h

+class EventPipeEvent;
+class EventPipeSession;
+
+class EventPipeEventSource


I found the name unhelpful in figuring out what this class does. Is it true that this classes sole responsibility to provide process information, then maybe a name like ProcessInfoEventSource would be more appropriate.

EventPipeEventSource is the EventPipe EventSource - basically, it will provide events about EventPipe. Today, the only event is the ProcessInfo event, but you can see this expanding quickly to include things like:

The set of enabled providers with keyword, level, etc.

Logging when a provider is registered / unregistered.

Diagnostics around the circular buffer (e.g. when a buffer is stolen because we've hit the max size of the circular buffer).

This is the just the first use of this class.

nategraf · 2018-03-21T17:58:09Z

src/vm/eventpipeeventsource.cpp

+    pSession->AddSessionProvider(pSessionProvider);
+}
+
+void EventPipeEventSource::SendProcessInfo(LPCWSTR pCommandLine)


Will this function ever log more than command line args? If not maybe calling it SendCommndLine would be better by being more specific.

I suspect it will, as we decide what other process information we want to log. For example, we might include things like process affinity mask. The general design is that you can easily add new parameters to the end of the event which makes things backwards compatible. I want to avoid changing the name of this to something more specific because it means that we really need to log a new event for any new information, which just feels heavy-weight.

brianrob · 2018-03-21T19:02:15Z

Confirmed that Ubuntu CoreFX test failures are unrelated to this change.

brianrob · 2018-03-21T19:23:14Z

Thanks all for the review. I will get this in once the CI completes.

brianrob · 2018-03-21T20:30:55Z

Tizen run has completed with no failures, but is hung cleaning up.

brianrob added 4 commits March 20, 2018 15:44

Log process and runtime informtion to EventPipe traces.

780d492

Ignore EventPipe events in tests.

ba7fb59

Fix Windows build error.

07a361c

Fix more Windows build errors.

d9c874c

brianrob requested review from nategraf, adamsitnik and vancem March 20, 2018 23:25

Contract fixes, fixes to #ifdefs, and a fix to the native EventData s…

ec44ada

…truct for Windows where unsigned long is 4 bytes (vs. 8 bytes on Unix).

adamsitnik approved these changes Mar 21, 2018

View reviewed changes

nategraf reviewed Mar 21, 2018

View reviewed changes

Add comments per review feedback.

58e6a98

nategraf approved these changes Mar 21, 2018

View reviewed changes

brianrob merged commit b82063e into dotnet:master Mar 21, 2018

brianrob deleted the issue_11725 branch March 21, 2018 20:31

llamadonica mentioned this pull request Jan 31, 2020

Regression in vm/corhost.cpp dotnet/runtime#10027

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add More Process Information to EventPipe Traces #17080

Add More Process Information to EventPipe Traces #17080

brianrob commented Mar 20, 2018

brianrob commented Mar 20, 2018

brianrob commented Mar 21, 2018

adamsitnik left a comment

adamsitnik Mar 21, 2018

adamsitnik Mar 21, 2018

brianrob Mar 21, 2018

adamsitnik Mar 21, 2018

brianrob Mar 21, 2018

nategraf Mar 21, 2018

brianrob Mar 21, 2018

nategraf Mar 21, 2018

brianrob Mar 21, 2018

nategraf Mar 21, 2018

brianrob Mar 21, 2018

nategraf Mar 21, 2018

brianrob Mar 21, 2018

brianrob commented Mar 21, 2018

brianrob commented Mar 21, 2018

brianrob commented Mar 21, 2018


		enum class EventPipeEventLevel;

		enum class EventPipeParameterType

Add More Process Information to EventPipe Traces #17080

Add More Process Information to EventPipe Traces #17080

Conversation

brianrob commented Mar 20, 2018

brianrob commented Mar 20, 2018

brianrob commented Mar 21, 2018

adamsitnik left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

brianrob commented Mar 21, 2018

brianrob commented Mar 21, 2018

brianrob commented Mar 21, 2018