Horizon: RuntimeException - Unable to write output.

[lasselehtinen]

• Horizon Version: 3.6.0
• Laravel Version: 6.14.0
• PHP Version: 7.4.2
• Redis Driver & Version: predis/phpredis 5.1.1
• Database Driver & Version: MySQL 8.0.17

Description:

We did an simultaneous upgrade from CentOS 7 to 8 and from PHP 7.3 to 7.4 and we started to get Symfony\Component\Console\Exception\RuntimeException - Unable to write output exceptions from the Horizon Supervisor. Sometimes restarting Horizon or rebooting the machine fixes the issue for a while. I have no idea what might be causing this.

Stacktrace:

Symfony\Component\Console\Exception\RuntimeException Unable to write output. 
    /var/www/projectname/releases/7/vendor/symfony/console/Output/StreamOutput.php:79 Symfony\Component\Console\Output\StreamOutput::doWrite
    /var/www/projectname/releases/7/vendor/symfony/console/Output/Output.php:166 Symfony\Component\Console\Output\Output::write
    /var/www/projectname/releases/7/vendor/symfony/console/Style/OutputStyle.php:56 Symfony\Component\Console\Style\OutputStyle::write
    /var/www/projectname/releases/7/vendor/symfony/console/Style/SymfonyStyle.php:395 Symfony\Component\Console\Style\SymfonyStyle::write
    /var/www/projectname/releases/7/vendor/laravel/horizon/src/Console/SupervisorCommand.php:83 Laravel\Horizon\Console\SupervisorCommand::Laravel\Horizon\Console\{closure}
    [internal] call_user_func
    /var/www/projectname/releases/7/vendor/laravel/horizon/src/Supervisor.php:471 Laravel\Horizon\Supervisor::output
    /var/www/projectname/releases/7/vendor/laravel/horizon/src/Supervisor.php:134 Laravel\Horizon\Supervisor::Laravel\Horizon\{closure}
    [internal] call_user_func
    /var/www/projectname/releases/7/vendor/laravel/horizon/src/ProcessPool.php:165 Laravel\Horizon\ProcessPool::Laravel\Horizon\{closure}
    /var/www/projectname/releases/7/vendor/symfony/process/Process.php:1328 Symfony\Component\Process\Process::Symfony\Component\Process\{closure}
    /var/www/projectname/releases/7/vendor/symfony/process/Process.php:1441 Symfony\Component\Process\Process::readPipes
    /var/www/projectname/releases/7/vendor/symfony/process/Process.php:1359 Symfony\Component\Process\Process::updateStatus
    /var/www/projectname/releases/7/vendor/symfony/process/Process.php:854 Symfony\Component\Process\Process::isRunning
    /var/www/projectname/releases/7/vendor/laravel/horizon/src/ProcessPool.php:297 Laravel\Horizon\ProcessPool::Laravel\Horizon\{closure}
    [internal] array_filter
    /var/www/projectname/releases/7/vendor/laravel/framework/src/Illuminate/Support/Arr.php:611 Illuminate\Support\Arr::where
    /var/www/projectname/releases/7/vendor/laravel/framework/src/Illuminate/Support/Collection.php:352 Illuminate\Support\Collection::filter
    /var/www/projectname/releases/7/vendor/laravel/horizon/src/ProcessPool.php:298 Laravel\Horizon\ProcessPool::runningProcesses
    /var/www/projectname/releases/7/vendor/laravel/framework/src/Illuminate/Support/HigherOrderCollectionProxy.php:60 Illuminate\Support\HigherOrderCollectionProxy::Illuminate\Support\{closure}
    [internal] array_map
    /var/www/projectname/releases/7/vendor/laravel/framework/src/Illuminate/Support/Collection.php:638 Illuminate\Support\Collection::map
    /var/www/projectname/releases/7/vendor/laravel/framework/src/Illuminate/Support/HigherOrderCollectionProxy.php:61 Illuminate\Support\HigherOrderCollectionProxy::__call
    /var/www/projectname/releases/7/vendor/laravel/horizon/src/Supervisor.php:232 Laravel\Horizon\Supervisor::terminate
    /var/www/projectname/releases/7/vendor/laravel/horizon/src/ListensForSignals.php:52 Laravel\Horizon\Supervisor::processPendingSignals
    /var/www/projectname/releases/7/vendor/laravel/horizon/src/Supervisor.php:292 Laravel\Horizon\Supervisor::loop
    /var/www/projectname/releases/7/vendor/laravel/horizon/src/Supervisor.php:267 Laravel\Horizon\Supervisor::monitor
    /var/www/projectname/releases/7/vendor/laravel/horizon/src/Console/SupervisorCommand.php:92 Laravel\Horizon\Console\SupervisorCommand::start
    /var/www/projectname/releases/7/vendor/laravel/horizon/src/Console/SupervisorCommand.php:67 Laravel\Horizon\Console\SupervisorCommand::handle
    [internal] call_user_func_array
    /var/www/projectname/releases/7/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php:32 Illuminate\Container\BoundMethod::Illuminate\Container\{closure}
    /var/www/projectname/releases/7/vendor/laravel/framework/src/Illuminate/Container/Util.php:36 Illuminate\Container\Util::unwrapIfClosure
    /var/www/projectname/releases/7/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php:90 Illuminate\Container\BoundMethod::callBoundMethod
    /var/www/projectname/releases/7/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php:34 Illuminate\Container\BoundMethod::call
    /var/www/projectname/releases/7/vendor/laravel/framework/src/Illuminate/Container/Container.php:590 Illuminate\Container\Container::call
    /var/www/projectname/releases/7/vendor/laravel/framework/src/Illuminate/Console/Command.php:173 Illuminate\Console\Command::execute
    /var/www/projectname/releases/7/vendor/symfony/console/Command/Command.php:255 Symfony\Component\Console\Command\Command::run
    /var/www/projectname/releases/7/vendor/laravel/framework/src/Illuminate/Console/Command.php:160 Illuminate\Console\Command::run
    /var/www/projectname/releases/7/vendor/symfony/console/Application.php:1012 Symfony\Component\Console\Application::doRunCommand
    /var/www/projectname/releases/7/vendor/symfony/console/Application.php:272 Symfony\Component\Console\Application::doRun
    /var/www/projectname/releases/7/vendor/symfony/console/Application.php:148 Symfony\Component\Console\Application::run
    /var/www/projectname/releases/7/vendor/laravel/framework/src/Illuminate/Console/Application.php:93 Illuminate\Console\Application::run
    /var/www/projectname/releases/7/vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php:131 Illuminate\Foundation\Console\Kernel::handle
    /var/www/projectname/releases/7/artisan:35 [main]

