Testing the overhead of creating connections vs using a pool in Weblogic

We had a need to understand the overhead of creating connections versus using a pool. Connection pooling is most beneficial when using very short lived database sessions. If the associated database request takes longer than a few seconds, we needed to understand what positive impact pooling would have. In other words, if the request takes a minute, a second to open the connection is less impactful, reducing the benefit of pooling.

Short of running a complete regression test, we came up with what is below to drive conversation…

Request = http://host:port/threadtest.jsp?count=50&pool=false

Drop this in the autodeploy directory…

<%@ page import="java.sql.*"%>
<%@ page import="javax.sql.*"%>
<%@ page import="javax.naming.*"%>

<%
class TestConns implements Runnable{
  boolean pool;
  weblogic.logging.NonCatalogLogger ncl = new weblogic.logging.NonCatalogLogger("Thread Test");
  TestConns(boolean pool) {
    this.pool = pool;
    Thread t = new Thread(this);
    t.start();
  }
  public void run() {
    ncl.info("pool = " + pool + " start");
    try {
      if (this.pool) {
        InitialContext ic = new InitialContext();
        DataSource ds = (DataSource)ic.lookup("jdbc/mdsrep");
        Connection conn = ds.getConnection();
        conn.close();
      }
      else {
        try {
          Connection conn = DriverManager.getConnection("jdbc:oracle:thin:user/password@dbhost:dbport/dbservicename.domainname");
          conn.close();
        }
        catch (Exception e3) {
          ncl.error(e3.getMessage());
          return;
        }
      }
    }
    catch (Exception e) {
      ncl.error(e.getMessage());
    }
    ncl.info("pool = " + pool + " end");
  }
}
for (int i = 1; i <= Integer.parseInt(request.getParameter("count")); i++) {
  TestConns t = new TestConns(Boolean.parseBoolean(request.getParameter("pool")));
}
%>

…and you will see log entries such as the following when requesting the page…

/u01/app/oracle/product/fmw: find . -mmin -1 -type f | xargs egrep 'pool' | grep 12:24 | tail -1
./user_projects/domains/assortplan/servers/AdminServer/logs/AdminServer.log00020:####      <> <> <673ae030-d2ab-456d-9ffa-2adfa36aa033-000002c8> <1475771052021>  
/u01/app/oracle/product/fmw:

We saw 247 milliseconds per physical connection…

/u01/app/oracle/product/fmw: find . -mmin -30 -type f | xargs egrep '12:24.*Thread Test' | awk '{gsub("<","",$0);gsub(">","",$0);if ($20 ~ "start") {s[$12]=$15} else {t[$12]=$15}} END {for (i in t) {if (s[i] != "") {print i,t[i]-s[i]}}}' | sort | awk '{s+=$2} END {print s/NR}'
247.537

…and 5 milliseconds from a pool…

/u01/app/oracle/product/fmw: find . -mmin -30 -type f | xargs egrep ' 1:24.*Thread Test' | awk '{gsub("<","",$0);gsub(">","",$0);if ($20 ~ "start") {s[$12]=$15} else {t[$12]=$15}} END {for (i in t) {if (s[i] != "") {print i,t[i]-s[i]}}}' | sort | awk '{s+=$2} END {print s/NR}'
5.58
cmhlcarchapp02:oracle:/u01/app/oracle/product/fmw: