Intermittent test failure for create-user

[zacharyweidenbach]

First off, thank you for this excellent example. I have learned a lot from it!

I'm encountering an intermittent test failure for the create-user e2e spec.

~/C/P/domain-driven-hexagon master = !3 ?2 ❯ yarn test                                                       4s 06:41:20 AM
yarn run v1.22.19
$ jest --config .jestrc.json
 PASS  tests/user/delete-user/delete-user.e2e-spec.ts (12.032 s)
 FAIL  tests/user/create-user/create-user.e2e-spec.ts (12.212 s)
  ● Create a user › I can create a user

    expect(received).toBe(expected) // Object.is equality

    Expected: "string"
    Received: "undefined"

      42 |     then('I receive my user ID', () => {
      43 |       const response = ctx.latestResponse as IdResponse;
    > 44 |       expect(typeof response.id).toBe('string');
         |                                  ^
      45 |     });
      46 |
      47 |     and('I can see my user in a list of all users', async () => {

      at Object.stepFunction (tests/user/create-user/create-user.e2e-spec.ts:44:34)
      at node_modules/jest-cucumber/src/feature-definition-creation.ts:134:65

Test Suites: 1 failed, 1 passed, 2 total
Tests:       1 failed, 6 passed, 7 total
Snapshots:   0 total
Time:        12.906 s
Ran all test suites.
error Command failed with exit code 1.
info Visit https://yarnpkg.com/en/docs/cli/run for documentation about this command.

When I log out the result monad at the controller for that particular endpoint, I see what might be a clue.

When all tests pass, I see the conflict monad printed to the console, then the successful monad that contains the user entity id

~/C/P/domain-driven-hexagon master = !3 ?2 ❯ yarn test                                                      17s 06:42:58 AM
yarn run v1.22.19
$ jest --config .jestrc.json
 PASS  tests/user/delete-user/delete-user.e2e-spec.ts (9.954 s)
  ● Console

    console.log
      ResultType {
        [Symbol(Val)]: UserAlreadyExistsError: User already exists
            at CreateUserService.execute (/Users/zacharyweidenbach/Code/Personal/domain-driven-hexagon/src/modules/user/commands/create-user/create-user.service.ts:39:20)
            at processTicksAndRejections (node:internal/process/task_queues:95:5)
            at CreateUserHttpController.create (/Users/zacharyweidenbach/Code/Personal/domain-driven-hexagon/src/modules/user/commands/create-user/create-user.http.controller.ts:42:7) {
          cause: ConflictException [Error]: Record already exists
              at UserRepository.insert (/Users/zacharyweidenbach/Code/Personal/domain-driven-hexagon/src/libs/db/sql-repository.base.ts:118:15)
              at processTicksAndRejections (node:internal/process/task_queues:95:5)
              at /Users/zacharyweidenbach/Code/Personal/domain-driven-hexagon/src/libs/db/sql-repository.base.ts:215:24
              at execTransaction (/Users/zacharyweidenbach/Code/Personal/domain-driven-hexagon/node_modules/slonik/dist/src/connectionMethods/transaction.js:19:24)
              at transaction (/Users/zacharyweidenbach/Code/Personal/domain-driven-hexagon/node_modules/slonik/dist/src/connectionMethods/transaction.js:77:16)
              at /Users/zacharyweidenbach/Code/Personal/domain-driven-hexagon/node_modules/slonik/dist/src/binders/bindPool.js:120:24
              at createConnection (/Users/zacharyweidenbach/Code/Personal/domain-driven-hexagon/node_modules/slonik/dist/src/factories/createConnection.js:111:18)
              at Object.transaction (/Users/zacharyweidenbach/Code/Personal/domain-driven-hexagon/node_modules/slonik/dist/src/binders/bindPool.js:119:20)
              at CreateUserService.execute (/Users/zacharyweidenbach/Code/Personal/domain-driven-hexagon/src/modules/user/commands/create-user/create-user.service.ts:35:7)
              at CreateUserHttpController.create (/Users/zacharyweidenbach/Code/Personal/domain-driven-hexagon/src/modules/user/commands/create-user/create-user.http.controller.ts:42:7) {
            cause: [UniqueIntegrityConstraintViolationError],
            metadata: undefined,
            correlationId: 'r0aTGk',
            code: 'GENERIC.CONFLICT'
          },
          metadata: undefined,
          correlationId: 'r0aTGk',
          code: 'USER.ALREADY_EXISTS'
        },
        [Symbol(T)]: false
      } result

      at CreateUserHttpController.create (src/modules/user/commands/create-user/create-user.http.controller.ts:44:13)

 PASS  tests/user/create-user/create-user.e2e-spec.ts (10.035 s)
  ● Console

    console.log
      ResultType {
        [Symbol(Val)]: '9ed7cc92-5903-4107-a6e3-f1cf7536eb1d',
        [Symbol(T)]: true
      } result

      at CreateUserHttpController.create (src/modules/user/commands/create-user/create-user.http.controller.ts:44:13)


Test Suites: 2 passed, 2 total
Tests:       7 passed, 7 total
Snapshots:   0 total
Time:        10.585 s, estimated 13 s
Ran all test suites.
✨  Done in 15.33s.

However, when the test fails, I see the success monad printed first, then the conflict monad

~/C/P/domain-driven-hexagon master = !2 ?2 ❯ yarn test                                                      16s 06:51:45 AM
yarn run v1.22.19
$ jest --config .jestrc.json
 PASS  tests/user/delete-user/delete-user.e2e-spec.ts
  ● Console

    console.log
      ResultType {
        [Symbol(Val)]: '4d479c18-2f8a-4fd8-a4cc-8ae30e3ce6a3',
        [Symbol(T)]: true
      } result

      at CreateUserHttpController.create (src/modules/user/commands/create-user/create-user.http.controller.ts:44:13)

 FAIL  tests/user/create-user/create-user.e2e-spec.ts (5.084 s)
  ● Console

    console.log
      ResultType {
        [Symbol(Val)]: UserAlreadyExistsError: User already exists
            at CreateUserService.execute (/Users/zacharyweidenbach/Code/Personal/domain-driven-hexagon/src/modules/user/commands/create-user/create-user.service.ts:39:20)
            at processTicksAndRejections (node:internal/process/task_queues:95:5)
            at CreateUserHttpController.create (/Users/zacharyweidenbach/Code/Personal/domain-driven-hexagon/src/modules/user/commands/create-user/create-user.http.controller.ts:42:7) {
          cause: ConflictException [Error]: Record already exists
              at UserRepository.insert (/Users/zacharyweidenbach/Code/Personal/domain-driven-hexagon/src/libs/db/sql-repository.base.ts:118:15)
              at processTicksAndRejections (node:internal/process/task_queues:95:5)
              at /Users/zacharyweidenbach/Code/Personal/domain-driven-hexagon/src/libs/db/sql-repository.base.ts:215:24
              at execTransaction (/Users/zacharyweidenbach/Code/Personal/domain-driven-hexagon/node_modules/slonik/dist/src/connectionMethods/transaction.js:19:24)
              at transaction (/Users/zacharyweidenbach/Code/Personal/domain-driven-hexagon/node_modules/slonik/dist/src/connectionMethods/transaction.js:77:16)
              at /Users/zacharyweidenbach/Code/Personal/domain-driven-hexagon/node_modules/slonik/dist/src/binders/bindPool.js:120:24
              at createConnection (/Users/zacharyweidenbach/Code/Personal/domain-driven-hexagon/node_modules/slonik/dist/src/factories/createConnection.js:111:18)
              at Object.transaction (/Users/zacharyweidenbach/Code/Personal/domain-driven-hexagon/node_modules/slonik/dist/src/binders/bindPool.js:119:20)
              at CreateUserService.execute (/Users/zacharyweidenbach/Code/Personal/domain-driven-hexagon/src/modules/user/commands/create-user/create-user.service.ts:35:7)
              at CreateUserHttpController.create (/Users/zacharyweidenbach/Code/Personal/domain-driven-hexagon/src/modules/user/commands/create-user/create-user.http.controller.ts:42:7) {
            cause: [UniqueIntegrityConstraintViolationError],
            metadata: undefined,
            correlationId: 'DkMKdX',
            code: 'GENERIC.CONFLICT'
          },
          metadata: undefined,
          correlationId: 'DkMKdX',
          code: 'USER.ALREADY_EXISTS'
        },
        [Symbol(T)]: false
      } result

      at CreateUserHttpController.create (src/modules/user/commands/create-user/create-user.http.controller.ts:44:13)

  ● Create a user › I can create a user

    expect(received).toBe(expected) // Object.is equality

    Expected: "string"
    Received: "undefined"

      42 |     then('I receive my user ID', () => {
      43 |       const response = ctx.latestResponse as IdResponse;
    > 44 |       expect(typeof response.id).toBe('string');
         |                                  ^
      45 |     });
      46 |
      47 |     and('I can see my user in a list of all users', async () => {

      at Object.stepFunction (tests/user/create-user/create-user.e2e-spec.ts:44:34)
      at node_modules/jest-cucumber/src/feature-definition-creation.ts:134:65

Test Suites: 1 failed, 1 passed, 2 total
Tests:       1 failed, 6 passed, 7 total
Snapshots:   0 total
Time:        5.534 s, estimated 15 s
Ran all test suites.
error Command failed with exit code 1.
info Visit https://yarnpkg.com/en/docs/cli/run for documentation about this command.

I'm looking into this more, but my first instinct is that either the tests are running in parallel and that is creating some race condition, although I don't see any jest arguments altering the worker count to enable parallel test execution. Alternatively there might be something wrong in the testing infrastructure for the response context and it being mutated in a non-deterministic way.

[zacharyweidenbach]

Some more detail, if I test.skip on the 'I try to create a user with invalid data' test, I can make the test fail every time. This suggests that the tests fail intermittently when the 'I can create a user' runs first. And when I run the create-user.e2e-spec.ts in isolation, the test passes.

This leads me to believe there is some residual state from the delete-user.e2e-spec.ts test that causes this failure.

[Sairyss]

I just tried it and tests worked fine for me. Here are the steps that I used:

1. npm run docker:env - run docker
2. create database ddh_tests - execute this SQL query to create a database for tests
3. npm run migration:up:tests - execute migrations for test db
4. npm run test:e2e - run tests

[zacharyweidenbach]

That more or less matches what I did you setup the test suite.

It very much seems to matter what the test execution order is. The order that seems to reliably reproduced the issue, is:

1. delete-user.e2e-spec.ts
2. create-user.e2e-spec.ts - specifically with the I can create a user test running first. skipping the other test makes this easier to reproduce, because then it's just a matter of jest executing the delete-user test suite before the create-user test suite.

I've also added logging in the tests in order to query the entire contents of the user table in the db right before the I can create a user runs, and it shows the table as empty. This is more concerning, as now I suspect there is something wrong with the server-side code to unexpectedly encounter a user conflict on the john doe email address. I'll keep digging and report my findings back here.

[Sairyss]

@zacharyweidenbach you are executing yarn test, you have to execute yarn test:e2e

[zacharyweidenbach]

That seems to have resolved the failures. Even if I use jest's test-sequencer to coerce jest into running the delete-user test first, they both pass. Although that raises the question what's different between the .jestrc.json file and the jest-e2e.json that could explain why it was failing for yarn test and not yarn test:e2e. The only difference between them seems to be the coverageDirectory and the testRegex. I would expect to see different global setup files or something to understand what was missing from the yarn test config.

[zacharyweidenbach]

Disregard, I see the test:e2e script uses -i which is the jest option --runInBand in order to serialize the tests on the current process.

[zacharyweidenbach]

Closing, using the wrong test script