porque é que o php-fpm desova e destrói centenas de crianças por segundo sem carga no servidor?

Question

O php7.0-fpm.log está mostrando centenas de crianças sendo geradas por segundo e sendo imediatamente destruídas. Isso está acontecendo sem parar. O log é assim:

[09-Mar-2017 02:58:25] NOTICE: [pool www] child 4980 started
[09-Mar-2017 02:58:25] NOTICE: [pool www] child 4978 exited with code 0 after 0.014658 seconds from start
[09-Mar-2017 02:58:25] NOTICE: [pool www] child 4981 started
[09-Mar-2017 02:58:25] NOTICE: [pool www] child 4980 exited with code 0 after 0.014354 seconds from start
[09-Mar-2017 02:58:25] NOTICE: [pool www] child 4982 started
[09-Mar-2017 02:58:25] NOTICE: [pool www] child 4979 exited with code 0 after 0.015170 seconds from start
[09-Mar-2017 02:58:25] NOTICE: [pool www] child 4983 started
[09-Mar-2017 02:58:25] NOTICE: [pool www] child 4981 exited with code 0 after 0.014709 seconds from start
[09-Mar-2017 02:58:25] NOTICE: [pool www] child 4984 started
[09-Mar-2017 02:58:25] NOTICE: [pool www] child 4982 exited with code 0 after 0.014741 seconds from start
[09-Mar-2017 02:58:25] NOTICE: [pool www] child 4985 started
[09-Mar-2017 02:58:25] NOTICE: [pool www] child 4983 exited with code 0 after 0.014727 seconds from start
[09-Mar-2017 02:58:25] NOTICE: [pool www] child 4986 started

Configurações de /etc/php/7.0/fpm/php-fpm.conf :

