Поделиться через

Диагностика и устранение неполадок, связанных с медленным выполнением запросов пакета SDK Azure Cosmos DB для .NET

  • Статья

ОБЛАСТЬ ПРИМЕНЕНИЯ: NoSQL

В Azure Cosmos DB можно заметить замедление выполнения запросов. Задержки могут происходить по разным причинам, например из-за регулирования запросов или архитектуры вашего приложения. В этой статье описаны разные первопричины этой проблемы.

Высокая частота запросов

Регулирование запросов — самая распространенная причина их медленного выполнения. Azure Cosmos DB регулирует запросы, если они используют больше единиц запросов, чем выделено для базы данных или контейнера. В пакете SDK имеется встроенная логика для повторного выполнения таких запросов. В статье, посвященной устранению неполадок, связанных со слишком высокой частотой запросов, рассказывается, как проверить, выполняется ли регулирование запросов, и как масштабировать учетную запись, чтобы избежать подобных проблем в будущем.

Проектирование приложений

При проектировании приложения следуйте рекомендациям по использованию пакета SDK для .NET, чтобы обеспечить наилучшую производительность. Если ваше приложение не соответствует рекомендациям SDK, запросы могут выполняться медленно или завершаться сбоем.

При разработке приложения учитывайте указанные ниже моменты.

Операции с метаданными

Если вам нужно проверить существование базы данных или контейнера, не делайте этого путем вызова Create...IfNotExistsAsync или Read...Async перед выполнением операции с элементом. Такая проверка должна выполняться только при запуске приложения, когда она необходима, т/ е. если вы ожидаете удаления объектов (в противном случае она не требуется). Эти операции с метаданными вызывают дополнительную задержку, не поддерживают соглашения об уровне обслуживания и имеют собственные отдельные ограничения. Они не масштабируются как операции с данными.

Медленные запросы в режиме массовой передачи

Режим массовой передачи — это режим, оптимизированный для увеличения пропускной способности. Он предназначен для передачи больших объемов данных и не является режимом для оптимизации задержки. Он предназначен для того, чтобы эффективно использовать доступную пропускную способность. Если при использовании режима массовой передачи запросы выполняются медленно, убедитесь в следующем:

  • Приложение скомпилировано в конфигурации выпуска.
  • Вы не измеряете задержку при отладке приложения (отладчики не подключены).
  • Объем операций высокий — не используйте для менее 1000 операций. Подготовленная пропускная способность определяет, сколько операций в секунду можно обработать. Ваша цель — использовать как можно больше пропускной способности.
  • Отслеживайте в контейнере возникновение сценариев регулирования. Если контейнер постоянно регулируется, то объем данных больше, чем у подготовленной пропускной способности, и необходимо либо вертикально увеличить масштаб контейнера, либо уменьшить объем данных (например, за один раз создавать небольшие пакеты данных).
  • Вы правильно используете шаблон async/await для обработки всех параллельных задач и не блокируете асинхронные операции.

Сбор диагностических данных

Для всех ответов в пакете SDK, включая CosmosException, доступно свойство Diagnostics. В это свойство записываются все сведения, связанные с одним запросом, в том числе сведения о повторных попытках и временных сбоях.

Система возвращает данные свойства в виде строки. От версии к версии содержимое этой строки изменяется. Это связано с совершенствованием программного обеспечения для улучшения процесса устранения неполадок в различных сценариях. В каждой версии пакета SDK будут критические изменения форматирования этой строки. Не анализируйте эту строку, чтобы избежать проблем, связанных с критическими изменениями. В следующем примере кода показано, как выполнять чтение данных из журналов диагностики с помощью пакета SDK для .NET.

try
{
    ItemResponse<Book> response = await this.Container.CreateItemAsync<Book>(item: testItem);
    if (response.Diagnostics.GetClientElapsedTime() > ConfigurableSlowRequestTimeSpan)
    {
        // Log the response.Diagnostics.ToString() and add any additional info necessary to correlate to other logs 
    }
}
catch (CosmosException cosmosException)
{
    // Log the full exception including the stack trace with: cosmosException.ToString()
    
    // The Diagnostics can be logged separately if required with: cosmosException.Diagnostics.ToString()
}

