Add span IDs that uniquely identify spans

This branch introduces a `span::Id` type and changes span equality to be
based on the span's `Id`. The `Id` type is used to identify the span
within the context of the process.

These span IDs are intended to be used as a source of truth for
determining whether two span handles are equal. Previously, this
was done based on the span's creation timestamp and metadata, but the
creation timestamps are slated for removal (see #24). When they are
removed, the metadata alone will not be sufficient to uniquely identify
the span, since that would mean two distinct spans created at the same
call site would be "equal".

Similarly, we cannot base span equality on their field values, for a
number of reasons:
+ Two spans with the same metadata and no fields would be equal,
  even if they are distinct periods of time.
+ Similarly, two spans which happen to have the same field values, but
  represent distinct periods of time would also be incorrectly equal.
+ Using field values for equality and hashing would require that
 `Value`s implement `Hash` and `PartialEq`, which they cannot do when
  they are represented by trait objects (as these traits are not object
  safe).
+ Also, comparing the field values would require iterating across all
  the fields.

Currently, the `Id` type is represented by a `u64`. However, the `Id`
type is opaque to downstream users, beyond the contract of implementing
`Clone`, `Hash`, and `PartialEq`, and being able to be _constructed_
from a `u64`, so we could swap out this implementation with something
else later fairly transparently, as long as we can construct it from a
`u64`.

`Subscriber`s are responsible for generating the IDs for each span
(through the `Subscriber::new_span_id` trait method), allowing them to
choose the span ID generation strategy that supports their use case.

Required for #24

tokio-trace-log/src/lib.rs

@@ -23,7 +23,7 @@ extern crate tokio_trace;
 extern crate log;
 
 use std::{io, time::Instant};
-use tokio_trace::{Subscriber, Event, SpanData, Meta};
+use tokio_trace::{span, Subscriber, Event, SpanData, Meta};
 
 /// Format a log record as a trace event in the current span.
 pub fn format_trace(record: &log::Record) -> io::Result<()> {
@@ -155,6 +155,10 @@ impl Subscriber for LogSubscriber {
         log::logger().enabled(&metadata.as_log())
     }
 
+    fn new_span_id(&self, metadata: &Meta) -> span::Id {
+        span::Id::from_u64(0)
+    }
+
     fn observe_event<'event, 'meta: 'event>(&self, event: &'event Event<'event, 'meta>) {
         let fields = event.debug_fields();
         let meta = event.meta.as_log();

tokio-trace/examples/sloggish/sloggish_subscriber.rs

@@ -21,7 +21,7 @@ use std::{
     hash::{BuildHasher, Hash, Hasher},
     fmt,
     io::{self, Write},
-    sync::Mutex,
+    sync::{Mutex, atomic::{AtomicUsize, Ordering}},
     time::{Instant, SystemTime},
 };
 
@@ -32,6 +32,7 @@ pub struct SloggishSubscriber {
     t0_sys: SystemTime,
     hash_builder: RandomState,
     stack: Mutex<Vec<u64>>,
+    ids: AtomicUsize,
 }
 
 struct ColorLevel(Level);
@@ -57,6 +58,7 @@ impl SloggishSubscriber {
             t0_sys: SystemTime::now(),
             hash_builder: RandomState::new(),
             stack: Mutex::new(vec![]),
+            ids: AtomicUsize::new(0),
         }
     }
 
@@ -117,6 +119,11 @@ impl tokio_trace::Subscriber for SloggishSubscriber {
         true
     }
 
+    fn new_span_id(&self, _: &tokio_trace::Meta) -> tokio_trace::span::Id {
+        let next = self.ids.fetch_add(1, Ordering::SeqCst) as u64;
+        tokio_trace::span::Id::from_u64(next)
+    }
+
     #[inline]
     fn observe_event<'event, 'meta: 'event>(&self, event: &'event tokio_trace::Event<'event, 'meta>) {
         let mut stderr = self.stderr.lock();

tokio-trace/src/dispatcher.rs

@@ -1,4 +1,4 @@
-use {subscriber::Subscriber, Event, SpanData, Meta};
+use {span, subscriber::Subscriber, Event, SpanData, Meta};
 
 use std::{
     sync::atomic::{AtomicUsize, Ordering, ATOMIC_USIZE_INIT},
@@ -64,6 +64,15 @@ impl Subscriber for Builder {
         }
     }
 
+    fn new_span_id(&self, metadata: &Meta) -> span::Id {
+        // TODO: this shouldn't let the first attached subscriber always be in
+        // control of the span ID, but the dispatcher type is going away soon
+        // anyway, so for now, it just needs to compile.
+        self.subscribers.get(0)
+            .map(|subscriber| subscriber.new_span_id(metadata))
+            .unwrap_or_else(|| span::Id::from_u64(0))
+    }
+
     #[inline]
     fn enter(&self, span: &SpanData, at: Instant) {
         for subscriber in &self.subscribers {
@@ -97,6 +106,11 @@ impl Subscriber for Dispatcher {
         self.0.enabled(metadata)
     }
 
+    #[inline]
+    fn new_span_id(&self, metadata: &Meta) -> span::Id {
+        self.0.new_span_id(metadata)
+    }
+
     #[inline]
     fn observe_event<'event, 'meta: 'event>(&self, event: &'event Event<'event, 'meta>) {
         self.0.observe_event(event)
@@ -123,6 +137,10 @@ impl Subscriber for NoDispatcher {
         false
     }
 
+    fn new_span_id(&self, _metadata: &Meta) -> span::Id {
+        span::Id::from_u64(0)
+    }
+
     fn observe_event<'event, 'meta: 'event>(&self, _event: &'event Event<'event, 'meta>) {
         // Do nothing.
     }

tokio-trace/src/lib.rs

@@ -193,8 +193,10 @@ macro_rules! span {
         {
             use $crate::{span, Subscriber, Dispatcher, Meta};
             static META: Meta<'static> = static_meta!($name, $($k),* );
-            if Dispatcher::current().enabled(&META) {
+            let dispatcher = Dispatcher::current();
+            if dispatcher.enabled(&META) {
                 span::Span::new(
+                    dispatcher.new_span_id(&META),
                     ::std::time::Instant::now(),
                     &META,
                     vec![ $(Box::new($val)),* ], // todo: wish this wasn't double-boxed...

tokio-trace/src/span.rs

@@ -101,6 +101,19 @@ pub struct Data {
     inner: Arc<DataInner>,
 }
 
+/// Identifies a span within the context of a process.
+///
+/// Span IDs are used primarily to determine of two handles refer to the same
+/// span, without requiring the comparison of the span's fields.
+///
+/// They are generated by `Subscriber`s for each span as it is created, through
+/// the [`Subscriber::new_span_id`] trait method. See the documentation for that
+/// method for more information on span ID generation.
+///
+/// [`Subscriber::new_span_id`]: ../subscriber/trait.Subscriber.html#tymethod.new_span_id
+#[derive(Clone, Debug, PartialEq, Hash)]
+pub struct Id(u64);
+
 /// Internal representation of the data associated with a span.
 ///
 /// This has the potential to outlive the span itself, if a `Data` reference to
@@ -120,6 +133,8 @@ struct DataInner {
 
     pub field_values: Vec<Box<dyn Value>>,
 
+    pub id: Id,
+
     state: AtomicUsize,
 }
 
@@ -193,12 +208,14 @@ impl Span {
     /// directly.
     #[doc(hidden)]
     pub fn new(
+        id: Id,
         opened_at: Instant,
         static_meta: &'static StaticMeta,
         field_values: Vec<Box<dyn Value>>,
     ) -> Self {
         let parent = Active::current();
         let data = Data::new(
+            id,
             opened_at,
             parent.as_ref().map(Active::data),
             static_meta,
@@ -269,6 +286,7 @@ impl Into<Option<Data>> for Span {
 
 impl Data {
     fn new(
+        id: Id,
         opened_at: Instant,
         parent: Option<&Data>,
         static_meta: &'static StaticMeta,
@@ -280,6 +298,7 @@ impl Data {
                 parent: parent.cloned(),
                 static_meta,
                 field_values,
+                id,
                 state: AtomicUsize::new(0),
             })
         }
@@ -394,6 +413,11 @@ impl Data {
         }
     }
 
+    /// Returns the span's identifier.
+    pub fn id(&self) -> Id {
+        Id(self.inner.id.0)
+    }
+
     fn set_state(&self, prev: State, next: State) {
         self.inner.state.compare_and_swap(
             prev as usize,
@@ -423,6 +447,15 @@ impl fmt::Debug for Data {
     }
 }
 
+// ===== impl Id =====
+
+impl Id {
+    pub fn from_u64(u: u64) -> Self {
+        Id(u)
+    }
+}
+
+
 // ===== impl Active =====
 
 impl Active {
@@ -530,15 +563,13 @@ impl Hash for ActiveInner {
 
 impl Hash for DataInner {
     fn hash<H: Hasher>(&self, state: &mut H) {
-        self.opened_at.hash(state);
-        self.static_meta.hash(state);
+        self.id.hash(state);
     }
 }
 
 impl cmp::PartialEq for DataInner {
     fn eq(&self, other: &DataInner) -> bool {
-        self.opened_at == other.opened_at &&
-        self.static_meta == other.static_meta
+        self.id == other.id
     }
 }
 
@@ -685,4 +716,51 @@ mod tests {
         });
     }
 
+    #[test]
+    fn handles_to_the_same_span_are_equal() {
+        // Create a mock subscriber that will return `true` on calls to
+        // `Subscriber::enabled`, so that the spans will be constructed. We
+        // won't enter any spans in this test, so the subscriber won't actually
+        // expect to see any spans.
+        subscriber::mock().run();
+
+        let foo1 = span!("foo");
+        let foo2 = foo1.clone();
+
+        // Two handles that point to the same span are equal.
+        assert_eq!(foo1, foo2);
+
+        // The two span's data handles are also equal.
+        assert_eq!(foo1.data(), foo2.data());
+    }
+
+    #[test]
+    fn handles_to_different_spans_are_not_equal() {
+        subscriber::mock().run();
+
+        // Even though these spans have the same name and fields, they will have
+        // differing metadata, since they were created on different lines.
+        let foo1 = span!("foo", bar = 1, baz = false);
+        let foo2 = span!("foo", bar = 1, baz = false);
+
+        assert_ne!(foo1, foo2);
+        assert_ne!(foo1.data(), foo2.data());
+    }
+
+    #[test]
+    fn handles_to_different_spans_with_the_same_metadata_are_not_equal() {
+        subscriber::mock().run();
+
+        // Every time time this function is called, it will return a _new
+        // instance_ of a span with the same metadata, name, and fields.
+        fn make_span() -> Span {
+            span!("foo", bar = 1, baz = false)
+        }
+
+        let foo1 = make_span();
+        let foo2 = make_span();
+
+        assert_ne!(foo1, foo2);
+        assert_ne!(foo1.data(), foo2.data());
+    }
 }

tokio-trace/src/subscriber.rs

@@ -1,4 +1,4 @@
-use super::{Event, SpanData, Meta};
+use super::{span, Event, SpanData, Meta};
 use std::time::Instant;
 
 pub trait Subscriber {
@@ -8,6 +8,23 @@ pub trait Subscriber {
     /// if the span would be discarded anyway.
     fn enabled(&self, metadata: &Meta) -> bool;
 
+    /// Returns a new [span ID] for a span with the specified metadata.
+    ///
+    /// Span IDs are used to uniquely identify spans, so span equality will be
+    /// based on the returned ID. Thus, if the subscriber wishes for all spans
+    /// with the same metadata to be considered equal, it should return the same
+    /// ID every time it is given a particular set of metadata. Similarly, if it
+    /// wishes for two separate instances of a span with the same metadata to *not*
+    /// be equal, it should return a distinct ID every time this function is called,
+    /// regardless of the metadata.
+    ///
+    /// Subscribers which do not rely on the implementations of `PartialEq`,
+    /// `Eq`, and `Hash` for `Span`s are free to return span IDs with value 0
+    /// from all calls to this function, if they so choose.
+    ///
+    /// [span ID]: ../span/struct.Id.html
+    fn new_span_id(&self, metadata: &Meta) -> span::Id;
+
     /// Note that this function is generic over a pair of lifetimes because the
     /// `Event` type is. See the documentation for [`Event`] for details.
     ///
@@ -82,6 +99,10 @@ where
         (self.filter)(metadata) && self.inner.enabled(metadata)
     }
 
+    fn new_span_id(&self, metadata: &Meta) -> span::Id {
+        self.inner.new_span_id(metadata)
+    }
+
     #[inline]
     fn observe_event<'event, 'meta: 'event>(&self, event: &'event Event<'event, 'meta>) {
         self.inner.observe_event(event)
@@ -105,13 +126,14 @@ pub use self::test_support::*;
 mod test_support {
     use super::Subscriber;
     use ::{Event, SpanData, Meta};
-    use ::span::MockSpan;
+    use ::span::{self, MockSpan};
 
     use std::{
         cell::RefCell,
         collections::VecDeque,
         time::Instant,
         thread,
+        sync::atomic::{AtomicUsize, Ordering},
     };
 
     struct ExpectEvent {
@@ -126,6 +148,7 @@ mod test_support {
 
     struct Running {
         expected: RefCell<VecDeque<Expect>>,
+        ids: AtomicUsize,
     }
 
     pub struct MockSubscriber {
@@ -166,6 +189,7 @@ mod test_support {
                 .try_init();
             let subscriber = Running {
                 expected: RefCell::new(self.expected),
+                ids: AtomicUsize::new(0),
             };
             MOCK_SUBSCRIBER.with(move |mock| {
                 *mock.borrow_mut() = Some(subscriber);
@@ -179,6 +203,10 @@ mod test_support {
             true
         }
 
+        fn new_span_id(&self, _meta: &Meta) -> span::Id {
+            span::Id::from_u64(self.ids.fetch_add(1, Ordering::SeqCst) as u64)
+        }
+
         fn observe_event<'event, 'meta: 'event>(&self, _event: &'event Event<'event, 'meta>) {
             match self.expected.borrow_mut().pop_front() {
                 None => {}
@@ -237,6 +265,15 @@ mod test_support {
             true
         }
 
+        fn new_span_id(&self, meta: &Meta) -> span::Id {
+            MOCK_SUBSCRIBER.with(|mock| {
+                mock.borrow()
+                    .as_ref()
+                    .map(|subscriber| subscriber.new_span_id(meta))
+                    .unwrap_or_else(|| span::Id::from_u64(0))
+            })
+        }
+
         fn observe_event<'event, 'meta: 'event>(&self, event: &'event Event<'event, 'meta>) {
             MOCK_SUBSCRIBER.with(|mock| {
                 if let Some(ref subscriber) = *mock.borrow() {