How to measure time to execute a query when using DBCP+JdbcTemplate

Keep the following things in your mind if you are planning to measure the time taken to execute a query when you make use of Apache DBCP + Spring JdbcTemplate.

You will never be able to find out the time taken to execute a query in the database by measuring the the time it takes to complete any variant of JdbcTemplate.query...() or JdbcTemplate.execute...() . Making use of any of these functions involve the following steps:
  1. Time taken to borrow a connection from the pool
  2. Time taken to create a statement from the connection and bind the parameters if needed
  3. Time taken to send the query to the database
  4. Time taken to execute the query in the database (this is the time you are specifically interested in)
  5. Time taken to receive the result from the database (depending on the fetch size you have set, this will vary). For UPDATEs, only the update count is sent back from the database.
  6. Time taken in the row mapping (if you are making use of RowMapper) or time taken to consume all the rows from ResultSet (if you are making use of ResultSetExtractor)
  7. Time taken to return the connection to the pool
If you are sending the request over a long latency line, the time you are measuring is bound to be off by a few milliseconds due to steps 3 and 5. For e.g. to reach from west coast to east coast in US, it might takes 50 ms or more.

If you are making use of a connection pool that has all the connections borrowed all the time, then the time taken in steps 1 and 7 are significant. For e.g. during my experiments I have seen some threads waiting as long as 100 ms when there are 10 connections and 23 threads using the connection pool.

So the most reliable way of measuring the time spent in the database will involve the following things:
  1. Make sure you understand the average round-trip time between the database and your application. You will have to use this one for your analysis. You can use ping to measure this. If ICMP is not allowed in your network, make use of netcat.
  2. Make use of StatementCallback since it will help you in measuring time taken from steps 2 to 6 above. In other words the measurement will not be skewed by the DBCP borrow and return.
  3. Make use of PreparedStatementCreator variants of query() so that you will know the time when the statement has been created.
  4. If you are making use of RowMapper, the approximate time the query completed is when you start processing the first row. If you are making use of ResultSetExtractor, the time when extractData is called is the approximate query completion time. If you are making use of RowCallbackHandler, make use of ResultSet.isFirst() to decide the approximate query completion time.
  5. There is no way of excluding the time taken in DBCP when making use of batchUpdate().
  6. There is no way of excluding the time taken in returning a connection back to the pool when making use of update() functions.
Hope these guidelines will be useful to you. I followed them when I had to measure the time difference between the database and the host where my application was running. It is very tricky in the presence of the DBCP since borrowing and returning always skews the numbers.

Comments

Post a Comment

Popular posts from this blog

Gotchas with DBCP

I had to make use of DB connection pool in one of the applications that I was implementing. Since I am new to Java, everyone in the team was suggesting why don't you make use of Commons DBCP. Being a fan of reuse, I decided to make use of DBCP and started reading about the parameters that are exposed so that I can customize DBCP to fit my needs. While reading through the available configuration parameters , I was thinking, "I don't need to check the connection to be bad on every borrow or return. It is sufficient if I check for being bad only when the connection is sitting idle in the pool." So I set the testWhileIdle to be true and set the validationQuery to be "SELECT 1 FROM DUAL". I was thinking that the configuration that I had was the optimal for the situation in hand. But one thing I overlooked was, the default value for the testOnBorrow is true. So the moment you set the validationQuery to be any non-null value, every connection you borrow from the po
Read more

A note on Java's Calendar set() method

Remember that the Calendar's internal fields include year, month, date, hour, minutes, seconds, milliseconds and time zone. Whenever you are calling a set() method with multiple fields, like set(year, month, date), it will not affect the rest of the fields. Remember that there is no set() method with multiple fields available to set the milliseconds. If you would like to set the milliseconds, you must use set(Calendar.MILLISECOND, value). Likewise, if you are planning to set all the fields, its a good idea to reset all the fields using clear() method. This will clear milliseconds as well. Most of the times, millisecond field may not be of interest to you. But if you are going to use the UTC milliseconds, by calling getTimeInMillis(), then make sure you set the right values for milliseconds as well.
Read more

The mysterious ORA-03111 error

Recently one of the applications that I developed started throwing exceptions, that had the following message: SQL state [72000]; error code [1013]; ORA-03111: break received on communication channel When I googled around, I couldn't come across anything useful. Sadly enough most of the sites just showed the documentation for that error, without any explanation from anyone experiencing that issues. So here you go, with the best possible explanation that I could come up with. My application sets two things on the connection that is throwing this exception: It sets the fetchSize to be 2500 rows It sets the query timeout to be 10 seconds The database server and the application are separated over a long latency network (actually there is a NetEm box that emulates the long latency between these two boxes) which has a latency characteristic of 50+/-5 milliseconds. This is the whole setup. It is important to understand how the timeout is handled by the Oracle client (in my case JDBC clien
Read more