Серьезная задержка с использованием HttpClient в сочетании с NServiceBus

Question

Серьезная задержка с использованием HttpClient в сочетании с NServiceBus

Я делаю интеграцию POC, используя NServiceBus. Эта интеграция запускает уведомления API, когда что-то происходит.

Все это работает, но серьезные проблемы с производительностью возрастают при выполнении параллельных HTTP-запросов.

У меня настроена конечная точка, которая выполняет одно: отправка запроса (уведомления) json в REST API.

Моя настройка:

Конечная точка (каркас 4.6.1) имеет 1 статический HttpClient, который инициализируется только один раз при запуске программы:

internal static void Intitialize()
        {
            ServicePointManager.DefaultConnectionLimit = 100;
            var apiSettings = NotificationEngineManager.GetInterfaceSettings()?.API;
            NotificationClient = new HttpClient();
            NotificationClient.Timeout = TimeSpan.FromSeconds(45);
            if (!string.IsNullOrEmpty(apiSettings.UserName))
            {
                var byteArray = Encoding.ASCII.GetBytes($"{apiSettings.UserName}:{apiSettings.Password}");
                NotificationClient.DefaultRequestHeaders.Authorization = new AuthenticationHeaderValue("Basic", Convert.ToBase64String(byteArray));
            }
        }

        internal static HttpClient NotificationClient { get; set; }

Мой обработчик отвечает за размещение запросов:

   public async Task Handle(EventRegistered message, IMessageHandlerContext context)
            {
                var apiSettings = NotificationEngineManager.GetInterfaceSettings()?.API;
                if (apiSettings == null)
                {
                    throw new BusinessException("No valid API settings found");
                }

                JsonSerializerSettings settings = new JsonSerializerSettings();
                settings.NullValueHandling = NullValueHandling.Ignore;
                settings.DateFormatString = "s";
                settings.Converters.Add(new StringEnumConverter { });


                try
                {
                    var jsonRequest = JsonConvert.SerializeObject(message.Notification, settings);
                    var response = await HttpClients.NotificationClient.PostAsync(apiSettings.Endpoint, new StringContent(jsonRequest, Encoding.UTF8, "application/json"));
                    response.EnsureSuccessStatusCode();
                }
                catch (TaskCanceledException)
                {
                    throw new Exception("Notifiaction Request timed out.");
                }

                await context.Publish(new NotificationSent(message, DateTime.Now)).ConfigureAwait(false);

}

Эта проблема:

Конечная точка NServiceBus обрабатывает 10 сообщений одновременно, что означает 10 запросов HTTP post одновременно.

API остальных занимает около 0,2 с, чтобы ответить на 1 сообщение. Но одновременный запуск 10 http-запросов занимает около 35 секунд. Все запросы начинаются одновременно, но также и заканчиваются в одно и то же время, что примерно через 35 секунд.

С помощью netstat Команда Я вижу 10 открытых TCP-подключений к API. Таким образом, HttpClient обрабатывает параллельные запросы.

Странно то, что если я установил параллелизм моей конечной точки на 1, то есть запросы http обрабатываются 1 на 1, все 10 запросов были обработаны в течение 2 секунд.

Если я установлю уровень параллелизма моей конечной точки равным 20 или более, время ожидания почти для всех запросов (тайм-аут = 45 с).

То же самое можно воспроизвести, используя HttpWebRequest вместо HttpClient.

Я в недоумении здесь. Что мне не хватает? Похоже, что все запросы ожидают друг друга, либо на клиенте, либо на сервере. Любая помощь очень ценится.

Rest API - это базовый.NET Core API, работающий на ISS (не экспресс).

// POST api/notification
        [HttpPost]
        [Authorize]
        public async Task<IActionResult> Post([FromBody] Notification notification)
        {
            try
            {
                return Accepted();
            }
            catch (Exception ex)
            {

                return BadRequest(ex);
            }

        }

ОБНОВЛЕНИЕ: Журнал на стороне клиента (nservicebus) и на стороне сервера (api). Оба работают в режиме отладки на локальном хосте и легко воспроизводятся.

сторона клиента

    log.Info($"Start request {message.Event.Id.ToString()}");
                    var response = await HttpClients.NotificationClient.PostAsync(apiSettings.Endpoint, new StringContent(jsonRequest, Encoding.UTF8, "application/json"));              
                    response.EnsureSuccessStatusCode();
                    log.Info($"Stop request {message.Event.Id.ToString()}");

