You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@httpd.apache.org by "Carlucci, Tony" <ac...@mitre.org> on 2012/07/23 20:36:19 UTC

[users@httpd] Intermittent mod_proxy_ajp error - APR does not understand this error code: proxy: dialog

Hello, I've been trying to track down an intermittent problem with a Java web application that is running on tcServer fronted by Apache HTTP Server.    We get intermittent "Server Unavailable / HTTP 500" errors, and when we do see them, there is the same set of log statements written to the Apache HTTP Server error log:

[Mon Jul 23 10:03:15 2012] [error] (70014)End of file found: ajp_ilink_receive() can't receive header
[Mon Jul 23 10:03:15 2012] [error] ajp_read_header: ajp_ilink_receive failed
[Mon Jul 23 10:03:15 2012] [error] (120006)APR does not understand this error code: proxy: dialog to 127.0.0.1:7071 (127.0.0.1) failed

We are not seeing any error messages in the tcServer logs.

I believe the issue is with the mod_proxy_ajp module but it's been very difficult tracking down what exactly the problem is.   What's interesting is that this Apache / tcServer configuration is used with other applications that work just fine and never have the intermittent 500 error.   We also can run our application strictly in Tomcat (no Apache front) without any intermittent errors.

We haven't ruled out that there could be something in our Java application code that is causing this, in combination with the mod_proxy_ajp module, but we have hit a wall as to what this issue could be.  Has anyone else experienced a similar intermittent issue combined with the above error messages?  Below is a copy of the error log and some configuration settings.

Thanks, Tony

---------------------
Apache HTTP Error Log
---------------------
[Mon Jul 23 10:03:15 2012] [debug] mod_cache.c(141): Adding CACHE_SAVE filter for /myapp/
[Mon Jul 23 10:03:15 2012] [debug] mod_cache.c(148): Adding CACHE_REMOVE_URL filter for /myapp/
[Mon Jul 23 10:03:15 2012] [debug] mod_proxy_ajp.c(45): proxy: AJP: canonicalising URL //127.0.0.1:7071/myapp/
[Mon Jul 23 10:03:15 2012] [debug] proxy_util.c(1506): [client ***cleansed***] proxy: ajp: found worker ajp://127.0.0.1:7071/myapp for ajp://127.0.0.1:7071/myapp/
[Mon Jul 23 10:03:15 2012] [debug] mod_proxy.c(1020): Running scheme ajp handler (attempt 0)
[Mon Jul 23 10:03:15 2012] [debug] mod_proxy_http.c(1963): proxy: HTTP: declining URL ajp://127.0.0.1:7071/myapp/
[Mon Jul 23 10:03:15 2012] [debug] mod_proxy_ajp.c(681): proxy: AJP: serving URL ajp://127.0.0.1:7071/myapp/
[Mon Jul 23 10:03:15 2012] [debug] proxy_util.c(2011): proxy: AJP: has acquired connection for (127.0.0.1)
[Mon Jul 23 10:03:15 2012] [debug] proxy_util.c(2067): proxy: connecting ajp://127.0.0.1:7071/myapp/ to 127.0.0.1:7071
[Mon Jul 23 10:03:15 2012] [debug] proxy_util.c(2193): proxy: connected /myapp/ to 127.0.0.1:7071
[Mon Jul 23 10:03:15 2012] [debug] ajp_header.c(224): Into ajp_marshal_into_msgb
[Mon Jul 23 10:03:15 2012] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[0] [x-forwarded-for] = [***cleansed***]
[Mon Jul 23 10:03:15 2012] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[1] [Host] = [***cleansed***]
[Mon Jul 23 10:03:15 2012] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[2] [Connection] = [keep-alive]
[Mon Jul 23 10:03:15 2012] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[3] [User-Agent] = [Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/536.11 (KHTML, like Gecko) Chrome/20.0.1132.57 Safari/536.11]
[Mon Jul 23 10:03:15 2012] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[4] [Accept] = [text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8]
[Mon Jul 23 10:03:15 2012] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[5] [Accept-Encoding] = [gzip,deflate,sdch]
[Mon Jul 23 10:03:15 2012] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[6] [Accept-Language] = [en-US,en;q=0.8]
[Mon Jul 23 10:03:15 2012] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[7] [Accept-Charset] = [ISO-8859-1,utf-8;q=0.7,*;q=0.3]
[Mon Jul 23 10:03:15 2012] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[8] [Cookie] = [SSOTOKEN=***cleansed***]
[Mon Jul 23 10:03:15 2012] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[9] [SSO_LOGIN] = [***cleansed***]
[Mon Jul 23 10:03:15 2012] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[10] [SSO_ID] = [***cleansed***]
[Mon Jul 23 10:03:15 2012] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[11] [SSO_EMAIL] = [***cleansed***]
[Mon Jul 23 10:03:15 2012] [debug] ajp_header.c(450): ajp_marshal_into_msgb: Done
[Mon Jul 23 10:03:15 2012] [debug] mod_proxy_ajp.c(268): proxy: APR_BUCKET_IS_EOS
[Mon Jul 23 10:03:15 2012] [debug] mod_proxy_ajp.c(273): proxy: data to read (max 8186 at 4)
[Mon Jul 23 10:03:15 2012] [debug] mod_proxy_ajp.c(288): proxy: got 0 bytes of data
[Mon Jul 23 10:03:15 2012] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 03
[Mon Jul 23 10:03:15 2012] [debug] ajp_header.c(697): ajp_parse_type: got 03
[Mon Jul 23 10:03:15 2012] [debug] mod_proxy_ajp.c(460): Ignoring flush message received before headers
[Mon Jul 23 10:03:15 2012] [error] (70014)End of file found: ajp_ilink_receive() can't receive header
[Mon Jul 23 10:03:15 2012] [error] ajp_read_header: ajp_ilink_receive failed
[Mon Jul 23 10:03:15 2012] [debug] mod_proxy_ajp.c(549): (120006)APR does not understand this error code: ajp_read_header failed
[Mon Jul 23 10:03:15 2012] [debug] mod_proxy_ajp.c(564): proxy: Processing of request failed backend: 1, output: 0
[Mon Jul 23 10:03:15 2012] [error] (120006)APR does not understand this error code: proxy: dialog to 127.0.0.1:7071 (127.0.0.1) failed
[Mon Jul 23 10:03:15 2012] [debug] proxy_util.c(2029): proxy: AJP: has released connection for (127.0.0.1)
[Mon Jul 23 10:03:15 2012] [debug] mod_deflate.c(615): [***cleansed***] Zlib: Compressed 323 to 218 : URL /myapp/

