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

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

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

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

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

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

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

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

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

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

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

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

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

  • Ваше приложение скомпилировано в режиме Release.
  • Вы не измеряете задержку при отладке приложения (отладчики не подключены).
  • Объем операций высокий — не используйте массовую обработку для менее чем 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 получает все метаданные из шлюза.

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

Количество запросов Сценарий Описание
Одиночный для всех Истечение времени ожидания запроса или 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.

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

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

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

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

ГрафикЗапросов

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

  • 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.

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

  • Last updated on