// When using Stream APIs
ResponseMessage response = await this.Container.CreateItemStreamAsync(partitionKey, stream);
if (response.Diagnostics.GetClientElapsedTime() > ConfigurableSlowRequestTimeSpan || !response.IsSuccessStatusCode)
{
    // Log the diagnostics and add any additional info necessary to correlate to other logs with: response.Diagnostics.ToString()
}

Диагностика в версии 3.19 и выше

В каждой версии пакета SDK структура JSON подвергается значительным изменениям. Из-за этого небезопасно анализировать строку. JSON представляет древовидную структуру запроса, проходящего через пакет SDK. В следующих разделах рассматриваются некоторые основные моменты, которые следует учитывать.

Хронология загрузки ЦП

Высокая загрузка ЦП — самая распространенная причиной медленного выполнения запросов. Для оптимальной задержки загрузка ЦП должна составлять примерно 40 %. Используйте 10 секунд в качестве интервала для наблюдения за максимальной (не средней) загрузкой ЦП. Всплески ЦП чаще встречаются при запросах между разделами, когда запросы могут выполнять несколько подключений для одного запроса.

Истечение времени ожидания связано с диагностикой:

"systemHistory": [
{
"dateUtc": "2021-11-17T23:38:28.3115496Z",
"cpu": 16.731,
"memory": 9024120.000,
"threadInfo": {
"isThreadStarving": "False",
....
}

},
{
"dateUtc": "2021-11-17T23:38:38.3115496Z",
"cpu": 16.731,
"memory": 9024120.000,
"threadInfo": {
"isThreadStarving": "False",
....
}

},
...
]
  • Если значения cpu превышают 70 %, истечение времени ожидания, скорее всего, вызвано нехваткой ресурсов ЦП. В этом случае для решения проблемы следует изучить источник высокой загрузки ЦП и сократить ее или масштабировать компьютер, чтобы увеличить количество ресурсов.
  • Если узлы threadInfo/isThreadStarving имеют значения True, причиной является нехватка потоков. В этом случае для решения проблемы следует изучить причины нехватки потоков (потенциально заблокированные потоки) или масштабировать компьютеры, чтобы увеличить количество ресурсов.
  • Если время dateUtc между измерениями не составляет примерно 10 секунд, это также указывает на состязание в пуле потоков. Работа ЦП измеряется в виде независимых задач, которые помещаются в очередь в пул потоков каждые 10 секунд. Если время между измерениями больше, это указывает на то, что асинхронные задачи не могут быть обработаны своевременно. Наиболее распространенный сценарий заключается в том, что код приложения блокирует вызовы асинхронного кода.

Решение

Клиентское приложение, использующее пакет SDK, следует масштабировать вертикально или горизонтально.

HttpResponseStats

HttpResponseStats — это запросы, которые отправляются в шлюз. Даже в режиме непосредственного доступа пакет SDK получает все метаданные из шлюза.

Если запрос выполняется медленно, сначала убедитесь, что ни одно из предыдущих предложений не помогло решить проблему. Если запросы по-прежнему выполняются медленно, на разные проблемы будут указывать разные признаки. Дополнительные сведения см. в следующей таблице.

Количество запросов Сценарий Description
Один ко всем Истекло время ожидания запроса или HttpRequestExceptions Указывает на нехватку портов SNAT или нехватку ресурсов на компьютере для своевременной обработки запроса.
Один или небольшой процент (условия Соглашения об уровне обслуживания не нарушаются) Все Один медленно выполняемый запрос или небольшой процент таких запросов может свидетельствовать о нескольких разных временных проблемах; это ожидаемая проблема.
Все Все Указывает на проблему с инфраструктурой или сетью.
Нарушены условия Соглашения об уровне обслуживания Никаких изменений в приложении и Соглашение об уровне обслуживания отменено. Указывает на проблему в службе Azure Cosmos DB. 
"HttpResponseStats": [
    {
        "StartTimeUTC": "2021-06-15T13:53:09.7961124Z",
        "EndTimeUTC": "2021-06-15T13:53:09.7961127Z",
        "RequestUri": "https://127.0.0.1:8081/dbs/347a8e44-a550-493e-88ee-29a19c070ecc/colls/4f72e752-fa91-455a-82c1-bf253a5a3c4e",
        "ResourceType": "Collection",
        "HttpMethod": "GET",
        "ActivityId": "e16e98ec-f2e3-430c-b9e9-7d99e58a4f72",
        "StatusCode": "OK"
    }
]

