Failing test to catch PostgreSQL warnings

Signed-off-by: John Gomersall <[email protected]>

src/domain/services/import.service.spec.ts

@@ -13,7 +13,6 @@ import { createClient } from 'redis';
 import { GenericContainer } from 'testcontainers';
 import { setTimeout } from 'timers/promises';
 
-let index = 0;
 const lastModified = 1692032161;
 
 function testProducts() {
@@ -36,37 +35,43 @@ function testProducts() {
   return { products, productIdExisting, productIdNew };
 }
 
-// Need to specify argumet list bellow so that calls in the assertion is typed
-// eslint-disable-next-line @typescript-eslint/no-unused-vars
-const findMock = jest.fn((_filter, _projection) => ({
-  next: async () => {
-    return index++ <= mockedProducts.length ? mockedProducts[index - 1] : null;
-  },
-  close: jest.fn(),
-}));
+const findCalls = [];
 
 jest.mock('mongodb', () => {
   return {
     MongoClient: jest.fn(() => ({
       connect: jest.fn(),
-      db: () => ({
-        collection: () => ({
-          find: findMock,
-        }),
-      }),
+      db: () => {
+        let index = 0;
+        return {
+          collection: () => ({
+            find: (...args: any) => {
+              findCalls.push(args);
+              return {
+                next: async () => {
+                  return index++ <= mockedProducts.length
+                    ? mockedProducts[index - 1]
+                    : null;
+                },
+                close: jest.fn(),
+              };
+            },
+          }),
+        };
+      },
       close: jest.fn(),
     })),
   };
 });
 
 let mockedProducts = [];
 function mockMongoDB(productList) {
-  index = 0;
   mockedProducts = productList;
 }
 
 // Import tests can sometimes take a little time in GitHub
-jest.setTimeout(10000);
+// Plus Allow a little time for the testcontainer to start
+jest.setTimeout(300000);
 
 describe('importFromMongo', () => {
   it('should import a new product update existing products and delete missing products', async () => {
@@ -103,7 +108,7 @@ describe('importFromMongo', () => {
 
       await importService.importFromMongo();
 
-      // THEN: New product is addeded, updated product is updated and other product is unchanged
+      // THEN: New product is added, updated product is updated and other product is unchanged
       expect(deleteMock).toHaveBeenCalledTimes(1);
       let updateId = deleteMock.mock.calls[0][0];
       // Re-format updateId the way Postgres provides it
@@ -213,12 +218,12 @@ describe('importFromMongo', () => {
 
       // WHEN: Doing an incremental import from MongoDB
       mockMongoDB(products);
-      findMock.mockClear();
+      findCalls.length = 0;
       await importService.importFromMongo('');
 
       // THEN: Mongo find is called with the setting as a parameter
-      expect(findMock).toHaveBeenCalledTimes(2); // Called for normal an obsolete prodocuts
-      expect(findMock.mock.calls[0][0].last_modified_t.$gt).toBe(
+      expect(findCalls).toHaveLength(2); // Called for normal an obsolete prodocuts
+      expect(findCalls[0][0].last_modified_t.$gt).toBe(
         Math.floor(startFrom.getTime() / 1000),
       );
 
@@ -228,9 +233,9 @@ describe('importFromMongo', () => {
     });
   });
 
-  it('should cope with nul charactes', async () => {
+  it('should cope with nul characters', async () => {
     await createTestingModule([DomainModule], async (app) => {
-      // WHEN: Impoting data containing nul characters
+      // WHEN: Importing data containing nul characters
       const { productIdNew } = testProducts();
       mockMongoDB([
         {
@@ -269,7 +274,6 @@ describe('importFromMongo', () => {
 
       // WHEN: Doing an import from MongoDB
       mockMongoDB(testData);
-      findMock.mockClear();
       await importService.importFromMongo('');
 
       // THEN: The last modified date is set correctly
@@ -346,9 +350,30 @@ describe('ProductTag', () => {
   });
 });
 
+describe('importWithFilter', () => {
+  it.only('should not get an error with concurrent imports', async () => {
+    await createTestingModule([DomainModule], async (app) => {
+      const importService = app.get(ImportService);
+
+      // WHEN: Doing an incremental import from MongoDB
+      const { products, productIdExisting, productIdNew } = testProducts();
+      mockMongoDB(products);
+      const imports = [];
+      // Need more than 10 concurrent imports to start to see errors
+      for (let i = 0; i < 11; i++) {
+        imports.push(
+          importService.importWithFilter(
+            { code: { $in: [productIdExisting, productIdNew] } },
+            ProductSource.EVENT,
+          ),
+        );
+      }
+      await Promise.all(imports);
+    });
+  });
+});
+
 describe('receiveMessages', () => {
-  // Allow a little time for the testcontainer to start
-  jest.setTimeout(30000);
   it('should call importwithfilter when a message is received', async () => {
     await createTestingModule([DomainModule], async (app) => {
       // GIVEN: Redis is running

src/mikro-orm.config.ts

@@ -7,13 +7,16 @@ import {
   defineConfig,
 } from '@mikro-orm/core';
 import { SCHEMA } from './constants';
+import { Logger } from '@nestjs/common';
 
 class DateTimeNtzType extends DateTimeType {
   getColumnType(): string {
     return 'timestamp';
   }
 }
 
+const logger = new Logger('MikroOrm');
+
 export default defineConfig({
   entities: ['./dist/domain/entities'],
   entitiesTs: ['./src/domain/entities'],
@@ -47,6 +50,16 @@ export default defineConfig({
     path: 'dist/migrations',
     pathTs: 'src/migrations',
   },
+  pool: {
+    afterCreate: function (conn: any, done: any) {
+      conn.query('select 1 as result', function (err) {
+        conn.on('notice', function (msg) {
+          logger.error('Notice from PostgreSQL: ' + msg.message);
+        });
+        done(err, conn);
+      });
+    },
+  },
   // Uncomment the below and 'app.useLogger(new Logger());' to the test to see Mikro-ORM logs
   // debug: ['query', 'query-params'],
 });

test/test.helper.ts

@@ -1,26 +1,48 @@
 import { MikroORM, RequestContext } from '@mikro-orm/core';
 import { logger } from '@mikro-orm/nestjs';
+import { ConsoleLogger } from '@nestjs/common';
 import { Test, TestingModule } from '@nestjs/testing';
 import { randomBytes } from 'crypto';
 
 export function randomCode() {
   return 'TEST-' + randomBytes(20).toString('base64');
 }
 
+class TestLogger extends ConsoleLogger {
+  errors = new Array<string>();
+  expectedErrors = 0;
+  constructor() {
+    super();
+    this.setLogLevels(['error']);
+  }
+  error(message: string, ...rest: any[]) {
+    this.errors.push(message);
+    if (this.errors.length > this.expectedErrors) {
+      super.error(message, ...rest);
+    }
+  }
+  assertExpectedErrors() {
+    expect(this.errors).toHaveLength(this.expectedErrors);
+  }
+}
+
 export async function createTestingModule(
   imports: any[],
-  callback: { (app: TestingModule): Promise<void> },
+  callback: { (app: TestingModule, logger: TestLogger): Promise<void> },
 ) {
+  const testLogger = new TestLogger();
   const app = await Test.createTestingModule({
     imports: imports,
   }).compile();
+  app.useLogger(testLogger);
   await app.init();
 
   const orm = app.get(MikroORM);
   try {
     await RequestContext.createAsync(orm.em, async () => {
-      await callback(app);
+      await callback(app, testLogger);
     });
+    testLogger.assertExpectedErrors();
   } catch (e) {
     (e.errors ?? [e]).map((e) => logger.error(e.message, e.stack));
     throw e;