Error while reading line from the server

Managed to get hold of part of the stack trace with events prior to the exception when «MarkJobsAsMigrated» gets run

Have also seen the error following

• MarkJobAsReserved

{abs_path: "artisan"}
{function: "handle", abs_path: "vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php"}
{function: "run", abs_path: "vendor/laravel/framework/src/Illuminate/Console/Application.php"}
{function: "run", abs_path: "vendor/symfony/console/Application.php"}
{function: "doRun", abs_path: "vendor/symfony/console/Application.php"}
{function: "doRunCommand", abs_path: "vendor/symfony/console/Application.php"}
{function: "run", abs_path: "vendor/laravel/framework/src/Illuminate/Console/Command.php"}
{function: "run", abs_path: "vendor/symfony/console/Command/Command.php"}
{function: "execute", abs_path: "vendor/laravel/framework/src/Illuminate/Console/Command.php"}
{function: "call", abs_path: "vendor/laravel/framework/src/Illuminate/Container/Container.php"}
{function: "call", abs_path: "vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php"}
{function: "callBoundMethod", abs_path: "vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php"}
{function: "IlluminateContainer{closure}", abs_path: "vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php"}
{function: "call_user_func_array", abs_path: "vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php", vars: {…}, in_app: false, lineno: 0, …}
{function: "handle", abs_path: "vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php"}
{function: "runWorker", abs_path: "vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php"}
{function: "daemon", abs_path: "vendor/laravel/framework/src/Illuminate/Queue/Worker.php"}
{function: "getNextJob", abs_path: "vendor/laravel/framework/src/Illuminate/Queue/Worker.php"}
{function: "pop", abs_path: "vendor/laravel/horizon/src/RedisQueue.php"}
{function: "pop", abs_path: "vendor/laravel/framework/src/Illuminate/Queue/RedisQueue.php"}
{function: "migrate", abs_path: "vendor/laravel/framework/src/Illuminate/Queue/RedisQueue.php"}
{function: "migrateExpiredJobs", abs_path: "vendor/laravel/horizon/src/RedisQueue.php"}
{function: "tap", abs_path: "vendor/laravel/framework/src/Illuminate/Support/helpers.php"}
{function: "LaravelHorizon{closure}", abs_path: "vendor/laravel/horizon/src/RedisQueue.php"}
{function: "event", abs_path: "vendor/laravel/horizon/src/RedisQueue.php"}
{function: "dispatch", abs_path: "vendor/laravel/framework/src/Illuminate/Events/Dispatcher.php"}
{function: "IlluminateEvents{closure}", abs_path: "vendor/laravel/framework/src/Illuminate/Events/Dispatcher.php"}
{function: "call_user_func_array", abs_path: "vendor/laravel/horizon/src/Listeners/MarkJobsAsMigrated.php", vars: {…}, in_app: false, lineno: 0, …}
{function: "handle", abs_path: "vendor/laravel/horizon/src/Listeners/MarkJobsAsMigrated.php"}
{function: "migrated", abs_path: "vendor/laravel/horizon/src/Repositories/RedisJobRepository.php"}
{function: "__call", abs_path: "vendor/laravel/framework/src/Illuminate/Redis/Connections/Connection.php"}
{function: "command", abs_path: "vendor/laravel/framework/src/Illuminate/Redis/Connections/Connection.php"}
{function: "pipeline", abs_path: "vendor/predis/predis/src/Client.php"}
{function: "sharedContextFactory", abs_path: "vendor/predis/predis/src/Client.php"}
{function: "createPipeline", abs_path: "vendor/predis/predis/src/Client.php"}
{function: "execute", abs_path: "vendor/predis/predis/src/Pipeline/Pipeline.php"}
{function: "flushPipeline", abs_path: "vendor/predis/predis/src/Pipeline/Pipeline.php"}
{function: "executePipeline", abs_path: "vendor/predis/predis/src/Pipeline/Pipeline.php"}
{function: "readResponse", abs_path: "vendor/predis/predis/src/Connection/AbstractConnection.php"}
{function: "read", abs_path: "vendor/predis/predis/src/Connection/StreamConnection.php"}
{function: "onConnectionError", abs_path: "vendor/predis/predis/src/Connection/AbstractConnection.php"}

