Cannot update two milestones in parallel

[maxceem]

When sending two requests for updating milestones in parallel, one of them fails with error

{
  "id": "b7e49a46-a4cb-4de6-a1a1-fa5e45e2862d",
  "result": {
    "success": false,
    "status": 500,
    "content": {
      "message": "could not serialize access due to concurrent update"
    },
    "debug": "SequelizeDatabaseError: could not serialize access due to concurrent update\n    at Query.formatError (/usr/src/app/node_modules/sequelize/lib/dialects/postgres/query.js:357:14)\n    at Query.<anonymous> (/usr/src/app/node_modules/sequelize/lib/dialects/postgres/query.js:88:19)\n    at emitOne (events.js:115:13)\n    at Query.emit (events.js:210:7)\n    at Query.handleError (/usr/src/app/node_modules/pg/lib/query.js:108:8)\n    at Connection.<anonymous> (/usr/src/app/node_modules/pg/lib/client.js:171:26)\n    at emitOne (events.js:115:13)\n    at Connection.emit (events.js:210:7)\n    at Socket.<anonymous> (/usr/src/app/node_modules/pg/lib/connection.js:109:12)\n    at emitOne (events.js:115:13)\n    at Socket.emit (events.js:210:7)\n    at addChunk (_stream_readable.js:252:12)\n    at readableAddChunk (_stream_readable.js:239:11)\n    at Socket.Readable.push (_stream_readable.js:197:10)\n    at TCP.onread [as _originalOnread] (net.js:589:20)\n    at TCP.onread (/usr/src/app/node_modules/async-listener/glue.js:188:31)\nFrom previous event:\n    at Query.run (/usr/src/app/node_modules/sequelize/lib/dialects/postgres/query.js:74:17)\n    at /usr/src/app/node_modules/sequelize/lib/sequelize.js:849:20\n    at /usr/src/app/node_modules/retry-as-promised/index.js:39:21\nFrom previous event:\n    at retryAsPromised (/usr/src/app/node_modules/retry-as-promised/index.js:29:10)\n    at /usr/src/app/node_modules/sequelize/lib/sequelize.js:848:12\n    at /usr/src/app/node_modules/continuation-local-storage/context.js:84:17\nFrom previous event:\n    at Promise.then (/usr/src/app/node_modules/sequelize/lib/promise.js:21:17)\n    at transactionResolver (/usr/src/app/node_modules/sequelize/lib/sequelize.js:1284:40)\n    at /usr/src/app/node_modules/continuation-local-storage/context.js:84:17\nFrom previous event:\n    at Sequelize.transaction (/usr/src/app/node_modules/sequelize/lib/sequelize.js:1313:12)\n    at module.exports (/usr/src/app/dist/routes/milestones/update.js:158:37)\n    at Layer.handle [as handle_request] (/usr/src/app/node_modules/express/lib/router/layer.js:95:5)\n    at next (/usr/src/app/node_modules/express/lib/router/route.js:137:13)\n    at authorizer.can.then (/usr/src/app/node_modules/tc-core-library-js/lib/middleware/permissions.js:10:9)\n    at propagateAslWrapper (/usr/src/app/node_modules/async-listener/index.js:478:23)\n    at /usr/src/app/node_modules/async-listener/glue.js:188:31\n    at /usr/src/app/node_modules/async-listener/index.js:515:70\n    at /usr/src/app/node_modules/async-listener/glue.js:188:31\n    at <anonymous>\n    at process._tickDomainCallback [as _tickCallback] (internal/process/next_tick.js:228:7)"
  }
}

Example of two requests:

• PATCH https://api.topcoder-dev.com/v4/timelines/412/milestones/1562 with payload

  {
    "param": {
      "details": {
        "content": {
          "links": [{
            "title": "Design 1",
            "url": "http://test.com",
            "type": "marvelapp"
          }, {
            "title": "Design 2",
            "url": "http://test.com",
            "type": "marvelapp"
          }]
        }
      },
      "status": "completed"
    }
  }
  

• PATCH https://api.topcoder-dev.com/v4/timelines/412/milestones/1561 with payload

   {
     "param": {
       "details": {
         "prevMilestoneContent": {
           "links": [{
             "title": "Design 1",
             "url": "http://test.com",
             "type": "marvelapp"
           }, {
             "title": "Design 2",
             "url": "http://test.com",
             "type": "marvelapp"
           }]
         }
       }
     }
   }
  

User pat_monahan.
Both two milestones from one timeline.

Probably this issue is related to #118

Update this issue doesn't happen every time.

[maxceem]

For the next two calls I get this issue for all the cases:

