ydb-nodejs-sdk
ydb-nodejs-sdk copied to clipboard
ydb-platform
BAD_SESSION on retries
Я использую @ydbjs, чтобы подключаться к serverless БД в облаке Яндекса. Клиентом выступает бот, работающий на Cloud Functions.
Во времена пиковых загрузок я заметил, что функция «зависает» и убивается сервисом по тайм-ауту. При этом в логах Node периодически (не всегда) жалуется на то, что что-то в коде вызывает слишком большой setTimeout.
Скриншот из Cloud Functions
Я так понимаю, это из-за того, что в retryConfig указан budget: Infinity. Но основная проблема, скорее всего, в другом. Дебаг на локальной машине показал то, что это может быть недочётом в @ydbjs/query.
Из логов:
-
ydbjs:driver driver is ready<-- ок -
ydbjs:grpc /Ydb.Query.V1.QueryService/ExecuteQuery RESOURCE_EXHAUSTED: ResourceExhausted<-- так пару раз -
attempt 3: calling retry function,ydbjs:query creating query client for nodeId: 50150n<-- новая попытка -
ydbjs:query query part failed, status: 400100<-- BAD_SESSION -
ydbjs:retry attempt 3: no delay before next retry,ydbjs:query query part failed, status: 400100<-- и так по кругу
dev.js
import { getSACredentialsFromJson, IamAuthService } from "ydb-sdk";
import { Driver } from "@ydbjs/core";
import { retry } from '@ydbjs/retry';
import { AccessTokenCredentialsProvider } from "@ydbjs/auth/access-token";
import { query } from "@ydbjs/query";
const saKeyFile = process.env.SA_KEY_FILE;
const saCredentials = getSACredentialsFromJson(saKeyFile);
const authService = new IamAuthService(saCredentials);
const token = (await authService.getAuthMetadata()).get("x-ydb-auth-ticket")[0];
const credentialsProvider = new AccessTokenCredentialsProvider({ token });
const ydb = new Driver(process.env.YDB_CONNECTION_STRING, {
credentialsProvider,
"ydb.sdk.ready_timeout_ms": 5000,
"ydb.sdk.token_timeout_ms": 5000,
"ydb.sdk.enable_discovery": false,
});
await retry({
budget: 2,
}, async (signal) => {
await ydb.ready(signal);
});
await ydb.ready();
const sql = query(ydb);
console.log(await sql`SELECT 1`);
Полные логи
$ DEBUG=ydbjs:* node --trace-warnings dev.js
ydbjs:driver Driver(connectionString: grpcs://ydb.serverless.yandexcloud.net:2135/?database=/ru-central1/<...>, options: { credentialsProvider: AccessTokenCredentialsProvider { middleware: [Function: bound middleware] AsyncGeneratorFunction }, 'ydb.sdk.ready_timeout_ms': 5000, 'ydb.sdk.token_timeout_ms': 5000, 'ydb.sdk.enable_discovery': false }) +0ms
ydbjs:driver:pool creating connection pool +0ms
ydbjs:driver:conn create channel to node id=-1n address=ydb.serverless.yandexcloud.net:2135 +0ms
ydbjs:driver discovery disabled, using single endpoint +2ms
ydbjs:retry attempt 1: calling retry function +0ms
ydbjs:driver waiting for driver to become ready +0ms
ydbjs:driver single endpoint ready +104ms
ydbjs:driver driver is ready +0ms
ydbjs:retry attempt 1: success +105ms
ydbjs:driver waiting for driver to become ready +1ms
ydbjs:driver driver is ready +0ms
ydbjs:query creating query instance for text: SELECT 1 +0ms
ydbjs:query starting query execution: SELECT 1 +1ms
ydbjs:driver waiting for driver to become ready +1ms
ydbjs:driver driver is ready +0ms
ydbjs:retry attempt 1: calling retry function +0ms
ydbjs:query creating query client for nodeId: undefined +0ms
ydbjs:driver creating client for Ydb.Query.V1.QueryService +1ms
ydbjs:query creating new session +1ms
ydbjs:grpc /Ydb.Query.V1.QueryService/CreateSession OK +0ms
ydbjs:driver creating client for Ydb.Query.V1.QueryService with preferNodeId: 50150 +30ms
ydbjs:query session ydb://session/3?node_id=50150&id=NDhjMmEzOWEtZWExZDZjNDYtMzU4OWQ1NDAtNTllOWU5OGM= created and attached +53ms
ydbjs:grpc /Ydb.Query.V1.QueryService/ExecuteQuery RESOURCE_EXHAUSTED: ResourceExhausted +619ms
ydbjs:retry attempt 1: waiting 1349 ms before next retry +651ms
ydbjs:query retrying query, attempt 1, error: ClientError: /Ydb.Query.V1.QueryService/ExecuteQuery RESOURCE_EXHAUSTED: ResourceExhausted
ydbjs:query at wrapClientError (/home/turikhay/projects/o6o2/bot/node_modules/nice-grpc/lib/client/wrapClientError.js:9:16)
ydbjs:query at Object.serverStreamingMethod [as next] (/home/turikhay/projects/o6o2/bot/node_modules/nice-grpc/lib/client/createServerStreamingMethod.js:41:57)
ydbjs:query at process.processTicksAndRejections (node:internal/process/task_queues:105:5)
ydbjs:query at async debug (file:///home/turikhay/projects/o6o2/bot/node_modules/@ydbjs/core/dist/middleware.js:8:16)
ydbjs:query at async AccessTokenCredentialsProvider.middleware (file:///home/turikhay/projects/o6o2/bot/node_modules/@ydbjs/auth/dist/index.js:11:16)
ydbjs:query at async Object.next (/home/turikhay/projects/o6o2/bot/node_modules/nice-grpc/lib/client/createServerStreamingMethod.js:68:40)
ydbjs:query at async file:///home/turikhay/projects/o6o2/bot/node_modules/@ydbjs/query/dist/query.js:160:28
ydbjs:query at async retry (file:///home/turikhay/projects/o6o2/bot/node_modules/@ydbjs/query/node_modules/@ydbjs/retry/dist/index.js:24:26)
ydbjs:query at async file:///home/turikhay/projects/o6o2/bot/dev.js:25:13 {
ydbjs:query path: '/Ydb.Query.V1.QueryService/ExecuteQuery',
ydbjs:query code: 8,
ydbjs:query details: 'ResourceExhausted'
ydbjs:query } +2s
ydbjs:retry attempt 2: calling retry function +1s
ydbjs:query creating query client for nodeId: 50150n +1ms
ydbjs:driver creating client for Ydb.Query.V1.QueryService with preferNodeId: 50150 +2s
ydbjs:grpc /Ydb.Query.V1.QueryService/ExecuteQuery RESOURCE_EXHAUSTED: ResourceExhausted +2s
ydbjs:retry attempt 2: waiting 3601 ms before next retry +399ms
ydbjs:query retrying query, attempt 2, error: ClientError: /Ydb.Query.V1.QueryService/ExecuteQuery RESOURCE_EXHAUSTED: ResourceExhausted
ydbjs:query at wrapClientError (/home/turikhay/projects/o6o2/bot/node_modules/nice-grpc/lib/client/wrapClientError.js:9:16)
ydbjs:query at Object.serverStreamingMethod [as next] (/home/turikhay/projects/o6o2/bot/node_modules/nice-grpc/lib/client/createServerStreamingMethod.js:41:57)
ydbjs:query at process.processTicksAndRejections (node:internal/process/task_queues:105:5)
ydbjs:query at async debug (file:///home/turikhay/projects/o6o2/bot/node_modules/@ydbjs/core/dist/middleware.js:8:16)
ydbjs:query at async AccessTokenCredentialsProvider.middleware (file:///home/turikhay/projects/o6o2/bot/node_modules/@ydbjs/auth/dist/index.js:11:16)
ydbjs:query at async Object.next (/home/turikhay/projects/o6o2/bot/node_modules/nice-grpc/lib/client/createServerStreamingMethod.js:68:40)
ydbjs:query at async file:///home/turikhay/projects/o6o2/bot/node_modules/@ydbjs/query/dist/query.js:160:28
ydbjs:query at async retry (file:///home/turikhay/projects/o6o2/bot/node_modules/@ydbjs/query/node_modules/@ydbjs/retry/dist/index.js:24:26)
ydbjs:query at async file:///home/turikhay/projects/o6o2/bot/dev.js:25:13 {
ydbjs:query path: '/Ydb.Query.V1.QueryService/ExecuteQuery',
ydbjs:query code: 8,
ydbjs:query details: 'ResourceExhausted'
ydbjs:query } +4s
ydbjs:retry attempt 3: calling retry function +4s
ydbjs:query creating query client for nodeId: 50150n +0ms
ydbjs:driver creating client for Ydb.Query.V1.QueryService with preferNodeId: 50150 +4s
ydbjs:query query part failed, status: 400100 +36ms
ydbjs:grpc /Ydb.Query.V1.QueryService/ExecuteQuery OK +4s
ydbjs:retry attempt 3: no delay before next retry +36ms
ydbjs:retry attempt 4: calling retry function +0ms
ydbjs:query creating query client for nodeId: 50150n +1ms
ydbjs:driver creating client for Ydb.Query.V1.QueryService with preferNodeId: 50150 +37ms
ydbjs:query query part failed, status: 400100 +22ms
ydbjs:grpc /Ydb.Query.V1.QueryService/ExecuteQuery OK +23ms
ydbjs:retry attempt 4: no delay before next retry +24ms
ydbjs:retry attempt 5: calling retry function +0ms
ydbjs:query creating query client for nodeId: 50150n +1ms
ydbjs:driver creating client for Ydb.Query.V1.QueryService with preferNodeId: 50150 +23ms
ydbjs:grpc /Ydb.Query.V1.QueryService/ExecuteQuery RESOURCE_EXHAUSTED: ResourceExhausted +390ms
ydbjs:retry attempt 5: waiting 31611 ms before next retry +389ms
ydbjs:query retrying query, attempt 5, error: ClientError: /Ydb.Query.V1.QueryService/ExecuteQuery RESOURCE_EXHAUSTED: ResourceExhausted
ydbjs:query at wrapClientError (/home/turikhay/projects/o6o2/bot/node_modules/nice-grpc/lib/client/wrapClientError.js:9:16)
ydbjs:query at Object.serverStreamingMethod [as next] (/home/turikhay/projects/o6o2/bot/node_modules/nice-grpc/lib/client/createServerStreamingMethod.js:41:57)
ydbjs:query at process.processTicksAndRejections (node:internal/process/task_queues:105:5)
ydbjs:query at async debug (file:///home/turikhay/projects/o6o2/bot/node_modules/@ydbjs/core/dist/middleware.js:8:16)
ydbjs:query at async AccessTokenCredentialsProvider.middleware (file:///home/turikhay/projects/o6o2/bot/node_modules/@ydbjs/auth/dist/index.js:11:16)
ydbjs:query at async Object.next (/home/turikhay/projects/o6o2/bot/node_modules/nice-grpc/lib/client/createServerStreamingMethod.js:68:40)
ydbjs:query at async file:///home/turikhay/projects/o6o2/bot/node_modules/@ydbjs/query/dist/query.js:160:28
ydbjs:query at async retry (file:///home/turikhay/projects/o6o2/bot/node_modules/@ydbjs/query/node_modules/@ydbjs/retry/dist/index.js:24:26)
ydbjs:query at async file:///home/turikhay/projects/o6o2/bot/dev.js:25:13 {
ydbjs:query path: '/Ydb.Query.V1.QueryService/ExecuteQuery',
ydbjs:query code: 8,
ydbjs:query details: 'ResourceExhausted'
ydbjs:query } +35s
ydbjs:retry attempt 6: calling retry function +34s
ydbjs:query creating query client for nodeId: 50150n +1ms
ydbjs:driver creating client for Ydb.Query.V1.QueryService with preferNodeId: 50150 +35s
ydbjs:query query part failed, status: 400100 +30ms
ydbjs:grpc /Ydb.Query.V1.QueryService/ExecuteQuery OK +34s
ydbjs:retry attempt 6: no delay before next retry +31ms
ydbjs:retry attempt 7: calling retry function +0ms
ydbjs:query creating query client for nodeId: 50150n +1ms
ydbjs:driver creating client for Ydb.Query.V1.QueryService with preferNodeId: 50150 +31ms
ydbjs:query query part failed, status: 400100 +23ms
ydbjs:grpc /Ydb.Query.V1.QueryService/ExecuteQuery OK +24ms
ydbjs:retry attempt 7: no delay before next retry +24ms
ydbjs:retry attempt 8: calling retry function +0ms
ydbjs:query creating query client for nodeId: 50150n +1ms
ydbjs:driver creating client for Ydb.Query.V1.QueryService with preferNodeId: 50150 +24ms
ydbjs:query query part failed, status: 400100 +23ms
ydbjs:grpc /Ydb.Query.V1.QueryService/ExecuteQuery OK +23ms
ydbjs:retry attempt 8: no delay before next retry +23ms
ydbjs:retry attempt 9: calling retry function +0ms
ydbjs:query creating query client for nodeId: 50150n +0ms
ydbjs:driver creating client for Ydb.Query.V1.QueryService with preferNodeId: 50150 +23ms
ydbjs:query query part failed, status: 400100 +23ms
ydbjs:grpc /Ydb.Query.V1.QueryService/ExecuteQuery OK +23ms
ydbjs:retry attempt 9: no delay before next retry +23ms
ydbjs:retry attempt 10: calling retry function +0ms
ydbjs:query creating query client for nodeId: 50150n +0ms
ydbjs:driver creating client for Ydb.Query.V1.QueryService with preferNodeId: 50150 +23ms
ydbjs:query query part failed, status: 400100 +23ms
ydbjs:grpc /Ydb.Query.V1.QueryService/ExecuteQuery OK +23ms
ydbjs:retry attempt 10: no delay before next retry +23ms
ydbjs:retry attempt 11: calling retry function +0ms
ydbjs:query creating query client for nodeId: 50150n +0ms
ydbjs:driver creating client for Ydb.Query.V1.QueryService with preferNodeId: 50150 +23ms
ydbjs:grpc /Ydb.Query.V1.QueryService/ExecuteQuery RESOURCE_EXHAUSTED: ResourceExhausted +389ms
ydbjs:retry attempt 11: waiting 2047611 ms before next retry +389ms
В качестве хотфикса залатал вот эти части:
diff --git a/packages/query/src/query.ts b/packages/query/src/query.ts
index 412625e..f7ff2e2 100644
--- a/packages/query/src/query.ts
+++ b/packages/query/src/query.ts
@@ -118,6 +118,7 @@ export class Query<T extends any[] = unknown[]> extends EventEmitter<QueryEventM
let retryConfig: RetryConfig = {
...defaultRetryConfig,
signal,
+ budget: 10,
idempotent: this.#idempotent,
onRetry: (retryCtx) => {
dbg.log('retrying query, attempt %d, error: %O', retryCtx.attempt, retryCtx.error)
@@ -219,6 +220,12 @@ export class Query<T extends any[] = unknown[]> extends EventEmitter<QueryEventM
for await (let part of stream) {
signal.throwIfAborted()
+ if (part.status === StatusIds_StatusCode.BAD_SESSION) {
+ dbg.log('invalidating session')
+ sessionId = undefined
+ throw new YDBError(part.status, part.issues)
+ }
+
if (part.status !== StatusIds_StatusCode.SUCCESS) {
dbg.log('query part failed, status: %d', part.status)
throw new YDBError(part.status, part.issues)
