Description

See the reproduction steps section for the code I wrote.

The code outputs the following log.

{
  "EventId": 1,
  "LogLevel": "Information",
  "Category": "Microsoft.Extensions.Http.Logging.HttpClientLogger",
  "Message": "GET dot.net/REDACTED",
  "State": {
    "Message": "LatencyInfo=,,http.request.method=GET,server.address=dot.net,url.path=REDACTED,Duration=2613,http.response.status_code=200",
    "LatencyInfo": ",",
    "http.request.method": "GET",
    "server.address": "dot.net",
    "url.path": "REDACTED",
    "Duration": 2613,
    "http.response.status_code": 200
  }
}

The LatencyInfo in log is empty. How can I get it to output a valid value here?

I apologise if I have misunderstood how to use this library. In that case, please tell me how to use it correctly.

Reproduction Steps

using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Logging;

var services = new ServiceCollection();

services
    .AddHttpClient()
    .AddRedaction()
    .AddLatencyContext()
    .AddExtendedHttpClientLogging()
    .AddHttpClientLatencyTelemetry();

services.AddLogging(static builder =>
    builder.AddJsonConsole(static options =>
    {
        options.JsonWriterOptions = new()
        {
            Indented = true
        };
    }));

await using var serviceProvider = services.BuildServiceProvider();

var client = serviceProvider.GetRequiredService<HttpClient>();

using var response = await client.GetAsync("http://dot.net").ConfigureAwait(false);

Console.WriteLine(response.StatusCode);

Expected behavior

The LatencyInfo in the log should be as follows, shouldn't it?

"LatencyInfo": ",handreqs/dnss/dnse/cons/cone/cones/rlq/reqhs/reqhe/reshs/reshe/enrin/,0.1706/68.8664/81.0259/86.9632/335.9692/341.1706/341.921/342.4656/342.7676/629.649/630.2728/1358.2388999999998/"

Actual behavior

The LatencyInfo in the log is as follows

"LatencyInfo":","

Regression?

The behavior was the same in ver 8.0.0.

Known Workarounds

No response

Configuration

<Project Sdk="Microsoft.NET.Sdk">

  <PropertyGroup>
    <OutputType>Exe</OutputType>
    <TargetFramework>net9.0</TargetFramework>
    <ImplicitUsings>enable</ImplicitUsings>
    <Nullable>enable</Nullable>
  </PropertyGroup>

  <ItemGroup>
    <PackageReference Include="Microsoft.Extensions.Compliance.Redaction" Version="9.0.0" />
    <PackageReference Include="Microsoft.Extensions.Http.Diagnostics" Version="9.0.0" />
    <PackageReference Include="Microsoft.Extensions.Logging.Console" Version="9.0.0" />
  </ItemGroup>

</Project>

Other information

HttpClientLoggerHandler runs outside HttpLatencyTelemetryHandler because the wrapHandlersPipeline parameter is set to true when the HttpClientLogger is added.

The ILatencyContext is stored in AsyncLocal, so it is not possible to read the value that was set downstream of the call from upstream.
In other words, I think that the HttpClientLoggerHandler cannot get the values set by the HttpLatencyTelemetryHandler.

When I changed the wrapHandlersPipeline parameter to false while debugging, I got the output I wrote in the Expected behaviour section. Is it correct that this parameter is true?

Alternatively, using AsyncState instead of AsyncLocal.