• PATCH https://api.topcoder-dev.com/v4/timelines/412/milestones/1561

      {
     "param": {
       "details": {
         "prevMilestoneContent": {
           "links": [{
             "title": "Design 1",
             "url": "http://test.com",
             "type": "marvelapp"
           }, {
             "title": "Design 2",
             "url": "http://test.com",
             "type": "marvelapp"
           }]
         },
         "content": {
           "extensionRequest": null,
           "links": [{
             "title": "Design 1",
             "url": "http://test.com",
             "type": "marvelapp",
             "isSelected": true
           }, {
             "title": "Design 2",
             "url": "http://test.com",
             "type": "marvelapp",
             "isSelected": true
           }]
         }
       },
       "status": "completed"
     }
   }
  

• PATCH https://api.topcoder-dev.com/v4/timelines/412/milestones/1563

       {
     "param": {
       "details": {
         "prevMilestoneContent": {
           "extensionRequest": null,
           "links": [{
             "title": "Design 1",
             "url": "http://test.com",
             "type": "marvelapp",
             "isSelected": true
           }, {
             "title": "Design 2",
             "url": "http://test.com",
             "type": "marvelapp",
             "isSelected": true
           }]
         }
       }
     }
   }
  

Project where it happens http://local.topcoder-dev.com:3000/projects/6994/plan

[ngoctay]

@vikasrohit
The current logic of updating a milestone will include cascade updating other milestones (order, start/end date..)

So "could not serialize access due to concurrent update" will be thrown if the above 2 concurrent calls cascade updating any same milestone.

I suggest to keep the current status of the API, and change the front-end to make the calls sequentially.

[gondzo]

We should just add locks to milestone objects when fetching them and that will solve the issue, ex
at

tc-project-service/src/routes/milestones/update.js

Line 36 in f979c48

return models.Milestone.findAll({

we should do something like
Model.findAll({
where: ...,
transaction: t1,
lock: t1.LOCK...
});
fetching all the milestones at the start of the request will block all other requests to update the same milestone/timeline

[vikasrohit]

Thanks @ngoctay for the investigation and your understanding is correct. We have already have work around of calling it sequentially at front end in place, however, we like to know that if there is any possibility of fixing it more elegantly. Just want to be sure that we are not doing any thing that is not industry standard.

[vikasrohit]

@gondzo Is not taking lock automatically when we are starting transaction?

[gondzo]

no, read only queries don't create any locks afaik

[vikasrohit]

Yep, that is true when they are outside of a transaction. I guess, when they are in transaction, it depends on the isolation level?

[ngoctay]

@gondzo
It doesn't work. The 1st call succeeded, but the 2nd call failed. deadlock detected

{"name":"tc-projects-service-prod","hostname":"ngoctay-pc","pid":14244,"requestId":"22daa237-e0f2-4531-a7d4-efc646933125","level":50,"err":{"message":"deadlock detected","name":"SequelizeDatabaseError","stack":"SequelizeDatabaseError: deadlock detected\n at Query.formatError (C:\\work\\nodejs\\tc-project-service7\\tc-project-service\\node_modules\\sequelize\\lib\\dialects\\postgres\\query.js:357:14)\n at Query.<anonymous> (C:\\work\\nodejs\\tc-project-service7\\tc-project-service\\node_modules\\sequelize\\lib\\dialects\\postgres\\query.js:88:19)\n at emitOne (events.js:116:13)\n at Query.emit (events.js:211:7)\n at Query.handleError (C:\\work\\nodejs\\tc-project-service7\\tc-project-service\\node_modules\\pg\\lib\\query.js:108:8)\n at Connection.<anonymous> (C:\\work\\nodejs\\tc-project-service7\\tc-project-service\\node_modules\\pg\\lib\\client.js:171:26)\n at emitOne (events.js:116:13)\n at Connection.emit (events.js:211:7)\n at Socket.<anonymous> (C:\\work\\nodejs\\tc-project-service7\\tc-project-service\\node_modules\\pg\\lib\\connection.js:109:12)\n at emitOne (events.js:116:13)\n at Socket.emit (events.js:211:7)\n at addChunk (_stream_readable.js:263:12)\n at readableAddChunk (_stream_readable.js:250:11)\n at Socket.Readable.push (_stream_readable.js:208:10)\n at TCP.onread [as _originalOnread] (net.js:607:20)\n at TCP.onread (C:\\work\\nodejs\\tc-project-service7\\tc-project-service\\node_modules\\async-listener\\glue.js:188:31)"},"msg":"deadlock detected","time":"2018-08-27T16:35:35.310Z","v":0}

IMO, this should not be a bug.
We should not allow to update a resource from 2 calls concurrently,

[vikasrohit]

@ngoctay @gondzo Just as information again (not in relation with latest comments), we are trying to find out if this situation is common across standard api development or are we doing some thing different here. And if we are doing something wrong, we need to fix in that case only, otherwise we are good. :)

[vikasrohit]

Moving to backlog for now as we haven't found a good solution for it yet but we are able to overcome this by making call sequentially from front end.