Skip to content

Commit f523ad5

Browse files
committed
chore: bless and minor cleanup
1 parent 2326701 commit f523ad5

File tree

9 files changed

+314
-94
lines changed

9 files changed

+314
-94
lines changed

examples/basic_non_verbose.stdout

Lines changed: 29 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,29 @@
1+
1:main┐basic_non_verbose::hierarchical-example version=0.1
2+
1:main├─┐basic_non_verbose::server host="localhost", port=8080
3+
1:main│ ├─ Xms INFO basic_non_verbose starting
4+
1:main│ ├─ Xs INFO basic_non_verbose listening
5+
1:main│ ├─┐basic_non_verbose::conn peer_addr="82.9.9.9", port=42381
6+
1:main│ │ ├─ Xms DEBUG basic_non_verbose connected
7+
1:main│ │ ├─ Xms DEBUG basic_non_verbose message received, length=2
8+
1:main│ ├─┘
9+
1:main│ ├─┐basic_non_verbose::conn peer_addr="8.8.8.8", port=18230
10+
1:main│ │ ├─ Xms DEBUG basic_non_verbose connected
11+
1:main│ ├─┘
12+
1:main│ ├─┐basic_non_verbose::foomp 42 <- format string, normal_var=43
13+
1:main│ │ ├─ Xms ERROR basic_non_verbose hello
14+
1:main│ ├─┘
15+
1:main│ ├─┐basic_non_verbose::conn peer_addr="82.9.9.9", port=42381
16+
1:main│ │ ├─ Xms WARN basic_non_verbose weak encryption requested, algo="xor"
17+
1:main│ │ ├─ Xms DEBUG basic_non_verbose response sent, length=8
18+
1:main│ │ ├─ Xms DEBUG basic_non_verbose disconnected
19+
1:main│ ├─┘
20+
1:main│ ├─┐basic_non_verbose::conn peer_addr="8.8.8.8", port=18230
21+
1:main│ │ ├─ Xms DEBUG basic_non_verbose message received, length=5
22+
1:main│ │ ├─ Xms DEBUG basic_non_verbose response sent, length=8
23+
1:main│ │ ├─ Xms DEBUG basic_non_verbose disconnected
24+
1:main│ ├─┘
25+
1:main│ ├─ Xs WARN basic_non_verbose internal error
26+
1:main│ ├─ Xs ERROR basic_non_verbose this is a log message
27+
1:main│ ├─ Xs INFO basic_non_verbose exit
28+
1:main├─┘
29+
1:main┘

examples/concurrent.rs

Lines changed: 9 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -73,9 +73,17 @@ fn main() {
7373
std::thread::sleep(std::time::Duration::from_millis(300));
7474

7575
let _ = countdown_b.poll_unpin(&mut cx);
76+
77+
peer1.in_scope(|| {
78+
warn!("peer1 warning");
79+
});
80+
81+
tracing::info!("finished polling countdowns");
7682
});
7783

78-
tracing::info!("finished countdowns");
84+
drop(peer1);
85+
86+
tracing::info!("all done!");
7987

8088
info!("exit")
8189
}

examples/concurrent.stdout

Lines changed: 32 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,32 @@
1+
1:main┐open(v): concurrent::hierarchical-example version=0.1
2+
1:main│└┐open(v): concurrent::server host="localhost", port=8080
3+
1:main│ ├─ Xms INFO concurrent starting
4+
1:main│ ├─ Xs INFO concurrent listening
5+
1:main│ ├┐pre_open: concurrent::server host="localhost", port=8080
6+
1:main│ │└┐open(v): concurrent::empty-span
7+
1:main│ │┌┘close(v): concurrent::empty-span
8+
1:main│ ├┘post_close: concurrent::server host="localhost", port=8080
9+
1:main│ ├─ Xs DEBUG concurrent starting countdowns
10+
1:main│ ├┐pre_open: concurrent::server host="localhost", port=8080
11+
1:main│ │└┐open(v): concurrent::countdowns
12+
1:main│ │ │└┐open(v): concurrent::countdown_a
13+
1:main│ │ │ ├─ Xms DEBUG concurrent polling countdown, label="a", count=3
14+
1:main│ │ │ ├┐pre_open: concurrent::countdown_a
15+
1:main│ │ │└┐open(v): concurrent::countdown_b
16+
1:main│ │ │ ├─ Xms DEBUG concurrent polling countdown, label="b", count=5
17+
1:main│ │ │ ├─ Xms DEBUG concurrent polling countdown, label="b", count=4
18+
1:main│ │ │┌┘close(v): concurrent::countdown_b
19+
1:main│ │ ├┘post_close: concurrent::countdowns
20+
1:main│ │ │┌┘close(v): concurrent::countdown_a
21+
1:main│ │ ├┘post_close: concurrent::countdowns
22+
1:main│ │┌┘close(v): concurrent::countdowns
23+
1:main│ ├┘post_close: concurrent::server host="localhost", port=8080
24+
1:main│ ├─ Xs INFO concurrent finished countdowns
25+
1:main│ ├─ Xs INFO concurrent exit
26+
1:main│ ├┐pre_open: concurrent::server host="localhost", port=8080
27+
1:main│ │└┐open(v): concurrent::conn peer_addr="82.9.9.9", port=42381
28+
1:main│ │┌┘close(v): concurrent::conn peer_addr="82.9.9.9", port=42381
29+
1:main│ ├┘post_close: concurrent::server host="localhost", port=8080
30+
1:main│┌┘close(v): concurrent::server host="localhost", port=8080
31+
1:main├┘post_close: concurrent::hierarchical-example version=0.1
32+
1:main┘close(v): concurrent::hierarchical-example version=0.1

