Server: Added support for app level slow SQL query log

packages/server/src/config.ts

@@ -48,6 +48,9 @@ export interface EnvVariables {
 	BUSINESS_EMAIL?: string;
 
 	COOKIES_SECURE?: string;
+
+	SLOW_QUERY_LOG_ENABLED?: string;
+	SLOW_QUERY_LOG_MIN_DURATION?: string; // ms
 }
 
 let runningInDocker_: boolean = false;
@@ -56,6 +59,17 @@ export function runningInDocker(): boolean {
 	return runningInDocker_;
 }
 
+function envParseBool(s: string): boolean {
+	return s === '1';
+}
+
+function envParseInt(s: string, defaultValue: number = null): number {
+	if (!s) return defaultValue === null ? 0 : defaultValue;
+	const output = Number(s);
+	if (isNaN(output)) throw new Error(`Invalid number: ${s}`);
+	return output;
+}
+
 function databaseHostFromEnv(runningInDocker: boolean, env: EnvVariables): string {
 	if (env.POSTGRES_HOST) {
 		// When running within Docker, the app localhost is different from the
@@ -72,8 +86,16 @@ function databaseHostFromEnv(runningInDocker: boolean, env: EnvVariables): strin
 }
 
 function databaseConfigFromEnv(runningInDocker: boolean, env: EnvVariables): DatabaseConfig {
+	const baseConfig: DatabaseConfig = {
+		client: DatabaseConfigClient.Null,
+		name: '',
+		slowQueryLogEnabled: envParseBool(env.SLOW_QUERY_LOG_ENABLED),
+		slowQueryLogMinDuration: envParseInt(env.SLOW_QUERY_LOG_MIN_DURATION, 10000),
+	};
+
 	if (env.DB_CLIENT === 'pg') {
 		return {
+			...baseConfig,
 			client: DatabaseConfigClient.PostgreSQL,
 			name: env.POSTGRES_DATABASE || 'joplin',
 			user: env.POSTGRES_USER || 'joplin',
@@ -84,6 +106,7 @@ function databaseConfigFromEnv(runningInDocker: boolean, env: EnvVariables): Dat
 	}
 
 	return {
+		...baseConfig,
 		client: DatabaseConfigClient.SQLite,
 		name: env.SQLITE_DATABASE,
 		asyncStackTraces: true,

packages/server/src/db.ts

@@ -104,25 +104,55 @@ export async function waitForConnection(dbConfig: DatabaseConfig): Promise<Conne
 	}
 }
 
+function makeSlowQueryHandler(duration: number, connection: any, sql: string, bindings: any[]) {
+	return setTimeout(() => {
+		try {
+			logger.warn(`Slow query (${duration}ms+):`, connection.raw(sql, bindings).toString());
+		} catch (error) {
+			logger.error('Could not log slow query', { sql, bindings }, error);
+		}
+	}, duration);
+}
+
+export function setupSlowQueryLog(connection: DbConnection, slowQueryLogMinDuration: number) {
+	interface QueryInfo {
+		timeoutId: any;
+		startTime: number;
+	}
+
+	const queryInfos: Record<any, QueryInfo> = {};
+
+	connection.on('query', (data) => {
+		const timeoutId = makeSlowQueryHandler(slowQueryLogMinDuration, connection, data.sql, data.bindings);
+
+		queryInfos[data.__knexQueryUid] = {
+			timeoutId,
+			startTime: Date.now(),
+		};
+	});
+
+	connection.on('query-response', (_response, data) => {
+		const q = queryInfos[data.__knexQueryUid];
+		if (q) {
+			clearTimeout(q.timeoutId);
+			delete queryInfos[data.__knexQueryUid];
+		}
+	});
+
+	connection.on('query-error', (_response, data) => {
+		const q = queryInfos[data.__knexQueryUid];
+		if (q) {
+			clearTimeout(q.timeoutId);
+			delete queryInfos[data.__knexQueryUid];
+		}
+	});
+}
+
 export async function connectDb(dbConfig: DatabaseConfig): Promise<DbConnection> {
 	const connection = knex(makeKnexConfig(dbConfig));
 
-	const debugSlowQueries = false;
-
-	if (debugSlowQueries) {
-		const startTimes: Record<string, number> = {};
-
-		const slowQueryDuration = 10;
-
-		connection.on('query', (data) => {
-			startTimes[data.__knexQueryUid] = Date.now();
-		});
-
-		connection.on('query-response', (_response, data) => {
-			const duration = Date.now() - startTimes[data.__knexQueryUid];
-			if (duration < slowQueryDuration) return;
-			console.info(`SQL: ${data.sql} (${duration}ms)`);
-		});
+	if (dbConfig.slowQueryLogEnabled) {
+		setupSlowQueryLog(connection, dbConfig.slowQueryLogMinDuration);
 	}
 
 	return connection;

packages/server/src/utils/types.ts

@@ -50,6 +50,7 @@ export interface AppContext extends Koa.Context {
 }
 
 export enum DatabaseConfigClient {
+	Null = 'null',
 	PostgreSQL = 'pg',
 	SQLite = 'sqlite3',
 }
@@ -64,6 +65,8 @@ export interface DatabaseConfig {
 	user?: string;
 	password?: string;
 	asyncStackTraces?: boolean;
+	slowQueryLogEnabled?: boolean;
+	slowQueryLogMinDuration?: number;
 }
 
 export interface MailerConfig {