Pushing many subsequent messages to SQS causes PHP to crash

[esbenp]

Hi. I have an odd issue with my queue. I have a supervisor process that will push multiple messages onto SQS. However, after a couple of messages the process will crash with no apparent error message.

To debug I started adding random logging statements (I use Laravel framework) in aws-sdk-php but with no success.

In AwsClientTrait.php I added something like this

public function __call($name, array $args)
{
    $params = isset($args[0]) ? $args[0] : [];

    if (substr($name, -5) === 'Async') {
        return $this->executeAsync(
            $this->getCommand(substr($name, 0, -5), $params)
        );
    }

    \Log::info('before aws');
    $result = $this->execute($this->getCommand($name, $params));
    \Log::info('after aws');

    return $result;
}

and in the GuzzleV6 handler I added some logging too

public function __invoke(Psr7Request $request, array $options = [])
{
    $stack = HandlerStack::create();
    $logger = new Logger('Logger');
    $logger->pushHandler(new StreamHandler(storage_path('request_log.log'), Logger::DEBUG));
    $stack->push(
    Middleware::log(
        $logger,
        new MessageFormatter('{request} - {response}')
    )
    );
    $this->client = new Client([
        'handler' => $stack
    ]);
    \Log::info('guzzle', [
        'url' => $request->getUri()
    ]);

    return $this->client->sendAsync($request, $this->parseOptions($options))
        ->otherwise(
            static function (\Exception $e) {
                $error = [
                    'exception'        => $e,
                    'connection_error' => $e instanceof ConnectException,
                    'response'         => null,
                ];

                if ($e instanceof RequestException && $e->getResponse()) {
                    $error['response'] = $e->getResponse();
                }

                return new Promise\RejectedPromise($error);
            }
        );
}

As a timeline these logging statements can be viewed as before aws -> guzzle -> after aws

After a few successful messages my process will crash somewhere between guzzle and after aws. There are no messages in my nginx log, php log or syslog. The only evidence I can find of the process crashing is a statement in my supervisor log:

2017-05-17 10:15:36,280 INFO exited: importing01_00 (terminated by SIGKILL; not expected)

When I check the log created by the Monolog handler that I created in the GuzzleV6 handler there is a bunch of successful messages - but the request that causes it all to crash is not logged at all.

I am really unsure as to what steps I can take to further get to the bottom as this issue which is why I am posting here. Since it somehow happens somewhere in the aws-sdk-php code, have you seen this behaviour before? Any ideas for what steps I can take to further investigate?

My stack is nginx 1.9.9 php 7.1.5 (I have also tried using php 7.1.2) aws-sdk-php 3.27.1 Laravel framework 5.3.31 Ubuntu 14.04.3 LTS

[imshashank]

@esbenp Sorry that you are having this issue.

I have not seen this kind of error before but since this is a long running supervisor process, I would recommend scheduling the garbage collector to run after every few minutes (can be done using php.ini). I would also recommend monitoring the memory of the system to make sure that nginx is not killing php processes if they exceed certain memory limit.

Also, apache/nginx has a max_execution_time setting which can cause the process to die if it is running for a certain time.

I'll recommend you to have a look at that as well. Please let me know if this fixes your problem or we can dig deeper.

[waseemdarwin]

Facing the same issue with many workers processing multiple messages. @esbenp did you got the Root Cause for this?