Link to home
Start Free TrialLog in
Avatar of LN N
LN N

asked on

Apache2 with PHP FPM Recurring Error

I have recently moved from using the default Apache2 Handler + mpm_prefork to FastCGI + mpm_event. Everything looks fine except for this error message that keeps appearing in the error.log every few minutes:

AH00524: Handler for fastcgi-script returned invalid result code 32

I have not been able to find more details or a solution for this problem.

On more thing is previously when I run an API call, I would receive a timeout (500 Internal Server Error) at 30s into the request. I updated the /etc/apache2/conf-available/php5-fpm.conf with -idle-timeout 300, and it would continue to run beyond 30s and return data properly.

However, after the API call completes I also see the same error:

AH00524: Handler for fastcgi-script returned invalid result code 32

What configuration could I be missing?
Thanks in advance!
Avatar of David Favor
David Favor
Flag of United States of America image

When I setup FPM, I setup deep logging of all accesses in access.log under a /var/log/php$ver-fpm directory.

I'd suggest you setup deep logging for both Apache + FPM.

Be sure you're running Apache-2.4.29 + mod_event + PHP-7.12 - because latest Apache fixes many HTTP2 + FPM (proxy) conversation problems.

Looking at your FPM access.log + Apache error.log will likely show up what's occurring.

You may have to increase your Apache verbosity, if PHP logs show nothing useful.
Bear in mind that there are different timeouts. There is the Apache timeout, which is for the initial request, then there's a timeout for the internal request to come back from FastCGI, and then finally there's the individual timeout / time limit on the script itself. The shortest one is going to be the first to hit.

The Apache Timeout:
https://httpd.apache.org/docs/2.4/mod/core.html#timeout

The FPM Timeout is the one you've set with " -idle-timeout 300"

