tracing, as I've been pitching to @nikomatsakis:
log, but it can also function as a
tracingcrate. I started on docs: https://github.com/tokio-rs/tracing/pull/496
spans track causality and temporality, which let you build up an execution graph of libraries and applications _without_ runtime support. with that information, you can replicate ra's hierarchical profiling feature, amongst others.
spanshould typically correspond to whatever you consider to be a semantically meaningful unit of work. in Chalk's case, you might want to attach a span to a strand, which would allow you to track that end-to-end. in ra's case, you might have a top-level span for each lsp query, with more fine grained spans as appropriate.
tracing: at a high level, both
chalkrun some sort of queries over large graphs.
here are some neat libraries atop of tracing, for what it's worth:
now that i've pitched the benefits, feel free to explain your needs and i can tell you what's ready and what need a bit of work :)
@David Barsky would you recommend switching rust-analyzer's hierarchical profiling from a hand-written thing to
tracing? The metrics I am interested most is the amount of code I need to maintain and compile times.
So right now, chalk doesn't make use of
log I don't think. Instead it uses the
info_heading macros in
chalk-macros (I think)
@David Barsky It would be super awesome if you sent a PR introducing
tracing. From what I can tell, that would be immediately helpful when looking at performance with
@matklad if it’s _just_ the hierarchal profiling, _maybe_ not. if you’d like to start to replace other instrumentation systems, like logging or whatever, then i’m inclined to say yes. I’ve found tracing-like systems as a great way to onboard new engineers and debug complex systems at work, and that could be handy for rust-analyzer.
@Jack Huey gotcha, those macros look decently similar to log’s, i think. i think tracing could be used to replace those, but in terms of global performance overviews, you’ll need to instrument with the spans to note units of work. the
#[instrument] macro helps.
i’m also on vacation so i’ll be a bit slow to respond, i’m sorry.
Really, the existing macros essentially just output with
eprintln and also manage indentation too
Haven't really looked at
tracing much, only briefly. So really don't know how perf overviews could be checked
Also on vacation, so I understand :)
perf-related views would really be a thing once tracing has a sufficiently comprehensive view of a program’s execution graph, which is comes much more quickly than you’d expect.
you can think of spans as nodes in graph, but it’s up to you to you demarcate the different nodes. we’re trying to reduce the amount of effort needed to mark different sections. it’s less than say, metrics libraries, but more than what some folks might be used to.
for what it’s worth @matklad, i wanted something like the profiling tools you have in ra_prof to live in tracing (would be super handy for debugging/profiling services) but never got around it to writing that integration. too little time.
the main win of having something like ra_prof in tracing is that existing annotations can be reused for the the style of profiling you have. not sure compile times would really decrease, but they won’t increase, and you might end up owning less code.
anyways, i’ll dump the last few thoughts: if you need an incremental, graph-based instrumentation system, tracing’s a great fit. it’s great for debugging and understanding complex systems. if your current approach to instrumentation and debugging works well enough, tracing will still be there when you do start to need it. that being said, the benefits of tracing-like systems are surprisingly large, even early on & when it might feel like overkill. i think it might be a formalization of what’s currently in chalk and ra_prof, but i can’t say if the formalization is right for you now.
i’ll post a screenshot of the sort of data it can collect after i sleep (8-9 hours from now).
Screen-Shot-2020-01-06-at-8.29.42-PM.png a formatter that attempts to mimic ra-prof, but is also inspired by what
tracing already has + slog
Are these times the diff between current event and last? Or current event and last event or span?
@Jack Huey these times are the difference between the current event and the last event/span, whichever was the last one.
so the top-level span ("server") doesn't have an attached elapsed timer, because it lives for the lifetime of the program
so the 18.104.22.168 messaged received elapsed is to the beginning of the conn span, not to the previous disconnect?
yes, the beginning of the
that can change easily
to be entirely honest, I'm not entirely sure how the "elapsed" time should be counted
I would say beginning of the span
so the current behavior?
Yea, current behavior seems most correct