Add traceparent header parsing for w3c tracecontext

[mateiidavid]

This is a proof of concept PR to show what changes would be necessary to support tracecontext, the OpenTelemetry "standardised" way of propagating distributed tracing context (aka w3c format).

A copy of the RFC can be found here. The RFC/specification has a processing model for how the header(s) should be parsed. This proof of concept contains most cases, some which are a bit more trivial to implement have been left out and will be done when (or if) this moves forward. The parsing logic is also a bit rushed and I will want to revisit it if conceptually this all looks sound.

Also, most notably, tracestate is not being handled at all, since it's optional:

Vendors receiving a tracestate request header MUST send it to outgoing requests. It MAY mutate the value of this header before passing to outgoing requests. When mutating tracestate, the order of unmodified key/value pairs MUST be preserved. Modified keys SHOULD be moved to the beginning (left) of the list.

Likewise, the proxy will likely not want to implement some parts of the specification, the one that stands out to me is the absence of a traceparent header. On absence, the spec says we should start a trace, we will want to instead parse b3 headers (we shouldn't create our own trace if it's not present on the request).

To test, I used an emojivoto fork configured with otel instead of opencensus library. If we go ahead with this, I plan on pushing my branch to the emojivoto repo along with manifests so that reviewers can test in their environments. For now, I've included pictures from a trace (vote-bot --> voting, note that bot-vote naming is to distinguish my fork from the original code, bit confusing maybe, sorry).

Note: in the first picture notice how the last service (voting) didn't really have a proxy span. On refresh, the span appeared. Think this is just Jaeger being flakey.

Pictures of Jaeger query

Signed-off-by: Matei David [email protected]

[mateiidavid]

Update:

Added a unit test, refactored logic to make everything look a bit neater. Tested again (attached screenshot at the bottom of the post). Should be ready for review.

Testing:

Need:

• k3d with linkerd and linkerd-jaeger installed
• Emojivoto
• Proxy image

Emojivoto needs to be built using otel sdk and API instead of opencensus. I have a branch here that changes this in vote-bot, web and voting.

$ git clone && git checkout matei/add-w3c-support
# Need protoc v1.1 to gen protobuf
 go install google.golang.org/grpc/cmd/[email protected]
# This should also compile protos
 NODE_OPTIONS=--openssl-legacy-provider make build

$ k3d image import -c tracing docker.io/buoyantio/emojivoto-web:v12 docker.io/buoyantio/emojivoto-voting-svc:v12 docker.io/buoyantio/emojivo
to-emoji-svc:v12 docker.io/buoyantio/emojivoto-svc-base:v12

Emojivoto manifests

Note: pods and namespace have different names because I wanted to run it in parallel with emojivoto to see diff in spans generated.

apiVersion: v1
kind: Namespace
metadata:
  name: votoemoji
---
apiVersion: v1
kind: ServiceAccount
metadata:
  name: emoji
  namespace: votoemoji
---
apiVersion: v1
kind: ServiceAccount
metadata:
  name: voting
  namespace: votoemoji
---
apiVersion: v1
kind: ServiceAccount
metadata:
  name: web
  namespace: votoemoji
---
apiVersion: v1
kind: Service
metadata:
  name: emoji-svc
  namespace: votoemoji
spec:
  ports:
  - name: grpc
    port: 8080
    targetPort: 8080
  - name: prom
    port: 8801
    targetPort: 8801
  selector:
    app: emoji-svc
---
apiVersion: v1
kind: Service
metadata:
  name: voting-svc
  namespace: votoemoji
spec:
  ports:
  - name: grpc
    port: 8080
    targetPort: 8080
  - name: prom
    port: 8801
    targetPort: 8801
  selector:
    app: voting-svc
---
apiVersion: v1
kind: Service
metadata:
  name: web-svc
  namespace: votoemoji
spec:
  ports:
  - name: http
    port: 80
    targetPort: 8080
  selector:
    app: web-svc
  type: ClusterIP
---
apiVersion: apps/v1
kind: Deployment
metadata:
  labels:
    app.kubernetes.io/name: emoji
    app.kubernetes.io/part-of: votoemoji
    app.kubernetes.io/version: v12
  name: emoji
  namespace: votoemoji
spec:
  replicas: 1
  selector:
    matchLabels:
      app: emoji-svc
      version: v12
  template:
    metadata:
      labels:
        app: emoji-svc
        version: v12
    spec:
      containers:
      - env:
        - name: GRPC_PORT
          value: "8080"
        - name: PROM_PORT
          value: "8801"
        imagePullPolicy: IfNotPresent
        image: docker.io/buoyantio/emojivoto-emoji-svc:v12
        name: emoji-svc
        ports:
        - containerPort: 8080
          name: grpc
        - containerPort: 8801
          name: prom
        resources:
          requests:
            cpu: 100m
      serviceAccountName: emoji
