Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

tokio: Enable trace subscriber propagation in the runtime #966

Merged
merged 3 commits into from
Mar 13, 2019
Merged
Show file tree
Hide file tree
Changes from 1 commit
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
2 changes: 2 additions & 0 deletions Cargo.toml
Expand Up @@ -70,6 +70,7 @@ rt-full = [
"tokio-current-thread",
"tokio-executor",
"tokio-threadpool",
"tokio-trace-core",
]
sync = ["tokio-sync"]
tcp = ["tokio-tcp"]
Expand Down Expand Up @@ -105,6 +106,7 @@ tokio-threadpool = { version = "0.1.8", path = "tokio-threadpool", optional = tr
tokio-tcp = { version = "0.1.0", path = "tokio-tcp", optional = true }
tokio-udp = { version = "0.1.0", path = "tokio-udp", optional = true }
tokio-timer = { version = "0.2.8", path = "tokio-timer", optional = true }
tokio-trace-core = { version = "0.1", path = "tokio-trace/tokio-trace-core", optional = true }

# Needed until `reactor` is removed from `tokio`.
mio = { version = "0.6.14", optional = true }
Expand Down
1 change: 1 addition & 0 deletions src/lib.rs
Expand Up @@ -135,6 +135,7 @@ pub mod util;

if_runtime! {
extern crate tokio_executor;
extern crate tokio_trace_core;
pub mod executor;
pub mod runtime;

Expand Down
23 changes: 17 additions & 6 deletions src/runtime/threadpool/builder.rs
Expand Up @@ -11,6 +11,7 @@ use tokio_reactor;
use tokio_threadpool::Builder as ThreadPoolBuilder;
use tokio_timer::clock::{self, Clock};
use tokio_timer::timer::{self, Timer};
use tokio_trace_core::dispatcher::{self, Dispatch};

/// Builds Tokio Runtime with custom configuration values.
///
Expand Down Expand Up @@ -90,10 +91,10 @@ impl Builder {

/// Set builder to set up the thread pool instance.
#[deprecated(
since="0.1.9",
note="use the `core_threads`, `blocking_threads`, `name_prefix`, \
`keep_alive`, and `stack_size` functions on `runtime::Builder`, \
instead")]
since = "0.1.9",
note = "use the `core_threads`, `blocking_threads`, `name_prefix`, \
`keep_alive`, and `stack_size` functions on `runtime::Builder`, \
instead")]
#[doc(hidden)]
pub fn threadpool_builder(&mut self, val: ThreadPoolBuilder) -> &mut Self {
self.threadpool_builder = val;
Expand Down Expand Up @@ -330,14 +331,24 @@ impl Builder {
// Get a handle to the clock for the runtime.
let clock = self.clock.clone();

let pool = self.threadpool_builder
// Get the current trace dispatcher.
// TODO(eliza): when `tokio-trace-core` is stable enough to take a
// public API dependency, we should allow users to set a custom
// subscriber for the runtime.
let dispatch = dispatcher::get_default(Dispatch::clone);

let pool = self
.threadpool_builder
.around_worker(move |w, enter| {
let index = w.id().to_usize();
let dispatch = dispatch.clone();
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is this clone required? It seems like most of the other with_default things are fine with a reference.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@seanmonstar A Dispatch is internally just an Arc --- we could potentially make with_default take an &Dispatch and perform the clone itself. I thought it was better to take it by value since the dispatcher might not always need to be cloned when with_default is used in other cases`...

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

That’s a good point. with_dispatch should probably take a ref to follow the pattern.

The fn can clone internally.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I've opened #971 to make this change. As I had suspected, it has the downside of requiring the arc to be cloned twice when entering a span using the tokio-trace::Span type. If we decide this is acceptable, I can rebase onto that branch.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Setting the dispatcher every time a span is entered is unexpected to me. Can you expand on that decision?

Copy link
Member Author

@hawkw hawkw Mar 11, 2019

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@carllerche

Setting the dispatcher every time a span is entered is unexpected to me. Can you expand on that decision?

Setting the default dispatcher on span entry is a relic of when spans tracked their parent's ID. At that time, it was necessary to ensure that any spans created inside a span were observed by the same subscriber that originally provided the entered span with an ID, as otherwise, new spans would be created with parent IDs that did not originate from that subscriber.

Now that spans don't track their parent ID, this is no longer necessary. However, removing this behavior does mean that if a span is entered outside of the subscriber context it was created in, any subsequent spans will be observed by the current default subscriber and thus will not be part of the original span's trace tree. Since subscribers are not expected to change frequently, and spans are not expected to move between them, this is likely acceptable.

I've removed this on my branch for #971 in commit 345567d.

Not setting the dispatcher on entry does make span entry/exit significantly faster. Here are the results of running a benchmark that enters a span, does nothing, and immediately exits it, before this change:

test enter_span              ... bench:          93 ns/iter (+/- 14)

...and after:

test enter_span              ... bench:          51 ns/iter (+/- 9)


tokio_reactor::with_default(&reactor_handles[index], enter, |enter| {
clock::with_default(&clock, enter, |enter| {
timer::with_default(&timer_handles[index], enter, |_| {
w.run();
dispatcher::with_default(dispatch, || {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Just noting, out of context, "dispatcher" sounds like a task dispatcher, not something about traces...

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@seanmonstar in f409c12, I changed the way the Dispatch type and the dispatcher module are imported so that they're all namespaced as trace::dispatcher --- hopefully that's clearer!

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I do agree w/ sean... trace::dispatcher helps some. IMO it would be better if it was trace::subscriber, but I also know why it isn't subscriber (Dispatcher::new(subscriber)).

I'm not going to make a request either way. I just wanted to provide these thoughts to @seanmonstar and @hawkw

w.run();
})
});
})
});
Expand Down