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

rewrite the speedscope|chromium exporter logic to ensure that the output is always correct #1212

Merged
merged 5 commits into from
Jun 26, 2020

Conversation

adamsitnik
Copy link
Member

This is a proper fix for #1178 (at least I hope so)

Intro to file format

Both speedscope and chromium expect the exported data to be in a certain order.

Let's consider the following application:

void M()
{
    A();
    C();
}

void A() => B();
void B() {}
void C() => D();
void D() {}

The expected order of exported profile events is:

Open M
Open A
Open B
Close B
Close A
Open C
Open D
Close D
Close C
Close M

Imagine that you pick up a pen and you want to draw CPU samples in time order from the left to the right. This order makes it very easy.

Past

When I was implementing the initial version of the exporter, I've decided to expand all leaf CPU samples (walk the stack), aggregate all samples per method, and then sort them by time (ascending) and depth. This approach worked for some scenarios, but not all of them. Recently speedscope has introduced a validation of the input data in jlfwong/speedscope#273 and it has broke us, because our files were not always correct (#1178 dotnet/diagnostics#1206)

Proposal

I think that instead of aggregating all samples by methods and then sorting them, we should compare the current call stack with previous one, and generate the open and close events on the fly. (not horizontal but vertical approach).

I've tested the new implementation against all the trace files I had and it works fine.

@swift-kim I've added an integration test for the trace files that you have provided. Please let me know if this is OK.

Examples:

https://www.speedscope.app/#profileURL=https://gist.githubusercontent.com/adamsitnik/dee155b6a0be32f0bbb70f3f65398592/raw/da422696bacfa95b002d390b1cdb3bf02a7a4aff/HeartRateMonitor.speedscope.json

https://www.speedscope.app/#profileURL=https://gist.githubusercontent.com/adamsitnik/6bd989322777b21aa0c6a1987320dfba/raw/1a1df74b6be3cb903dc0105ea996ea3c7b846c05/VoiceMemo.speedscope.json

@brianrob Could you please take a look? I hope that this fix is going to solve all the problems we had with the exporter once and for all.

Copy link
Contributor

@josalem josalem left a comment

Choose a reason for hiding this comment

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

LGTM! Comments inline. I think this is a more robust way of creating "continuous" events from non-contiguous data. Thanks for the changes!

src/TraceEvent/Stacks/StackSourceWriterHelper.cs Outdated Show resolved Hide resolved

// in case both samples start at the same time, the one with smaller metric should be the first one
return x.Metric.CompareTo(y.Metric);
return left.RelativeTime + (left.Metric * 1.001) < right.RelativeTime;
Copy link
Contributor

Choose a reason for hiding this comment

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

Is the factor of 1.001 arbitrary or is this based on some characteristic of the metric?

Copy link
Member Author

Choose a reason for hiding this comment

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

most of the times when events are continuous the following statement should be true

left.Metric == right.RelativeTime - left.RelativeTime

however, RelativeTime is double while Metric is float and we are sometimes loosing a very small fraction of metric in the conversion. the 1.001 is just to cover this possible diff.

src/TraceEvent/TraceEvent.Tests/SpeedScopeExporterTests.cs Outdated Show resolved Hide resolved
@josalem
Copy link
Contributor

josalem commented Jun 18, 2020

I did a similar analysis for an old hack that I used to do pseudo call counting for a cachegrind format converter.

Copy link
Contributor

@swift-kim swift-kim left a comment

Choose a reason for hiding this comment

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

The patch worked for all the trace files I have. Thank you for the great work!

src/TraceEvent/TraceEvent.Tests/SpeedScopeExporterTests.cs Outdated Show resolved Hide resolved
Co-authored-by: John Salem <josalem@microsoft.com>
Co-authored-by: Swift Kim <swift.kim@samsung.com>
@adamsitnik
Copy link
Member Author

The patch worked for all the trace files I have. Thank you for the great work!

thanks for letting me know!

maybe we can add more sample traces here?

sure! as long as they are not very big we should add few more cases

@brianrob
Copy link
Member

@adamsitnik thanks for doing this. Apologies for the delay.

@brianrob brianrob merged commit abc0041 into microsoft:master Jun 26, 2020
@adamsitnik
Copy link
Member Author

thanks for doing this. Apologies for the delay.

thank you for the review!

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.

None yet

4 participants