---------------------------------
Apache HTTP Server (apachectl -V)
---------------------------------
Server version: Apache/2.2.22 (Unix)
Server built:   Jul 17 2012 17:20:28
Server's Module Magic Number: 20051115:30
Server loaded:  APR 1.4.5, APR-Util 1.4.1
Compiled using: APR 1.4.5, APR-Util 1.4.1
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 SINGLE_LISTEN_UNSERIALIZED_ACCEPT
-D APR_HAS_OTHER_CHILD
-D AP_HAVE_RELIABLE_PIPED_LOGS
-D DYNAMIC_MODULE_LIMIT=128
-D HTTPD_ROOT="/apps/apache2"
-D SUEXEC_BIN="/apps/apache2/bin/suexec"
-D DEFAULT_SCOREBOARD="logs/apache_runtime_status"
-D DEFAULT_ERRORLOG="logs/error_log"
-D AP_TYPES_CONFIG_FILE="conf/mime.types"
-D SERVER_CONFIG_FILE="conf/httpd.conf"

-------------------------------
httpd.conf (relevant settings):
-------------------------------
<IfModule worker.c>
StartServers 2
MaxClients 400
MinSpareThreads 25
MaxSpareThreads 75
ThreadsPerChild 25
MaxRequestsPerChild 10000
</IfModule>

ProxyRequests Off
ProxyPreserveHost on
ProxyReceiveBufferSize 0
ProxyErrorOverride Off
RewriteEngine on

ProxyPass /myapp ajp://127.0.0.1:7071/myapp
ProxyPassReverse /myapp ajp://127.0.0.1:7071/myapp

-----------------------------------------------
tcServer 2.0.4.RELEASE (Tomcat 6.0.29 binaries)
-----------------------------------------------
server.xml:

