trace scope tracking is not happy with concurrency

[RalfJung]

When running a concurrent program with MIRI_LOG=info, the nesting depth of the resulting trace is huge even when logging code that happens directly on the main thread. I think tracing might not deal well with the fact that we have multiple stacks that are independently nested? @oli-obk is there anything we can do to improve that?

[oli-obk]

oh 🤦 yea. We could pop all the current thread's frames and push the new thread's frames on thread switching. Could end up expensive, but only happens while you're logging, so it should be fine.

[RalfJung]

Back then someone said the trace library supports a notion of "thread" (or so) and we could use that. What happened to that statement?^^

[oli-obk]

I don't think we can hijack that for our purposes, but I'll look into it.

[RalfJung]

So does this need a new feature in tracing-tree first? Should we file a feature request there?

[oli-obk]

I think this is the same issue as async tracing has

davidbarsky/tracing-tree#60

davidbarsky/tracing-tree#74

[RalfJung]

But those are both closed...

[RalfJung]

davidbarsky/tracing-tree#74 seems to indicate that we can already have multiple independent scopes, they are just not rendered properly? Currently Miri doesn't even tell tracing about the threads so there's no way it can do anything. All we do is:

        let span = info_span!("frame", "{}", instance);
        self.frame_mut().tracing_span.enter(span);

We need some way to manually set the parent span I think?

Or at least, something has to happen when we switch threads. Should we "exit" all the spans of the old thread and "enter" all the spans of the new thread? That needs spans that can be exited and entered multiple times. Also we don't want the full stack trace of leaving and entering all these spans when switching threads I think... though maybe sometimes we do.

[ten3roberts]

Adding to this.

Yes, tracing-tree has no notion of threads. However, there is a new feature called retracing, which will re-open a span and its parents up to the common ancestor of the last outputted span during an event.

The previous behavior was to just straight up print the event when it came, ignoring if the last printed span is correct or not, the new retracing feature (off by default for now), will reprint the spans leading up to the event.

Due to this, tracing/tracing-tree does not need to know about threads, as the relationships between an events associated span (and its parents) are enough to deduce a proper tree.

There was a slight issue regarding an oversight in the combination with verbose entry and eager spans, and that is currently in motion in davidbarsky/tracing-tree#78 to be reviewed and merged.

If you want to you can try out that branch in miri, and enable retracing and see how it fares in miri. I'll be happy to help fix any issue with it if it happens to arise.

[RalfJung]

Due to this, tracing/tracing-tree does not need to know about threads, as the relationships between an events associated span (and its parents) are enough to deduce a proper tree.

How is the parent of a span determined? Currently I don't think Miri provides the required information to tracing, and I don't know how we should provide that information. But this was all set up by @oli-obk and I barely understand it anyway...

What I would have expected is to be able to say "this span is a child of that span" or "this span is a root, not child of anything". The APIs we currently use don't seem to offer that, but there may be other APIs I have been missing.