Timeout of 3 seconds exceeded

[zhangxiaohou]

I get this error report everytime after some problem happened.Then I review the code in "vendor\malkusch\lock"and find some bug for Redis:If u set a lock for the bucket and the client broke,this lock will never be release so that every request will be stoped by the "setnx".I wonder if u have some solution for this bug,and sorry for my English :p by zhangxiaohou

[malkusch]

Could you please provide the PHP and Redis version. Do you have a minimal example to reproduce the problem?

[zhangxiaohou]

php - 5.6.6 ;Redis server v=2.8.4 ; For reproducing this bug,u can bootstrap a token-bucet named tb ,for example.Then set a key named lock_tb manual in Redis. After that,if u want to consume a token ,the bug will reproduce.Here is the detail:

1. redis-cli set lock_tb 123
2. run this php code:

<?php
require_once "vendor/autoload.php";
use bandwidthThrottle\tokenBucket\Rate;
use bandwidthThrottle\tokenBucket\TokenBucket;
use bandwidthThrottle\tokenBucket\BlockingConsumer;
use bandwidthThrottle\tokenBucket\storage\PHPRedisStorage;

$redis = new Redis();
$redis->connect("127.0.0.1");
$storage  = new PHPRedisStorage( "tb", $redis);
$rate = new Rate(10, Rate::SECOND);
$bucket = new TokenBucket(10, $rate, $storage);
$consumer = new BlockingConsumer($bucket);
$bucket->bootstrap(1);

$result = $consumer->consume(1);
echo "API respose\n";

1. bug reproduce and the stack trace here:

Fatal error: Uncaught exception 'malkusch\lock\exception\TimeoutException' with message 'Timeout of 3 seconds exceeded.' in /Applications/MAMP/htdocs/token-bucket/vendor/malkusch/lock/classes/util/Loop.php:86
Stack trace:
#0 /Applications/MAMP/htdocs/token-bucket/vendor/malkusch/lock/classes/mutex/SpinlockMutex.php(74): malkusch\lock\util\Loop->execute(Object(Closure))
#1 /Applications/MAMP/htdocs/token-bucket/vendor/malkusch/lock/classes/mutex/LockMutex.php(37): malkusch\lock\mutex\SpinlockMutex->lock()
#2 /Applications/MAMP/htdocs/token-bucket/vendor/malkusch/lock/classes/util/DoubleCheckedLocking.php(74): malkusch\lock\mutex\LockMutex->synchronized(Object(Closure))
#3 /Applications/MAMP/htdocs/token-bucket/classes/TokenBucket.php(115): malkusch\lock\util\DoubleCheckedLocking->then(Object(Closure))
#4 /Applications/MAMP/htdocs/token-bucket/testRate.php(22): bandwidthThrottle\tokenBucket\TokenBucket->bootstrap(1)
#5 {main}
  thrown in /Applications/MAMP/htdocs/token-bucket/vendor/malkusch/lock/classes/util/Loop.php on line 86

[zhangxiaohou]

I found some documentation , i think deadlocks happend in this bug http://redis.io/commands/setnx

[malkusch]

Why do you add the key with redis-cli set lock_tb 123? This will of course timeout, as this key is never released. Your example is too artificial and does not represent the real issue.

Could it be that you are somehow experiencing something like https://github.com/phpredis/phpredis/issues/579? This was fixed in phpredis-2.2.8. Which phpredis version are you using (php -i | grep -i "redis version")? Could you switch to Predis and see if it happens with PredisStorage as well?

[zhangxiaohou]

i add that key to simulate a situation:if a client request come in and the token-bucket add a lock (like the lock_tb here),but before the lock be released ,the client crash or some bug happened ,then the lock will never be released. It happened to me so i wonder if u get something like this .

[malkusch]

the lock will never be released.

That should not happen as PHPRedisMutex is using the EX option (which is 3 seconds as default).

It happened to me

It's normal that you observe a lock key in Redis. But this key should expire after 3 seconds. So, when this happens to you, what shows redis-cli ttl lock_tb?

May I ask you again: Which phpredis version are you using (php -i | grep -i "redis version")? Could you switch to Predis and see if it happens with PredisStorage as well (after removing the offending key from redis)?

[keilestone]

I have the same problem, do you solve it? :(