HeaderProgation middleware: logger scope

[alefranz]

This add the headers captured by the HeaderProgation middleware into the logger scope.

I understand that it is not current practice to have official Middlewares add information to the logger scope, however I believe it's a reasonable requirement to tag the log entries with the propagated header values.
Currently it could be achieved anyway, but, when relying on the valuefactory to determine the values, it requires to access the captured headers (but how they are stored should be an internal implementation details) and a bit of code.

Features

• Opt-in behaviour
• Headers are added to the scope using the PropagatedName
• When formatted as string, the scope uses space as separator:
  • it looks like there is no specific convention as I found used either space or comma as separator, even inside the same scope. Am I missing something?
  • In this context space makes sense as comma is already used to separate multiple values (behaviour of StringValues)
• No cost per request when not enabled
• No startup cost when not enabled
• Changed HeaderPropagationValues.Headers to be internal as I believe logging was the only reason to keep it exposed and it feels a bit risky to expose it given it is not thread safe.

Please let me know how you feel about including this functionality.

If this can be considered as PR, I can provide details on the implementation choices if it can help the code review.

Thank you,
Alessio

cc: @rynowak

[rynowak]

I understand that it is not current practice to have official Middlewares add information to the logger scope, however I believe it's a reasonable requirement to tag the log entries with the propagated header values.

What scenarios did you have in mind for this? I'm having trouble why you'd want the forwarded headers specifically to create a scope rather than the original request headers.

We typically are looking for a very strong motivation when we think about creating a scope. The kinds of things that create scopes today: the request, MVC, EF - top level concepts that users code against all of the time.

If you're passionate about this idea, this seems like something that you could ship as a package.

/cc @anurse @davidfowl

[alefranz]

Hi Ryan,
thanks for taking the time to look into this.
I believe this is a functionality needed to complete the feature, and it was also asked for it in the original issue dotnet/extensions#526

My main use case would be in a tracing scenario (not to other readers: yes, this is not a tracing feature but allow to achieve that in legacy/mixed scenarios).

So for example if you have an incoming header transactionid that you are propagating to all your microservices, you want to have those transactionid in all logs generated, but as you said you can just retrieve it from the request.
However in this middleware we allow also to generate values, so for example if you have a call which doesn't have the transactionid you can generate a value for it. To be able to add this generated value in your logs you will have then to access HeaderPropagationValues.Headers to get this value, in fact I kept it public for that reason but it should probably be internal.
Also, to achieve this is not a trivial amount of code.
This could be however not what everyone needs, in fact it is optional.

In my opinion this is a more common need compared to what is currently added to the scope by default, as for example the connectionId is not used unless you are really investigating low level issues.

But as I mentioned I understand that it's not current practice to add logger scopes in the middlewares and this could probably require a dedicated discussion which is too late to have now for 3.0.

Maybe the solution could be to have a generic logger middleware that has the capability to retrieve context from the different middlewares to be added to the logger scope. Or at least some syntactic sugar to include data to the scope.

I can ship this as a 3rd party library if this is not viable, no problem.
Would it be ok to keep HeaderPropagationValues.Headers public?

Thank you,
Alessio

[davidfowl]

In my opinion this is a more common need compared to what is currently added to the scope by default, as for example the connectionId is not used unless you are really investigating low level issues.

We're pushing people in a different direction for distributed tracing, towards the WC3 trace context spec (https://w3c.github.io/trace-context/). We'll have support for this built into .NET Core 3.0. It's pretty much what you want and the header names have been agreed upon by the broader community.

In my opinion this is a more common need compared to what is currently added to the scope by default, as for example the connectionId is not used unless you are really investigating low level issues.

ConnectionId isn't super useful unless you're debugging the networking layer. We could even leave it out by default as the request id basically includes the connection id by default.

But as I mentioned I understand that it's not current practice to add logger scopes in the middlewares and this could probably require a dedicated discussion which is too late to have now for 3.0.

You can totally do that, we just don't do it in our middleware because there's very little value in attaching more properties to every single log statement when hosting is trying to be minimal about it.

Maybe the solution could be to have a generic logger middleware that has the capability to retrieve context from the different middlewares to be added to the logger scope. Or at least some syntactic sugar to include data to the scope.

#5914

I can ship this as a 3rd party library if this is not viable, no problem.
Would it be ok to keep HeaderPropagationValues.Headers public?

Sounds fine to me, I'll let @rynowak decide on that one, as I don't think we'll be recommending this middleware for tracing unless people are trying to interop with their system's existing headers.

[alefranz]

Hi David,
I appreciate your feedback.

You can totally do that, we just don't do it in our middleware because there's very little value in attaching more properties to every single log statement when hosting is trying to be minimal about it.

This is opinionated, in my experience is often more useful to have less logging (e.g. only warning ad above) but with more details on it. But being minimal should definitely be the default.

I don't think we'll be recommending this middleware for tracing unless people are trying to interop with their system's existing headers.

I knew I should not have used that example and yet, I did it :)
Btw I wasn't able to find any issue about considering supporting mixed/legacy scenario in the Trace Context implementation, do you happen to have at hand an issue number or resource to point me to?

Thank you,
Alessio

[rynowak]

I can ship this as a 3rd party library if this is not viable, no problem.

I think it would be better for now if you ship this as a 3rd party library. The header propagation feature is totally new, and I don't want to build too much infrastructure around it until we have some actual usage. Plus as @davidfowl mentioned, we plan to have a good tracing story by default, and we don't want to confuse people.

Those factors make me say no to us shipping something like this, at least for now.

Would it be ok to keep HeaderPropagationValues.Headers public?

Please suggest whatever changes you need to make this possible. We've got a short amount of time (1.5 weeks) to make API changes before it will become harder to include them in the release.

[davidfowl]

Btw I wasn't able to find any issue about considering supporting mixed/legacy scenario in the Trace Context implementation, do you happen to have at hand an issue number or resource to point me to?

What do you mean?

[alefranz]

Btw I wasn't able to find any issue about considering supporting mixed/legacy scenario in the Trace Context implementation, do you happen to have at hand an issue number or resource to point me to?

What do you mean?

Apologies, that wasn't clear at all. I was asking if there is some work planned (and where is it tracked) around a gradual migration from a custom tracing solution to the new built-in W3C one in a microservice architecture. e..g just continuing to flow the "legacy" tracing header alongside the new one (as at some pint in the chain of services there will be one that does not understand the trace context and will drop it) versus "upgrade/downgrade" from a custom header to the trace context or something along this lines.

[analogrelay]

This is a somewhat-stale draft PR now and would be targeting 5.0. Should we keep this going or close it for now and return to the underlying work later? I lean towards closing if we don't expect to revive it for 5.0 soon (can always be re-opened). (Thoughts @rynowak @davidfowl @alefranz)

[alefranz]

I think it would be better for now if you ship this as a 3rd party library. The header propagation feature is totally new, and I don't want to build too much infrastructure around it until we have some actual usage. Plus as @davidfowl mentioned, we plan to have a good tracing story by default, and we don't want to confuse people.

Hi @anurse, I'm ok to close this and I can release this as 3rd party library and eventually reconsider it later if there is interest, as suggested by @rynowak.

Thank you!