StoreResult

StoreResult представляет отдельный запрос к Azure Cosmos DB с использованием режима непосредственного доступа по протоколу TCP.

Если запросы по-прежнему выполняются медленно, на разные проблемы будут указывать разные признаки. Дополнительные сведения см. в следующей таблице.

Количество запросов Сценарий Description
Один ко всем StoreResult содержит TransportException Указывает на нехватку портов SNAT или нехватку ресурсов на компьютере для своевременной обработки запроса.
Один или небольшой процент (условия Соглашения об уровне обслуживания не нарушаются) Все Один медленно выполняемый запрос или небольшой процент таких запросов может свидетельствовать о нескольких разных временных проблемах; это ожидаемая проблема.
Все Все Проблема с инфраструктурой или сетью.
Нарушены условия Соглашения об уровне обслуживания Запросы содержат несколько кодов ошибок сбоя, например 410 Указывает на проблему со службой Azure Cosmos DB или клиентским компьютером.
Нарушены условия Соглашения об уровне обслуживания Значения StorePhysicalAddress не изменены и нет кода состояния, связанного со сбоем Вероятно, проблема с Azure Cosmos DB.
Нарушены условия Соглашения об уровне обслуживания В StorePhysicalAddress указан прежний идентификатор раздела, но другие идентификаторы реплик, и нет кода состояния, связанного со сбоем. Вероятно, проблема с Azure Cosmos DB.
Нарушены условия Соглашения об уровне обслуживания Значение StorePhysicalAddress случайное и нет кода состояния, связанного со сбоем. Указывает на проблему с компьютером.

При получении нескольких результатов сохранения для одного запроса, учитывайте следующее:

  • Применение строгой согласованности и согласованности ограниченного устаревания всегда дает не менее двух результатов сохранения.
  • Проверьте код состояния для каждого StoreResult. Пакет SDK автоматически повторяет попытки при нескольких различных временных сбоях. Мы постоянно совершенствуем пакет SDK, чтобы охватить дополнительные сценарии.

RequestTimeline

Отображение времени для различных этапов отправки и получения запроса на уровне транспорта.

  • ChannelAcquisitionStarted: время получения или создания подключения. Подключения можно создать по нескольким причинам, например: предыдущее соединение было закрыто из-за неактивности с помощью CosmosClientOptions.IdleTcpConnectionTimeout, объем одновременных запросов превышает число одновременных запросов, превышающих CosmosClientOptions.MaxRequestsPerTcpConnection, подключение было закрыто из-за сетевой ошибки, или приложение не соответствует шаблону Singleton и новые экземпляры постоянно создаются. После установки подключения он повторно используется для последующих запросов, поэтому это не должно влиять на задержку P99, если ранее упомянутые проблемы не происходят.
  • Pipelined: время, затраченное на запись запроса в сокет TCP. Запрос может быть записан только в сокете TCP по одному за раз, большое значение указывает узкие места в сокете TCP, который обычно связан с заблокированными потоками с кодом приложения или большим размером запросов.
  • Transit time: время, затраченное на сеть после записи запроса на сокет TCP. Сравните это число с BELatencyInMs. Если значение BELatencyInMs мало, это означает, что время было потрачено на выполнение сетевых операций, а не на работу службы Azure Cosmos DB. Если запрос завершился сбоем со временем ожидания, он указывает, сколько времени клиент ждал без ответа, а источник — это задержка в сети.
  • Received: время между ответом было получено и обработано пакетом SDK. Обычно большое значение вызвано нехваткой или заблокированными потоками.

ServiceEndpointStatistics

Сведения о конкретном внутреннем сервере. Пакет SDK может открывать несколько подключений к одному внутреннему серверу в зависимости от количества ожидающих запросов и значения MaxConcurrentRequestsPerConnection.

  • inflightRequests — число ожидающих запросов к внутреннему серверу (возможно, от разных секций). Большое значение может привести к увеличению объема трафика и большой задержке.
  • openConnections — общее число подключений, открытых к одному внутреннему серверу. Может быть полезно для обозначения нехватки портов SNAT, если это число очень велико.

