diff --git a/.config/ci.yml b/.config/ci.yml index 7d5261aacd..5fcf78b737 100644 --- a/.config/ci.yml +++ b/.config/ci.yml @@ -115,6 +115,10 @@ db: user: postgres pass: ci + ## Log a warning to the server console if any query takes longer than this to complete. + ## Measured in milliseconds; set to 0 to disable. (default: 300) + #slowQueryThreshold: 300 + # If false, then query results will be cached in redis. # If true (default), then queries will not be cached. # This will reduce database load at the cost of increased Redis traffic and risk of bugs and unpredictable behavior. diff --git a/.config/cypress-devcontainer.yml b/.config/cypress-devcontainer.yml index 51f408983c..97263da68f 100644 --- a/.config/cypress-devcontainer.yml +++ b/.config/cypress-devcontainer.yml @@ -57,6 +57,10 @@ db: user: postgres pass: postgres + ## Log a warning to the server console if any query takes longer than this to complete. + ## Measured in milliseconds; set to 0 to disable. (default: 300) + #slowQueryThreshold: 300 + # If false, then query results will be cached in redis. # If true (default), then queries will not be cached. # This will reduce database load at the cost of increased Redis traffic and risk of bugs and unpredictable behavior. diff --git a/.config/docker_example.yml b/.config/docker_example.yml index 1b55eee7f5..3aaa56e333 100644 --- a/.config/docker_example.yml +++ b/.config/docker_example.yml @@ -118,6 +118,10 @@ db: user: example-misskey-user pass: example-misskey-pass + ## Log a warning to the server console if any query takes longer than this to complete. + ## Measured in milliseconds; set to 0 to disable. (default: 300) + #slowQueryThreshold: 300 + # If false, then query results will be cached in redis. # If true (default), then queries will not be cached. # This will reduce database load at the cost of increased Redis traffic and risk of bugs and unpredictable behavior. diff --git a/.config/example.yml b/.config/example.yml index b7843da9ad..8cac42c050 100644 --- a/.config/example.yml +++ b/.config/example.yml @@ -121,13 +121,15 @@ db: user: sharkey pass: example-misskey-pass + ## Log a warning to the server console if any query takes longer than this to complete. + ## Measured in milliseconds; set to 0 to disable. (default: 300) + #slowQueryThreshold: 300 + # If false, then query results will be cached in redis. # If true (default), then queries will not be cached. # This will reduce database load at the cost of increased Redis traffic and risk of bugs and unpredictable behavior. #disableCache: false - # - # Extra Connection options #extra: # ssl: true diff --git a/packages/backend/src/config.ts b/packages/backend/src/config.ts index d61112ae40..c2e7efd456 100644 --- a/packages/backend/src/config.ts +++ b/packages/backend/src/config.ts @@ -41,6 +41,7 @@ type Source = { db?: string; user?: string; pass?: string; + slowQueryThreshold?: number; disableCache?: boolean; extra?: { [x: string]: string }; }; @@ -225,6 +226,7 @@ export type Config = { db: string; user: string; pass: string; + slowQueryThreshold?: number; disableCache?: boolean; extra?: { [x: string]: string }; }; @@ -411,6 +413,10 @@ export function loadConfig(): Config { const internalMediaProxy = `${scheme}://${host}/proxy`; const redis = convertRedisOptions(config.redis, host); + // nullish => 300 (default) + // 0 => undefined (disabled) + const slowQueryThreshold = (config.db.slowQueryThreshold ?? 300) || undefined; + return { version, publishTarballInsteadOfProvideRepositoryUrl: !!config.publishTarballInsteadOfProvideRepositoryUrl, @@ -429,7 +435,7 @@ export function loadConfig(): Config { apiUrl: `${scheme}://${host}/api`, authUrl: `${scheme}://${host}/auth`, driveUrl: `${scheme}://${host}/files`, - db: { ...config.db, db: dbDb, user: dbUser, pass: dbPass }, + db: { ...config.db, db: dbDb, user: dbUser, pass: dbPass, slowQueryThreshold }, dbReplications: config.dbReplications, dbSlaves: config.dbSlaves, fulltextSearch: config.fulltextSearch, @@ -637,7 +643,7 @@ function applyEnvOverrides(config: Source) { // these are all the settings that can be overridden _apply_top([['url', 'port', 'address', 'socket', 'chmodSocket', 'disableHsts', 'id', 'dbReplications', 'websocketCompression']]); - _apply_top(['db', ['host', 'port', 'db', 'user', 'pass', 'disableCache']]); + _apply_top(['db', ['host', 'port', 'db', 'user', 'pass', 'slowQueryThreshold', 'disableCache']]); _apply_top(['dbSlaves', Array.from((config.dbSlaves ?? []).keys()), ['host', 'port', 'db', 'user', 'pass']]); _apply_top([ ['redis', 'redisForPubsub', 'redisForJobQueue', 'redisForTimelines', 'redisForReactions', 'redisForRateLimit'], diff --git a/packages/backend/src/postgres.ts b/packages/backend/src/postgres.ts index 34fca6dd92..b4bd934972 100644 --- a/packages/backend/src/postgres.ts +++ b/packages/backend/src/postgres.ts @@ -98,9 +98,12 @@ pg.types.setTypeParser(20, Number); export const dbLogger = new MisskeyLogger('db'); const sqlLogger = dbLogger.createSubLogger('sql', 'gray'); +const sqlMigrateLogger = sqlLogger.createSubLogger('migrate'); +const sqlSchemaLogger = sqlLogger.createSubLogger('schema'); export type LoggerProps = { disableQueryTruncation?: boolean; + enableQueryLogging?: boolean; enableQueryParamLogging?: boolean; printReplicationMode?: boolean, }; @@ -112,7 +115,7 @@ function highlightSql(sql: string) { } function truncateSql(sql: string) { - return sql.length > 100 ? `${sql.substring(0, 100)}...` : sql; + return sql.length > 100 ? `${sql.substring(0, 100)} [truncated]` : sql; } function stringifyParameter(param: any) { @@ -136,7 +139,7 @@ class MyCustomLogger implements Logger { modded = truncateSql(modded); } - return highlightSql(modded); + return this.props.enableQueryLogging ? highlightSql(modded) : modded; } @bindThis @@ -150,6 +153,8 @@ class MyCustomLogger implements Logger { @bindThis public logQuery(query: string, parameters?: any[], queryRunner?: QueryRunner) { + if (!this.props.enableQueryLogging) return; + const prefix = (this.props.printReplicationMode && queryRunner) ? `[${queryRunner.getReplicationMode()}] ` : undefined; @@ -161,7 +166,8 @@ class MyCustomLogger implements Logger { const prefix = (this.props.printReplicationMode && queryRunner) ? `[${queryRunner.getReplicationMode()}] ` : undefined; - sqlLogger.error(this.transformQueryLog(query, { prefix }), this.transformParameters(parameters)); + const transformed = this.transformQueryLog(query, { prefix }); + sqlLogger.error(`Query error (${error}): ${transformed}`, this.transformParameters(parameters)); } @bindThis @@ -169,22 +175,32 @@ class MyCustomLogger implements Logger { const prefix = (this.props.printReplicationMode && queryRunner) ? `[${queryRunner.getReplicationMode()}] ` : undefined; - sqlLogger.warn(this.transformQueryLog(query, { prefix }), this.transformParameters(parameters)); + const transformed = this.transformQueryLog(query, { prefix }); + sqlLogger.warn(`Query is slow (${time}ms): ${transformed}`, this.transformParameters(parameters)); } @bindThis public logSchemaBuild(message: string) { - sqlLogger.info(message); + sqlSchemaLogger.debug(message); } @bindThis - public log(message: string) { - sqlLogger.info(message); + public log(level: 'log' | 'info' | 'warn', message: string) { + switch (level) { + case 'log': + case 'info': { + sqlLogger.info(message); + break; + } + case 'warn': { + sqlLogger.warn(message); + } + } } @bindThis public logMigration(message: string) { - sqlLogger.info(message); + sqlMigrateLogger.debug(message); } } @@ -314,14 +330,13 @@ export function createPostgresDataSource(config: Config) { }, } : false, logging: log, - logger: log - ? new MyCustomLogger({ - disableQueryTruncation: config.logging?.sql?.disableQueryTruncation, - enableQueryParamLogging: config.logging?.sql?.enableQueryParamLogging, - printReplicationMode: !!config.dbReplications, - }) - : undefined, - maxQueryExecutionTime: 300, + logger: new MyCustomLogger({ + disableQueryTruncation: config.logging?.sql?.disableQueryTruncation, + enableQueryLogging: log, + enableQueryParamLogging: config.logging?.sql?.enableQueryParamLogging, + printReplicationMode: !!config.dbReplications, + }), + maxQueryExecutionTime: config.db.slowQueryThreshold, entities: entities, migrations: ['../../migration/*.js'], });