{"action":"created","issue":{"url":"https://api.github.com/repos/OptimalBits/bull/issues/371","repository_url":"https://api.github.com/repos/OptimalBits/bull","labels_url":"https://api.github.com/repos/OptimalBits/bull/issues/371/labels{/name}","comments_url":"https://api.github.com/repos/OptimalBits/bull/issues/371/comments","events_url":"https://api.github.com/repos/OptimalBits/bull/issues/371/events","html_url":"https://github.com/OptimalBits/bull/issues/371","id":188382903,"number":371,"title":"\"Unexpected token u in JSON at position 0\" while processing job","user":{"login":"bradvogel","id":821706,"avatar_url":"https://avatars.githubusercontent.com/u/821706?v=3","gravatar_id":"","url":"https://api.github.com/users/bradvogel","html_url":"https://github.com/bradvogel","followers_url":"https://api.github.com/users/bradvogel/followers","following_url":"https://api.github.com/users/bradvogel/following{/other_user}","gists_url":"https://api.github.com/users/bradvogel/gists{/gist_id}","starred_url":"https://api.github.com/users/bradvogel/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/bradvogel/subscriptions","organizations_url":"https://api.github.com/users/bradvogel/orgs","repos_url":"https://api.github.com/users/bradvogel/repos","events_url":"https://api.github.com/users/bradvogel/events{/privacy}","received_events_url":"https://api.github.com/users/bradvogel/received_events","type":"User","site_admin":false},"labels":[{"id":45333491,"url":"https://api.github.com/repos/OptimalBits/bull/labels/bug","name":"bug","color":"fc2929","default":true}],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":6,"created_at":"2016-11-09T23:48:47Z","updated_at":"2016-11-13T00:37:37Z","closed_at":null,"body":"I'm noticing that some of our jobs are \"corrupted\" and the queue is throwing the following error when trying to process them:\r\n\r\n```\r\nError processing job: SyntaxError: Unexpected token u in JSON at position 0\r\n    at Object.parse (native)\r\n    at Function.Job.fromData (/Users/brad/dev/bull-queue/node_modules/bull/lib/job.js:418:33)\r\n    at /Users/brad/dev/bull-queue/node_modules/bull/lib/job.js:68:18\r\n    at tryCatcher (/Users/brad/dev/bull-queue/node_modules/bluebird/js/release/util.js:16:23)\r\n```\r\n\r\nIn inspecting the job in redis using `hgetall bull:test:1` I can see that only `attemptsMade`, `stacktrace`, and `failedReason` keys are present in the job data.\r\n\r\nThis leads me to believe that a job failed (and `_saveAttempt` was called) _after_ the job data had been already removed - which can only happen if the job was completed by another worker. And the only way another worker could have completed it is if the first worker failed to renew the lock.\r\n\r\nTo fix this, what do you think about the following solutions:\r\n1. Making `Job.prototype.moveToFailed` an atomic script that guarantees that we own the lock before moving the job. So if another worker picked up the job and it got double processed, we won't do farther damage by trying to move that completed job back to the delayed queue.\r\n2. Making the lock token job specific instead of queue specific, so a single queue instance can't double process its own jobs.\r\n\r\nThis is related to #273."},"comment":{"url":"https://api.github.com/repos/OptimalBits/bull/issues/comments/260158407","html_url":"https://github.com/OptimalBits/bull/issues/371#issuecomment-260158407","issue_url":"https://api.github.com/repos/OptimalBits/bull/issues/371","id":260158407,"user":{"login":"doublerebel","id":212827,"avatar_url":"https://avatars.githubusercontent.com/u/212827?v=3","gravatar_id":"","url":"https://api.github.com/users/doublerebel","html_url":"https://github.com/doublerebel","followers_url":"https://api.github.com/users/doublerebel/followers","following_url":"https://api.github.com/users/doublerebel/following{/other_user}","gists_url":"https://api.github.com/users/doublerebel/gists{/gist_id}","starred_url":"https://api.github.com/users/doublerebel/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/doublerebel/subscriptions","organizations_url":"https://api.github.com/users/doublerebel/orgs","repos_url":"https://api.github.com/users/doublerebel/repos","events_url":"https://api.github.com/users/doublerebel/events{/privacy}","received_events_url":"https://api.github.com/users/doublerebel/received_events","type":"User","site_admin":false},"created_at":"2016-11-13T00:37:37Z","updated_at":"2016-11-13T00:37:37Z","body":"I was able to create a repeatable case where the jobs are double processed, and the stalled event is not emitted.  Thanks for the heads up to check and make sure stalled was not the case.  Here is the test case, but the failure also exists in several of my past builds and in OptimalBits/bull master builds also.\r\nhttps://travis-ci.org/nextorigin/bull/builds/175392452\r\n\r\nAs described in http://redis.io/commands/SET under **Patterns**, the recommended way to create a distributed lock is now the 'redlock' algorithm.  I implemented the algo and [it fixes the cluster test case](https://travis-ci.org/nextorigin/bull/builds/175401676), but I still have a little work to do to get the rest of the tests passing with the new lock logic.\r\n\r\nOnce I'm finished we should probably check how the redlock algo affects performance.  Right now there are many failed lock attempts but we are running jobs quickly in the tests, it may not be a noticeable performance hit in real-world situations.\r\n"}}
{"actor":{"display_login":"doublerebel"}}