search

laravel / horizon

Dashboard and code-driven configuration for Laravel queues.
https://laravel.com/docs/horizon
MIT License
3.83k stars 643 forks source link

php artisan horizon process does not die on redis failure #1385

Closed cyppe closed 6 months ago

cyppe commented 6 months ago

Horizon Version

5.22.1

Laravel Version

10.43.0

PHP Version

8.3.2

Redis Driver

PhpRedis

Redis Version

6.0.2

Database Driver & Version

No response

Description

I noticed that the php artisan horizon process does not die when redis fails. So it's left in a semi-running state when it looks like it's still working. But in fact the master supervisor is stuck so it does not create any new workers etc.

Stacktrace from logs when it happens is attached further down in this issue.

I would prefer that the exception makes the process die so supervisor or other type of service can restart the process.

I am open for other suggestions too if it's not something maintainers want to change. Maybe it's possible to extend some method/exception to force it to fail?

Just to be clear - my redis is back again but mastersupervisor is still dead/stuck.

But status commands show like if it still works:

root@generate-horizon-deployment-56cf977969-hkmnl:/app# php artisan  horizon:list
+---------------------------------------------------+-----+--------------------------------------------------------+---------+
| Name                                              | PID | Supervisors                                            | Status  |
+---------------------------------------------------+-----+--------------------------------------------------------+---------+
| generate-horizon-deployment-56cf977969-hkmnl-cSvu | 1   | supervisor-1, supervisor-2, supervisor-3, supervisor-4 | running |
+---------------------------------------------------+-----+--------------------------------------------------------+---------+

root@generate-horizon-deployment-56cf977969-hkmnl:/app# php artisan horizon:status
Horizon is running.

root@generate-horizon-deployment-56cf977969-hkmnl:/app# php artisan horizon:supervisors
+----------------------------------------------------------------+-----+---------+-----------------------------------------------+-----------+
| Name                                                           | PID | Status  | Workers                                       | Balancing |
+----------------------------------------------------------------+-----+---------+-----------------------------------------------+-----------+
| generate-horizon-deployment-56cf977969-hkmnl-cSvu:supervisor-4 | 18  | running | redis:generate (1)                            | auto      |
| generate-horizon-deployment-56cf977969-hkmnl-cSvu:supervisor-3 | 17  | running | redis:database_events (1)                     | auto      |
| generate-horizon-deployment-56cf977969-hkmnl-cSvu:supervisor-2 | 16  | running | redis-long-running:generate-esales-import (1) | auto      |
| generate-horizon-deployment-56cf977969-hkmnl-cSvu:supervisor-1 | 15  | running | redis:default (1)                             | auto      |
+----------------------------------------------------------------+-----+---------+-----------------------------------------------+-----------+

Processes running:


