horizon: Reconnecting to redis (after short unavailability), not working with password protected redis instance
- Horizon Version: v3.4.4
- Laravel Version: v6.9.0
- PHP Version: 7.4.0
- Redis Driver & Version: phpredis 5.1.1
Description:
This issue has been haunting us a long time now. Initially we did not know why this was randomly happening (Issue #708 ) later we found out that the re-connecting in general was not working (Issue #716 ) which was fixed by taylor (thank you!) but this only is now working correctly for redis instances that are not password protected.
In a situation where horizon is running against a redis instances that is password protected, and redis is shortly (or long) unavailable, even after redis is back, horizon will not recover spitting out NOAUTH errors like this one:
ERROR: NOAUTH Authentication required. {"exception":"[object] (RedisException(code: 0): NOAUTH Authentication required. at /var/www/vendor/laravel/framework/src/Illuminate/Redis/Connections/Connection.php:111)
[stacktrace]
#0 /var/www/vendor/laravel/framework/src/Illuminate/Redis/Connections/Connection.php(111): Redis->lLen('commands:master...')
#1 /var/www/vendor/laravel/framework/src/Illuminate/Redis/Connections/PhpRedisConnection.php(440): Illuminate\\Redis\\Connections\\Connection->command('llen', Array)
#2 /var/www/vendor/laravel/framework/src/Illuminate/Redis/Connections/Connection.php(211): Illuminate\\Redis\\Connections\\PhpRedisConnection->command('llen', Array)
#3 /var/www/vendor/laravel/framework/src/Illuminate/Redis/Connections/PhpRedisConnection.php(482): Illuminate\\Redis\\Connections\\Connection->__call('llen', Array)
#4 /var/www/vendor/laravel/horizon/src/RedisHorizonCommandQueue.php(51): Illuminate\\Redis\\Connections\\PhpRedisConnection->__call('llen', Array)
#5 /var/www/vendor/laravel/horizon/src/MasterSupervisor.php(263): Laravel\\Horizon\\RedisHorizonCommandQueue->pending('master:d4711be9...')
#6 /var/www/vendor/laravel/horizon/src/MasterSupervisor.php(240): Laravel\\Horizon\\MasterSupervisor->processPendingCommands()
#7 /var/www/vendor/laravel/horizon/src/MasterSupervisor.php(213): Laravel\\Horizon\\MasterSupervisor->loop()
#8 /var/www/vendor/laravel/horizon/src/Console/HorizonCommand.php(63): Laravel\\Horizon\\MasterSupervisor->monitor()
#9 [internal function]: Laravel\\Horizon\\Console\\HorizonCommand->handle(Object(Laravel\\Horizon\\Repositories\\RedisMasterSupervisorRepository))
#10 /var/www/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(32): call_user_func_array(Array, Array)
#11 /var/www/vendor/laravel/framework/src/Illuminate/Container/Util.php(36): Illuminate\\Container\\BoundMethod::Illuminate\\Container\\{closure}()
#12 /var/www/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(90): Illuminate\\Container\\Util::unwrapIfClosure(Object(Closure))
#13 /var/www/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(34): Illuminate\\Container\\BoundMethod::callBoundMethod(Object(App\\Extensions\\Illuminate\\Foundation\\Application), Array, Object(Closure))
#14 /var/www/vendor/laravel/framework/src/Illuminate/Container/Container.php(590): Illuminate\\Container\\BoundMethod::call(Object(App\\Extensions\\Illuminate\\Foundation\\Application), Array, Array, NULL)
#15 /var/www/vendor/laravel/framework/src/Illuminate/Console/Command.php(202): Illuminate\\Container\\Container->call(Array)
#16 /var/www/vendor/symfony/console/Command/Command.php(255): Illuminate\\Console\\Command->execute(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Illuminate\\Console\\OutputStyle))
#17 /var/www/vendor/laravel/framework/src/Illuminate/Console/Command.php(189): Symfony\\Component\\Console\\Command\\Command->run(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Illuminate\\Console\\OutputStyle))
#18 /var/www/vendor/symfony/console/Application.php(1011): Illuminate\\Console\\Command->run(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))
#19 /var/www/vendor/symfony/console/Application.php(272): Symfony\\Component\\Console\\Application->doRunCommand(Object(Laravel\\Horizon\\Console\\HorizonCommand), Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))
#20 /var/www/vendor/symfony/console/Application.php(148): Symfony\\Component\\Console\\Application->doRun(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))
#21 /var/www/vendor/laravel/framework/src/Illuminate/Console/Application.php(93): Symfony\\Component\\Console\\Application->run(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))
#22 /var/www/vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php(131): Illuminate\\Console\\Application->run(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))
#23 /var/www/artisan(37): Illuminate\\Foundation\\Console\\Kernel->handle(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))
#24 {main}
Important. This ONLY happens with the phpredis driver, predis is not affected.
Steps To Reproduce:
- Have a fresh (or not fresh) laravel installation with horizon.
- Have a redis instance that is password protected (for example running it from this dockerfile)
- configure your database.php in laravel accordingly to have correct redis password set
FROM redis:5.0.2
COPY redis.conf /usr/local/etc/redis/redis.conf
CMD [ "redis-server", "/usr/local/etc/redis/redis.conf" ]
where the redis.conf looks like this
requirepass testpassword
- Then start horizon, let it warm up
- turn off your redis instance or break the connection between horizon & redis somehow.
- turn on redis instance again (or enable connection between horizon & redis again)
- horizon will continuously spit out errors as specified above (NOAUTH)
About this issue
- Original URL
- State: closed
- Created 4 years ago
- Comments: 40 (26 by maintainers)
As an update: The past few maintenance cycles were without issues and the NOAUTH issue is definitively solved with phpredis 5.2.2
However persistent redis connections are still extremely unstable and making problems for us. @michael-grunder hinted us towards other things we can try, but we’ve now had to focus on other issues at hand so we reverted back to not-persistent connections, which are now working fine.
I’m closing this ticket and thanking everybody involved, especially @michael-grunder for all his work at phpredis!
Hi everyone 👋
I don’t actually think phpredis/phpredis#1742 will solve this issue. It could theoretically be related, but that’s more of a performance bug where we’re sending far too many
ECHOcalls to Redis to keep the persistent connections from going out of sync.That said, I do believe it’s been fixed via phpredis/phpredis@35372a1f64f643cf4ce52c62c61e326e7d6a1e6e
I pulled down the docker-compose setup @graemlourens created and was able to trigger the error somewhat reliably by doing the following while tailing the horizon logs:
Basically I’m nuking every redis connection in a loop and eventually it always gets into the
NOAUTHstate when I use phpredis5.2.1.However, I have not been able to put it into that state using the develop branch of phpredis. I haven’t bisected the problem to 100% confirm that is the commit but I suspect it is.
I’ll do some more testing tomorrow and if i can confirm this commit has fixed the problem will package up a release candidate with just this change included.
Feel free to try as well and let me know if you can still trigger the issue using our develop branch.
Cheers! Mike
@michael-grunder @graemlourens thanks to you both for all your time and help on this so far.
There is a new upcoming release of PHPRedis on its way, fixing a known issue about bad persistent connection states. https://github.com/phpredis/phpredis/issues/1742 The branch phpredis 5.2.1-liveness is the one that will fix this issue.
Still i can not understand though why this also happened for non-persistent connections, but at this point i’m desperate to try anything.
This morning also in our app containers (that are also using persistent redis connections) connections to redis were randomly failing, even if redis was open, what leads to the conclusion that there is some situation where certain persistent redis connections get ‘bad’ and when used, fail unexpectedly. This would also support the theory that this issue has nothing to do with horizon or laravel in general.
We’ll update to the new phpredis version as soon as we can and hope that i can come back with good news…
@michael-grunder thank you for your update. We’ll be releasing a new version (of our app) with phpredis 5.2.2 in the next 2 days and then monitor the situation over the next 2 weeks. I’ll get back to you if we still see any sign of trouble. After nearly 4 months this would be a delight to be able to put this one to bed! 😃
I’ve created a release branch for phpredis 5.2.2RC1 with fixes for this issue.
My goal is the smallest change possible so it is simply 5.2.1 with two additional commits:
If people have the time it would be awesome for others to confirm that it does in fact solve the problem.
Assuming all goes well I can get the RC out over the weekend with a GA release to follow shortly after.
@michael-grunder hey mike, that sounds great. And indeed, i linked the wrong issue/commit. I actually meant that one you wrote, thx for correcting me.
I did a quick test and it seems that the auth fix in the develop branch actually is working, but this is just really a highlevel-check without any deeper understanding on phpredis itsself. I’ll leave that kind of review to others with more knowledge about your package.
I’m really excited to roll this out to our environments as soon as you have packaged and released this new version. I can then happily give you more long term feedback when its been in Operations for a few weeks.
Kind regards, Graem
@wolkenheim thank you for your thoughts. Very good to hear that you were able to reproduce it with the horizon_test.zip i provided.
Temporary solution until we find the root cause is mentioned by @pulkitjalan but requires you to fork/patch laravel framework, and is in no way a permanent or even intermediate solution.
@graemlourens we are having this same problem and have been looking for a solution for a while now. I think I have finally been able to consistently produce the problem locally.
Adding
NOAUTHto the check as you suggested does help to solve the problem on laravels side.There is no reliable way I can see right now to also do a config check for a password, and the exception is still thrown regardless, however, the horizon worker does not get stuck and keep throwing these exceptions so it does solve that issue.
Developer of phpredis here, feel free to open an issue in our repo if the work in phpredis/phpredis#1668 doesn’t solve the problem.
I believe to have finally found the issue. I can reproduce the error, but only maybe 1 out of 20 attempts. It depends on the state of the redis-connection at the time of reboot of the redis server.
The underlying problem seems not to be the way laravel-reconnects (this was correctly handled in laravel/framework#30778 ) but that phpredis (not predis) itsself has a ‘reconnect’ feature that is not reliable remembering to auth. There are 2 ancient but seemingly partially resolved tickets (even if they are closed): https://github.com/phpredis/phpredis/issues/515 and https://github.com/phpredis/phpredis/issues/403 whereby exactly this behaviour is described.
My problem is that i can not force this situation to happen reliably, so until i can do that, i’m not able to create a ticket in phpredis.
However the problem can be solved on side of laravel if we would not only catch the phrase ‘went away’ in src/Illuminate/Redis/Connections/PhpRedisConnection.php but also ‘NOAUTH’ assuming there is a password in the configuration (to prevent false positive in case you actually forgot to set a password in your config) and in that case reconnect. I tested this and it works as expected without that i can forsee any negative impacts.
This is the only way i’m able to explain this behaviour. Can somebody doublecheck my assumptions & conclusions?
UPDATE:
I just found that a new stable version of phpredis has been released (5.2) and in there, there is a ticket concerning persistent connections (which is irrelevant to this problem as it happens for both situations) but there is a part of the code change so that AUTH gets sent before PING what would make sense could be solving this issue (without laravel having to do anything). The Ticket is here: https://github.com/phpredis/phpredis/issues/1668 and i’ll now be rolling out the new Version of phpredis to see if this issue still persists.
I’ll keep this issue updated with new information.