Skip to content
This repository was archived by the owner on Aug 30, 2022. It is now read-only.

Commit ffdd052

Browse files
tudorisaachier
authored andcommitted
Fix deadlock if steady_clock::now() returns the same value twice (#132)
* Fix deadlock if steady_clock::now() returns the same value twice `Span::isFinished()` returns true iff the span's duration is zero. So, if `steady_clock::now()` returns the same value at span creation as at `Finish()` (unlikely, but possible, especially in virtualized environments), the following scenario can happen: - `Span::FinishWithOptions` sets `_duration` to zero - and then calls `reportSpan`, which calls `RemoteReporter::report` - which acquires the reporter mutex and - adds the span to the reporter's `_queue` Later: - `RemoteReporter::sweepQueue` acquires the reporter mutex - `RemoteReporter::sweepQueue` makes a copy of the span (https://github.com/jaegertracing/jaeger-client-cpp/blob/7e9a135b362c47f7e4d42e0693b05b91a70e6888/src/jaegertracing/reporters/RemoteReporter.cpp#L95) - The span is serialized in `RemoteReporter::sendSpan` - The span (the copy made above) needs to be destroyed because the block in `sweepQueue` ends. - The span's destructor is called, which calls `FinishWithOptions` again - ... which sees that `_duration` is zero, so `isFinished()` returns false: https://github.com/jaegertracing/jaeger-client-cpp/blob/7e9a135b362c47f7e4d42e0693b05b91a70e6888/src/jaegertracing/Span.cpp#L94 - so it tries to call `reportSpan` again - which tries to acquire the reporter's mutex - but we're holding the lock in `sweepQueue`, so - deadlock. Relevant stack trace: ``` (gdb) bt (gdb) bt #0 __lll_lock_wait () at ../sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135 #1 0x00007fb09c722023 in __GI___pthread_mutex_lock (mutex=0x7fb088b1c1c0) at ../nptl/pthread_mutex_lock.c:78 #2 0x00007fb08860987b in jaegertracing::reporters::RemoteReporter::report(jaegertracing::Span const&) () from /usr/local/lib/libjaegertracing_plugin.so #3 0x00007fb0885b6506 in jaegertracing::Span::FinishWithOptions(opentracing::v2::FinishSpanOptions const&) [clone .localalias.361] () from /usr/local/lib/libjaegertracing_plugin.so #4 0x00007fb08860849a in jaegertracing::Span::~Span() [clone .constprop.253] () from /usr/local/lib/libjaegertracing_plugin.so #5 0x00007fb08860a8fa in jaegertracing::reporters::RemoteReporter::sweepQueue() () from /usr/local/lib/libjaegertracing_plugin.so #6 0x00007fb0886f2f5f in execute_native_thread_routine () from /usr/local/lib/libjaegertracing_plugin.so #7 0x00007fb09c71f6db in start_thread (arg=0x7fb087574700) at pthread_create.c:463 #8 0x00007fb0989ae88f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95 ``` Fixed by enforcing a minimum span duration of 1 `SteadyClock` tick. Signed-off-by: Tudor Bosman <[email protected]> * fix typo Signed-off-by: Tudor Bosman <[email protected]>
1 parent ccd9019 commit ffdd052

File tree

1 file changed

+6
-0
lines changed

1 file changed

+6
-0
lines changed

src/jaegertracing/Span.cpp

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -96,6 +96,12 @@ void Span::FinishWithOptions(
9696
return;
9797
}
9898
_duration = finishTimeSteady - _startTimeSteady;
99+
if (_duration <= SteadyClock::duration()) {
100+
// Enforce minimum duration of 1 tick (1ns on Linux),
101+
// so isFinished() returns true
102+
_duration = SteadyClock::duration(1);
103+
}
104+
99105
tracer = _tracer;
100106

101107
std::copy(finishSpanOptions.log_records.begin(),

0 commit comments

Comments
 (0)