You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@httpd.apache.org by SpliFF <sp...@warriorhut.org> on 2011/10/28 08:49:27 UTC
[users@httpd] AJP proxy timeout problem
I've having an issue where a long-running backend script behind AJP is causing apache to error with "Service Temporarily
Unavailable" after exactly 5 minutes.
I tried to solve this by moving from mod_rewrite to mod_proxy, with the following configuration:
# Search Engine Safe URL rewrite
# Redirect Coldfusion requests to index.cfm
# matches /file.mp4 but not /file:name.mp4 (ie; is a real file)
RewriteCond %{REQUEST_FILENAME} !/[^/:]+\.[^/:]{2,5}$
RewriteRule (.*) /index.cfm$1 [PT]
# Proxy CFML files to Jetty via AJP connector
<Proxy *>
Allow from 127.0.0.1
</Proxy>
ProxyPreserveHost On
ProxyRequests Off
ProxyPassMatch ^/(.+\.cf[cm])(/.*)?$ ajp://localhost:8009/$1$2 connectiontimeout=6000 timeout=6000
If I'm not mistaken those timeouts are in seconds so AJP should be waiting at least 100 minutes.
I also made sure the Railo backend would wait long enough, using the following CFML tag:
<cfsetting requesttimeout=6000 />
I checked the Jetty (Application server) config but there doesn't seem to be any timeout options.
The apache error log (with debugging) says:
[Fri Oct 28 15:28:45 2011] [debug] mod_proxy_ajp.c(45): proxy: AJP: canonicalising URL
//localhost:8009/index.cfm/subscribers/importold
[Fri Oct 28 15:28:45 2011] [debug] proxy_util.c(1525): [client 192.168.1.60] proxy: *: found reverse proxy worker for
ajp://localhost:8009/index.cfm/subscribers/importold
[Fri Oct 28 15:28:45 2011] [debug] mod_proxy.c(1015): Running scheme ajp handler (attempt 0)
[Fri Oct 28 15:28:45 2011] [debug] mod_proxy_ajp.c(659): proxy: AJP: serving URL
ajp://localhost:8009/index.cfm/subscribers/importold
[Fri Oct 28 15:28:45 2011] [debug] proxy_util.c(2011): proxy: AJP: has acquired connection for (*)
[Fri Oct 28 15:28:45 2011] [debug] proxy_util.c(2067): proxy: connecting
ajp://localhost:8009/index.cfm/subscribers/importold to localhost:8009
[Fri Oct 28 15:28:45 2011] [debug] proxy_util.c(2193): proxy: connected /index.cfm/subscribers/importold to localhost:8009
[Fri Oct 28 15:28:45 2011] [debug] proxy_util.c(2444): proxy: AJP: fam 2 socket created to connect to *
[Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(224): Into ajp_marshal_into_msgb
[Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[0] [Host] =
[users.arcmail.betamax.arc.net.au]
[Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[1] [User-Agent] = [Mozilla/5.0 (X11;
Linux x86_64; rv:7.0.1) Gecko/20100101 Firefox/7.0.1]
[Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[2] [Accept] =
[text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8]
[Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[3] [Accept-Language] = [en-us,en;q=0.5]
[Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[4] [Accept-Encoding] = [gzip, deflate]
[Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[5] [Accept-Charset] =
[ISO-8859-1,utf-8;q=0.7,*;q=0.7]
[Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[6] [DNT] = [1]
[Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[7] [Connection] = [keep-alive]
[Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[8] [Cookie] =
[CFID=d5b4b21d-bea4-4875-b2f3-7dc003c7fa64; CFTOKEN=0; FW_BUGZ=; RAILO_ADMIN_LANG=en; RAILO_ADMIN_LASTPAGE=server.cache]
[Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(450): ajp_marshal_into_msgb: Done
[Fri Oct 28 15:28:45 2011] [debug] mod_proxy_ajp.c(265): proxy: APR_BUCKET_IS_EOS
[Fri Oct 28 15:28:45 2011] [debug] mod_proxy_ajp.c(270): proxy: data to read (max 8186 at 4)
[Fri Oct 28 15:28:45 2011] [debug] mod_proxy_ajp.c(285): proxy: got 0 bytes of data
[Fri Oct 28 15:28:46 2011] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 06
[Fri Oct 28 15:28:46 2011] [debug] ajp_header.c(697): ajp_parse_type: got 06
[Fri Oct 28 15:33:46 2011] [error] ajp_read_header: ajp_ilink_receive failed
[Fri Oct 28 15:33:46 2011] [debug] mod_proxy_ajp.c(531): (120006)APR does not understand this error code:
ajp_read_header failed
[Fri Oct 28 15:33:46 2011] [debug] mod_proxy_ajp.c(546): proxy: Processing of request failed backend: 1, output: 0
[Fri Oct 28 15:33:46 2011] [error] (120006)APR does not understand this error code: proxy: dialog to (null) (*) failed
[Fri Oct 28 15:33:46 2011] [debug] proxy_util.c(2029): proxy: AJP: has released connection for (*)
Note the delay between "ajp_parse_type: got 06" and "ajp_ilink_receive failed" is 5 minutes accurate to the second. I
read somewhere that 5 minutes is the default timeout for mod_proxy so my suspicion is the timeout settings are being
ignored. The only other theory I have is that the [PT] flag on the first rewrite rule is causing those values to be ignored.
---------------------------------------------------------------------
The official User-To-User support forum of the Apache HTTP Server Project.
See <URL:http://httpd.apache.org/userslist.html> for more info.
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
" from the digest: users-digest-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org
Re: [users@httpd] AJP proxy timeout problem
Posted by Rainer Jung <ra...@kippdata.de>.
On 29.10.2011 10:21, SpliFF wrote:
> 2.2.20 running on Gentoo 64-bit.
>
> Server version: Apache/2.2.20 (Unix)
> Server built: Sep 22 2011 02:42:57
> Server's Module Magic Number: 20051115:28
> Server loaded: APR 1.4.5, APR-Util 1.3.12
> Compiled using: APR 1.4.5, APR-Util 1.3.12
> Architecture: 64-bit
> Server MPM: Worker
> threaded: yes (fixed thread count)
> forked: yes (variable process count)
> Server compiled with....
> -D APACHE_MPM_DIR="server/mpm/worker"
> -D APR_HAS_SENDFILE
> -D APR_HAS_MMAP
> -D APR_HAVE_IPV6 (IPv4-mapped addresses enabled)
> -D APR_USE_SYSVSEM_SERIALIZE
> -D APR_USE_PTHREAD_SERIALIZE
> -D APR_HAS_OTHER_CHILD
> -D AP_HAVE_RELIABLE_PIPED_LOGS
> -D DYNAMIC_MODULE_LIMIT=128
> -D HTTPD_ROOT="/usr"
> -D SUEXEC_BIN="/usr/sbin/suexec"
> -D DEFAULT_SCOREBOARD="logs/apache_runtime_status"
> -D DEFAULT_ERRORLOG="logs/error_log"
> -D AP_TYPES_CONFIG_FILE="/etc/apache2/mime.types"
> -D SERVER_CONFIG_FILE="/etc/apache2/httpd.conf"
>
>
> On 28/10/11 19:16, Rainer Jung wrote:
>> Which version of httpd?
>>
>> On 28.10.2011 08:49, SpliFF wrote:
>>> I've having an issue where a long-running backend script behind AJP is causing apache to error with "Service Temporarily
>>> Unavailable" after exactly 5 minutes.
>>>
>>> I tried to solve this by moving from mod_rewrite to mod_proxy, with the following configuration:
>>>
>>> # Search Engine Safe URL rewrite
>>> # Redirect Coldfusion requests to index.cfm
>>> # matches /file.mp4 but not /file:name.mp4 (ie; is a real file)
>>> RewriteCond %{REQUEST_FILENAME} !/[^/:]+\.[^/:]{2,5}$
>>> RewriteRule (.*) /index.cfm$1 [PT]
>>>
>>> # Proxy CFML files to Jetty via AJP connector
>>> <Proxy *>
>>> Allow from 127.0.0.1
>>> </Proxy>
>>> ProxyPreserveHost On
>>> ProxyRequests Off
>>> ProxyPassMatch ^/(.+\.cf[cm])(/.*)?$ ajp://localhost:8009/$1$2 connectiontimeout=6000 timeout=6000
>>>
>>>
>>> If I'm not mistaken those timeouts are in seconds so AJP should be waiting at least 100 minutes.
>>>
>>> I also made sure the Railo backend would wait long enough, using the following CFML tag:
>>>
>>> <cfsetting requesttimeout=6000 />
>>>
>>> I checked the Jetty (Application server) config but there doesn't seem to be any timeout options.
>>>
>>> The apache error log (with debugging) says:
>>>
>>> [Fri Oct 28 15:28:45 2011] [debug] mod_proxy_ajp.c(45): proxy: AJP: canonicalising URL
>>> //localhost:8009/index.cfm/subscribers/importold
>>> [Fri Oct 28 15:28:45 2011] [debug] proxy_util.c(1525): [client 192.168.1.60] proxy: *: found reverse proxy worker for
>>> ajp://localhost:8009/index.cfm/subscribers/importold
>>> [Fri Oct 28 15:28:45 2011] [debug] mod_proxy.c(1015): Running scheme ajp handler (attempt 0)
>>> [Fri Oct 28 15:28:45 2011] [debug] mod_proxy_ajp.c(659): proxy: AJP: serving URL
>>> ajp://localhost:8009/index.cfm/subscribers/importold
>>> [Fri Oct 28 15:28:45 2011] [debug] proxy_util.c(2011): proxy: AJP: has acquired connection for (*)
>>> [Fri Oct 28 15:28:45 2011] [debug] proxy_util.c(2067): proxy: connecting
>>> ajp://localhost:8009/index.cfm/subscribers/importold to localhost:8009
>>> [Fri Oct 28 15:28:45 2011] [debug] proxy_util.c(2193): proxy: connected /index.cfm/subscribers/importold to localhost:8009
>>> [Fri Oct 28 15:28:45 2011] [debug] proxy_util.c(2444): proxy: AJP: fam 2 socket created to connect to *
>>> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(224): Into ajp_marshal_into_msgb
>>> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[0] [Host] =
>>> [users.arcmail.betamax.arc.net.au]
>>> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[1] [User-Agent] = [Mozilla/5.0 (X11;
>>> Linux x86_64; rv:7.0.1) Gecko/20100101 Firefox/7.0.1]
>>> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[2] [Accept] =
>>> [text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8]
>>> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[3] [Accept-Language] = [en-us,en;q=0.5]
>>> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[4] [Accept-Encoding] = [gzip, deflate]
>>> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[5] [Accept-Charset] =
>>> [ISO-8859-1,utf-8;q=0.7,*;q=0.7]
>>> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[6] [DNT] = [1]
>>> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[7] [Connection] = [keep-alive]
>>> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[8] [Cookie] =
>>> [CFID=d5b4b21d-bea4-4875-b2f3-7dc003c7fa64; CFTOKEN=0; FW_BUGZ=; RAILO_ADMIN_LANG=en; RAILO_ADMIN_LASTPAGE=server.cache]
>>> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(450): ajp_marshal_into_msgb: Done
>>> [Fri Oct 28 15:28:45 2011] [debug] mod_proxy_ajp.c(265): proxy: APR_BUCKET_IS_EOS
>>> [Fri Oct 28 15:28:45 2011] [debug] mod_proxy_ajp.c(270): proxy: data to read (max 8186 at 4)
>>> [Fri Oct 28 15:28:45 2011] [debug] mod_proxy_ajp.c(285): proxy: got 0 bytes of data
>>> [Fri Oct 28 15:28:46 2011] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 06
>>> [Fri Oct 28 15:28:46 2011] [debug] ajp_header.c(697): ajp_parse_type: got 06
>>> [Fri Oct 28 15:33:46 2011] [error] ajp_read_header: ajp_ilink_receive failed
>>> [Fri Oct 28 15:33:46 2011] [debug] mod_proxy_ajp.c(531): (120006)APR does not understand this error code:
>>> ajp_read_header failed
>>> [Fri Oct 28 15:33:46 2011] [debug] mod_proxy_ajp.c(546): proxy: Processing of request failed backend: 1, output: 0
>>> [Fri Oct 28 15:33:46 2011] [error] (120006)APR does not understand this error code: proxy: dialog to (null) (*) failed
>>> [Fri Oct 28 15:33:46 2011] [debug] proxy_util.c(2029): proxy: AJP: has released connection for (*)
>>>
>>> Note the delay between "ajp_parse_type: got 06" and "ajp_ilink_receive failed" is 5 minutes accurate to the second. I
>>> read somewhere that 5 minutes is the default timeout for mod_proxy so my suspicion is the timeout settings are being
>>> ignored. The only other theory I have is that the [PT] flag on the first rewrite rule is causing those values to be ignored.
Did you truncate the log output? There seems to be helpful lines missing.
In addition: what kind of inf did you relace by "*"? It is fine to
replace confidential info, but in some places I would have just expected
something like "localhost" where you put "*". So I wonder whether there
are other proxy workers defined in the configuration apart from the ones
you have shown us?
I checked the code again, mod_proxy_ajp.c constructs the connection
using ap_proxy_connect_backend() which explicitely uses the worker
timeouts if set and only falls back to the proxy or server timeouts if
no worker timeout is set.
Regards,
Rainer
---------------------------------------------------------------------
The official User-To-User support forum of the Apache HTTP Server Project.
See <URL:http://httpd.apache.org/userslist.html> for more info.
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
" from the digest: users-digest-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org
Re: [users@httpd] AJP proxy timeout problem
Posted by SpliFF <sp...@warriorhut.org>.
2.2.20 running on Gentoo 64-bit.
Server version: Apache/2.2.20 (Unix)
Server built: Sep 22 2011 02:42:57
Server's Module Magic Number: 20051115:28
Server loaded: APR 1.4.5, APR-Util 1.3.12
Compiled using: APR 1.4.5, APR-Util 1.3.12
Architecture: 64-bit
Server MPM: Worker
threaded: yes (fixed thread count)
forked: yes (variable process count)
Server compiled with....
-D APACHE_MPM_DIR="server/mpm/worker"
-D APR_HAS_SENDFILE
-D APR_HAS_MMAP
-D APR_HAVE_IPV6 (IPv4-mapped addresses enabled)
-D APR_USE_SYSVSEM_SERIALIZE
-D APR_USE_PTHREAD_SERIALIZE
-D APR_HAS_OTHER_CHILD
-D AP_HAVE_RELIABLE_PIPED_LOGS
-D DYNAMIC_MODULE_LIMIT=128
-D HTTPD_ROOT="/usr"
-D SUEXEC_BIN="/usr/sbin/suexec"
-D DEFAULT_SCOREBOARD="logs/apache_runtime_status"
-D DEFAULT_ERRORLOG="logs/error_log"
-D AP_TYPES_CONFIG_FILE="/etc/apache2/mime.types"
-D SERVER_CONFIG_FILE="/etc/apache2/httpd.conf"
On 28/10/11 19:16, Rainer Jung wrote:
> Which version of httpd?
>
> On 28.10.2011 08:49, SpliFF wrote:
>> I've having an issue where a long-running backend script behind AJP is causing apache to error with "Service Temporarily
>> Unavailable" after exactly 5 minutes.
>>
>> I tried to solve this by moving from mod_rewrite to mod_proxy, with the following configuration:
>>
>> # Search Engine Safe URL rewrite
>> # Redirect Coldfusion requests to index.cfm
>> # matches /file.mp4 but not /file:name.mp4 (ie; is a real file)
>> RewriteCond %{REQUEST_FILENAME} !/[^/:]+\.[^/:]{2,5}$
>> RewriteRule (.*) /index.cfm$1 [PT]
>>
>> # Proxy CFML files to Jetty via AJP connector
>> <Proxy *>
>> Allow from 127.0.0.1
>> </Proxy>
>> ProxyPreserveHost On
>> ProxyRequests Off
>> ProxyPassMatch ^/(.+\.cf[cm])(/.*)?$ ajp://localhost:8009/$1$2 connectiontimeout=6000 timeout=6000
>>
>>
>> If I'm not mistaken those timeouts are in seconds so AJP should be waiting at least 100 minutes.
>>
>> I also made sure the Railo backend would wait long enough, using the following CFML tag:
>>
>> <cfsetting requesttimeout=6000 />
>>
>> I checked the Jetty (Application server) config but there doesn't seem to be any timeout options.
>>
>> The apache error log (with debugging) says:
>>
>> [Fri Oct 28 15:28:45 2011] [debug] mod_proxy_ajp.c(45): proxy: AJP: canonicalising URL
>> //localhost:8009/index.cfm/subscribers/importold
>> [Fri Oct 28 15:28:45 2011] [debug] proxy_util.c(1525): [client 192.168.1.60] proxy: *: found reverse proxy worker for
>> ajp://localhost:8009/index.cfm/subscribers/importold
>> [Fri Oct 28 15:28:45 2011] [debug] mod_proxy.c(1015): Running scheme ajp handler (attempt 0)
>> [Fri Oct 28 15:28:45 2011] [debug] mod_proxy_ajp.c(659): proxy: AJP: serving URL
>> ajp://localhost:8009/index.cfm/subscribers/importold
>> [Fri Oct 28 15:28:45 2011] [debug] proxy_util.c(2011): proxy: AJP: has acquired connection for (*)
>> [Fri Oct 28 15:28:45 2011] [debug] proxy_util.c(2067): proxy: connecting
>> ajp://localhost:8009/index.cfm/subscribers/importold to localhost:8009
>> [Fri Oct 28 15:28:45 2011] [debug] proxy_util.c(2193): proxy: connected /index.cfm/subscribers/importold to localhost:8009
>> [Fri Oct 28 15:28:45 2011] [debug] proxy_util.c(2444): proxy: AJP: fam 2 socket created to connect to *
>> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(224): Into ajp_marshal_into_msgb
>> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[0] [Host] =
>> [users.arcmail.betamax.arc.net.au]
>> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[1] [User-Agent] = [Mozilla/5.0 (X11;
>> Linux x86_64; rv:7.0.1) Gecko/20100101 Firefox/7.0.1]
>> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[2] [Accept] =
>> [text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8]
>> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[3] [Accept-Language] = [en-us,en;q=0.5]
>> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[4] [Accept-Encoding] = [gzip, deflate]
>> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[5] [Accept-Charset] =
>> [ISO-8859-1,utf-8;q=0.7,*;q=0.7]
>> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[6] [DNT] = [1]
>> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[7] [Connection] = [keep-alive]
>> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[8] [Cookie] =
>> [CFID=d5b4b21d-bea4-4875-b2f3-7dc003c7fa64; CFTOKEN=0; FW_BUGZ=; RAILO_ADMIN_LANG=en; RAILO_ADMIN_LASTPAGE=server.cache]
>> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(450): ajp_marshal_into_msgb: Done
>> [Fri Oct 28 15:28:45 2011] [debug] mod_proxy_ajp.c(265): proxy: APR_BUCKET_IS_EOS
>> [Fri Oct 28 15:28:45 2011] [debug] mod_proxy_ajp.c(270): proxy: data to read (max 8186 at 4)
>> [Fri Oct 28 15:28:45 2011] [debug] mod_proxy_ajp.c(285): proxy: got 0 bytes of data
>> [Fri Oct 28 15:28:46 2011] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 06
>> [Fri Oct 28 15:28:46 2011] [debug] ajp_header.c(697): ajp_parse_type: got 06
>> [Fri Oct 28 15:33:46 2011] [error] ajp_read_header: ajp_ilink_receive failed
>> [Fri Oct 28 15:33:46 2011] [debug] mod_proxy_ajp.c(531): (120006)APR does not understand this error code:
>> ajp_read_header failed
>> [Fri Oct 28 15:33:46 2011] [debug] mod_proxy_ajp.c(546): proxy: Processing of request failed backend: 1, output: 0
>> [Fri Oct 28 15:33:46 2011] [error] (120006)APR does not understand this error code: proxy: dialog to (null) (*) failed
>> [Fri Oct 28 15:33:46 2011] [debug] proxy_util.c(2029): proxy: AJP: has released connection for (*)
>>
>> Note the delay between "ajp_parse_type: got 06" and "ajp_ilink_receive failed" is 5 minutes accurate to the second. I
>> read somewhere that 5 minutes is the default timeout for mod_proxy so my suspicion is the timeout settings are being
>> ignored. The only other theory I have is that the [PT] flag on the first rewrite rule is causing those values to be ignored.
> ---------------------------------------------------------------------
> The official User-To-User support forum of the Apache HTTP Server Project.
> See <URL:http://httpd.apache.org/userslist.html> for more info.
> To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
> " from the digest: users-digest-unsubscribe@httpd.apache.org
> For additional commands, e-mail: users-help@httpd.apache.org
>
---------------------------------------------------------------------
The official User-To-User support forum of the Apache HTTP Server Project.
See <URL:http://httpd.apache.org/userslist.html> for more info.
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
" from the digest: users-digest-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org
Re: [users@httpd] AJP proxy timeout problem
Posted by Rainer Jung <ra...@kippdata.de>.
Which version of httpd?
On 28.10.2011 08:49, SpliFF wrote:
> I've having an issue where a long-running backend script behind AJP is causing apache to error with "Service Temporarily
> Unavailable" after exactly 5 minutes.
>
> I tried to solve this by moving from mod_rewrite to mod_proxy, with the following configuration:
>
> # Search Engine Safe URL rewrite
> # Redirect Coldfusion requests to index.cfm
> # matches /file.mp4 but not /file:name.mp4 (ie; is a real file)
> RewriteCond %{REQUEST_FILENAME} !/[^/:]+\.[^/:]{2,5}$
> RewriteRule (.*) /index.cfm$1 [PT]
>
> # Proxy CFML files to Jetty via AJP connector
> <Proxy *>
> Allow from 127.0.0.1
> </Proxy>
> ProxyPreserveHost On
> ProxyRequests Off
> ProxyPassMatch ^/(.+\.cf[cm])(/.*)?$ ajp://localhost:8009/$1$2 connectiontimeout=6000 timeout=6000
>
>
> If I'm not mistaken those timeouts are in seconds so AJP should be waiting at least 100 minutes.
>
> I also made sure the Railo backend would wait long enough, using the following CFML tag:
>
> <cfsetting requesttimeout=6000 />
>
> I checked the Jetty (Application server) config but there doesn't seem to be any timeout options.
>
> The apache error log (with debugging) says:
>
> [Fri Oct 28 15:28:45 2011] [debug] mod_proxy_ajp.c(45): proxy: AJP: canonicalising URL
> //localhost:8009/index.cfm/subscribers/importold
> [Fri Oct 28 15:28:45 2011] [debug] proxy_util.c(1525): [client 192.168.1.60] proxy: *: found reverse proxy worker for
> ajp://localhost:8009/index.cfm/subscribers/importold
> [Fri Oct 28 15:28:45 2011] [debug] mod_proxy.c(1015): Running scheme ajp handler (attempt 0)
> [Fri Oct 28 15:28:45 2011] [debug] mod_proxy_ajp.c(659): proxy: AJP: serving URL
> ajp://localhost:8009/index.cfm/subscribers/importold
> [Fri Oct 28 15:28:45 2011] [debug] proxy_util.c(2011): proxy: AJP: has acquired connection for (*)
> [Fri Oct 28 15:28:45 2011] [debug] proxy_util.c(2067): proxy: connecting
> ajp://localhost:8009/index.cfm/subscribers/importold to localhost:8009
> [Fri Oct 28 15:28:45 2011] [debug] proxy_util.c(2193): proxy: connected /index.cfm/subscribers/importold to localhost:8009
> [Fri Oct 28 15:28:45 2011] [debug] proxy_util.c(2444): proxy: AJP: fam 2 socket created to connect to *
> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(224): Into ajp_marshal_into_msgb
> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[0] [Host] =
> [users.arcmail.betamax.arc.net.au]
> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[1] [User-Agent] = [Mozilla/5.0 (X11;
> Linux x86_64; rv:7.0.1) Gecko/20100101 Firefox/7.0.1]
> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[2] [Accept] =
> [text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8]
> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[3] [Accept-Language] = [en-us,en;q=0.5]
> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[4] [Accept-Encoding] = [gzip, deflate]
> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[5] [Accept-Charset] =
> [ISO-8859-1,utf-8;q=0.7,*;q=0.7]
> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[6] [DNT] = [1]
> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[7] [Connection] = [keep-alive]
> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[8] [Cookie] =
> [CFID=d5b4b21d-bea4-4875-b2f3-7dc003c7fa64; CFTOKEN=0; FW_BUGZ=; RAILO_ADMIN_LANG=en; RAILO_ADMIN_LASTPAGE=server.cache]
> [Fri Oct 28 15:28:45 2011] [debug] ajp_header.c(450): ajp_marshal_into_msgb: Done
> [Fri Oct 28 15:28:45 2011] [debug] mod_proxy_ajp.c(265): proxy: APR_BUCKET_IS_EOS
> [Fri Oct 28 15:28:45 2011] [debug] mod_proxy_ajp.c(270): proxy: data to read (max 8186 at 4)
> [Fri Oct 28 15:28:45 2011] [debug] mod_proxy_ajp.c(285): proxy: got 0 bytes of data
> [Fri Oct 28 15:28:46 2011] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 06
> [Fri Oct 28 15:28:46 2011] [debug] ajp_header.c(697): ajp_parse_type: got 06
> [Fri Oct 28 15:33:46 2011] [error] ajp_read_header: ajp_ilink_receive failed
> [Fri Oct 28 15:33:46 2011] [debug] mod_proxy_ajp.c(531): (120006)APR does not understand this error code:
> ajp_read_header failed
> [Fri Oct 28 15:33:46 2011] [debug] mod_proxy_ajp.c(546): proxy: Processing of request failed backend: 1, output: 0
> [Fri Oct 28 15:33:46 2011] [error] (120006)APR does not understand this error code: proxy: dialog to (null) (*) failed
> [Fri Oct 28 15:33:46 2011] [debug] proxy_util.c(2029): proxy: AJP: has released connection for (*)
>
> Note the delay between "ajp_parse_type: got 06" and "ajp_ilink_receive failed" is 5 minutes accurate to the second. I
> read somewhere that 5 minutes is the default timeout for mod_proxy so my suspicion is the timeout settings are being
> ignored. The only other theory I have is that the [PT] flag on the first rewrite rule is causing those values to be ignored.
---------------------------------------------------------------------
The official User-To-User support forum of the Apache HTTP Server Project.
See <URL:http://httpd.apache.org/userslist.html> for more info.
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
" from the digest: users-digest-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org