<Executor name="tomcatThreadPool" namePrefix="tomcat-ajp--" maxThreads="300" minSpareThreads="50"/>
<Connector executor="tomcatThreadPool"
               address="127.0.0.1"
               port="7071"
               protocol="org.apache.coyote.ajp.AjpAprProtocol"
               connectionTimeout="60000"
               redirectPort="8443"
               backlog="100"
               tcpNoDelay="true"
               enableLookups="false"
               URIEncoding="UTF-8" />






Re: [users@httpd] Intermittent mod_proxy_ajp error - APR does not understand this error code: proxy: dialog

Posted by Simone Caruso <in...@simonecaruso.com>.
On 25/07/2012 14:23, Carlucci, Tony wrote:
>> -----Original Message-----
>> From: Rainer Jung [mailto:rainer.jung@kippdata.de]
>> Sent: Wednesday, July 25, 2012 5:00 AM
>> To: users@httpd.apache.org
>> Subject: Re: [users@httpd] Intermittent mod_proxy_ajp error - APR does not
>> understand this error code: proxy: dialog
>>
>> On 23.07.2012 20:36, Carlucci, Tony wrote:
>>> Hello, I’ve been trying to track down an intermittent problem with a
>>> Java web application that is running on tcServer fronted by Apache HTTP
>>> Server.    We get intermittent “Server Unavailable / HTTP 500” errors,
>>> and when we do see them, there is the same set of log statements written
>>> to the Apache HTTP Server error log:
>>>
>>> [Mon Jul 23 10:03:15 2012] [error] (70014)End of file found:
>>> ajp_ilink_receive() can't receive header
>>>
>>> [Mon Jul 23 10:03:15 2012] [error] ajp_read_header: ajp_ilink_receive failed
>>>
>>> [Mon Jul 23 10:03:15 2012] [error] (120006)APR does not understand this
>>> error code: proxy: dialog to 127.0.0.1:7071 (127.0.0.1) failed
>>>
>>> We are not seeing any error messages in the tcServer logs.
>>>
>>> I believe the issue is with the mod_proxy_ajp module but it’s been very
>>> difficult tracking down what exactly the problem is.   What’s
>>> interesting is that this Apache / tcServer configuration is used with
>>> other applications that work just fine and never have the intermittent
>>> 500 error.   We also can run our application strictly in Tomcat (no
>>> Apache front) without any intermittent errors.
>>>
>>> We haven’t ruled out that there could be something in our Java
>>> application code that is causing this, in combination with the
>>> mod_proxy_ajp module, but we have hit a wall as to what this issue could
>>> be.  Has anyone else experienced a similar intermittent issue combined
>>> with the above error messages?  Below is a copy of the error log and
>>> some configuration settings.
>> You might want to check the following discussion thread:
>>
>>    http://marc.info/?t=123905265500007&r=1&w=2
>>
>> To actually narrow down the cause I would:
>>
>> - use ping as mentioned in the thread
>> - check whether the timeout you have set on the Tomcat connector is
>> roughly the same as used by mod_proxy_ajp
>> - check whether it looks like happening mostly for the same URL, then it
>> is more likely a servlet issue
>> - if it happens often enough sniff the traffic between Apache and Tomcat
>> and then check the packet details for one of the broken requests. For
>> this to work you might need to move Tomcat away from localhost.
>>
> Thanks for the suggestions Rainer, I'll give these a try.
>
> Tony


forget mod_proxy_ajp, use mod_jk

-- 
Simone Caruso
IT Consultant
+39 349 65 90 805


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org


RE: [users@httpd] Intermittent mod_proxy_ajp error - APR does not understand this error code: proxy: dialog

