php-fpm proxy error

wolfdogg · 2014-05-04 18:49:29

I think this warrants a new topic, am i the only one thats still seeing this?

After going through my new apache upgrade settings 3 times now mainly using this resource https://wiki.archlinux.org/index.php/LA … xy_handler and this https://bbs.archlinux.org/viewtopic.php?id=178124 two consecutive weekends in a row i load the site, and its giving proxy errors again. It seems like it breaks itself over the course of a week.

// error_log
[Sun May 04 11:30:03.033327 2014] [proxy:error] [pid 17699] (111)Connection refused: AH00957: FCGI: attempt to connect to 127.0.0.1:9000 (*) failed
[Sun May 04 11:30:03.033523 2014] [proxy_fcgi:error] [pid 17699] [client 192.168.1.99:49471] AH01079: failed to make connection to backend: 127.0.0.1

//access_log
192.168.1.99 - - [04/May/2014:11:30:03 -0700] "GET / HTTP/1.1" 503 1039

basically im geting 503 error.

i found that after uncommenting the line from my httpd.conf

#ProxyPassMatch ^/(.*\.php(/.*)?)$ fcgi://127.0.0.1:9000/srv/http/$1

and restarting php-fpm and httpd, i simply get a message

file not found

then after commenting it back, and restarting httpd, and php-fpm, the site loads.

well thats what i did anyway, but it appears that i may have simply needed to restart php-fpm, but i cant be sure.

this has happened a couple weeks in a row , (each time i try to do some development on this machine on the weekends), however last weekend i totally gutted the pertinent parts of the configs, and redid them, but same problem this week.

will i have to restart php-fpm next week? am i missing something?

//httpd-conf

#LoadModule mpm_event_module modules/mod_mpm_event.so
 LoadModule mpm_prefork_module modules/mod_mpm_prefork.so

LoadModule proxy_handler_module modules/mod_proxy_handler.so
<FilesMatch \.php$>
    SetHandler "proxy:fcgi://127.0.0.1:9000/"
</FilesMatch>

# Server-pool management (MPM specific)
Include conf/extra/httpd-mpm.conf

# not using this method
#ProxyPassMatch ^/(.*\.php(/.*)?)$ fcgi://127.0.0.1:9000/srv/http/$1

And can somebody clarify what type of apache installation this has become? Is this now a "FastCGI" setup, or what is the exact terminology?

Last edited by wolfdogg (2014-05-04 18:52:33)

wolfdogg · 2014-05-10 23:50:52

little bump. yep, had to restart php-fpm again right now, until then, i was troubleshotting up the wrong tree.

access log before and after restart

192.168.1.99 - - [10/May/2014:11:55:51 -0700] "GET / HTTP/1.1" 503 1039
192.168.1.99 - - [10/May/2014:11:55:54 -0700] "GET /users HTTP/1.1" 503 1039
192.168.1.99 - - [10/May/2014:11:56:45 -0700] "GET /users HTTP/1.1" 503 1039
192.168.1.99 - - [10/May/2014:16:51:11 -0700] "GET /users HTTP/1.1" 503 1039
192.168.1.99 - - [10/May/2014:16:52:47 -0700] "GET /users HTTP/1.1" 200 5950
192.168.1.99 - - [10/May/2014:16:52:48 -0700] "GET /css/bootstrap.css HTTP/1.1" 200 132636
192.168.1.99 - - [10/May/2014:16:52:48 -0700] "GET /js/bootstrap.js HTTP/1.1" 200 61903
192.168.1.99 - - [10/May/2014:16:52:48 -0700] "GET /js/jquery.js HTTP/1.1" 200 273199
192.168.1.99 - - [10/May/2014:16:52:49 -0700] "GET /_wdt/8cf870 HTTP/1.1" 200 28613

Last edited by wolfdogg (2014-05-10 23:52:46)

Spider.007 · 2014-05-11 09:33:12

Tell us what's in the fpm access and error logs when you're getting 503's. Also; what does `systemctl status php-fpm` say?

tachy · 2014-05-15 15:00:49

I would guess that the php-fpm service crashes at some point, as it would explain why apache ProxyPass cannot connect to it on 127.0.0.1:9000

Like Spider.007, I suggest checking the status of the php-fpm service.
Also, see if there's anything in /var/log/php-fpm.log.
If you have enabled any logs in your FPM pool settings, check those too.

I am thinking, since you get a HTTP 503, the number of concurrent requests are perhaps exceeding pm.max_children