pid = /run/php/php7.0-fpm.pid
error_log = /var/log/php7.0-fpm.log
include=/etc/php/7.0/fpm/pool.d/*.conf

Configurações de /etc/php/7.0/fpm/pool.d/www.conf :

pm = dynamic
pm.max_children = 5
pm.start_servers = 2
pm.min_spare_servers = 1
pm.max_spare_servers = 3
;pm.process_idle_timeout = 10s;
;pm.max_requests = 500
catch_workers_output = yes
php_flag[display_errors] = on
php_admin_value[error_log] = /var/log/phperrors.log
php_admin_flag[log_errors] = on

Todas as outras linhas são comentadas com ; (configurações padrão). Este é o Ubuntu 16.04, usando os pacotes padrão. As versões PHP e Nginx são as seguintes:

php-fpm7.0 -v
PHP 7.0.13-0ubuntu0.16.04.1 (fpm-fcgi)
Copyright (c) 1997-2016 The PHP Group
Zend Engine v3.0.0, Copyright (c) 1998-2016 Zend Technologies
    with Zend OPcache v7.0.13-0ubuntu0.16.04.1, Copyright (c) 1999-2016, by Zend Technologies

nginx -v
nginx version: nginx/1.10.0 (Ubuntu)

Nenhum ajuste foi feito (além de ativar o registro). Este servidor ainda não está implementado na produção, portanto, não há carga de usuário.

Por que o php-fpm está desovando e destruindo imediatamente centenas de crianças por segundo? Isso é um erro de configuração, ou o Ubuntu 16.04 vem com uma versão php-fpm com bugs?

    

Answer 1

Nem configuração incorreta nem versão com bugs. Na verdade, não há nada para se preocupar.

A razão pela qual seus processos estão saindo e reaparecendo tão rápido é que você está usando o valor padrão para pm.max_requests em seu arquivo de configuração do conjunto php-fpm, como é comentado por meio de um símbolo de ponto-e-vírgula ; . Para entender o que o parâmetro pm.max_requests significa, você pode ler a seguinte descrição tirada da configuração padrão:

pm.max_requests = int

The number of requests each child process should execute before respawning. This can be useful to work around memory leaks in 3rd party libraries. For endless request processing specify '0'. Equivalent to PHP_FCGI_MAX_REQUESTS. Default value: 0.

E o seu é 0, uma vez que é comentado. Você pode configurá-lo para algo como 100-500 (dependendo de suas necessidades) para que o php-fpm recicle o processo depois de processar essa quantidade de solicitações.

A propósito, você deve notar que essas mensagens no seu arquivo de registro são apenas informativas e não há nada errado, então não se preocupe. Essas entradas de log podem ser evitadas usando o valor de warning em vez de notice para o parâmetro log_level em php-fpm.conf . Está quase mostrando tudo - um pouco menos que debug level - já que o valor padrão é definido como notice .

Extraído da configuração padrão:

log_level = string

Error log level. Possible values: alert, error, warning, notice, debug. Default value: notice.

Boa sorte

    

Answer 2

Isso vem acontecendo em um dos meus servidores com o Ubuntu 14 (PHP 5) e 16 (PHP 7). Com a versão anterior, houve algum atraso, mas com a versão mais recente, assim que uma única solicitação problemática é atendida pelo processo do FPM, ela fica ativa.

Percebi que o tipo problemático de solicitações acontecem com exec , como em link mas eu ainda não vejo como isso deve causar isso . Parece estar intimamente correlacionado com a execução de material em segundo plano (com o operador & ).

Eu não posso oferecer uma solução real, apenas o meu script de contorno fugaz que é executado a partir do cron:

#!/bin/sh -e

v=${1:-7.0}
poolname=${2:-www}

# requires Restart=always and KillMode=process in /lib/systemd/system/php7.0-fpm.service!
retire_fpm() {
  logger -p user.crit -t $0 "$(sudo pkill -e php$v-fpm || sudo pkill -e php-fpm$v || echo "aiee, could not find php fpm version $v to retire" >&2)"
}

if sudo initctl version 2>/dev/null; then # upstart
  logdir=/var/log
  logfile=$logdir/upstart/php$v-fpm.log
else
  logdir=/var/log
  logfile=$logdir/php$v-fpm.log
fi

logfile_huge=$(test -e $logfile && find $logfile -size +200M || true)
if [ -n "$logfile_huge" ]; then
  logger -p user.crit -t $0 "demolishing $logfile to prevent the partition from filling up"
  cp /dev/null $logfile
fi

rotated_logfile_huge=$(test -e $logfile.1 && find $logfile.1 -size +200M || true)
if [ -n "$rotated_logfile_huge" ]; then
  logger -p user.crit -t $0 "demolishing $logfile.1 to prevent the partition from filling up"
  cp /dev/null $logfile.1
fi

if [ ! -e $logfile ]; then
  if ! df -P $logdir/ | awk '/^\// && $5+0 > 50 { exit(1) }'; then
    logger -p user.crit -t $0 "initiating php$v-fpm termination (init will restart it) because there is no $logfile yet the partition is filling up"
  else
    logger -p user.crit -t $0 "initiating php$v-fpm termination (init will restart it) because there is no $logfile, something went awry"
  fi
  retire_fpm
  exit
fi

logfile_grew=$(find $logfile -size +5M || true)

if [ -z "$logfile_grew" ]; then
  exit 0
fi

# 5 lines: handle recovery: one started line, one exited line, three post-signal lines
recent_fast_respawns=$(tail -5 $logfile | egrep -c ' NOTICE: .pool '$poolname'. child .+ exited with code 0 after 0....... seconds from start')

if [ "$recent_fast_respawns" -le 1 ]; then
  logger -p user.notice -t $0 "php$v-fpm log $logfile indicates a lot of recent activity, but only $recent_fast_respawns recent fast respawns, leaving it be"
  exit 0
fi

logger -p user.crit -t $0 "initiating php$v-fpm termination (init will restart it) because $logfile indicates $recent_fast_respawns recent fast respawns"
retire_fpm

Isso nunca deveria ter existido ... e, no entanto, eu o atualizei ao longo do tempo. < suspiro >