feat: add option to pass postgres server notices to client logger (ty…

…peorm#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: typeorm#2216

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"

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;
 }

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);
             });

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;
+}

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",
+            });
+        })));
+    });
+});