Redis queue : «Error while reading line from the server» #355

First I am not sure this is a lumen specific error or a Laravel error too.
I have an app running on laravel (5.1) which dispatch jobs, handled by a lumen (5.1) worker.

I have multiple jobs running totally fine, however, if a job runs more than 60 seconds (I made some tests 59.75727891922s -> no error, 60.091041898727s -> error), I get the following :

`[2016-02-05 02:27:07] lumen.ERROR: exception ‘PredisConnectionConnectionException’ with message ‘Error while reading line from the server. [tcp://127.0.0.1:6379]’ in /var/www/app/vendor/predis/predis/src/Connection/AbstractConnection.php:168
Stack trace:
#0 /var/www/app/vendor/predis/predis/src/Connection/StreamConnection.php(210): PredisConnectionAbstractConnection->onConnectionError(‘Error while rea. ‘)
#1 /var/www/app/vendor/predis/predis/src/Connection/AbstractConnection.php(133): PredisConnectionStreamConnection->read()
#2 /var/www/app/vendor/predis/predis/src/Connection/AbstractConnection.php(125): PredisConnectionAbstractConnection->readResponse(Object(PredisCommandZSetRemove))
#3 /var/www/app/vendor/predis/predis/src/Client.php(326): PredisConnectionAbstractConnection->executeCommand(Object(PredisCommandZSetRemove))
#4 /var/www/app/vendor/predis/predis/src/Client.php(310): PredisClient->executeCommand(Object(PredisCommandZSetRemove))
#5 /var/www/app/vendor/illuminate/queue/RedisQueue.php(154): PredisClient->__call(‘zrem’, Array)
#6 /var/www/app/vendor/illuminate/queue/RedisQueue.php(154): PredisClient->zrem(‘queues:processi. ‘, ‘ <«job»:»Illumin. ‘)
#7 /var/www/app/vendor/illuminate/queue/Jobs/RedisJob.php(73): IlluminateQueueRedisQueue->deleteReserved(‘processing’, ‘ <«job»:»Illumin. ‘)
#8 /var/www/app/vendor/illuminate/queue/CallQueuedHandler.php(46): IlluminateQueueJobsRedisJob->delete()
#9 /var/www/app/vendor/illuminate/queue/Jobs/Job.php(129): IlluminateQueueCallQueuedHandler->call(Object(IlluminateQueueJobsRedisJob), Array)
#10 /var/www/app/vendor/illuminate/queue/Jobs/RedisJob.php(51): IlluminateQueueJobsJob->resolveAndFire(Array)
#11 /var/www/app/vendor/illuminate/queue/Worker.php(208): IlluminateQueueJobsRedisJob->fire()
#12 /var/www/app/vendor/illuminate/queue/Worker.php(159): IlluminateQueueWorker->process(‘redis’, Object(IlluminateQueueJobsRedisJob), ‘3’, 0)
#13 /var/www/app/vendor/illuminate/queue/Worker.php(111): IlluminateQueueWorker->pop(NULL, ‘processing’, 0, ‘3’, ‘3’)
#14 /var/www/app/vendor/illuminate/queue/Worker.php(87): IlluminateQueueWorker->runNextJobForDaemon(NULL, ‘processing’, 0, ‘3’, ‘3’)
#15 /var/www/app/vendor/illuminate/queue/Console/WorkCommand.php(103): IlluminateQueueWorker->daemon(NULL, ‘processing’, 0, 128, ‘3’, ‘3’)
#16 /var/www/app/vendor/illuminate/queue/Console/WorkCommand.php(71): IlluminateQueueConsoleWorkCommand->runWorker(NULL, ‘processing’, 0, 128, true)
#17 [internal function]: IlluminateQueueConsoleWorkCommand->fire()
#18 /var/www/app/vendor/illuminate/container/Container.php(502): call_user_func_array(Array, Array)
#19 /var/www/app/vendor/illuminate/console/Command.php(150): IlluminateContainerContainer->call(Array)
#20 /var/www/app/vendor/symfony/console/Command/Command.php(259): IlluminateConsoleCommand->execute(Object(SymfonyComponentConsoleInputArgvInput), Object(SymfonyComponentConsoleOutputConsoleOutput))
#21 /var/www/app/vendor/illuminate/console/Command.php(136): SymfonyComponentConsoleCommandCommand->run(Object(SymfonyComponentConsoleInputArgvInput), Object(SymfonyComponentConsoleOutputConsoleOutput))
#22 /var/www/app/vendor/symfony/console/Application.php(878): IlluminateConsoleCommand->run(Object(SymfonyComponentConsoleInputArgvInput), Object(SymfonyComponentConsoleOutputConsoleOutput))
#23 /var/www/app/vendor/symfony/console/Application.php(195): SymfonyComponentConsoleApplication->doRunCommand(Object(IlluminateQueueConsoleWorkCommand), Object(SymfonyComponentConsoleInputArgvInput), Object(SymfonyComponentConsoleOutputConsoleOutput))
#24 /var/www/app/vendor/symfony/console/Application.php(126): SymfonyComponentConsoleApplication->doRun(Object(SymfonyComponentConsoleInputArgvInput), Object(SymfonyComponentConsoleOutputConsoleOutput))
#25 /var/www/app/vendor/laravel/lumen-framework/src/Console/Kernel.php(78): SymfonyComponentConsoleApplication->run(Object(SymfonyComponentConsoleInputArgvInput), Object(SymfonyComponentConsoleOutputConsoleOutput))
#26 /var/www/app/artisan(35): LaravelLumenConsoleKernel->handle(Object(SymfonyComponentConsoleInputArgvInput), Object(SymfonyComponentConsoleOutputConsoleOutput))
#27

I stumble upon this issue predis/predis#121 but that wasn’t that.

I have set an expire time of 120 seconds (laravel/framework#8577), tried to add the ‘read_write_timeout’ => -1 parameter (http://stackoverflow.com/questions/11776029/predis-is-giving-error-while-reading-line-from-server) in database.php but nothing works.

For the record, some of the jobs use PhpRedis (no persistent connection) so I don’t know if that may conflict with Predis (which seems not as all jobs running under 60s don’t trigger the error).

My worker config in supervisor is the following :
[program:queue_processing] command=php artisan queue:work —daemon —sleep=3 —queue=processing —tries=3 process_name=%(program_name)s_%(process_num)02d numprocs=4 autostart=true autorestart=true

Let me know if I can provide more infos.

The text was updated successfully, but these errors were encountered:

Источник

Error while reading line from the server #33

Using redis for php 5.2 branch. I’m getting random «Error while reading line from the server» error. The command i used is lpush a serialized string.

I’m using predis on a php daemon script, meaning it’s up all the time. I’ve already set the timeout for redis.conf to 0.

The text was updated successfully, but these errors were encountered:

Have you already followed the steps described here to debug your issue before opening a new issue with the very same title? See also this thread on the Redis list, it might also be something unrelated to client-side issues.

Thank you nrk. I will try setting the socket_timeout and read_write_timeout and report my findings here later.

If you are using Predis in a daemon-like script you should set read_write_timeout to -1 if you want to completely disable the timeout (this value works with older and newer versions of Predis). Also, remember that you must disable the default timeout of Redis by setting timeout = 0 in redis.conf or Redis will drop the connection of idle clients after 300 seconds of inactivity.

nrk, tried as mentioned and it’s now working perfectly. Thank you!

However, there’s still a lot of connection timeouts now and then. I’ve already set timeout = 0 and read_write_timeout to -1. Is there anything that we can do to debug this when it occurs?

timeout is not a connection parameter recognized by Predis, you should use connection_timeout instead. The default value for connection_timeout is 5 seconds, you could try to raise its value but I don’t think it’s a solution to your problem. You should try and see what’s going on on your server when those timeouts occurs, it really depends on your application so I can’t be of any help. The possible reasons for those timeouts could be:

1. network connectivity issues if your Redis server is not on the localhost
2. are you sure you are not using expensive calls to the KEYS command somewhere in you scripts? Depending on the number of keys store on Redis, KEYS can end up blocking the server which, in the meanwhile, it will not be able to process other requests or incoming connections.

I’ll leave this issue open for now, but I’m quite sure it’s definitely not something related to Predis.

nrk. As advised, I’ve raised connection_timeout to 30. Will be monitoring this.

1. Yes, we are using multiple redis nodes that are not localhost but they are on private network (so at least should be more stable?)
2. Not using KEYS. However, we are snapshotting every 900s. From the log it appears that the system is taking 8s to save to HD. Shouldn’t be the cause of the connection timeout right?
3. Any advise as to how to monitor the server when the timeout occurs? The timeout’s pretty random. I checked redis log, and mostly it’s just snapshotting messages.

Another update, I measured the connection, and it appears that indeed the exception occured after 5s. I tried modifying the connection_timeout via:

new Predis_Client($param, array(‘read_write_timeout’ => -1, ‘connection_timeout’ => 30));

Is that correct? It doesn’t seems to take effect the 30s connection_timeout and still throw exception.

They are connection parameters and not client options, so read_write_timeout and connection_timeout must be specified as parameters in $param .

1. Unless it’s not a private network on Amazon EC2 (high latency and various issues from time to time), then it shouldn’t.
2. Snapshotting shouldn’t block the server as far as I know
3. You can check the timings of the timeouts against the snapshotting logs. Other than that, it really depends on the architecture of your application and your infrastructure, sorry but I can’t give you support on that.

Honestly, Predis doesn’t do anything fancy with the socket resources when connecting to a host since it’s something delegated almost entirely to PHP’s internals, so it can be either a bug in PHP (unlikely, but still a possibility) or some configuration/runtime issue on your servers, or Redis doing some heavy operations that end up blocking the server for a while.

nrk, thank you again for your reply. I found the problem, and it’s just the server running out of ip_conntrack issue. Once the conntrack is fixed, the connection timeout goes away as well.

Nice to know that you have finally found the actual problem behind those timeouts. I will probably add this somewhere in the FAQ to give users an initial list of checks for troubleshooting timeout issues.

Источник

Error while reading line from the server

The application that I am building checks for idle reservations every 5 minutes, and deletes them. I am using redis as the queue set up. Redis is set up by default in forge, so I created a queue worker through the forge panel with the following config: n

n
• connection: redis n
• queue: default n
• timeout: 30 n
• processes: 2 n
• tries: any n
• daemon: yes n n

The error starts whenever I fire of a Notification that send an email as well as an SMS. The emails are always sent fine, even after the error appears in the logs, but the SMS part (NEXMO) never get delivered. And every 2-3 minutes the following error gets logged: n

Not a direct solution I think. But did you restart your queue worker when you made the change to read_write_timeout? n

Getting similar issues on Heroku when running multiple dynos.nSeems to error immediately after I dispatch a job to the queue or a few minutes after a job tries to process. n

I added the following code to log more information on these errors. n

# \App\Exceptions\Handler::reportnn if ($exception instanceof CommunicationException) <n $stream = $exception->getConnection()->getResource();n $errorMessage = var_export(stream_get_meta_data($stream), true);n \Log::error(«Redis connection exception», [n ‘metadata’ => $errorMessagen ]);n >n n

This looks like I’m blocked while trying to connect to read/write n

Error while reading line from the server. [tcp://redis.localhost:6379] {"exception":"[object] (Predis\Connection\ConnectionException(code: 0): Error while reading line from the server. [tcp://redis.localhost:6379] at /var/www/manage.localhost/vendor/predis/predis/src/Connection/AbstractConnection.php:155)

#0 /var/www/manage.localhost/vendor/predis/predis/src/Connection/StreamConnection.php(314): Predis\Connection\AbstractConnection->onConnectionError('Error while rea...')
#1 /var/www/manage.localhost/vendor/predis/predis/src/Connection/AbstractConnection.php(120): Predis\Connection\StreamConnection->read()
#2 /var/www/manage.localhost/vendor/predis/predis/src/Connection/AbstractConnection.php(112): Predis\Connection\AbstractConnection->readResponse(Object(Predis\Command\ListPopFirstBlocking))
#3 /var/www/manage.localhost/vendor/predis/predis/src/Client.php(331): Predis\Connection\AbstractConnection->executeCommand(Object(Predis\Command\ListPopFirstBlocking))
#4 /var/www/manage.localhost/vendor/predis/predis/src/Client.php(314): Predis\Client->executeCommand(Object(Predis\Command\ListPopFirstBlocking))
#5 /var/www/manage.localhost/vendor/laravel/framework/src/Illuminate/Redis/Connections/Connection.php(96): Predis\Client->__call('blpop', Array)
#6 /var/www/manage.localhost/vendor/laravel/framework/src/Illuminate/Redis/Connections/Connection.php(108): Illuminate\Redis\Connections\Connection->command('blpop', Array)
#7 /var/www/manage.localhost/vendor/laravel/framework/src/Illuminate/Queue/RedisQueue.php(230): Illuminate\Redis\Connections\Connection->__call('blpop', Array)
#8 /var/www/manage.localhost/vendor/laravel/framework/src/Illuminate/Queue/RedisQueue.php(213): Illuminate\Queue\RedisQueue->blockingPop('queues:events')
#9 /var/www/manage.localhost/vendor/laravel/framework/src/Illuminate/Queue/RedisQueue.php(165): Illuminate\Queue\RedisQueue->retrieveNextJob('queues:events')
#10 /var/www/manage.localhost/vendor/laravel/horizon/src/RedisQueue.php(92): Illuminate\Queue\RedisQueue->pop('events')
#11 /var/www/manage.localhost/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(246): Laravel\Horizon\RedisQueue->pop('events')
#12 /var/www/manage.localhost/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(107): Illuminate\Queue\Worker->getNextJob(Object(Laravel\Horizon\RedisQueue), 'events')
#13 /var/www/manage.localhost/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(101): Illuminate\Queue\Worker->daemon('website_manager', 'events', Object(Illuminate\Queue\WorkerOptions))
#14 /var/www/manage.localhost/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(85): Illuminate\Queue\Console\WorkCommand->runWorker('website_manager', 'events')
#15 [internal function]: Illuminate\Queue\Console\WorkCommand->handle()
#16 /var/www/manage.localhost/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(29): call_user_func_array(Array, Array)
#17 /var/www/manage.localhost/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(87): Illuminate\Container\BoundMethod::Illuminate\Container\{closure}()
#18 /var/www/manage.localhost/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(31): Illuminate\Container\BoundMethod::callBoundMethod(Object(Illuminate\Foundation\Application), Array, Object(Closure))
#19 /var/www/manage.localhost/vendor/laravel/framework/src/Illuminate/Container/Container.php(564): Illuminate\Container\BoundMethod::call(Object(Illuminate\Foundation\Application), Array, Array, NULL)
#20 /var/www/manage.localhost/vendor/laravel/framework/src/Illuminate/Console/Command.php(183): Illuminate\Container\Container->call(Array)
#21 /var/www/manage.localhost/vendor/symfony/console/Command/Command.php(252): Illuminate\Console\Command->execute(Object(Symfony\Component\Console\Input\ArgvInput), Object(Illuminate\Console\OutputStyle))
#22 /var/www/manage.localhost/vendor/laravel/framework/src/Illuminate/Console/Command.php(170): Symfony\Component\Console\Command\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Illuminate\Console\OutputStyle))
#23 /var/www/manage.localhost/vendor/symfony/console/Application.php(865): Illuminate\Console\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#24 /var/www/manage.localhost/vendor/symfony/console/Application.php(241): Symfony\Component\Console\Application->doRunCommand(Object(Laravel\Horizon\Console\WorkCommand), Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#25 /var/www/manage.localhost/vendor/symfony/console/Application.php(143): Symfony\Component\Console\Application->doRun(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#26 /var/www/manage.localhost/vendor/laravel/framework/src/Illuminate/Console/Application.php(88): Symfony\Component\Console\Application->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#27 /var/www/manage.localhost/vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php(121): Illuminate\Console\Application->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#28 /var/www/manage.localhost/artisan(35): Illuminate\Foundation\Console\Kernel->handle(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#29 {main}

Решение

'read_write_timeout' => 0,

Другие решения

Других решений пока нет …