2018-04-18 09:05:23.2886 INFO NOTIFY_WO_OUT 8 Start request
2018-04-18 09:05:23.2886 INFO NOTIFY_WO_OUT 10 Start request
2018-04-18 09:05:23.2886 INFO NOTIFY_WO_OUT 5 Start request
2018-04-18 09:05:23.2886 INFO NOTIFY_WO_OUT 2 Start request
2018-04-18 09:05:23.2886 INFO NOTIFY_WO_OUT 4 Start request
2018-04-18 09:05:23.6336 INFO NOTIFY_WO_OUT 6 Start request
2018-04-18 09:05:24.6329 INFO NOTIFY_WO_OUT 9 Start request
2018-04-18 09:05:25.6142 INFO NOTIFY_WO_OUT 1 Start request
2018-04-18 09:05:26.6544 INFO NOTIFY_WO_OUT 7 Start request
2018-04-18 09:05:27.6545 INFO NOTIFY_WO_OUT 3 Start request
2018-04-18 09:05:47.2034 INFO NOTIFY_WO_OUT 5 Stop request
2018-04-18 09:05:47.6285 INFO NOTIFY_WO_OUT 3 Stop request
2018-04-18 09:05:47.9855 INFO NOTIFY_WO_OUT 6 Stop request
2018-04-18 09:05:48.0550 INFO NOTIFY_WO_OUT 9 Stop request
2018-04-18 09:05:48.5226 INFO NOTIFY_WO_OUT 4 Stop request
2018-04-18 09:05:48.5526 INFO NOTIFY_WO_OUT 10 Stop request
2018-04-18 09:05:48.9987 INFO NOTIFY_WO_OUT 8 Stop request
2018-04-18 09:05:49.0347 INFO NOTIFY_WO_OUT 1 Stop request
2018-04-18 09:05:49.0647 INFO NOTIFY_WO_OUT 7 Stop request
2018-04-18 09:05:49.3017 INFO NOTIFY_WO_OUT 2 Stop request

регистрация на стороне сервера. Промежуточное программное обеспечение добавлено в начало конвейера.

2018-04-18 09:05:38.7660 INFO Begin Request 6
2018-04-18 09:05:38.7850 INFO message 6 received
2018-04-18 09:05:38.8150 INFO End Request 6
2018-04-18 09:05:39.4036 INFO Begin Request 9
2018-04-18 09:05:39.4231 INFO message 9 received
2018-04-18 09:05:39.4551 INFO End Request 9
2018-04-18 09:05:39.7172 INFO Begin Request 10
2018-04-18 09:05:39.7512 INFO message 10 received
2018-04-18 09:05:39.7512 INFO Begin Request 8
2018-04-18 09:05:39.7812 INFO End Request 10
2018-04-18 09:05:39.8132 INFO message 8 received
2018-04-18 09:05:39.8302 INFO End Request 8
2018-04-18 09:05:40.0722 INFO Begin Request 1
2018-04-18 09:05:40.1097 INFO message 1 received
2018-04-18 09:05:40.1097 INFO Begin Request 5
2018-04-18 09:05:40.1413 INFO message 5 received
2018-04-18 09:05:40.1703 INFO End Request 1
2018-04-18 09:05:40.1913 INFO End Request 5
2018-04-18 09:05:40.4033 INFO Begin Request 3
2018-04-18 09:05:40.4403 INFO message 3 received
2018-04-18 09:05:40.4563 INFO End Request 3
2018-04-18 09:05:40.5173 INFO Begin Request 7
2018-04-18 09:05:40.5508 INFO message 7 received
2018-04-18 09:05:40.5663 INFO End Request 7
2018-04-18 09:05:41.0100 INFO Begin Request 4
2018-04-18 09:05:41.0470 INFO message 4 received
2018-04-18 09:05:41.0630 INFO End Request 4
2018-04-18 09:05:41.3535 INFO Begin Request 2
2018-04-18 09:05:41.3740 INFO message 2 received
2018-04-18 09:05:41.4080 INFO End Request 2

Просмотр запроса 8. Запрос был инициирован в коде.23. Сервер получил запрос на.39. Таким образом, разрыв составляет 16 секунд.

1

c# dotnet-httpclient nservicebus

Источник

user1679668 16 апр '18 в 15:34

1 ответ

Решение

Другие вопросы по тегам c# dotnet-httpclient nservicebus

user1679668 18 апр '18 в 09:47 2018-04-18 09:47 · Accepted Answer · 2018-04-18 09:47

Я регистрировал трассировку сети, используя System.Diagnostics и NLog. Это вызывало серьезное падение производительности.

Отключение System.Diagnostics решило мою проблему.

1

Источник

user1679668 18 апр '18 в 09:47