commons-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Phil Steitz <p...@steitz.com>
Subject Re: dbcp blocked on webapp startup
Date Fri, 27 Jun 2008 02:11:29 GMT
Adrian Woodhead wrote:
> Hey there,
>
> I am experiencing some odd behaviour related to DBCP. We have an 
> application that is deployed in Tomcat 6.0.16 on Linux with Java 6. It 
> uses dbcp 1.2.2 (with commons pool 1.3) and we have a pooled 
> datasource configured in spring which is in turn used by ibatis. This 
> webapp receives around 300-600 requests per second. When we deploy new 
> versions of the app we restart tomcat from scratch and it *usually* 
> stars up just fine. However, every now and then (say 20% of the time) 
> it starts up, runs OK for less than a minute and then just freezes up. 
> I did a stack dump at this point and see many BLOCKED threads all 
> blocked in the same spot (BasicDataSource line 1123 where is creates a 
> datasource and returns it). Here is a portion of the thread dump 
> showing the symptom:
>
> "http-80-15" daemon prio=10 tid=0x00002aaaf51f8800 nid=0x1bfa waiting 
> for monitor entry [0x0000000043158000..0x0000000043159d40]
>   java.lang.Thread.State: BLOCKED (on object monitor)
>    at 
> org.apache.commons.dbcp.BasicDataSource.createDataSource(BasicDataSource.java:1123) 
>
>    - waiting to lock <0x00002aaab58758a8> (a 
> org.apache.commons.dbcp.BasicDataSource)
>    at 
> org.apache.commons.dbcp.BasicDataSource.getConnection(BasicDataSource.java:880) 
>
>    at 
> org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:113)

>
>    at 
> org.springframework.jdbc.datasource.TransactionAwareDataSourceProxy$TransactionAwareInvocationHandler.invoke(TransactionAwareDataSourceProxy.java:210)

>
>    at $Proxy0.prepareStatement(Unknown Source)
>    at 
> com.ibatis.sqlmap.engine.execution.SqlExecutor.prepareStatement(SqlExecutor.java:494)

>
>    at 
> com.ibatis.sqlmap.engine.execution.SqlExecutor.executeQuery(SqlExecutor.java:176) 
>
>    at 
> com.ibatis.sqlmap.engine.mapping.statement.GeneralStatement.sqlExecuteQuery(GeneralStatement.java:205)

>
>    at 
> com.ibatis.sqlmap.engine.mapping.statement.GeneralStatement.executeQueryWithCallback(GeneralStatement.java:173)

>
>    at 
> com.ibatis.sqlmap.engine.mapping.statement.GeneralStatement.executeQueryForObject(GeneralStatement.java:104)

>
>    at 
> com.ibatis.sqlmap.engine.impl.SqlMapExecutorDelegate.queryForObject(SqlMapExecutorDelegate.java:566)

>
>    at 
> com.ibatis.sqlmap.engine.impl.SqlMapExecutorDelegate.queryForObject(SqlMapExecutorDelegate.java:541)

>
>    at 
> com.ibatis.sqlmap.engine.impl.SqlMapSessionImpl.queryForObject(SqlMapSessionImpl.java:106)

>
>    at 
> com.ibatis.sqlmap.engine.impl.SqlMapClientImpl.queryForObject(SqlMapClientImpl.java:83)

>
>    at 
> post.audioscrobbler.submission.dao.ibatis.IbatisCatalogueDao.getAlbumId(IbatisCatalogueDao.java:273)

>
>    at 
> post.audioscrobbler.submission.realtime.SubmissionRequestHandler1_2.handleRequest(SubmissionRequestHandler1_2.java:106)

>
>    at 
> post.audioscrobbler.submission.realtime.SubmissionServlet1_2.handleRequest(SubmissionServlet1_2.java:177)

>
>    at 
> post.audioscrobbler.submission.realtime.SubmissionServlet1_2.handleSubmission(SubmissionServlet1_2.java:134)

>
>    at 
> post.audioscrobbler.submission.realtime.BaseSubmissionServlet.doPost(BaseSubmissionServlet.java:131)

>
>    at 
> post.audioscrobbler.submission.realtime.SubmissionServlet1_2.doPost(SubmissionServlet1_2.java:26)

>
>    at javax.servlet.http.HttpServlet.service(HttpServlet.java:710)
>    at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
>    at 
> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)

>
>    at 
> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)

>
>    at 
> org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233) 
>
>    at 
> org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175) 
>
>    at 
> org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128) 
>
>    at 
> org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) 
>
>    at 
> org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) 
>
>    at 
> org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:286) 
>
>    at 
> org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:844) 
>
>    at 
> org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:583)

>
>    at 
> org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:447)
>    at java.lang.Thread.run(Thread.java:619)
>
> At this point we have to restart tomcat and hope everything goes ok 
> the next startup. Does anybody have any idea what could be causing 
> this? Are we doing something wrong with our settings? We have 3 data 
> sources defined (2 postgres, 1 mysql) all using dbcp configured 
> similarly and I see threads in the BLOCKED state at the same line for 
> all 3 of them. Here is our config for one of them:
>
>  <bean id="catSlaveDataSource" 
> class="org.apache.commons.dbcp.BasicDataSource">
>    <property name="driverClassName" value="org.postgresql.Driver"/>
>    <property name="url" value="${db.catslave.url}"/>
>    <property name="username" value="${db.catslave.username}"/>
>    <property name="password" value="${db.catslave.password}"/>
>    <property name="maxActive" value="25"/>
>    <property name="maxIdle" value="10"/>
>    <property name="maxWait" value="1000"/>
>    <property name="testOnBorrow" value="true"/>
>    <property name="testOnReturn" value="true"/>
>    <property name="validationQuery" value="select version();"/>
>  </bean>
>
> Any advice, tips, help would be really appreciated, I haven't been 
> able to find anything on the 'net about this.

One possible explanation is that initialization of one (all three?) of 
your datasources is hanging on validation.  That would leave one of the 
threads in the validateConnectionFactory method (or 
PoolableConnectionFactory.makeObject) waiting on the database connection 
or validation query.  Can you find such a thread?  The others will queue 
up waiting for the first requesting thread to create the datasource.  
The way it works is that the datasource is created on first activation 
of createDatasource and subsequent calls return the instance created on 
the first call.

Send me a full thread dump and I will have a look if this does not help. 

You will likely also get better throughput if you upgrade to pool 1.4, 
though that will not solve the problem above it it is queuing on 
datasource creation.

Phil
 

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


Mime
View raw message