504 Gateway Time-out

How to start Nginx (or listen a http port) after PHP-FPM startup in a single container?

I have issues running Nginx+PHP-FPM in a single container on Cloud Run. My container is based on Alpine and manages Nginx and PHP-FPM startup by Supervisor. Overall it works fine, but there’s a short timeframe between when Nginx starts listening to an HTTP port and when PHP-FPM spinups. This leads to the appearance of 502 HTTP errors with the following log message:

6#6: *3 connect() failed (111: Connection refused) while connecting to upstream, client: 169.254.8.129, server: _, request: "POST / HTTP/1.1", upstream: "fastcgi://127.0.0.1:9000" 

The issue here is that Cloud Run decides that the container is ready to handle requests when it opens the 8080 port. Immediately after the port opening, Cloud Run sends a request which always fails on the first attempt because FPM is not ready yet. The log message NOTICE: fpm is running, pid 4 appears after the first request has arrived and failed. How to manage Nginx to open its port only when PHP-FPM is ready? Supervisor config:

[supervisord] nodaemon=true logfile=/dev/null logfile_maxbytes=0 pidfile=/run/supervisord.pid [program:php-fpm] command=php-fpm -F stdout_logfile=/dev/stdout stdout_logfile_maxbytes=0 stderr_logfile=/dev/stderr stderr_logfile_maxbytes=0 autorestart=false startretries=0 [program:nginx] command=nginx -g 'daemon off;' stdout_logfile=/dev/stdout stdout_logfile_maxbytes=0 stderr_logfile=/dev/stderr stderr_logfile_maxbytes=0 autorestart=false startretries=0 

# Write temporary files to /tmp so they can be created as a non-privileged user client_body_temp_path /tmp/client_temp; proxy_temp_path /tmp/proxy_temp_path; fastcgi_temp_path /tmp/fastcgi_temp; uwsgi_temp_path /tmp/uwsgi_temp; scgi_temp_path /tmp/scgi_temp; access_log /dev/stdout; error_log /dev/stderr notice; server < listen 8080 default_server; index index.php; keepalive_requests 10; keepalive_timeout 60 60; root /var/www/html/app/public; charset utf-8; server_name _; # Deny hidden files (.htaccess, .htpasswd, .DS_Store). location ~ /\. < deny all; access_log off; log_not_found off; >######################## # mappings # ######################## location ~ \.(js|css|png|jpg|ico) < expires 5d; try_files $uri $uri/ =404; return 404; ># Allow fpm ping and status from localhost location ~ ^/(fpm-status|fpm-ping)$ < access_log off; allow 127.0.0.1; deny all; fastcgi_param SCRIPT_FILENAME $document_root$fastcgi_script_name; include fastcgi_params; fastcgi_pass 127.0.0.1:9000; >location / < client_max_body_size 100m; try_files $uri @fpm; >location @fpm < # worker may take long time to finish (max 1 hour) fastcgi_read_timeout 3600s; fastcgi_split_path_info ^(.+\.php)(/.*)$; include fastcgi_params; fastcgi_param HTTP_PROXY ""; fastcgi_pass 127.0.0.1:9000; fastcgi_index index.php; fastcgi_param SCRIPT_FILENAME /var/www/html/app/public/index.php; fastcgi_param SCRIPT_NAME index.php; >> 

I have enabled FPM ping/status pages. Can I use them to trigger the Nginx port opening? Update 1: I tried to adjust supervisord priorities and start seconds:

. [program:php-fpm] . priority=100 startsecs=3 [program:nginx] . priority=200 

[18-Dec-2020 00:31:04] NOTICE: ready to handle connections [18-Dec-2020 00:31:04] NOTICE: fpm is running, pid 3 2020-12-18 00:30:30,689 INFO success: php-fpm entered RUNNING state, process has stayed up for > than 3 seconds (startsecs) 2020-12-18 00:30:28,388 INFO success: nginx entered RUNNING state, process has stayed up for > than 1 seconds (startsecs) Error POST 502 549 B 3.286 s Google-Cloud-Scheduler https://***.run.app/ 169.254.8.129 - - [18/Dec/2020:00:30:27 +0000] "POST / HTTP/1.1" 502 150 "-" "Google-Cloud-Scheduler" 169.254.8.129 - - [18/Dec/2020:00:30:27 +0000] "POST / HTTP/1.1" 502 150 "-" "Google-Cloud-Scheduler" "35.187.131.214" 2020/12/18 00:30:27 [error] 6#6: *3 connect() failed (111: Connection refused) while connecting to upstream, client: 169.254.8.129, server: _, request: "POST / HTTP/1.1", upstream: "fastcgi://127.0.0.1:9000", host: "***.run.app" 2020-12-18 00:30:26,937 INFO spawned: 'nginx' with pid 4 2020-12-18 00:30:26,829 INFO spawned: 'php-fpm' with pid 3 2020-12-18 00:30:25,730 INFO supervisord started with pid 1 2020-12-18 00:30:25,704 CRIT Supervisor is running as root. Privileges were not dropped because no user 

