diff --git a/examples/custom-logger/dummy.ts b/examples/custom-logger/dummy.ts index 4c03644f..7c013a5d 100644 --- a/examples/custom-logger/dummy.ts +++ b/examples/custom-logger/dummy.ts @@ -1,5 +1,5 @@ import {main} from '../utils'; -import {Logger, LogFn, Driver, getCredentialsFromEnv, setupLogger, setDefaultLogger} from 'ydb-sdk'; +import {Logger, LogFn, Driver, getCredentialsFromEnv/*, setupLogger, setDefaultLogger*/} from 'ydb-sdk'; const logFunction: LogFn = (obj: any, ...args: any[]) => { console.log('Custom logging!', obj, ...args); @@ -14,11 +14,12 @@ const MyLogger: Logger = { }; export async function run(logger: Logger, endpoint: string, database: string) { - setupLogger(MyLogger); - setDefaultLogger(MyLogger); // will work too + + // setupLogger(MyLogger); + // setDefaultLogger(MyLogger); // will work too logger.info('Driver initializing...'); const authService = getCredentialsFromEnv(); - const driver = new Driver({endpoint, database, authService}); + const driver = new Driver({endpoint, database, authService, logger: MyLogger}); const timeout = 10000; if (!(await driver.ready(timeout))) { logger.fatal(`Driver has not become ready in ${timeout}ms!`); diff --git a/examples/custom-logger/pino.ts b/examples/custom-logger/pino.ts index d15b3504..f876013a 100644 --- a/examples/custom-logger/pino.ts +++ b/examples/custom-logger/pino.ts @@ -1,13 +1,13 @@ import {mainWithoutLogger} from '../utils'; -import {Driver, getCredentialsFromEnv, setupLogger} from 'ydb-sdk'; +import {Driver, getCredentialsFromEnv/*, setupLogger*/} from 'ydb-sdk'; import pino from 'pino'; export async function run(endpoint: string, database: string) { const logger = pino({level: 'debug'}); logger.info('Driver initializing...'); - setupLogger(logger); + // setupLogger(logger); const authService = getCredentialsFromEnv(); - const driver = new Driver({endpoint, database, authService}); + const driver = new Driver({endpoint, database, authService, logger}); const timeout = 10000; if (!(await driver.ready(timeout))) { logger.fatal(`Driver has not become ready in ${timeout}ms!`); diff --git a/examples/custom-logger/winston.ts b/examples/custom-logger/winston.ts index 7a9d9bef..0b0cfa4f 100644 --- a/examples/custom-logger/winston.ts +++ b/examples/custom-logger/winston.ts @@ -1,5 +1,5 @@ import {mainWithoutLogger} from '../utils'; -import {Driver, getCredentialsFromEnv, Logger, setupLogger} from 'ydb-sdk'; +import {Driver, getCredentialsFromEnv, Logger/*, setupLogger*/} from 'ydb-sdk'; import winston from 'winston'; export async function run(endpoint: string, database: string) { @@ -14,7 +14,7 @@ export async function run(endpoint: string, database: string) { trace: 6, }, }) as unknown as Logger; - /* + /* Log levels accordance: YDB-SDK-logger -> winston (npm levels) fatal -> !!! no such level, set exact as error @@ -24,10 +24,10 @@ export async function run(endpoint: string, database: string) { debug -> debug trace -> silly(6) */ - setupLogger(logger); + // setupLogger(logger); logger.info('Driver initializing...'); const authService = getCredentialsFromEnv(); - const driver = new Driver({endpoint, database, authService}); + const driver = new Driver({endpoint, database, authService, logger}); const timeout = 10000; if (!(await driver.ready(timeout))) { logger.fatal(`Driver has not become ready in ${timeout}ms!`); diff --git a/src/__tests__/e2e/query-service/method-execute.ts b/src/__tests__/e2e/query-service/method-execute.ts index 1781a6a0..f5d99411 100644 --- a/src/__tests__/e2e/query-service/method-execute.ts +++ b/src/__tests__/e2e/query-service/method-execute.ts @@ -1,14 +1,13 @@ import DiscoveryService from "../../../discovery/discovery-service"; import {ENDPOINT_DISCOVERY_PERIOD} from "../../../constants"; import {AnonymousAuthService} from "../../../credentials/anonymous-auth-service"; -import {getLogger} from "../../../logging"; import {SessionBuilder} from "../../../query/query-session-pool"; -import {QuerySession} from "../../../query/query-session"; +import {QuerySession, IExecuteResult} from "../../../query"; import {declareType, TypedData, TypedValues, Types} from "../../../types"; import {Ydb} from "ydb-sdk-proto"; import StatsMode = Ydb.Query.StatsMode; import ExecMode = Ydb.Query.ExecMode; -import {IExecuteResult} from "../../../query/query-session-execute"; +import {getDefaultLogger} from "../../../logger/get-default-logger"; const DATABASE = '/local'; const ENDPOINT = 'grpcs://localhost:2136'; @@ -222,7 +221,7 @@ describe('Query.execute()', () => { } async function testOnOneSessionWithoutDriver() { - const logger = getLogger(); + const logger = getDefaultLogger(); const authService = new AnonymousAuthService(); discoveryService = new DiscoveryService({ diff --git a/src/__tests__/e2e/query-service/query-service-client.ts b/src/__tests__/e2e/query-service/query-service-client.ts index 0728136d..56eaa31a 100644 --- a/src/__tests__/e2e/query-service/query-service-client.ts +++ b/src/__tests__/e2e/query-service/query-service-client.ts @@ -1,11 +1,10 @@ import Driver from "../../../driver"; import {AnonymousAuthService} from "../../../credentials/anonymous-auth-service"; -import {IExecuteResult} from "../../../query/query-session-execute"; import * as errors from "../../../errors"; import path from "path"; import fs from "fs"; import {AUTO_TX} from "../../../table"; -import {QuerySession} from "../../../query/query-session"; +import {QuerySession, IExecuteResult} from "../../../query"; const DATABASE = '/local'; const ENDPOINT = 'grpcs://localhost:2135'; diff --git a/src/__tests__/e2e/query-service/rows-conversion.ts b/src/__tests__/e2e/query-service/rows-conversion.ts index d51708b5..bb3c5f3d 100644 --- a/src/__tests__/e2e/query-service/rows-conversion.ts +++ b/src/__tests__/e2e/query-service/rows-conversion.ts @@ -1,12 +1,11 @@ import DiscoveryService from "../../../discovery/discovery-service"; -import {QuerySession} from "../../../query/query-session"; -import {getLogger} from "../../../logging"; +import {QuerySession, RowType} from "../../../query"; import {AnonymousAuthService} from "../../../credentials/anonymous-auth-service"; import {ENDPOINT_DISCOVERY_PERIOD} from "../../../constants"; import {SessionBuilder} from "../../../query/query-session-pool"; import {declareType, TypedData, TypedValues, Types} from "../../../types"; -import {RowType} from "../../../query/query-session-execute"; import {Ydb} from "ydb-sdk-proto"; +import {getDefaultLogger} from "../../../logger/get-default-logger"; const DATABASE = '/local'; const ENDPOINT = 'grpcs://localhost:2136'; @@ -138,7 +137,7 @@ describe('Rows conversion', () => { } async function testOnOneSessionWithoutDriver() { - const logger = getLogger(); + const logger = getDefaultLogger(); const authService = new AnonymousAuthService(); discoveryService = new DiscoveryService({ diff --git a/src/__tests__/e2e/query-service/transactions.ts b/src/__tests__/e2e/query-service/transactions.ts index 943ac122..28c55213 100644 --- a/src/__tests__/e2e/query-service/transactions.ts +++ b/src/__tests__/e2e/query-service/transactions.ts @@ -1,11 +1,10 @@ -import {getLogger} from "../../../logging"; import {AnonymousAuthService} from "../../../credentials/anonymous-auth-service"; import DiscoveryService from "../../../discovery/discovery-service"; import {ENDPOINT_DISCOVERY_PERIOD} from "../../../constants"; import {SessionBuilder} from "../../../query/query-session-pool"; -import {QuerySession} from "../../../query/query-session"; +import {QuerySession, IExecuteResult} from "../../../query"; import * as symbols from "../../../query/symbols"; -import {IExecuteResult} from "../../../query/query-session-execute"; +import {getDefaultLogger} from "../../../logger/get-default-logger"; const DATABASE = '/local'; const ENDPOINT = 'grpc://localhost:2136'; @@ -111,7 +110,7 @@ describe('Query service transactions', () => { } async function testOnOneSessionWithoutDriver() { - const logger = getLogger(); + const logger = getDefaultLogger(); const authService = new AnonymousAuthService(); discoveryService = new DiscoveryService({ diff --git a/src/__tests__/e2e/table-service/bytestring-identity.test.ts b/src/__tests__/e2e/table-service/bytestring-identity.test.ts index a31a8d2c..a1f97370 100644 --- a/src/__tests__/e2e/table-service/bytestring-identity.test.ts +++ b/src/__tests__/e2e/table-service/bytestring-identity.test.ts @@ -1,6 +1,6 @@ import Driver from '../../../driver'; import {declareType, TypedData, Types} from '../../../types'; -import {withRetries} from '../../../retries'; +import {withRetries} from '../../../retries_obsoleted'; import {Column, TableSession, TableDescription} from "../../../table"; import {initDriver, destroyDriver, TABLE} from "../../../utils/test"; diff --git a/src/__tests__/e2e/table-service/retries.test.ts b/src/__tests__/e2e/table-service/retries.test.ts index f7a0a2bc..580cfb28 100644 --- a/src/__tests__/e2e/table-service/retries.test.ts +++ b/src/__tests__/e2e/table-service/retries.test.ts @@ -18,13 +18,13 @@ import { Undetermined, YdbError, } from '../../../errors'; -import {FallbackLogger} from '../../../logging'; -import {RetryParameters, retryable} from '../../../retries'; +import {retryable, RetryParameters} from '../../../retries_obsoleted'; import {Endpoint} from "../../../discovery"; import {pessimizable} from "../../../utils"; -import {initDriver, destroyDriver} from "../../../utils/test"; +import {destroyDriver, initDriver} from "../../../utils/test"; +import {LogLevel, SimpleLogger} from "../../../logger/simple-logger"; -const logger = new FallbackLogger({level: 'error'}); +const logger = new SimpleLogger({level: LogLevel.error}); class ErrorThrower { constructor(public endpoint: Endpoint) {} diff --git a/src/__tests__/unit/auth-errors.test.ts b/src/__tests__/unit/auth-errors.test.ts index 413882ca..8deeba4f 100644 --- a/src/__tests__/unit/auth-errors.test.ts +++ b/src/__tests__/unit/auth-errors.test.ts @@ -1,24 +1,30 @@ -import { FallbackLogger, setupLogger } from '../../logging'; -setupLogger(new FallbackLogger({level: 'error'})) - -import { ServiceError } from '@grpc/grpc-js/build/src/call'; -import { TransportUnavailable } from '../../errors'; -import { StatusObject } from '@grpc/grpc-js'; -import { Status } from '@grpc/grpc-js/build/src/constants'; +import {ServiceError} from '@grpc/grpc-js/build/src/call'; +import {TransportUnavailable} from '../../errors'; +import {StatusObject} from '@grpc/grpc-js'; +import {Status} from '@grpc/grpc-js/build/src/constants'; import {StaticCredentialsAuthService} from "../../credentials/static-credentials-auth-service"; import {IamAuthService} from "../../credentials/iam-auth-service"; +import {buildTestLogger} from "../../logger/tests/test-logger"; describe('Retries on errors in auth services', () => { const mockIamCounter = {retries: 0} const mockStaticCredCounter = {retries: 0} + + // @ts-ignore + let testLogger: Logger; + // @ts-ignore + let testLoggerFn: jest.Mock; + function mockCallErrorFromStatus(status: StatusObject): ServiceError { const message = `${status.code} ${Status[status.code]}: ${status.details}`; return Object.assign(new Error(message), status); } - beforeEach(() => {}); - beforeAll(() => { + beforeEach(() => { + ({testLogger: testLogger, testLoggerFn: testLoggerFn} = buildTestLogger()); + }); + beforeAll(() => { jest.mock('ydb-sdk-proto', () => { const actual = jest.requireActual('ydb-sdk-proto') as typeof import('ydb-sdk-proto') @@ -52,7 +58,7 @@ describe('Retries on errors in auth services', () => { iamEndpoint: '2', privateKey: Buffer.from('3'), serviceAccountId: '4', - }); + }, testLogger); // mock jwt request return iamAuth['getJwtRequest'] = () => ''; @@ -63,7 +69,10 @@ describe('Retries on errors in auth services', () => { }); it('Static creds auth service - UNAVAILABLE', async () => { - const staticAuth = new StaticCredentialsAuthService('usr', 'pwd', 'endpoint'); + const staticAuth = new StaticCredentialsAuthService( + 'usr', + 'pwd', + 'endpoint', testLogger); await expect(async () => { await staticAuth.getAuthMetadata() diff --git a/src/__tests__/unit/backoff-settings.test.ts b/src/__tests__/unit/backoff-settings.test.ts index cf9e0e1e..ebbe6296 100644 --- a/src/__tests__/unit/backoff-settings.test.ts +++ b/src/__tests__/unit/backoff-settings.test.ts @@ -1,4 +1,4 @@ -import {BackoffSettings} from '../../retries'; +import {BackoffSettings} from '../../retries_obsoleted'; import * as utils from '../../utils'; function runTest(backoff: BackoffSettings, retries: number, min: number, max: number) { it(`have correct value for ${retries} retries`, () => { diff --git a/src/__tests__/unit/context-do.test.ts b/src/__tests__/unit/context-do.test.ts index 1c009d22..1e864ebc 100644 --- a/src/__tests__/unit/context-do.test.ts +++ b/src/__tests__/unit/context-do.test.ts @@ -1,4 +1,4 @@ -import {Context, setContextIdGenerator} from "../../context/Context"; +import {Context, setContextIdGenerator} from "../../context"; describe('Context.do', () => { beforeEach(() => { diff --git a/src/__tests__/unit/context-ensure.test.ts b/src/__tests__/unit/context-ensure.test.ts index 47125088..98322b9c 100644 --- a/src/__tests__/unit/context-ensure.test.ts +++ b/src/__tests__/unit/context-ensure.test.ts @@ -1,5 +1,4 @@ -import {Context} from "../../context/Context"; -import {EnsureContext} from "../../context/ensureContext"; +import {Context, ensureContext} from "../../context"; describe('ensureContext', () => { it('positional args', () => { @@ -7,7 +6,7 @@ describe('ensureContext', () => { // @ts-ignore noArgs(): void; noArgs(ctx: Context): void; - @EnsureContext(true) + @ensureContext(true) noArgs(ctx: Context): void { expect(ctx instanceof Context).toBeTruthy(); } @@ -15,7 +14,7 @@ describe('ensureContext', () => { // @ts-ignore posArgs(n: number, s: string): void; posArgs(ctx: Context, n: number, s: string): void; - @EnsureContext(true) + @ensureContext(true) posArgs(ctx: Context, n: number, s: string) { expect(ctx instanceof Context).toBeTruthy(); expect(n).toBe(12); @@ -26,7 +25,7 @@ describe('ensureContext', () => { static staticNoArgs(): void; static staticNoArgs(ctx: Context): void; - @EnsureContext(true) + @ensureContext(true) static staticNoArgs(ctx: Context) { expect(ctx instanceof Context).toBeTruthy(); } @@ -49,7 +48,7 @@ describe('ensureContext', () => { // noArgs(opts: { // ctx?: Context, // }): void; - @EnsureContext() + @ensureContext() noArgs(opts?: { ctx?: Context, }): void { @@ -57,7 +56,7 @@ describe('ensureContext', () => { expect(ctx instanceof Context).toBeTruthy(); } - @EnsureContext(false) // should throw error cause fire arg is not obj + @ensureContext(false) // should throw error cause fire arg is not obj mismatchTypeOfArgs(n: number, s: string) { expect(n).toBe(12); expect(s).toBe('test'); diff --git a/src/context/ensureContext.ts b/src/context/ensure-context.ts similarity index 93% rename from src/context/ensureContext.ts rename to src/context/ensure-context.ts index 85e2b1ed..1b79dcd1 100644 --- a/src/context/ensureContext.ts +++ b/src/context/ensure-context.ts @@ -1,4 +1,4 @@ -import {Context} from "./Context"; +import {Context} from "./context"; /** * Decorator that ensures: @@ -10,7 +10,7 @@ import {Context} from "./Context"; * * @param isPositionalArgs */ -export function EnsureContext(isPositionalArgs?: boolean) { // TODO: Should I got logger somehow? +export function ensureContext(isPositionalArgs?: boolean) { // TODO: Should I got logger somehow? return (_target: any, _propertyKey: string, descriptor: PropertyDescriptor) => { const originalMethod = descriptor.value; // const wrappedMethodName = `${target.constructor.name}::${propertyKey}`; // for regular method diff --git a/src/context/has-object-context.ts b/src/context/has-object-context.ts new file mode 100644 index 00000000..060c471d --- /dev/null +++ b/src/context/has-object-context.ts @@ -0,0 +1,9 @@ +import {Context} from "./context"; + +export interface HasObjectContext { + /** + * The context in which the object was created. Useful for tracking object initialization and background operations. + * During dispose/destroy operation it is useful to log the current context and the context in which the object was created. + */ + readonly objCtx: Context; +} diff --git a/src/context/index.ts b/src/context/index.ts new file mode 100644 index 00000000..8e15647d --- /dev/null +++ b/src/context/index.ts @@ -0,0 +1,4 @@ +export {Context, CtxDispose, CtxCancel, CtxDone, CtxUnsubcribe, CtxIdGenerator, setContextIdGenerator} from './context'; +export {ensureContext} from './ensure-context'; +export {HasObjectContext} from './has-object-context'; +export * as contextSymbols from './symbols'; diff --git a/src/credentials/iam-auth-service.ts b/src/credentials/iam-auth-service.ts index 5f66f1bc..1ab3b11f 100644 --- a/src/credentials/iam-auth-service.ts +++ b/src/credentials/iam-auth-service.ts @@ -3,12 +3,16 @@ import {yandex} from "ydb-sdk-proto"; import * as grpc from "@grpc/grpc-js"; import jwt from "jsonwebtoken"; import {GrpcService, sleep, withTimeout} from "../utils"; -import {retryable} from "../retries"; +import {retryable} from "../retries_obsoleted"; import IamTokenService = yandex.cloud.iam.v1.IamTokenService; import ICreateIamTokenResponse = yandex.cloud.iam.v1.ICreateIamTokenResponse; import {addCredentialsToMetadata} from "./add-credentials-to-metadata"; import {IAuthService} from "./i-auth-service"; import {ISslCredentials, makeDefaultSslCredentials} from "../utils/ssl-credentials"; +import {HasLogger} from "../logger/has-logger"; +import {Logger} from "../logger/simple-logger"; +import {getDefaultLogger} from "../logger/get-default-logger"; +import {ensureContext} from "../context"; export interface IIamCredentials { serviceAccountId: string, @@ -17,16 +21,25 @@ export interface IIamCredentials { iamEndpoint: string } -class IamTokenGrpcService extends GrpcService { - constructor(iamCredentials: IIamCredentials, sslCredentials: ISslCredentials) { +class IamTokenGrpcService extends GrpcService implements HasLogger { + public readonly logger: Logger; + + constructor(iamCredentials: IIamCredentials, sslCredentialsOrLogger?: ISslCredentials | Logger, logger?: Logger) { + const hasLogger = typeof sslCredentialsOrLogger === 'object' && sslCredentialsOrLogger !== null && 'error' in sslCredentialsOrLogger; super( iamCredentials.iamEndpoint, 'yandex.cloud.iam.v1.IamTokenService', IamTokenService, - sslCredentials, + (sslCredentialsOrLogger && !hasLogger) ? (sslCredentialsOrLogger as ISslCredentials) : undefined, ); + if (hasLogger) { + this.logger = sslCredentialsOrLogger as Logger; + } else { + this.logger = logger ?? getDefaultLogger(); + } } + @ensureContext(true) @retryable() create(request: yandex.cloud.iam.v1.ICreateIamTokenRequest) { return this.api.create(request); @@ -37,7 +50,7 @@ class IamTokenGrpcService extends GrpcService { } } -export class IamAuthService implements IAuthService { +export class IamAuthService implements IAuthService, HasLogger { private jwtExpirationTimeout = 3600 * 1000; private tokenExpirationTimeout = 120 * 1000; private tokenRequestTimeout = 10 * 1000; @@ -46,11 +59,20 @@ export class IamAuthService implements IAuthService { private tokenUpdateInProgress: Boolean = false; private readonly iamCredentials: IIamCredentials; private readonly sslCredentials: ISslCredentials; + public readonly logger: Logger; - constructor(iamCredentials: IIamCredentials, sslCredentials?: ISslCredentials) { + constructor(iamCredentials: IIamCredentials, logger?: Logger); + constructor(iamCredentials: IIamCredentials, sslCredentials?: ISslCredentials, logger?: Logger); + constructor(iamCredentials: IIamCredentials, sslCredentialsOrLogger?: ISslCredentials | Logger, logger?: Logger) { this.iamCredentials = iamCredentials; - this.sslCredentials = sslCredentials || makeDefaultSslCredentials() this.tokenTimestamp = null; + if (typeof sslCredentialsOrLogger === 'object' && sslCredentialsOrLogger !== null && 'error' in sslCredentialsOrLogger) { + this.sslCredentials = makeDefaultSslCredentials() + this.logger = sslCredentialsOrLogger as Logger; + } else { + this.sslCredentials = (sslCredentialsOrLogger as ISslCredentials) || makeDefaultSslCredentials() + this.logger = logger ?? getDefaultLogger(); + } } getJwtRequest() { @@ -79,6 +101,7 @@ export class IamAuthService implements IAuthService { let runtimeIamAuthService = new IamTokenGrpcService( this.iamCredentials, this.sslCredentials, + this.logger, ); const tokenPromise = runtimeIamAuthService.create({jwt: this.getJwtRequest()}); const result = await withTimeout( diff --git a/src/credentials/static-credentials-auth-service.ts b/src/credentials/static-credentials-auth-service.ts index b7737e17..23f51ff0 100644 --- a/src/credentials/static-credentials-auth-service.ts +++ b/src/credentials/static-credentials-auth-service.ts @@ -2,13 +2,17 @@ import {Ydb} from "ydb-sdk-proto"; import AuthServiceResult = Ydb.Auth.LoginResult; import {ISslCredentials} from "../utils/ssl-credentials"; import {GrpcService, withTimeout} from "../utils"; -import {retryable} from "../retries"; +import {retryable} from "../retries_obsoleted"; import {DateTime} from "luxon"; import {getOperationPayload} from "../utils/process-ydb-operation-result"; import * as grpc from "@grpc/grpc-js"; import {addCredentialsToMetadata} from "./add-credentials-to-metadata"; import {IAuthService} from "./i-auth-service"; +import {HasLogger} from "../logger/has-logger"; +import {Logger} from "../logger/simple-logger"; +import {getDefaultLogger} from "../logger/get-default-logger"; +import {ensureContext} from "../context"; interface StaticCredentialsAuthOptions { /** Custom ssl sertificates. If you use it in driver, you must use it here too */ @@ -24,11 +28,12 @@ interface StaticCredentialsAuthOptions { tokenExpirationTimeout?: number } -class StaticCredentialsGrpcService extends GrpcService { - constructor(endpoint: string, sslCredentials?: ISslCredentials) { +class StaticCredentialsGrpcService extends GrpcService implements HasLogger { + constructor(endpoint: string, sslCredentials?: ISslCredentials, public readonly logger: Logger = getDefaultLogger()) { super(endpoint, 'Ydb.Auth.V1.AuthService', Ydb.Auth.V1.AuthService, sslCredentials); } + @ensureContext(true) @retryable() login(request: Ydb.Auth.ILoginRequest) { return this.api.login(request); @@ -49,18 +54,39 @@ export class StaticCredentialsAuthService implements IAuthService { private password: string; private endpoint: string; private sslCredentials: ISslCredentials | undefined; + public readonly logger: Logger; constructor( user: string, password: string, endpoint: string, options?: StaticCredentialsAuthOptions + ); + constructor( + user: string, + password: string, + endpoint: string, + loggerOrOptions: Logger | StaticCredentialsAuthOptions, + options?: StaticCredentialsAuthOptions + ); + constructor( + user: string, + password: string, + endpoint: string, + loggerOrOptions?: Logger | StaticCredentialsAuthOptions, + options?: StaticCredentialsAuthOptions ) { this.tokenTimestamp = null; this.user = user; this.password = password; this.endpoint = endpoint; this.sslCredentials = options?.sslCredentials; + if (typeof loggerOrOptions === 'object' && loggerOrOptions !== null && 'error' in loggerOrOptions) { + this.logger = loggerOrOptions as Logger; + } else { + options = loggerOrOptions; + this.logger = getDefaultLogger(); + } if (options?.tokenRequestTimeout) this.tokenRequestTimeout = options.tokenRequestTimeout; if (options?.tokenExpirationTimeout) this.tokenExpirationTimeout = options.tokenExpirationTimeout; } @@ -75,6 +101,7 @@ export class StaticCredentialsAuthService implements IAuthService { let runtimeAuthService = new StaticCredentialsGrpcService( this.endpoint, this.sslCredentials, + this.logger, ); const tokenPromise = runtimeAuthService.login({ user: this.user, diff --git a/src/discovery/discovery-service.ts b/src/discovery/discovery-service.ts index 37785bc3..89e348f0 100644 --- a/src/discovery/discovery-service.ts +++ b/src/discovery/discovery-service.ts @@ -2,15 +2,14 @@ import {Ydb} from "ydb-sdk-proto"; import DiscoveryServiceAPI = Ydb.Discovery.V1.DiscoveryService; import {Endpoint, SuccessDiscoveryHandler} from "./endpoint"; import EventEmitter from "events"; -import {Logger} from "../logging"; import _ from "lodash"; import {Events} from "../constants"; -import {retryable} from "../retries"; +import {retryable} from "../retries_obsoleted"; import {ISslCredentials} from "../utils/ssl-credentials"; import {getOperationPayload} from "../utils/process-ydb-operation-result"; -import {AuthenticatedService} from "../utils/authenticated-service"; -import {withTimeout} from "../utils/with-timeout"; +import {AuthenticatedService, withTimeout} from "../utils"; import {IAuthService} from "../credentials/i-auth-service"; +import {Logger} from "../logger/simple-logger"; type FailureDiscoveryHandler = (err: Error) => void; const noOp = () => { diff --git a/src/driver.ts b/src/driver.ts index 57c08048..264502fa 100644 --- a/src/driver.ts +++ b/src/driver.ts @@ -1,6 +1,5 @@ import {ENDPOINT_DISCOVERY_PERIOD} from './constants'; import {TimeoutExpired} from './errors'; -import {getLogger, Logger} from './logging'; import {makeSslCredentials, ISslCredentials} from './utils/ssl-credentials'; import DiscoveryService from "./discovery/discovery-service"; import {TableClient} from "./table"; @@ -10,6 +9,8 @@ import SchemeService from "./schema/scheme-client"; import SchemeClient from "./schema/scheme-client"; import {parseConnectionString} from "./utils/parse-connection-string"; import {QueryClient} from "./query"; +import {Logger} from "./logger/simple-logger"; +import {getDefaultLogger} from "./logger/get-default-logger"; export interface IPoolSettings { minLimit?: number; @@ -43,7 +44,7 @@ export default class Driver { public schemeClient: SchemeService; constructor(settings: IDriverSettings) { - this.logger = settings.logger || getLogger(); + this.logger = settings.logger || getDefaultLogger(); if (settings.connectionString) { const {endpoint, database} = parseConnectionString(settings.connectionString); diff --git a/src/errors.ts b/src/errors.ts index d9428793..7e63fad0 100644 --- a/src/errors.ts +++ b/src/errors.ts @@ -2,10 +2,17 @@ import {StatusObject as GrpcStatusObject} from '@grpc/grpc-js'; import {Ydb} from 'ydb-sdk-proto'; import ApiStatusCode = Ydb.StatusIds.StatusCode; import {Status as GrpcStatus} from '@grpc/grpc-js/build/src/constants'; +import {RetryPolicySymbol} from "./retries/symbols"; const TRANSPORT_STATUSES_FIRST = 401000; const CLIENT_STATUSES_FIRST = 402000; +export const enum Backoff { + No, + Fast, + Slow, +} + export enum StatusCode { STATUS_CODE_UNSPECIFIED = ApiStatusCode.STATUS_CODE_UNSPECIFIED, SUCCESS = ApiStatusCode.SUCCESS, @@ -27,27 +34,64 @@ export enum StatusCode { UNDETERMINED = ApiStatusCode.UNDETERMINED, UNSUPPORTED = ApiStatusCode.UNSUPPORTED, SESSION_BUSY = ApiStatusCode.SESSION_BUSY, + EXTERNAL_ERROR = ApiStatusCode.EXTERNAL_ERROR, // Client statuses /** Cannot connect or unrecoverable network error. (map from gRPC UNAVAILABLE) */ - TRANSPORT_UNAVAILABLE = TRANSPORT_STATUSES_FIRST + 10, + TRANSPORT_UNAVAILABLE = TRANSPORT_STATUSES_FIRST + 10, // grpc code: 14 (GrpcStatus.UNAVAILABLE) // Theoritically should begin with `TRANSPORT_`, but renamed due to compatibility - CLIENT_RESOURCE_EXHAUSTED = TRANSPORT_STATUSES_FIRST + 20, - CLIENT_DEADLINE_EXCEEDED = TRANSPORT_STATUSES_FIRST + 30, + CLIENT_RESOURCE_EXHAUSTED = TRANSPORT_STATUSES_FIRST + 20, // grpc code: 8 (GrpcStatus.RESOURCE_EXHAUSTED) + CLIENT_DEADLINE_EXCEEDED = TRANSPORT_STATUSES_FIRST + 30, // grpc code: 4 (GrpcStatus.DEADLINE_EXCEEDED) + CLIENT_CANCELED = TRANSPORT_STATUSES_FIRST + 34, // SDK local + + UNAUTHENTICATED = CLIENT_STATUSES_FIRST + 30, // SDK local + SESSION_POOL_EMPTY = CLIENT_STATUSES_FIRST + 40, // SDK local +} - UNAUTHENTICATED = CLIENT_STATUSES_FIRST + 30, - SESSION_POOL_EMPTY = CLIENT_STATUSES_FIRST + 40, +/** + * Depending on the type of error, the retryer decides how to proceed and whether + * the session can continue to be used or not. + */ +export type SpecificErrorRetryPolicy = { + /** + * Backoff.No - retry imminently if retry for the operation is true. + * Backoff.Fast - retry accordingly to fast retry policy. + * Backoff.Slow - retry accordingly to slow retry policy. + * Note: current attempt count set to zero if the error is not with the same type as was on previous attempt. + */ + backoff: Backoff, + /** + * true - delete session from pool, is case of the error. + */ + deleteSession: boolean, + /** + * true - retry for idempotent operations. + */ + idempotent: boolean, + /** + * true - retry for non-idempotent operations. + */ + nonIdempotent: boolean +} + +function retryPolicy(backoff: Backoff, deleteSession: boolean, idempotent: boolean, nonIdempotent: boolean): SpecificErrorRetryPolicy { + return {backoff, deleteSession, idempotent, nonIdempotent}; } export class YdbError extends Error { + public static [RetryPolicySymbol]: SpecificErrorRetryPolicy; + static formatIssues(issues?: null | any[]) { return issues ? JSON.stringify(issues, null, 2) : ''; } + /** + * If YDB returns an error YdbError is thrown. + * @param operation + */ static checkStatus(operation: { status?: (Ydb.StatusIds.StatusCode|null); issues?: (Ydb.Issue.IIssueMessage[]|null); - }) { if (!operation.status) { throw new MissingStatus('Missing status!'); @@ -67,6 +111,10 @@ export class YdbError extends Error { } } + /** + * Issues from Ydb are returned as a tree with nested issues. Returns the list of issues as a flat array. + * The nested issues follow their parents. + */ private static flatIssues(issues: Ydb.Issue.IIssueMessage[]) { const res: Ydb.Issue.IIssueMessage[] = []; processLevel(issues); @@ -89,85 +137,114 @@ export class YdbError extends Error { } } +export class StatusCodeUnspecified extends YdbError { // TODO: Make gets issued + static status = StatusCode.STATUS_CODE_UNSPECIFIED + public static [RetryPolicySymbol] = retryPolicy(Backoff.No, false, false, false) +} -export class Unauthenticated extends YdbError { +export class Unauthenticated extends YdbError { // TODO: Make gets issued static status = StatusCode.UNAUTHENTICATED + public static [RetryPolicySymbol] = retryPolicy(Backoff.No, true, false, false) } export class SessionPoolEmpty extends YdbError { - static status = StatusCode.SESSION_POOL_EMPTY + static status = StatusCode.SESSION_POOL_EMPTY; + public static [RetryPolicySymbol] = retryPolicy(Backoff.Fast, false, true, true); // TODO: not found go impl yet } export class BadRequest extends YdbError { - static status = StatusCode.BAD_REQUEST + static status = StatusCode.BAD_REQUEST; + public static [RetryPolicySymbol] = retryPolicy(Backoff.No, false, false, false); } export class Unauthorized extends YdbError { - static status = StatusCode.UNAUTHORIZED + static status = StatusCode.UNAUTHORIZED; + public static [RetryPolicySymbol] = retryPolicy(Backoff.No, false, false, false); } export class InternalError extends YdbError { - static status = StatusCode.INTERNAL_ERROR + static status = StatusCode.INTERNAL_ERROR; + public static [RetryPolicySymbol] = retryPolicy(Backoff.No, false, false, false); } export class Aborted extends YdbError { static status = StatusCode.ABORTED + public static [RetryPolicySymbol] = retryPolicy(Backoff.Fast, false, true, true); } export class Unavailable extends YdbError { static status = StatusCode.UNAVAILABLE + public static [RetryPolicySymbol] = retryPolicy(Backoff.Fast, false, true, true); } export class Overloaded extends YdbError { static status = StatusCode.OVERLOADED + public static [RetryPolicySymbol] = retryPolicy(Backoff.Slow, false, true, true); } export class SchemeError extends YdbError { - static status = StatusCode.SCHEME_ERROR + static status = StatusCode.SCHEME_ERROR; + public static [RetryPolicySymbol] = retryPolicy(Backoff.No, false,false, false); } export class GenericError extends YdbError { - static status = StatusCode.GENERIC_ERROR + static status = StatusCode.GENERIC_ERROR; + public static [RetryPolicySymbol] = retryPolicy(Backoff.No, false, false, false); } export class BadSession extends YdbError { - static status = StatusCode.BAD_SESSION + static status = StatusCode.BAD_SESSION; + public static [RetryPolicySymbol] = retryPolicy(Backoff.No, true, true, true); } export class Timeout extends YdbError { - static status = StatusCode.TIMEOUT + static status = StatusCode.TIMEOUT; + public static [RetryPolicySymbol] = retryPolicy(Backoff.No, false, false, false); } export class PreconditionFailed extends YdbError { static status = StatusCode.PRECONDITION_FAILED + public static [RetryPolicySymbol] = retryPolicy(Backoff.No, false, false, false) } export class NotFound extends YdbError { - static status = StatusCode.NOT_FOUND + static status = StatusCode.NOT_FOUND; + public static [RetryPolicySymbol] = retryPolicy(Backoff.No, false, false, false); } export class AlreadyExists extends YdbError { - static status = StatusCode.ALREADY_EXISTS + static status = StatusCode.ALREADY_EXISTS; + public static [RetryPolicySymbol] = retryPolicy(Backoff.No, false, false, false); } export class SessionExpired extends YdbError { - static status = StatusCode.SESSION_EXPIRED + static status = StatusCode.SESSION_EXPIRED; + public static [RetryPolicySymbol] = retryPolicy(Backoff.No, true, false, false); } export class Cancelled extends YdbError { - static status = StatusCode.CANCELLED + static status = StatusCode.CANCELLED; + public static [RetryPolicySymbol] = retryPolicy(Backoff.Fast, false, false, false); } export class Undetermined extends YdbError { - static status = StatusCode.UNDETERMINED + static status = StatusCode.UNDETERMINED; + public static [RetryPolicySymbol] = retryPolicy(Backoff.Fast, false, true, false); } export class Unsupported extends YdbError { - static status = StatusCode.UNSUPPORTED + static status = StatusCode.UNSUPPORTED; + public static [RetryPolicySymbol] = retryPolicy(Backoff.Fast, true, true, true); } export class SessionBusy extends YdbError { - static status = StatusCode.SESSION_BUSY + static status = StatusCode.SESSION_BUSY; + public static [RetryPolicySymbol] = retryPolicy(Backoff.Fast, true, true, true); +} + +export class ExternalError extends YdbError { + static status = StatusCode.EXTERNAL_ERROR; + public static [RetryPolicySymbol] = retryPolicy(Backoff.No, false, false, true); } const SUCCESS_CODES = new Set([ @@ -194,6 +271,7 @@ const SERVER_SIDE_ERROR_CODES = new Map([ [StatusCode.UNDETERMINED, Undetermined], [StatusCode.UNSUPPORTED, Unsupported], [StatusCode.SESSION_BUSY, SessionBusy], + [StatusCode.EXTERNAL_ERROR, ExternalError], ]); export class TransportError extends YdbError { @@ -221,14 +299,17 @@ export class TransportError extends YdbError { export class TransportUnavailable extends TransportError { static status = StatusCode.TRANSPORT_UNAVAILABLE; + public static [RetryPolicySymbol] = retryPolicy(Backoff.Fast, true, true, false); } -export class ClientDeadlineExceeded extends TransportError { +export class ClientDeadlineExceeded extends TransportError { // TODO: static status = StatusCode.CLIENT_DEADLINE_EXCEEDED; + public static [RetryPolicySymbol] = retryPolicy(Backoff.No, false, false, false); } export class ClientResourceExhausted extends TransportError { static status = StatusCode.CLIENT_RESOURCE_EXHAUSTED; + public static [RetryPolicySymbol] = retryPolicy(Backoff.Slow, false, true, true); } const TRANSPORT_ERROR_CODES = new Map([ @@ -238,6 +319,15 @@ const TRANSPORT_ERROR_CODES = new Map([ [GrpcStatus.RESOURCE_EXHAUSTED, ClientResourceExhausted] ]); +export class ClientCancelled extends YdbError { + static status = StatusCode.CLIENT_CANCELED; + public static [RetryPolicySymbol] = retryPolicy(Backoff.Slow, false, true, true); + + constructor(public readonly cause: Error) { + super(`Operation cancelled. Cause: ${cause.message}`); + } +} + export class MissingOperation extends YdbError {} export class MissingValue extends YdbError {} diff --git a/src/index.ts b/src/index.ts index fb236acf..2a903efb 100644 --- a/src/index.ts +++ b/src/index.ts @@ -4,11 +4,14 @@ export { getLogger, setupLogger, setDefaultLogger, - Logger, - LogFn, FallbackLogger, getFallbackLogFunction, -} from './logging'; +} from './logger/deprecated'; + +export { + Logger, + LogFn, +} from './logger/simple-logger'; export {default as Driver, IDriverSettings, IPoolSettings} from './driver'; @@ -32,7 +35,7 @@ export { export {getCredentialsFromEnv, getSACredentialsFromJson} from './utils/parse-env-vars'; export {ISslCredentials} from './utils/ssl-credentials'; -export {withRetries, RetryParameters} from './retries'; +export {withRetries, RetryParameters} from './retries_obsoleted'; export {YdbError, StatusCode} from './errors'; diff --git a/src/logger/deprecated.ts b/src/logger/deprecated.ts new file mode 100644 index 00000000..3141bb9c --- /dev/null +++ b/src/logger/deprecated.ts @@ -0,0 +1,43 @@ +import {getDefaultLogger} from "./get-default-logger"; +import {Logger} from "./simple-logger"; + +/** + * @deprecated + * After refactoring the only logger that is in use, is the logger passed in object creation settings of Driver. As + * fallback logger there use SimpleLogger. + */ +export const setupLogger = (_: Logger) => { + // nothing +}; +/** + * @deprecated + * After refactoring the only logger that is in use, is the logger passed in object creation settings of Driver. As + * fallback logger there use SimpleLogger. + */ +export const getLogger = () => { + return getDefaultLogger(); +}; +/** + * @deprecated + * After refactoring the only logger that is in use, is the logger passed in object creation settings of Driver. As + * fallback logger there use SimpleLogger. + */ +export const setDefaultLogger = () => { + // nothing +}; +/** + * @deprecated + * After refactoring the only logger that is in use, is the logger passed in object creation settings of Driver. As + * fallback logger there use SimpleLogger. + */ +export const FallbackLogger = () => { + // nothing +}; +/** + * @deprecated + * After refactoring the only logger that is in use, is the logger passed in object creation settings of Driver. As + * fallback logger there use SimpleLogger. + */ +export const getFallbackLogFunction = () => { + // nothing +}; diff --git a/src/logger/get-default-logger.ts b/src/logger/get-default-logger.ts new file mode 100644 index 00000000..38195ed2 --- /dev/null +++ b/src/logger/get-default-logger.ts @@ -0,0 +1,11 @@ +import {DEFAULT_ENV_KEY, SimpleLogger} from "./simple-logger"; + +let defaultLogger: SimpleLogger; + +/** + * Returns a simple logger - logging to the console that takes the logging level from the environment + * variable YDB_SDK_LOGLEVEL. The default is "info". + */ +export function getDefaultLogger() { + return (defaultLogger || (defaultLogger = new SimpleLogger({envKey: DEFAULT_ENV_KEY}))); +} diff --git a/src/logger/has-logger.ts b/src/logger/has-logger.ts new file mode 100644 index 00000000..ccb0b48b --- /dev/null +++ b/src/logger/has-logger.ts @@ -0,0 +1,9 @@ +import {Logger} from "./simple-logger"; + +/** + * The interface grants that the object has a logger property. It is necessary that decorators can get + * the logger of the object whose method they are decorating. + */ +export interface HasLogger { + readonly logger: Logger; +} diff --git a/src/logger/hr-interval.ts b/src/logger/hr-interval.ts new file mode 100644 index 00000000..eeb4009f --- /dev/null +++ b/src/logger/hr-interval.ts @@ -0,0 +1,20 @@ +/** + * Formats time interval in human-readable form in toString(). + */ +export class HRInterval { + constructor(readonly periodMs: number) {} + toString() { + let remaining = Math.trunc(this.periodMs / 1000); + const hours = Math.trunc(remaining / 60 / 60); + + remaining -= hours * 60 * 60; + const minutes = Math.trunc(remaining / 60); + + const seconds = remaining - minutes * 60; + + return `${hours.toString() + .padStart(2, '0')}:${minutes.toString() + .padStart(2, '0')}:${seconds.toString() + .padStart(2, '0')}`; + } +} diff --git a/src/logger/simple-logger.ts b/src/logger/simple-logger.ts new file mode 100644 index 00000000..997903c1 --- /dev/null +++ b/src/logger/simple-logger.ts @@ -0,0 +1,151 @@ +export const DEFAULT_ENV_KEY = 'YDB_LOG_LEVEL'; +export const DEFAULT_LEVEL = 'info'; + +export enum LogLevel { + fatal = 'fatal', + error = 'error', + warn = 'warn', + info = 'info', + debug = 'debug', + trace = 'trace', +} + +export interface Logger { + fatal: LogFn, + error: LogFn, + warn: LogFn, + info: LogFn, + debug: LogFn, + trace: LogFn, +} + +/** + * For unit tests purposes. + */ +let consoleOrMock = console; + +/** + * **Only for unit tests purposes**. + */ +export const setMockConsole = (mockConsole: Console = console) => { + consoleOrMock = mockConsole; +}; + +const silentLogFn = () => {}; + +const simpleLogFnBuilder = (level: LogLevel): LogFn => { + const LEVEL = level.toUpperCase(); + + // eslint-disable-next-line @typescript-eslint/no-use-before-define + if (level === LogLevel.fatal) { + // eslint-disable-next-line @typescript-eslint/no-use-before-define,no-param-reassign + level = LogLevel.error; + } + + return function log(this: SimpleLogger, objOrMsg: string | unknown, ...args: unknown[]) { + const prefix: string[] = []; + + if (this.showTimestamp) { + prefix.push(new Date().toISOString()); + } + + if (this.showLevel) { + prefix.push(LEVEL); + } + + if (this.prefix) { + prefix.push(this.prefix); + } + + const prefixStr = prefix.length === 0 ? '' : `[${prefix.join(' ')}] `; + + if (typeof objOrMsg === 'object') { + if (typeof args[0] === 'string') { + // @ts-ignore + // eslint-disable-next-line @typescript-eslint/no-use-before-define + consoleOrMock[level](`${prefixStr}%o ${args[0]}`, ...args.splice(1), objOrMsg); + } else { + // @ts-ignore + // eslint-disable-next-line @typescript-eslint/no-use-before-define + consoleOrMock[level](prefix.length > 0 ? `${prefixStr}%o` : '%o', objOrMsg); + } + } else { + // @ts-ignore + // eslint-disable-next-line @typescript-eslint/no-use-before-define + consoleOrMock[level](`${prefixStr}${objOrMsg}`, ...args); + } + }; +}; + +/** + * The simplest logger class, with a minimal set of logging methods and the most simple output to the console. + */ +export class SimpleLogger implements Logger { + fatal: LogFn = silentLogFn; + error: LogFn = silentLogFn; + warn: LogFn = silentLogFn; + info: LogFn = silentLogFn; + debug: LogFn = silentLogFn; + trace: LogFn = silentLogFn; + + readonly prefix?: string; + + readonly showTimestamp: boolean; + readonly showLevel: boolean; + + constructor(options: { + /** + * Level down to which to log messages. Default is *info*. + */ + level?: LogLevel, + /** + * Prefix that gets added to a message, default undefined + */ + prefix?: string, + /** + * Whether to add the date and time to the message. Default is true. + */ + showTimestamp?: boolean, + /** + * Whether to add the message level. Default is true. + */ + showLevel?: boolean, + /** + * Environment variable with logging level, which if specified contains the level of + * logging - *error*, *warn*, *info*, *debug*, *trace*. If not specified, the value of + * level parameter is used. If a non-existing level value is specified, all levels are logged. + */ + envKey?: string, + } = {}) { + let { + level, + // eslint-disable-next-line prefer-const + prefix, + // eslint-disable-next-line prefer-const + showTimestamp, + // eslint-disable-next-line prefer-const + showLevel, + } = options; + + if (prefix) this.prefix = prefix; + this.showTimestamp = showTimestamp ?? true; + this.showLevel = showLevel ?? true; + + const envKey = options.envKey ?? DEFAULT_ENV_KEY; + const envLevel = process.env[envKey]; + + // @ts-ignore + level = envLevel === undefined ? level ?? LogLevel[DEFAULT_LEVEL] : LogLevel[envLevel]; + + for (const lvl of Object.values(LogLevel)) { + // @ts-ignore + this[lvl] = simpleLogFnBuilder(lvl); + if (lvl === level) break; + } + } +} + +export interface LogFn { + (obj: unknown, msg?: string, ...args: unknown[]): void; + (msg: string, ...args: unknown[]): void; +} diff --git a/src/logger/tests/test-logger.ts b/src/logger/tests/test-logger.ts new file mode 100644 index 00000000..801eac27 --- /dev/null +++ b/src/logger/tests/test-logger.ts @@ -0,0 +1,15 @@ +import { LogFn } from '../simple-logger'; + +export const buildTestLogger = () => { + const testLoggerFn = jest.fn(); + const testLogger = { + fatal: testLoggerFn.bind(undefined, 'fatal') as LogFn, + error: testLoggerFn.bind(undefined, 'error') as LogFn, + warn: testLoggerFn.bind(undefined, 'warn') as LogFn, + info: testLoggerFn.bind(undefined, 'info') as LogFn, + debug: testLoggerFn.bind(undefined, 'debug') as LogFn, + trace: testLoggerFn.bind(undefined, 'trace') as LogFn, + }; + + return { testLogger, testLoggerFn }; +}; diff --git a/src/logging.ts b/src/logging.ts deleted file mode 100644 index a6366634..00000000 --- a/src/logging.ts +++ /dev/null @@ -1,99 +0,0 @@ -export interface LogFn { - (obj: unknown, msg?: string, ...args: any[]): void; - (msg: string, ...args: any[]): void; -} - -export interface Logger { - fatal: LogFn; - error: LogFn; - warn: LogFn; - info: LogFn; - debug: LogFn; - trace: LogFn; -} - -const LOGLEVEL = process.env.YDB_SDK_LOGLEVEL || 'info'; - -const defaultLoggerOptions = { - level: LOGLEVEL, -}; - -let globalLogger: Logger | null = null; - -/** - * Sets up logger - * Use before any usage of YDB-SDK functions. If not used, fallback logger will be used - */ -export function setupLogger(logger: Logger) { - if(globalLogger !== null) globalLogger.warn(`Reassigning logger, some logs can be lost`) - globalLogger = logger; - globalLogger.debug(`Default logger changed to ${globalLogger.constructor.name}`); -} -/** - * @deprecated - * Use setupLogger instead - */ -export function setDefaultLogger(logger: Logger){ - return setupLogger(logger) -} - -/** basic fallback implementation of LogFn */ -export function getFallbackLogFunction(level: string) { - function log(msg: string, ...args: any[]): void; - function log(obj: unknown, msg?: string, ...args: any[]): void; - function log(obj: string | unknown, ...args: any[]): void { - const dateLevel = `[${new Date().toISOString()} ${level.toUpperCase()}]`; - - if (typeof obj === 'object') { - let objectString: string; - try { - objectString = JSON.stringify(obj); - } catch (error) { - objectString = String(obj); - } - console.log(dateLevel, objectString, ...args); - } else console.log(dateLevel, obj, ...args); - } - return log; -} - -export class FallbackLogger implements Logger { - fatal: LogFn = () => {}; - error: LogFn = () => {}; - warn: LogFn = () => {}; - info: LogFn = () => {}; - debug: LogFn = () => {}; - trace: LogFn = () => {}; - - constructor(options = defaultLoggerOptions) { - if (!options.level) options.level = 'info'; - switch (options.level.toLowerCase()) { - // @ts-ignore no-switch-case-fall-through - case 'trace': - this.trace = getFallbackLogFunction('trace'); - // @ts-ignore - case 'debug': - this.debug = getFallbackLogFunction('debug'); - default: - // @ts-ignore - case 'info': - this.info = getFallbackLogFunction('info'); - // @ts-ignore - case 'warn': - this.warn = getFallbackLogFunction('warn'); - // @ts-ignore - case 'error': - this.error = getFallbackLogFunction('error'); - case 'fatal': - this.fatal = getFallbackLogFunction('fatal'); - } - } -} - -export function getLogger(options?: any): Logger { - if (!globalLogger) { - globalLogger = new FallbackLogger(options); - globalLogger.debug('Using fallback logger'); - } - return globalLogger; -} diff --git a/src/query/query-client.ts b/src/query/query-client.ts index bb8c5f52..c9b924bd 100644 --- a/src/query/query-client.ts +++ b/src/query/query-client.ts @@ -3,12 +3,11 @@ import {QuerySessionPool, SessionCallback, SessionEvent} from "./query-session-p import {ISslCredentials} from "../utils/ssl-credentials"; import {IPoolSettings} from "../driver"; import DiscoveryService from "../discovery/discovery-service"; -import {Logger} from "../logging"; import {ClientOptions} from "../utils"; import {IAuthService} from "../credentials/i-auth-service"; import {Ydb} from "ydb-sdk-proto"; import {AUTO_TX} from "../table"; -import {withRetries} from "../retries"; +import {withRetries} from "../retries_obsoleted"; import { sessionTxSettingsSymbol, sessionTxIdSymbol, @@ -18,8 +17,9 @@ import { sessionReleaseSymbol } from "./symbols"; import {BadSession, SessionBusy} from "../errors"; -import {Context, CtxDispose} from "../context/Context"; -import {EnsureContext} from "../context/ensureContext"; +import {Context, CtxDispose} from "../context"; +import {ensureContext} from "../context/ensure-context"; +import {Logger} from "../logger/simple-logger"; export interface IQueryClientSettings { database: string; @@ -60,7 +60,7 @@ export class QueryClient extends EventEmitter { await this.pool.destroy(); } - @EnsureContext() + @ensureContext() public async do(opts: IDoOpts): Promise { let ctx = opts.ctx!; // guarnteed by @EnsureContext() let dispose: CtxDispose | undefined; @@ -116,7 +116,7 @@ export class QueryClient extends EventEmitter { } } - @EnsureContext() + @ensureContext() public doTx(opts: IDoOpts): Promise { if (!opts.txSettings) { opts = {...opts, txSettings: AUTO_TX.beginTx}; diff --git a/src/query/query-session-pool.ts b/src/query/query-session-pool.ts index adc98ffb..c3ce46c7 100644 --- a/src/query/query-session-pool.ts +++ b/src/query/query-session-pool.ts @@ -2,9 +2,8 @@ import {Ydb} from "ydb-sdk-proto"; export import QueryService = Ydb.Query.V1.QueryService; import CreateSessionRequest = Ydb.Query.CreateSessionRequest; import {Endpoint} from "../discovery"; -import {Logger} from "../logging"; import {ISslCredentials} from "../utils/ssl-credentials"; -import {retryable} from "../retries"; +import {retryable} from "../retries_obsoleted"; import EventEmitter from "events"; import DiscoveryService from "../discovery/discovery-service"; import {Events} from "../constants"; @@ -25,6 +24,7 @@ import { sessionReleaseSymbol, sessionIsDeletedSymbol } from './symbols'; +import {Logger} from "../logger/simple-logger"; export class SessionBuilder extends AuthenticatedService { public endpoint: Endpoint; diff --git a/src/query/query-session.ts b/src/query/query-session.ts index 70387348..d3640acd 100644 --- a/src/query/query-session.ts +++ b/src/query/query-session.ts @@ -1,8 +1,7 @@ import EventEmitter from "events"; import {QueryService, SessionBuilder, SessionEvent} from "./query-session-pool"; import {Endpoint} from "../discovery"; -import {Logger} from "../logging"; -import {retryable} from "../retries"; +import {retryable} from "../retries_obsoleted"; import {pessimizable} from "../utils"; import {ensureCallSucceeded} from "../utils/process-ydb-operation-result"; import {Ydb} from "ydb-sdk-proto"; @@ -34,6 +33,7 @@ import { commitTransaction as commitTransactionImpl, rollbackTransaction as rollbackTransactionImpl } from './query-session-transaction'; +import {Logger} from "../logger/simple-logger"; /** * Service methods, as they name in GRPC. diff --git a/src/retries/message.ts b/src/retries/message.ts new file mode 100644 index 00000000..17d1de2b --- /dev/null +++ b/src/retries/message.ts @@ -0,0 +1,4 @@ +export const fastBackoffRetryMessage = 'Caught an error %s, retrying with fast backoff in %d ms'; +export const slowBackoffRetryMessage = 'Caught an error %s, retrying with slow backoff in %d ms'; +export const notRetryableErrorMessage = 'Caught an error %s, it is not retriable'; +export const errorIsNotRetryableForNonIdempotentOperationMessage = 'Caught an error %s, it is not retriable for non idempotent operation'; diff --git a/src/retries/retryParameters.ts b/src/retries/retryParameters.ts new file mode 100644 index 00000000..ae7b0290 --- /dev/null +++ b/src/retries/retryParameters.ts @@ -0,0 +1,58 @@ +import * as utils from "../utils"; +import {YdbError} from "../errors"; + +export class BackoffSettings { + /** + * Create backoff settings - uses randomized exponential timeouts with a base of 2 + * Timeout formula: `2^min(retries, backoffCeiling) * backoffSlotDuration * (1 - random() * uncertainRatio)` + * @param backoffCeiling - max power — (n) in `2^n` + * @param backoffSlotDuration - multiplier for exponent + * @param uncertainRatio - timeout fraction that is randomized + */ + constructor( + public backoffCeiling: number, + public backoffSlotDuration: number, + private uncertainRatio = 0.5, + ) { + } + + async waitBackoffTimeout(retries: number) { + const slotsCount = 1 << Math.min(retries, this.backoffCeiling); + const maxDuration = slotsCount * this.backoffSlotDuration; + const duration = maxDuration * (1 - Math.random() * this.uncertainRatio); + return utils.sleep(duration); + } +} + +export class RetryParameters { + public timeout: number = 0; + public retryNotFound: boolean; + public unknownErrorHandler: (_error: unknown) => void; + public maxRetries: number; + public onYdbErrorCb: (_error: YdbError) => void; + public fastBackoff: BackoffSettings; + public slowBackoff: BackoffSettings; + + constructor(opts?: { + /** + * @deprecated to be consistent with other YDB SDKes, the repeater is now limited not by the number of attempts, but + * by the time to attempt the operation. use timeout parameter + */ + maxRetries?: number, // TODO: Obsoleted + onYdbErrorCb?: (_error: YdbError) => void, // TODO: Where is in use + backoffCeiling?: number, + backoffSlotDuration?: number, + timeout?: number, + }) { + if (opts?.hasOwnProperty('timeout') && opts.timeout! > 0) this.timeout = opts.timeout!; + + this.maxRetries = opts?.maxRetries ?? 10; + this.onYdbErrorCb = opts?.onYdbErrorCb ?? ((_error: YdbError) => { + }); + this.fastBackoff = new BackoffSettings(10, 5); + this.slowBackoff = new BackoffSettings(opts?.backoffCeiling ?? 6, opts?.backoffSlotDuration ?? 1000); + + this.retryNotFound = true; + this.unknownErrorHandler = () => {}; + } +} diff --git a/src/retries/retryStrategy.ts b/src/retries/retryStrategy.ts new file mode 100644 index 00000000..5dd1b42f --- /dev/null +++ b/src/retries/retryStrategy.ts @@ -0,0 +1,65 @@ +import {Backoff, ClientCancelled, SpecificErrorRetryPolicy, YdbError} from "../errors"; +import {HasLogger} from "../logger/has-logger"; +import {Logger} from "../logger/simple-logger"; +import {RetryParameters} from "./retryParameters"; +import {Context} from "../context"; +import {RetryPolicySymbol} from "./symbols"; + +export interface RetryDelta { + (ctx: Context, attemptsCount: number, logger: Logger): Promise<{ + result?: T, + err?: YdbError, // YdbError errors are not get thrown since to retry we also need to know is operation is idempotent + idempotent?: boolean + }>; +} + +export class RetryStrategy implements HasLogger { + constructor( + // public methodName = 'UnknownClass::UnknownMethod', + public retryParameters: RetryParameters, + public readonly logger: Logger + ) { + } + + // @EnsureContext(true) + public async retry( + ctx: Context, + fn: RetryDelta + ): Promise { + let attemptsCounter: number = 0; + let prevError: YdbError | undefined; + let sameErrorCount: number = 0; + while (true) { + const r = await fn(ctx, attemptsCounter++, this.logger); + // TODO: retryParameters.onYdbErrorCb(e); + // TODO: log debug messages + // TODO: repleca retries in a test + // TODO: pessinizable + if (r.err) { + // Note: deleteSession suppose to be processed in delta function + const retryPolicy = (r.err as any).constructor[RetryPolicySymbol] as SpecificErrorRetryPolicy; + const doRetry = r.idempotent ? retryPolicy.idempotent : retryPolicy.nonIdempotent; + if (doRetry) { + if (retryPolicy.backoff === Backoff.No) continue; // immediate retry + if (r.err === prevError) { // same repeating Error slows down retries exponentially + sameErrorCount++; + } else { + prevError = r.err; + sameErrorCount = 0; + } + const backoff = retryPolicy.backoff === Backoff.Fast + ? this.retryParameters.fastBackoff + : this.retryParameters.slowBackoff; + await backoff.waitBackoffTimeout(sameErrorCount); + } + if (ctx.err) { // here to make sure that operation was not cancelled while awaiting retry time + throw new ClientCancelled(ctx.err); + } + throw r.err; + } + return r.result!; + } + } +} + +export type RetryableResult = (target: HasLogger, propertyKey: string, descriptor: PropertyDescriptor) => void; diff --git a/src/retries/symbols.ts b/src/retries/symbols.ts new file mode 100644 index 00000000..4db79743 --- /dev/null +++ b/src/retries/symbols.ts @@ -0,0 +1 @@ +export const RetryPolicySymbol = Symbol('retryPolicy'); diff --git a/src/retries.ts b/src/retries_obsoleted.ts similarity index 84% rename from src/retries.ts rename to src/retries_obsoleted.ts index 87635b0f..d27de982 100644 --- a/src/retries.ts +++ b/src/retries_obsoleted.ts @@ -1,7 +1,8 @@ import {YdbError, TransportError} from './errors'; -import {getLogger, Logger} from './logging'; import * as errors from './errors'; import * as utils from "./utils"; +import {Logger} from "./logger/simple-logger"; +// import {getDefaultLogger} from "./logger/get-default-logger"; export class BackoffSettings { /** @@ -59,13 +60,13 @@ const RETRYABLE_ERRORS_FAST = [ const RETRYABLE_ERRORS_SLOW = [errors.Overloaded, errors.ClientResourceExhausted]; class RetryStrategy { - private logger: Logger; + // private logger: Logger; constructor( public methodName = 'UnknownClass::UnknownMethod', public retryParameters: RetryParameters, - logger?: Logger, + _logger?: Logger, ) { - this.logger = logger ?? getLogger(); + // this.logger = logger ?? getDefaultLogger(); } async retry(asyncMethod: () => Promise) { @@ -79,24 +80,24 @@ class RetryStrategy { if(TransportError.isMember(e)) e = TransportError.convertToYdbError(e) error = e; if (e instanceof YdbError) { - const errName = e.constructor.name; - const retriesLeft = retryParameters.maxRetries - retries; + // const errName = e.constructor.name; + // const retriesLeft = retryParameters.maxRetries - retries; if (RETRYABLE_ERRORS_FAST.some((cls) => e instanceof cls)) { retryParameters.onYdbErrorCb(e); if (e instanceof errors.NotFound && !retryParameters.retryNotFound) { throw e; } - this.logger.warn( - `Caught an error ${errName}, retrying with fast backoff, ${retriesLeft} retries left`, - ); + // this.logger.warn( + // `Caught an error ${errName}, retrying with fast backoff, ${retriesLeft} retries left`, + // ); await this.retryParameters.fastBackoff.waitBackoffTimeout(retries); } else if (RETRYABLE_ERRORS_SLOW.some((cls) => e instanceof cls)) { retryParameters.onYdbErrorCb(e); - this.logger.warn( - `Caught an error ${errName}, retrying with slow backoff, ${retriesLeft} retries left`, - ); + // this.logger.warn( + // `Caught an error ${errName}, retrying with slow backoff, ${retriesLeft} retries left`, + // ); await this.retryParameters.slowBackoff.waitBackoffTimeout(retries); } else { retryParameters.onYdbErrorCb(e); @@ -109,7 +110,7 @@ class RetryStrategy { } retries++; } - this.logger.warn('All retries have been used, re-throwing error'); + // this.logger.warn('All retries have been used, re-throwing error'); throw error; } } diff --git a/src/schema/scheme-client.ts b/src/schema/scheme-client.ts index 01391332..47ea25f1 100644 --- a/src/schema/scheme-client.ts +++ b/src/schema/scheme-client.ts @@ -15,7 +15,7 @@ import {IAuthService} from "../credentials/i-auth-service"; import {ISslCredentials} from "../utils/ssl-credentials"; import {ClientOptions} from "../utils"; import DiscoveryService from "../discovery/discovery-service"; -import {Logger} from "../logging"; +import {Logger} from "../logger/simple-logger"; interface ISchemeClientSettings { database: string; diff --git a/src/schema/scheme-service.ts b/src/schema/scheme-service.ts index 615eaaec..be5d8c29 100644 --- a/src/schema/scheme-service.ts +++ b/src/schema/scheme-service.ts @@ -7,12 +7,12 @@ import IMakeDirectoryRequest = Ydb.Scheme.IMakeDirectoryRequest; import IPermissions = Ydb.Scheme.IPermissions; import {OperationParamsSettings} from "../table"; import {AuthenticatedService, ClientOptions, pessimizable} from "../utils"; -import {Logger} from "../logging"; import {Endpoint} from "../discovery"; import {IAuthService} from "../credentials/i-auth-service"; import {ISslCredentials} from "../utils/ssl-credentials"; -import {retryable} from "../retries"; +import {retryable} from "../retries_obsoleted"; import {ensureOperationSucceeded, getOperationPayload} from "../utils/process-ydb-operation-result"; +import {Logger} from "../logger/simple-logger"; function preparePermissions(action?: IPermissions | null) { if (action && action.permissionNames) { diff --git a/src/table/table-client.ts b/src/table/table-client.ts index b5195b89..1d7769b9 100644 --- a/src/table/table-client.ts +++ b/src/table/table-client.ts @@ -3,13 +3,12 @@ import {TableSessionPool} from "./table-session-pool"; import {ISslCredentials} from "../utils/ssl-credentials"; import {IPoolSettings} from "../driver"; import DiscoveryService from "../discovery/discovery-service"; -import {Logger} from "../logging"; import {TableSession} from "./table-session"; import {ClientOptions} from "../utils"; import {IAuthService} from "../credentials/i-auth-service"; -import {Context} from "../context/Context"; -import {EnsureContext} from "../context/ensureContext"; +import {Context, ensureContext} from "../context"; +import {Logger} from "../logger/simple-logger"; export interface ITableClientSettings { database: string; @@ -32,7 +31,7 @@ export class TableClient extends EventEmitter { // @ts-ignore public async withSession(callback: (session: TableSession) => Promise, timeout?: number): Promise; public async withSession(ctx: Context, callback: (session: TableSession) => Promise, timeout?: number): Promise; - @EnsureContext(true) + @ensureContext(true) public async withSession(ctx: Context, callback: (session: TableSession) => Promise, timeout: number = 0): Promise { return this.pool.withSession(ctx, callback, timeout); } @@ -40,7 +39,7 @@ export class TableClient extends EventEmitter { // @ts-ignore public async withSessionRetry(callback: (session: TableSession) => Promise, timeout?: number, maxRetries?: number): Promise; public async withSessionRetry(ctx: Context, callback: (session: TableSession) => Promise, timeout?: number, maxRetries?: number): Promise; - @EnsureContext(true) + @ensureContext(true) public async withSessionRetry(ctx: Context, callback: (session: TableSession) => Promise, timeout: number = 0, maxRetries = 10): Promise { return this.pool.withSessionRetry(ctx, callback, timeout, maxRetries); } @@ -48,7 +47,7 @@ export class TableClient extends EventEmitter { // @ts-ignore public async destroy(): Promise; public async destroy(ctx: Context): Promise; - @EnsureContext(true) + @ensureContext(true) public async destroy(ctx: Context): Promise { await this.pool.destroy(ctx); } diff --git a/src/table/table-session-pool.ts b/src/table/table-session-pool.ts index 6c071bc9..56ac5199 100644 --- a/src/table/table-session-pool.ts +++ b/src/table/table-session-pool.ts @@ -4,9 +4,8 @@ import CreateSessionRequest = Ydb.Table.CreateSessionRequest; export import ICreateSessionResult = Ydb.Table.ICreateSessionResult; import CreateSessionResult = Ydb.Table.CreateSessionResult; import {Endpoint} from "../discovery"; -import {Logger} from "../logging"; import {ISslCredentials} from "../utils/ssl-credentials"; -import {retryable} from "../retries"; +import {retryable} from "../retries_obsoleted"; import EventEmitter from "events"; import DiscoveryService from "../discovery/discovery-service"; import {Events, SESSION_KEEPALIVE_PERIOD} from "../constants"; @@ -19,8 +18,8 @@ import {pessimizable} from "../utils"; import {getOperationPayload} from "../utils/process-ydb-operation-result"; import {AuthenticatedService, ClientOptions} from "../utils"; import {IAuthService} from "../credentials/i-auth-service"; -import {Context} from "../context/Context"; -import {EnsureContext} from "../context/ensureContext"; +import {Context, ensureContext} from "../context"; +import {Logger} from "../logger/simple-logger"; export class SessionBuilder extends AuthenticatedService { public endpoint: Endpoint; @@ -94,7 +93,7 @@ export class TableSessionPool extends EventEmitter { // @ts-ignore public async destroy(): Promise; public async destroy(ctx: Context): Promise; - @EnsureContext(true) + @ensureContext(true) public async destroy(_ctx: Context): Promise { this.logger.debug('Destroying pool...'); clearInterval(this.sessionKeepAliveId); @@ -241,7 +240,7 @@ export class TableSessionPool extends EventEmitter { // @ts-ignore public async withSession(callback: SessionCallback, timeout: number): Promise; public async withSession(ctx: Context, callback: SessionCallback, timeout: number): Promise; - @EnsureContext(true) + @ensureContext(true) public async withSession(ctx: Context, callback: SessionCallback, timeout: number = 0): Promise { const session = await this.acquire(timeout); return this._withSession(ctx, session, callback); @@ -250,7 +249,7 @@ export class TableSessionPool extends EventEmitter { // @ts-ignore public async withSessionRetry(callback: SessionCallback, timeout: number = 0, maxRetries: number): Promise; public async withSessionRetry(ctx: Context, callback: SessionCallback, timeout: number, maxRetries: number): Promise; - @EnsureContext(true) + @ensureContext(true) public async withSessionRetry(ctx: Context, callback: SessionCallback, timeout: number = 0, maxRetries: number = 10): Promise { const session = await this.acquire(timeout); return this._withSession(ctx, session, callback, maxRetries); diff --git a/src/table/table-session.ts b/src/table/table-session.ts index 63df1a47..eb70808b 100644 --- a/src/table/table-session.ts +++ b/src/table/table-session.ts @@ -21,13 +21,13 @@ import * as grpc from "@grpc/grpc-js"; import EventEmitter from "events"; import {ICreateSessionResult, SessionEvent, TableService} from "./table-session-pool"; import {Endpoint} from "../discovery"; -import {Logger} from "../logging"; -import {retryable} from "../retries"; +import {retryable} from "../retries_obsoleted"; import {MissingStatus, MissingValue, SchemeError, YdbError} from "../errors"; import {ResponseMetadataKeys} from "../constants"; import {pessimizable} from "../utils"; import {YdbOperationAsyncResponse, ensureOperationSucceeded, getOperationPayload} from "../utils/process-ydb-operation-result"; import {StreamEnd} from "../utils"; +import {Logger} from "../logger/simple-logger"; interface PartialResponse { status?: (Ydb.StatusIds.StatusCode | null); diff --git a/src/utils/parse-env-vars.ts b/src/utils/parse-env-vars.ts index dc104453..306ff0e1 100644 --- a/src/utils/parse-env-vars.ts +++ b/src/utils/parse-env-vars.ts @@ -1,10 +1,11 @@ import fs from 'fs'; -import {getLogger, Logger} from '../logging'; import {IamAuthService, IIamCredentials} from "../credentials/iam-auth-service"; import {MetadataAuthService} from "../credentials/metadata-auth-service"; import {TokenAuthService} from "../credentials/token-auth-service"; import {AnonymousAuthService} from "../credentials/anonymous-auth-service"; import {IAuthService} from "../credentials/i-auth-service"; +import {Logger} from "../logger/simple-logger"; +import {getDefaultLogger} from "../logger/get-default-logger"; export function getSACredentialsFromJson(filename: string): IIamCredentials { const buffer = fs.readFileSync(filename); @@ -18,7 +19,7 @@ export function getSACredentialsFromJson(filename: string): IIamCredentials { } export function getCredentialsFromEnv(logger?: Logger): IAuthService { - logger = logger || getLogger(); + logger = logger || getDefaultLogger(); if (process.env.YDB_SERVICE_ACCOUNT_KEY_FILE_CREDENTIALS) { logger.debug('YDB_SERVICE_ACCOUNT_KEY_FILE_CREDENTIALS env var found, using IamAuthService with params from that json file.'); return new IamAuthService(getSACredentialsFromJson(process.env.YDB_SERVICE_ACCOUNT_KEY_FILE_CREDENTIALS)); diff --git a/src/utils/ssl-credentials.ts b/src/utils/ssl-credentials.ts index 7d5129bc..e1768667 100644 --- a/src/utils/ssl-credentials.ts +++ b/src/utils/ssl-credentials.ts @@ -2,8 +2,8 @@ import * as fs from 'fs'; import * as tls from 'tls'; // noinspection ES6PreferShortImport -import { Logger } from '../logging'; import certs from '../certs/certs.json'; +import {Logger} from "../logger/simple-logger"; function makeInternalRootCertificates() { const internalRootCertificates = Buffer.from(certs.internal, 'utf8') diff --git a/src/utils/test/create-table.ts b/src/utils/test/create-table.ts index 5daed052..3564c406 100644 --- a/src/utils/test/create-table.ts +++ b/src/utils/test/create-table.ts @@ -1,5 +1,5 @@ import {Column, TableDescription, TableSession} from "../../table"; -import {withRetries} from "../../retries"; +import {withRetries} from "../../retries_obsoleted"; import {Types} from "../../types"; import {Row} from "./row";