So we use AWS ECS tasks to process our reports in production system. Now it seems that each Sunday, when we process most of these reports some of these tasks seem to get stuck and not do anything. If we restart php-fpm service, problem disappears.
I have SSH'ed into one of these tasks and used tools like ps, strace and phpspy to try and identify the problem. If I run ps aux, I can see around 20 php-fpm child processes. Running strace on each one of these and only a single child process is returning me some data. Here is that strace shows me:
poll([{fd=19, events=POLLIN}, {fd=14, events=POLLIN}], 2, 1000) = 0 (Timeout)
rt_sigaction(SIGPIPE, NULL, {sa_handler=SIG_IGN, sa_mask=[PIPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f1884c06040}, 8) = 0
rt_sigaction(SIGPIPE, {sa_handler=SIG_IGN, sa_mask=[PIPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f1884c06040}, NULL, 8) = 0
poll([{fd=19, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 0 (Timeout)
rt_sigaction(SIGPIPE, {sa_handler=SIG_IGN, sa_mask=[PIPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f1884c06040}, NULL, 8) = 0
rt_sigaction(SIGPIPE, NULL, {sa_handler=SIG_IGN, sa_mask=[PIPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f1884c06040}, 8) = 0
rt_sigaction(SIGPIPE, {sa_handler=SIG_IGN, sa_mask=[PIPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f1884c06040}, NULL, 8) = 0
poll([{fd=14, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 0 (Timeout)
rt_sigaction(SIGPIPE, {sa_handler=SIG_IGN, sa_mask=[PIPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f1884c06040}, NULL, 8) = 0
poll([{fd=19, events=POLLIN}, {fd=14, events=POLLIN}], 2, 1000) = 0 (Timeout)
rt_sigaction(SIGPIPE, NULL, {sa_handler=SIG_IGN, sa_mask=[PIPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f1884c06040}, 8) = 0
rt_sigaction(SIGPIPE, {sa_handler=SIG_IGN, sa_mask=[PIPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f1884c06040}, NULL, 8) = 0
Running phpspy on the same PID, I can see same piece of code being executed, almost as if it's stuck in infinite loop:
0 curl_multi_select <internal>:-1
1 GuzzleHttp\Handler\CurlMultiHandler::tick /srv/www/vendor/guzzlehttp/guzzle/src/Handler/CurlMultiHandler.php:101
2 GuzzleHttp\Handler\CurlMultiHandler::execute /srv/www/vendor/guzzlehttp/guzzle/src/Handler/CurlMultiHandler.php:136
3 GuzzleHttp\Promise\Promise::invokeWaitFn /srv/www/vendor/guzzlehttp/promises/src/Promise.php:243
4 GuzzleHttp\Promise\Promise::waitIfPending /srv/www/vendor/guzzlehttp/promises/src/Promise.php:219
5 GuzzleHttp\Promise\Promise::invokeWaitList /srv/www/vendor/guzzlehttp/promises/src/Promise.php:262
6 GuzzleHttp\Promise\Promise::waitIfPending /srv/www/vendor/guzzlehttp/promises/src/Promise.php:219
7 GuzzleHttp\Promise\Promise::invokeWaitList /srv/www/vendor/guzzlehttp/promises/src/Promise.php:262
8 GuzzleHttp\Promise\Promise::waitIfPending /srv/www/vendor/guzzlehttp/promises/src/Promise.php:219
9 GuzzleHttp\Promise\Promise::wait /srv/www/vendor/guzzlehttp/promises/src/Promise.php:60
10 GuzzleHttp\Promise\EachPromise::GuzzleHttp\Promise\{closure} /srv/www/vendor/guzzlehttp/promises/src/EachPromise.php:109
11 GuzzleHttp\Promise\Promise::invokeWaitFn /srv/www/vendor/guzzlehttp/promises/src/Promise.php:243
12 GuzzleHttp\Promise\Promise::waitIfPending /srv/www/vendor/guzzlehttp/promises/src/Promise.php:219
13 GuzzleHttp\Promise\Promise::wait /srv/www/vendor/guzzlehttp/promises/src/Promise.php:60
14 PiExt\S3Client\S3Client::fetchObjectsInParallel /srv/www/library/pi-ext/s3-client/src/S3Client.php:169
15 PiExt\S3Client\S3Client::getObjects /srv/www/library/pi-ext/s3-client/src/S3Client.php:99
So judging from this stacktrace, I can see that it is continuously trying to get S3 Object using Curl. If I use lsof command on same PID, then I cann see all these connections to S3:
php-fpm8. 39 www-data 14u IPv4 322974 0t0 TCP ip-10-0-0-201.eu-west-1.compute.internal:34416->s3-eu-west-1-r-w.amazonaws.com:https (ESTABLISHED)
php-fpm8. 39 www-data 16u IPv4 322980 0t0 TCP ip-10-0-0-201.eu-west-1.compute.internal:34428->s3-eu-west-1-r-w.amazonaws.com:https (CLOSE_WAIT)
php-fpm8. 39 www-data 17u IPv4 322979 0t0 TCP ip-10-0-0-201.eu-west-1.compute.internal:34426->s3-eu-west-1-r-w.amazonaws.com:https (CLOSE_WAIT)
php-fpm8. 39 www-data 18u IPv4 322975 0t0 TCP ip-10-0-0-201.eu-west-1.compute.internal:34418->s3-eu-west-1-r-w.amazonaws.com:https (CLOSE_WAIT)
php-fpm8. 39 www-data 19u IPv4 322964 0t0 TCP ip-10-0-0-201.eu-west-1.compute.internal:34396->s3-eu-west-1-r-w.amazonaws.com:https (ESTABLISHED)
php-fpm8. 39 www-data 20u IPv4 322971 0t0 TCP ip-10-0-0-201.eu-west-1.compute.internal:34410->s3-eu-west-1-r-w.amazonaws.com:https (CLOSE_WAIT)
php-fpm8. 39 www-data 21u IPv4 322976 0t0 TCP ip-10-0-0-201.eu-west-1.compute.internal:34420->s3-eu-west-1-r-w.amazonaws.com:https (CLOSE_WAIT)
php-fpm8. 39 www-data 22u IPv4 322977 0t0 TCP ip-10-0-0-201.eu-west-1.compute.internal:34422->s3-eu-west-1-r-w.amazonaws.com:https (CLOSE_WAIT)
php-fpm8. 39 www-data 23u IPv4 322965 0t0 TCP ip-10-0-0-201.eu-west-1.compute.internal:34398->s3-eu-west-1-r-w.amazonaws.com:https (ESTABLISHED)
php-fpm8. 39 www-data 24u IPv4 322981 0t0 TCP ip-10-0-0-201.eu-west-1.compute.internal:34430->s3-eu-west-1-r-w.amazonaws.com:https (CLOSE_WAIT)
php-fpm8. 39 www-data 25u IPv4 322966 0t0 TCP ip-10-0-0-201.eu-west-1.compute.internal:34400->s3-eu-west-1-r-w.amazonaws.com:https (CLOSE_WAIT)
php-fpm8. 39 www-data 27u IPv4 322982 0t0 TCP ip-10-0-0-201.eu-west-1.compute.internal:34432->s3-eu-west-1-r-w.amazonaws.com:https (CLOSE_WAIT)
php-fpm8. 39 www-data 28u IPv4 322961 0t0 TCP ip-10-0-0-201.eu-west-1.compute.internal:34388->s3-eu-west-1-r-w.amazonaws.com:https (CLOSE_WAIT)
php-fpm8. 39 www-data 30u IPv4 322978 0t0 TCP ip-10-0-0-201.eu-west-1.compute.internal:34424->s3-eu-west-1-r-w.amazonaws.com:https (CLOSE_WAIT)
php-fpm8. 39 www-data 31u IPv4 322962 0t0 TCP ip-10-0-0-201.eu-west-1.compute.internal:34390->s3-eu-west-1-r-w.amazonaws.com:https (CLOSE_WAIT)
php-fpm8. 39 www-data 32u IPv4 322983 0t0 TCP ip-10-0-0-201.eu-west-1.compute.internal:34434->s3-eu-west-1-r-w.amazonaws.com:https (CLOSE_WAIT)
php-fpm8. 39 www-data 33u IPv4 322968 0t0 TCP ip-10-0-0-201.eu-west-1.compute.internal:34404->s3-eu-west-1-r-w.amazonaws.com:https (CLOSE_WAIT)
php-fpm8. 39 www-data 34u IPv4 322985 0t0 TCP ip-10-0-0-201.eu-west-1.compute.internal:34438->s3-eu-west-1-r-w.amazonaws.com:https (CLOSE_WAIT)
php-fpm8. 39 www-data 35u IPv4 322984 0t0 TCP ip-10-0-0-201.eu-west-1.compute.internal:34436->s3-eu-west-1-r-w.amazonaws.com:https (CLOSE_WAIT)
php-fpm8. 39 www-data 36u IPv4 322969 0t0 TCP ip-10-0-0-201.eu-west-1.compute.internal:34406->s3-eu-west-1-r-w.amazonaws.com:https (CLOSE_WAIT)
php-fpm8. 39 www-data 37u IPv4 322986 0t0 TCP ip-10-0-0-201.eu-west-1.compute.internal:34440->s3-eu-west-1-r-w.amazonaws.com:https (CLOSE_WAIT)
PHP Version: 8.0.9 Curl version: 7.58.0 Guzzle version: 6.x