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

Improve ftime-trace implementation. #3797

Merged
merged 8 commits into from
Aug 14, 2021

Conversation

JohanEngelen
Copy link
Member

  • Rewrite ftime-trace to our own implementatation instead of using LLVM's time trace code. The disadvantage is that this removes LLVM's work from the trace (optimization), but has the large benefit of being able to tailor the tracing output to our needs.
  • Add memory tracing to ftime-trace (not possible with LLVM's implementation)
  • Do not output the sum for each "category"/named string. This causes the LLVM output to be very long, because we put more information in each time segment name. Tooling that processes the time trace output can do this summing itself (i.e. Tracy), and makes the time trace much more pleasant to view in trace viewers.
  • Add source file location info to time trace (Tracy understands it) (not possible with LLVM's implementation)

- Rewrite ftime-trace to our own implementatation instead of using LLVM's time trace code. The disadvantage is that this removes LLVM's work from the trace (optimization), but has the large benefit of being able to tailor the tracing output to our needs.
- Add memory tracing to ftime-trace (not possible with LLVM's implementation)
- Do not output the sum for each "category"/named string. This causes the LLVM output to be _very_ long, because we put more information in each time segment name. Tooling that processes the time trace output can do this summing itself (i.e. Tracy), and makes the time trace much more pleasant to view in trace viewers.
@kinke
Copy link
Member

kinke commented Jul 28, 2021

Sounds nice! Excluding the LLVM stats seems fine to me, after all it's mostly about introspecting time spent in frontend and glue layer.

Wrt. memory stats, AFAICT you're tracking frontend memory consumption only. Not sure if glue layer and LLVM consumption is really relevant, but at least with mimalloc, we could probably get the overall heap stats via mi_stats_print_out() or so.

@JohanEngelen
Copy link
Member Author

Sounds nice! Excluding the LLVM stats seems fine to me, after all it's mostly about introspecting time spent in frontend and glue layer.

Wrt. memory stats, AFAICT you're tracking frontend memory consumption only. Not sure if glue layer and LLVM consumption is really relevant, but at least with mimalloc, we could probably get the overall heap stats via mi_stats_print_out() or so.

Memory stats definitely needs more work, I'll leave that for the future. I'm actually not sure if I'm interpreting the GC stats correctly. It's like you say, this does not track the C++ memory usage. But I think the frontend usage is a lot more (CTFE...) than that.
We can also think of other useful stats (like number of template instantiations?). As for timing regions, CTFE is not tracked well I think.

@JohanEngelen
Copy link
Member Author

Apparently gdmd does not define D_InlineAsm_X86_64 ? Very strange. But OK, I've implemented a fallback option, with only time in seconds as resolution. Based on https://github.com/D-Programming-GDC/gdc/blob/e5a495a8490b4eb3acb78448f79920e2ee8a9ca9/libphobos/libdruntime/rt/util/random.d#L17-L63

@kinke
Copy link
Member

kinke commented Jul 28, 2021

[GDC doesn't support DMD-style inline asm (which that predefined version stands for).]

@JohanEngelen
Copy link
Member Author

JohanEngelen commented Jul 29, 2021

And now I need a compile-time (!) wait(1 second) :D

Edit: no longer needed after using core.time.MonoTime

this.beginningOfTime = time / time_scale;
}

void beginScope(const(char)[] name, const(char)[] details, Loc loc)
Copy link
Member

Choose a reason for hiding this comment

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

const ref Loc?

Copy link
Member Author

Choose a reason for hiding this comment

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

Loc is small (size of two pointers), so I chose to copy it, because it's probably faster.

Copy link
Member

Choose a reason for hiding this comment

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

It doesn't really matter, hence the ?; it was primarily for consistency with the frontend, which mostly uses const ref Loc but isn't totally consistent either.

{
// {"ph":"X","name": "Sema1: somename","ts":111,"dur":222,"loc":"filename.d:123","args": {"detail": "something", "loc":"filename.d:123"},"pid":0,"tid":0}

void writeLocation(Loc loc)
Copy link
Member

Choose a reason for hiding this comment

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

const ref?

Copy link
Member Author

Choose a reason for hiding this comment

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

Loc is small (size of two pointers), so I chose to copy it, because it's probably faster.

@JohanEngelen
Copy link
Member Author

Good to merge?

Copy link
Contributor

@thewilsonator thewilsonator left a comment

Choose a reason for hiding this comment

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

LGTM apart from the const ref on the Loc which is only bad because for the frontend source uses const ref Loc everywhere and not using it is surprising.

…surement' stage uses ticks as unit

- Fix crash on `ldc2 -ftime-trace` without files passed.
@JohanEngelen
Copy link
Member Author

Conversion to core.time.MonoTime complete, ready now.

Copy link
Member

@kinke kinke left a comment

Choose a reason for hiding this comment

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

LGTM, thanks, also nice to have less integer divisions now. I guess the test will remain a bit brittle (OS context switches etc.), but we'll see.

@kinke
Copy link
Member

kinke commented Aug 13, 2021

@JohanEngelen: I'm about to merge v2.097.2 and release LDC v1.27.1, mainly to re-add an AArch64 Linux package. Including this might be nice, so please merge if you agree.

@JohanEngelen JohanEngelen merged commit c517ce9 into ldc-developers:master Aug 14, 2021
@JohanEngelen JohanEngelen deleted the timetraceupdate branch August 14, 2021 12:11
@JohanEngelen
Copy link
Member Author

Merged. Risk of introducing badness to 1.27 is very low.

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.

3 participants