examples/deferred.rs

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,6 @@
1-
use tracing::{debug, error, info, instrument, span, trace, warn, Level};
2-
use tracing_core::LevelFilter;
1+
use tracing::{
2+
debug, error, info, instrument, level_filters::LevelFilter, span, trace, warn, Level,
3+
};
34
use tracing_subscriber::{layer::SubscriberExt, registry::Registry, Layer};
45
use tracing_tree::HierarchicalLayer;
56

examples/deferred.stdout

Lines changed: 45 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,45 @@
1+
This prints before the span open message
2+
1:main┐open(v): deferred::hierarchical-example version=0.1
3+
1:main│└┐open(v): deferred::server host="localhost", port=8080
4+
1:main│ ├─ Xms INFO deferred starting
5+
1:main│ ├─ Xs INFO deferred listening
6+
1:main│ ├┐pre_open: deferred::server host="localhost", port=8080
7+
1:main│ │└┐open(v): deferred::conn peer_addr="82.9.9.9", port=42381
8+
1:main│ │ ├─ Xms DEBUG deferred connected, peer="peer1"
9+
1:main│ │ ├─ Xms DEBUG deferred message received, length=2
10+
1:main│ │┌┘close(v): deferred::conn peer_addr="82.9.9.9", port=42381
11+
1:main│ ├┘post_close: deferred::server host="localhost", port=8080
12+
1:main│ ├┐pre_open: deferred::server host="localhost", port=8080
13+
1:main│ │└┐open(v): deferred::conn peer_addr="82.9.9.9", port=61548
14+
1:main│ │┌┘close(v): deferred::conn peer_addr="82.9.9.9", port=61548
15+
1:main│ ├┘post_close: deferred::server host="localhost", port=8080
16+
1:main│ ├┐pre_open: deferred::server host="localhost", port=8080
17+
1:main│ │└┐open(v): deferred::conn peer_addr="8.8.8.8", port=18230
18+
1:main│ │ ├─ Xms DEBUG deferred connected, peer="peer3"
19+
1:main│ │┌┘close(v): deferred::conn peer_addr="8.8.8.8", port=18230
20+
1:main│ ├┘post_close: deferred::server host="localhost", port=8080
21+
1:main│ ├┐pre_open: deferred::server host="localhost", port=8080
22+
1:main│ │└┐open(v): deferred::foomp 42 <- format string, normal_var=43
23+
1:main│ │ ├─ Xms ERROR deferred hello
24+
1:main│ │┌┘close(v): deferred::foomp 42 <- format string, normal_var=43
25+
1:main│ ├┘post_close: deferred::server host="localhost", port=8080
26+
1:main│ ├┐pre_open: deferred::server host="localhost", port=8080
27+
1:main│ │└┐open(v): deferred::conn peer_addr="82.9.9.9", port=42381
28+
1:main│ │ ├─ Xms WARN deferred weak encryption requested, algo="xor"
29+
1:main│ │ ├─ Xms DEBUG deferred response sent, length=8
30+
1:main│ │ ├─ Xms DEBUG deferred disconnected
31+
1:main│ │┌┘close(v): deferred::conn peer_addr="82.9.9.9", port=42381
32+
1:main│ ├┘post_close: deferred::server host="localhost", port=8080
33+
1:main│ ├┐pre_open: deferred::server host="localhost", port=8080
34+
1:main│ │└┐open(v): deferred::conn peer_addr="8.8.8.8", port=18230
35+
1:main│ │ ├─ Xms DEBUG deferred message received, length=5
36+
1:main│ │ ├─ Xms DEBUG deferred response sent, length=8
37+
1:main│ │ ├─ Xms DEBUG deferred disconnected
38+
1:main│ │┌┘close(v): deferred::conn peer_addr="8.8.8.8", port=18230
39+
1:main│ ├┘post_close: deferred::server host="localhost", port=8080
40+
1:main│ ├─ Xs WARN deferred internal error
41+
1:main│ ├─ Xs ERROR deferred this is a log message
42+
1:main│ ├─ Xs INFO deferred exit
43+
1:main│┌┘close(v): deferred::server host="localhost", port=8080
44+
1:main├┘post_close: deferred::hierarchical-example version=0.1
45+
1:main┘close(v): deferred::hierarchical-example version=0.1

