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

[6.x] Fixed ConcurrencyLimiter #30005

Merged
merged 1 commit into from
Sep 16, 2019

Conversation

arjanwestdorp
Copy link
Contributor

Today I was using the ConcurrencyLimiter in my application and I noticed that it was not working as expected. I'm using it to ensure that there is only one worker executing a type of job at a time.
While running this locally with two queue workers I noticed that both workers were processing the same type of job even though I configured it to have a concurrency of only 1. After debugging I figured out it is related to the redis prefix. This prefix is now configured by default in laravel/laravel#4982 so it will affect all users using Laravel 6. Any application that is using horizon will also experience this issue as horizon is adding horizon: as default prefix.

I've setup two queue workers while dispatching two jobs to the queue with the following script.

dispatch(function () {
    Redis::funnel('foo')
        ->limit(1)
        ->then(function () {
            Log::info('[START] A');
            sleep(10);
            Log::info('[STOP] A');
        }, function () {
            Log::info('lock already obtained');
        });
});

dispatch(function () {
    Redis::funnel('foo')
        ->limit(1)
        ->then(function () {
            Log::info('[START] B');
            sleep(10);
            Log::info('[STOP] B');
        }, function () {
            Log::info('lock already obtained');
        });
});

My log file gives the following output:

[2019-09-16 09:28:16] local.INFO: [START] A
[2019-09-16 09:28:18] local.INFO: [START] B
[2019-09-16 09:28:26] local.INFO: [STOP] A
[2019-09-16 09:28:28] local.INFO: [STOP] B

As you can see both jobs were running at the same time. After running redis-cli monitor these are the redis commands that are executed (by Illuminate\Redis\Limiters\ConccurencyLimiter@lockScript`):

1568626342.225175 [0 lua] "mget" "laravel_database_foo1"
1568626342.225189 [0 lua] "set" "foo1" "v8E0BkXy82EAYqqrj3DX" "EX" "60"
1568626343.732566 [0 lua] "mget" "laravel_database_foo1"
1568626343.732575 [0 lua] "set" "foo1" "WPj9R8LXlLdWqygJyxqk" "EX" "60"

It's trying to get the lock record WITH prefix, but it's setting the lock record WITHOUT prefix.
Basically the whole concurrency check is not functioning at all at the moment when there is a redis prefix configured.

This PR makes sure the KEYS value is used to ensure the prefix is added when setting the lock record key.

When running the same test after this change this is the output:

[2019-09-16 09:36:49] local.INFO: [START] A
[2019-09-16 09:36:53] local.INFO: lock already obtained
[2019-09-16 09:36:59] local.INFO: [STOP] A

And redis-cli monitor is now showing this:

1568626609.462540 [0 lua] "mget" "laravel_database_foo1"
1568626609.462553 [0 lua] "set" "laravel_database_foo1" "dHVlZDemEgpncgEcxvLO" "EX" "60"
1568626610.862919 [0 lua] "mget" "laravel_database_foo1"
1568626611.114044 [0 lua] "mget" "laravel_database_foo1"
1568626611.368472 [0 lua] "mget" "laravel_database_foo1"

@jmarcher
Copy link
Contributor

Please provide some tests.

@arjanwestdorp
Copy link
Contributor Author

Setting the prefix in the InteractsWithRedis trait made 4 out of the 5 tests fail for the ConcurrenyLimiterTest. I assume that proves enough the issue?

@taylorotwell taylorotwell merged commit 441ba59 into laravel:6.x Sep 16, 2019
@GrahamCampbell GrahamCampbell changed the title [6.x] ConcurrencyLimiter seems to be broken [6.x] Fixed ConcurrencyLimiter Sep 16, 2019
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