httpd-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Carlucci, Tony" <acarlu...@mitre.org>
Subject [users@httpd] Intermittent mod_proxy_ajp error - APR does not understand this error code: proxy: dialog
Date Mon, 23 Jul 2012 18:36:19 GMT
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" />






Mime
View raw message