src/format.rs

Lines changed: 3 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -341,12 +341,7 @@ fn indent_block_with_lines(
341341
SpanMode::Open { .. } => buf.push_str(LINE_OPEN),
342342
SpanMode::Retrace { .. } => buf.push_str(LINE_OPEN),
343343
SpanMode::Close { .. } => buf.push_str(LINE_CLOSE),
344-
SpanMode::PreOpen | SpanMode::PostClose => {
345-
unreachable!(
346-
"indent_amount: {} {}, style: {:?}",
347-
indent_amount, indent, style
348-
)
349-
}
344+
SpanMode::PreOpen | SpanMode::PostClose => {}
350345
SpanMode::Event => {}
351346
}
352347
}
@@ -482,7 +477,8 @@ fn indent_block(
482477
let indent_spaces = indent * indent_amount;
483478
buf.reserve(block.len() + (lines.len() * indent_spaces));
484479

485-
// The PreOpen and PostClose events are generated for the indent of the child span
480+
// The PreOpen and PostClose need to match up with the indent of the entered child span one more indent
481+
// deep
486482
if matches!(style, SpanMode::PreOpen | SpanMode::PostClose) {
487483
indent += 1;
488484
}

src/lib.rs

Lines changed: 54 additions & 78 deletions
Original file line numberDiff line numberDiff line change
@@ -7,16 +7,11 @@ use format::{write_span_mode, Buffers, ColorLevel, Config, FmtEvent, SpanMode};
77
use is_terminal::IsTerminal;
88
use nu_ansi_term::{Color, Style};
99
use std::{
10-
any::Any,
1110
fmt::{self, Write as _},
12-
hint::spin_loop,
1311
io,
1412
iter::Fuse,
1513
mem,
16-
sync::{
17-
atomic::{AtomicU64, Ordering},
18-
Mutex,
19-
},
14+
sync::Mutex,
2015
time::Instant,
2116
};
2217
use tracing_core::{
@@ -29,7 +24,7 @@ use tracing_log::NormalizeEvent;
2924
use tracing_subscriber::{
3025
fmt::MakeWriter,
3126
layer::{Context, Layer},
32-
registry::{self, LookupSpan, ScopeFromRoot, SpanRef},
27+
registry::{LookupSpan, ScopeFromRoot, SpanRef},
3328
};
3429

3530
// Span extension data
@@ -40,11 +35,11 @@ pub(crate) struct Data {
4035
}
4136

4237
impl Data {
43-
pub fn new(attrs: &Attributes<'_>, printed: bool) -> Self {
38+
pub fn new(attrs: &Attributes<'_>, written: bool) -> Self {
4439
let mut span = Self {
4540
start: Instant::now(),
4641
kvs: Vec::new(),
47-
written: printed,
42+
written,
4843
};
4944
attrs.record(&mut span);
5045
span
@@ -274,82 +269,65 @@ where
274269
) where
275270
S: Subscriber + for<'new_span> LookupSpan<'new_span>,
276271
{
277-
{
278-
// let was_written = if let Some(data) = new_span.extensions_mut().get_mut::<Data>() {
279-
// let written = data.written;
280-
// data.written = true;
281-
// written
282-
// } else {
283-
// eprintln!("Span not written");
284-
// false
285-
// };
286-
287-
let should_write = if self.config.deferred_spans {
288-
if let Some(data) = new_span.extensions_mut().get_mut::<Data>() {
289-
!data.written
290-
} else {
291-
false
292-
}
272+
let should_write = if self.config.deferred_spans {
273+
if let Some(data) = new_span.extensions_mut().get_mut::<Data>() {
274+
!data.written
275+
} else {
276+
false
277+
}
278+
} else {
279+
false
280+
};
281+
282+
if self.config.span_retrace || should_write {
283+
let was_written = if let Some(data) = new_span.extensions_mut().get_mut::<Data>() {
284+
mem::replace(&mut data.written, true)
293285
} else {
286+
// `on_new_span` was not called, before
287+
// Consider if this should panic instead, which is *technically* correct but is
288+
// bad behavior for a logging layer in production.
294289
false
295290
};
296291

297-
if self.config.span_retrace || should_write {
298-
let was_written = if let Some(data) = new_span.extensions_mut().get_mut::<Data>() {
299-
mem::replace(&mut data.written, true)
300-
} else {
301-
// `on_new_span` was not called, before
302-
// Consider if this should panic instead, which is *technically* correct but is
303-
// bad behavior for a logging layer in production.
304-
false
305-
};
306-
307-
let old_span_id = bufs.current_span.replace((new_span.id()).clone());
308-
let old_span_id = old_span_id.as_ref();
309-
310-
if Some(&new_span.id()) != old_span_id {
311-
let old_span = old_span_id.as_ref().and_then(|v| ctx.span(v));
312-
313-
// Print the previous span before entering a new deferred or retraced span
314-
if self.config.verbose_entry {
315-
if let Some(old_span) = &old_span {
316-
self.write_span_info(old_span, bufs, ctx, SpanMode::PreOpen);
317-
}
318-
}
292+
let old_span_id = bufs.current_span.replace((new_span.id()).clone());
293+
let old_span_id = old_span_id.as_ref();
294+
295+
if Some(&new_span.id()) != old_span_id {
296+
let old_span = old_span_id.as_ref().and_then(|v| ctx.span(v));
319297

320-
let old_path = old_span.as_ref().map(scope_path).into_iter().flatten();
321-
322-
let new_path = scope_path(new_span);
323-
324-
// Print the path from the common base of the two spans
325-
let new_path = DifferenceIter::new(old_path, new_path, |v| v.id());
326-
327-
for span in new_path {
328-
self.write_span_info(
329-
&span,
330-
bufs,
331-
ctx,
332-
if was_written {
333-
SpanMode::Retrace
334-
} else {
335-
SpanMode::Open {
336-
verbose: self.config.verbose_entry,
337-
}
338-
},
339-
)
298+
// Print the previous span before entering a new deferred or retraced span
299+
if self.config.verbose_entry {
300+
if let Some(old_span) = &old_span {
301+
self.write_span_info(old_span, bufs, SpanMode::PreOpen);
340302
}
341303
}
304+
305+
let old_path = old_span.as_ref().map(scope_path).into_iter().flatten();
306+
307+
let new_path = scope_path(new_span);
308+
309+
// Print the path from the common base of the two spans
310+
let new_path = DifferenceIter::new(old_path, new_path, |v| v.id());
311+
312+
for span in new_path {
313+
self.write_span_info(
314+
&span,
315+
bufs,
316+
if was_written {
317+
SpanMode::Retrace
318+
} else {
319+
SpanMode::Open {
320+
verbose: self.config.verbose_entry,
321+
}
322+
},
323+
)
324+
}
342325
}
343326
}
344327
}
345328

346-
fn write_span_info<S>(
347-
&self,
348-
span: &SpanRef<S>,
349-
bufs: &mut Buffers,
350-
ctx: &Context<S>,
351-
style: SpanMode,
352-
) where
329+
fn write_span_info<S>(&self, span: &SpanRef<S>, bufs: &mut Buffers, style: SpanMode)
330+
where
353331
S: Subscriber + for<'span> LookupSpan<'span>,
354332
{
355333
let ext = span.extensions();
@@ -446,14 +424,13 @@ where
446424

447425
if self.config.verbose_entry {
448426
if let Some(span) = span.parent() {
449-
self.write_span_info(&span, bufs, &ctx, SpanMode::PreOpen);
427+
self.write_span_info(&span, bufs, SpanMode::PreOpen);
450428
}
451429
}
452430

453431
self.write_span_info(
454432
&span,
455433
bufs,
456-
&ctx,
457434
SpanMode::Open {
458435
verbose: self.config.verbose_entry,
459436
},
@@ -586,7 +563,6 @@ where
586563
self.write_span_info(
587564
&span,
588565
bufs,
589-
&ctx,
590566
SpanMode::Close {
591567
verbose: self.config.verbose_exit,
592568
},
@@ -597,7 +573,7 @@ where
597573
// Consider parent as entered
598574
bufs.current_span = Some(parent_span.id());
599575

600-
self.write_span_info(&parent_span, bufs, &ctx, SpanMode::PostClose);
576+
self.write_span_info(&parent_span, bufs, SpanMode::PostClose);
601577
}
602578
}
603579
}

0 commit comments

Comments
 (0)