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

Database queue driver doesn't reconnect #15179

Closed
carlosvini opened this issue Aug 31, 2016 · 28 comments
Closed

Database queue driver doesn't reconnect #15179

carlosvini opened this issue Aug 31, 2016 · 28 comments

Comments

@carlosvini
Copy link

Hi,

The database queue driver doesn't seem to reconnect to the DB after losing connection.
Although I am able to work around this issue it's a big gotcha for other users of the queue daemon with similar settings.
Normal DB operations already have a tryAgainIfCausedByLostConnection method so the same logic could be used for this case: https://github.com/laravel/framework/blob/5.2/src/Illuminate/Database/Connection.php#L691

System:

Laravel: 5.2.45
PHP: 7.0.10
Mac: OS X 10.11.6

Steps to reproduce:

  • Start queue daemon:
QUEUE_DRIVER=database php artisan queue:work --daemon --quiet --sleep=1
  • Restart MySQL:
brew services stop mysql  # or "service mysql stop" on Ubuntu
sleep 10
brew services start mysql # or "service mysql start" on Ubuntu

Stack trace

PDOException: SQLSTATE[HY000]: General error: 2006 MySQL server has gone away in /Users/example/vendor/laravel/framework/src/Illuminate/Database/Connection.php:584
Stack trace:
#0 /Users/example/vendor/laravel/framework/src/Illuminate/Database/Connection.php(584): PDO->exec('SAVEPOINT trans...')
#1 /Users/example/vendor/laravel/framework/src/Illuminate/Queue/DatabaseQueue.php(162): Illuminate\Database\Connection->beginTransaction()
#2 /Users/example/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(180): Illuminate\Queue\DatabaseQueue->pop()
#3 /Users/example/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(149): Illuminate\Queue\Worker->getNextJob(Object(Illuminate\Queue\DatabaseQueue), NULL)
#4 /Users/example/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(111): Illuminate\Queue\Worker->pop(NULL, NULL, 0, '1', 0)
#5 /Users/example/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(85): Illuminate\Queue\Worker->runNextJobForDaemon(NULL, NULL, 0, '1', 0)
#6 /Users/example/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(119): Illuminate\Queue\Worker->daemon(NULL, NULL, 0, 128, '1', 0)
#7 /Users/example/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(78): Illuminate\Queue\Console\WorkCommand->runWorker(NULL, NULL, 0, 128, true)
#8 [internal function]: Illuminate\Queue\Console\WorkCommand->fire()
#9 /Users/example/vendor/laravel/framework/src/Illuminate/Container/Container.php(507): call_user_func_array(Array, Array)
#10 /Users/example/vendor/laravel/framework/src/Illuminate/Console/Command.php(169): Illuminate\Container\Container->call(Array)
#11 /Users/example/vendor/symfony/console/Command/Command.php(256): Illuminate\Console\Command->execute(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#12 /Users/example/vendor/laravel/framework/src/Illuminate/Console/Command.php(155): Symfony\Component\Console\Command\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#13 /Users/example/vendor/symfony/console/Application.php(791): Illuminate\Console\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#14 /Users/example/vendor/symfony/console/Application.php(186): Symfony\Component\Console\Application->doRunCommand(Object(Illuminate\Queue\Console\WorkCommand), Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#15 /Users/example/vendor/symfony/console/Application.php(117): Symfony\Component\Console\Application->doRun(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#16 /Users/example/vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php(107): Symfony\Component\Console\Application->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#17 /Users/example/artisan(35): Illuminate\Foundation\Console\Kernel->handle(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#18 {main}  
@GrahamCampbell
Copy link
Member

We should automatically reconnect for such errors.

@GrahamCampbell
Copy link
Member

Hmm, seems we only do that for query executions, not acquiring transactions. Ping @taylorotwell.

@vaidas-lungis
Copy link

vaidas-lungis commented Sep 6, 2016

@jp7carlos

Although I am able to work around this issue

Can you provide a work around? :)

@yajra
Copy link
Contributor

yajra commented Sep 6, 2016

+1 to get notified on this thread. Might be connected on an issue in my package yajra/laravel-oci8#191. Thanks!

@sp0tteh
Copy link
Contributor

sp0tteh commented Sep 9, 2016

Seem to be encountering the same issue on 5.2 on PHP 7

The queues work for a day, then failed and sit in reserved. Seems It's also trying to log into the failed jobs table but that is also failing.

