diff --git a/.gitignore b/.gitignore index b6988a40c..7388faab7 100644 --- a/.gitignore +++ b/.gitignore @@ -1,7 +1,8 @@ +.vscode/ +.idea/ build/ coverage/ node_modules/ -npm-debug.log ormconfig.json -.vscode -.idea/ \ No newline at end of file +ormlogs.log +npm-debug.log \ No newline at end of file diff --git a/docs/logging.md b/docs/logging.md index d68bd4676..01c9779c3 100644 --- a/docs/logging.md +++ b/docs/logging.md @@ -24,7 +24,7 @@ You can enable all queries logging by simply setting `logging: true` in your con } ``` -This configuration will enable all executing queries logging + errors of failed queries. +This configuration will enable all executing queries logging and failed query errors. ## Logging options @@ -99,8 +99,8 @@ You can enable any of them in connection options this way: { host: "localhost", ... - logger: "simple-console", - logging: true + logging: true, + logger: "file" } ``` diff --git a/ormconfig.json.dist b/ormconfig.json.dist index 54f67cac5..9f69fa5a6 100644 --- a/ormconfig.json.dist +++ b/ormconfig.json.dist @@ -8,9 +8,7 @@ "username": "test", "password": "test", "database": "test", - "logging": { - "logQueries": false - } + "logging": false }, { "skip": false, @@ -21,18 +19,14 @@ "username": "test", "password": "test", "database": "test", - "logging": { - "logQueries": false - } + "logging": false }, { "skip": false, "name": "sqlite", "type": "sqlite", "database": "temp/sqlitedb.db", - "logging": { - "logQueries": false - } + "logging": false }, { "skip": false, @@ -43,9 +37,7 @@ "username": "test", "password": "test", "database": "test", - "logging": { - "logQueries": false - } + "logging": false }, { "skip": true, @@ -55,9 +47,7 @@ "username": "sa", "password": "admin", "database": "test", - "logging": { - "logQueries": false - } + "logging": false }, { "skip": true, @@ -68,9 +58,7 @@ "password": "oracle", "port": 1521, "sid": "xe.oracle.docker", - "logging": { - "logQueries": false - } + "logging": false }, { "skip": false, @@ -78,8 +66,6 @@ "name": "mongodb", "type": "mongodb", "database": "test", - "logging": { - "logQueries": false - } + "logging": false } ] \ No newline at end of file diff --git a/sample/sample1-simple-entity/app.ts b/sample/sample1-simple-entity/app.ts index 0e65d9442..a6df1bfe3 100644 --- a/sample/sample1-simple-entity/app.ts +++ b/sample/sample1-simple-entity/app.ts @@ -1,7 +1,6 @@ import "reflect-metadata"; import {ConnectionOptions, createConnection} from "../../src/index"; import {Post} from "./entity/Post"; -import {QueryFailedError} from "../../src/error/QueryFailedError"; const options: ConnectionOptions = { // type: "oracle", @@ -10,13 +9,13 @@ const options: ConnectionOptions = { // password: "oracle", // port: 1521, // sid: "xe.oracle.docker", - // "name": "mysql", - // "type": "mysql", - // "host": "localhost", - // "port": 3306, - // "username": "test", - // "password": "test", - // "database": "test", + "name": "mysql", + "type": "mysql", + "host": "localhost", + "port": 3306, + "username": "test", + "password": "test", + "database": "test", // type: "postgres", // host: "localhost", // port: 5432, @@ -29,35 +28,48 @@ const options: ConnectionOptions = { // "password": "admin12345", // "database": "test", // port: 1521, - type: "sqlite", - database: "temp/sqlitedb.db", - logging: ["query", "error"], + // type: "sqlite", + // database: "temp/sqlitedb.db", + // logger: "file", + // logging: ["query", "error"], // logging: ["error", "schema", "query"], + // maxQueryExecutionTime: 90, autoSchemaSync: true, entities: [Post] }; createConnection(options).then(async connection => { - try { - await connection.query("CREATE DATABASE 'aaaa' AND DIE"); + // const posts: Post[] = []; + // for (let i = 0; i < 100; i++) { + // let post = new Post(); + // post.text = "Hello how are you?"; + // post.title = "hello"; + // post.likesCount = 100; + // posts.push(post); + // } + // + // await connection.manager.save(posts); - } catch (err) { - console.log("-------------------------------"); - console.log("ERRROR: ", err instanceof QueryFailedError); - console.log(err); - } + // try { + // await connection.query("CREATE DATABASE 'aaaa' AND DIE"); + // + // } catch (err) { + // console.log("-------------------------------"); + // console.log("ERRROR: ", err instanceof QueryFailedError); + // console.log(err); + // } - // let post = new Post(); - // post.text = "Hello how are you?"; - // post.title = "hello"; - // post.likesCount = 100; + let post = new Post(); + post.text = "Hello how are you?"; + post.title = "hello"; + post.likesCount = 100; - // let postRepository = connection.getRepository(Post); + let postRepository = connection.getRepository(Post); - // postRepository - // .save(post) - // .then(post => console.log("Post has been saved: ", post)) - // .catch(error => console.log("Cannot save. Error: ", error)); + postRepository + .save(post) + .then(post => console.log("Post has been saved: ", post)) + .catch(error => console.log("Cannot save. Error: ", error)); }, error => console.log("Cannot connect: ", error)); diff --git a/src/driver/mysql/MysqlQueryRunner.ts b/src/driver/mysql/MysqlQueryRunner.ts index b7d3e5a2d..a2f639045 100644 --- a/src/driver/mysql/MysqlQueryRunner.ts +++ b/src/driver/mysql/MysqlQueryRunner.ts @@ -165,7 +165,16 @@ export class MysqlQueryRunner implements QueryRunner { return new Promise(async (ok, fail) => { const databaseConnection = await this.connect(); this.driver.connection.logger.logQuery(query, parameters, this); + const queryStartTime = +new Date(); databaseConnection.query(query, parameters, (err: any, result: any) => { + + // log slow queries if maxQueryExecution time is set + const maxQueryExecutionTime = this.driver.connection.options.maxQueryExecutionTime; + const queryEndTime = +new Date(); + const queryExecutionTime = queryEndTime - queryStartTime; + if (maxQueryExecutionTime && queryExecutionTime > maxQueryExecutionTime) + this.driver.connection.logger.logQuerySlow(queryExecutionTime, query, parameters, this); + if (err) { this.driver.connection.logger.logQueryError(err, query, parameters, this); return fail(new QueryFailedError(query, parameters, err)); diff --git a/src/driver/oracle/OracleQueryRunner.ts b/src/driver/oracle/OracleQueryRunner.ts index 5bf08cf0c..862789119 100644 --- a/src/driver/oracle/OracleQueryRunner.ts +++ b/src/driver/oracle/OracleQueryRunner.ts @@ -176,7 +176,17 @@ export class OracleQueryRunner implements QueryRunner { return new Promise(async (ok, fail) => { this.driver.connection.logger.logQuery(query, parameters, this); + const queryStartTime = +new Date(); + const handler = (err: any, result: any) => { + + // log slow queries if maxQueryExecution time is set + const maxQueryExecutionTime = this.driver.connection.options.maxQueryExecutionTime; + const queryEndTime = +new Date(); + const queryExecutionTime = queryEndTime - queryStartTime; + if (maxQueryExecutionTime && queryExecutionTime > maxQueryExecutionTime) + this.driver.connection.logger.logQuerySlow(queryExecutionTime, query, parameters, this); + if (err) { this.driver.connection.logger.logQueryError(err, query, parameters, this); return fail(new QueryFailedError(query, parameters, err)); diff --git a/src/driver/postgres/PostgresQueryRunner.ts b/src/driver/postgres/PostgresQueryRunner.ts index f6cba36b7..017fb0a8a 100644 --- a/src/driver/postgres/PostgresQueryRunner.ts +++ b/src/driver/postgres/PostgresQueryRunner.ts @@ -189,7 +189,17 @@ export class PostgresQueryRunner implements QueryRunner { return new Promise(async (ok, fail) => { const databaseConnection = await this.connect(); this.driver.connection.logger.logQuery(query, parameters, this); + const queryStartTime = +new Date(); + databaseConnection.query(query, parameters, (err: any, result: any) => { + + // log slow queries if maxQueryExecution time is set + const maxQueryExecutionTime = this.driver.connection.options.maxQueryExecutionTime; + const queryEndTime = +new Date(); + const queryExecutionTime = queryEndTime - queryStartTime; + if (maxQueryExecutionTime && queryExecutionTime > maxQueryExecutionTime) + this.driver.connection.logger.logQuerySlow(queryExecutionTime, query, parameters, this); + if (err) { this.driver.connection.logger.logQueryError(err, query, parameters, this); fail(new QueryFailedError(query, parameters, err)); diff --git a/src/driver/sqlite/SqliteQueryRunner.ts b/src/driver/sqlite/SqliteQueryRunner.ts index 633226dfe..1539ecf31 100644 --- a/src/driver/sqlite/SqliteQueryRunner.ts +++ b/src/driver/sqlite/SqliteQueryRunner.ts @@ -144,7 +144,16 @@ export class SqliteQueryRunner implements QueryRunner { return new Promise(async (ok, fail) => { const databaseConnection = await this.connect(); this.driver.connection.logger.logQuery(query, parameters, this); + const queryStartTime = +new Date(); databaseConnection.all(query, parameters, (err: any, result: any) => { + + // log slow queries if maxQueryExecution time is set + const maxQueryExecutionTime = this.driver.connection.options.maxQueryExecutionTime; + const queryEndTime = +new Date(); + const queryExecutionTime = queryEndTime - queryStartTime; + if (maxQueryExecutionTime && queryExecutionTime > maxQueryExecutionTime) + this.driver.connection.logger.logQuerySlow(queryExecutionTime, query, parameters, this); + if (err) { this.driver.connection.logger.logQueryError(err, query, parameters, this); fail(new QueryFailedError(query, parameters, err)); diff --git a/src/driver/sqlserver/SqlServerQueryRunner.ts b/src/driver/sqlserver/SqlServerQueryRunner.ts index 9162275f9..9bc12680a 100644 --- a/src/driver/sqlserver/SqlServerQueryRunner.ts +++ b/src/driver/sqlserver/SqlServerQueryRunner.ts @@ -276,8 +276,16 @@ export class SqlServerQueryRunner implements QueryRunner { } }); } + const queryStartTime = +new Date(); request.query(query, (err: any, result: any) => { + // log slow queries if maxQueryExecution time is set + const maxQueryExecutionTime = this.driver.connection.options.maxQueryExecutionTime; + const queryEndTime = +new Date(); + const queryExecutionTime = queryEndTime - queryStartTime; + if (maxQueryExecutionTime && queryExecutionTime > maxQueryExecutionTime) + this.driver.connection.logger.logQuerySlow(queryExecutionTime, query, parameters, this); + const resolveChain = () => { if (promiseIndex !== -1) this.queryResponsibilityChain.splice(promiseIndex, 1); diff --git a/src/driver/websql/WebsqlQueryRunner.ts b/src/driver/websql/WebsqlQueryRunner.ts index cd4b9cf4e..000e5d2d1 100644 --- a/src/driver/websql/WebsqlQueryRunner.ts +++ b/src/driver/websql/WebsqlQueryRunner.ts @@ -184,11 +184,22 @@ export class WebsqlQueryRunner implements QueryRunner { return new Promise(async (ok, fail) => { - this.driver.connection.logger.logQuery(query, parameters, this); const db = await this.connect(); // todo(dima): check if transaction is not active + + this.driver.connection.logger.logQuery(query, parameters, this); + const queryStartTime = +new Date(); + db.transaction((tx: any) => { tx.executeSql(query, parameters, (tx: any, result: any) => { + + // log slow queries if maxQueryExecution time is set + const maxQueryExecutionTime = this.driver.connection.options.maxQueryExecutionTime; + const queryEndTime = +new Date(); + const queryExecutionTime = queryEndTime - queryStartTime; + if (maxQueryExecutionTime && queryExecutionTime > maxQueryExecutionTime) + this.driver.connection.logger.logQuerySlow(queryExecutionTime, query, parameters, this); + const rows = Object .keys(result.rows) .filter(key => key !== "length") diff --git a/src/logger/AdvancedConsoleLogger.ts b/src/logger/AdvancedConsoleLogger.ts index 642fc1dc6..6d6927129 100644 --- a/src/logger/AdvancedConsoleLogger.ts +++ b/src/logger/AdvancedConsoleLogger.ts @@ -6,7 +6,7 @@ const chalk = require("chalk"); /** * Performs logging of the events in TypeORM. - * This version of logger uses console to log events and does not use syntax highlighting. + * This version of logger uses console to log events and use syntax highlighting. */ export class AdvancedConsoleLogger implements Logger { diff --git a/src/logger/FileLogger.ts b/src/logger/FileLogger.ts index b4c5f0e7d..e2d54c796 100644 --- a/src/logger/FileLogger.ts +++ b/src/logger/FileLogger.ts @@ -1,10 +1,12 @@ import {LoggerOptions} from "./LoggerOptions"; import {QueryRunner} from "../query-runner/QueryRunner"; import {Logger} from "./Logger"; -import {writeFileSync} from "fs"; +import {appendFileSync} from "fs"; +import {PlatformTools} from "../platform/PlatformTools"; /** * Performs logging of the events in TypeORM. + * This version of logger logs everything into ormlogs.log file. */ export class FileLogger implements Logger { @@ -25,7 +27,7 @@ export class FileLogger implements Logger { logQuery(query: string, parameters?: any[], queryRunner?: QueryRunner) { if (this.options === "all" || this.options === true || (this.options instanceof Array && this.options.indexOf("query") !== -1)) { const sql = query + (parameters && parameters.length ? " -- PARAMETERS: " + this.stringifyParams(parameters) : ""); - this.write("executing query" + ": " + sql); + this.write("[QUERY]: " + sql); } } @@ -36,8 +38,8 @@ export class FileLogger implements Logger { if (this.options === "all" || this.options === true || (this.options instanceof Array && this.options.indexOf("error") !== -1)) { const sql = query + (parameters && parameters.length ? " -- PARAMETERS: " + this.stringifyParams(parameters) : ""); this.write([ - `query failed: ` + sql, - `error:`, error + `[FAILED QUERY]: ${sql}`, + `[QUERY ERROR]: ${error}` ]); } } @@ -47,10 +49,7 @@ export class FileLogger implements Logger { */ logQuerySlow(time: number, query: string, parameters?: any[], queryRunner?: QueryRunner) { const sql = query + (parameters && parameters.length ? " -- PARAMETERS: " + this.stringifyParams(parameters) : ""); - this.write([ - `query is slow: ` + sql, - `execution time: ` + time - ]); + this.write(`[SLOW QUERY: ${time} ms]: ` + sql); } /** @@ -66,19 +65,19 @@ export class FileLogger implements Logger { * Perform logging using given logger, or by default to the console. * Log has its own level and message. */ - log(level: "log"|"info"|"warn"|"error", message: any, queryRunner?: QueryRunner) { + log(level: "log"|"info"|"warn", message: any, queryRunner?: QueryRunner) { switch (level) { case "log": if (this.options === "all" || (this.options instanceof Array && this.options.indexOf("log") !== -1)) - this.write(message); + this.write("[LOG]: " + message); break; case "info": if (this.options === "all" || (this.options instanceof Array && this.options.indexOf("info") !== -1)) - this.write(message); + this.write("[INFO]: " + message); break; case "warn": if (this.options === "all" || (this.options instanceof Array && this.options.indexOf("warn") !== -1)) - this.write(message); + this.write("[WARN]: " + message); break; } } @@ -92,7 +91,9 @@ export class FileLogger implements Logger { */ protected write(strings: string|string[]) { strings = strings instanceof Array ? strings : [strings]; - writeFileSync("ormlogs.log", strings.join("\r\n")); // todo: make async + const basePath = PlatformTools.load("app-root-path").path; + strings = (strings as string[]).map(str => "[" + new Date().toISOString() + "]" + str); + appendFileSync(basePath + "/ormlogs.log", strings.join("\r\n") + "\r\n"); // todo: use async or implement promises? } /** diff --git a/src/logger/SimpleConsoleLogger.ts b/src/logger/SimpleConsoleLogger.ts index 0cad4d68a..06f79b1e5 100644 --- a/src/logger/SimpleConsoleLogger.ts +++ b/src/logger/SimpleConsoleLogger.ts @@ -4,6 +4,7 @@ import {Logger} from "./Logger"; /** * Performs logging of the events in TypeORM. + * This version of logger uses console to log events and does not use syntax highlighting. */ export class SimpleConsoleLogger implements Logger { @@ -61,7 +62,7 @@ export class SimpleConsoleLogger implements Logger { * Perform logging using given logger, or by default to the console. * Log has its own level and message. */ - log(level: "log"|"info"|"warn"|"error", message: any, queryRunner?: QueryRunner) { + log(level: "log"|"info"|"warn", message: any, queryRunner?: QueryRunner) { switch (level) { case "log": if (this.options === "all" || (this.options instanceof Array && this.options.indexOf("log") !== -1))