Hi,
disabling DB_CLOSE_DELAY (setting to -1) did not help at all. Still
got the same results.
I am attaching stripped log (I have also removed date/time for better
reading) with 3 threads reading concurrently from simple table (NODE:
ID, ID_PARENT, KEY, VALUE). As you can see the database is beeing
closed and reopened again and again.
The log (long - sorry):
/**/Connection conn1209 =
DriverManager.getConnection("jdbc:h2:myDB;ACCESS_MODE_LOG=r;ACCESS_MODE_DATA=r;DB_CLOSE_DELAY=-1;TRACE_LEVEL_SYSTEM_OUT=3",
"", "")
jdbc[1211]:
/**/PreparedStatement prep1203 = conn1209.prepareStatement("SELECT *
FROM NODE WHERE ID_PARENT = ?");
jdbc[1209]:
/**/conn1207.close();
jdbc[1209]:
/*SQL */ROLLBACK;
session: disconnecting #1209
session: disconnected #1209
jdbc[1211]:
/**/prep1203.setInt(1, 438);
jdbc[1211]:
/**/ResultSet rs1203 = prep1203.executeQuery();
jdbc[1211]:
/*SQL l:38*/SELECT * FROM NODE WHERE ID_PARENT = ? {1: 438};
session: connecting #1212 to myDB
jdbc[1212]:
/*SQL */SET ACCESS_MODE_LOG r;
jdbc[1212]:
/*SQL */SET TRACE_LEVEL_SYSTEM_OUT 3;
jdbc[1212]:
/*SQL */SET ACCESS_MODE_DATA r;
jdbc[1212]:
/*SQL */SET DB_CLOSE_DELAY -1;
session: connected #1212
jdbc[1211]:
/**/rs1203.next();
jdbc[1211]:
/**/prep1203.close();
jdbc[1212]:
/**/Connection conn1210 =
DriverManager.getConnection("jdbc:h2:myDB;ACCESS_MODE_LOG=r;ACCESS_MODE_DATA=r;DB_CLOSE_DELAY=-1;TRACE_LEVEL_SYSTEM_OUT=3",
"", "")
jdbc[1212]:
/**/PreparedStatement prep1204 = conn1210.prepareStatement("SELECT *
FROM NODE WHERE ID_PARENT = ?");
jdbc[1210]:
/**/conn1208.close();
jdbc[1212]:
/**/prep1204.setInt(1, 11561);
jdbc[1212]:
/**/ResultSet rs1204 = prep1204.executeQuery();
jdbc[1210]:
/*SQL */ROLLBACK;
session: disconnecting #1210
session: disconnected #1210
jdbc[1212]:
/*SQL l:38 #:11*/SELECT * FROM NODE WHERE ID_PARENT = ? {1: 11561};
session: connecting #1213 to myDB
jdbc[1212]:
/**/rs1204.next();
jdbc[1213]:
/*SQL */SET ACCESS_MODE_LOG r;
jdbc[1212]:
/**/rs1204.getInt("ID");
jdbc[1213]:
/*SQL */SET TRACE_LEVEL_SYSTEM_OUT 3;
jdbc[1212]:
/**/rs1204.getInt("ID_PARENT");
jdbc[1212]:
/**/rs1204.getString("KEY");
jdbc[1212]:
/**/rs1204.getObject("VALUE");
jdbc[1213]:
/*SQL */SET ACCESS_MODE_DATA r;
jdbc[1212]:
/**/rs1204.next();
jdbc[1212]:
/**/rs1204.getInt("ID");
jdbc[1213]:
/*SQL */SET DB_CLOSE_DELAY -1;
jdbc[1212]:
/**/rs1204.getInt("ID_PARENT");
jdbc[1212]:
/**/rs1204.getString("KEY");
jdbc[1212]:
/**/rs1204.getObject("VALUE");
jdbc[1212]:
/**/rs1204.next();
jdbc[1212]:
/**/rs1204.getInt("ID");
jdbc[1212]:
/**/rs1204.getInt("ID_PARENT");
session: connected #1213
jdbc[1212]:
/**/rs1204.getString("KEY");
jdbc[1212]:
/**/rs1204.getObject("VALUE");
jdbc[1213]:
/**/Connection conn1211 =
DriverManager.getConnection("jdbc:h2:myDB;ACCESS_MODE_LOG=r;ACCESS_MODE_DATA=r;DB_CLOSE_DELAY=-1;TRACE_LEVEL_SYSTEM_OUT=3",
"", "")
jdbc[1213]:
/**/PreparedStatement prep1205 = conn1211.prepareStatement("SELECT *
FROM NODE WHERE ID_PARENT = ?");
jdbc[1211]:
/**/conn1209.close();
jdbc[1211]:
/*SQL */ROLLBACK;
session: disconnecting #1211
session: disconnected #1211
jdbc[1212]:
/**/rs1204.next();
jdbc[1213]:
/**/prep1205.setInt(1, 9902);
session: connecting #1214 to myDB
jdbc[1214]:
/*SQL */SET ACCESS_MODE_LOG r;
jdbc[1214]:
/*SQL */SET TRACE_LEVEL_SYSTEM_OUT 3;
jdbc[1213]:
/**/ResultSet rs1205 = prep1205.executeQuery();
jdbc[1212]:
/**/rs1204.getInt("ID");
jdbc[1214]:
/*SQL */SET ACCESS_MODE_DATA r;
jdbc[1213]:
/*SQL l:38*/SELECT * FROM NODE WHERE ID_PARENT = ? {1: 9902};
jdbc[1213]:
/**/rs1205.next();
jdbc[1213]:
/**/prep1205.close();
jdbc[1212]:
/**/rs1204.getInt("ID_PARENT");
jdbc[1212]:
/**/rs1204.getString("KEY");
jdbc[1212]:
/**/rs1204.getObject("VALUE");
jdbc[1212]:
/**/rs1204.next();
jdbc[1212]:
/**/rs1204.getInt("ID");
jdbc[1212]:
/**/rs1204.getInt("ID_PARENT");
jdbc[1212]:
/**/rs1204.getString("KEY");
jdbc[1212]:
/**/rs1204.getObject("VALUE");
jdbc[1212]:
/**/rs1204.next();
jdbc[1212]:
/**/rs1204.getInt("ID");
jdbc[1212]:
/**/rs1204.getInt("ID_PARENT");
jdbc[1212]:
/**/rs1204.getString("KEY");
jdbc[1212]:
/**/rs1204.getObject("VALUE");
jdbc[1212]:
/**/rs1204.next();
jdbc[1212]:
/**/rs1204.getInt("ID");
jdbc[1212]:
/**/rs1204.getInt("ID_PARENT");
jdbc[1212]:
/**/rs1204.getString("KEY");
jdbc[1212]:
/**/rs1204.getObject("VALUE");
jdbc[1212]:
/**/rs1204.next();
jdbc[1212]:
/**/rs1204.getInt("ID");
jdbc[1212]:
/**/rs1204.getInt("ID_PARENT");
jdbc[1212]:
/**/rs1204.getString("KEY");
jdbc[1212]:
/**/rs1204.getObject("VALUE");
jdbc[1212]:
/**/rs1204.next();
jdbc[1212]:
/**/rs1204.getInt("ID");
jdbc[1212]:
/**/rs1204.getInt("ID_PARENT");
jdbc[1212]:
/**/rs1204.getString("KEY");
jdbc[1212]:
/**/rs1204.getObject("VALUE");
jdbc[1214]:
/*SQL */SET DB_CLOSE_DELAY -1;
session: connected #1214
jdbc[1212]:
/**/rs1204.next();
jdbc[1212]:
/**/rs1204.getInt("ID");
jdbc[1212]:
/**/rs1204.getInt("ID_PARENT");
jdbc[1212]:
/**/rs1204.getString("KEY");
jdbc[1212]:
/**/rs1204.getObject("VALUE");
jdbc[1214]:
/**/Connection conn1212 =
DriverManager.getConnection("jdbc:h2:myDB;ACCESS_MODE_LOG=r;ACCESS_MODE_DATA=r;DB_CLOSE_DELAY=-1;TRACE_LEVEL_SYSTEM_OUT=3",
"", "")
jdbc[1214]:
/**/PreparedStatement prep1206 = conn1212.prepareStatement("SELECT *
FROM NODE WHERE ID_PARENT = ?");
jdbc[1212]:
/**/rs1204.next();
jdbc[1212]:
/**/rs1204.getInt("ID");
jdbc[1212]:
/**/rs1204.getInt("ID_PARENT");
jdbc[1212]:
/**/rs1204.getString("KEY");
jdbc[1212]:
/**/rs1204.getObject("VALUE");
jdbc[1212]:
/**/rs1204.next();
jdbc[1212]:
/**/prep1204.close();
jdbc[1214]:
/**/prep1206.setInt(1, 439);
jdbc[1213]:
/**/conn1211.close();
jdbc[1214]:
/**/ResultSet rs1206 = prep1206.executeQuery();
jdbc[1213]:
/*SQL */ROLLBACK;
jdbc[1214]:
/*SQL l:38*/SELECT * FROM NODE WHERE ID_PARENT = ? {1: 439};
jdbc[1214]:
/**/rs1206.next();
jdbc[1214]:
/**/prep1206.close();
session: disconnecting #1213
session: disconnected #1213
session: connecting #1215 to myDB
...
etc etc
...
On 17 Říj, 22:55, Lukas Zapletal <[EMAIL PROTECTED]> wrote:
> Hi,
>
> I have been told by Christian d'Heureuse to set the DB_CLOSE_DELAY
> parameter to -1. I will try on monday.
>
> LZ
>
> On 17 Říj, 13:50, Lukas Zapletal <[EMAIL PROTECTED]> wrote:
>
> > We have found the problem is in the org.h2.jdbcx.JdbcConnectionPool in
> > this method:
>
> > private Connection getConnectionNow() throws SQLException {
> > if (isDisposed) {
> > throw new IllegalStateException("Connection pool has been
> > disposed.");
> > }
> > PooledConnection pc;
> > if (!recycledConnections.empty()) {
> > pc = (PooledConnection) recycledConnections.pop();
> > } else {
> > pc = dataSource.getPooledConnection();
> > }
> > Connection conn = pc.getConnection(); // here
> > activeConnections++;
> > pc.addConnectionEventListener(poolConnectionEventListener);
> > return conn;
> > }
>
> > It calls PooledConnection.getConnection() on every connection client
> > request. The documentation of the Connection
> > javax.sql.PooledConnection.getConnection() throws SQLException is:
>
> > Creates and returns a Connection object that is a handle for the
> > physical connection that this PooledConnection object represents. The
> > connection pool manager calls this method when an application has
> > called the method DataSource.getConnection and there are no
> > PooledConnection objects available. See the interface description for
> > more information. Returns: a Connection object that is a handle to
> > this PooledConnection object Throws:
> > SQLException - if a database access error occurs;
> > SQLFeatureNotSupportedException - if the JDBC driver does not support
> > this method.
>
> > If I understand correctly this method should be called only if there
> > are no other connections in the pool. The implementation from H2 (and
> > the MiniConnectionPoolManager) calls this every time. Since the H2
> > implementation of the org.h2.jdbcx.JdbcXAConnection.getConnection
> > closes and reopens the connection its the cause of slowness -> every
> > request to the connection pool = close/create connection. In embedded
> > mode = close/open database files which is very slow.
>
> > I just wanted to give you the results from my investigation - maybe
> > you will be interested in (or maybe am I totally missing somehting).
> > Thanks for H2/MiniConnectionPoolManager anyway - great pieces of
> > software.
>
> > LZ
>
> > On 16 Říj, 14:32, Lukas Zapletal <[EMAIL PROTECTED]> wrote:
>
> > > Hi,
>
> > > I am reading from a one embedded table (one milion of records). I am
> > > doing very intensive small reads (1-10 records) of all records.
>
> > > When I am doing this in one connection I am done in 7 seconds.
>
> > > When I use the JdbcConnectionPool (with one thread - one connection)
> > > the very same thing is about 25 seconds.
>
> > > This is very strange. I understand that using connection pool is a bit
> > > slower than using one connection but three times? Since there is only
> > > one thread and one connection in the pool there should not be any
> > > blocking (waiting). Why am I getting these results?
>
> > > Thanks
--~--~---------~--~----~------------~-------~--~----~
You received this message because you are subscribed to the Google Groups "H2
Database" group.
To post to this group, send email to [email protected]
To unsubscribe from this group, send email to [EMAIL PROTECTED]
For more options, visit this group at
http://groups.google.com/group/h2-database?hl=en
-~----------~----~----~----~------~----~------~--~---