ConnectionStatistics

Сведения о конкретном подключении (новом или старом), которому назначается запрос.

  • waitforConnectionInit — текущий запрос ожидал завершения инициализации нового подключения. Это приведет к увеличению задержки.
  • callsPendingReceive — количество вызовов, ожидающих получения, до отправки этого вызова. Большое число может указывать на то, что до этого вызова уже было много вызовов, и это может привести к более высокой задержке. Если это число имеет большое значение, это может означать блокирующую проблему начала строки, возможно, вызванную другим запросом, например операцией запроса или канала, которая обрабатывается слишком долго. Попробуйте уменьшить значение CosmosClientOptions.MaxRequestsPerTcpConnection, чтобы увеличить число каналов.
  • LastSentTime — время отправки последнего запроса на этот сервер. Вместе с LastReceivedTime может использоваться для определения проблем с подключением или конечной точкой. Например, при большом числе тайм-аутов приема время отправки будет намного больше, чем время получения.
  • lastReceive — время получения последнего запроса от этого сервера.
  • lastSendAttempt — время последней попытки отправки.

Размеры запроса и ответа

  • requestSizeInBytes: общий размер запроса, отправленного в Azure Cosmos DB
  • responseMetadataSizeInBytes: размер заголовков, возвращаемых из Azure Cosmos DB
  • responseBodySizeInBytes: размер содержимого, возвращаемого из Azure Cosmos DB
"StoreResult": {
    "ActivityId": "bab6ade1-b8de-407f-b89d-fa2138a91284",
    "StatusCode": "Ok",
    "SubStatusCode": "Unknown",
    "LSN": 453362,
    "PartitionKeyRangeId": "1",
    "GlobalCommittedLSN": 0,
    "ItemLSN": 453358,
    "UsingLocalLSN": true,
    "QuorumAckedLSN": -1,
    "SessionToken": "-1#453362",
    "CurrentWriteQuorum": -1,
    "CurrentReplicaSetSize": -1,
    "NumberOfReadRegions": 0,
    "IsValid": true,
    "StorePhysicalAddress": "rntbd://127.0.0.1:10253/apps/DocDbApp/services/DocDbServer92/partitions/a4cb49a8-38c8-11e6-8106-8cdcd42c33be/replicas/1s/",
    "RequestCharge": 1,
    "RetryAfterInMs": null,
    "BELatencyInMs": "0.304",
    "transportRequestTimeline": {
        "requestTimeline": [
            {
                "event": "Created",
                "startTimeUtc": "2022-05-25T12:03:36.3081190Z",
                "durationInMs": 0.0024
            },
            {
                "event": "ChannelAcquisitionStarted",
                "startTimeUtc": "2022-05-25T12:03:36.3081214Z",
                "durationInMs": 0.0132
            },
            {
                "event": "Pipelined",
                "startTimeUtc": "2022-05-25T12:03:36.3081346Z",
                "durationInMs": 0.0865
            },
            {
                "event": "Transit Time",
                "startTimeUtc": "2022-05-25T12:03:36.3082211Z",
                "durationInMs": 1.3324
            },
            {
                "event": "Received",
                "startTimeUtc": "2022-05-25T12:03:36.3095535Z",
                "durationInMs": 12.6128
            },
            {
                "event": "Completed",
                "startTimeUtc": "2022-05-25T12:03:36.8621663Z",
                "durationInMs": 0
            }
        ],
        "serviceEndpointStats": {
            "inflightRequests": 1,
            "openConnections": 1
        },
        "connectionStats": {
            "waitforConnectionInit": "False",
            "callsPendingReceive": 0,
            "lastSendAttempt": "2022-05-25T12:03:34.0222760Z",
            "lastSend": "2022-05-25T12:03:34.0223280Z",
            "lastReceive": "2022-05-25T12:03:34.0257728Z"
        },
        "requestSizeInBytes": 447,
        "responseMetadataSizeInBytes": 438,
        "responseBodySizeInBytes": 604
    },
    "TransportException": null
}

Частота сбоев нарушает Соглашение об уровне обслуживания Azure Cosmos DB

Обратитесь в службу поддержки Azure.

Следующие шаги