[driesvints]

I guess the below already happened when restarting the machine but just checking to be sure. Did you:

• Restart supervisor?
• Restart nginx?
• Restart php-fpm?

Did you upgrade Horizon as well? Did you republish the assets?

[lasselehtinen]

Hi,

I restarted the whole server this morning and I have not seen the error again since. So basically all those three were restarted. Horizon is now upgraded to v3.6.1 and I republished the assets just in case. But assets should not matter in this case, since the error is coming from the supervisor console output?

If this pops again, is there anything I can do provide additional information? Seems like the Horizon log does not have anything related to this, most likely because it is an exception and it is written in the normal Laravel log.

[driesvints]

Not that I know of. Definitely keep an eye out on log files like nginx, php-fpm, laravel log.

[lasselehtinen]

Anyone else having the same issue. In my case this was a case of free disk space being filled. The exception was different in Bugsnag than in the Laravel log which revealed the culprit.

[2020-02-13 18:34:43] production.ERROR: curl_exec(): write of 8192 bytes failed with errno=28 No space left on device {"exception":"[object] (ErrorException(code: 0): curl_exec(): write of 8192 bytes failed with errno=28 No space left o$
[stacktrace]

[robtesch]

Hi guys, I am experiencing the same issue intermittently. Seems to have only started in the last couple of days.

Horizon Version: 4.0.1
Laravel Version: 7.1.0
PHP Version: 7.4.3
Redis Driver & Version: predis 1.1.1 (i think?)
Database Driver & Version: MySQL 8.0.15

[robtesch]

Hi there guys, this is happening more and more frequently on my side and I am really having trouble figuring out exactly why. I've included a stack trace below if that helps at all.

[2020-03-16 15:34:59] production.ERROR: Unable to write output. {"exception":"[object] (Symfony\\Component\\Console\\Exception\\RuntimeException(code: 0): Unable to write output. at /home/forge/portal.myimportantlaravelapp.com/vendor/symfony/console/Output/StreamOutput.php:79)
[stacktrace]
#0 /home/forge/portal.myimportantlaravelapp.com/vendor/symfony/console/Output/Output.php(166): Symfony\\Component\\Console\\Output\\StreamOutput->doWrite()
#1 /home/forge/portal.myimportantlaravelapp.com/vendor/symfony/console/Output/Output.php(132): Symfony\\Component\\Console\\Output\\Output->write()
#2 /home/forge/portal.myimportantlaravelapp.com/vendor/symfony/console/Style/OutputStyle.php(62): Symfony\\Component\\Console\\Output\\Output->writeln()
#3 /home/forge/portal.myimportantlaravelapp.com/vendor/symfony/console/Style/SymfonyStyle.php(375): Symfony\\Component\\Console\\Style\\OutputStyle->writeln()
#4 /home/forge/portal.myimportantlaravelapp.com/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(186): Symfony\\Component\\Console\\Style\\SymfonyStyle->writeln()
#5 /home/forge/portal.myimportantlaravelapp.com/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(166): Illuminate\\Queue\\Console\\WorkCommand->writeStatus()
#6 /home/forge/portal.myimportantlaravelapp.com/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(143): Illuminate\\Queue\\Console\\WorkCommand->writeOutput()
#7 /home/forge/portal.myimportantlaravelapp.com/vendor/laravel/framework/src/Illuminate/Events/Dispatcher.php(369): Illuminate\\Queue\\Console\\WorkCommand->Illuminate\\Queue\\Console\\{closure}()
#8 /home/forge/portal.myimportantlaravelapp.com/vendor/laravel/framework/src/Illuminate/Events/Dispatcher.php(218): Illuminate\\Events\\Dispatcher->Illuminate\\Events\\{closure}()
#9 /home/forge/portal.myimportantlaravelapp.com/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(524): Illuminate\\Events\\Dispatcher->dispatch()
#10 /home/forge/portal.myimportantlaravelapp.com/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(358): Illuminate\\Queue\\Worker->raiseAfterJobEvent()
#11 /home/forge/portal.myimportantlaravelapp.com/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(306): Illuminate\\Queue\\Worker->process()
#12 /home/forge/portal.myimportantlaravelapp.com/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(132): Illuminate\\Queue\\Worker->runJob()
#13 /home/forge/portal.myimportantlaravelapp.com/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(112): Illuminate\\Queue\\Worker->daemon()
#14 /home/forge/portal.myimportantlaravelapp.com/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(96): Illuminate\\Queue\\Console\\WorkCommand->runWorker()
#15 /home/forge/portal.myimportantlaravelapp.com/vendor/laravel/horizon/src/Console/WorkCommand.php(46): Illuminate\\Queue\\Console\\WorkCommand->handle()
#16 [internal function]: Laravel\\Horizon\\Console\\WorkCommand->handle()
#17 /home/forge/portal.myimportantlaravelapp.com/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(32): call_user_func_array()
#18 /home/forge/portal.myimportantlaravelapp.com/vendor/laravel/framework/src/Illuminate/Container/Util.php(36): Illuminate\\Container\\BoundMethod::Illuminate\\Container\\{closure}()
#19 /home/forge/portal.myimportantlaravelapp.com/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(90): Illuminate\\Container\\Util::unwrapIfClosure()
#20 /home/forge/portal.myimportantlaravelapp.com/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(34): Illuminate\\Container\\BoundMethod::callBoundMethod()
#21 /home/forge/portal.myimportantlaravelapp.com/vendor/laravel/framework/src/Illuminate/Container/Container.php(590): Illuminate\\Container\\BoundMethod::call()
#22 /home/forge/portal.myimportantlaravelapp.com/vendor/laravel/framework/src/Illuminate/Console/Command.php(134): Illuminate\\Container\\Container->call()
#23 /home/forge/portal.myimportantlaravelapp.com/vendor/symfony/console/Command/Command.php(255): Illuminate\\Console\\Command->execute()
#24 /home/forge/portal.myimportantlaravelapp.com/vendor/laravel/framework/src/Illuminate/Console/Command.php(121): Symfony\\Component\\Console\\Command\\Command->run()
#25 /home/forge/portal.myimportantlaravelapp.com/vendor/symfony/console/Application.php(912): Illuminate\\Console\\Command->run()
#26 /home/forge/portal.myimportantlaravelapp.com/vendor/symfony/console/Application.php(264): Symfony\\Component\\Console\\Application->doRunCommand()
#27 /home/forge/portal.myimportantlaravelapp.com/vendor/symfony/console/Application.php(140): Symfony\\Component\\Console\\Application->doRun()
#28 /home/forge/portal.myimportantlaravelapp.com/vendor/laravel/framework/src/Illuminate/Console/Application.php(93): Symfony\\Component\\Console\\Application->run()
#29 /home/forge/portal.myimportantlaravelapp.com/vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php(130): Illuminate\\Console\\Application->run()
#30 /home/forge/portal.myimportantlaravelapp.com/artisan(37): Illuminate\\Foundation\\Console\\Kernel->handle()
#31 {main}

[metallurgical]

Yup, happening frequently on my side as well,, not able to figure the root cause at the moment

[robtesch]

My latest theory is that it happens if you manually throw an exception from a queued job, but I am busy adding some more logging to confirm this.

[lasselehtinen]

@robtesch You might be onto something. The jobs that create this error do indeed have manually thrown exceptions in them.

[robtesch]

@robtesch You might be onto something. The jobs that create this error do indeed have manually thrown exceptions in them.

Well, @lasselehtinen that theory is out the window now unfortunately as i've just got the same error happening on a simple notification class with no manual exception throwing. The new theory is, it's simply whenever there's any kind of exception within a queued job. It's quite frustrating because the actual exception itself is hidden, and we only get to see the "Unable to write output" exception.

For what it's worth, I have investigated the case of free disk space being filled, and that is certainly not the case here. System has plenty of disk space, ram, cpu etc available (consistently running at or below 50% usage for all above).

[mfn]

I've had this recently happening too, still on Laravel 6 with Horizon 3. But it was the first time this happen (twice in a short time frame):

Symfony\Component\Console\Exception\RuntimeException: Unable to write output.
#32 /vendor/symfony/console/Output/StreamOutput.php(79): Symfony\Component\Console\Output\StreamOutput::doWrite
#31 /vendor/symfony/console/Output/Output.php(166): Symfony\Component\Console\Output\Output::write
#30 /vendor/symfony/console/Output/Output.php(132): Symfony\Component\Console\Output\Output::writeln
#29 /vendor/symfony/console/Style/OutputStyle.php(64): Symfony\Component\Console\Style\OutputStyle::writeln
#28 /vendor/symfony/console/Style/SymfonyStyle.php(380): Symfony\Component\Console\Style\SymfonyStyle::writeln
#27 /vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(186): Illuminate\Queue\Console\WorkCommand::writeStatus
#26 /vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(166): Illuminate\Queue\Console\WorkCommand::writeOutput
#25 /vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(143): Illuminate\Queue\Console\WorkCommand::Illuminate\Queue\Console\{closure}
#24 /vendor/laravel/framework/src/Illuminate/Events/Dispatcher.php(369): Illuminate\Events\Dispatcher::Illuminate\Events\{closure}
#23 /vendor/laravel/framework/src/Illuminate/Events/Dispatcher.php(218): Illuminate\Events\Dispatcher::dispatch
#22 /vendor/fntneves/laravel-transactional-events/src/Neves/Events/TransactionalDispatcher.php(114): Neves\Events\TransactionalDispatcher::dispatch
#21 /vendor/laravel/framework/src/Illuminate/Queue/Worker.php(509): Illuminate\Queue\Worker::raiseAfterJobEvent
#20 /vendor/laravel/framework/src/Illuminate/Queue/Worker.php(370): Illuminate\Queue\Worker::process
#19 /vendor/laravel/framework/src/Illuminate/Queue/Worker.php(314): Illuminate\Queue\Worker::runJob
#18 /vendor/laravel/framework/src/Illuminate/Queue/Worker.php(134): 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(37): null

For all I know, the job in question successfully finished but it's parent supervisor _was not_ present anymore.

So in my case this is a "one time thing" and I didn't further pursue it.

[JacobBennett]

I'm having the same issue. Running Laravel 7.0 on PHP 7.4

Happening for both my Scheduler and my Queue Listener. Super odd. I restart them, and it will work for a while no problem. A day or so passes, and it's back to failing again. No idea what could be causing this but will post back if I figure anything out.

[driesvints]

I'll reopen but appreciating any help with this.

[taylorotwell]

Has anyone reported this to Symfony?

[JacobBennett]

Yeah, I honestly have no solid solution to this, just happened to run across this. I'll say that I am running on an IIS server for this particular one, so I'm not positive its not somehow caused by the environment it's running in. Just found it odd that others were having this same odd issue.

[JacobBennett]

I have not reported to Symfony no, it is at the end of the day a Symfony component that is failing to write so would make sense. I can throw something over on their side of things though.

[driesvints]

@JacobBennett (and anyone else on this thread): Nicolas Grekas asked me if you could try with different symfony/console versions to see if the problem was introduced in a specific version. He also said that opening up an issue on the Symfony repo is the best choice. Especially given the comment below at the exception that triggers it:

I'll leave this open to follow up.

[driesvints]

Nicolas also said that if a PHP Notice is triggered it would be nice to see what happens there (see the @ in that code snippet).

[robtesch]

@taylorotwell since nobody else appears to have done so yet, i've now submitted this one to Symfony.

[JacobBennett]

Hey @driesvints I could try doing different console versions but the problem is that it never fails immediately, only after running for a period of time. I have alerts set up to message me as soon as it happens though so will see what we get.

I think I might just remove that @ on that line and see if that uncovers anything for me. Great idea!

Also, full disclosure, our business is pivoting along with the rest of the globe to make sure we can handle all the challenges being introduced during this COVID-19 pandemic. This issue for me, while annoying, has a rather simple solution for the time being which is to restart my workers. It's likely I may not be able to prioritize this in the current week but I will get back to this as I can.

[driesvints]

Someone noted on the Symfony issue that the problem is with the latest PHP 7.4 release. So I'm going to close this as it has nothing to do with Horizon itself. Best to follow up on either the Symfony or PHP issue report.

https://github.com/symfony/symfony/issues/36166#issuecomment-602503225

[JacobBennett]

Thanks @driesvints

[JacobBennett]

Looks like a fix is in the works https://github.com/symfony/symfony/pull/36222

[lasselehtinen]

For those following this issue, the fix for this was released on following Symfony releases. So running composer update should update symfony/process.

Release v3.4.39
Release v4.4.7
Release v5.0.7