root@generate-horizon-deployment-56cf977969-hkmnl:/app# ps aux
USER         PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root           1  0.0  0.7 259736 62356 ?        Ss   19:59   0:04 php /app/artisan horizon -vvv
root          15  0.0  0.7 259736 62320 ?        SN   19:59   0:04 /usr/bin/php8.3 artisan horizon:supervisor generate-horizon-deployment-56cf977969-hkmnl-cSvu:supervisor-1 redis --workers-name=default --balance=auto -
root          16  0.0  0.7 259736 63096 ?        SN   19:59   0:04 /usr/bin/php8.3 artisan horizon:supervisor generate-horizon-deployment-56cf977969-hkmnl-cSvu:supervisor-2 redis-long-running --workers-name=default --b
root          17  0.0  0.7 259736 63072 ?        SN   19:59   0:04 /usr/bin/php8.3 artisan horizon:supervisor generate-horizon-deployment-56cf977969-hkmnl-cSvu:supervisor-3 redis --workers-name=default --balance=auto -
root          18  0.0  0.7 259736 62280 ?        SN   19:59   0:04 /usr/bin/php8.3 artisan horizon:supervisor generate-horizon-deployment-56cf977969-hkmnl-cSvu:supervisor-4 redis --workers-name=default --balance=auto -
root         873  0.0  0.7 257688 61840 ?        SN   21:14   0:00 /usr/bin/php8.3 artisan horizon:work redis --name=default --supervisor=generate-horizon-deployment-56cf977969-hkmnl-cSvu:supervisor-4 --backoff=0 --max
root         874  0.0  0.7 257688 62048 ?        SN   21:14   0:00 /usr/bin/php8.3 artisan horizon:work redis --name=default --supervisor=generate-horizon-deployment-56cf977969-hkmnl-cSvu:supervisor-1 --backoff=0 --max
root         883  0.0  0.7 257688 61912 ?        SN   21:14   0:00 /usr/bin/php8.3 artisan horizon:work redis --name=default --supervisor=generate-horizon-deployment-56cf977969-hkmnl-cSvu:supervisor-3 --backoff=0 --max
root         893  0.0  0.0   8032  4240 pts/0    Ss+  21:27   0:00 /bin/bash
root         904  0.0  0.0   8028  4240 pts/1    Ss   21:30   0:00 /bin/bash
root        1321  7.4  4.4 559728 364192 ?       SN   21:37   1:05 /usr/bin/php8.3 artisan horizon:work redis-long-running --name=default --supervisor=generate-horizon-deployment-56cf977969-hkmnl-cSvu:supervisor-2 --ba
root        1343  0.0  0.0  10468  3408 pts/1    R+   21:51   0:00 ps aux

But workers do not process any jobs.

Here is logs and stacktrace, where you can see the final jobs it processed before Redis went away and it became stuck.

 2024-02-10 22:06:14 App\Jobs\ImportProductsToRedisJob cd029588-172a-4eef-b1bb-1aa99aa1f250  RUNNING
  2024-02-10 22:06:14 App\Jobs\ImportProductsToRedisJob bfebeec5-407a-443b-bd69-3603c5fce19e  3s DONE
  2024-02-10 22:06:14 App\Jobs\ImportProductsToRedisJob 862c30d5-041b-4702-9ff0-2ef551bc1ae0  RUNNING
