Print the duration of the span when closing a span

[oli-obk]

* I'd like to be able to visually distinguish between a span that has _exited_ and a span that has _closed_. That could be done with durations, but that's not the only approach.

  * As I'm writing this comment, I remembered that tracing-tree isn't really used with asynchronous or non-blocking code. Therefore, I'm not sure how useful this feature is _in the first place_.

* One idea I had was to use durations from the _start_ of the span. However, after thinking about it a bit more, I realized that this opens a larger design space that's best discussed in a separate issue. I'd prefer to _not_ block merging this PR on that point.

In the latter case we have to store the opening somewhere, any tips?

Sure! Here's the approach I was thinking of:

* `new_span` creates a [`DateTime<Local>`](https://github.com/davidbarsky/tracing-tree/blob/main/src/lib.rs#L23). Nothing needs to change here.

* In an `on_exit` or `on_close` method, copy [this approach](https://github.com/davidbarsky/tracing-tree/blob/6a81afb008ac2af974620d06491376c329c04893/src/lib.rs#L269-L282) to calculate the elapsed time of the span.

I did not realize all timings are from the start of the current span. I thought they were from the start of the program :facepalm:

Ok, this seems easy enough to do. Though I'm now also wondering if the start of a span should also have a timing printed, basically giving the time from the start of its parent span.

[davidbarsky]

Thanks for opening this!

I did not realize all timings are from the start of the current span. I thought they were from the start of the program 🤦

No worries! I think this is also doable by borrowing the implementation of tracing_subscriber::fmt::time::Uptime. The "start" can be stored as a field in the layer. I would expect that the time between the the creation of the layer and the first event would be pretty short, thankfully.

Though I'm now also wondering if the start of a span should also have a timing printed, basically giving the time from the start of its parent span.

I think I experimented with this a while ago, but I didn't find it to be particularly useful because I've noticed in the codebases I'm responsible for, there's virtually no delay between creating and entering a span. I'm open to be convinced on this, especially if Chalk/rustc/Miri have different span creation patterns.

[oli-obk]

I think I experimented with this a while ago, but I didn't find it to be particularly useful because I've noticed in the codebases I'm responsible for, there's virtually no delay between creating and entering a span. I'm open to be convinced on this, especially if Chalk/rustc/Miri have different span creation patterns.

Ah, that's not what I meant. I meant printing the time within the parent span. So if we enter a span, that span entering has currently no time offset to the parent, but every event in the parent would have had one. If there was a long time since the last event in the parent span, the information when the new span was entered relative to it may be of interest to the users.