Last edited by tachy (2014-05-15 15:06:34)

vostok4 · 2014-05-15 16:19:37

I don't have much to add other than the fact that the php-fpm backend for me is horribly unstable. For a small personal project, I just ended up setting a cronjob to restart the server over and over... its a horrid solution but I ran out of time trying to root cause it. I was behind nginx, but I don't think that matters. I tried every combination of process management, nothing ever did it. If it was a x64 box I would have switched to HHVM long ago.

wolfdogg · 2014-05-31 19:29:32

im working on this today again, it's 503'd again.

thanks for pointing out the php-fpm logs, here they are;

php-fpm.log is empty,

php-fpm.log.1

$ sudo cat php-fpm.log.1
[18-May-2014 00:00:04] NOTICE: using inherited socket fd=6, "127.0.0.1:9000"
[18-May-2014 00:00:04] NOTICE: fpm is running, pid 1992
[18-May-2014 00:00:04] NOTICE: ready to handle connections
[18-May-2014 00:00:04] NOTICE: systemd monitor interval set to 10000ms
[20-May-2014 12:48:07] NOTICE: Terminating ...
[20-May-2014 12:48:07] NOTICE: exiting, bye-bye!

php-fpm.log.2

$ sudo cat php-fpm.log.1
[18-May-2014 00:00:04] NOTICE: using inherited socket fd=6, "127.0.0.1:9000"
[18-May-2014 00:00:04] NOTICE: fpm is running, pid 1992
[18-May-2014 00:00:04] NOTICE: ready to handle connections
[18-May-2014 00:00:04] NOTICE: systemd monitor interval set to 10000ms
[20-May-2014 12:48:07] NOTICE: Terminating ...
[20-May-2014 12:48:07] NOTICE: exiting, bye-bye!
[wolfdogg@falcon log]$ sudo cat php-fpm.log.2
[12-May-2014 00:00:07] NOTICE: using inherited socket fd=6, "127.0.0.1:9000"
[12-May-2014 00:00:07] NOTICE: fpm is running, pid 1992
[12-May-2014 00:00:07] NOTICE: ready to handle connections
[12-May-2014 00:00:07] NOTICE: systemd monitor interval set to 10000ms
[18-May-2014 00:00:04] NOTICE: Reloading in progress ...
[18-May-2014 00:00:04] NOTICE: reloading: execvp("/usr/bin/php-fpm", {"/usr/bin/php-fpm", "--nodaemonize", "--pid", "/run/php-fpm/php-fpm.pid"})

php-fpm.log.3 which contains the records from the last day i worked with it on the 10th when i made that post

$ sudo cat php-fpm.log.3
[04-May-2014 11:35:52] NOTICE: fpm is running, pid 17799
[04-May-2014 11:35:52] NOTICE: ready to handle connections
[04-May-2014 11:35:52] NOTICE: systemd monitor interval set to 10000ms
[04-May-2014 11:36:34] NOTICE: Terminating ...
[04-May-2014 11:36:34] NOTICE: exiting, bye-bye!
[04-May-2014 11:36:34] NOTICE: fpm is running, pid 17812
[04-May-2014 11:36:34] NOTICE: ready to handle connections
[04-May-2014 11:36:34] NOTICE: systemd monitor interval set to 10000ms
[04-May-2014 11:36:48] NOTICE: Terminating ...
[04-May-2014 11:36:48] NOTICE: exiting, bye-bye!
[04-May-2014 11:36:48] NOTICE: fpm is running, pid 17841
[04-May-2014 11:36:48] NOTICE: ready to handle connections
[04-May-2014 11:36:48] NOTICE: systemd monitor interval set to 10000ms
[10-May-2014 11:22:05] NOTICE: Terminating ...
[10-May-2014 11:22:05] NOTICE: exiting, bye-bye!
[10-May-2014 16:52:44] NOTICE: fpm is running, pid 1992
[10-May-2014 16:52:44] NOTICE: ready to handle connections
[10-May-2014 16:52:44] NOTICE: systemd monitor interval set to 10000ms
[12-May-2014 00:00:07] NOTICE: Reloading in progress ...
[12-May-2014 00:00:07] NOTICE: reloading: execvp("/usr/bin/php-fpm", {"/usr/bin/php-fpm", "--nodaemonize", "--pid", "/run/php-fpm/php-fpm.pid"})

excerpts from the error log from the 10th

