Fully featured low overhead profiler for Java EE and Java SE platforms.
Ultimate profiling and monitoring solution for Gradle, Maven, Ant, JUnit and TestNG.
Easy to use performance and memory profiler for .NET framework.

Performance charts and database connection pool

Moderators: Vladimir Kondratyev, Anton Katilin

Performance charts and database connection pool

Postby DavidW » Sat Jun 13, 2015 12:42 am

I've tried this with a couple of applications, and 2 versions of Yourkit (my copy of Yourkit 2013 and the 2015 build 15060). If I profile an application running in Tomcat that uses connection pools (one of the apps used the Oracle OracleXADataSource, accessed from Spring by looking it up in JNDI, the other app uses the Apache connection pool), I see from the performance charts that there are a great number of connections opened and (rapidly) closed. Does Yourkit not distinguish between closing a database connection and returning it to a connection pool?

App 1 config in Tomcat context:
<Resource name="jdbc/MyDataSource" auth="Container"
type="javax.sql.DataSource" driverClassName="oracle.jdbc.xa.client.OracleXADataSource"
url="jdbc:oracle:thin:..." username="..." password="..." maxActive="20" maxIdle="10"
maxWait="-1" testOnBorrow="true" validationQuery="select 1 from dual" validationQueryTimeout="3"/>
App 1 Spring config for datasource:
<jee:jndi-lookup id="myDataSource" jndi-name="jdbc/MyDataSource" resource-ref="true"/>

App 2 Spring config using Apache pool:
<bean id="dataSource" class="org.apache.commons.dbcp.BasicDataSource" destroy-method="close">
<property name="driverClassName" value="com.microsoft.sqlserver.jdbc.SQLServerDriver"/>
<property name="url" value="..."/>
<property name="username" value="..."/>
<property name="password" value="..."/>
<property name="initialSize" value="100" />
<property name="maxActive" value="100" />
<property name="maxIdle" value="50" />
<property name="minIdle" value="25" />
</bean>

Both applications then use Spring's JdbcTemplate, passing the datasource bean.
DavidW
 
Posts: 2
Joined: Sat Jun 13, 2015 12:24 am

Re: Performance charts and database connection pool

Postby DavidW » Sat Jun 20, 2015 2:55 pm

OK, since some people seem interested, I'll describe what I found.
I wrote a small app that starts some threads, each thread runs a query using Spring's JdbcTemplate. The template uses a datasource created from the Apache dbcp project (dbcp2, version 2.1). I created an aspect (AspectJ) that intercepts calls to constructors or the close method of any class that implements java.sql.Connection (the aspect properly handles issues with superclasses, delegating calls, etc). I then periodically report, for each such connection type, the class, number of constructor calls, number of close calls, and the remaining unclosed connections. dbcp was configured to have 5 pooled connections, remaining config is the default (max idle 8, min idle 0). Since I started 10 threads, I expected that I would start 5 connections and leave them open for the duration of the test. I also wrote an aspect that reported when dbcp actually created a new connection. Here is a sample output:
pool created connection #1
pool created connection #5
pool created connection #4
pool created connection #2
pool created connection #3
Class oracle.jdbc.driver.T4CConnection opened=1, closed=0, still open=1
total opened=1, closed=0, still open=1
=================================
Class oracle.jdbc.driver.T4CConnection opened=1, closed=0, still open=1
Class org.apache.commons.dbcp2.PoolableConnection opened=1, closed=0, still open=1
total opened=2, closed=0, still open=2
=================================
Class oracle.jdbc.driver.T4CConnection opened=5, closed=0, still open=5
Class org.apache.commons.dbcp2.PoolingDataSource$PoolGuardConnectionWrapper opened=3, closed=0, still open=3
Class org.apache.commons.dbcp2.PoolableConnection opened=5, closed=0, still open=5
total opened=13, closed=0, still open=13
=================================
Class oracle.jdbc.driver.T4CConnection opened=5, closed=0, still open=5
Class org.apache.commons.dbcp2.PoolingDataSource$PoolGuardConnectionWrapper opened=5, closed=0, still open=5
Class org.apache.commons.dbcp2.PoolableConnection opened=5, closed=0, still open=5
total opened=15, closed=0, still open=15
=================================
Class oracle.jdbc.driver.T4CConnection opened=5, closed=0, still open=5
Class org.apache.commons.dbcp2.PoolingDataSource$PoolGuardConnectionWrapper opened=5, closed=0, still open=5
Class org.apache.commons.dbcp2.PoolableConnection opened=5, closed=0, still open=5
total opened=15, closed=0, still open=15
=================================
Class oracle.jdbc.driver.T4CConnection opened=5, closed=0, still open=5
Class org.apache.commons.dbcp2.PoolingDataSource$PoolGuardConnectionWrapper opened=10, closed=5, still open=5
Class org.apache.commons.dbcp2.PoolableConnection opened=5, closed=0, still open=5
total opened=20, closed=5, still open=15
=================================
Class oracle.jdbc.driver.T4CConnection opened=5, closed=0, still open=5
Class org.apache.commons.dbcp2.PoolingDataSource$PoolGuardConnectionWrapper opened=10, closed=5, still open=5
Class org.apache.commons.dbcp2.PoolableConnection opened=5, closed=0, still open=5
total opened=20, closed=5, still open=15
=================================
Class oracle.jdbc.driver.T4CConnection opened=5, closed=0, still open=5
Class org.apache.commons.dbcp2.PoolingDataSource$PoolGuardConnectionWrapper opened=15, closed=10, still open=5
Class org.apache.commons.dbcp2.PoolableConnection opened=5, closed=0, still open=5
total opened=25, closed=10, still open=15
=================================
Class oracle.jdbc.driver.T4CConnection opened=5, closed=0, still open=5
Class org.apache.commons.dbcp2.PoolingDataSource$PoolGuardConnectionWrapper opened=15, closed=10, still open=5
Class org.apache.commons.dbcp2.PoolableConnection opened=5, closed=0, still open=5
total opened=25, closed=10, still open=15
=================================


So, the class T4CConnection represents the underlying Oracle database connection, and I see that I construct 5 of them, and never close them. PoolableConnection is a class that dbcp instantiates to wrap the actual database connection, and this is what it keeps in the pool. Again, 5 of them, never closed. The PoolGuardConnectionWrapper is more interesting. When dbcp lends a connection from the pool, it doesn't give you a PoolableConnection - instead, it wraps it in this wrapper class, and it creates a new wrapper instance every time you ask the pool for a connection.

This all explains some of the Yourkit data. It appears that, similar to my aspect, Yourkit is watching constructors and close calls for connections, but it doesn't understand the meaning of these classes. The constantly increasing number of opens and closes that it reports is due to the PoolGuardConnectionWrapper.

One last puzzle remains, though. Yourkit reports the number of remaining open connections at any point on the chart. And it reports 5, while my stats above report 15. How does Yourkit know to disregard the 2 wrapping classes, in terms of how many connections are still open, but it isn't smart enough to ignore the PoolGuardConnectionWrapper instantiations on borrow from the pool? Or is this intentional, to allow you to see how many connections you are borrowing from the pool? If the latter, I expect many people would be as confused as I was.

I haven't retried my test in the case where I use JNDI to get the datasource from Tomcat, because the app that I am dealing with in real life is using dbcp.
DavidW
 
Posts: 2
Joined: Sat Jun 13, 2015 12:24 am


Return to Java Profiler

Who is online

Users browsing this forum: No registered users and 8 guests