Posted by "Carlucci, Tony" <ac...@mitre.org>.
>-----Original Message-----
>From: Rainer Jung [mailto:rainer.jung@kippdata.de]
>Sent: Wednesday, July 25, 2012 5:00 AM
>To: users@httpd.apache.org
>Subject: Re: [users@httpd] Intermittent mod_proxy_ajp error - APR does not
>understand this error code: proxy: dialog
>
>On 23.07.2012 20:36, Carlucci, Tony wrote:
>> Hello, I’ve been trying to track down an intermittent problem with a
>> Java web application that is running on tcServer fronted by Apache HTTP
>> Server.    We get intermittent “Server Unavailable / HTTP 500” errors,
>> and when we do see them, there is the same set of log statements written
>> to the Apache HTTP Server error log:
>>
>> [Mon Jul 23 10:03:15 2012] [error] (70014)End of file found:
>> ajp_ilink_receive() can't receive header
>>
>> [Mon Jul 23 10:03:15 2012] [error] ajp_read_header: ajp_ilink_receive failed
>>
>> [Mon Jul 23 10:03:15 2012] [error] (120006)APR does not understand this
>> error code: proxy: dialog to 127.0.0.1:7071 (127.0.0.1) failed
>>
>> We are not seeing any error messages in the tcServer logs.
>>
>> I believe the issue is with the mod_proxy_ajp module but it’s been very
>> difficult tracking down what exactly the problem is.   What’s
>> interesting is that this Apache / tcServer configuration is used with
>> other applications that work just fine and never have the intermittent
>> 500 error.   We also can run our application strictly in Tomcat (no
>> Apache front) without any intermittent errors.
>>
>> We haven’t ruled out that there could be something in our Java
>> application code that is causing this, in combination with the
>> mod_proxy_ajp module, but we have hit a wall as to what this issue could
>> be.  Has anyone else experienced a similar intermittent issue combined
>> with the above error messages?  Below is a copy of the error log and
>> some configuration settings.
>
>You might want to check the following discussion thread:
>
>    http://marc.info/?t=123905265500007&r=1&w=2
>
>To actually narrow down the cause I would:
>
>- use ping as mentioned in the thread
>- check whether the timeout you have set on the Tomcat connector is
>roughly the same as used by mod_proxy_ajp
>- check whether it looks like happening mostly for the same URL, then it
>is more likely a servlet issue
>- if it happens often enough sniff the traffic between Apache and Tomcat
>and then check the packet details for one of the broken requests. For
>this to work you might need to move Tomcat away from localhost.
>

Thanks for the suggestions Rainer, I'll give these a try.

Tony

>Regards,
>
>Rainer
>
>---------------------------------------------------------------------
>To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
>For additional commands, e-mail: users-help@httpd.apache.org


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org

Re: [users@httpd] Intermittent mod_proxy_ajp error - APR does not understand this error code: proxy: dialog

Posted by Rainer Jung <ra...@kippdata.de>.
On 23.07.2012 20:36, Carlucci, Tony wrote:
> Hello, I’ve been trying to track down an intermittent problem with a
> Java web application that is running on tcServer fronted by Apache HTTP
> Server.    We get intermittent “Server Unavailable / HTTP 500” errors,
> and when we do see them, there is the same set of log statements written
> to the Apache HTTP Server error log:
>
> [Mon Jul 23 10:03:15 2012] [error] (70014)End of file found:
> ajp_ilink_receive() can't receive header
>
> [Mon Jul 23 10:03:15 2012] [error] ajp_read_header: ajp_ilink_receive failed
>
> [Mon Jul 23 10:03:15 2012] [error] (120006)APR does not understand this
> error code: proxy: dialog to 127.0.0.1:7071 (127.0.0.1) failed
>
> We are not seeing any error messages in the tcServer logs.
>
> I believe the issue is with the mod_proxy_ajp module but it’s been very
> difficult tracking down what exactly the problem is.   What’s
> interesting is that this Apache / tcServer configuration is used with
> other applications that work just fine and never have the intermittent
> 500 error.   We also can run our application strictly in Tomcat (no
> Apache front) without any intermittent errors.
>
> We haven’t ruled out that there could be something in our Java
> application code that is causing this, in combination with the
> mod_proxy_ajp module, but we have hit a wall as to what this issue could
> be.  Has anyone else experienced a similar intermittent issue combined
> with the above error messages?  Below is a copy of the error log and
> some configuration settings.

You might want to check the following discussion thread:

    http://marc.info/?t=123905265500007&r=1&w=2

To actually narrow down the cause I would:

- use ping as mentioned in the thread
- check whether the timeout you have set on the Tomcat connector is 
roughly the same as used by mod_proxy_ajp
- check whether it looks like happening mostly for the same URL, then it 
is more likely a servlet issue
- if it happens often enough sniff the traffic between Apache and Tomcat 
and then check the packet details for one of the broken requests. For 
this to work you might need to move Tomcat away from localhost.

Regards,

Rainer

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org