stevejgordon / CorrelationId

An ASP.NET Core middleware component which synchronises a correlation ID for cross API request logging.
MIT License
558 stars 106 forks source link

TraceId is not set to Correlation ID #75

Closed NxSoftware closed 4 years ago

NxSoftware commented 4 years ago

Unless I'm misunderstanding what behaviour this library is intending to provide it would appear that the TraceId in the console log scope (enabled using "IncludeScopes": true in appsettings.json) doesn't get set to the generated Correlation ID.

This is the output from the current master branch sample app with the following options provided to AddDefaultCorrelationId:

options.AddToLoggingScope = true;
options.IgnoreRequestHeader = false;
options.IncludeInResponse = true;
options.RequestHeader = "My-Custom-Correlation-Id";
options.ResponseHeader = "X-Correlation-Id";
options.UpdateTraceIdentifier = true;
dbug: CorrelationId.CorrelationIdMiddleware[100]
      => ConnectionId:0HLSQHURG1MH3 => RequestPath:/ RequestId:0HLSQHURG1MH3:00000001, SpanId:|1145a7a6-4829067df8c95821., TraceId:1145a7a6-4829067df8c95821, ParentId:
      Running correlation ID processing
info: CorrelationId.CorrelationIdMiddleware[106]
      => ConnectionId:0HLSQHURG1MH3 => RequestPath:/ RequestId:0HLSQHURG1MH3:00000001, SpanId:|1145a7a6-4829067df8c95821., TraceId:1145a7a6-4829067df8c95821, ParentId:
      No correlation ID was found in the request headers
dbug: CorrelationId.CorrelationIdMiddleware[108]
      => ConnectionId:0HLSQHURG1MH3 => RequestPath:/ RequestId:0HLSQHURG1MH3:00000001, SpanId:|1145a7a6-4829067df8c95821., TraceId:1145a7a6-4829067df8c95821, ParentId:
      Generated a correlation ID dd6a85fb-1d24-4450-828b-ac5357ac6d57 using the CorrelationId.Providers.GuidCorrelationIdProvider provider
dbug: CorrelationId.CorrelationIdMiddleware[109]
      => ConnectionId:0HLSQHURG1MH3 => RequestPath:/ RequestId:0HLSQHURG1MH3:00000001, SpanId:|1145a7a6-4829067df8c95821., TraceId:1145a7a6-4829067df8c95821, ParentId:
      Updating the TraceIdentifier value on the HttpContext
dbug: CorrelationId.CorrelationIdMiddleware[110]
      => ConnectionId:0HLSQHURG1MH3 => RequestPath:/ RequestId:0HLSQHURG1MH3:00000001, SpanId:|1145a7a6-4829067df8c95821., TraceId:1145a7a6-4829067df8c95821, ParentId:
      Creating the correlation context for this request
dbug: CorrelationId.CorrelationIdMiddleware[101]
      => ConnectionId:0HLSQHURG1MH3 => RequestPath:/ RequestId:0HLSQHURG1MH3:00000001, SpanId:|1145a7a6-4829067df8c95821., TraceId:1145a7a6-4829067df8c95821, ParentId:
      Correlation ID processing was completed with a final correlation ID dd6a85fb-1d24-4450-828b-ac5357ac6d57
dbug: CorrelationId.CorrelationIdMiddleware[111]
      => ConnectionId:0HLSQHURG1MH3 => RequestPath:/ RequestId:0HLSQHURG1MH3:00000001, SpanId:|1145a7a6-4829067df8c95821., TraceId:1145a7a6-4829067df8c95821, ParentId:
      Disposing the correlation context for this request
dbug: CorrelationId.CorrelationIdMiddleware[112]
      => ConnectionId:0HLSQHURG1MH3 => RequestPath:/ RequestId:0HLSQHURG1MH3:00000001, SpanId:|1145a7a6-4829067df8c95821., TraceId:1145a7a6-4829067df8c95821, ParentId:
      Writing correlation ID response header X-Correlation-Id with value dd6a85fb-1d24-4450-828b-ac5357ac6d57

Trace Id being 1145a7a6-4829067df8c95821 and Correlation Id being dd6a85fb-1d24-4450-828b-ac5357ac6d57

NxSoftware commented 4 years ago

Having a bit more of a look it seems that the RequestId in the logged scope is retrieved from the HttpContext.TraceIdentifier property, not sure where the logged TraceId value comes from.

Regardless, neither value is what was set by the CorrelationId middleware.

stevejgordon commented 4 years ago

The TraceId set in the logging scope above is coming fro the current Activity.

There are quite a lot of considerations around messing with the Activity directly and I currently feel that adjusting that should be a decision in user code. I may revisit that but right now I'm unconvinced. Activities support the concept of correlation of requests and logs and provide a richer, standards-compliant approach. I feel that CorrelationID and Activity should remain distinct. Correlation ID is a simpler library which can be used in place of or alongside Activities.

VictorioBerra commented 3 years ago

Same issue here. The "TraceId" I see in my log output is unchanged despite options.UpdateTraceIdentifier = true. If you AddToLoggingScope = true it shows up in the logs. Hope this helps someone.