1 (edited by OwllwO 2014-11-14 00:48:09)

Topic: PHP-FPM in PHP 5.6.3 Changes

thanks for the the repos, been using them for while and they are incredibly useful.

I updated to PHP 5.6.3 today and am now having problems with PHP-FPM.
I have read through the release notes and can see some changes to PHP-FPM (by Remi) but they seem to deal with script names, which I do not think is the issue.

On Centos 7 I use PHP-FPM on ports, with each server on a different port, 9000, 9001, 9002 etc.

Each server log produces the following:
"[proxy:error] ~ FCGI: attempt to connect to 127.0.0.1:9002 (*) failed"
"[proxy_fcgi:error]~ failed to make connection to backend: 127.0.0.1"

The PHP-FPM Error log:
[13-Nov-2014 17:23:50] NOTICE: Terminating ...
[13-Nov-2014 17:23:50] NOTICE: exiting, bye-bye!
[13-Nov-2014 17:23:50] NOTICE: fpm is running, pid 11442
[13-Nov-2014 17:23:50] ERROR: epoll: unable to add fd 7
[13-Nov-2014 17:23:50] ERROR: epoll: unable to add fd 7
[13-Nov-2014 17:23:50] ERROR: epoll: unable to add fd 7
[13-Nov-2014 17:23:50] ERROR: epoll: unable to add fd 7
[13-Nov-2014 17:23:50] ERROR: epoll: unable to add fd 7
[13-Nov-2014 17:23:50] ERROR: epoll: unable to add fd 7
[13-Nov-2014 17:23:50] NOTICE: ready to handle connections
[13-Nov-2014 17:23:50] NOTICE: systemd monitor interval set to 10000ms

Those entries are produced on every restart.
The ports are not being used by another service. I use PHP-FPM "On-Demand" in-case it matters.

Any hints suggestions or help is welcomed.

Re: PHP-FPM in PHP 5.6.3 Changes

I will try to investigate

I don't see any change between 5.6.2 and 5.6.3 which explain such error..

Desktop: Fedora 29 x86_64 + rpmfusion + remi-test + remi-dev
Laptop:  Fedora 30 x86_64 + rpmfusion + remi (SCL only)
Hosting Server: CentOS 6.10 x86_64 with EPEL, remi, remi-php72 and remi-php72-test

Re: PHP-FPM in PHP 5.6.3 Changes

Please confirm the version used before update to 5.6.3 ?

Desktop: Fedora 29 x86_64 + rpmfusion + remi-test + remi-dev
Laptop:  Fedora 30 x86_64 + rpmfusion + remi (SCL only)
Hosting Server: CentOS 6.10 x86_64 with EPEL, remi, remi-php72 and remi-php72-test

Re: PHP-FPM in PHP 5.6.3 Changes

