Improvement: better concurrency support of interleaved futures

[ten3roberts]

See: #60

[ten3roberts]

Added a debugging for span modes, to see why a branch was printed, to be able to debug if it is a retrace, pre-open or open event

[ten3roberts]

When working on this I've managed to implement two other things using the same bit of code that was required for retracing two work.

The changes include:

• Span retracing #60
• Fix broken lines when only one of verbose_open/exit are enabled #66
• Defer span opening until an event is generated inside (and skipping the span altogether if not)

Additionally, there is a small with_span_modes that prints the kind of the span event such as open/pre_open/close etc, which aids when debugging this crate and figuring out what a line. If you don't want it to remain I'll happily remove it

I've added examples and tests for each.

Here is how retracing looks:

Please do let me know what you think of this @oli-obk

[davidbarsky]

I really like the overall outcome of this in the screenshot! I'll need to dig into the specifics, though.

[ten3roberts]

Good to hear.

Interestingly the deferred/lazy spans didn't require any extensive rewrite, but rather didn't need more than simply doing nothing in on_new_span and having the existing span retracing print the span when encountered in an event.

Another thing that changed is having the Buffers locked and passed to write_span_info rather than locking inside of it (inside the retrace loop etc), to avoid interleaving multithreaded calls as that would muddle the current_span temporal context.

The default behavior is unchanged, and the retracing is opt-in. I am consider if it may be a good idea for discoverability and autoimprovement if retracing could be enabled by default, as having it off just makes events seem to appear in the wrong span. The retracing feature essential connects each "timeline" or branch of events with a line branching off the right vertical line, which can be seen in the screenshot above when interleaving spans of different depths and parents.

[ten3roberts]

Another thing that I've been wondering about is the standard or suggested style for writing tracing events.

It seems as if both you and hyperium use the lowercase terse/machine like format, while some others use a more sentence or subject-verb-object style f writing them

For example

trace!("ignore unknown frame type {:#x}", ty);

While others have used

trace!("Ignoring unknown frame type {:#x}", ty)

I've awkardly found both in this PR :sweat_smile:, just wanting to keep consistency of this while I am at it.

Anyways, hoping you find this PR useful and in good quality. Let me know if you have any changes you request and I'll be happy to fix them up

[davidbarsky]

The default behavior is unchanged, and the retracing is opt-in. I am consider if it may be a good idea for discoverability and autoimprovement if retracing could be enabled by default, as having it off just makes events seem to appear in the wrong span. The retracing feature essential connects each "timeline" or branch of events with a line branching off the right vertical line, which can be seen in the screenshot above when interleaving spans of different depths and parents.

I think for those that need it, they really need. We can always call it out on the main documentation page.

It seems as if both you and hyperium use the lowercase terse/machine like format, while some others use a more sentence or subject-verb-object style f writing them

Yeah, my feeling is the value—pardon the pun—are the key/values on spans and events. The sentence is really more to provide a hint of context on what is happening, so a full sentence isn't as valuable.

I've awkardly found both in this PR 😅, just wanting to keep consistency of this while I am at it.

I think this occurred because the original example was lifted from slog, which preferred more of the sentence-style to logging.

[ten3roberts]

Alright thanks, that really explains it.

I'll fix those sentences up to be consistent, and I suppose the current doc comments on the builder are enough, as there doesn't seem to be any "overview" in lib.rs to consider.

May I re-add you as a reviewer when done with that? Is there anything more I should add or fix up?

[ten3roberts]

Hi @oli-obk do you think we could get this PR reviewed?

I'd love to hear what you think about this feature and its implementation

[oli-obk]

Sorry I'm still completely swamped with rustc reviews since I returned from vacation last week. The rendered version lgtm, but I won't get to reviewing the code in depth in the next week

[ten3roberts]

Sorry I'm still completely swamped with rustc reviews since I returned from vacation last week. The rendered version lgtm, but I won't get to reviewing the code in depth in the next week

No worries at all, this is the nature of asynchronous work, so don't stress yourself over it. Just wanted to know all was ok and that this wasn't forgotten 😊

Do you think a new crates.io version could be published with this, or are there more things that are in planning before that?

[oli-obk]

I'm looking at https://github.com/davidbarsky/tracing-tree/pull/68, too, so we could publish with both changes. If it looks like it needs more time, we'll publish a new version with just everything up to this PR