Can logging inherit metadata from spans?

[nickb937]

Most of my functions are decorated with #[tracing:instrument] and sometimes I store the span field information in the definition too, or use span.record() to store the metadata later calculated in the function.

What I'd like to know is whether it is possible for info!() logs to inherit the metadata of the span so that it can be written to stdout as part of the normal log message?

The purpose is that whilst I might look at traces in something like Tempo where that metadata exists, I also like to be able to query the logs system directly.

Currently I have to duplicate the metadata for each info!() statement, which can mean up-to 10 pieces of duplicated metadata written per statement for a given function.

[mladedav]

It depends on the logging layer, if you're using fmt subscriber provided in tracing-subscriber, you're probably looking for with_current_span or with_span_list.

[mladedav]

That's weird, if you're using with_current_span, the output of each longline should be something like this: {"fields":{"message":"msg","event_field1":"...",...},"span":{"span_field1":"...",...}}

I'm assuming you're using json output since that's your example, I don't know if the other formatters behave differently.

Anyway if you want something more specific like really moving the span fields together with the event fields, you'd need to use a different subscriber for more control over the output.

[hawkw]

It seems like what you want is to flatten all the fields on the current span into the top-level JSON object, rather than emitting a "span" sub-object or a "spans" list. The reason the JSON formatter doesn't do this currently is because an event occurs not only within the current span, but also in that span's parent(s). Using the with_span_list option, the whole list of parent spans is included. Span fields are namespaced by the name of the span that defines them, so there may be multiple fields with the same name within the list of all fields defined by parents, so there could be multiple fields with the same name in the trace.

We could probably add an option to include parent span fields in the top level JSON object. However, we'd probably want to do it by adding the span name as a prefix to the field, to resolve potential namespace collisions between fields defined on multiple spans and on the event itself. For example, if we have something like this:

let _span1 = info_span!("span1", myfield = 1).entered();
let _span2 = info_span!("span2", myfield = 2, something = false).entered();
info!(myfield = 3, "my event");

we would want to output JSON like this:

{"message": "my event", "myfield": 3, "span2.myfield": 2, "span2.something": false, "span1.myfield": 1, ...}

[nickb937]

The handy thing about flattening the namespace is that I can write very simple LogsQL filter like myfield:"3" to pull everything associated to myfield where value is 3. If the span is prefixed onto the field name then it becomes harder. But I get why you'd prefix the span, since you've no guarantee that the same field name isn't used within the same span for different values, like might happen in a for..loop. Perhaps this just throws up more problems and corner cases than is worth considering.

[mladedav]

Sorry, it seems I didn't understand what you were after at all.

There is a PR trying to add what I think you want here #2705

[nickb937]

Ah ha, thanks, #2705 is indeed it, https://github.com/mladedav/json-subscriber looks like the path forward.