It turned out that the problem was that I had the option
"FILE_LOCK=SERIALIZED" on the connection URL (so I lied when I said
there we no extra options). When that was removed, the problem went
away. So, looks like something may be a bit wonky with that
experimental flag.

Rob

On Feb 9, 3:04 pm, robeden <[email protected]> wrote:
> Hello all -
>
> I have an application using H2 in embedded mode. I made some unrelated
> changes and now I'm receiving the following exception:
>
> java.io.IOException: org.h2.jdbc.JdbcSQLException: Database is already
> closed (to disable automatic closing at VM shutdown, add
> ";DB_CLOSE_ON_EXIT=FALSE" to the db URL) [90121-147]
>         at
> com.trustedcs.ttc.data.impl.JDBCLocalData.confirmSnapshot_internal(JDBCLoca 
> lData.java:
> 766)
>         at
> com.trustedcs.ttc.data.impl.AbstractLocalData.confirmSnapshot(AbstractLocal 
> Data.java:
> 1061)
>         at
> com.trustedcs.ttc.data.impl.JDBCLocalData.confirmSnapshot(JDBCLocalData.jav a:
> 33)
>         at
> com.trustedcs.ttc.data.impl.JDBCLocalDataTest.testSnapshots(JDBCLocalDataTe 
> st.java:
> 284)
>         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>         at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:
> 39)
>         at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImp 
> l.java:
> 25)
>         at
> com.intellij.junit3.JUnit3IdeaTestRunner.doRun(JUnit3IdeaTestRunner.java:
> 109)
>         at
> com.intellij.junit3.JUnit3IdeaTestRunner.startRunnerWithArgs(JUnit3IdeaTest 
> Runner.java:
> 43)
>         at
> com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitSt 
> arter.java:
> 196)
>         at
> com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:
> 65)
>         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>         at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:
> 39)
>         at com.intellij.rt.execution.application.AppMain.main(AppMain.java:
> 115)
> Caused by: org.h2.jdbc.JdbcSQLException: Database is already closed
> (to disable automatic closing at VM shutdown, add
> ";DB_CLOSE_ON_EXIT=FALSE" to the db URL) [90121-147]
>         at org.h2.message.DbException.getJdbcSQLException(DbException.java:
> 327)
>         at org.h2.message.DbException.get(DbException.java:167)
>         at org.h2.message.DbException.get(DbException.java:144)
>         at org.h2.message.DbException.get(DbException.java:133)
>         at org.h2.jdbc.JdbcConnection.checkClosed(JdbcConnection.java:1333)
>         at org.h2.jdbcx.JdbcXAConnection
> $PooledJdbcConnection.checkClosed(JdbcXAConnection.java:519)
>         at org.h2.jdbc.JdbcConnection.checkClosed(JdbcConnection.java:1308)
>         at org.h2.jdbc.JdbcConnection.prepareStatement(JdbcConnection.java:
> 231)
>         at
> com.trustedcs.ttc.data.impl.JDBCLocalData.confirmSnapshot_internal(JDBCLoca 
> lData.java:
> 726)
>         ... 24 more
>
> I've added the requested parameter to the connection URL without any
> change.
>
> Here's the line where I create the DataSource:
>
>         this.data_source = JdbcConnectionPool.create(
>                 "jdbc:h2:" + H2_FS_HEADER + file_base.getPath() +
>                 ";DB_CLOSE_ON_EXIT=FALSE;MAX_MEMORY_ROWS=" + MAX_MEMORY_ROWS +
> H2_EXTRA_OPTIONS, "sa", "sa" );
>
> MAX_MEMORY_ROWS is set to "100000", no other extra options are
> currently specified.
>
> I close the Connection after I'm done with it each time, but dispose()
> is not being called on the DataSource.
>
> I've enabled trace level 3. Here's the last part of the file:
>
> ------------------------------------------------
> 02-09 15:00:00 database: opened C:\Users\reden.TCS\AppData\Local\Temp
> \ttc
> 02-09 15:00:00 database: connecting session #2 to C:\Users\reden.TCS
> \AppData\Local\Temp\ttc
> 02-09 15:00:00 jdbc[2]:
> /*SQL */SET FILE_LOCK SERIALIZED;
> 02-09 15:00:00 jdbc[2]:
> /*SQL */SET MAX_MEMORY_ROWS 100000;
> 02-09 15:00:00 jdbc[2]:
> /*SQL */SET OPEN_NEW TRUE;
> 02-09 15:00:00 jdbc[2]:
> /*SQL */SET TRACE_LEVEL_FILE 3;
> 02-09 15:00:00 jdbc[2]:
> /**/ResultSet rs17 = prep37.executeQuery();
> 02-09 15:00:00 lock: 1 exclusive write lock requesting for SYS
> 02-09 15:00:00 lock: 1 exclusive write lock added for SYS
> 02-09 15:00:00 index: SYS_DATA remove ( /* key:61 */ 31, 0, 3, 'CREATE
> SEQUENCE PUBLIC.SNAPSHOT_ID START WITH 1')
> 02-09 15:00:00 pageStore: log undo 529
> 02-09 15:00:00 pageStore: updateRecord page[529] data leaf table:0
> entries:10 parent:514 keys:[41, 43, 45, 47, 49, 51, 53, 55, 57, 65,
> 65] offsets:[1979, 1904, 1725, 1652, 1536, 1462, 1372, 1294, 1146,
> 1097, 1044]
> 02-09 15:00:00 pageStore: log undo 514
> 02-09 15:00:00 pageStore: updateRecord page[514] data node table:0
> entries:2 [524, 523, 529]
> 02-09 15:00:00 pageStore: log - s:1 table:0 row:( /* key:61 */ 31, 0,
> 3, 'CREATE SEQUENCE PUBLIC.SNAPSHOT_ID START WITH 1')
> 02-09 15:00:00 index: SYS_DATA add ( /* key:66 */ 31, 0, 3, 'CREATE
> SEQUENCE PUBLIC.SNAPSHOT_ID START WITH 33')
> 02-09 15:00:00 pageStore: log + s:1 table:0 row:( /* key:66 */ 31, 0,
> 3, 'CREATE SEQUENCE PUBLIC.SNAPSHOT_ID START WITH 33')
> 02-09 15:00:00 pageStore: log commit s:1
> 02-09 15:00:00 lock: 1 exclusive write lock unlock SYS
> 02-09 15:00:00 jdbc[2]:
> /*SQL #:1 t:2*/select snapshot_id.nextval;
> 02-09 15:00:00 jdbc[2]:
> /**/rs17.next();
> 02-09 15:00:00 jdbc[2]:
> /**/rs17.getInt(1);
> 02-09 15:00:00 jdbc[2]:
> /**/prep37.close();
> 02-09 15:00:00 jdbc[2]:
> /**/rs17.close();
> 02-09 15:00:00 jdbc[2]:
> /**/PreparedStatement prep38 = conn12.prepareStatement("select id
> data_id, data_key, data_value, replication_type, null snap_id from
> data where is_active = 't'");
> 02-09 15:00:00 jdbc[2]:
> /**/PreparedStatement prep39 = conn12.prepareStatement("insert into
> snapshot_info( id, ts, comment, user_id, confirmed ) values ( ?, ?,
> null, null, 'f' )");
> 02-09 15:00:00 jdbc[2]:
> /**/prep39.setInt(1, 1);
> 02-09 15:00:00 jdbc[2]:
> /**/prep39.setLong(2, 1297285197749L);
> 02-09 15:00:00 jdbc[2]:
> /**/prep39.executeUpdate();
> 02-09 15:00:00 lock: 2 exclusive write lock requesting for
> SNAPSHOT_INFO
> 02-09 15:00:00 lock: 2 exclusive write lock added for SNAPSHOT_INFO
> 02-09 15:00:00 index: SNAPSHOT_INFO_DATA add ( /* key:1 */ 1,
> 1297285197749, NULL, NULL, FALSE)
> 02-09 15:00:00 pageStore: log undo 527
> 02-09 15:00:00 pageStore: updateRecord page[527] data leaf table:23
> entries:1 parent:0 keys:[1, 0, 0, 0, 0] offsets:[2037, 0, 0, 0, 0]
> 02-09 15:00:00 pageStore: log + s:2 table:23 row:( /* key:1 */ 1,
> 1297285197749, NULL, NULL, FALSE)
> 02-09 15:00:00 index: CONFIRMED_IDX add ( /* key:1 */ 1,
> 1297285197749, NULL, NULL, FALSE)
> 02-09 15:00:00 pageStore: log undo 528
> 02-09 15:00:00 pageStore: updateRecord page[528] b-tree leaf table:26
> entries:1
> 02-09 15:00:00 jdbc[2]:
> /*SQL l:97 #:1 t:1*/insert into snapshot_info( id, ts, comment,
> user_id, confirmed ) values ( ?, ?, null, null, 'f' ) {1: 1, 2:
> 1297285197749};
> 02-09 15:00:00 pageStore: log commit s:2
> 02-09 15:00:00 lock: 2 exclusive write lock unlock SNAPSHOT_INFO
> 02-09 15:00:00 jdbc[2]:
> /**/prep39.close();
> 02-09 15:00:00 jdbc[2]:
> /**/PreparedStatement prep40 = conn12.prepareStatement("insert into
> snapshot( id, data_id ) values ( ?, ? )");
> 02-09 15:00:00 jdbc[2]:
> /**/prep40.setInt(1, 1);
> 02-09 15:00:00 jdbc[2]:
> /**/ResultSet rs18 = prep38.executeQuery();
> 02-09 15:00:00 lock: 2 shared read lock requesting for DATA
> 02-09 15:00:00 jdbc[2]:
> /*SQL #:2*/select id data_id, data_key, data_value, replication_type,
> null snap_id from data where is_active = 't';
> 02-09 15:00:00 jdbc[2]:
> /**/rs18.next();
> 02-09 15:00:00 jdbc[2]:
> /**/rs18.getInt("data_id");
> 02-09 15:00:00 jdbc[2]:
> /**/rs18.getString("data_key");
> 02-09 15:00:00 jdbc[2]:
> /**/rs18.getString("data_value");
> 02-09 15:00:00 jdbc[2]:
> /**/rs18.next();
> 02-09 15:00:00 jdbc[2]:
> /**/rs18.getInt("data_id");
> 02-09 15:00:00 jdbc[2]:
> /**/rs18.getString("data_key");
> 02-09 15:00:00 jdbc[2]:
> /**/rs18.getString("data_value");
> 02-09 15:00:00 jdbc[2]:
> /**/rs18.getByte("replication_type");
> 02-09 15:00:00 jdbc[2]:
> /**/prep40.setInt(2, 3);
> 02-09 15:00:00 jdbc[2]:
> /**/prep40.addBatch();
> 02-09 15:00:00 jdbc[2]:
> /**/rs18.next();
> 02-09 15:00:00 jdbc[2]:
> /**/prep40.executeBatch();
> 02-09 15:00:00 lock: 2 exclusive write lock requesting for SNAPSHOT
> 02-09 15:00:00 lock: 2 exclusive write lock added for SNAPSHOT
> 02-09 15:00:00 index: SNAPSHOT_DATA add ( /* key:1 */ 1, 3)
> 02-09 15:00:00 pageStore: log undo 530
> 02-09 15:00:00 pageStore: updateRecord page[530] data leaf table:27
> entries:1 parent:0 keys:[1, 0, 0, 0, 0] offsets:[2046, 0, 0, 0, 0]
> 02-09 15:00:00 pageStore: log + s:2 table:27 row:( /* key:1 */ 1, 3)
> 02-09 15:00:00 index: PRIMARY_KEY_3F add ( /* key:1 */ 1, 3)
> 02-09 15:00:00 pageStore: log undo 531
> 02-09 15:00:00 pageStore: updateRecord page[531] b-tree leaf table:28
> entries:1
> 02-09 15:00:00 lock: 2 shared read lock requesting for SNAPSHOT_INFO
> 02-09 15:00:00 jdbc[2]:
> /*SQL l:51 #:1 t:1*/insert into snapshot( id, data_id ) values
> ( ?, ? ) {1: 1, 2: 3};
> 02-09 15:00:00 pageStore: log commit s:2
> 02-09 15:00:00 lock: 2 exclusive write lock unlock SNAPSHOT
> 02-09 15:00:00 jdbc[2]:
> /**/conn12.commit();
> 02-09 15:00:00 jdbc[2]:
> /*SQL */COMMIT;
> 02-09 15:00:00 jdbc[2]:
> /**/prep40.close();
> 02-09 15:00:00 jdbc[2]:
> /**/conn12.rollback();
> 02-09 15:00:00 jdbc[2]:
> /*SQL */ROLLBACK;
> 02-09 15:00:00 jdbc[2]:
> /**/conn12.setAutoCommit(true);
> 02-09 15:00:00 jdbc[2]:
> /**/prep38.close();
> 02-09 15:00:00 jdbc[2]:
> /**/rs18.close();
> 02-09 15:00:00 database: checkpoint start
> 02-09 15:00:00 lock: 1 exclusive write lock requesting for SYS
> 02-09 15:00:00 lock: 1 exclusive write lock added for SYS
> 02-09 15:00:00 index: SYS_DATA remove ( /* key:66 */ 31, 0, 3, 'CREATE
> SEQUENCE PUBLIC.SNAPSHOT_ID START WITH 33')
> 02-09 15:00:00 pageStore: log - s:1 table:0 row:( /* key:66 */ 31, 0,
> 3, 'CREATE SEQUENCE PUBLIC.SNAPSHOT_ID START WITH 33')
> 02-09 15:00:00 index: SYS_DATA add ( /* key:68 */ 31, 0, 3, 'CREATE
> SEQUENCE PUBLIC.SNAPSHOT_ID START WITH 2')
> 02-09 15:00:00 pageStore: log + s:1 table:0 row:( /* key:68 */ 31, 0,
> 3, 'CREATE SEQUENCE PUBLIC.SNAPSHOT_ID START WITH 2')
> 02-09 15:00:00 pageStore: log commit s:1
> 02-09 15:00:00 lock: 1 exclusive write lock unlock SYS
> 02-09 15:00:00 pageStore: checkpoint
> 02-09 15:00:00 pageStore: pageOut.storePage [8] stream data key:3 pos:
> 989 remaining:1059
> 02-09 15:00:00 pageStore: pageOut.storePage fill 8
> 02-09 15:00:00 pageStore: writeBack page[514] data node table:0
> entries:2 [524, 523, 529]
> 02-09 15:00:00 pageStore: writeBack page[527] data leaf table:23
> entries:1 parent:0 keys:[1, 0, 0, 0, 0] offsets:[2037, 0, 0, 0, 0]
> 02-09 15:00:00 pageStore: writeBack page[528] b-tree leaf table:26
> entries:1
> 02-09 15:00:00 pageStore: writeBack page[529] data leaf table:0
> entries:11 parent:514 keys:[41, 43, 45, 47, 49, 51, 53, 55, 57, 65,
> 68] offsets:[1979, 1904, 1725, 1652, 1536, 1462, 1372, 1294, 1146,
> 1097, 1044]
> 02-09 15:00:00 pageStore: writeBack page[530] data leaf table:27
> entries:1 parent:0 keys:[1, 0, 0, 0, 0] offsets:[2046, 0, 0, 0, 0]
> 02-09 15:00:00 pageStore: writeBack page[531] b-tree leaf table:28
> entries:1
> 02-09 15:00:00 pageStore: getFirstUncommittedSection
> 02-09 15:00:00 pageStore: log.removeUntil 5 9
> 02-09 15:00:00 pageStore: setLogFirstPage key: 3 trunk: 5 data: 9
> 02-09 15:00:00 pageStore: writeVariableHeader
> 02-09 15:00:00 pageStore: pageOut.storePage [9] stream data key:3 pos:
> 12 remaining:2036
> 02-09 15:00:00 pageStore: pageOut.storePage fill 9
> 02-09 15:00:00 pageStore: writeFree
> 02-09 15:00:00 fileLock: load {changePending=true-0.6164730986723942,
> method=serialized, id=12e0c392c4e3ce552c23ab607b6c6dd8595a11ccb8e}
> 02-09 15:00:00 fileLock: save {logPos=1071, method=serialized,
> id=12e0c392c4e3ce552c23ab607b6c6dd8595a11ccb8e}
> 02-09 15:00:00 database: checkpoint end
> 02-09 15:00:02 jdbc[2]:
> /**/conn13.close();
> 02-09 15:00:02 fileLock: load {logPos=1071, method=serialized,
> id=12e0c392c4e3ce552c23ab607b6c6dd8595a11ccb8e}
> 02-09 15:00:02 database: disconnecting session #2
> 02-09 15:00:02 pageStore: close
> 02-09 15:00:02 pageStore: log close
> 02-09 15:00:02 fileLock: load {logPos=1071, method=serialized,
> id=12e0c392c4e3ce552c23ab607b6c6dd8595a11ccb8e}
> 02-09 15:00:02 database: disconnected session #2
> ------------------------------------------------
>
> Here's a link if you want to see the full 
> file:http://dl.dropbox.com/u/239809/ttc.trace.db
>
> Any suggestions?
>
> Thanks,
> Rob

-- 
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.

Reply via email to