Skip to content

Commit aa43680

Browse files
ten3robertsten3roberts
committed
fix: pre-open for retraced spans
1 parent 09adf54 commit aa43680

File tree

5 files changed

+42
-43
lines changed

5 files changed

+42
-43
lines changed

‎examples/concurrent_eager.rs

+1
Original file line numberDiff line numberDiff line change
@@ -18,6 +18,7 @@ fn main() {
1818
.with_thread_ids(true)
1919
.with_span_retrace(true)
2020
.with_deferred_spans(false)
21+
.with_verbose_entry(true)
2122
.with_targets(true);
2223

2324
let subscriber = Registry::default().with(layer);

‎examples/concurrent_eager.stdout

+8-4
Original file line numberDiff line numberDiff line change
@@ -1,15 +1,19 @@
11
1:main┐concurrent_eager::spawn_fut key="a"
22
1:main┐concurrent_eager::spawn_fut key="b"
33
1:main┐concurrent_eager::spawn_fut key="a"
4-
1:main├───┐concurrent_eager::a
4+
1:main├─┐concurrent_eager::spawn_fut key="a"
5+
1:main│ └─┐concurrent_eager::a
56
1:main┐concurrent_eager::spawn_fut key="b"
6-
1:main├───┐concurrent_eager::b
7+
1:main├─┐concurrent_eager::spawn_fut key="b"
8+
1:main│ └─┐concurrent_eager::b
79
1:main┐concurrent_eager::spawn_fut key="a"
8-
1:main├───┐concurrent_eager::a
10+
1:main├─┐concurrent_eager::spawn_fut key="a"
11+
1:main│ └─┐concurrent_eager::a
912
1:main│ ├─── Xms INFO concurrent_eager a
1013
1:main├───┘
1114
1:main┐concurrent_eager::spawn_fut key="b"
12-
1:main├───┐concurrent_eager::b
15+
1:main├─┐concurrent_eager::spawn_fut key="b"
16+
1:main│ └─┐concurrent_eager::b
1317
1:main│ ├─── Xms INFO concurrent_eager b
1418
1:main├───┘
1519
1:main┘

‎examples/concurrent_verbose.stdout

+9-12
Original file line numberDiff line numberDiff line change
@@ -1,24 +1,21 @@
11
1:main┐concurrent_verbose::hierarchical-example version=0.1
2-
1:main├───┐concurrent_verbose::server host="localhost", port=8080
2+
1:main├─┐concurrent_verbose::hierarchical-example version=0.1
3+
1:main│ └─┐concurrent_verbose::server host="localhost", port=8080
34
1:main│ ├─── Xms INFO concurrent_verbose starting
45
1:main│ ├─── Xs INFO concurrent_verbose listening
56
1:main│ ├─── Xs DEBUG concurrent_verbose starting countdowns
6-
1:main│ ├─┐concurrent_verbose::server host="localhost", port=8080
7-
1:main│ │ └─┐concurrent_verbose::countdowns
8-
1:main│ │ ├───┐concurrent_verbose::countdown_a
9-
1:main│ │ │ ├─── Xms DEBUG concurrent_verbose polling countdown, label="a", count=3
7+
1:main│ ├───┐concurrent_verbose::countdowns
108
1:main│ │ ├─┐concurrent_verbose::countdowns
11-
1:main│ │ │ └─┐concurrent_verbose::countdown_b
9+
1:main│ │ │ └─┐concurrent_verbose::countdown_a
10+
1:main│ │ │ ├─── Xms DEBUG concurrent_verbose polling countdown, label="a", count=3
11+
1:main│ │ ├───┐concurrent_verbose::countdown_b
1212
1:main│ │ │ ├─── Xms DEBUG concurrent_verbose polling countdown, label="b", count=5
1313
1:main│ │ │ ├─── Xms DEBUG concurrent_verbose polling countdown, label="b", count=4
14-
1:main│ │ ├─┐concurrent_verbose::countdowns
15-
1:main│ │ │ └─┐concurrent_verbose::countdown_a
14+
1:main│ │ ├───┐concurrent_verbose::countdown_a
1615
1:main│ │ │ ├─── Xms DEBUG concurrent_verbose polling countdown, label="a", count=2
17-
1:main│ ├─┐concurrent_verbose::server host="localhost", port=8080
18-
1:main│ │ └─┐concurrent_verbose::conn peer_addr="82.9.9.9", port=42381
16+
1:main│ ├───┐concurrent_verbose::conn peer_addr="82.9.9.9", port=42381
1917
1:main│ │ ├─── Xms WARN concurrent_verbose peer1 warning
20-
1:main│ ├─┐concurrent_verbose::server host="localhost", port=8080
21-
1:main│ │ └─┐concurrent_verbose::countdowns
18+
1:main│ ├───┐concurrent_verbose::countdowns
2219
1:main│ │ ├─── Xms INFO concurrent_verbose finished polling countdowns
2320
1:main│ │ │ ┌─┘concurrent_verbose::countdown_b
2421
1:main│ │ ├─┘concurrent_verbose::countdowns

‎examples/deferred.stdout

+10-13
Original file line numberDiff line numberDiff line change
@@ -1,35 +1,32 @@
11
-> This prints before the span open message
2-
1:main┐open(v): deferred::hierarchical-example version=0.1
3-
1:main├─┐open: deferred::server host="localhost", port=8080
2+
1:main┐open: deferred::hierarchical-example version=0.1
3+
1:main├┐pre_open: deferred::hierarchical-example version=0.1
4+
1:main│└┐open(v): deferred::server host="localhost", port=8080
45
1:main│ ├─ Xms INFO deferred starting
56
1:main│ ├─ Xs INFO deferred listening
67
-> Deferring two levels of spans
7-
1:main│ ├┐pre_open: deferred::server host="localhost", port=8080
8-
1:main│ │└┐open(v): deferred::connections
9-
1:main│ │ ├─┐open: deferred::conn peer_addr="82.9.9.9", port=42381
8+
1:main│ ├─┐open: deferred::connections
9+
1:main│ │ ├┐pre_open: deferred::connections
10+
1:main│ │ │└┐open(v): deferred::conn peer_addr="82.9.9.9", port=42381
1011
1:main│ │ │ ├─ Xms DEBUG deferred connected, peer="peer1"
1112
1:main│ │ │ ├─ Xms DEBUG deferred message received, length=2
1213
1:main│ │ │┌┘close(v): deferred::conn peer_addr="82.9.9.9", port=42381
1314
1:main│ │ ├┘post_close: deferred::connections
14-
1:main│ │ ├┐pre_open: deferred::connections
15-
1:main│ │ │└┐open(v): deferred::conn peer_addr="8.8.8.8", port=18230
15+
1:main│ │ ├─┐open: deferred::conn peer_addr="8.8.8.8", port=18230
1616
1:main│ │ │ ├─ Xms DEBUG deferred connected, peer="peer3"
1717
1:main│ │ │┌┘close(v): deferred::conn peer_addr="8.8.8.8", port=18230
1818
1:main│ │ ├┘post_close: deferred::connections
19-
1:main│ │ ├┐pre_open: deferred::connections
20-
1:main│ │ │└┐open(v): deferred::foomp 42 <- format string, normal_var=43
19+
1:main│ │ ├─┐open: deferred::foomp 42 <- format string, normal_var=43
2120
1:main│ │ │ ├─ Xms ERROR deferred hello
2221
1:main│ │ │┌┘close(v): deferred::foomp 42 <- format string, normal_var=43
2322
1:main│ │ ├┘post_close: deferred::connections
24-
1:main│ │ ├┐pre_open: deferred::connections
25-
1:main│ │ │└┐open(v): deferred::conn peer_addr="82.9.9.9", port=42381
23+
1:main│ │ ├─┐open: deferred::conn peer_addr="82.9.9.9", port=42381
2624
1:main│ │ │ ├─ Xms WARN deferred weak encryption requested, algo="xor"
2725
1:main│ │ │ ├─ Xms DEBUG deferred response sent, length=8
2826
1:main│ │ │ ├─ Xms DEBUG deferred disconnected
2927
1:main│ │ │┌┘close(v): deferred::conn peer_addr="82.9.9.9", port=42381
3028
1:main│ │ ├┘post_close: deferred::connections
31-
1:main│ │ ├┐pre_open: deferred::connections
32-
1:main│ │ │└┐open(v): deferred::conn peer_addr="8.8.8.8", port=18230
29+
1:main│ │ ├─┐open: deferred::conn peer_addr="8.8.8.8", port=18230
3330
1:main│ │ │ ├─ Xms DEBUG deferred message received, length=5
3431
1:main│ │ │ ├─ Xms DEBUG deferred response sent, length=8
3532
1:main│ │ │ ├─ Xms DEBUG deferred disconnected

‎src/lib.rs

+14-14
Original file line numberDiff line numberDiff line change
@@ -6,7 +6,7 @@ use format::{write_span_mode, Buffers, ColorLevel, Config, FmtEvent, SpanMode};
66

77
use nu_ansi_term::{Color, Style};
88
use std::{
9-
fmt::{self, Write as _},
9+
fmt::{self, Write},
1010
io::{self, IsTerminal},
1111
iter::Fuse,
1212
mem,
@@ -273,6 +273,7 @@ where
273273
new_span: &SpanRef<'a, S>,
274274
bufs: &mut Buffers,
275275
ctx: &'a Context<S>,
276+
pre_open: bool,
276277
) where
277278
S: Subscriber + for<'new_span> LookupSpan<'new_span>,
278279
{
@@ -306,13 +307,13 @@ where
306307
false
307308
};
308309

309-
// Print the previous span before entering a new deferred or retraced span
310-
if i == 0 && self.config.verbose_entry {
311-
if let Some(parent) = &span.parent() {
312-
self.write_span_info(parent, bufs, SpanMode::PreOpen);
310+
let verbose = i == 1 && pre_open && span.id() == new_span_id;
311+
// Print the parent of the new span if `pre_open==true`
312+
if verbose {
313+
if let Some(span) = span.parent() {
314+
self.write_span_info(&span, bufs, SpanMode::PreOpen);
313315
}
314316
}
315-
let verbose = self.config.verbose_entry && i == 0;
316317

317318
self.write_span_info(
318319
&span,
@@ -485,15 +486,14 @@ where
485486

486487
let bufs = &mut *self.bufs.lock().unwrap();
487488

488-
if self.config.verbose_entry {
489-
if let Some(span) = span.parent() {
490-
self.write_span_info(&span, bufs, SpanMode::PreOpen);
491-
}
492-
}
493-
494489
if self.config.span_retrace {
495-
self.write_retrace_span(&span, bufs, &ctx);
490+
self.write_retrace_span(&span, bufs, &ctx, self.config.verbose_entry);
496491
} else {
492+
if self.config.verbose_entry {
493+
if let Some(span) = span.parent() {
494+
self.write_span_info(&span, bufs, SpanMode::PreOpen);
495+
}
496+
}
497497
// Store the most recently entered span
498498
bufs.current_span = Some(span.id());
499499
self.write_span_info(
@@ -516,7 +516,7 @@ where
516516

517517
if let Some(new_span) = &span {
518518
if self.config.span_retrace || self.config.deferred_spans {
519-
self.write_retrace_span(new_span, bufs, &ctx);
519+
self.write_retrace_span(new_span, bufs, &ctx, self.config.verbose_entry);
520520
}
521521
}
522522

0 commit comments

Comments
 (0)