Identical request ID on every new request

[klingerf]

It looks like we're assigning the same request ID to every linkerd request that doesn't already have an existing context set. To track this down, I modified the HttpTraceInitializer as follows:

diff --git a/linkerd/protocol/http/src/main/scala/com/twitter/finagle/buoyant/linkerd/HttpTraceInitializer.scala b/linkerd/protocol/http/src/main/scala/com/twitter/finagle/buoyant/linkerd/HttpTraceInitializer.scala
index bd63829..49d3056 100644
--- a/linkerd/protocol/http/src/main/scala/com/twitter/finagle/buoyant/linkerd/HttpTraceInitializer.scala
+++ b/linkerd/protocol/http/src/main/scala/com/twitter/finagle/buoyant/linkerd/HttpTraceInitializer.scala
@@ -4,6 +4,7 @@ import com.twitter.finagle.{Status => _, _}
 import com.twitter.finagle.http._
 import com.twitter.finagle.tracing._
 import com.twitter.finagle.buoyant.SampledTracer
+import java.util.logging.Logger

 /**
  * Typically, finagle clients initialize trace ids to capture a
@@ -15,6 +16,8 @@ import com.twitter.finagle.buoyant.SampledTracer
 object HttpTraceInitializer {
   val role = TraceInitializerFilter.role

+  private[this] val log = Logger.getLogger(getClass.getName)
+
   object clear extends Stack.Module0[ServiceFactory[Request, Response]] {
     val role = HttpTraceInitializer.role
     val description = "Clears all tracing info"
@@ -45,6 +48,7 @@ object HttpTraceInitializer {

         withTracer(tracer, ctx) {
           setId(tracer, Trace.id) {
+            log.fine(s"request id: ${Trace.id}")
             service(req)
           }
         }

And sure enough, when issuing three independent http requests, I get:

D 0209 19:28:46.819 THREAD17: request id: 59f8caf4faf96b61.59f8caf4faf96b61<:59f8caf4faf96b61
D 0209 19:28:47.644 THREAD18: request id: 59f8caf4faf96b61.59f8caf4faf96b61<:59f8caf4faf96b61
D 0209 19:28:48.322 THREAD19: request id: 59f8caf4faf96b61.59f8caf4faf96b61<:59f8caf4faf96b61