---
apiVersion: apps/v1
kind: Deployment
metadata:
  labels:
    app.kubernetes.io/name: vote-bot
    app.kubernetes.io/part-of: votoemoji
    app.kubernetes.io/version: v12
  name: vote-bot
  namespace: votoemoji
spec:
  replicas: 1
  selector:
    matchLabels:
      app: vote-bot
      version: v12
  template:
    metadata:
      labels:
        app: vote-bot
        version: v12
    spec:
      containers:
      - command:
        - emojivoto-vote-bot
        env:
        - name: WEB_HOST
          value: web-svc.votoemoji:80
        image: docker.io/buoyantio/emojivoto-web:v12
        imagePullPolicy: IfNotPresent
        name: vote-bot
        resources:
          requests:
            cpu: 10m
---
apiVersion: apps/v1
kind: Deployment
metadata:
  labels:
    app.kubernetes.io/name: voting
    app.kubernetes.io/part-of: votoemoji
    app.kubernetes.io/version: v12
  name: voting
  namespace: votoemoji
spec:
  replicas: 1
  selector:
    matchLabels:
      app: voting-svc
      version: v12
  template:
    metadata:
      labels:
        app: voting-svc
        version: v12
    spec:
      containers:
      - env:
        - name: GRPC_PORT
          value: "8080"
        - name: PROM_PORT
          value: "8801"
        image: docker.io/buoyantio/emojivoto-voting-svc:v12
        imagePullPolicy: IfNotPresent
        name: voting-svc
        ports:
        - containerPort: 8080
          name: grpc
        - containerPort: 8801
          name: prom
        resources:
          requests:
            cpu: 100m
      serviceAccountName: voting
---
apiVersion: apps/v1
kind: Deployment
metadata:
  labels:
    app.kubernetes.io/name: web
    app.kubernetes.io/part-of: votoemoji
    app.kubernetes.io/version: v12
  name: web
  namespace: votoemoji
spec:
  replicas: 1
  selector:
    matchLabels:
      app: web-svc
      version: v12
  template:
    metadata:
      labels:
        app: web-svc
        version: v12
    spec:
      containers:
      - env:
        - name: WEB_PORT
          value: "8080"
        - name: EMOJISVC_HOST
          value: emoji-svc.votoemoji:8080
        - name: VOTINGSVC_HOST
          value: voting-svc.votoemoji:8080
        - name: INDEX_BUNDLE
          value: dist/index_bundle.js
        image: docker.io/buoyantio/emojivoto-web:v12
        imagePullPolicy: IfNotPresent
        name: web-svc
        ports:
        - containerPort: 8080
          name: http
        resources:
          requests:
            cpu: 100m
      serviceAccountName: web

Once proxy branch is built, namespace can be annotated with proxy-version override and spans should be generated successfully. We always sample requests from root span (e.g vote-bot) so that should be honored end-to-end.

Pics from new commit

RFC Diff

Some handling of the traceparent version is not present in this PR. I can make the changes, I thought we should limit mutations as much as possible -- also, if an invalid version is parsed, according to the spec we'd have to reset the header values, which means the proxy would function as a root span. If something is not formatted correctly I opted to instead not include the traceparent header at all.

e.g

If the version cannot be parsed, the vendor creates a new traceparent header and deletes tracestate.

This is not a case we're currently handling.

Full RFC processing suggestion can be found here: https://www.w3.org/TR/trace-context-1/#a-traceparent-is-received

[adleong]

Looks great! Couple of tiny suggestions.

[olix0r]

Should we start splitting this module into submodules? It seems like a w3c module would be appropriate, for instance.

[mateiidavid]

Split everything into submodules. I declared the modules in propagation.rs. In each submodule we use helpers from propagation, it's a bit of a circular dependency but I wanted to pull all parsing and unpacking functions that work on a specific format out of propagation. End result is that only the increment and unpacks need to be public so we don't leak out any parsing logic to other modules. Let me know if this looks good.

Also, changed one big assumption. Whenever flags cannot be parsed we invalidate the whole trace. According to the spec, flags are optional (meaning a 0 is sent instead?). If a traceparent cannot be parsed (i.e bad version, or bad id) we invalidate it. Flags shouldn't be any different, we shouldn't hint at what the flags should be (by setting it to 0 if it can't be hex decoded or if it's missing). So we simply fail.

[hawkw]

this looks good to me! i commented on some small style suggestions, but no blockers in my book!

[hawkw]