[2016-09-09 14:59:04] local.ERROR: Symfony\Component\Debug\Exception\FatalThrowableError: Call to a member function prepare() on null in /var/www/api/build-369/vendor/laravel/framework/src/Illuminate/Database/Connection.php:453
Stack trace:
#0 /var/www/api/build-369/vendor/laravel/framework/src/Illuminate/Database/Connection.php(718): Illuminate\Database\Connection->Illuminate\Database\{closure}(Object(ThermoView\Database\Connections\MysqlConnection), 'insert into `fa...', Array)
#1 /var/www/api/build-369/vendor/laravel/framework/src/Illuminate/Database/Connection.php(681): Illuminate\Database\Connection->runQueryCallback('insert into `fa...', Array, Object(Closure))
#2 /var/www/api/build-369/vendor/laravel/framework/src/Illuminate/Database/Connection.php(454): Illuminate\Database\Connection->run('insert into `fa...', Array, Object(Closure))
#3 /var/www/api/build-369/vendor/laravel/framework/src/Illuminate/Database/Connection.php(410): Illuminate\Database\Connection->statement('insert into `fa...', Array)
#4 /var/www/api/build-369/vendor/laravel/framework/src/Illuminate/Database/Query/Processors/Processor.php(32): Illuminate\Database\Connection->insert('insert into `fa...', Array)
#5 /var/www/api/build-369/vendor/laravel/framework/src/Illuminate/Database/Query/Builder.php(2055): Illuminate\Database\Query\Processors\Processor->processInsertGetId(Object(Illuminate\Database\Query\Builder), 'insert into `fa...', Array, NULL)
#6 /var/www/api/build-369/vendor/laravel/framework/src/Illuminate/Queue/Failed/DatabaseFailedJobProvider.php(58): Illuminate\Database\Query\Builder->insertGetId(Array)
#7 /var/www/api/build-369/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(313): Illuminate\Queue\Failed\DatabaseFailedJobProvider->log('beanstalkd', 'default', '{"job":"Illumin...')
#8 /var/www/api/build-369/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(204): Illuminate\Queue\Worker->logFailedJob('beanstalkd', Object(Illuminate\Queue\Jobs\BeanstalkdJob))
#9 /var/www/api/build-369/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(156): Illuminate\Queue\Worker->process('beanstalkd', Object(Illuminate\Queue\Jobs\BeanstalkdJob), '2', 0)
#10 /var/www/api/build-369/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(111): Illuminate\Queue\Worker->pop(NULL, NULL, 0, '3', '2')
#11 /var/www/api/build-369/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(85): Illuminate\Queue\Worker->runNextJobForDaemon(NULL, NULL, 0, '3', '2')
#12 /var/www/api/build-369/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(119): Illuminate\Queue\Worker->daemon(NULL, NULL, 0, 128, '3', '2')
#13 /var/www/api/build-369/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(78): Illuminate\Queue\Console\WorkCommand->runWorker(NULL, NULL, 0, 128, true)
#14 [internal function]: Illuminate\Queue\Console\WorkCommand->fire()
#15 /var/www/api/build-369/vendor/laravel/framework/src/Illuminate/Container/Container.php(507): call_user_func_array(Array, Array)
#16 /var/www/api/build-369/vendor/laravel/framework/src/Illuminate/Console/Command.php(169): Illuminate\Container\Container->call(Array)
#17 /var/www/api/build-369/vendor/symfony/console/Command/Command.php(256): Illuminate\Console\Command->execute(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#18 /var/www/api/build-369/vendor/laravel/framework/src/Illuminate/Console/Command.php(155): Symfony\Component\Console\Command\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#19 /var/www/api/build-369/vendor/symfony/console/Application.php(794): Illuminate\Console\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#20 /var/www/api/build-369/vendor/symfony/console/Application.php(186): Symfony\Component\Console\Application->doRunCommand(Object(Illuminate\Queue\Console\WorkCommand), Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#21 /var/www/api/build-369/vendor/symfony/console/Application.php(117): Symfony\Component\Console\Application->doRun(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#22 /var/www/api/build-369/vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php(107): Symfony\Component\Console\Application->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#23 /var/www/api/build-369/artisan(35): Illuminate\Foundation\Console\Kernel->handle(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#24 {main}  
'

https://github.com/laravel/framework/blob/v5.2.40/src/Illuminate/Database/Connection.php#L453

pdo here returns null

@sisve
Copy link
Contributor

sisve commented Sep 11, 2016

@vaidas-lungis The workaround is probably to not use --daemon

@carlosvini
Copy link
Author

carlosvini commented Sep 12, 2016

@vaidas-lungis Workarounds are ugly

  • calling die() when you get a PDOException inside the worker
  • manually restarting the worker when you receive too many errors on your monitoring tool
  • Not using --daemon, or restarting the worker every X minutes

