Event blocks #546

adamsitnik · 2018-01-30T22:13:05Z

This simplifies the V3 format. I also spit out the code for the old format so it would be easier to remove it later.

…d it's lenght does not come first

# Conflicts: # src/FastSerialization/FastSerialization.cs

vancem · 2018-01-31T00:01:29Z

src/TraceEvent/TraceEvent.csproj

@@ -3,6 +3,7 @@

  <PropertyGroup>
    <TargetFrameworks>net45;netstandard1.6</TargetFrameworks>
+    <LangVersion>7.0</LangVersion>


Including @sharwell

Please remove this and update the declaration in src\Directory.Build.props instead. That way all projects benefit from it uniformly.

I am OK moving to C# 7. It means a dependency on VS 2017, but realistically we have probably already many dependencies on 2017 (msbuild files, nuget support, bug fixes, ...)

@vancem done

vancem · 2018-01-31T01:02:47Z

src/TraceEvent/EventPipe/EventPipeEventSource.cs

-
-            var entryObj = _deserializer.GetEntryObject(); // this call invokes FromStream and reads header data
+#endif
+            _deserializer.RegisterFactory("!EventTrace.", delegate { return this; });


Why do the names of the types begin with ! and end with .? If it is just to avoid collision, we should not worry about this, as the namespace is just THIS FILE and no more. I would prefer the names 'EventTrace' and 'EventBlock' (I could even be talked into simply 'Trace' and 'EventBlock' as these are the names you would use if you had to come up with names that need only be unique in this file. (We may end up with other kinds of block, and frankly 'Block' is not descriptive enough on its own'.

I am not very proud of this, but..

Every object is serialized as:

<BeginObject> size is 1 <BeginObject> size is 2 <NullReference> size is 3 <objectVersion> size is 7 <minReaderVersion> size is 11 <stringLength> size is 15 <string> size is 15 + stringLength </EndObject> size is 16 + stringLength <Content /> <-- this must be aligned, so stringLength has to be aligned too ;) </EndObject>

So I decided to enforce a rule that type name length must be a multiplication of 4. This + padding the content ensures that everything is aligned. I know that it sounds stupid, but I did not have better idea. The other idea for names I had was EventBlock4B

@vancem is that acceptable?

What you described is SUPER subtle and fragile (any change will break alignment). You don't want one piece code (what goes in the headers) to be responsible for a subtle invariant needed later on (the alignment of a block).

In general, whenever you write a piece of code, you should be thinking about some programmer (who might by you), a year later trying to figure out your code, and WANTING TO LEARN AS LITTLE AS POSSIBLE about it to get his job done. Thus you want everything to be 'obvious' and 'explicit' as possible. Being 'smart' is a BAD idea unless there is a compelling reason to (e.g. it improves perf in a non-trivial way, and then you have to pay that 'smartness' by documenting it) Sometimes we fall short, but this is the goal.

Given that you added a new 'Padding' tag, I figured what you did was add these to the 'tail' of the object before. But thinking about it, I don't like that either, because it places the burden of alignment on the PREVISOUS object, and it is also pretty subtle (you need to know that there will be an end-object byte afterward and adjust for that).

All of that is too subtle. The 'obvious' thing to do is to 'align when you need it' INSIDE objects. Thus where we need alignment is INSIDE the EventBlock. Thus after emitting the block size, the writer will simply emit 0 to 3 bytes until the output pointer is 4 byte aligned (this counts as part of the payload). Similarly, the reader, after reading the block size will read bytes until its input pointer is 4 byte aligned. This is just a few lines of code, and makes alignment very clear and explicit (frankly you don't need asserts, since you FORCED the alignment at that point.

Notice this approach is robust (no matter what is happening OUTSIDE this object, you get the alignment you want. It is LOCAL (only code associated with EventBlock needs to care, and it is EXPLICIT (there is code (near where you would care), that has the 'job' of providing alignment and programmers can see it (it is not a subtle ramification of something that seems to have another purpose).

I would like us to use this approach (or something equally 'obvious') and then you can rip out the subtle names ! and . in the names).

Seems like you also don't need to change IFastSerializable either.

vancem · 2018-01-31T01:07:56Z

src/TraceEvent/EventPipe/EventPipeEventSource.cs


-            // Because we told the deserialize to use 'this' when creating a EventPipeFile, we 
-            // expect the entry object to be 'this'.
-            Debug.Assert(entryObj == this);


Why did we remove the assert? (of course it goes after 'entryObj' is defined, but it is still correct and valuable (as well as the comment.

I removed this assert because I implemented unit tests to verify the correct behavior of this code. (CanParseHeaderOfV1EventPipeFile and CanParseHeaderOfV3EventPipeFile)

imho we should have more unit tests and fewer debug.asserts (I understand that we use Debug.Assert here as a debug-only code contracts) to make the code more easy to understand and maintain.

I reverted this change.

vancem · 2018-01-31T01:23:53Z

src/TraceEvent/EventPipe/EventPipeEventSource.cs

        {
-            // Guess that the event is < 1000 bytes or whatever is left in the stream.  
-            int eventSizeGuess = Math.Min(1000, _endOfEventStream.Sub(reader.Current));
+            nint eventSizeGuess =


As a rule I don't like to use ?: except in cases where it clearly fits on a line. For everything else use if statements.

However I think I was trying to be too smart and just made the code complex. Time to simplify. For the first call to Get Pointer simply use EventPipeHeaderSize. Then make the call to GetPointer down below unconditional. This is simpler and probably as efficient as what is there now.

vancem · 2018-01-31T01:28:39Z

src/TraceEvent/EventPipe/EventPipeEventSource.cs

@@ -8,11 +10,15 @@
 using System.Diagnostics;
 using System.Runtime.InteropServices;

+using nint = System.Int32; // as of today the deserializer is limited to 32 bit, in case we change in the future we don't want to miss any cast


Don't bother with nint. While we might relax the serialization so that the TOTAL size of the file is > 4Gig (in that case StreamLabel needs to be bigger), nint today is only used to measure the size of single event, and I think we can safely assume we are not likely to make THAT bigger than 4Gig.

you are right, it was over-engineering

vancem · 2018-01-31T01:29:37Z

src/TraceEvent/EventPipe/EventPipeEventSource.cs

            Debug.Assert(0 < eventData->TotalEventSize && eventData->TotalEventSize < 0x20000);  // TODO really should be 64K but BulkSurvivingObjectRanges needs fixing.

+            nint eventDataEndIncludingAlignmentPadding = (nint)reader.Current + eventData->TotalEventSize;


This should be

StreamLabel eventDataEndIncludingAlignmentPadding = reader.Current.Add(eventData->TotalEventSize);

For what it is worth, I think you could just call it eventDataEnd be clear. This is especially true because there is no padding in the code for an individual event (each event should start on a 4 byte boundary, and everything in the event is also a multiple of 4 bytes, so you can ignore alignment issues).

vancem · 2018-01-31T01:40:32Z

src/TraceEvent/EventPipe/EventPipeEventSource.cs

            EventPipeEventHeader* eventData = (EventPipeEventHeader*)reader.GetPointer(eventSizeGuess);
+
            // Basic sanity checks.  Are the timestamps and sizes sane.  
            Debug.Assert(sessionEndTimeQPC <= eventData->TimeStamp);
            Debug.Assert(sessionEndTimeQPC == 0 || eventData->TimeStamp - sessionEndTimeQPC < _QPCFreq * 24 * 3600);
            Debug.Assert(0 <= eventData->PayloadSize && eventData->PayloadSize <= eventData->TotalEventSize);


I would also assert that that the Version < 3 or

eventData->Payload is 4 byte aligned. and eventData->PayloadSize is a multiple of 4.

vancem · 2018-01-31T01:44:13Z

src/TraceEvent/EventPipe/EventPipeEventSource.cs

            {
                deserializer.Read(out pointerSize);
                deserializer.Read(out _processId);
                deserializer.Read(out numberOfProcessors);
                deserializer.Read(out _expectedCPUSamplingRate);
+                // TODO: alig


Can remove the TODO.

vancem · 2018-01-31T01:52:44Z

src/TraceEvent/EventPipe/EventPipeEventSource.cs

            _eventRecord = (TraceEventNativeMethods.EVENT_RECORD*)Marshal.AllocHGlobal(sizeof(TraceEventNativeMethods.EVENT_RECORD));
            ClearMemory(_eventRecord, sizeof(TraceEventNativeMethods.EVENT_RECORD));

-            if (pointerSize == 4)


This is another case where I prefer using if than ?:. (because it does not fit on a line) In general ?: is hard to read unless it is really short. Yes, you are cloning the _eventRecord->EventHeader.Flags part but that is OK.

_eventRecord->EventHeader.Flags = TraceEventNativeMethods.EVENT_HEADER_FLAG_64_BIT_HEADER;

I have simplified it to: (ushort)(pointerSize * 8)

vancem · 2018-01-31T02:01:38Z

src/TraceEvent/EventPipe/EventPipeEventSource.cs

+            // Dispatch through all the events.  
+            PinnedStreamReader deserializerReader = (PinnedStreamReader)deserializer.Reader;
+
+            // Align to a 4 byte boundary


I assume that the way this works is that you aligned the EventPipeEventBlock as a whole so there was no need to do alignment inside the block.

You can simply delete the *ptr variable however (since it is not used except for asserts), and add an assert that _startEventData is 4 byte aligned above).

vancem

I put a few relatively minor requests for change, but on the whole it looks fine.

vancem · 2018-01-31T16:11:07Z

src/TraceEvent/EventPipe/EventPipeEventSource.cs

 namespace Microsoft.Diagnostics.Tracing
 {
    /// <summary>
    /// EventPipeEventSource knows how to decode EventPipe (generated by the .NET 
-    /// core runtime).   
+    /// core runtime).    Please see 


Nit, looks like the 'Please see' is incomplete.

vancem · 2018-01-31T16:26:49Z

src/TraceEvent/EventPipe/EventPipeEventSource.cs

-                _eventRecord->EventHeader.Flags = TraceEventNativeMethods.EVENT_HEADER_FLAG_32_BIT_HEADER;
-            else
-                _eventRecord->EventHeader.Flags = TraceEventNativeMethods.EVENT_HEADER_FLAG_64_BIT_HEADER;
+            _eventRecord->EventHeader.Flags = (ushort)(pointerSize * 8);


Please don't set the flags this way (I prefer the original). The issue is that the code is now COMPLETELY obscure (you have to know the specific values of EVENT_HEADER_FLAG_*_BIT_HEADER, to understand why this work. This is the kind of thing you let optimizer do.

But more to the point, it is my JOB to do performance investigations/improvements and the very first thing I tell people, is that generally speaking 90+% of all your code is NOT performance sensitive and you should be writing your code to maximize clarity, and maintainability and other metrics. Only in that last < 10% (it is usually more like 1%) of your code does it matter.

So is this the hot 10%? The answer is easy: no. This code only gets called when metadata events are seen, and those should be probably less than 1% of the trace. Thus without even doing a measurement I can tell you that this code is NOT the hot 10% and thus we should be optimizing for clarity.

Now you can debate me whether the 'if' or the ?: is clearer, but I would generally argue that if you have the choice between using a rare construct/pattern and using a common one/cliche, you should use the common one. 'if' is MUCH more common that ?:, and thus should be preferred unless there is a clear advantage (e.g. shrinking 4 lines to 1 is reasonable advantage, but that only works if resulting line is short. If you have to break it up again, you lose the advantage.

I like micro-optimizations, but not that much ;)

For me, it was the just simplest way to write it.

I reverted the change.

adamsitnik · 2018-01-31T16:58:10Z

@vancem done

vancem

The only changes I want are

Make the type names normal names.
Make the alignment explicit in EventBlock. (or some equally simple/explicit way of doing it).

vancem · 2018-01-31T17:05:00Z

src/TraceEvent/EventPipe/EventPipeEventSource.cs

-
+#endif
+            _deserializer.RegisterFactory("!EventTrace.", delegate { return this; });
+            _deserializer.RegisterFactory("!EventBlock.", delegate { return new EventPipeEventBlock(this); });


These names should just be probably 'Trace' and 'EventBlock'.

adamsitnik · 2018-02-01T17:55:17Z

@vancem Done. changes

Corresponding change in CoreCLR

vancem · 2018-02-01T18:15:44Z

@adamsitnik I want to thank you for your work on this PR. I know that I can be a bit of a pain, and probably more pedantic than is good, but I am very pleased with the result, and want to thank you for your work on this.

Good Job!

adamsitnik · 2018-02-01T18:25:28Z

@vancem Big thanks for the review. And patience! I can see that I can learn a LOT from you.

vancem and others added 11 commits January 23, 2018 17:05

Changes for the next version of the EventPipe file format

374e5c7

Added Versioning support, documentation

a2b12b5

Update V3 format for Event MetaData

f7be4c0

This simplifies the V3 format. I also spit out the code for the old format so it would be easier to remove it later.

nits

2c2d5b3

Merge remote-tracking branch 'vancem/EventPipeV3' into eventBlocks

058bd99

making it work with the latest format

557d88f

padding support

acefa2c

get ProviderId based on ProviderName, assume Metadata is mandatory an…

a61b5c2

…d it's lenght does not come first

update the tests

92b0de7

update test file after merge of my fork with CoreCLR/master

6cbc9cf

Merge remote-tracking branch 'upstream/master' into eventBlocks

19f197a

# Conflicts: # src/FastSerialization/FastSerialization.cs

vancem reviewed Jan 31, 2018

View reviewed changes

update C# version for all projects

a0af499

vancem reviewed Jan 31, 2018

View reviewed changes

vancem suggested changes Jan 31, 2018

View reviewed changes

improvements after code review

f936d63

vancem reviewed Jan 31, 2018

View reviewed changes

improvements after code review

9ff5e95

vancem suggested changes Jan 31, 2018

View reviewed changes

vancem reviewed Jan 31, 2018

View reviewed changes

aligning change: after the block size comes eventual padding

9c7fb68

vancem approved these changes Feb 1, 2018

View reviewed changes

vancem merged commit ed9cc8d into microsoft:master Feb 1, 2018

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Event blocks #546

Event blocks #546

adamsitnik commented Jan 30, 2018

vancem Jan 31, 2018

adamsitnik Jan 31, 2018

vancem Jan 31, 2018

adamsitnik Jan 31, 2018

vancem Jan 31, 2018

vancem Jan 31, 2018

adamsitnik Jan 31, 2018

vancem Jan 31, 2018

vancem Jan 31, 2018

adamsitnik Jan 31, 2018

vancem Jan 31, 2018 •

edited

Loading

vancem Jan 31, 2018 •

edited

Loading

adamsitnik Jan 31, 2018

vancem Jan 31, 2018

vancem Jan 31, 2018

adamsitnik Jan 31, 2018

vancem Jan 31, 2018

vancem left a comment

vancem Jan 31, 2018

vancem Jan 31, 2018

adamsitnik Jan 31, 2018

adamsitnik commented Jan 31, 2018

vancem left a comment

vancem Jan 31, 2018

adamsitnik commented Feb 1, 2018

vancem commented Feb 1, 2018

adamsitnik commented Feb 1, 2018

		Debug.Assert(0 < eventData->TotalEventSize && eventData->TotalEventSize < 0x20000); // TODO really should be 64K but BulkSurvivingObjectRanges needs fixing.

		nint eventDataEndIncludingAlignmentPadding = (nint)reader.Current + eventData->TotalEventSize;

Event blocks #546

Event blocks #546

Conversation

adamsitnik commented Jan 30, 2018

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

vancem Jan 31, 2018 • edited Loading

Choose a reason for hiding this comment

vancem Jan 31, 2018 • edited Loading

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

vancem 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

adamsitnik commented Jan 31, 2018

vancem left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

adamsitnik commented Feb 1, 2018

vancem commented Feb 1, 2018

adamsitnik commented Feb 1, 2018

vancem Jan 31, 2018 •

edited

Loading

vancem Jan 31, 2018 •

edited

Loading