Implement demo subscriber #1
Conversation
|
cc @hawkw |
|
Not sure how to request a proper review (your handle doesn't show up), but i've marked you as collaborator, in case that helps :) |
| } | ||
|
|
||
| fn record(&self, span: &span::Id, _values: &span::Record) { | ||
| // Not entirely sure when this is called |
There was a problem hiding this comment.
I'm not really sure when this is called, since everything seems to be recorded via events. Is events supposed to passthrough to record?
There was a problem hiding this comment.
record is called when a span wishes to record fields other than those which were recorded in new_span.
For example:
// "foo = 3" will be recorded if you call `record` on the `Attributes` passed to `new_span`.
// Since values are not provided for the `bar` and `baz` fields, the span's `Metadata` will
// indicate that it _has_ those fields, but values for them won't be recorded at this time.
let mut span = span!("my_span", foo = 3, bar, baz);
// `Subscriber::record` will be called with a `Record` containing "bar = false"
span.record("bar", &false);
// `Subscriber::record` will be called with a `Record` containing "baz = "a string""
span.record("baz", &"a string");If the purpose of Subscriber::record wasn't clear from the docs, they probably ought to be improved --- I would love an issue against tokio-rs/tokio about that...
| } | ||
|
|
||
| fn record(&self, span: &span::Id, _values: &span::Record) { | ||
| // Not entirely sure when this is called |
There was a problem hiding this comment.
record is called when a span wishes to record fields other than those which were recorded in new_span.
For example:
// "foo = 3" will be recorded if you call `record` on the `Attributes` passed to `new_span`.
// Since values are not provided for the `bar` and `baz` fields, the span's `Metadata` will
// indicate that it _has_ those fields, but values for them won't be recorded at this time.
let mut span = span!("my_span", foo = 3, bar, baz);
// `Subscriber::record` will be called with a `Record` containing "bar = false"
span.record("bar", &false);
// `Subscriber::record` will be called with a `Record` containing "baz = "a string""
span.record("baz", &"a string");If the purpose of Subscriber::record wasn't clear from the docs, they probably ought to be improved --- I would love an issue against tokio-rs/tokio about that...
| let mut spans = self.spans.lock().unwrap(); | ||
| let id = spans.len() + 1; | ||
| spans.push(Span { | ||
| label: attributes.metadata().name().to_string(), |
There was a problem hiding this comment.
Note that in addition to metadata, a span's Attributes will also contain any fields that were provided when the span was created. You can record these fields here by passing a visitor to the Attributes::record function.
| } | ||
|
|
||
| pub struct DemoSubscriber { | ||
| spans: Mutex<Vec<Span>>, |
There was a problem hiding this comment.
You may not be particularly concerned about performance since this is just a demo, but it's worth noting that both the spans and the current span context will likely be read from more often than they're written to (i.e. you read from them in Subscriber::event but only write to them in Subscriber::{new_span, enter, exit}). So you will likely get better performance using a read-write lock rather than a mutex.
There was a problem hiding this comment.
Also, for the tokio-console project in particular, it shouldn't actually be necessary to store data in-process for each span. Instead, we can just send messages to the external aggregator with span IDs, and use those IDs to hydrate any dynamic data associated with that span.
This won't really work for a demo subscriber that's just printing to stdout (if you want to print dynamic data every time something happens in a span), but it's worth mentioning now.
There was a problem hiding this comment.
Yes, a read-write lock would make more sense. But when performance is a concern, we should look into parking_lot at first and not std. Whilste their primitives are being integrated into std, most rust versions >1.26.0 will still lack in performance.
Regarding out-of-process data for spans, i haven't thought about that yet, that would make a pretty lightweight subscriber!
There was a problem hiding this comment.
Yes, a read-write lock would make more sense. But when performance is a concern, we should look into
parking_lotat first and not std. Whilste their primitives are being integrated into std, most rust versions>1.26.0will still lack in performance.
Yeah, that's correct --- I used parking_lot's rwlocks in tokio-trace-fmt's span store and saw a pretty significant performance improvement. As a side note, if you're interested in how a high-performance span store might look, you may want to take a look at fmt's implementation --- I tried to make sure it was reasonably well-commented.
But, for a demo, it's definitely not important to implement something like this, and since the span data used by tokio-trace-console will be stored out of process, it may not be something we ever end up worrying about!
|
|
||
| pub struct DemoSubscriber { | ||
| spans: Mutex<Vec<Span>>, | ||
| stack: Mutex<Vec<u64>>, |
There was a problem hiding this comment.
Note that this is storing one global stack of spans for the entire process. In tokio-trace, individual threads may be in separate spans, so if you want your subscriber to behave properly in a multithreaded context, you'll probably want this to be a thread-local rather than global.
There was a problem hiding this comment.
Oh that makes sense! Also no synchronization would be required for stack access.
-
For reference, a span id might move between threads (e.g. a future storing its span being moved to another thread/executor), but at that point it shouldn't be on the stack anymore? Since the span would be a member of the future, moving it to another thread while its span is on the stack should be blocked by the borrow checker.
-
But what about a thread pool? The tasks would loose the span stack of their outer caller and live within the span stack of the thread pool. I think that would be a good use case where you might want to set the parent of the task spans? Otherwise it would probably be hard to reason about why and where the work happend.
-
Actually while i'm thinking about it, this has affects the architecture heavily. The (out-of-process) console might have interest in the span stack for visualization purposes (tree style view, timelines), but also needs to know which threads are running and on which thread an event/record was issued. So the subscriber would need to assign and manage internal ids for ThreadIds.
There was a problem hiding this comment.
These are great questions --- you definitely have the right intuitions here.
1. For reference, a span id might move between threads (e.g. a future storing its span being moved to another thread/executor), but at that point it shouldn't be on the stack anymore? Since the span would be a member of the future, moving it to another thread while its span is on the stack should be blocked by the borrow checker.
Not necessarily --- there isn't a rule stating that only a single thread can be executing in a span at a time. We might enter a span and then spawn a future on the threadpool which is also in that span, for example:
let mut span = span!("foo");
let mut span2 = span.clone();
span.enter(move || {
tokio::spawn(future.instrument(span2));
// do other stuff inside the span...
})I think that we should only consider a span to no longer be on the stack for a given thread when it informs us that it's been exited.
2. But what about a thread pool? The tasks would loose the span stack of their outer caller and live within the span stack of the thread pool. I think that would be a good use case where you might want to set the parent of the task spans? Otherwise it would probably be hard to reason about why and where the work happend.
You're entirely correct --- this is why it's necessary to track a concept of spans having parents as well as having a span stack. In my experience, the main use of the stack is just for knowing what span we'll be in when the current span is exited, not for displaying a hierarchy of spans, we'd want to use parents for this.
3. Actually while i'm thinking about it, this has affects the architecture heavily. The (out-of-process) console might have interest in the span stack for visualization purposes (tree style view, timelines), but also needs to know which threads are running and on which thread an event/record was issued. So the subscriber would need to assign and manage internal ids for [ThreadId](https://doc.rust-lang.org/std/thread/struct.ThreadId.html)s.
When we've added tokio-trace instrumentation to the other tokio crates (soon!), each tokio-threadpool worker thread will do all its work inside of a span annotated with that worker's ID. So some of that work will be done for us...
| fn drop_span(&self, id: span::Id) { | ||
| let mut spans = self.spans.lock().unwrap(); | ||
| // This cannot underflow because it's guaranteed to be called correctly | ||
| spans[id.into_u64() as usize - 1].ref_count -= 1; |
There was a problem hiding this comment.
Note that when a span's ref count is zero, the subscriber is free to drop any data stored for that span.
There was a problem hiding this comment.
True, but here the IDs correspond to vector indices. This makes dropping data difficult, since one can could only free spans at the end of the vector. Reusing indices would help a lot with memory usage.
There was a problem hiding this comment.
Reusing indices would help a lot with memory usage.
Yup, this is (again) what tokio-trace-fmt does --- you're definitely on the right track! :D
Again this may not matter for a demo, but I wanted to mention it regardless since it's an important part of the API.
Also, we may care about doing other behaviours when a span's refcount hits zero --- for example, if we're collecting time profiles of how long we spent in a span, the refcount reaching zero is a good time to consider a span as "over" for the purpose of that profile. In tokio-trace-console, this is where we would probably want to send a message to the console client that the span has been closed (even if we don't have any internal state to clean up).
|
@hawkw Thank you very much for your thorough review and your time for my questions! :) |
No description provided.