Nevermind.

I had a non-instantaneous ON COMMIT trigger on the database; the validationQuery
(in server.xml) gets run each time you call datasource.getConnection(), and it
commits after running. (I had to turn on -D FBLog4j, and watch the wire data to
figure that out.)

So every getConnection() was causing a commit, causing a trigger to run, slowing
it down. I had the trigger set to abort in the case of a read-only transaction
(otherwise firing up FlameRobin was enough to cause problems, because it fetches
database info in a read-only transaction), but the validationQuery does *not*
run in a read-only transaction.

I still want my validationQuery, and I want to keep my ON COMMIT trigger, so I
think I'll just have to hack it so it becomes something like:

validationQuery="select rdb$set_context('USER_TRANSACTION',
'validationqueryonly', 1) from rdb$database"

... and skip the ON COMMIT trigger if that's set. (Should generally only be set
for the validationQuery, which commits; who knows, maybe it'll come in handy for
other transactions that were not made in read-only mode, but where I know the
trigger is unnecessary?)

INFO 18:09:01.359 ajp-8009-1 eddy.util.Profiler : ... GettingConnection lasted
0.0ms.

Zero milliseconds? Yeah, that's a lot better.

"We're all fine here, now, thank you. How are you?" -- Solo, H.

-Philip

---------- Original Message -----------
From: "unordained" <unordained_00@...>
To: Firebird-Java@yahoogroups.com
Sent: Thu, 5 Feb 2009 16:23:58 -0600
Subject: [Firebird-Java] performance of getConnection() with Tomcat and DBCP

> I can't find anyone having posted their average connection times, but
> I'd like to know what's "normal", because this doesn't feel right.
>
> I've got Tomcat/DBCP configured to use 10 to 200 connections at a time
> (maxIdle, maxActive). I can verify that it's keeping connections open
> (rdb$set_context('USER_SESSION'... was used to make *sure* a given
> connection is getting used more than once). And yet, just doing
> datasource.getConnection() consistently takes 50 to 100 milliseconds,
> even after I've pounded the server and made sure the connection pool
> is primed, which I find strange -- the rest of my statements execute
> in as little as a millisecond! The entire servlet call may only add a
> few milliseconds on top of the cost of connecting to the server, so
> proportionally, it's a big deal to me.
>
> These tests were against localhost, with nothing else hitting the
> server. Can anyone confirm this is normal? Better/worse than average?
> Any tips on getting it to "connect" (start a new transaction) faster
> with pooling?
>
> Tomcat 6, Jaybird 2.1.6 (with a custom tbp_mappings file that makes
> REPEATABLE_READ not wait), Firebird 2.1.1, JRE 1.6. The
> resultSetHoldable stuff is because of JasperReports, so sub-reports
> won't fail. If that's somehow the problem, I can probably have two
> resources, one for everyday servlets, and another just for reports.
>
> Tomcat server.xml config:
>
> <Resource auth="Container"
> validationQuery="select 1 from rdb$database"
> defaultTransactionIsolation="REPEATABLE_READ"
> driverClassName="org.firebirdsql.jdbc.FBDriver"
> logAbandoned="true"
> name="jdbc/eddy"
> password="********"
> removeAbandoned="true"
> removeAbandonedTimeout="300"
> type="javax.sql.DataSource"
>
>

url="jdbc:firebirdsql:localhost/3050:c:\\projects\\bnt\\database\\eddy1.fdb?autoReconnect=true&defaultResultSetHoldable=true"

> maxActive="200"
> maxIdle="10"
> maxWait="1000"
> username="********"/>
>
> Method for getting a connection for my servlet:
>
> public static Connection GetFirebirdConnection () throws Exception {
> Context initContext = new InitialContext();
> Context envContext = (Context) initContext.lookup("java:/comp/env");
> DataSource ds = (DataSource) envContext.lookup("jdbc/eddy");
> Profiler.push("GettingConnection");
> Connection conn = ds.getConnection();
> Profiler.pop("GettingConnection");
> conn.setAutoCommit(false);
> qry.voidVoidProcedure(conn, "ut_begin_session"); // increments "session_uses"
> l4j.debug( "use# " + qry.singletonQuery(conn, "select
> rdb$get_context('USER_SESSION', 'session_uses') from rdb$database",
> null) + " on " + "conn# " + qry.singletonQuery(conn, "select
> current_connection from rdb$database", null) + " known as " + "trans#
> " + qry.singletonQuery(conn, "select current_transaction from
> rdb$database", null)); return conn; }
>
> Example in my log files:
>
> INFO 16:15:23.968 TP-Processor26 eddy.util.Profiler : ... GettingConnection
> lasted 107.2ms.
>
> DEBUG 16:15:23.968 TP-Processor26 eddy.util.db.mgt : use# 31 on
> conn# 238645 known as trans# 1168430
> (On this particular call, the *entire* process took 181ms --
> connecting to the database was more than half the cost!)
>
> Thanks (anyone),
>
> -Philip
>
> ------------------------------------
>
> Yahoo! Groups Links
>
>
>