Both apps still started by Supervisord simultaneously and nginx initializes first. The RUNNING state that Supervisord applies to apps means nothing for Cloud Run.

Источник

Nginx, PHP-fpm и таймауты

Многих из нас интересует работа Nginx в паре с PHP-fpm и то, почему процессы прерываются а ошибок нет, я попробую рассказать об этом.

Итак, обычно, на следующие параметры не обращают внимание, а зря, ведь это базовые вещи, которые должны быть заданны в настройках, иначе они будут иметь дефолтное значение, или например одно значение может быть заданно, а второе нет:

nginx.conf	fastcgi_read_timeout	Количество секунд, которое будет ждать Nginx от PHP-fpm (задаёт таймаут при чтении ответа FastCGI-сервера). Таймаут устанавливается не на всю передачу ответа, а только между двумя операциями чтения. Если по истечении этого времени FastCGI-сервер ничего не передаст, соединение закрывается. По-умолчанию 60 секунд.
php-fpm.conf	request_terminate_timeout	Таймаут для обслуживания одного запроса, после чего рабочий процесс будет завершен. Этот вариант следует использовать, когда опция ‘max_execution_time’ в php.ini не останавливает выполнение скрипта по каким-то причинам. Значение ‘0’ означает ‘выключено’. Доступные единицы измерения: s(econds), m(inutes), h(ours) или d(ays). Значение по умолчанию: 0, т.е. никогда.

Значит, дефолтно, если php будет отдавать ответ более 60 секунд, то nginx закроет соединение и клиент получит 504 Gateway Time-out.

Если request_terminate_timeout сработает раньше чем fastcgi_read_timeout , то nginx выдаст: 502 Bad Gateway, в противном случае: 504 Gateway Time-out

Практика

1. Укажем количество секунд, которое будет ждать Nginx от PHP-fpm:

server < . location ~ ^/app\.php(/|$) < . fastcgi_read_timeout 3; > >

2. В файл /etc/php5/fpm/php-fpm.conf добавляем таймауты нашего пула:

[site-local]

request_slowlog_timeout = 5 s
request_terminate_timeout = 30 s

3. Создаем PHP-файл /var/www/site/web/app.php с следующим содержимым:

4. Выполняем запрос к нашему сайту:

curl -i http://site.local/info.json
HTTP/1.1 504 Gateway Time-out
Server: nginx/1.9.3 (Ubuntu)
Date: Wed, 27 Apr 2016 16:58:17 GMT
Content-Type: text/html
Content-Length: 191
Connection: keep-alive

504 Gateway Time-out

---

nginx/1.9.3 (Ubuntu)

как видите, сработала настройка fastcgi_read_timeout.

5. Смотрим на то, что происходит в PHP-fpm:

# /usr/sbin/php5-fpm
[27-Apr-2016 16:56:35] NOTICE: fpm is running, pid 98
[27-Apr-2016 16:56:35] NOTICE: ready to handle connections
[27-Apr-2016 16:56:35] NOTICE: systemd monitor interval set to 10000ms

Обратите внимание, сработала php-fpm настройка request_slowlog_timeout :

[27-Apr-2016 16:58:16] ERROR: failed to ptrace(ATTACH) child 100: Operation not permitted (1)
[27-Apr-2016 16:58:16] WARNING: [pool site-local] child 100, script ‘/var/www/site/web/app.php’ (request: «GET /app.php») executing too slow ( 5 .385329 sec), logging

но, PHP-fpm-процесс все еще живет и выполняется (если в нем появляются ошибки, они будут записаны в логи).

Теперь внимание, сработала php-fpm настройка request_terminate_timeout :

[27-Apr-2016 16:58:44] WARNING: [pool site-local] child 100, script ‘/var/www/site/web/app.php’ (request: «GET /app.php») execution timed out ( 30 .382169 sec), terminating
[27-Apr-2016 16:58:44] WARNING: [pool site-local] child 100 exited on signal 15 (SIGTERM) after 129.988014 seconds from start

Все, после этой строки никаких ошибок Вы не увидите, т.к. PHP-fpm-процесс, обслуживающий запрос под номером 100, был убит.

Кстати: как видите лог-записи 2:

первая — говорит о том, какой скрипт отрабатывал и через сколько он был убит:

[27-Apr-2016 16:58:44] WARNING: [pool site-local] child 100, script ‘/var/www/site/web/app.php’ (request: «GET /app.php») execution timed out (30.382169 sec), terminating

вторая — говорит о том, каким сигналом был убит дочерний пхп-фпм процесс и сколько времени он прожил (129 секунд — за это время он мог отработать ряд запросов, но увы текущий запрос был долгим, поэтому пхп-фпм принял решение убить процесс):

[27-Apr-2016 16:58:44] WARNING: [pool site-local] child 100 exited on signal 15 (SIGTERM) after 129.988014 seconds from start