FYI there is only 2 set of changes in FPM.
- Path info (already applied in my 5.6.2 RPM)
- IPv6 (doesn't seem related to this...)

Desktop: Fedora 29 x86_64 + rpmfusion + remi-test + remi-dev
Laptop:  Fedora 30 x86_64 + rpmfusion + remi (SCL only)
Hosting Server: CentOS 6.10 x86_64 with EPEL, remi, remi-php72 and remi-php72-test

Re: PHP-FPM in PHP 5.6.3 Changes

I was using 5.6.2 prior to the update.

Re: PHP-FPM in PHP 5.6.3 Changes

Here is the output from /var/log/php-fpm/error.log when log_level string is set to debug.

When php-fpm is stopped all is normal:
[14-Nov-2014 09:06:02] NOTICE: Terminating ...
[14-Nov-2014 09:06:02] NOTICE: exiting, bye-bye!

When php-fpm is started (with debug mode):
[14-Nov-2014 09:06:28.176757] DEBUG: pid 5224, fpm_scoreboard_init_main(), line 40: got clock tick '100'
[14-Nov-2014 09:06:28.177080] DEBUG: pid 5224, fpm_event_init_main(), line 337: event module is epoll and 61 fds have been reserved
[14-Nov-2014 09:06:28.177111] NOTICE: pid 5224, fpm_init(), line 85: fpm is running, pid 5224
[14-Nov-2014 09:06:28.177121] ERROR: pid 5224, fpm_event_epoll_add(), line 177: epoll: unable to add fd 7
[14-Nov-2014 09:06:28.177126] ERROR: pid 5224, fpm_event_epoll_add(), line 177: epoll: unable to add fd 7
[14-Nov-2014 09:06:28.177131] ERROR: pid 5224, fpm_event_epoll_add(), line 177: epoll: unable to add fd 7
[14-Nov-2014 09:06:28.177136] ERROR: pid 5224, fpm_event_epoll_add(), line 177: epoll: unable to add fd 7
[14-Nov-2014 09:06:28.177141] ERROR: pid 5224, fpm_event_epoll_add(), line 177: epoll: unable to add fd 7
[14-Nov-2014 09:06:28.177147] DEBUG: pid 5224, fpm_event_loop(), line 366: 71232 bytes have been reserved in SHM
[14-Nov-2014 09:06:28.177152] NOTICE: pid 5224, fpm_event_loop(), line 367: ready to handle connections
[14-Nov-2014 09:06:28.177175] DEBUG: pid 5224, fpm_systemd_heartbeat(), line 68: have notify start to systemd
[14-Nov-2014 09:06:28.177181] NOTICE: pid 5224, fpm_systemd_heartbeat(), line 75: systemd monitor interval set to 10000ms
[14-Nov-2014 09:06:29.178228] DEBUG: pid 5224, fpm_pctl_perform_idle_server_maintenance(), line 362: [pool ex1] currently 0 active children, 0 spare children
[14-Nov-2014 09:06:29.178253] DEBUG: pid 5224, fpm_pctl_perform_idle_server_maintenance(), line 362: [pool ex2] currently 0 active children, 0 spare children
[14-Nov-2014 09:06:29.178262] DEBUG: pid 5224, fpm_pctl_perform_idle_server_maintenance(), line 362: [pool ex3] currently 0 active children, 0 spare children
[14-Nov-2014 09:06:29.178270] DEBUG: pid 5224, fpm_pctl_perform_idle_server_maintenance(), line 362: [pool ex4] currently 0 active children, 0 spare children
[14-Nov-2014 09:06:29.178275] DEBUG: pid 5224, fpm_pctl_perform_idle_server_maintenance(), line 362: [pool ex5] currently 0 active children, 0 spare children
[14-Nov-2014 09:06:29.178281] DEBUG: pid 5224, fpm_pctl_perform_idle_server_maintenance(), line 362: [pool ex6] currently 0 active children, 0 spare children
[14-Nov-2014 09:06:30.179339] DEBUG: pid 5224, fpm_pctl_perform_idle_server_maintenance(), line 362: [pool ex7] currently 0 active children, 0 spare children
[14-Nov-2014 09:06:30.179368] DEBUG: pid 5224, fpm_pctl_perform_idle_server_maintenance(), line 362: [pool ex8] currently 0 active children, 0 spare children
it continues to cycle through each of the pools etc...etc...

And then when stopped normal messages:
[14-Nov-2014 09:10:59.127531] DEBUG: pid 5224, fpm_got_signal(), line 85: received SIGTERM
[14-Nov-2014 09:10:59.127547] NOTICE: pid 5224, fpm_got_signal(), line 86: Terminating ...
[14-Nov-2014 09:10:59.127552] DEBUG: pid 5224, fpm_pctl(), line 231: switching to 'terminating' state
[14-Nov-2014 09:10:59.127557] NOTICE: pid 5224, fpm_pctl_exit(), line 70: exiting, bye-bye!

I do not think there is anything helpful in these logs, but wanted to share just in case.

Re: PHP-FPM in PHP 5.6.3 Changes

[14-Nov-2014 09:06:28.177152] NOTICE: pid 5224, fpm_event_loop(), line 367: ready to handle connections

Is fpm serving request from some pool ?
Is SElinux enabled (if yes could worth a try temporary disabling it, IIRC fpm port need some special context)

Can you share the pool configuration ? (I can't reproduce for now)

Desktop: Fedora 29 x86_64 + rpmfusion + remi-test + remi-dev
Laptop:  Fedora 30 x86_64 + rpmfusion + remi (SCL only)
Hosting Server: CentOS 6.10 x86_64 with EPEL, remi, remi-php72 and remi-php72-test

Re: PHP-FPM in PHP 5.6.3 Changes

Could also be related to https://bugs.php.net/bug.php?id=68420

Desktop: Fedora 29 x86_64 + rpmfusion + remi-test + remi-dev
Laptop:  Fedora 30 x86_64 + rpmfusion + remi (SCL only)
Hosting Server: CentOS 6.10 x86_64 with EPEL, remi, remi-php72 and remi-php72-test

Re: PHP-FPM in PHP 5.6.3 Changes

"[proxy:error] ~ FCGI: attempt to connect to 127.0.0.1:9002 (*) failed"

So you are using local FPM server
Probably listen = 127.0.0.1:9000 (as in default provided configuration) should help.

Now need to understand why is it now listening, by default, on IPv6 address

Desktop: Fedora 29 x86_64 + rpmfusion + remi-test + remi-dev
Laptop:  Fedora 30 x86_64 + rpmfusion + remi (SCL only)
Hosting Server: CentOS 6.10 x86_64 with EPEL, remi, remi-php72 and remi-php72-test

10 (edited by OwllwO 2014-11-14 11:46:24)

Re: PHP-FPM in PHP 5.6.3 Changes

(wrote this while you wrote above comment, am a slow typer!)
SElinux is disabled, I use Webmin/Virtualmin which is incompatible with SElinux.

Currently I am not directing any sites to php-fpm. In each httpd.conf I have commented outed out:
#ProxyPassMatch ^/(.*\.php(/.*)?)$ fcgi://127.0.0.1:9002/home/v2ap/public_html/$1

fpm is running but only the master process:

# systemctl status php-fpm
php-fpm.service - The PHP FastCGI Process Manager
   Loaded: loaded (/usr/lib/systemd/system/php-fpm.service; enabled)
   Active: active (running) since Fri 2014-11-14 09:11:01 GMT; 2h 10min ago
Main PID: 5416 (php-fpm)
   Status: "Processes active: 0, idle: 0, Requests: 0, slow: 0, Traffic: 0req/sec"
   CGroup: /system.slice/php-fpm.service
           └─5416 php-fpm: master process (/etc/php-fpm.conf)

The php-fpm.conf is default.

Each pool has the following format, all are ondemand:

[v2ap]

listen = 127.0.0.1:9002
listen.allowed_clients = 127.0.0.1

user = v2ap
group = v2ap

pm = ondemand
pm.max_children = 10
pm.process_idle_timeout = 10s
pm.max_requests = 500

catch_workers_output = yes
php_admin_value[error_log] = /var/log/php-fpm/www-error.log
php_admin_flag[log_errors] = on
php_value[session.save_handler] = files
php_value[session.save_path]    = /var/lib/php/session


There was very little information about ondemand when I started using it but it has been working flawlessly until now.

The bug you suggested sounds related but but I have been using "127.0.0.1:9002"  rather than "localhost:9002".
I will test some pools with different " listen = 127.0.0.1:9002 " values. I think " listen=:::9000" would be the suggestion.

Will post results.
thanks for taking the time to check this out.

Re: PHP-FPM in PHP 5.6.3 Changes

I have tested pools with different layouts of localhost:
Original listen = 127.0.0.1:9002

Listen = ::9002
This produces the error:
Nov 14 12:26:01 server.ex.com php-fpm[10564]: [14-Nov-2014 12:26:01] ERROR: getaddrinfo: Name or service not known
Nov 14 12:26:01 server.ex.com php-fpm[10564]: [14-Nov-2014 12:26:01] ERROR: FPM initialization failed
Nov 14 12:26:01 server.ex.com systemd[1]: php-fpm.service: main process exited, code=exited, status=78/n/a
Nov 14 12:26:01 server.ex.com systemd[1]: Failed to start The PHP FastCGI Process Manager.
Nov 14 12:26:01 server.ex.com systemd[1]: Unit php-fpm.service entered failed state.

listen = :::9005
This works but only once. If I do two pools with that layout then the second produces the error:
[14-Nov-2014 12:31:03] ERROR: epoll: unable to add fd 8

The only difference in the error is fd 8 rather than the previous fd 7.

Re: PHP-FPM in PHP 5.6.3 Changes

So I have test a single "ondemand" pool with 5.6.3 (but on Fedora 19)

It work as expected (listen = 127.0.0.1:9002)
Need to try multi-pool and on RHEL-7 now...

Desktop: Fedora 29 x86_64 + rpmfusion + remi-test + remi-dev
Laptop:  Fedora 30 x86_64 + rpmfusion + remi (SCL only)
Hosting Server: CentOS 6.10 x86_64 with EPEL, remi, remi-php72 and remi-php72-test

Re: PHP-FPM in PHP 5.6.3 Changes

Amazing, thanks.
Reading back I have not mentioned my Apache version, 2.4.6 .

Re: PHP-FPM in PHP 5.6.3 Changes

OK, I can reproduce on multi pool, only one is working

Desktop: Fedora 29 x86_64 + rpmfusion + remi-test + remi-dev
Laptop:  Fedora 30 x86_64 + rpmfusion + remi (SCL only)
Hosting Server: CentOS 6.10 x86_64 with EPEL, remi, remi-php72 and remi-php72-test

Re: PHP-FPM in PHP 5.6.3 Changes

I just found:

" This change (or another FPM related change in version 5.5.19 and 5.6.3) seems to break PHP-FPM when using the network stack. It can be reproduced e.g. on Ubuntu 14.04 by creating 5 different pools (port numbers 9001 to 9005) and then starting the PHP-FPM service. I would expect to have a listener on each of the five ports, instead only the first pool is actually loaded. The others fail to load (can e.g. be checked with netstat -tlpn | sort).

I had to downgrade to version 5.5.18/5.6.2 to fix the issue.! "

at: https://github.com/php/php-src/pull/631

The bug issue you linked earlier is mentioned too (https://bugs.php.net/bug.php?id=68420), the patch which caused that touches the ports too @ https://github.com/php/php-src/pull/631 … 967b64L259

Thanks for testing out and confirming that it was not just my configuration.

Re: PHP-FPM in PHP 5.6.3 Changes

https://bugs.php.net/68423 is probably your bug.

I just fix it, and runnning a C7 test build which I will upload shortly

Of course test welcome.

Desktop: Fedora 29 x86_64 + rpmfusion + remi-test + remi-dev
Laptop:  Fedora 30 x86_64 + rpmfusion + remi (SCL only)
Hosting Server: CentOS 6.10 x86_64 with EPEL, remi, remi-php72 and remi-php72-test

Re: PHP-FPM in PHP 5.6.3 Changes

Can you please give a try to test build available in http://rpms.famillecollet.com/temp/

(those packages are not signed)

Desktop: Fedora 29 x86_64 + rpmfusion + remi-test + remi-dev
Laptop:  Fedora 30 x86_64 + rpmfusion + remi (SCL only)
Hosting Server: CentOS 6.10 x86_64 with EPEL, remi, remi-php72 and remi-php72-test

18 (edited by OwllwO 2014-11-14 21:08:06)

Re: PHP-FPM in PHP 5.6.3 Changes

I tested the new fpm package and it works perfectly, there are no errors produced whatsoever.
Multi-pool works and so does everything else I could think off trying.

It is performing exactly as it did with the 5.6.2 PHP-FPM package.

In case it matters, I only installed the FPM package (rpm -Uvh --nodeps http://rpms.famillecollet.com/temp/php- … x86_64.rpm)

Remi, thanks, incredibly helpful and a really fast patch.

Re: PHP-FPM in PHP 5.6.3 Changes

FYI, I think I have fixed the recent FPM regressions/bugs (68420, 68421 and 68423).

I will be mostly offline this week-end, this will give some time for others to test the fix.

I plan to apply these patches in my RPM, and to provide new build (5.5 and 5.6) start of next week.


P.S. yes, some real life activity wink

Desktop: Fedora 29 x86_64 + rpmfusion + remi-test + remi-dev
Laptop:  Fedora 30 x86_64 + rpmfusion + remi (SCL only)
Hosting Server: CentOS 6.10 x86_64 with EPEL, remi, remi-php72 and remi-php72-test

Re: PHP-FPM in PHP 5.6.3 Changes

New build (5.5.19-2 and 5.6.3-3) "already" available with the 3 FPM fix.

Desktop: Fedora 29 x86_64 + rpmfusion + remi-test + remi-dev
Laptop:  Fedora 30 x86_64 + rpmfusion + remi (SCL only)
Hosting Server: CentOS 6.10 x86_64 with EPEL, remi, remi-php72 and remi-php72-test

Re: PHP-FPM in PHP 5.6.3 Changes

Seing a similar behavior in PHP 7.0.1 on CentOS 7.

I can start exactly one pool, only on port 9000. Anything other than that and here is what happens, even with just ONE pool:

# systemctl restart php70-php-fpm.service
Job for php70-php-fpm.service failed because the control process exited with error code. See "systemctl status php70-php-fpm.service" and "journalctl -xe" for details.
Dec 25 12:53:16 ip-16-0-0-170.ec2.internal systemd[1]: Starting The PHP FastCGI Process Manager...
Dec 25 12:53:16 ip-16-0-0-170.ec2.internal php-fpm[10285]: [25-Dec-2015 12:53:16] ERROR: unable to bind listening socket for address '127.0.0.1:9001': Permission denied (13)
Dec 25 12:53:16 ip-16-0-0-170.ec2.internal php-fpm[10285]: [25-Dec-2015 12:53:16] ERROR: FPM initialization failed
Dec 25 12:53:16 ip-16-0-0-170.ec2.internal systemd[1]: php70-php-fpm.service: main process exited, code=exited, status=78/n/a
Dec 25 12:53:16 ip-16-0-0-170.ec2.internal systemd[1]: Failed to start The PHP FastCGI Process Manager.
Dec 25 12:53:16 ip-16-0-0-170.ec2.internal systemd[1]: Unit php70-php-fpm.service entered failed state.
Dec 25 12:53:16 ip-16-0-0-170.ec2.internal systemd[1]: php70-php-fpm.service failed.
(...)
-- Unit php70-php-fpm.service has begun starting up.
Dec 25 12:53:16 ip-16-0-0-170.ec2.internal php-fpm[10285]: [25-Dec-2015 12:53:16] ERROR: unable to bind listening socket for address '127.0.0.1:9001': Permission denied (13)
Dec 25 12:53:16 ip-16-0-0-170.ec2.internal php-fpm[10285]: [25-Dec-2015 12:53:16] ERROR: FPM initialization failed
Dec 25 12:53:16 ip-16-0-0-170.ec2.internal systemd[1]: php70-php-fpm.service: main process exited, code=exited, status=78/n/a
Dec 25 12:53:16 ip-16-0-0-170.ec2.internal systemd[1]: Failed to start The PHP FastCGI Process Manager.
-- Subject: Unit php70-php-fpm.service has failed
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/li … temd-devel
--
-- Unit php70-php-fpm.service has failed.
--
-- The result is failed.
Dec 25 12:53:16 ip-16-0-0-170.ec2.internal systemd[1]: Unit php70-php-fpm.service entered failed state.
Dec 25 12:53:16 ip-16-0-0-170.ec2.internal systemd[1]: php70-php-fpm.service failed.
Dec 25 12:53:16 ip-16-0-0-170.ec2.internal polkitd[9145]: Unregistered Authentication Agent for unix-process:10280:2783175 (system bus name :1.50, object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8) (disconnected from bus)
lines 1658-1700/1700 (END)
-------------
Only port 9000 works.
As soon as the port 9000 is replaced by any other port number (9001, 9002, 9003,...9009), it won't work. It makes no difference if it is one pool or several; the port number seems to be the problem here.

Re: PHP-FPM in PHP 5.6.3 Changes

Look like a SELinux issue, the port need httpd context:

semanage port -a -t http_port_t -p tcp 9002

P.S. please, create a new thread for a new problem, instead of using this old one.

Desktop: Fedora 29 x86_64 + rpmfusion + remi-test + remi-dev
Laptop:  Fedora 30 x86_64 + rpmfusion + remi (SCL only)
Hosting Server: CentOS 6.10 x86_64 with EPEL, remi, remi-php72 and remi-php72-test