[Sat May 10 11:41:01.388872 2014] [ssl:warn] [pid 1084] AH01909: mysite.com:443:0 server certificate does NOT include an ID which matches the server name
[Sat May 10 11:41:01.419019 2014] [ssl:warn] [pid 1085] AH01909: mysite.com:443:0 server certificate does NOT include an ID which matches the server name
[Sat May 10 11:41:03.796558 2014] [proxy:error] [pid 1086] (111)Connection refused: AH00957: FCGI: attempt to connect to 127.0.0.1:9000 (*) failed
[Sat May 10 11:41:03.796704 2014] [proxy_fcgi:error] [pid 1086] [client 192.168.1.99:61935] AH01079: failed to make connection to backend: 127.0.0.1
[Sat May 10 11:41:06.158186 2014] [proxy:error] [pid 1087] (111)Connection refused: AH00957: FCGI: attempt to connect to 127.0.0.1:9000 (*) failed
[Sat May 10 11:41:06.158331 2014] [proxy_fcgi:error] [pid 1087] [client 192.168.1.99:61937] AH01079: failed to make connection to backend: 127.0.0.1
[Sat May 10 11:41:39.383567 2014] [proxy:error] [pid 1088] (111)Connection refused: AH00957: FCGI: attempt to connect to 127.0.0.1:9000 (*) failed
[Sat May 10 11:41:39.383722 2014] [proxy_fcgi:error] [pid 1088] [client 192.168.1.99:61943] AH01079: failed to make connection to backend: 127.0.0.1
[Sat May 10 11:41:39.945939 2014] [proxy:error] [pid 1090] (111)Connection refused: AH00957: FCGI: attempt to connect to 127.0.0.1:9000 (*) failed
[Sat May 10 11:41:39.946091 2014] [proxy_fcgi:error] [pid 1090] [client 192.168.1.99:61945] AH01079: failed to make connection to backend: 127.0.0.1

all logs from today where i have made only two accesses so far

[Sat May 31 01:42:04.993834 2014] [ssl:warn] [pid 534] AH01909: mysite.com:443:0 server certificate does NOT include an ID which matches the server name
[Sat May 31 01:42:05.180928 2014] [ssl:warn] [pid 565] AH01909: mysite.com:443:0 server certificate does NOT include an ID which matches the server name
[Sat May 31 01:56:12.387048 2014] [ssl:warn] [pid 652] AH01909: mysite.com:443:0 server certificate does NOT include an ID which matches the server name
[Sat May 31 01:56:12.571606 2014] [ssl:warn] [pid 675] AH01909: mysite.com:443:0 server certificate does NOT include an ID which matches the server name
[Sat May 31 12:21:47.200490 2014] [proxy:error] [pid 679] (111)Connection refused: AH00957: FCGI: attempt to connect to 127.0.0.1:9000 (*) failed
[Sat May 31 12:21:47.200692 2014] [proxy_fcgi:error] [pid 679] [client 192.168.1.99:53345] AH01079: failed to make connection to backend: 127.0.0.1
[Sat May 31 12:21:56.870612 2014] [core:error] [pid 681] [client 192.168.1.99:53351] AH00037: Symbolic link not allowed or link target not accessible: /home/wolfdogg/sites/pear
[Sat May 31 12:21:56.879164 2014] [core:alert] [pid 681] [client 192.168.1.99:53351] /home/wolfdogg/sites/anothersite/.htaccess: Options not allowed here
[Sat May 31 12:22:00.000880 2014] [access_compat:error] [pid 681] [client 192.168.1.99:53351] AH01797: client denied by server configuration: /home/wolfdogg/sites/symfony/app/, referer: http://falcon/
[Sat May 31 12:22:00.002812 2014] [access_compat:error] [pid 681] [client 192.168.1.99:53351] AH01797: client denied by server configuration: /home/wolfdogg/sites/symfony/src/, referer: http://falcon/
[Sat May 31 12:22:01.793681 2014] [proxy:error] [pid 681] (111)Connection refused: AH00957: FCGI: attempt to connect to 127.0.0.1:9000 (*) failed
[Sat May 31 12:22:01.793785 2014] [proxy_fcgi:error] [pid 681] [client 192.168.1.99:53351] AH01079: failed to make connection to backend: 127.0.0.1, referer: http://falcon/symfony/

looks like i missed updating one of my .htaccess files, and that i have a ssl misconfigration on one of my sites in this sandbox, other than that i just see failed connections in the error log.

the access log from today