внимание: у обоих записей child 100 (это ведь один реальный процесс)

1. В реальном проекте таймаут-параметры Nginx и PHP-fpm должны быть одинаковы (но не обязательно, главное чтобы в PHP-fpm был указан request_terminate_timeout)
2. Собирайте статистику выполнения Nginx-запросов и если они достигают или превышают лимиты — оптимизируйте сайт или увеличивайте лимиты 🙂

Другие заметки

Ниже опишу дополнительные заметки

Неправильное ощущение

С какого-то времени PHP-fpm согласно таймауту стал завершать процессы сигналом 9:

WARNING: [pool www] child 28 exited on signal 9 (SIGKILL) after 207.053563 seconds from start

И я сразу подумал, что проблема в request_terminate_timeout , но причиной тому были настройка pm.max_requests=100

Если pm.max_requests указать больше 0, то php-fpm-master будет убивать php-fpm-kid процесс после того, как php-fpm-kid обслужил указанное кол-во http-запросов (в данном случае 100). Это конечно полезно для избежания утечек памяти при использовании сторонних библиотек. Для бесконечной обработки запросов укажите ‘0’. Эквивалент PHP_FCGI_MAX_REQUESTS. Значение по умолчанию: 0.

Зависимость php-fpm от nginx

Говорят, можно завершать php-fpm процесс, если завершился nginx-процесс который его «породил». Это было бы очень правильной стратегией, потому что нет смысла тратить ресурсы/мощности сервера, если клиент уже не собирается получать ответ.

К сожалению, у меня это сделать не получилось, но пробовал я так:

1. устанавливал «fastcgi_ignore_client_abort on» в nginx
2. устанавливал ignore_user_abort(false); в php-скрипте

Клиент отказался ждать

Если клиент прервал соединение с nginx (раньше чем успел ответить php-fpm), то например при двух запросах, мы увидим такие access-логи:

nginx_1 | 172.18.0.1 - - [24/Aug/2021:10:22:20 +0000] "POST /api/v2/page HTTP/1.1" 499 0 "-" "-" nginx_1 | 172.18.0.1 - - [24/Aug/2021:10:22:20 +0000] "POST /api/v2/page HTTP/1.1" 499 0 "-" "-" php-fpm_1 | 172.18.0.4 - 24/Aug/2021:10:22:19 +0000 "POST /index.php" 200 php-fpm_1 | 172.18.0.4 - 24/Aug/2021:10:22:19 +0000 "POST /index.php" 200

Почему нельзя доверять max_execution_time

PHP когда считает время выполнения скрипта (и анализируя значение выставленное функцией set_time_limit() и директивой max_execution_time) не берет в расчет время, затраченное на различные действия вне скрипта, такие как системные вызовы функции system(), sleep(), потоковые операции, запросы к базам данных и т.п..

Например, если max_execution_time равен 30 секунд, при этом стоит sleep(10), то PHP остановит выполнение скрипта только по прошествии 40 секунд.

Мало того, если тайм-аут изначально был 30 секунд, и через 25 секунд после запуска скрипта будет вызвана функция set_time_limit(20) , то скрипт будет работать максимум 45 секунд.

А еще к минусам можно отнести наличие hard_timeout которое продлевает max_execution_time на случай, если вдруг что-то застрянет (по умолчанию: 0).

Источник

Тема: PHP-FPM на запускается!

PHP-FPM на запускается!

Работали сайты под php-fpm и вдруг стала выдаваться 502 Bad Gateway (nginx отдает ошибку разу без ожидания)
при этом сайт напрямую через apache работает и дальше корректно.

Что через socket (/var/run/php5-fpm-sock) что через порт (127,0,0,1:9000) не работает

Порт светится, файерволом не закрыт, через netsat проверяли — socket тоже создается как надо

В логе php-fpm наблюдаются следующие ошибки:
[14-Oct-2014 17:19:16] NOTICE: Finishing .
[14-Oct-2014 17:19:16] NOTICE: exiting, bye-bye!
[14-Oct-2014 17:19:17] NOTICE: fpm is running, pid 32065
[14-Oct-2014 17:19:17] NOTICE: ready to handle connections
[14-Oct-2014 17:19:20] WARNING: [pool www] child 32081 exited with code 127 after 0.002703 seconds from start
[14-Oct-2014 17:19:20] NOTICE: [pool www] child 32082 started
[14-Oct-2014 17:19:23] WARNING: [pool www] child 32082 exited with code 127 after 2.855172 seconds from start
[14-Oct-2014 17:19:23] NOTICE: [pool www] child 32086 started
[14-Oct-2014 17:19:24] WARNING: [pool www] child 32086 exited with code 127 after 1.555343 seconds from start
[14-Oct-2014 17:19:24] NOTICE: [pool www] child 32088 started
и т.д.

Помогите найти причину или подскажите где искать?

Источник