Endless HttpMessageHandler cleanup cycle with C# cmdlets using .NET generic host

[markm77]

area-Extensions-HttpClientFactory

Hi there,

I have a c# PowerShell module with cmdlets that make use of the .NET generic host. It uses .NET standard 2.1.

Unfortunately after a few calls to the cmdlets I start to get endless debug messages in the PowerShell terminal....

dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[100]
      Starting HttpMessageHandler cleanup cycle with 1 items

I looked at this thread (aspnet/HttpClientFactory#165) and used JetBrains' dotMemory to force a garbage collection but it doesn't fix it.

I did the shortest path analysis below but to be honest I'm not sure entirely how to interpret it.

Any help appreciated....

[ghost]

Tagging subscribers to this area: @dotnet/ncl
Notify danmosemsft if you want to be subscribed.

[scalablecory]

Do you have a small repro demonstrating this?

[markm77]

Thanks very much for the comment @scalablecory . The repo where this problem occus is actually https://github.com/markm77/open-banking-connector-csharp - the PS module project is https://github.com/markm77/open-banking-connector-csharp/tree/master/src/OpenBankingConnector.Configuration. This project is very much still in development but I did a big effort to create the smallest possible repro today including creating a no-action cmdlet. However this didn't work - seems a lot of the complexity is needed for a repro.

I will give creating a smallish repro another go later in the week but just to be clear the problem is now fully reproducible with the full project. After two minutes exactly the following messages occur:

 HttpMessageHandler expired after 120000ms for client 'OBC'
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[100]
      Starting HttpMessageHandler cleanup cycle with 1 items
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[101]
      Ending HttpMessageHandler cleanup cycle after 0.2079ms - processed: 0 items - remaining: 1 items
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[100]
      Starting HttpMessageHandler cleanup cycle with 1 items
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[101]
      Ending HttpMessageHandler cleanup cycle after 0.017ms - processed: 0 items - remaining: 1 items

Is there any way I can reduce this 120 s to help me create a smallish repro? Just means I don't have to wait 2 mins every time I try something.....

[markm77]

Okay, sorry for the delay with this as creating a minimal repro from a large codebase turned out to be very time-consuming esp. with the 2min test time for each change. However I've done it now so hopefully this can be finally fixed.

You can repro by creating a C# project with two source files as follows.

Project file

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

  <PropertyGroup>
    <TargetFramework>netstandard2.1</TargetFramework>
    <RuntimeIdentifier>win10-x64</RuntimeIdentifier>
    <AssemblyName>PSModuleIssueRepro</AssemblyName>
    <RootNamespace>PSModuleIssueRepro</RootNamespace>
    <CopyLocalLockFileAssemblies>true</CopyLocalLockFileAssemblies>
  </PropertyGroup>

  <ItemGroup>
    <PackageReference Include="Microsoft.Extensions.Hosting" Version="3.1.5" />
    <PackageReference Include="Microsoft.Extensions.Http" Version="3.1.5" />
    <PackageReference Include="PowerShellStandard.Library" Version="5.1.0" PrivateAssets="all">
      <PrivateAssets>All</PrivateAssets>
    </PackageReference>
  </ItemGroup>

</Project>

Cmdlet file

using System.Management.Automation;
using System.Net.Http;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Hosting;
using Microsoft.Extensions.Logging;

namespace PSModuleIssueRepro
{
    [Cmdlet(VerbsCommon.New, "Test")]
    [OutputType(typeof(void))]
    public class NewTest : Cmdlet
    {
        protected readonly IHost _host;

        public NewTest() 
        {
            var builder = new HostBuilder()
                .ConfigureServices(
                    (hostContext, services) =>
                    {
                        services.AddHttpClient("client1");
                        services.AddSingleton<IService1>(
                            sp =>
                            {
                                var hcf = sp.GetRequiredService<IHttpClientFactory>();
                                var client = hcf.CreateClient("client1");
                                return new Service1(client);
                            });
                    })
                .UseConsoleLifetime()
                .ConfigureLogging(
                    (hostingContext, logging) =>
                    {
                        logging.SetMinimumLevel(LogLevel.Debug);
                        logging.AddConsole();
                    });
            _host = builder.Build();
            _host.Start();
        }
        protected override void BeginProcessing()
        {
            WriteVerbose($"start");
        }
        protected override void ProcessRecord()
        {
            using var serviceScope = _host.Services.CreateScope();
            var _ = serviceScope.ServiceProvider.GetService<IService1>();
        }
        protected override void EndProcessing()
        {
            WriteVerbose($"end");
        }
    }
}

Service file

using System.Net.Http;

namespace PSModuleIssueRepro
{
    public interface IService1 { }
    public class Service1 : IService1
    {
        private readonly HttpClient _httpClient;
        public Service1(HttpClient httpClient)
        {
            _httpClient = httpClient;
        }
    }
}

After creating and building the project, you can then reproduce the issue by launching PowerShell 7 via pwsh and entering the following:

Import-Module .\PSModuleIssueRepro\bin\Debug\netstandard2.1\win10-x64\PSModuleIssueRepro.dll
New-Test

You will find after exactly 2 minutes you get error messages as follows and you will need to force-exit to exit the PowerShell shell (exit won't work).

dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[103]
      HttpMessageHandler expired after 120000ms for client 'client1'
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[100]
      Starting HttpMessageHandler cleanup cycle with 1 items
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[101]
      Ending HttpMessageHandler cleanup cycle after 0.7491ms - processed: 0 items - remaining: 1 items
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[100]
      Starting HttpMessageHandler cleanup cycle with 1 items
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[101]
      Ending HttpMessageHandler cleanup cycle after 0.0174ms - processed: 0 items - remaining: 1 items

Hopefully this is sufficient info to repro the problem, feel free to ask any follow-up questions etc....

[ericstj]

I believe the logging is by-design. It looks to me like your Service is keeping a reference to the HttpClient and that will keep the handler rooted. The service is registered as a singleton which I think means the service will be created once and kept alive for the lifetime of the host and the host will be kept alive by the cmdlet instance. The logging is just because you've enabled debug level logging and this debug statement is telling you the handler is still rooted by something after time has passed.

/cc @davidfowl @maryamariyan to check my understanding here. FYI @dotnet/ncl

[Lechus]

@markm77 more info @ #28842
Just add a filter to logging to not show it.

[davidfowl]

That's right.

[markm77]

Thanks people for comments. So I guess the Cmdlet class instance and _host field are staying around even though the user PowerShell command has completed, right? I had assumed PowerShell would spin up an instance of the class each time the cmdlet was invoked from PowerShell and then tear it down but looks like I'm wrong. Logging is enabled to capture C# library logs as the cmdlets I am building are an admin interface for a bigger C# application. Logging is configured in app settings in the same way as for the web (ASP.NET Core) interface to the same C# application (I am trying to keep these two front-ends as similar as possible for ease of use and debug.) But I should be able to work out a way around this. Thanks for the help! I'll close this shortly after any replies.

[ericstj]

I guess the Cmdlet class instance and _host field are staying around even though the user PowerShell command has completed

I'm not too familiar on Cmdlet lifecycles but that's what it would seem like from what you shared. @daxian-dbw or @SteveL-MSFT might know.

If you found that the lifetime of the Cmdlet was too long, you could always use a WeakReference for the host or the HttpClient and then recreate it as needed if it was no longer alive.

[davidfowl]

You need to dispose the host in order to dispose the service provider which will dispose the other services.

[daxian-dbw]

I had assumed PowerShell would spin up an instance of the class each time the cmdlet was invoked from PowerShell and then tear it down

Yes, that's exactly what PowerShell does to invoke a cmdlet. If your cmdlet class implements IDisposible, then PowerShell will call its Dispose method after the invocation, so you can dispose the host there like @davidfowl said.

Here is an example:

using System;
using System.Management.Automation;

namespace dotnet3
{
    [Cmdlet(VerbsCommon.New, "Test")]
    public class NewTest : Cmdlet, IDisposable
    {
        protected override void BeginProcessing()
        {
            WriteVerbose("Processing");
        }

        public void Dispose()
        {
            Console.WriteLine("instance was disposed.");
        }
    }
}

Invocation of New-Test looks like this:

[markm77]

Hi there,

Thanks for all this info and sorry to be slow getting back to this due to overload.

I was going to close this call except I still have a problem.

I implemented IDisposable and added the following method to NewTest:

        public void Dispose()
        {
            _host.StopAsync();
            Console.WriteLine("Host stopped.");
        }

But this did not solve the issue even though logging shows the NewTest class was disposed. Do I need to do something more to dispose the IHost beyond just stopping it?

There is also an architecture decision here for me which someone might have a view on. Should I have a single IHost which is shared by all cmdlets and lives forever or should I spin up an IHost per cmdlet invocation making sure IHost setup/teardown works properly? Obviously the current situation of a new IHost every cmdlet invocation which is not disposed is undesirable but thinking what might be best to replace it with. (I will also update the HttpClient design.)

I had some issues with one IHost per Xunit test recently and resolved these successfully by sharing an IHost between multiple Xunit tests via a fixture so maybe I should try a similar approach here to avoid IHost setup/teardown penalty.

BR,
Mark

[davidfowl]

Yes, you need to call IHost.Dispose

[markm77]

Like this?

        public async void Dispose()
        {
            await _host.StopAsync();
            _host.Dispose();
            Console.WriteLine("Host disposed.");
        }

[markm77]

Unfortunately above code doesn't solve issue either....

[davidfowl]

No, not like like, like this:

public async Dispose()
{
    _host.Dispose();
    Console.WriteLine("Host disposed.");
}

[markm77]

Thanks @davidfowl . Sadly below which I think you meant still produces the problem....

        public void Dispose()
        {
            _host.Dispose();
            Console.WriteLine("Host disposed3.");
        }

[davidfowl]

Is it being called?

[markm77]

Yeah, I put "3" on the log to make sure the code is called.

PowerShell log....

=====> PowerShell Preview Integrated Console v2020.7.0 <=====

PS C:\ReposTmp\PSModuleIssueRepro> c:\ReposTmp\PSModuleIssueRepro\PSModuleIssueRepro\Scripts\TestScript5.ps1
Microsoft (R) Build Engine version 16.6.0+5ff7b0c9e for .NET Core
Copyright (C) Microsoft Corporation. All rights reserved.        

  Determining projects to restore...
  All projects are up-to-date for restore.
  PSModuleIssueRepro -> C:\ReposTmp\PSModuleIssueRepro\PSModuleIssueRepro\bin\Debug\netstandard2.1\PSModuleIssueRepro.dll
  PSModuleIssueRepro -> C:\ReposTmp\PSModuleIssueRepro\PSModuleIssueRepro\bin\Debug\netstandard2.1\publish\
VERBOSE: Loading module from path 'C:\ReposTmp\PSModuleIssueRepro\PSModuleIssueRepro\bin\Debug\netstandard2.1\publish\PSModuleIssueRepro.dll'.
VERBOSE: Importing cmdlet 'New-Test'.
VERBOSE: Environment ready

dbug: Microsoft.Extensions.Hosting.Internal.Host[1]    
      Hosting starting
info: Microsoft.Hosting.Lifetime[0]
      Application started. Press Ctrl+C to shut down.  
VERBOSE: start
info: Microsoft.Hosting.Lifetime[0]
      Hosting environment: Production
info: Microsoft.Hosting.Lifetime[0]
      Content root path: C:\Program Files\PowerShell\7\
dbug: Microsoft.Extensions.Hosting.Internal.Host[2]    
      Hosting started
VERBOSE: end
Host disposed3.
VERBOSE: New-Test: output


PS C:\ReposTmp\PSModuleIssueRepro\PSModuleIssueRepro\Scripts> dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[103]
      HttpMessageHandler expired after 120000ms for client 'client1'
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[100]
      Starting HttpMessageHandler cleanup cycle with 1 items
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[101]
      Ending HttpMessageHandler cleanup cycle after 0.7407ms - processed: 0 items - remaining: 1 items
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[100]
      Starting HttpMessageHandler cleanup cycle with 1 items
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[101]
      Ending HttpMessageHandler cleanup cycle after 0.0163ms - processed: 0 items - remaining: 1 items
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[100]
      Starting HttpMessageHandler cleanup cycle with 1 items
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[101]
      Ending HttpMessageHandler cleanup cycle after 0.0174ms - processed: 0 items - remaining: 1 items
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[100]
      Starting HttpMessageHandler cleanup cycle with 1 items
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[101]

[markm77]

Here's my test script. I tend to re-publish and import module into PowerShell when testing (as script shows) so I can re-build module in C# without having to make sure the DLL is unloaded from PowerShell. I simply restart PowerShell in VS Code and run to pick up latest module build.

$VerbosePreference = "Continue"
[bool] $UsePublish = $true

if ($UsePublish) {
  if (-not (Test-Path env:ModulePublished)) {
    Push-Location C:\ReposTmp\PSModuleIssueRepro\PSModuleIssueRepro
    dotnet publish
    Pop-Location
    $env:ModulePublished = 'true' 
  }
  $importDir = "C:\ReposTmp\PSModuleIssueRepro\PSModuleIssueRepro\bin\Debug\netstandard2.1\publish\PSModuleIssueRepro.dll"
}
else {
  $importDir = "C:\ReposTmp\PSModuleIssueRepro\PSModuleIssueRepro\bin\Debug\netstandard2.1\PSModuleIssueRepro.dll"
}

import-module $importDir

write-verbose ("Environment ready" + [Environment]::NewLine)

$myOutput = New-Test
write-verbose ("New-Test: output" + [Environment]::NewLine + ($myOutput | out-string).trim() + [Environment]::NewLine)

[tmp1k]

I have this same concern as well. except for me the remaining count keeps increasing.

Microsoft.Extensions.Http.DefaultHttpClientFactory: Debug: Starting HttpMessageHandler cleanup cycle with 6 items
Microsoft.Extensions.Http.DefaultHttpClientFactory: Debug: Ending HttpMessageHandler cleanup cycle after 0.0024ms - processed: 0 items - remaining: 6 items

so far i haven't seen the remaining item count decrease. it's counting over 15 items now. been running for a good several minutes now. wondering why the cleanup cycle doesn't seem to be doing anything
Debug: Ending HttpMessageHandler cleanup cycle after 0.0031ms - processed: 0 items - remaining: 16 items

I was thinking the httpClientFactory should be managing this. Should I expect that remaining count to drop back to 0?

Basically I register a named http client with some retry policy extension method that applies a polly policy

services.AddHttpClient("MyHttpClient", o =>
{
    var baseUrl = Configuration["MyApi:BaseUrl"];
    o.BaseAddress = new Uri(baseUrl);
    o.DefaultRequestHeaders.Authorization = new System.Net.Http.Headers.AuthenticationHeaderValue("Bearer", Configuration["MyApi:AccessToken"]);
})
 .WithTransientWaitAndRetryLoggingPolicy<MyApiDataProvider>(numberOfRetires: 3);

then register a service that depends on IHttpClientFactory, which will use the factory to create the named client to issue a get request

services.AddTransient<MyApiDataProvider>();

public MyApiDataProvider(IHttpClientFactory httpClientFactory)
{
    _httpClientFactory = httpClientFactory ?? throw new ArgumentNullException(nameof(httpClientFactory));
}
 public async Task<ApiResponse> GetAsync(string id)
{
    var requestUrl = $"resource/{id}/data}";
    var httpClient = _httpClientFactory.CreateClient("MyHttpClient");
    var response = await httpClient.GetAsync(requestUrl);
    var responseResult = JsonSerializer.Deserialize<ApiResponse>(await response.Content.ReadAsStringAsync());
    responseResult .IsSuccess = response.IsSuccessStatusCode;
    return responseResult ;
}

then I have a hosted background service that depends on the Api data provider service and just keeps polling an api for new data on some wait interval

services.AddHostedService<MyBackgroundService>();

public MyBackgroundService(MyApiDataProvider apiDataProvider)
{
    _apiDataProvider = apiDataProvider?? throw new ArgumentNullException(nameof(apiDataProvider));
}

protected override async Task ExecuteAsync(CancellationToken cancellationToken)
{
        while (!cancellationToken.IsCancellationRequested)
        {
             var result = await _apiDataProvider.GetAsync(id);

             await Process(result);

             await Task.Delay(TimeSpan.FromSeconds(_waitInterval.TotalSeconds), cancellationToken).ConfigureAwait(false);
        }
}

I also tried registering a typed httpClient and injecting an HttpClient dependency into MyApiDataProvider.
Then injecting the IServiceProvider into the background service to ask for an instance of apiDataProvider from the services provider, thinking the httpclientfactory would be in play providing the apiDataProvider with a proper client; but I observed the same debug messages with the remaining count just increasing.

If I just inject an httpClient into the typed client, and inject the typed client into the background service, the remaining count stays at 1 which makes since since the background service is holding onto that one instance.

[tmp1k]

services.AddTransient();

public MyApiDataProvider(IHttpClientFactory httpClientFactory)
{
_httpClientFactory = httpClientFactory ?? throw new ArgumentNullException(nameof(httpClientFactory));
}
public async Task GetAsync(string id)
{
var requestUrl = $"resource/{id}/data}";
var httpClient = _httpClientFactory.CreateClient("MyHttpClient");
var response = await httpClient.GetAsync(requestUrl);
var responseResult = JsonSerializer.Deserialize(await response.Content.ReadAsStringAsync());
responseResult .IsSuccess = response.IsSuccessStatusCode;
return responseResult ;
}

missing a using statement for the httpClient obtained from the factory. could that be my oversight. i think if the count stays at 1 that means previous instances are getting cleaned and perhaps the last used one is still holding but that should be OK.
but even with using var httpClient = _httpClientFactory.CreateClient("MyHttpClient"); i still observe the remaining count increases.

i set a breakpoint startup where the base address and authentication header gets set and the breakpoint gets hit each time which is expected.

[rf-0]

@tmp1k Did you find a solution? I also have a scoped service (AddScoped) with an injected http client (AddHttpClient).

Disposing of the http client manually (Dispose()) doesn't seem to solve it.

[maleowy]

net 6, AddHttpClient() and named client configuration at composition root, using mostly transient services with injected IHttpClientFactory which creates named clients. Is using HttpClient more than that? I see plenty of cleanup in logs and my service that uses http client is not operational because of that :/

[Prikalel]

Ok, i've done my infinitive loop like this https://learn.microsoft.com/en-us/aspnet/core/fundamentals/host/hosted-services?view=aspnetcore-5.0&tabs=visual-studio and now the server can be stopped.👌

[Ludwintor]

Still no solution on this? All my services are transient but everytime HttpMessageHandler gets expired after 2 minutes - it justs stacks items for cleanup cycle and nothing is processed but sometimes after stacking some more items its just randomly processes some of (but not all) remaining items and overall unprocessed items keeps increasing

And after long time of spamming in logs about cleanups it just sometimes cleanup them all. Is it intentional behaviour and I just have to supress these logs?

[justinpenguin45]

Same

[HellGate94]

add another one to the list

[thakurarun]

Adding one more-

[CarnaViire]

This works as expected.

The cleanup can only process the handlers that were garbage collected. Until your app triggers a GC, the clean up is not able to verify that the handlers are not used anymore.

For the illustration purposes, here is an example of manually triggering Full GC (full src in the end of the post):

services.AddKeyedTransient<DisposeTrackingHandler>(KeyedService.AnyKey);
services.ConfigureHttpClientDefaults(b => b.SetHandlerLifetime(TimeSpan.FromSeconds(5)));

services.AddHttpClient("discard")
    .AddHttpMessageHandler(sp => sp.GetRequiredKeyedService<DisposeTrackingHandler>("discard"));

// ...

_ = httpClientFactory.CreateClient("discard");

PrintAliveHandlers();
await Delay30s();

GcCollect();
await Delay30s();

PrintAliveHandlers();

// -----

void GcCollect()
{
    log.LogInformation("GcCollect");
    GC.Collect();
    GC.WaitForPendingFinalizers();
    GC.Collect();
}

Which shows that after GC the handler gets successfully processed and disposed:

info: Program[0]
      Creating 'discard'
trce: DisposeTrackingHandler[0]
      _name='discard', .ctor
info: Program[0]
      Alive handlers: [ discard ]
trce: Program[0]
      Delay30s
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[103]
      HttpMessageHandler expired after 5000ms for client 'discard'
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[100]
      Starting HttpMessageHandler cleanup cycle with 1 items
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[101]
      Ending HttpMessageHandler cleanup cycle after 0.1875ms - processed: 0 items - remaining: 1 items
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[100]
      Starting HttpMessageHandler cleanup cycle with 1 items
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[101]
      Ending HttpMessageHandler cleanup cycle after 0.0016ms - processed: 0 items - remaining: 1 items
info: Program[0]
      GcCollect
trce: Program[0]
      Delay30s
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[100]
      Starting HttpMessageHandler cleanup cycle with 1 items
trce: DisposeTrackingHandler[0]
      _name='discard', Dispose
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[101]
      Ending HttpMessageHandler cleanup cycle after 0.7665ms - processed: 1 items - remaining: 0 items
info: Program[0]
      Alive handlers: [  ]

---

If GC doesn't help, it is possible a handler is erroneously rooted (saved in a field or in a variable) for the prolonged period of time, so it can't be collected in time.

services.AddHttpClient("rooted")
    .AddHttpMessageHandler(sp => sp.GetRequiredKeyedService<DisposeTrackingHandler>("rooted"));

services.AddHttpClient("weak-ref")
    .AddHttpMessageHandler(sp => sp.GetRequiredKeyedService<DisposeTrackingHandler>("weak-ref"));

// ...

log.LogInformation($"Creating 'rooted'");
var rootedClient = httpClientFactory.CreateClient("rooted");

log.LogInformation($"Creating 'weak-ref'");
var weakRefClient = httpClientFactory.CreateClient("weak-ref");
var weakRef = new WeakReference(weakRefClient);
weakRefClient = null;

PrintAliveHandlers();
await Delay30s();

GcCollect();
await Delay30s();

PrintAliveHandlers();

log.LogInformation("Unrooting 'rooted'");
rootedClient.Dispose();
rootedClient = null;

GcCollect();
await Delay30s();

PrintAliveHandlers();

You can see that weak-ref got cleaned up right away, while rooted had to wait until it was not rooted anymore

info: Program[0]
      Creating 'rooted'
trce: DisposeTrackingHandler[0]
      _name='rooted', .ctor
info: Program[0]
      Creating 'weak-ref'
trce: DisposeTrackingHandler[0]
      _name='weak-ref', .ctor
info: Program[0]
      Alive handlers: [ rooted, weak-ref ]
trce: Program[0]
      Delay30s
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[103]
      HttpMessageHandler expired after 5000ms for client 'rooted'
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[103]
      HttpMessageHandler expired after 5000ms for client 'weak-ref'
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[100]
      Starting HttpMessageHandler cleanup cycle with 2 items
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[101]
      Ending HttpMessageHandler cleanup cycle after 0.1766ms - processed: 0 items - remaining: 2 items
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[100]
      Starting HttpMessageHandler cleanup cycle with 2 items
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[101]
      Ending HttpMessageHandler cleanup cycle after 0.0022ms - processed: 0 items - remaining: 2 items
info: Program[0]
      GcCollect
trce: Program[0]
      Delay30s
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[100]
      Starting HttpMessageHandler cleanup cycle with 2 items
trce: DisposeTrackingHandler[0]
      _name='weak-ref', Dispose
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[101]
      Ending HttpMessageHandler cleanup cycle after 0.9956ms - processed: 1 items - remaining: 1 items
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[100]
      Starting HttpMessageHandler cleanup cycle with 1 items
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[101]
      Ending HttpMessageHandler cleanup cycle after 0.0017ms - processed: 0 items - remaining: 1 items
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[100]
      Starting HttpMessageHandler cleanup cycle with 1 items
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[101]
      Ending HttpMessageHandler cleanup cycle after 0.0026ms - processed: 0 items - remaining: 1 items
info: Program[0]
      Alive handlers: [ rooted ]
info: Program[0]
      Unrooting 'rooted'
info: Program[0]
      GcCollect
trce: Program[0]
      Delay30s
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[100]
      Starting HttpMessageHandler cleanup cycle with 1 items
trce: DisposeTrackingHandler[0]
      _name='rooted', Dispose
dbug: Microsoft.Extensions.Http.DefaultHttpClientFactory[101]
      Ending HttpMessageHandler cleanup cycle after 0.05ms - processed: 1 items - remaining: 0 items
info: Program[0]
      Alive handlers: [  ]

---

Complete runnable example

using System.Runtime.CompilerServices;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Logging;

var services = new ServiceCollection();

services.AddLogging(b => b
    .ClearProviders()
    .AddConsole()
    .SetMinimumLevel(LogLevel.Trace));

services.AddKeyedTransient<DisposeTrackingHandler>(KeyedService.AnyKey);

services.ConfigureHttpClientDefaults(b => b.SetHandlerLifetime(TimeSpan.FromSeconds(5)));

services.AddHttpClient("rooted")
    .AddHttpMessageHandler(sp => sp.GetRequiredKeyedService<DisposeTrackingHandler>("rooted"));

services.AddHttpClient("weak-ref")
    .AddHttpMessageHandler(sp => sp.GetRequiredKeyedService<DisposeTrackingHandler>("weak-ref"));

services.AddHttpClient("discard")
    .AddHttpMessageHandler(sp => sp.GetRequiredKeyedService<DisposeTrackingHandler>("discard"));

var serviceProvider = services.BuildServiceProvider();

// ---

var log = serviceProvider.GetRequiredService<ILogger<Program>>();
var httpClientFactory = serviceProvider.GetRequiredService<IHttpClientFactory>();

log.LogInformation($"Creating 'rooted'");
var rootedClient = httpClientFactory.CreateClient("rooted");

log.LogInformation($"Creating 'weak-ref'");
var weakRefClient = httpClientFactory.CreateClient("weak-ref");
var weakRef = new WeakReference(weakRefClient);
weakRefClient = null;

log.LogInformation($"Creating 'discard'");
_ = httpClientFactory.CreateClient("discard");

// ---

PrintAliveHandlers();
await Delay30s();

GcCollect();
await Delay30s();

PrintAliveHandlers();

log.LogInformation("Unrooting 'rooted'");
rootedClient.Dispose();
rootedClient = null;

GcCollect();
await Delay30s();

PrintAliveHandlers();

// ----------------------------------------------------------------

void GcCollect()
{
    log.LogInformation("GcCollect");
    GC.Collect();
    GC.WaitForPendingFinalizers();
    GC.Collect();
}

async Task Delay30s()
{
    log.LogTrace("Delay30s");
    await Task.Delay(TimeSpan.FromSeconds(30));
}

void PrintAliveHandlers()
{
    log.LogInformation("Alive handlers: [ {list} ]", DisposeTrackingHandler.GetNames());
}

// ----------------------------------------------------------------

class DisposeTrackingHandler : DelegatingHandler
{
    private static readonly List<string> _instanceNames = [];
    public static string GetNames()
    {
        lock (_instanceNames)
        {
            return string.Join(", ", _instanceNames);
        }
    }

    private readonly ILogger<DisposeTrackingHandler> _log;
    private readonly string _name;

    private bool _disposed;

    public DisposeTrackingHandler([ServiceKey] string name, ILogger<DisposeTrackingHandler> log)
    {
        _log = log;
        _name = name;

        Trace();
        lock (_instanceNames)
        {
            _instanceNames.Add(_name);
        }
    }

    protected override void Dispose(bool disposing)
    {
        if (_disposed)
        {
            return;
        }
        _disposed = true;

        Trace();
        base.Dispose(disposing);
        lock (_instanceNames)
        {
            _instanceNames.Remove(_name);
        }
    }

    private void Trace([CallerMemberName] string? memberName = null) => _log.LogTrace("_name='{name}', {memberName}", _name, memberName ?? "(?)");
}

[CarnaViire]

Triage: Closing as answered above.
If there's something we missed, please let us know. Thanks!