tomcat-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Kaleb Pederson <kpeder...@mail.ewu.edu>
Subject Re: Tomcat becoming almost completely non-responsive
Date Mon, 04 Oct 2004 15:18:57 GMT
John,

Thanks for the feedback.  My code is actually quite simple and I have 
everything factored out to single function that handles the DB code.  I'll 
paste it below for you, and others to look at.  *Please let me know* if there 
is an exit path that I somehow missed.

I already have tomcat setup to log abandoned connections.  At your 
instigation, I grep'd the logs and found a few instances of it in the logs 
which I was unaware of.  Each one of them corresponds to a time we had high 
load on the server, so I, hopefully not niavely ;), am guesssing that the 
abandoned timeout was shorter (currently 60 seconds) than the time it took 
the server to respond to the request (up to 5 minutes).  I guess I should up 
the abandoned timeout as that could flame the problem.

If I'm interpreting the thread dump and mysqladmin processlist information 
correctly, what I'm seeing is that MySQL considers the DB connection to be 
sleeping, and that 48 of my active db threads were in object.wait() after a 
call to  AbandonedObjectPool.borrowObject() which seems to get called in 
every case after a call to DataSource.getConnection():

// note that I removed the org.apache.commons prefix
48 like "TP-Processor312" daemon prio=1 tid=0x70331680 nid=0x5e87 waiting for 
monitor entry [6df79000..6df7a87c] at 
dbcp.PoolableConnectionFactory.validateObject(PoolableConnectionFactory.java:316)
    - waiting to lock <0x7b071438> (a dbcp.PoolableConnectionFactory)
    at pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:833)
    at dbcp.AbandonedObjectPool.borrowObject(AbandonedObjectPool.java:119)
    at dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:140)
    at dbcp.BasicDataSource.getConnection(BasicDataSource.java:518)
    // the function in my filter that checks the DB.
    at RequestFilterServlet.getUrlMapping(RequestFilterServlet.java:187)
    ...

Here's the code that handles the db:

 protected RedirectInfo getUrlMapping(String requestURI) {
 
  RedirectInfo retval = null;
  Connection conn = null;
  Statement statement = null;
  ResultSet result = null;

  try {
    conn = ds.getConnection();
   statement = conn.createStatement();
   statement.setEscapeProcessing(true);
   result = statement.executeQuery(QUERY_UNIQUE_MATCH + quote(requestURI));
   
   if (!result.first()) {
    result = statement.executeQuery(QUERY_CHILD_MATCH_1 + quote(requestURI) + 
QUERY_CHILD_MATCH_2);
   }
   
   // get the information
   if (result.first()) {
    retval = new RedirectInfo(); 
    retval.setURL(result.getString(1));
    retval.setCode(result.getInt(2));
    debug(requestURI + " -> " + retval.getURL() + " [" + 
Integer.toString(retval.getCode()) + "]");
   } else {
    debug("No matching redirect URL found for " + requestURI);
   }
  } catch(SQLException e) {
   log("SQLException caught: " + e.getMessage(), e);
  } finally {
   try {
    // cleanup after myself
    if (statement != null) statement.close();
    if (conn != null) conn.close();
   } catch (SQLException e) {
    log("Error cleaning up connection/statement: " + e.getMessage(),e);
   }
  }
  
  return retval;
 }

Thanks for all the help.

--Kaleb

On Sunday 03 October 2004 1:58 pm, jthompson@honda.co.nz wrote:
> The most likely reason for your connections not being re-used is that your
> java code isn't explicitly closing connections, statements and result sets
> after use.
> If visiting all your code is too onerous a task, you could add the
> following parameters to your data-source configuration:
>
> <parameter>
>   <name>removeAbandoned</name>
>   <value>true</value>
>  </parameter>
> <parameter>
>   <name>removeAbandonedTimeout</name>
>   <value>60</value>
>  </parameter>
>
> The effect of the above is to mark any data-pool connection as re-usable
> after 60 seconds of inactivity.
> You can add the following to log abandonned connection activity:
>
> <parameter>
>   <name>logAbandoned</name>
>   <value>true</value>
>  </parameter>
>
> John Thompson
>
> |---------+---------------------------->
> |
> |         |           Kaleb Pederson   |
> |         |           <kpederson@mail.e|
> |         |           wu.edu>          |
> |         |
> |         |           02/10/2004 10:07 |
> |         |           AM               |
> |         |           Please respond to|
> |         |           "Tomcat Users    |
> |         |           List"            |
> |
> |---------+---------------------------->
> |
>   >------------------------------------------------------------------------
>   >--------------------------------------|
>   >
>   |       To:       Tomcat Users List <tomcat-user@jakarta.apache.org>     
>   |                                      | cc:                             
>   |                                                                       |
>   | Subject:  Tomcat becoming almost completely non-responsive             
>   |                                |
>   |
>   >------------------------------------------------------------------------
>   >--------------------------------------|
>
> Hello,
>
> I have an interesting problem.  After a while, tomcat (5.0.27) becomes
> almost
> completely non-responsive.  If I telnet in to port 8009  (I'm using apache
> and mod_jk2), I get no response, at least not within the default timeout.
> If
> a browse to a page, I will generally, after about 4-5 minutes, see a page
> returned.
>
> To narrow down the slowness, I generated a full thread dump, and found the
> following information:
>
> [ see attachment for more info]
> Total threads: 180
> executeQuery: 2 //  executing a db query
> validateConnection: 0 // trying to validate their connection
> validateObect: 48 // in
> commons.dbcp.PoolableConnectionFactory.validateObject
> socketAccept: 3 // accepting a socket
> socketRead0: 10 // reading a socket
> ReferenceQueue: 1
> ThreadPool$MonitorRunnable: 2
> borrowObject and Object.wait: 85 // trying to get an object from the pool
> Object.wait: 20 // threads just waiting around
> Remaining:  9 // misc. threads
>
> My database connection is setup so that I have 50 allowed connections,
> which
> matches my 48 in validateObject and 2 executing queries.  However, when I
> query the database status, I see 2 active threads and the rest are
> 'sleeping', just waiting around, as they would be if the connection pool
> hadn't released them yet.
>
> So, why would there be 48 connections that seemed locked and weren't
> querying
> the DB?  And then the other 85 that were seemingly waiting on the 45?  Any
> ideas what might be going on?  The DB is ready?  I have log abandoned
> turned
> and an haven't seen a problem yet.  If the load drops sufficiently on the
> server, everything eventually returns back to normal, otherwise it takes
> 5-10
> minutes to get a response from the server.
>
> I have attached an abbreviated form of the thread dump which should provide
> all the critical information and can provide as much other information as
> is
> necessary.
>
> Thanks for the help.  *All* suggestions welcome ;)
>
> --Kaleb
>
>
> ---------------------------------------------------------------------
>  To unsubscribe, e-mail: tomcat-user-unsubscribe@jakarta.apache.org
> For additional commands, e-mail: tomcat-user-help@jakarta.apache.org
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: tomcat-user-unsubscribe@jakarta.apache.org
> For additional commands, e-mail: tomcat-user-help@jakarta.apache.org

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


Mime
View raw message