If you have knowledge/time just fork laravel, fix this and send a PR

@vaidas-lungis
Copy link

Yea I used second option.
listen command will use more CPU as it loops work command?

@sisve
Copy link
Contributor

sisve commented Sep 13, 2016

@vaidas-lungis Probably. My personal opinion is that the daemon mode is an abomination. Php is meant to die. The daemon mode introduces complex scenarios where you need to handle dead database connections, memory limits and garbage collection, and other nasty things regarding long running php scripts. All these need to be handled. Basically, it adds complexity to save some cpu.

The queue documentation has removed any mentions of the daemon workers in 5.3, and the supervisor configuration example no longer contains --daemon. I do not know if this was an oversight, or intentional.

There’s several issues that just make PHP the wrong tool for this. Remember, PHP will die, no matter how hard you try. First and foremost, there’s the issue of memory leaks. PHP never cared to free memory once it’s not used anymore, because everything will be freed at the end – by dying. In a continually-running process, that will slowly keep increasing the allocated memory (which is, in fact, wasted memory), until reaching PHP’s memory_limit value and killing your process without a warning. You did nothing wrong, except expecting the process to live forever. Under load, replace the “slowly” part for “pretty quickly”.


But more importantly, keeping a program running forever was never PHP’s top priority, that’s why problems like the above one weren’t never really solved.

Source: https://software-gunslinger.tumblr.com/post/47131406821/php-is-meant-to-die

@nhowell
Copy link
Contributor

nhowell commented Sep 14, 2016

Hmm, seems we only do that for query executions, not acquiring transactions.

This might be what's causing my queue problems.

@nhowell
Copy link
Contributor

nhowell commented Sep 15, 2016

I have supervisor set up to run php artisan queue:work --tries=3 and I'm seeing this error in my laravel.log every 3 seconds (implicit --sleep=3). This is preventing my queued jobs from running.

[2016-09-15 09:30:12] ERROR: exception 'ErrorException' with message 'Error while sending QUERY packet. PID=12902' in /example/vendor/laravel/framework/src/Illuminate/Database/Connection.php:610
Stack trace:
#0 [internal function]: Illuminate\Foundation\Bootstrap\HandleExceptions->handleError(2, 'Error while sen...', '/example/...', 610, Array)
#1 /example/vendor/laravel/framework/src/Illuminate/Database/Connection.php(610): PDO->beginTransaction()
#2 /example/vendor/laravel/framework/src/Illuminate/Queue/DatabaseQueue.php(175): Illuminate\Database\Connection->beginTransaction()
#3 /example/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(184): Illuminate\Queue\DatabaseQueue->pop('default')
#4 /example/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(155): Illuminate\Queue\Worker->getNextJob(Object(Illuminate\Queue\DatabaseQueue), 'default')
...

Is the cause that beginTransaction() is not checking if it needs to reconnect() first?

If it helps, I can run php artisan queue:work --once to manually process a job without any issue. Also, I'm running Laravel 5.3.8 and using MySQL.

@zhouyixiang
Copy link

zhouyixiang commented Sep 25, 2016

I'm running Laravel 5.3.9 with MySQL, and have the same issue as @nhowell . I'm also running several Laravel 5.1 projects, but none of them has such issue so far. Below is the stack trace.