And the PHP timeout can be set in either the php.ini file (for all scripts) or on a per-script basis with:
set_time_limit(#);  (where # is the number of seconds for the timeout, or zero to disable the PHP timeout)

The default Apache timeout is 60 seconds, and the default PHP time limit is 30 seconds, so if your script is aborting at 30 seconds, I'd suggest adding:
set_time_limit(0);
to the top of your PHP script and then trying again.

If it still fails, search your Apache config for the Timeout directive and make sure it hasn't been set to a lower-than-desired value (or set it yourself to match the FPM timeout).
Avatar of LN N
LN N

ASKER

@gr8gonzo I am aware of the different timeouts, and even before this I have already added the following:
/etc/php5/apache2/php.ini
max_execution_time            3600
max_input_time                  300
default_socket_timeout      3600

/etc/php5/fpm/php-fpm.conf
request_terminate_timeout = 3600s

/etc/php5/fpm/php.ini
default_socket_timeout = 3600

/etc/apache2/apache2.conf
Timeout 300

Yet it is still failing.
Avatar of LN N

ASKER

@David Favor Thank you, I will try that.
Just to avoid assumptions, have you restarted all the services to ensure your changes have taken effect?
Avatar of LN N

ASKER

Yes, I have.

I found these lines in the php5-fpm.log:

[04-Dec-2017 17:01:03] NOTICE: fpm is running, pid 5515
[04-Dec-2017 17:01:03] NOTICE: ready to handle connections
[04-Dec-2017 17:01:03] NOTICE: systemd monitor interval set to 10000ms
[04-Dec-2017 17:04:07] NOTICE: Terminating ...
[04-Dec-2017 17:04:07] NOTICE: exiting, bye-bye!
[04-Dec-2017 17:08:53] NOTICE: fpm is running, pid 6343
[04-Dec-2017 17:08:53] NOTICE: ready to handle connections
[04-Dec-2017 17:08:53] NOTICE: systemd monitor interval set to 10000ms
[04-Dec-2017 17:08:55] NOTICE: Terminating ...
[04-Dec-2017 17:08:55] NOTICE: exiting, bye-bye!
[04-Dec-2017 17:08:55] NOTICE: fpm is running, pid 7318
[04-Dec-2017 17:08:55] NOTICE: ready to handle connections
[04-Dec-2017 17:08:55] NOTICE: systemd monitor interval set to 10000ms
[05-Dec-2017 10:36:53] NOTICE: Terminating ...
[05-Dec-2017 10:36:53] NOTICE: exiting, bye-bye!
[05-Dec-2017 10:36:53] NOTICE: fpm is running, pid 26264
[05-Dec-2017 10:36:53] NOTICE: ready to handle connections
[05-Dec-2017 10:36:53] NOTICE: systemd monitor interval set to 10000ms
[05-Dec-2017 10:36:55] NOTICE: Terminating ...
[05-Dec-2017 10:36:55] NOTICE: exiting, bye-bye!
[05-Dec-2017 10:36:55] NOTICE: fpm is running, pid 26910
[05-Dec-2017 10:36:55] NOTICE: ready to handle connections
[05-Dec-2017 10:36:55] NOTICE: systemd monitor interval set to 10000ms
[05-Dec-2017 11:15:01] WARNING: [pool www] server reached pm.max_children setting (5), consider raising it
[05-Dec-2017 11:37:03] WARNING: [pool www] server reached pm.max_children setting (5), consider raising it
[05-Dec-2017 12:15:04] WARNING: [pool www] server reached pm.max_children setting (5), consider raising it
[05-Dec-2017 15:42:43] NOTICE: Terminating ...
[05-Dec-2017 15:42:43] NOTICE: exiting, bye-bye!

Do you have any idea why it keeps terminating?
Do the terminations correspond with any requests in the Apache log?
And do you have the PHP engine logging turned on?
Avatar of LN N

ASKER

I have updated the /etc/php5/fpm/pool.d/www.conf with the following settings --
pm = dynamic
pm.max_children = 72
pm.start_servers = 16
pm.min_spare_servers = 8
pm.max_spare_servers = 32
pm.max_requests = 1000
-- and it seems to work great, but when I run an API call that would take longer than 30 - 40 seconds to complete, I get an empty payload (200 OK) at 30 - 40 seconds.

I know this is a FastCGI timeout, but I don't know how to increase it.

I am trying to find a setting similar to what I found here --
https://httpd.apache.org/mod_fcgid/mod/mod_fcgid.html (FcgidIOTimeout Directive)
https://stackoverflow.com/questions/13905004/how-to-fix-fastcgi-timeout-issues-in-plesk
-- but those look slightly different.

I do not have a /etc/apache2/mods-available/fcgid.conf, but I do have a /etc/apache2/mods-enabled/fastcgi.conf file.
None of the php5-fpm.log output, including the [05-Dec-2017 12:15:04] WARNING: [pool www] server reached pm.max_children setting (5), consider raising it should cause any errors.

Reading through postings about this, it appears this relates to some Apache as the error relates to...

AH00524 - Handler for (null) returned invalid result code - which basically means Apache seems to have somehow overwritten some internal data structure + lost it's FPM connection.

This fix appears to be upgrade Apache, as this problem seems to disappear in more recent versions of Apache.

Latest version of Apache is 2.4.29 + one patch set (hence the "-1" in current Ubuntu packaging).

lxd: net11-david-favor # dpkg -l | grep apache
ii  apache2                                    2.4.29-1+ubuntu17.04.1+deb.sury.org+1                    amd64        Apache HTTP Server
ii  apache2-bin                                2.4.29-1+ubuntu17.04.1+deb.sury.org+1                    amd64        Apache HTTP Server (modules and other binary files)
ii  apache2-data                               2.4.29-1+ubuntu17.04.1+deb.sury.org+1                    all          Apache HTTP Server (common files)
ii  apache2-utils                              2.4.29-1+ubuntu17.04.1+deb.sury.org+1                    amd64        Apache HTTP Server (utility programs for web servers)
ii  libapache2-mod-geoip                       1.2.10-1   

Open in new window


Try installing latest Apache + my guess is your problem will magically resolve.
This question needs an answer!
Become an EE member today
7 DAY FREE TRIAL
Members can start a 7-Day Free trial then enjoy unlimited access to the platform.
View membership options
or
Learn why we charge membership fees
We get it - no one likes a content blocker. Take one extra minute and find out why we block content.