Skip to content

Commit ad442e2

Browse files
committed
fix(subscriber): ignore exiting spans that were never entered
Similarly, if we don't record entering a span due to event buffer capacity, it doesn't make sense to record exiting it. This commit changes the `ConsoleLayer` to only push a span to the current thread's span stack if we were able to successfully send an `Enter` event to the aggregator. This means that it won't be considered the parent span for other events/spans. When a span is exited, we only send an `Exit` event to the aggregator if the span *was* previously recorded as being entered. In theory, ignoring subsequent events on spans that were dropped due to buffer capacity technically means we are losing *more* data than we would have if we did not ignore those spans. But, the data we are losing here is *wrong*. For example, we cannot calculate a correct poll time for a poll where we didn't record the beginning of the poll, and we only recorded the poll ending. Therefore, I think it's better to ignore this data than to make a half-assed attempt to record it even though we know it's incorrect. I believe this will probably also fix issue #180. That issue occurs when we attempt to decrement the number of times a task has been polled, and sometimes --- if an `enter` event for that task was missed --- we may subtract more than we've added to the counter. By ignoring exits for spans that we never recorded as entered, this panic should now be avoided.
1 parent 0cd7a2f commit ad442e2

File tree

2 files changed

+19
-7
lines changed

2 files changed

+19
-7
lines changed

console-subscriber/src/lib.rs

Lines changed: 16 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -721,20 +721,24 @@ where
721721
return;
722722
}
723723
let _default = dispatcher::set_default(&self.no_dispatch);
724-
self.current_spans
725-
.get_or_default()
726-
.borrow_mut()
727-
.push(id.clone());
728-
729724
let parent_id = cx.span(id).and_then(|s| s.parent().map(|p| p.id()));
730-
self.send(
725+
let sent = self.send(
731726
&self.shared.dropped_tasks,
732727
Event::Enter {
733728
at: SystemTime::now(),
734729
id: id.clone(),
735730
parent_id,
736731
},
737732
);
733+
734+
// if we were able to record the send successfully, track entering the
735+
// span. if not, ignore the enter, to avoid inconsistent data.
736+
if sent {
737+
self.current_spans
738+
.get_or_default()
739+
.borrow_mut()
740+
.push(id.clone());
741+
}
738742
}
739743

740744
fn on_exit(&self, id: &span::Id, cx: Context<'_, S>) {
@@ -744,7 +748,12 @@ where
744748

745749
let _default = dispatcher::set_default(&self.no_dispatch);
746750
if let Some(spans) = self.current_spans.get() {
747-
spans.borrow_mut().pop(id);
751+
if !spans.borrow_mut().pop(id) {
752+
// we did not actually pop the span --- entering it may not have
753+
// been successfully recorded. in this case, ignore the exit,
754+
// since the aggregator was never informed of the entry.
755+
return;
756+
}
748757
}
749758

750759
let parent_id = cx.span(id).and_then(|s| s.parent().map(|p| p.id()));

console-subscriber/src/stack.rs

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -34,6 +34,9 @@ impl SpanStack {
3434
!duplicate
3535
}
3636

37+
/// Pop a currently entered span.
38+
///
39+
/// Returns `true` if the span was actually exited.
3740
#[inline]
3841
pub(crate) fn pop(&mut self, expected_id: &Id) -> bool {
3942
if let Some((idx, _)) = self

0 commit comments

Comments
 (0)