[2016-09-25 10:56:41] .ERROR: ErrorException: Error while sending QUERY packet. PID=22891 in /example/vendor/laravel/framework/src/Illuminate/Database/Connection.php:608
Stack trace:
#0 [internal function]: Illuminate\Foundation\Bootstrap\HandleExceptions->handleError(2, 'Error while sen...', '/var/www/vhosts...', 608, Array)
#1 /example/vendor/laravel/framework/src/Illuminate/Database/Connection.php(608): PDO->beginTransaction()
#2 /example/vendor/laravel/framework/src/Illuminate/Queue/DatabaseQueue.php(175): Illuminate\Database\Connection->beginTransaction()
#3 /example/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(184): Illuminate\Queue\DatabaseQueue->pop('user')
#4 /example/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(154): Illuminate\Queue\Worker->getNextJob(Object(Illuminate\Queue\DatabaseQueue), 'user')
#5 /example/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(112): Illuminate\Queue\Worker->runNextJob('database', 'user', Object(Illuminate\Queue\WorkerOptions))
#6 /example/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(74): Illuminate\Queue\Worker->runNextJobForDaemon('database', 'user', Object(Illuminate\Queue\WorkerOptions))
#7 /example/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(97): Illuminate\Queue\Worker->daemon('database', 'user', Object(Illuminate\Queue\WorkerOptions))
#8 /example/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(78): Illuminate\Queue\Console\WorkCommand->runWorker('database', 'user')
#9 [internal function]: Illuminate\Queue\Console\WorkCommand->fire()
#10 /example/vendor/laravel/framework/src/Illuminate/Container/Container.php(507): call_user_func_array(Array, Array)
#11 /example/vendor/laravel/framework/src/Illuminate/Console/Command.php(169): Illuminate\Container\Container->call(Array)
#12 /example/vendor/symfony/console/Command/Command.php(256): Illuminate\Console\Command->execute(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#13 /example/vendor/laravel/framework/src/Illuminate/Console/Command.php(155): Symfony\Component\Console\Command\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#14 /example/vendor/symfony/console/Application.php(818): Illuminate\Console\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#15 /example/vendor/symfony/console/Application.php(186): Symfony\Component\Console\Application->doRunCommand(Object(Illuminate\Queue\Console\WorkCommand), Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#16 /example/vendor/symfony/console/Application.php(117): Symfony\Component\Console\Application->doRun(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#17 /example/vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php(122): Symfony\Component\Console\Application->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#18 /example/artisan(35): Illuminate\Foundation\Console\Kernel->handle(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#19 {main}

@themsaid
Copy link
Member

This issue should be fixed by #15511, please ping me if it's not.

@pun-ky
Copy link

pun-ky commented Oct 29, 2016

@zhouyixiang I am running L 5.3.10 / MySQL 5.7.16-0ubuntu0.16.04.1, app is connecting without problems but when I run CLI php artisan queue:work I am getting same error, strange :/ any idea to fix?

@nhowell
Copy link
Contributor

nhowell commented Oct 29, 2016

@pun-ky Updating to at least Laravel v5.3.19 should fix it.

@iget-esoares
Copy link
Contributor

@themsaid

I still having this issue on Laravel 5.2. I'm running Queue Daemon using DB Queue driver, monitored by Supervisord.

I'm just having 500 error messages like this everyday on my log:
PDOException: SQLSTATE[HY000]: General error: 2006 MySQL server has gone away in /home/cdt/www/[dont-care]/releases/20161207205655/vendor/laravel/framework/src/Illuminate/Database/Connection.php:584 Stack trace: #0 /home/cdt/www/[dont-care]/releases/20161207205655/vendor/laravel/framework/src/Illuminate/Database/Connection.php(584): PDO->exec('SAVEPOINT trans...') #1 /home/cdt/www/[dont-care]/releases/20161207205655/vendor/laravel/framework/src/Illuminate/Queue/DatabaseQueue.php(162): Illuminate\Database\Connection->beginTransaction() #2

@nhowell
Copy link
Contributor

nhowell commented Dec 8, 2016

I still having this issue on Laravel 5.2

@iget-esoares There's your problem ;)

Laravel 5.2 does not have the #15511 fix.

@iget-esoares
Copy link
Contributor

@nhowell Do you know if this will be fixed on L5.2? If so I can do a PR.

@sisve
Copy link
Contributor

sisve commented Dec 8, 2016

Laravel 5.2 is no longer supported. Can you upgrade to Laravel 5.3?

@iget-esoares
Copy link
Contributor

@sisve, Yes I can, but it will take a few days to migrate and test since this is an old project that doesn't use unit testing. :(

@themsaid
Copy link
Member

themsaid commented Dec 8, 2016

@iget-esoares I'm afraid you'll need to upgrade :)

@njovin
Copy link

njovin commented Mar 8, 2017

@themsaid Is the fix going to be rolled into the LTS version of Laravel 5.1?

@sisve
Copy link
Contributor

sisve commented Mar 8, 2017

@njovin The mentioned pull request is already targetting 5.1.

@dusansalaj
Copy link

dusansalaj commented Apr 6, 2017

I am runnig Laravl 5.3.31 and I have the same problem with queue DB driver and connection lost. Shoul it by fixed in 5.3.18? Or where can I find the fix?

@dennisoderwald
Copy link

dennisoderwald commented Apr 24, 2017

@dusansalaj - same here, you find a solution? We use the latest version.

@iget-master
Copy link

@themsaid The issue still happening on 5.3.31 on some situations.

Yesterday I've finally upgraded from 5.2 to 5.3 just to get this bug solved.
Before this upgrade, running the daemon always causes the "MYSQL has gone away" error after the connection timeout.

Now, the error don't occour anymore on timeout, BUT, if I restart the mysql server, it cause infinite "MYSQL has gone away" again.

