Mailing-List: contact dev-help@tomcat.apache.org; run by ezmlm
Precedence: bulk
Reply-To: "Tomcat Developers List" <dev@tomcat.apache.org>
Received-SPF: pass (nike.apache.org: local policy)
Message-ID: <4A0855C7.5020906@ptc.com>
Date: Mon, 11 May 2009 11:43:51 -0500
From: Jess Holle <jessh@ptc.com>
User-Agent: Thunderbird 2.0.0.21 (Windows/20090302)
MIME-Version: 1.0
To: Tomcat Developers List <dev@tomcat.apache.org>
Subject: Proposed mod_jk logging patch
Content-Type: multipart/mixed;
 boundary="------------050605040405020104080704"

--------------050605040405020104080704
Content-Type: text/plain; charset=ISO-8859-1; format=flowed
Content-Transfer-Encoding: 7bit

I have noticed that mod_jk logging about a dead server is overtly 
verbose in some circumstances.

If you use it to load balance over a number of servers and one is dead 
you'll get several lines of error logging every time it retries the 
server (to see if it's alive yet).  This can get rather obnoxious when 
you're balancing over a number of ports which may or may not have a 
server listening at the time -- and when you're allowing retries of dead 
servers with any frequency.

The attached patch changes the level of such logging to debug for 
retries of a worker known to be in an error state, leaving the level at 
error for other cases.  The result is that you get error logging when a 
server is first determined to be unavailable -- and then are simply not 
bothered about this any longer.

Is there any chance of merging this patch into mod_jk?  The current 
level of log verbosity just isn't acceptable in cases where one is load 
balancing over a sparsely populated range of server ports, for instance.

--
Jess Holle

P.S. I already proposed a similar patch for mod_proxy_balancer/ajp.  
There appear to be additional issues there (having to do with load 
balancing getting "stuck" on a subset of the members), however, which 
are pushing us back to mod_jk anyway.


--------------050605040405020104080704
Content-Type: text/plain;
 name="quieterjklblog.diff"
Content-Transfer-Encoding: 7bit
Content-Disposition: inline;
 filename="quieterjklblog.diff"

--- native/common/jk_ajp_common.c.orig	2009-04-07 12:56:25.926105900 -0500
+++ native/common/jk_ajp_common.c	2009-04-07 12:53:22.408773900 -0500
@@ -1392,7 +1392,8 @@
 static int ajp_send_request(jk_endpoint_t *e,
                             jk_ws_service_t *s,
                             jk_logger_t *l,
-                            ajp_endpoint_t * ae, ajp_operation_t * op)
+                            ajp_endpoint_t * ae, ajp_operation_t * op,
+                            int probing) /* Added 'probing', which is true when probing/retrying failed worker [PTC] */
 {
     int err_conn = 0;
     int err_cping = 0;
@@ -1504,6 +1505,14 @@
         /* Connect to the backend.
          */
         if (ajp_connect_to_endpoint(ae, l) != JK_TRUE) {
+            /* Log at debug level rather than error level when 'probing' [PTC]
+            */
+            if ( probing )
+                jk_log(l, JK_LOG_DEBUG,
+                       "(%s) connecting to backend failed. Tomcat is probably not started "
+                       "or is listening on the wrong port (errno=%d)",
+                       ae->worker->name, ae->last_errno);
+            else
             jk_log(l, JK_LOG_ERROR,
                    "(%s) connecting to backend failed. Tomcat is probably not started "
                    "or is listening on the wrong port (errno=%d)",
@@ -2189,6 +2198,7 @@
     int rc = JK_UNSET;
     char *msg = "";
     int retry_interval;
+    int probing;  /* Added [PTC] */
 
     JK_TRACE_ENTER(l);
 
@@ -2286,6 +2296,10 @@
     aw->s->busy++;
     if (aw->s->state == JK_AJP_STATE_ERROR)
         aw->s->state = JK_AJP_STATE_PROBE;
+    /* Set 'probing' to true when aw->s->state == JK_AJP_STATE_PROBE;
+       indicates when worker is being probed/retried [PTC]
+    */
+    probing = ( aw->s->state == JK_AJP_STATE_PROBE );
     if (aw->s->busy > aw->s->max_busy)
         aw->s->max_busy = aw->s->busy;
     retry_interval = p->worker->retry_interval;
@@ -2317,7 +2331,7 @@
         log_error = JK_TRUE;
         rc = JK_UNSET;
         msg = "";
-        err = ajp_send_request(e, s, l, p, op);
+        err = ajp_send_request(e, s, l, p, op, probing); /* pass 'probing' to ajp_send_request() [PTC] */
         e->recoverable = op->recoverable;
         if (err == JK_CLIENT_RD_ERROR) {
             *is_error = JK_HTTP_BAD_REQUEST;
@@ -2463,6 +2477,13 @@
         ajp_next_connection(p, l);
     }
     /* Log the error only once per failed request. */
+    /* Log at debug level rather than error level when 'probing' [PTC]
+    */
+    if ( probing )
+        jk_log(l, JK_LOG_DEBUG,
+               "(%s) connecting to tomcat failed.",
+               aw->name);
+    else
     jk_log(l, JK_LOG_ERROR,
            "(%s) connecting to tomcat failed.",
            aw->name);


--------------050605040405020104080704
Content-Type: text/plain; charset=us-ascii


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