Странное ведение журнала HttpClient по завершению запроса задолго до завершения GetAsync

Question

Я делаю несколько HTTP-запросов к REST API, который возвращает довольно много данных (около 100 МБ). Я сейчас использовал HttpClientFactory из.Net Core, чтобы получить данные, и он отлично работает. Но то, что озадачило меня, - это несоответствие между моим временем и внутренним временем, которое исходит из самой библиотеки.

Вот пример сообщения из библиотеки:

Завершить обработку HTTP-запроса после 130311.0094мс - ОК

Дело в том, что действительно требуется 20-30 секунд, чтобы действительно загрузить все данные, даже если библиотека написала, что все закончено (выполнить client.GetAsync() метод).

Я предполагаю, что здесь происходит то, что библиотека очень хочет сообщать сразу после получения заголовка, не дожидаясь загрузки тела.

Это действительно звучит как ошибка, но я не уверен, что это так. Может быть, у кого-то есть лучшее объяснение того, почему это происходит?

PS Вот пример моего кода:

Stopwatch watch = new Stopwatch();
watch.Start();
var response = await Client.GetAsync(url);
watch.Stop();
Console.WriteLine($"Elapsed time {watch.ElapsedMilliseconds} ms");

Истекшее время в моем журнале намного выше, чем в системном сообщении.

PPS я пробовал работать с HttpCompletionOption.ResponseContentRead но это действительно не изменило результат, это все еще большая разница.

Answer 1

Похоже, что именно так промежуточное ПО в HttpClient работает, что используется каркасом логирования. По какой-то причине загрузка тела происходит вне конвейера, поэтому регистрация всегда происходит сразу после получения заголовков.

Более подробно в этом вопросе на github.