@iget-master
Copy link

@themsaid @GrahamCampbell Please take a look here

    public function beginTransaction()
    {
        if ($this->transactions == 0) {
            try {
                $this->getPdo()->beginTransaction();
            } catch (Exception $e) {
                if ($this->causedByLostConnection($e)) {
                    $this->reconnect();
                    $this->pdo->beginTransaction();
                } else {
                    throw $e;
                }
            }
        } elseif ($this->transactions >= 1 && $this->queryGrammar->supportsSavepoints()) {
            $this->getPdo()->exec(
                $this->queryGrammar->compileSavepoint('trans'.($this->transactions + 1))
            );
        }

        ++$this->transactions;

        $this->fireConnectionEvent('beganTransaction');
    }

Note that the connection fail will only be caught if transactions count is zero.
My logs point the error to the line 623 (the exec inside the elseif condition).

Since there's not a try-catch block here, the lost connections won't be detected and the Queue Woker will throw infinite errors on the log but will not reconnect.

@jaimyborgman
Copy link

jaimyborgman commented Aug 7, 2019

I know that its been a long time that this discussion had its last reply; we currently have the same issue and trying to investigate whats wrong... below i'll explain what we've seen so far.

With the following setup (forge provisioned on DO):
PHP (7.2.19)
MySQL (5.7.27)
laravel/framework (v5.8.4)
doctrine/orm (v2.6.3)
sentry/sentry (1.10.0)
sentry/sentry-laravel (0.8.1)

Only visible while dispatching through the horizon queue worker; like already said by other people it's not seen in horizon as an failed job but that's probably because of the architect of the queuing system itself. When failing (throwing an exception) laravel horizon will try the job again. What will happen on the background is as follows:

Currently a fresh setup; no open connections to the database (no sleeps) except for the "show processlist" command via CLI:

mysql> show processlist; +----+-------+-----------+------+---------+------+----------+------------------+ | Id | User | Host | db | Command | Time | State | Info | +----+-------+-----------+------+---------+------+----------+------------------+ | 47 | forge | localhost | NULL | Query | 0 | starting | show processlist | +----+-------+-----------+------+---------+------+----------+------------------+ 1 row in set (0.00 sec)

also Sentry is empty and no errors are logged yet. Then while running a background tasks via the CLI which simply checks the database for any expired invite tokens to be removed the issue occurs.

Inside Sentry the exception SQLSTATE[HY000]: General error: 2006 MySQL server has gone away has been received and if we check the processlist we see the following:

mysql> show processlist; +-----+-------+-----------------+-------+---------+------+----------+------------------+ | Id | User | Host | db | Command | Time | State | Info | +-----+-------+-----------------+-------+---------+------+----------+------------------+ | 47 | forge | localhost | NULL | Query | 0 | starting | show processlist | | 604 | forge | localhost:40066 | forge | Sleep | 69 | | NULL | +-----+-------+-----------------+-------+---------+------+----------+------------------+ 2 rows in set (0.00 sec)

So a new connection with PID 604 has been made and is idling right now... so when running the same script again we don't get an error in Sentry anymore since the system is using the same PID and refreshed the idling time as followed:

mysql> show processlist; +-----+-------+-----------------+-------+---------+------+----------+------------------+ | Id | User | Host | db | Command | Time | State | Info | +-----+-------+-----------------+-------+---------+------+----------+------------------+ | 47 | forge | localhost | NULL | Query | 0 | starting | show processlist | | 652 | forge | localhost:40426 | forge | Sleep | 11 | | NULL | +-----+-------+-----------------+-------+---------+------+----------+------------------+ 2 rows in set (0.00 sec)

So for what i can see is that when there is no current active or idling thread in mysql (also if you kill it on purpose) the issue occurs. Of course horizon is passing because of the second try, at that moment there is an active connection been made which is idling).

But if you kill it or don't have an connection available it will occur again... I saw some people talking about the framework which should reconnect if that happens but in my opinion we are never getting at that point in the code... or at least it looks like that... the exception has been thrown and is obvious being logged by Sentry and catched by horizon to retry again... so the framework wasn't involved at this moment. Also if this is an wider issue we should see it while connecting to the db in general via the framework but it only happens while queueing jobs and mostly when they are triggered by and CLI command inside Laravel.

Maybe this help a little further in finding a solution for this issue... but it looks like that either the framework/horizon or mysql is remembering somehow the PID number from a last alive connection (which has expired in the meantime) or booting mysql connections from queued workers isn't working correctly...

Either way i'll hope we can solve this issue some day.

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

No branches or pull requests