redis-lock
redis-lock copied to clipboard
Race condition with multiple pending locks allows lock to be acquired when it shouldn't
A bit of background:
I'm using Sidekiq to run tasks in the background. Some types of tasks use a lock to ensure only one task of the same type is running at any given time. For example, WorkerA has 5 running instances, the requirement is that those instances do not overlap. The way our tasks run, there can be 20+ instances waiting for the lock at the same time.
The race condition seems to happen on lines 42-44 in redis/lock.rb
if (current_lock.to_s.split('-').first.to_i) < Time.now.to_i
compare_value = self.getset(current_lock_key, expiration_value)
return true if compare_value == current_lock
end
It seems like all threads waiting on the lock suddenly get it when the lock expires.
This is the code I have that produces the problem:
def perform
Sidekiq.redis do |redis|
logger.info { 'Waiting for lock' }
redis.lock_for_update('test') do
logger.info { 'Got lock' }
sleep 20 # Simulate work
end
logger.info { 'Released lock' }
end
end
invoked with:
20.times { CreateResourceWorker.perform_async }
and the output:
2016-11-28T21:23:18.232Z 3125 TID-aso44 CreateResourceWorker JID-f5f6daf20eb3ee937557004e INFO: start
2016-11-28T21:23:18.233Z 3125 TID-aso44 CreateResourceWorker JID-f5f6daf20eb3ee937557004e INFO: Waiting for lock
2016-11-28T21:23:18.233Z 3125 TID-aso44 CreateResourceWorker JID-f5f6daf20eb3ee937557004e INFO: Got lock
2016-11-28T21:23:18.234Z 3125 TID-asogc CreateResourceWorker JID-aef10b9df26d0bf73665dcf3 INFO: start
2016-11-28T21:23:18.235Z 3125 TID-asogc CreateResourceWorker JID-aef10b9df26d0bf73665dcf3 INFO: Waiting for lock
2016-11-28T21:23:18.236Z 3125 TID-n541w CreateResourceWorker JID-60923f151802c7b6efb75974 INFO: start
2016-11-28T21:23:18.236Z 3125 TID-asous CreateResourceWorker JID-b167a9c4c097a710b65839d4 INFO: start
2016-11-28T21:23:18.236Z 3125 TID-n522s CreateResourceWorker JID-75a86b62d3d5a719ef3d817e INFO: start
2016-11-28T21:23:18.237Z 3125 TID-n541w CreateResourceWorker JID-60923f151802c7b6efb75974 INFO: Waiting for lock
2016-11-28T21:23:18.237Z 3125 TID-n532c CreateResourceWorker JID-35b13e9c7f51b4322ae45238 INFO: start
2016-11-28T21:23:18.238Z 3125 TID-asqew CreateResourceWorker JID-b2739407ba1d5d5a81369374 INFO: start
2016-11-28T21:23:18.238Z 3125 TID-aspes CreateResourceWorker JID-22de4c6a6f5cc7b48f5fd375 INFO: start
2016-11-28T21:23:18.238Z 3125 TID-n52v4 CreateResourceWorker JID-8ab415ea87a5c5929705f499 INFO: start
2016-11-28T21:23:18.240Z 3125 TID-n4dlo CreateResourceWorker JID-ae675f73062d60cc666398e0 INFO: start
2016-11-28T21:23:18.240Z 3125 TID-asous CreateResourceWorker JID-b167a9c4c097a710b65839d4 INFO: Waiting for lock
2016-11-28T21:23:18.240Z 3125 TID-n53o0 CreateResourceWorker JID-572ad62531e963c84b2f6259 INFO: start
2016-11-28T21:23:18.240Z 3125 TID-n5520 CreateResourceWorker JID-bde19b53283cb05ba09381d3 INFO: start
2016-11-28T21:23:18.241Z 3125 TID-n54gc CreateResourceWorker JID-913570bb2843e180863cd879 INFO: start
2016-11-28T21:23:18.241Z 3125 TID-n522s CreateResourceWorker JID-75a86b62d3d5a719ef3d817e INFO: Waiting for lock
2016-11-28T21:23:18.243Z 3125 TID-asp5w CreateResourceWorker JID-612571f10afcb6afc22b604e INFO: start
2016-11-28T21:23:18.243Z 3125 TID-n54us CreateResourceWorker JID-ccba092e3790844062b6a21f INFO: start
2016-11-28T21:23:18.244Z 3125 TID-asq1k CreateResourceWorker JID-8ed33256dc24197b8f093222 INFO: start
2016-11-28T21:23:18.244Z 3125 TID-n539k CreateResourceWorker JID-bcaae99e91f3a6412e130f45 INFO: start
2016-11-28T21:23:18.244Z 3125 TID-n532c CreateResourceWorker JID-35b13e9c7f51b4322ae45238 INFO: Waiting for lock
2016-11-28T21:23:18.244Z 3125 TID-n52h8 CreateResourceWorker JID-f4b894af75d17db099c245c0 INFO: start
2016-11-28T21:23:18.244Z 3125 TID-n53v8 CreateResourceWorker JID-a1e227c8825cfa114cfdd8eb INFO: start
2016-11-28T21:23:18.245Z 3125 TID-n52a0 CreateResourceWorker JID-aaeb28971024124052b4b1ce INFO: start
2016-11-28T21:23:18.246Z 3125 TID-n54nk CreateResourceWorker JID-413d3b0f694c102760be20a1 INFO: start
2016-11-28T21:23:18.246Z 3125 TID-asqew CreateResourceWorker JID-b2739407ba1d5d5a81369374 INFO: Waiting for lock
2016-11-28T21:23:18.247Z 3125 TID-aspes CreateResourceWorker JID-22de4c6a6f5cc7b48f5fd375 INFO: Waiting for lock
2016-11-28T21:23:18.247Z 3125 TID-n52v4 CreateResourceWorker JID-8ab415ea87a5c5929705f499 INFO: Waiting for lock
2016-11-28T21:23:18.248Z 3125 TID-n4dlo CreateResourceWorker JID-ae675f73062d60cc666398e0 INFO: Waiting for lock
2016-11-28T21:23:18.249Z 3125 TID-n53o0 CreateResourceWorker JID-572ad62531e963c84b2f6259 INFO: Waiting for lock
2016-11-28T21:23:18.250Z 3125 TID-n5520 CreateResourceWorker JID-bde19b53283cb05ba09381d3 INFO: Waiting for lock
2016-11-28T21:23:18.250Z 3125 TID-n54gc CreateResourceWorker JID-913570bb2843e180863cd879 INFO: Waiting for lock
2016-11-28T21:23:18.251Z 3125 TID-asp5w CreateResourceWorker JID-612571f10afcb6afc22b604e INFO: Waiting for lock
2016-11-28T21:23:18.252Z 3125 TID-n54us CreateResourceWorker JID-ccba092e3790844062b6a21f INFO: Waiting for lock
2016-11-28T21:23:18.253Z 3125 TID-asq1k CreateResourceWorker JID-8ed33256dc24197b8f093222 INFO: Waiting for lock
2016-11-28T21:23:18.254Z 3125 TID-n539k CreateResourceWorker JID-bcaae99e91f3a6412e130f45 INFO: Waiting for lock
2016-11-28T21:23:18.255Z 3125 TID-n52h8 CreateResourceWorker JID-f4b894af75d17db099c245c0 INFO: Waiting for lock
2016-11-28T21:23:18.256Z 3125 TID-n53v8 CreateResourceWorker JID-a1e227c8825cfa114cfdd8eb INFO: Waiting for lock
2016-11-28T21:23:18.257Z 3125 TID-n52a0 CreateResourceWorker JID-aaeb28971024124052b4b1ce INFO: Waiting for lock
2016-11-28T21:23:18.258Z 3125 TID-n54nk CreateResourceWorker JID-413d3b0f694c102760be20a1 INFO: Waiting for lock
2016-11-28T21:23:38.243Z 3125 TID-aso44 CreateResourceWorker JID-f5f6daf20eb3ee937557004e INFO: Released lock
2016-11-28T21:23:38.243Z 3125 TID-aso44 CreateResourceWorker JID-f5f6daf20eb3ee937557004e INFO: done: 20.011 sec
2016-11-28T21:23:38.250Z 3125 TID-asogc CreateResourceWorker JID-aef10b9df26d0bf73665dcf3 INFO: Got lock
2016-11-28T21:23:58.410Z 3125 TID-asogc CreateResourceWorker JID-aef10b9df26d0bf73665dcf3 INFO: Released lock
2016-11-28T21:23:58.411Z 3125 TID-asogc CreateResourceWorker JID-aef10b9df26d0bf73665dcf3 INFO: done: 40.177 sec
2016-11-28T21:23:58.427Z 3125 TID-asp5w CreateResourceWorker JID-612571f10afcb6afc22b604e INFO: Got lock
2016-11-28T21:24:18.551Z 3125 TID-asp5w CreateResourceWorker JID-612571f10afcb6afc22b604e INFO: Released lock
2016-11-28T21:24:18.551Z 3125 TID-asp5w CreateResourceWorker JID-612571f10afcb6afc22b604e INFO: done: 60.308 sec
2016-11-28T21:24:18.569Z 3125 TID-n54us CreateResourceWorker JID-ccba092e3790844062b6a21f INFO: Got lock
2016-11-28T21:24:20.681Z 3125 TID-n541w CreateResourceWorker JID-60923f151802c7b6efb75974 INFO: Got lock
2016-11-28T21:24:20.797Z 3125 TID-n52h8 CreateResourceWorker JID-f4b894af75d17db099c245c0 INFO: Got lock
2016-11-28T21:24:20.800Z 3125 TID-n52a0 CreateResourceWorker JID-aaeb28971024124052b4b1ce INFO: Got lock
2016-11-28T21:24:20.802Z 3125 TID-n53o0 CreateResourceWorker JID-572ad62531e963c84b2f6259 INFO: Got lock
2016-11-28T21:24:20.804Z 3125 TID-asous CreateResourceWorker JID-b167a9c4c097a710b65839d4 INFO: Got lock
2016-11-28T21:24:20.805Z 3125 TID-n532c CreateResourceWorker JID-35b13e9c7f51b4322ae45238 INFO: Got lock
2016-11-28T21:24:20.806Z 3125 TID-asq1k CreateResourceWorker JID-8ed33256dc24197b8f093222 INFO: Got lock
2016-11-28T21:24:20.808Z 3125 TID-n53v8 CreateResourceWorker JID-a1e227c8825cfa114cfdd8eb INFO: Got lock
2016-11-28T21:24:20.810Z 3125 TID-n4dlo CreateResourceWorker JID-ae675f73062d60cc666398e0 INFO: Got lock
2016-11-28T21:24:20.810Z 3125 TID-n539k CreateResourceWorker JID-bcaae99e91f3a6412e130f45 INFO: Got lock
2016-11-28T21:24:20.811Z 3125 TID-n54gc CreateResourceWorker JID-913570bb2843e180863cd879 INFO: Got lock
2016-11-28T21:24:31.381Z 3125 TID-aspes CreateResourceWorker JID-22de4c6a6f5cc7b48f5fd375 INFO: Got lock
2016-11-28T21:24:31.533Z 3125 TID-n52v4 CreateResourceWorker JID-8ab415ea87a5c5929705f499 INFO: Got lock
Yes, this package is useless. Locking is not done right.