Uncaught SQS Exception when symfony/messenger worker stopped
Hi there.
I'm using symfony/messenger with SQS transport configuration; async-aws/sqs 1.7.0
I have two recurring uncaught exceptions from SQS Connection.
I'm not sure, but I think the problem is coming from aws/async, not symfony/messenger.
Every ~3600 sec, symfony messenger worker is stopped because of time-limit option and is restarted automatically by supervisord.
When worker is stopping (I guess), SQS throw one of the two following uncaught exceptions.
After reading #1218, I tried to increase polling_timeout from default (0.1) to 0.5. I'll keep you informed.
Here the issue on symfony project
thrown in /home/ec2-user/acme/vendor/async-aws/sqs/src/Result/ReceiveMessageResult.php on line 33
#7 {main}
#6 [internal function]: Symfony\Component\Messenger\Bridge\AmazonSqs\Transport\Connection->__destruct()
#5 /home/ec2-user/acme/vendor/symfony/amazon-sqs-messenger/Transport/Connection.php(82): Symfony\Component\Messenger\Bridge\AmazonSqs\Transport\Connection->reset()
#4 /home/ec2-user/acme/vendor/symfony/amazon-sqs-messenger/Transport/Connection.php(371): Symfony\Component\Messenger\Bridge\AmazonSqs\Transport\Connection->fetchMessage()
#3 /home/ec2-user/acme/vendor/symfony/amazon-sqs-messenger/Transport/Connection.php(236): AsyncAws\Sqs\Result\ReceiveMessageResult->getMessages()
#2 /home/ec2-user/acme/vendor/async-aws/sqs/src/Result/ReceiveMessageResult.php(26): AsyncAws\Core\Result->initialize()
#1 /home/ec2-user/acme/vendor/async-aws/core/src/Result.php(133): AsyncAws\Sqs\Result\ReceiveMessageResult->populateResult(Object(AsyncAws\Core\Response))
#0 /home/ec2-user/acme/vendor/async-aws/sqs/src/Result/ReceiveMessageResult.php(33): SimpleXMLElement->__construct('')
Stack trace:
PHP Fatal error: Uncaught Exception: String could not be parsed as XML in /home/ec2-user/acme/vendor/async-aws/sqs/src/Result/ReceiveMessageResult.php:33
thrown in /home/ec2-user/acme/vendor/symfony/http-client/Response/AsyncResponse.php on line 287
#8 {main}
#7 [internal function]: Symfony\Component\Messenger\Bridge\AmazonSqs\Transport\Connection->__destruct()
#6 /home/ec2-user/acme/vendor/symfony/amazon-sqs-messenger/Transport/Connection.php(82): Symfony\Component\Messenger\Bridge\AmazonSqs\Transport\Connection->reset()
#5 /home/ec2-user/acme/vendor/symfony/amazon-sqs-messenger/Transport/Connection.php(371): Symfony\Component\Messenger\Bridge\AmazonSqs\Transport\Connection->fetchMessage()
#4 /home/ec2-user/acme/vendor/symfony/amazon-sqs-messenger/Transport/Connection.php(232): AsyncAws\Core\Result->resolve(0.1)
#3 /home/ec2-user/acme/vendor/async-aws/core/src/Result.php(63): AsyncAws\Core\Response->resolve(0.1)
#2 /home/ec2-user/acme/vendor/async-aws/core/src/Response.php(143): Symfony\Component\HttpClient\Response\ResponseStream->rewind()
#1 /home/ec2-user/acme/vendor/symfony/http-client/Response/ResponseStream.php(47): Generator->rewind()
#0 [internal function]: Symfony\Component\HttpClient\Response\AsyncResponse::stream(Array, 0.1, '...')
Stack trace:
PHP Fatal error: Uncaught LogicException: Instance of "Symfony\Component\HttpClient\Response\CurlResponse" is already consumed and cannot be managed by "Symfony\Component\HttpClient\RetryableHttpClient". A decorat
ed client should not call any of the response's methods in its "request()" method. in /home/ec2-user/acme/vendor/symfony/http-client/Response/AsyncResponse.php:287
polling_timeout have been increased from 0.1 to 0.5, no impact on error frequency.
Same issue here:
// The worker will automatically exit once it has processed 9 messages, been running for 15s or received a stop signal
// via the messenger:stop-workers command.
// Quit the worker with CONTROL-C.
// Re-run the command with a -vv option to see logs about consumed messages.
PHP Fatal error: Uncaught LogicException: Instance of "Symfony\Component\HttpClient\Response\CurlResponse" is already consumed and cannot be managed by "Symfony\Component\HttpClient\Response\AsyncResponse". A decorated client should not call any of the response's methods in its "request()" method. in /var/www/html/vendor/symfony/http-client/Response/AsyncResponse.php:284
Stack trace:
#0 /var/www/html/vendor/symfony/http-client/Response/AsyncResponse.php(66): Symfony\Component\HttpClient\Response\AsyncResponse::stream(Array, -0.0)
#1 /var/www/html/vendor/symfony/http-client/Response/CommonResponseTrait.php(142): Symfony\Component\HttpClient\Response\AsyncResponse::Symfony\Component\HttpClient\Response\{closure}(Object(Symfony\Component\HttpClient\Response\AsyncResponse), -0.0)
#2 /var/www/html/vendor/symfony/http-client/Response/AsyncResponse.php(96): Symfony\Component\HttpClient\Response\AsyncResponse::initialize(Object(Symfony\Component\HttpClient\Response\AsyncResponse))
#3 /var/www/html/vendor/async-aws/core/src/Response.php(141): Symfony\Component\HttpClient\Response\AsyncResponse->getStatusCode()
#4 /var/www/html/vendor/async-aws/core/src/Response.php(118): AsyncAws\Core\Response->resolve()
#5 [internal function]: AsyncAws\Core\Response->__destruct()
#6 {main}
thrown in /var/www/html/vendor/symfony/http-client/Response/AsyncResponse.php on line 284
Fatal error: Uncaught LogicException: Instance of "Symfony\Component\HttpClient\Response\CurlResponse" is already consumed and cannot be managed by "Symfony\Component\HttpClient\Response\AsyncResponse". A decorated client should not call any of the response's methods in its "request()" method. in /var/www/html/vendor/symfony/http-client/Response/AsyncResponse.php:284
Stack trace:
#0 /var/www/html/vendor/symfony/http-client/Response/AsyncResponse.php(66): Symfony\Component\HttpClient\Response\AsyncResponse::stream(Array, -0.0)
#1 /var/www/html/vendor/symfony/http-client/Response/CommonResponseTrait.php(142): Symfony\Component\HttpClient\Response\AsyncResponse::Symfony\Component\HttpClient\Response\{closure}(Object(Symfony\Component\HttpClient\Response\AsyncResponse), -0.0)
#2 /var/www/html/vendor/symfony/http-client/Response/AsyncResponse.php(96): Symfony\Component\HttpClient\Response\AsyncResponse::initialize(Object(Symfony\Component\HttpClient\Response\AsyncResponse))
#3 /var/www/html/vendor/async-aws/core/src/Response.php(141): Symfony\Component\HttpClient\Response\AsyncResponse->getStatusCode()
#4 /var/www/html/vendor/async-aws/core/src/Response.php(118): AsyncAws\Core\Response->resolve()
#5 [internal function]: AsyncAws\Core\Response->__destruct()
#6 {main}
thrown in /var/www/html/vendor/symfony/http-client/Response/AsyncResponse.php on line 284
Using symfony/amazon-sqs-messenger 6.3.0 and async-aws/sqs 1.7.0
I switched from FIFO to Standard SQS Queue. Problem disappeared.
Anything changed at this matter? The issue persists:
2024-03-12 16:23:25,185 INFO success: messenger-consume-async_commands_00 entered RUNNING state, process has stayed up for > than 3 seconds (startsecs)
2024-03-12T16:23:34.292735048Z 16:23:34 INFO [messenger] Stopping worker. ["transport_names" => ["async_commands"]]
2024-03-12T16:23:34.292753423Z 16:23:34 INFO [messenger] Worker stopped due to time limit of 10s exceeded ["timeLimit" => 10]
2024-03-12T16:23:35.682432174Z
2024-03-12T16:23:35.682844132Z In AsyncResponse.php line 286:
2024-03-12T16:23:35.682855674Z
2024-03-12T16:23:35.682858299Z [LogicException]
2024-03-12T16:23:35.682860007Z Instance of "Symfony\Component\HttpClient\Response\CurlResponse" is already
2024-03-12T16:23:35.682861591Z consumed and cannot be managed by "Symfony\Component\HttpClient\RetryableH
2024-03-12T16:23:35.682863132Z ttpClient". A decorated client should not call any of the response's method
2024-03-12T16:23:35.682864591Z s in its "request()" method.
2024-03-12T16:23:35.682866132Z
2024-03-12T16:23:35.682868049Z
2024-03-12T16:23:35.682869341Z Exception trace:
2024-03-12T16:23:35.682871091Z at /srv/app/vendor/symfony/http-client/Response/AsyncResponse.php:286
2024-03-12T16:23:35.682872549Z Symfony\Component\HttpClient\Response\AsyncResponse::stream() at n/a:n/a
2024-03-12T16:23:35.682874924Z Generator->rewind() at /srv/app/vendor/symfony/http-client/Response/ResponseStream.php:47
2024-03-12T16:23:35.682878841Z Symfony\Component\HttpClient\Response\ResponseStream->rewind() at /srv/app/vendor/async-aws/core/src/Response.php:149
2024-03-12T16:23:35.682880507Z AsyncAws\Core\Response->resolve() at /srv/app/vendor/async-aws/core/src/Result.php:69
2024-03-12T16:23:35.682899799Z AsyncAws\Core\Result->resolve() at /srv/app/vendor/symfony/amazon-sqs-messenger/Transport/Connection.php:234
2024-03-12T16:23:35.682902174Z Symfony\Component\Messenger\Bridge\AmazonSqs\Transport\Connection->fetchMessage() at /srv/app/vendor/symfony/amazon-sqs-messenger/Transport/Connection.php:374
2024-03-12T16:23:35.682903841Z Symfony\Component\Messenger\Bridge\AmazonSqs\Transport\Connection->reset() at /srv/app/vendor/symfony/amazon-sqs-messenger/Transport/Connection.php:80
2024-03-12T16:23:35.682905382Z Symfony\Component\Messenger\Bridge\AmazonSqs\Transport\Connection->__destruct() at n/a:n/a
2024-03-12T16:23:35.682906799Z
Same problem. I have tried to investigate, but the code is super complicated...
@stof, maybe you have some ideas of where I could begin or how to fix it?
I think the bug is due to the option wait_time in \Symfony\Component\Messenger\Bridge\AmazonSqs\Transport\Connection. When the Worker stops, the connection is still open, and we have the first chunk and data chunk without the last chunk.
This error begins after I update dependencies in my project. Among them:
-
async-aws/core,1.15.0->1.20.0 -
async-aws/ses,1.4.1->1.6.0 -
async-aws/sqs,1.7.0->1.9.0 -
symfony/amazon-sqs-messenger,v6.1.0->v6.3.0 -
symfony/messenger,v6.1.0->v6.3.4
I checked the changes but found nothing related to a bug.
any chance the issue to be fixed ?