Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

fix: FORMS-904 user insert race condition #1129

Merged
merged 1 commit into from
Nov 1, 2023

Conversation

bcgov-citz-ccft
Copy link
Collaborator

@bcgov-citz-ccft bcgov-citz-ccft commented Nov 1, 2023

Description

Users are reporting that they are occasionally receiving errors with the app. I think it would be best to fix existing errors in the application so that we can rule them out as being the cause of the problem.

When a user (IDIR or BCeID) logs in for the first time, the app is trying to create the “User” object twice. The second create will fail with a database exception, and this seems to have a cascading effect on the connection pool that causes other requests to fail (?).

ERROR: duplicate key value violates unique constraint "user_keycloakid_unique"
DETAIL: Key ("keycloakId")=(aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaaa) already exists.
UniqueViolationError: insert into "user" ("createdAt", "email", "firstName", "fullName", "id", "idpCode", "idpUserId", "keycloakId", "username") values ($1, $2, $3, $4, $5, $6, $7, $8, $9) returning "id" - duplicate key value violates unique constraint "user_keycloakid_unique"
    at wrapError (/opt/app-root/src/app/node_modules/db-errors/lib/dbErrors.js:19:14)
    at handleExecuteError (/opt/app-root/src/app/node_modules/objection/lib/queryBuilder/QueryBuilder.js:1123:32)
    at QueryBuilder.execute (/opt/app-root/src/app/node_modules/objection/lib/queryBuilder/QueryBuilder.js:449:20)
    at processTicksAndRejections (node:internal/process/task_queues:96:5)
    at async Object.createUser (/opt/app-root/src/app/src/forms/auth/service.js:26:7)
    at async Object.getUserId (/opt/app-root/src/app/src/forms/auth/service.js:121:14)
    at async Object.login (/opt/app-root/src/app/src/forms/auth/service.js:207:18)
    at async setUser (/opt/app-root/src/app/src/forms/auth/middleware/userAccess.js:25:23)

When this happens the timestamp on the error log is very soon after the “createdAt” timestamp that’s in the table.

Reproduce: create a BCeID form and a BCeID user. Make sure the user is not in the DB, if it is then delete it. Using a new incognito window go to the form link and log in. The network failures are for: rbac/current and forms/guid/options.

Looks like a race condition in app/src/forms/auth/service.js between getting the user and creating it:

    // if this user does not exists, add...
    let user = await User.query().first().where('idpUserId', obj.idpUserId);

    if (!user) {
      // add to the system.
      user = await service.createUser(obj);
    }

Types of changes

Bug fix (non-breaking change which fixes an issue)

Checklist

  • I have read the CONTRIBUTING doc
  • I have checked that unit tests pass locally with my changes
  • I have run the npm script lint on the frontend and backend
  • I have added tests that prove my fix is effective or that my feature works
  • I have added necessary documentation (if appropriate)
  • I have approval from the product owner for the contribution in this pull request

Further comments

  • They key to the fix was to ignore the exceptions based on the keycloakId constraint, and to fetch using the keycloakId and not the user table's id (each create will use its own guid for the id). This way if you have two inserts at the same time, then the second one will fail to insert but still retrieve the correct user.
  • Removed an extra read from the database in updateUser. Could be argued that it's there to ensure that the id exists in the DB before patching, but the calling code already does that and updateUser is not called from anywhere else.
  • I was working on tests but was bumping into limitations with the database mocking (or my knowledge of it!). Need to get this in ASAP though as we're having DB load problems again.

Copy link

github-actions bot commented Nov 1, 2023

Coverage Report (Application)

Totals Coverage
Statements: 41.9% ( 2636 / 6291 )
Methods: 36.84% ( 326 / 885 )
Lines: 47.44% ( 1759 / 3708 )
Branches: 32.45% ( 551 / 1698 )

Copy link

github-actions bot commented Nov 1, 2023

Coverage Report (Frontend)

Totals Coverage
Statements: 68.33% ( 1107 / 1620 )
Methods: 66.11% ( 199 / 301 )
Lines: 72.44% ( 778 / 1074 )
Branches: 53.06% ( 130 / 245 )

Comment on lines -57 to +56
await User.query(trx).patchAndFetchById(obj.id, update);
await User.query(trx).patchAndFetchById(id, update);
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This patchAndFetchById could probably be streamlined to just be a patch (since the return value is being ignored) but I didn't want to mess too much with this for now.

@bcgov-citz-ccft bcgov-citz-ccft merged commit 235af55 into master Nov 1, 2023
11 checks passed
@WalterMoar WalterMoar deleted the fix/904-user-insert-race-condition branch November 1, 2023 20:05
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants