From 5084e47be4fd42316ad47e6102645534fae45d9f Mon Sep 17 00:00:00 2001 From: Arty <26905074+artysidorenko@users.noreply.github.com> Date: Thu, 17 Sep 2020 12:40:28 +0100 Subject: [PATCH] feat: add option to pass postgres server notices to client logger (#6215) This feature for postgres connections means when you pass the logNotifications option, db notices and notifications will be passed to the logger with info log level Closes: #2216 --- docs/connection-options.md | 2 + .../postgres/PostgresConnectionOptions.ts | 5 + src/driver/postgres/PostgresDriver.ts | 9 ++ test/github-issues/2216/entity/Foo.ts | 16 +++ test/github-issues/2216/issue-2216.ts | 130 ++++++++++++++++++ 5 files changed, 162 insertions(+) create mode 100644 test/github-issues/2216/entity/Foo.ts create mode 100644 test/github-issues/2216/issue-2216.ts diff --git a/docs/connection-options.md b/docs/connection-options.md index d52a64bc81..219e141050 100644 --- a/docs/connection-options.md +++ b/docs/connection-options.md @@ -182,6 +182,8 @@ See [SSL options](https://github.com/mysqljs/mysql#ssl-options). * `poolErrorHandler` - A function that get's called when underlying pool emits `'error'` event. Takes single parameter (error instance) and defaults to logging with `warn` level. +* `logNotifications` - A boolean to determine whether postgres server [notice messages](https://www.postgresql.org/docs/current/plpgsql-errors-and-messages.html) and [notification events](https://www.postgresql.org/docs/current/sql-notify.html) should be included in client's logs with `info` level (default: `false`). + ## `sqlite` connection options * `database` - Database path. For example "./mydb.sql" diff --git a/src/driver/postgres/PostgresConnectionOptions.ts b/src/driver/postgres/PostgresConnectionOptions.ts index 18e65183b9..908360df6d 100644 --- a/src/driver/postgres/PostgresConnectionOptions.ts +++ b/src/driver/postgres/PostgresConnectionOptions.ts @@ -52,4 +52,9 @@ export interface PostgresConnectionOptions extends BaseConnectionOptions, Postgr * Defaults to logging error with `warn` level. */ readonly poolErrorHandler?: (err: any) => any; + + /** + * Include notification messages from Postgres server in client logs + */ + readonly logNotifications?: boolean; } diff --git a/src/driver/postgres/PostgresDriver.ts b/src/driver/postgres/PostgresDriver.ts index 59684c74bf..f5a8d8cdd6 100644 --- a/src/driver/postgres/PostgresDriver.ts +++ b/src/driver/postgres/PostgresDriver.ts @@ -1001,6 +1001,15 @@ export class PostgresDriver implements Driver { return new Promise((ok, fail) => { pool.connect((err: any, connection: any, release: Function) => { if (err) return fail(err); + + if (options.logNotifications) { + connection.on("notice", (msg: any) => { + msg && this.connection.logger.log("info", msg.message); + }); + connection.on("notification", (msg: any) => { + msg && this.connection.logger.log("info", `Received NOTIFY on channel ${msg.channel}: ${msg.payload}.`); + }); + } release(); ok(pool); }); diff --git a/test/github-issues/2216/entity/Foo.ts b/test/github-issues/2216/entity/Foo.ts new file mode 100644 index 0000000000..d7e2038db8 --- /dev/null +++ b/test/github-issues/2216/entity/Foo.ts @@ -0,0 +1,16 @@ +import { + Column, + Entity, + PrimaryGeneratedColumn, +} from "../../../../src"; + +@Entity("foo") +export class Foo { + @PrimaryGeneratedColumn("uuid") public uuid: string; + + @Column({ type: "citext", nullable: false }) + public lowercaseval: string; + + @Column({ type: "citext", nullable: false }) + public lowercaseval2: string; +} diff --git a/test/github-issues/2216/issue-2216.ts b/test/github-issues/2216/issue-2216.ts new file mode 100644 index 0000000000..3cb4287d9f --- /dev/null +++ b/test/github-issues/2216/issue-2216.ts @@ -0,0 +1,130 @@ +import sinon from "sinon"; +import {Connection} from "../../../src/connection/Connection"; +import {createTestingConnections, closeTestingConnections, reloadTestingDatabases } from "../../utils/test-utils"; +import { EntityManager, QueryRunner, SimpleConsoleLogger } from "../../../src"; +import { Foo } from "./entity/Foo"; +import { expect } from "chai"; + +describe("github issues > #2216 - Ability to capture Postgres notifications in logger", () => { + let connections: Connection[]; + let queryRunner: QueryRunner; + let manager: EntityManager; + let logInfoStub: sinon.SinonStub; + + before(() => { + logInfoStub = sinon.stub(SimpleConsoleLogger.prototype, "log"); + }); + beforeEach(async () => { + await reloadTestingDatabases(connections); + }); + afterEach(() => logInfoStub.resetHistory()); + after(() => logInfoStub.restore()); + + describe("when logNotifications option is NOT enabled", () => { + before(async () => { + connections = await createTestingConnections({ + enabledDrivers: ["postgres"], + entities: [Foo], + logging: true, + createLogger: () => new SimpleConsoleLogger(), + }); + }); + after(() => closeTestingConnections(connections)); + + it("should NOT pass extension setup notices to client", async () => Promise.all(connections.map(async connection => { + sinon.assert.neverCalledWith( + logInfoStub, + "info", + `extension "uuid-ossp" already exists, skipping` + ); + sinon.assert.neverCalledWith( + logInfoStub, + "info", + `extension "citext" already exists, skipping` + ); + }))); + + it("should NOT pass manual notices to client", async () => Promise.all(connections.map(async connection => { + queryRunner = connection.createQueryRunner(); + await queryRunner.query(`DO $do$ BEGIN RAISE NOTICE 'this is a notice'; END $do$`); + sinon.assert.neverCalledWith( + logInfoStub, + "info", + "this is a notice" + ); + await queryRunner.release(); + }))); + + it("should NOT pass 'listen -> notify' messages to client", async () => Promise.all(connections.map(async connection => { + queryRunner = connection.createQueryRunner(); + await queryRunner.query("LISTEN foo;"); + await queryRunner.query("NOTIFY foo, 'bar!'"); + sinon.assert.neverCalledWith( + logInfoStub, + "info", + "Received NOTIFY on channel foo: bar!." + ); + await queryRunner.release(); + }))); + }); + + describe("when logNotifications option is enabled", () => { + before(async () => { + connections = await createTestingConnections({ + enabledDrivers: ["postgres"], + entities: [Foo], + logging: true, + createLogger: () => new SimpleConsoleLogger(), + driverSpecific: { logNotifications: true }, + }); + }); + after(() => closeTestingConnections(connections)); + + it("should pass extension setup notices to client", async () => Promise.all(connections.map(async connection => { + sinon.assert.calledWith( + logInfoStub, + "info", + `extension "uuid-ossp" already exists, skipping` + ); + sinon.assert.calledWith( + logInfoStub, + "info", + `extension "citext" already exists, skipping` + ); + }))); + + it("should pass manual notices to client", async () => Promise.all(connections.map(async connection => { + queryRunner = connection.createQueryRunner(); + await queryRunner.query(`DO $do$ BEGIN RAISE NOTICE 'this is a notice'; END $do$`); + sinon.assert.calledWith( + logInfoStub, + "info", + "this is a notice" + ); + await queryRunner.release(); + }))); + + it("should pass 'listen -> notify' messages to client", async () => Promise.all(connections.map(async connection => { + queryRunner = connection.createQueryRunner(); + await queryRunner.query("LISTEN foo;"); + await queryRunner.query("NOTIFY foo, 'bar!'"); + sinon.assert.calledWith( + logInfoStub, + "info", + "Received NOTIFY on channel foo: bar!." + ); + await queryRunner.release(); + }))); + + it("should not interfere with actual queries", async () => Promise.all(connections.map(async connection => { + manager = connection.manager; + await manager.save(Object.assign(new Foo(), { lowercaseval: "foo", lowercaseval2: "bar"})); + const loadedFoo = await manager.findOne(Foo); + expect(loadedFoo).not.to.be.undefined; + expect(loadedFoo).to.contain({ + lowercaseval: "foo", + lowercaseval2: "bar", + }); + }))); + }); +});