AddHttpClientInstrumentation considers the activity finished as soon as the headers are sent

[Vlad-Stryapko]

I was playing around with HTTP instrumentation and noticed it considers the activity finished when the headers are available even if the body itself cannot be read yet. Is this the expected behaviour and is it possible to make sure the activity covers the entire request or should I add custom telemetry on-top of HTTP instrumentation to achieve that?

The repro is pretty simple.

Client is .NET 6 console app with the following OTel packages.

		<PackageReference Include="OpenTelemetry.Exporter.Console" Version="1.4.0" />
		<PackageReference Include="OpenTelemetry.Exporter.OpenTelemetryProtocol" Version="1.4.0" />
		<PackageReference Include="OpenTelemetry.Instrumentation.Http" Version="1.0.0-rc9.14" />

Program.cs

    static async Task Main(string[] args)
    {
        ConfigureSerilog(); 
        Log.Information("Start console");

        using var tracerProvider = Sdk.CreateTracerProviderBuilder()
            .SetResourceBuilder(ResourceBuilder.CreateDefault().AddService(
                serviceName: "test-console"))
            .AddSource("test-console")
            .AddConsoleExporter()
            .AddHttpClientInstrumentation()
            .AddOtlpExporter()
            .Build();

        using var parent = MyActivitySource.StartActivity("root");

        using (var innerActivity = MyActivitySource.StartActivity("http-call-manual"))
        {
            Log.Information("Will make http call");
            using HttpResponseMessage response = await client.GetAsync("http://localhost:11100/test/delay-simple", HttpCompletionOption.ResponseHeadersRead);
            Log.Information("Got response w/o body");
            response.EnsureSuccessStatusCode();
            var body = await response.Content.ReadAsStringAsync();
            Log.Information("Got body");
        }
    }

Server is Core 6 web app with a default controller and a simple middleware.

Packages:

	  <PackageReference Include="OpenTelemetry.Exporter.Console" Version="1.4.0" />
	  <PackageReference Include="OpenTelemetry.Exporter.OpenTelemetryProtocol" Version="1.4.0" />
	  <PackageReference Include="OpenTelemetry.Instrumentation.AspNetCore" Version="1.0.0-rc9.14" />
	  <PackageReference Include="OpenTelemetry.Extensions.Hosting" Version="1.4.0" />

Middleware

public class DelayMiddleware
{
    private readonly RequestDelegate _next;

    public DelayMiddleware(RequestDelegate next)
    {
        _next = next;
    }

    public async Task Invoke(HttpContext httpContext, ILogger<ApiAccessLoggingMiddleware> logger)
    {
        await _next(httpContext);
        await Task.Delay(10 * 1000);
        Log.Information("Middleware finished");
    }
}

When I start the console app, I notice it creates the activity as soon as headers are available. That is, as soon as client.GetAsync finishes.

Here's how it looks in Jaeger

[cijothomas]

The activity produced by HttpClient stops when the 1st byte is received I think, so the time to read the full response body is not included.

Related: #3277

[Vlad-Stryapko]

@cijothomas
Makes sense. I've decided I'll manually instrument the full time to get the response since that's what I need; I'd appreciate a note in the HTTP lib documentation. If it's OK, I can add the note myself via a PR.

[cijothomas]

A pr is most welcome. it'll be a good 1st step towards #3277