[2024-02-10 22:06:27] docker.ERROR: read error on connection to generate-keydb-service:6379 {"exception":"[object] (RedisException(code: 0): read error on connection to generate-keydb-service:6379 at /app/vendor/laravel/framework/src/Illuminate/Redis/Connections/Connection.php:116)
[stacktrace]
#0 /app/vendor/laravel/framework/src/Illuminate/Redis/Connections/Connection.php(116): Redis->lLen()
#1 /app/vendor/laravel/framework/src/Illuminate/Redis/Connections/PhpRedisConnection.php(531): Illuminate\\Redis\\Connections\\Connection->command()
#2 /app/vendor/laravel/framework/src/Illuminate/Redis/Connections/Connection.php(229): Illuminate\\Redis\\Connections\\PhpRedisConnection->command()
#3 /app/vendor/laravel/framework/src/Illuminate/Redis/Connections/PhpRedisConnection.php(564): Illuminate\\Redis\\Connections\\Connection->__call()
#4 /app/vendor/laravel/horizon/src/RedisHorizonCommandQueue.php(52): Illuminate\\Redis\\Connections\\PhpRedisConnection->__call()
#5 /app/vendor/laravel/horizon/src/MasterSupervisor.php(271): Laravel\\Horizon\\RedisHorizonCommandQueue->pending()
#6 /app/vendor/laravel/horizon/src/MasterSupervisor.php(250): Laravel\\Horizon\\MasterSupervisor->processPendingCommands()
#7 /app/vendor/laravel/horizon/src/MasterSupervisor.php(222): Laravel\\Horizon\\MasterSupervisor->loop()
#8 /app/vendor/laravel/horizon/src/Console/HorizonCommand.php(56): Laravel\\Horizon\\MasterSupervisor->monitor()
#9 /app/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(36): Laravel\\Horizon\\Console\\HorizonCommand->handle()
#10 /app/vendor/laravel/framework/src/Illuminate/Container/Util.php(41): Illuminate\\Container\\BoundMethod::Illuminate\\Container\\{closure}()
#11 /app/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(93): Illuminate\\Container\\Util::unwrapIfClosure()
#12 /app/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(35): Illuminate\\Container\\BoundMethod::callBoundMethod()
#13 /app/vendor/laravel/framework/src/Illuminate/Container/Container.php(662): Illuminate\\Container\\BoundMethod::call()
#14 /app/vendor/laravel/framework/src/Illuminate/Console/Command.php(211): Illuminate\\Container\\Container->call()
#15 /app/vendor/symfony/console/Command/Command.php(326): Illuminate\\Console\\Command->execute()
#16 /app/vendor/laravel/framework/src/Illuminate/Console/Command.php(180): Symfony\\Component\\Console\\Command\\Command->run()
#17 /app/vendor/symfony/console/Application.php(1096): Illuminate\\Console\\Command->run()
#18 /app/vendor/symfony/console/Application.php(324): Symfony\\Component\\Console\\Application->doRunCommand()
#19 /app/vendor/symfony/console/Application.php(175): Symfony\\Component\\Console\\Application->doRun()
#20 /app/vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php(201): Symfony\\Component\\Console\\Application->run()
#21 /app/artisan(35): Illuminate\\Foundation\\Console\\Kernel->handle()
#22 {main}
"} 
[2024-02-10 22:06:27] docker.ERROR: read error on connection to generate-keydb-service:6379 {"exception":"[object] (RedisException(code: 0): read error on connection to generate-keydb-service:6379 at /app/vendor/laravel/framework/src/Illuminate/Redis/Connections/Connection.php:116)
[stacktrace]
#0 /app/vendor/laravel/framework/src/Illuminate/Redis/Connections/Connection.php(116): Redis->lLen()
#1 /app/vendor/laravel/framework/src/Illuminate/Redis/Connections/PhpRedisConnection.php(531): Illuminate\\Redis\\Connections\\Connection->command()
#2 /app/vendor/laravel/framework/src/Illuminate/Redis/Connections/Connection.php(229): Illuminate\\Redis\\Connections\\PhpRedisConnection->command()
#3 /app/vendor/laravel/framework/src/Illuminate/Redis/Connections/PhpRedisConnection.php(564): Illuminate\\Redis\\Connections\\Connection->__call()
#4 /app/vendor/laravel/horizon/src/RedisHorizonCommandQueue.php(52): Illuminate\\Redis\\Connections\\PhpRedisConnection->__call()
#5 /app/vendor/laravel/horizon/src/Supervisor.php(331): Laravel\\Horizon\\RedisHorizonCommandQueue->pending()
#6 /app/vendor/laravel/horizon/src/Supervisor.php(290): Laravel\\Horizon\\Supervisor->processPendingCommands()
#7 /app/vendor/laravel/horizon/src/Supervisor.php(260): Laravel\\Horizon\\Supervisor->loop()
#8 /app/vendor/laravel/horizon/src/Console/SupervisorCommand.php(101): Laravel\\Horizon\\Supervisor->monitor()
#9 /app/vendor/laravel/horizon/src/Console/SupervisorCommand.php(76): Laravel\\Horizon\\Console\\SupervisorCommand->start()
#10 /app/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(36): Laravel\\Horizon\\Console\\SupervisorCommand->handle()
#11 /app/vendor/laravel/framework/src/Illuminate/Container/Util.php(41): Illuminate\\Container\\BoundMethod::Illuminate\\Container\\{closure}()
#12 /app/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(93): Illuminate\\Container\\Util::unwrapIfClosure()
#13 /app/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(35): Illuminate\\Container\\BoundMethod::callBoundMethod()
#14 /app/vendor/laravel/framework/src/Illuminate/Container/Container.php(662): Illuminate\\Container\\BoundMethod::call()
#15 /app/vendor/laravel/framework/src/Illuminate/Console/Command.php(211): Illuminate\\Container\\Container->call()
#16 /app/vendor/symfony/console/Command/Command.php(326): Illuminate\\Console\\Command->execute()
#17 /app/vendor/laravel/framework/src/Illuminate/Console/Command.php(180): Symfony\\Component\\Console\\Command\\Command->run()
#18 /app/vendor/symfony/console/Application.php(1096): Illuminate\\Console\\Command->run()
#19 /app/vendor/symfony/console/Application.php(324): Symfony\\Component\\Console\\Application->doRunCommand()
#20 /app/vendor/symfony/console/Application.php(175): Symfony\\Component\\Console\\Application->doRun()
#21 /app/vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php(201): Symfony\\Component\\Console\\Application->run()
#22 /app/artisan(35): Illuminate\\Foundation\\Console\\Kernel->handle()
#23 {main}
"} 
[2024-02-10 22:06:27] docker.ERROR: read error on connection to generate-keydb-service:6379 {"exception":"[object] (RedisException(code: 0): read error on connection to generate-keydb-service:6379 at /app/vendor/laravel/framework/src/Illuminate/Redis/Connections/Connection.php:116)
[stacktrace]
#0 /app/vendor/laravel/framework/src/Illuminate/Redis/Connections/Connection.php(116): Redis->get()
#1 /app/vendor/laravel/framework/src/Illuminate/Redis/Connections/PhpRedisConnection.php(531): Illuminate\\Redis\\Connections\\Connection->command()
#2 /app/vendor/laravel/framework/src/Illuminate/Redis/Connections/PhpRedisConnection.php(54): Illuminate\\Redis\\Connections\\PhpRedisConnection->command()
#3 /app/vendor/laravel/framework/src/Illuminate/Cache/RedisStore.php(65): Illuminate\\Redis\\Connections\\PhpRedisConnection->get()
#4 /app/vendor/laravel/framework/src/Illuminate/Cache/Repository.php(99): Illuminate\\Cache\\RedisStore->get()
#5 /app/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(705): Illuminate\\Cache\\Repository->get()
#6 /app/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(694): Illuminate\\Queue\\Worker->getTimestampOfLastQueueRestart()
#7 /app/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(307): Illuminate\\Queue\\Worker->queueShouldRestart()
#8 /app/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(192): Illuminate\\Queue\\Worker->stopIfNecessary()
#9 /app/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(137): Illuminate\\Queue\\Worker->daemon()
#10 /app/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(120): Illuminate\\Queue\\Console\\WorkCommand->runWorker()
#11 /app/vendor/laravel/horizon/src/Console/WorkCommand.php(51): Illuminate\\Queue\\Console\\WorkCommand->handle()
#12 /app/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(36): Laravel\\Horizon\\Console\\WorkCommand->handle()
#13 /app/vendor/laravel/framework/src/Illuminate/Container/Util.php(41): Illuminate\\Container\\BoundMethod::Illuminate\\Container\\{closure}()
#14 /app/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(93): Illuminate\\Container\\Util::unwrapIfClosure()
#15 /app/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(35): Illuminate\\Container\\BoundMethod::callBoundMethod()
#16 /app/vendor/laravel/framework/src/Illuminate/Container/Container.php(662): Illuminate\\Container\\BoundMethod::call()
#17 /app/vendor/laravel/framework/src/Illuminate/Console/Command.php(211): Illuminate\\Container\\Container->call()
#18 /app/vendor/symfony/console/Command/Command.php(326): Illuminate\\Console\\Command->execute()
#19 /app/vendor/laravel/framework/src/Illuminate/Console/Command.php(180): Symfony\\Component\\Console\\Command\\Command->run()
#20 /app/vendor/symfony/console/Application.php(1096): Illuminate\\Console\\Command->run()
#21 /app/vendor/symfony/console/Application.php(324): Symfony\\Component\\Console\\Application->doRunCommand()
#22 /app/vendor/symfony/console/Application.php(175): Symfony\\Component\\Console\\Application->doRun()
#23 /app/vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php(201): Symfony\\Component\\Console\\Application->run()
#24 /app/artisan(35): Illuminate\\Foundation\\Console\\Kernel->handle()
#25 {main}
"} 

In Connection.php line 116:

  [RedisException]                                         
  read error on connection to generate-keydb-service:6379  

Exception trace:
  at /app/vendor/laravel/framework/src/Illuminate/Redis/Connections/Connection.php:116
 Redis->get() at /app/vendor/laravel/framework/src/Illuminate/Redis/Connections/Connection.php:116
 Illuminate\Redis\Connections\Connection->command() at /app/vendor/laravel/framework/src/Illuminate/Redis/Connections/PhpRedisConnection.php:531
 Illuminate\Redis\Connections\PhpRedisConnection->command() at /app/vendor/laravel/framework/src/Illuminate/Redis/Connections/PhpRedisConnection.php:54
 Illuminate\Redis\Connections\PhpRedisConnection->get() at /app/vendor/laravel/framework/src/Illuminate/Cache/RedisStore.php:65
 Illuminate\Cache\RedisStore->get() at /app/vendor/laravel/framework/src/Illuminate/Cache/Repository.php:99
 Illuminate\Cache\Repository->get() at /app/vendor/laravel/framework/src/Illuminate/Queue/Worker.php:705
 Illuminate\Queue\Worker->getTimestampOfLastQueueRestart() at /app/vendor/laravel/framework/src/Illuminate/Queue/Worker.php:694
 Illuminate\Queue\Worker->queueShouldRestart() at /app/vendor/laravel/framework/src/Illuminate/Queue/Worker.php:307
 Illuminate\Queue\Worker->stopIfNecessary() at /app/vendor/laravel/framework/src/Illuminate/Queue/Worker.php:192
 Illuminate\Queue\Worker->daemon() at /app/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php:137
 Illuminate\Queue\Console\WorkCommand->runWorker() at /app/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php:120
 Illuminate\Queue\Console\WorkCommand->handle() at /app/vendor/laravel/horizon/src/Console/WorkCommand.php:51
 Laravel\Horizon\Console\WorkCommand->handle() at /app/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php:36
 Illuminate\Container\BoundMethod::Illuminate\Container\{closure}() at /app/vendor/laravel/framework/src/Illuminate/Container/Util.php:41
 Illuminate\Container\Util::unwrapIfClosure() at /app/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php:93
 Illuminate\Container\BoundMethod::callBoundMethod() at /app/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php:35
 Illuminate\Container\BoundMethod::call() at /app/vendor/laravel/framework/src/Illuminate/Container/Container.php:662
 Illuminate\Container\Container->call() at /app/vendor/laravel/framework/src/Illuminate/Console/Command.php:211
 Illuminate\Console\Command->execute() at /app/vendor/symfony/console/Command/Command.php:326
 Symfony\Component\Console\Command\Command->run() at /app/vendor/laravel/framework/src/Illuminate/Console/Command.php:180
 Illuminate\Console\Command->run() at /app/vendor/symfony/console/Application.php:1096
 Symfony\Component\Console\Application->doRunCommand() at /app/vendor/symfony/console/Application.php:324
 Symfony\Component\Console\Application->doRun() at /app/vendor/symfony/console/Application.php:175
 Symfony\Component\Console\Application->run() at /app/vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php:201
 Illuminate\Foundation\Console\Kernel->handle() at /app/artisan:35

Steps To Reproduce

  1. Start horizon with php artisan horizon

  2. Process some jobs

  3. Kill redis server

driesvints commented 6 months ago

Hi there. Right now we're not planning on any major changes here. You're always free to send in a PR so we can look at the code involved 👍