nit, take it or leave it: it might be a little bit nicer to use HeaderName::from_static here, because this would perform the validation that the string only contains valid header characters a single time, rather than repeating it every time we convert the &str into a HeaderName (which currently occurs every time it's used to access a HeaderMap):

Suggested change

	pub const HTTP_TRACEPARENT: &str = "traceparent";
	pub const HTTP_TRACEPARENT: http::HeaderName = http::HeaderName::from_static("traceparent");

we may want to do this for the b3 headers as well, but I didn't leave a comment on that because that code was already here.

[mateiidavid]

Bit besides the point but is the http crate used only for the types, basically? I thought hyper would have its own internal types to deal with requests and headers. I guess they're all just re-exports tho?

[olix0r]

The http crate contains core types like requests, headers, etc. Similarly, the Body trait is in the http_body crate Hyper uses those types (and reexports them for convenience). This allows these crates to have narrower public APIs so they can reach stability quicker/independently from the rest of Hyper. It also means we can depend on core types in libraries without exposing hyper as part of a public interface (which would influence stability/semver).

[hawkw]

also, i wonder if the warning ought to include the error returned by HeaderValue::from_str?

Suggested change

	if let Result::Ok(hv) = HeaderValue::from_str(&new_header) {
	request.headers_mut().insert(HTTP_TRACEPARENT, hv);
	} else {
	warn!("invalid value {} for tracecontext header", new_header);
	}
	match HeaderValue::from_str(&new_header)
	Ok(hv) => request.headers_mut().insert(HTTP_TRACEPARENT, hv),
	Err(error) => warn!("invalid value {new_header} for tracecontext header: {error}"),
	}

[mateiidavid]

Compiler will complain because we're not return an Option from the second branch. I wonder if that's why we used the if let syntax instead of a match? Do you know if we can somehow ignore the return types in the match arms?

[mateiidavid]

Also, had to change everything to be static and we're passing references now. Compiler yells otherwise for moving out of static item (which I guess makes lots of sense).

[olix0r]

I'm cutting my review short for time, but I think we need to take a thoughtful pass at the logs here:

• Are they consistent?
• Are INFO+ logs informative/actionable to users?
• My hunch is that most of the warns should be debugs...

[olix0r]

We should be consistent about log formatting. Specifically, i think all of our log messages should be capitalized (this file seems to have a mix of cases).

Suggested change

	warn!("invalid header: {:?}", &bytes_b64);
	warn!("Invalid header: {:?}", &bytes_b64);

Furthermore, what would a user do if they saw this warning? Is it going to be informative enough for them to act on?

[hawkw]

(FWIW, I believe this code was already here and this PR just moved it into a new module)

[mateiidavid]

I'm not sure if it's informative enough to act on without context around what is happening. It's not immediately clear that the header value is invalid because it's not a visible ASCII character, or that this is a value we are trying to set (as opposed to erroring out when reading the header from the inbound request).

I think this one in particular is a bit tricky. The conversion from &str to HeaderValue may fail only if the string does not contain visible ASCII codes (32 - 127). Since we encode the value using base64 (and that operation is infallible), we kind of have a guarantee that the value will be valid (b64 uses a subset of 32-127 afaik). I'm pretty sure this operation is infallible so we wouldn't actually see this warn message (in which case it'd be better to just delete and add a comment?). The same logic should apply to any header value that is hex encoded. If hex encoding is successful, we will only use a-f and 0-9 (potentially - too), all of which are visible ASCII characters.

For now, I'll update the message and level. Something like debug!(%header_value, %header, "Header value contains invalid ASCII characters"). I think printing the header (as well as the value) will give more contextual information on where the error is cropping up. We can only fail with invisible ascii characters. Alternatively, we could use map_err to log the error itself.

Since imo the operation is infallible, I'd just simplify everything to:

HeaderValue::from_str(&bytes_b64).ok().and_then(|hv| request.headers_mut.insert(GRPC_TRACE_HEADER, hv))

I don't want to modify too much of the existing codebase so it seemed more sensible to discuss this with both of you first.

[olix0r]

similarly

[olix0r]

Suggested change

	trace!("incremented span id: {span_id}");
	trace!("Incremented span id: {span_id}");

[olix0r]

Suggested change

	.map_err(|e| warn!("trace header {GRPC_TRACE_HEADER} is not base64 encoded: {e}"))
	.map_err(|e| warn!("{GRPC_TRACE_HEADER} is not base64 encoded: {e}"))

Looking at https://docs.rs/base64/latest/src/base64/decode.rs.html#10-28, I'm skeptical that the error messages we have here are useful to users.

[hawkw]

(FWIW, I believe this code was already here and this PR just moved it into a new module)

[mateiidavid]

Thanks for the suggestions! I went through the new and existing code and tried my best to make the log messages a bit more descriptive and useful to our users. I mainly thought of what I would find useful if I were to debug a trace propagation issue.

• Ensure log records are more consistent (warn! --> debug! in terms of level, opted to use structured logging except for some GRPC cases where interpolation made more sense, and capitalised the start of every message)
• Bubble up error in decode_id so we can include the header name where applicable. This will allow us to be more specific when writing the log message; for b3 this means we can include the exact header, for w3c it means we can include the all-purpose header name. This should give more context to users.
• Removed duplicate log entries from w3c. When parsing an invalid id we'd log twice: once when decoding from hex, and once in the match statement in the calling function. Replaced the match statement with ?. The id parsing can fail either when we have nothing to parse or when hex decoding fails (in which case we log in a different point)

Let me know if this looks better and I'm on the right path 🙏🏻