Question on mod_jk and tomcat

[chris derham <ch...@derham.me.uk>]

All,

We have apache running on Windows Web Server 2008 R2, fronting tomcat. We
use mod_jk to connect. We see these kind of log messages in mod_jk logs.
What do they mean?

[Thu Jul 28 12:30:56 2011] [14264:10144] [info] jk_ajp_common.c (1882):
Writing to client aborted or client network problems
[Thu Jul 28 12:30:56 2011] [14264:10144] [info] jk_ajp_common.c (2540):
(workerXtsRbge) sending request to tomcat failed (unrecoverable), because of
client write error (attempt=1)

   - Specifically what is the client here? The browser that called apache,
   or mod_jk as a client of tomcat?
   - What do the numbers in brackets mean [14264:10144] - bytes and time?
   - Does this mean that the browser was sent a http 500?
   - Is there a way that I can get the uniqueId logged along with these
   lines to make correlating the access and mod_)jk log easier?
   - I think I read somewhere that by default mod_jk will try a tomcat call
   once, and if that fails try again before giving up. Does the "attempt=1"
   mean this is the result of the first attempt or is it the result of the
   second (e.g. 0 based)? I assume that in the absence of a attempt=0 this must
   mean that the first attempt failed, and therefore assume that the second
   succeeded. Is this a fair assumption?

Under jkstatus I see Err and CE. From the legend Err means "Number of failed
requests" and CE is "Number of client errors".

Apache 2.2.17 - httpd.conf

    LoadModule    jk_module  modules/mod_jk.so
    JkWorkersFile d:/apps/Apache2.2/conf/workers.properties
    JkShmFile     d:/apps/Apache2.2/temp/mod_jk.shm
    JkLogFile     "|d:/apps/Apache2.2/bin/cronolog.exe
logs/mod_jk.%Y%m%d.log"
    JkLogLevel    info
    JkLogStampFormat "[%a %b %d %H:%M:%S %Y] "
    JkExtractSSL On
    JkHTTPSIndicator HTTPS
    JkSESSIONIndicator SSL_SESSION_ID
    JkCIPHERIndicator SSL_CIPHER
    JkCERTSIndicator SSL_CLIENT_CERT
    JkEnvVar UNIQUE_ID unknown
    JkEnvVar SSL_CLIENT_V_START

