RedisException "NOAUTH Authentication required." after a while (password protected redis + tls)

[graemlourens]

• Horizon Version: v3.4.2
• Laravel Version: v6.0.3
• PHP Version: 7.2.23
• Redis Driver & Version: phpredis 5.1.1

Description:

We currently are running horizon connected to redis via tls & AUTH password.
Until now we were using predis, and now switched to phpredis pecl package.
After doing the simple switch in database.php config driver to 'phpredis' (and leaving everything else as it was before) deploying worked, and queue processes started correctly.
After approximately 5 Minutes, we got a flood of errors all looking like this:

    "class": "RedisException",
    "message": "NOAUTH Authentication required.",
    "code": 0,
    "file": "\/var\/www\/vendor\/laravel\/framework\/src\/Illuminate\/Redis\/Connections\/Connection.php:111",
    "trace": [
        "\/var\/www\/vendor\/laravel\/framework\/src\/Illuminate\/Redis\/Connections\/Connection.php:111",
        "\/var\/www\/vendor\/laravel\/framework\/src\/Illuminate\/Redis\/Connections\/Connection.php:211",
        "\/var\/www\/vendor\/laravel\/framework\/src\/Illuminate\/Redis\/Connections\/PhpRedisConnection.php:451",
        "\/var\/www\/vendor\/laravel\/horizon\/src\/RedisHorizonCommandQueue.php:51",
        "\/var\/www\/vendor\/laravel\/horizon\/src\/MasterSupervisor.php:263",
        "\/var\/www\/vendor\/laravel\/horizon\/src\/MasterSupervisor.php:240",
        "\/var\/www\/vendor\/laravel\/horizon\/src\/MasterSupervisor.php:213",
        "\/var\/www\/vendor\/laravel\/horizon\/src\/Console\/HorizonCommand.php:63",
        "\/var\/www\/vendor\/laravel\/framework\/src\/Illuminate\/Container\/BoundMethod.php:32",
        "\/var\/www\/vendor\/laravel\/framework\/src\/Illuminate\/Container\/BoundMethod.php:90",
        "\/var\/www\/vendor\/laravel\/framework\/src\/Illuminate\/Container\/BoundMethod.php:34",
        "\/var\/www\/vendor\/laravel\/framework\/src\/Illuminate\/Container\/Container.php:591",
        "\/var\/www\/vendor\/laravel\/framework\/src\/Illuminate\/Console\/Command.php:192",
        "\/var\/www\/vendor\/symfony\/console\/Command\/Command.php:255",
        "\/var\/www\/vendor\/laravel\/framework\/src\/Illuminate\/Console\/Command.php:179",
        "\/var\/www\/vendor\/symfony\/console\/Application.php:915",
        "\/var\/www\/vendor\/symfony\/console\/Application.php:272",
        "\/var\/www\/vendor\/symfony\/console\/Application.php:148",
        "\/var\/www\/vendor\/laravel\/framework\/src\/Illuminate\/Console\/Application.php:90",

Before this error a few hundred jobs were processed correctly, and after this error, nothing was being processed anymore.

After a little of researching we came across a post noting that the password should additionally be set in the 'options' section of the config. And indeed this works, but we were not able to explain why, and where the issue is happening.

    'redis' => [

        'client' => 'phpredis',

        'cluster' => env('REDIS_CLUSTER', false),

        'general' => [
            'scheme'   => env('REDIS_SCHEME', 'tcp'),
            'host'     => env('REDIS_HOST', '127.0.0.1'),
            'port'     => env('REDIS_PORT', 6379),
            'database' => env('REDIS_DATABASE', 0),
            'password' => env('REDIS_PASSWORD', null),
            'timeout' => 1,
            'read_timeout' => 5,
        ],
        'options' => [
            'parameters' => [
                'password' => env('REDIS_PASSWORD', null)
            ],
        ],
    ],

We are currently unsure if this is a horizon issue or generally a illuminate redis issue.
Hoping that somebody can share their experiences to see the common denominator and explain this mystery.

Steps To Reproduce:

• use phpredis as a driver
• protect your redis instance with a password (we are currently also behind STUNNEL for tls usage)
• setup your database.php config as above but do NOT add the 'options' part.
• start horizon and process some jobs, after a while (at least for us) suddenly horizon is throwing lots of errors as noted above.

[graemlourens]

We have further information regarding this matter. It seems that we were experiencing a false positive with this 'options' configuration. It did not solve or prevent the issue.
I do not want to edit the initial issue as this would be too much of a change in description and the initial false positive information would be lost.

We have seen a correlation with short network interruptions and laravel horizon going into error flooding mode. We will observe this further today, and can still not explain why short network interruptions should cause this kind of behaviour.

I'll update with more information as soon as we have more test results.

[driesvints]

It seems your database.php file is out of date. Here's the current one: https://github.com/laravel/laravel/blob/master/config/database.php#L120-L145

Also: since this is the first time we've heard of an issue with this with the phpredis driver I suspect there is probably indeed a hiccup somewhere on your end. Feel free to add any more thoughts to the issue but I'm gonna close this one for now.

[HSPDev]

We just hit this issue too.

All 3 servers on DigitalOcean, perfect timing, began in unison. We use a hosted Redis 5 instance from DigitalOcean.

See here: https://i.imgur.com/LufPjnt.png

I can still run cache()->set() and see the data on other servers with ->get().
I can also still manually push jobs to the queue. Horizon dashboard even works and shows all the jobs.

I just can't get Horizon:work, to work. We get errors like:
NOAUTH Authentication required.

On the command

'horizon:work' redis --delay=0 --memory=128 --queue=default --sleep=3 --timeout=600 --tries=1 --supervisor='redacted-web-3-hUUK:supervisor-1'

Full trace sample:

RedisException: NOAUTH Authentication required.
#28 /vendor/laravel/framework/src/Illuminate/Redis/Connections/Connection.php(116): Redis::eval
#27 /vendor/laravel/framework/src/Illuminate/Redis/Connections/Connection.php(116): Illuminate\Redis\Connections\Connection::command
#26 /vendor/laravel/framework/src/Illuminate/Redis/Connections/PhpRedisConnection.php(504): Illuminate\Redis\Connections\PhpRedisConnection::command
#25 /vendor/laravel/framework/src/Illuminate/Redis/Connections/PhpRedisConnection.php(423): Illuminate\Redis\Connections\PhpRedisConnection::eval
#24 /vendor/laravel/framework/src/Illuminate/Queue/RedisQueue.php(208): Illuminate\Queue\RedisQueue::migrateExpiredJobs
#23 /vendor/laravel/horizon/src/RedisQueue.php(108): Laravel\Horizon\RedisQueue::migrateExpiredJobs
#22 /vendor/laravel/framework/src/Illuminate/Queue/RedisQueue.php(191): Illuminate\Queue\RedisQueue::migrate
#21 /vendor/laravel/framework/src/Illuminate/Queue/RedisQueue.php(167): Illuminate\Queue\RedisQueue::pop
#20 /vendor/laravel/horizon/src/RedisQueue.php(92): Laravel\Horizon\RedisQueue::pop
#19 /vendor/laravel/framework/src/Illuminate/Queue/Worker.php(284): Illuminate\Queue\Worker::getNextJob
#18 /vendor/laravel/framework/src/Illuminate/Queue/Worker.php(123): Illuminate\Queue\Worker::daemon
#17 /vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(112): Illuminate\Queue\Console\WorkCommand::runWorker
#16 /vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(96): Illuminate\Queue\Console\WorkCommand::handle
#15 /vendor/laravel/horizon/src/Console/WorkCommand.php(46): Laravel\Horizon\Console\WorkCommand::handle
#14 [internal](0): call_user_func_array
#13 /vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(32): Illuminate\Container\BoundMethod::Illuminate\Container\{closure}
#12 /vendor/laravel/framework/src/Illuminate/Container/Util.php(36): Illuminate\Container\Util::unwrapIfClosure
#11 /vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(90): Illuminate\Container\BoundMethod::callBoundMethod
#10 /vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(34): Illuminate\Container\BoundMethod::call
#9 /vendor/laravel/framework/src/Illuminate/Container/Container.php(590): Illuminate\Container\Container::call
#8 /vendor/laravel/framework/src/Illuminate/Console/Command.php(134): Illuminate\Console\Command::execute
#7 /vendor/symfony/console/Command/Command.php(255): Symfony\Component\Console\Command\Command::run
#6 /vendor/laravel/framework/src/Illuminate/Console/Command.php(121): Illuminate\Console\Command::run
#5 /vendor/symfony/console/Application.php(1001): Symfony\Component\Console\Application::doRunCommand
#4 /vendor/symfony/console/Application.php(271): Symfony\Component\Console\Application::doRun
#3 /vendor/symfony/console/Application.php(147): Symfony\Component\Console\Application::run
#2 /vendor/laravel/framework/src/Illuminate/Console/Application.php(93): Illuminate\Console\Application::run
#1 /vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php(131): Illuminate\Foundation\Console\Kernel::handle
#0 /artisan(35): null

There have been NO code changes, NO Deploys, NO config changes. I even checked out bash_history for other admins, login logs and other related stuff. Last deploy was 7 days ago.

Last reboot 20 days.

Uptime for Horizon master according to supervisor 7 days.

Scheduled Redis maintenance by DO, saturday.

We are running horizon using Supervisor on Ubuntu 16.04 / PHP 7.4.5
We are using the native PHPRedis driver after Laravel 7 upgrade, using the official php-redis ubuntu package.

[program:redacted-worker]
process_name=%(program_name)s_%(process_num)02d
command=/usr/bin/php7.4 /redacted-path/current/artisan horizon
autostart=true
autorestart=true
user=www-data
numprocs=1
redirect_stderr=false

[graemlourens]

@HSPDev please refer to #744 where this discussion was (extensively) continued.
Short summary: latest version of phpredis 5.2.2 seemingly solves the issue of NOAUTH error. Feel free to chip in in that thread if you're running the latest phpredis version and its still reproduceable for you.

[JulianMar]

just FYI, it's phpredis 5.2.2

[graemlourens]

just FYI, it's phpredis 5.2.2

thank you! fixed.