192.168.1.99 - - [31/May/2014:12:21:47 -0700] "GET / HTTP/1.1" 503 1039
192.168.1.99 - - [31/May/2014:12:21:47 -0700] "GET /favicon.ico HTTP/1.1" 304 -
192.168.1.99 - - [31/May/2014:12:21:56 -0700] "GET / HTTP/1.1" 200 7138
192.168.1.99 - - [31/May/2014:12:21:57 -0700] "GET /icons/blank.gif HTTP/1.1" 200 148
192.168.1.99 - - [31/May/2014:12:21:57 -0700] "GET /icons/folder.gif HTTP/1.1" 200 225
192.168.1.99 - - [31/May/2014:12:21:57 -0700] "GET /icons/image2.gif HTTP/1.1" 200 309
192.168.1.99 - - [31/May/2014:12:21:57 -0700] "GET /icons/text.gif HTTP/1.1" 200 229
192.168.1.99 - - [31/May/2014:12:21:57 -0700] "GET /icons/unknown.gif HTTP/1.1" 200 245
192.168.1.99 - - [31/May/2014:12:21:57 -0700] "GET /favicon.ico HTTP/1.1" 200 2007
192.168.1.99 - - [31/May/2014:12:21:59 -0700] "GET /symfony/ HTTP/1.1" 200 3241
192.168.1.99 - - [31/May/2014:12:22:00 -0700] "GET /icons/back.gif HTTP/1.1" 200 216
192.168.1.99 - - [31/May/2014:12:22:01 -0700] "GET /symfony/web/ HTTP/1.1" 503 1026

heres my httpd-mpm.conf file, i believe its default
http://bpaste.net/show/324981/

heres my php-fpm.conf file, i believe its default
http://bpaste.net/show/324972/

so i run the following and im back in action

$ systemctl restart php-fpm

its accessing fine now. its definitely php-fpm crashing.
after restarting now i have an entry in the php-fpm.log (a clean start)

$ cat php-fpm.log
[31-May-2014 12:55:33] NOTICE: fpm is running, pid 5098
[31-May-2014 12:55:33] NOTICE: ready to handle connections
[31-May-2014 12:55:33] NOTICE: systemd monitor interval set to 10000ms

and access log after accesing now...

192.168.1.99 - - [31/May/2014:12:55:37 -0700] "GET /symfony/ HTTP/1.1" 200 3241
192.168.1.99 - - [31/May/2014:12:55:39 -0700] "GET /symfony/web/ HTTP/1.1" 200 10269
192.168.1.99 - - [31/May/2014:12:55:44 -0700] "GET /symfony/web/css/5fa3cf3_loader_1.css HTTP/1.1" 200 1319
192.168.1.99 - - [31/May/2014:12:55:44 -0700] "GET /bootstrap/css/bootstrap.css HTTP/1.1" 404 1204
192.168.1.99 - - [31/May/2014:12:55:44 -0700] "GET /bootstrap/js/bootstrap.js HTTP/1.1" 404 1156
192.168.1.99 - - [31/May/2014:12:55:44 -0700] "GET /symfony/web/js/compiled/bottom_part_1_core_1.js HTTP/1.1" 200 157
192.168.1.99 - - [31/May/2014:12:55:45 -0700] "GET /bootstrap/js/bootstrap.js HTTP/1.1" 404 1156
192.168.1.99 - - [31/May/2014:12:55:45 -0700] "GET /symfony/web/_wdt/2bcf01 HTTP/1.1" 200 28709

Last edited by wolfdogg (2014-05-31 19:55:27)

garyamort · 2014-06-05 21:08:12

I've had problems with using php-fpm, hhvm, and xdebug on the same system.

All 3 of them default to using port 9000.

So either hhvm or php-fpm get the port first - and if xdebug is configured to try to automatically connect to a server it keeps making xdebug connections to the fastcgi server.

Rather then get trapped in troubleshooting it all, I just modify them all:
php-fpm using port 9100
hhvm uses port 9200
xdebug uses port 9300

Avoids getting stuck with weird conflicts.

Arch Linux

#1 2014-05-04 18:49:29

php-fpm proxy error

#2 2014-05-10 23:50:52

Re: php-fpm proxy error

#3 2014-05-11 09:33:12

Re: php-fpm proxy error

#4 2014-05-15 15:00:49

Re: php-fpm proxy error

#5 2014-05-15 16:19:37

Re: php-fpm proxy error

#6 2014-05-31 19:29:32

Re: php-fpm proxy error

#7 2014-06-05 21:08:12

Re: php-fpm proxy error

Board footer