Then within a virtual host element

    JkMount  /* workerXtsRbge
    JkUnMount /index.html workerXtsRbge
    JkUnMount /ie6unsupported.html workerXtsRbge

mod_jk v1.2.30 - worker.properties

  worker.list=mystatus, workerXtsRbge

  worker.template.type=ajp13
  worker.template.host=localhost
  worker.template.ping_timeout=1000
  worker.template.ping_mode=A

  worker.workerXtsRbge.reference=worker.template
  worker.workerXtsRbge.port=8010

Tomcat v7.0.12 - server.xml

    <Connector port="8010" protocol="AJP/1.3" redirectPort="8443"
enableLookups="false" />

Thanks

Chris

Re: Question on mod_jk and tomcat

[André Warnier <aw...@ice-sa.com>]

Hi.

Some responses in the text.  The responses are based on my experience, not on any thorough 
inspection of the code.

Maybe first, a basic note : from the point of view of Apache httpd, mod_jk is an internal 
"content generator" or "response handler".  Apache "runs" mod_jk as an internal module, 
and expects mod_jk to generate the response and write it to the client response stream. 
httpd doesn't "know" (and doesn't care) that to generate a response, mod_jk talks to a 
Tomcat in the background.
So whatwever mod_jk "says", you should see it as if it was httpd saying it.

chris derham wrote:
> All,
> 
> We have apache running on Windows Web Server 2008 R2, fronting tomcat. We
> use mod_jk to connect. We see these kind of log messages in mod_jk logs.
> What do they mean?
> 
> [Thu Jul 28 12:30:56 2011] [14264:10144] [info] jk_ajp_common.c (1882):
> Writing to client aborted or client network problems
> [Thu Jul 28 12:30:56 2011] [14264:10144] [info] jk_ajp_common.c (2540):
> (workerXtsRbge) sending request to tomcat failed (unrecoverable), because of
> client write error (attempt=1)

Typically, the above means that mod_jk had something (a Tomcat response) to write to the 
client (browser) connection, but could not, because the client connection is gone.
Typically also, that means that the (human) client got tired of waiting (or is just an 
impatient kind of person), and clicked away from the page or closed the browser window, or 
clicked "reload" or whatever causes the browser to close its original connection to the 
server.
(It could also be that some intermediate node between the browser and the httpd host 
closed the connection prematurely; like some proxy or gateway e.g.)

> 
>    - Specifically what is the client here? The browser that called apache,
>    or mod_jk as a client of tomcat?

The browser, or whatever else is on that side (e.g. wget, curl,..)

>    - What do the numbers in brackets mean [14264:10144] - bytes and time?
Don't know. (Could also be the internal sockets, or Apache child PID; since they seem to 
remain the same for multiple messages, I would think more of something like that).

>    - Does this mean that the browser was sent a http 500?

No, because nothing can be sent to the browser.  That is the problem here.  Even if mod_jk 
had an error 500 response (from Tomcat) to send back, it could not, because the client 
socket is closed.
If you increase the logging level of mod_jk, you may get a better idea of what exactly 
mod_jk is trying to send to the client at that time, and can't.


>    - Is there a way that I can get the uniqueId logged along with these
>    lines to make correlating the access and mod_)jk log easier?

You can increase the JkLogLevel.
But a word of caution : this kind of error is fairly frequent, and fairly normal in normal 
circumstances.  There isn't really anything you can do if you have nervous users clicking 
all over the place.

On the other hand, it may indicate a real problem : the users get impatient and click 
away, because the response time of the application (or some pages) is just too long and 
they are not getting any feedback and think the application is stalled.

Or there is something between the httpd server and the client which drops connections too 
quickly. I've known proxies which were set up like that.

You could use the Apache access log to track down issues like that. It is fairly easy to 
add the request duration in milliseconds, and examine the logs afterward to see if you 
have a general response time issue.

>    - I think I read somewhere that by default mod_jk will try a tomcat call
>    once, and if that fails try again before giving up. Does the "attempt=1"
>    mean this is the result of the first attempt or is it the result of the
>    second (e.g. 0 based)? I assume that in the absence of a attempt=0 this must
>    mean that the first attempt failed, and therefore assume that the second
>    succeeded. Is this a fair assumption?
> 
Don't know.  But in this particular case, there is not really any reason for mod_jk to 
resend a request to Tomcat.  It is the client side which has a problem, not the Tomcat side.

I think the "sending request to tomcat failed" part is just poor phrasing of the error 
message, and really means "the entire tomcat request/response cycle could not be 
completed".. but of course that is a bit long for a log message.

> Under jkstatus I see Err and CE. From the legend Err means "Number of failed
> requests" and CE is "Number of client errors".

That sounds like a reasonable interpretation.

Nothing wrong with the config below. Thanks for providing it.

André

> 
> Apache 2.2.17 - httpd.conf
> 
>     LoadModule    jk_module  modules/mod_jk.so
>     JkWorkersFile d:/apps/Apache2.2/conf/workers.properties
>     JkShmFile     d:/apps/Apache2.2/temp/mod_jk.shm
>     JkLogFile     "|d:/apps/Apache2.2/bin/cronolog.exe
> logs/mod_jk.%Y%m%d.log"
>     JkLogLevel    info
>     JkLogStampFormat "[%a %b %d %H:%M:%S %Y] "
>     JkExtractSSL On
>     JkHTTPSIndicator HTTPS
>     JkSESSIONIndicator SSL_SESSION_ID
>     JkCIPHERIndicator SSL_CIPHER
>     JkCERTSIndicator SSL_CLIENT_CERT
>     JkEnvVar UNIQUE_ID unknown
>     JkEnvVar SSL_CLIENT_V_START
> 
> Then within a virtual host element
> 
>     JkMount  /* workerXtsRbge
>     JkUnMount /index.html workerXtsRbge
>     JkUnMount /ie6unsupported.html workerXtsRbge
> 
> mod_jk v1.2.30 - worker.properties
> 
>   worker.list=mystatus, workerXtsRbge
> 
>   worker.template.type=ajp13
>   worker.template.host=localhost
>   worker.template.ping_timeout=1000
>   worker.template.ping_mode=A
> 
>   worker.workerXtsRbge.reference=worker.template
>   worker.workerXtsRbge.port=8010
> 
> Tomcat v7.0.12 - server.xml
> 
>     <Connector port="8010" protocol="AJP/1.3" redirectPort="8443"
> enableLookups="false" />
> 
> Thanks
> 
> Chris
> 


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