New database corruption

[TrendTimer.com]

I posted another message awhile back about a corrupted H2 database.  It happened again for me tonight.  I get the following exception.

Caused by: org.h2.jdbc.JdbcSQLException: File corrupted while reading record: "page[2255] data leaf table:49 TRE_FUNDINFO entries:6 parent:291 keys:[307394, 307395, 307396, 307397, 307398, 307399] offsets:[1831, 1595, 1325, 1065, 830, 581]". Possible solution: use the recovery tool; SQL statement:

DELETE FROM `tre_fundinfo` WHERE `id` = ? [90030-171]

at org.h2.message.DbException.getJdbcSQLException(DbException.java:329)

at org.h2.message.DbException.get(DbException.java:169)

at org.h2.message.DbException.get(DbException.java:146)

...

I'm not sure what I might have done to cause this.  I do routinely shut down my application at different moments.  I don't think the application was writing data at the moment of shutdown, but it's possible.  Even if it was, I don't think this should corrupt the database.  Basically any time this happens my application is completely broken.  Given that it has happened to me twice in the last month, I'm concerned that this might be a frequent occurrence.  As we all know, data stored in databases can be important, so it is important that it doesn't get lost.  I understand there is a database recovery tool of some sort, but end users shouldn't be expected to run this kind of thing.   

when I select from the table in the H2 Console I get:

General error: "java.lang.ArrayIndexOutOfBoundsException: 0"; SQL statement:
select * from tre_fundinfo [50000-171] HY000/50000 (Help)

Thomas,  I have saved a copy of the corrupted database.  It's about 150MB (before zipping).  If you're interested, I could place this somewhere you could download it from.

Thanks!

[TrendTimer.com]

Also, I'm using version h2-1.3.171.jar

[Ryan How]

Sorry, you might have said in another post, but what connection string are you using?

Are you using it over a network drive?

OS?

Any Out of Memory errors on this database?


Thanks, Ryan

--
You received this message because you are subscribed to the Google Groups "H2 Database" group.
To unsubscribe from this group and stop receiving emails from it, send an email to h2-database...@googlegroups.com.
To post to this group, send email to h2-da...@googlegroups.com.
Visit this group at http://groups.google.com/group/h2-database?hl=en.
For more options, visit https://groups.google.com/groups/opt_out.
 
 

[Thomas Mueller]

Hi,

I would be interested in the database files (*.db, including the trace file if there is one). It would be great if you could send them to me.

Regards,

Thomas

 

[TrendTimer.com]

Thanks Thomas.  I'll post a download link for these tonight.  I appreciate your help!  I've really been impressed with H2 except for these corruption issues.  The start-up time could be improved, but the overall performance is great.

[TrendTimer.com]

Thomas, you can download my corrupt database here:

http://www.trendtimer.com/db_corrupt/trendtimerdb/trendtimerdb.trace.db

http://www.trendtimer.com/db_corrupt/trendtimerdb/trendtimerdb.h2.db

Connection string is: Constants.jdbcString="jdbc:h2:file:"+databaseFolder+databaseName;

I'm running on Windows 8.

I have 16gb ram and haven't seen any memory problems

It's not a network drive

and am running h2-1.3.171.jar

I'd appreciate it if you could take a look. thanks a lot!

[Thomas Mueller]

Hi,

Thanks for the database files. Unfortunately, I don't see currently what the problem could be. There are some very strange error messages in the .trace.db file just before the problem occurs (see below), but other than that I don't see anything strange yet. I guess there is something special to what the application does in your case that triggers the problem, but I'm not sure what it could be. My current guess is that it is either related to a query that internally create a temporary table, or it is related to how the database is closed, maybe some concurrent processing while the database is being closed. I'm unable to reproduce the problem on my side so far. 

I see this or a similar exception quite a lot in the .trace.db file:

04-16 20:46:13 jdbc[2]: exception
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-171]

at org.h2.message.DbException.getJdbcSQLException(DbException.java:329)
at org.h2.message.DbException.get(DbException.java:169)
at org.h2.message.DbException.get(DbException.java:146)

at org.h2.message.DbException.get(DbException.java:135)
at org.h2.jdbc.JdbcConnection.checkClosed(JdbcConnection.java:1391)
at org.h2.jdbc.JdbcConnection.checkClosed(JdbcConnection.java:1366)
at org.h2.jdbc.JdbcConnection.prepareStatement(JdbcConnection.java:627)
at com.j256.ormlite.jdbc.JdbcDatabaseConnection.queryForOne(JdbcDatabaseConnection.java:271)
at com.j256.ormlite.jdbc.JdbcDatabaseConnection.queryForLong(JdbcDatabaseConnection.java:208)
at com.j256.ormlite.jdbc.JdbcDatabaseConnection.queryForLong(JdbcDatabaseConnection.java:203)
at com.j256.ormlite.jdbc.JdbcPooledConnectionSource.testConnection(JdbcPooledConnectionSource.java:379)
at com.j256.ormlite.jdbc.JdbcPooledConnectionSource.access$600(JdbcPooledConnectionSource.java:38)
at com.j256.ormlite.jdbc.JdbcPooledConnectionSource$ConnectionTester.testConnections(JdbcPooledConnectionSource.java:489)
at com.j256.ormlite.jdbc.JdbcPooledConnectionSource$ConnectionTester.run(JdbcPooledConnectionSource.java:427)
04-16 20:46:34 database: close

This is the really strange message that happens before the database is corrupt:

org.h2.message.DbException: Row not found when trying to delete from index "PUBLIC.SYS_DATA: 62628 62661" [90112-171]

at org.h2.message.DbException.get(DbException.java:169)

at org.h2.message.DbException.get(DbException.java:146)

at org.h2.index.PageDataLeaf.remove(PageDataLeaf.java:411)

at org.h2.index.PageDataNode.remove(PageDataNode.java:240)

at org.h2.index.PageDataIndex.remove(PageDataIndex.java:330)

at org.h2.table.RegularTable.removeRow(RegularTable.java:362)

at org.h2.engine.Database.removeMeta(Database.java:798)

at org.h2.engine.Database.update(Database.java:1431)

at org.h2.schema.Sequence.flush(Sequence.java:127)

at org.h2.schema.Sequence.flushWithoutMargin(Sequence.java:105)

at org.h2.schema.Sequence.close(Sequence.java:143)

at org.h2.engine.Database.close(Database.java:1127)

at org.h2.engine.DatabaseCloser.run(DatabaseCloser.java:80)

Caused by: org.h2.jdbc.JdbcSQLException: Row not found when trying to delete from index "PUBLIC.SYS_DATA: 62628 62661" [90112-171]

at org.h2.message.DbException.getJdbcSQLException(DbException.java:329)

... 13 more

04-16 20:46:34 database: close

java.lang.RuntimeException: log.removeUntil not found: 55439 last 54986

at org.h2.message.DbException.throwInternalError(DbException.java:228)

at org.h2.store.PageLog.removeUntil(PageLog.java:729)

at org.h2.store.PageLog.removeUntil(PageLog.java:704)

at org.h2.store.PageStore.checkpoint(PageStore.java:434)

at org.h2.engine.Database.closeOpenFilesAndUnlock(Database.java:1195)

at org.h2.engine.Database.close(Database.java:1148)

at org.h2.engine.DatabaseCloser.run(DatabaseCloser.java:80)

04-16 20:46:52 jdbc[2]: exception

[TrendTimer.com]

Hello, thanks.  While working on this application, I sometimes kill the java process directly from eclipse and it's possible I've done this while the database was being written to.  It could be related to this.  Generally when users close the application, they'll close the JFrame (clicking on the X) which shuts down the JVM more gracefully.  Still, there's always a chance for the process to get terminated abruptly.

So have you spent much time looking into the H2 startup time?  When I launch my application about half the startup time is getting H2 started.  It's not terrible, but perhaps you could figure out ways to improve this. :)

[Ryan How]

I don't think I ever close the database properly within Eclipse :).

If you close the database without shutting it down properly startup time will be quite slow. The larger the database, the slower it is. If you shut it down correctly I find it very quick to start up.

[Noel Grandin]

On 2013-04-23 05:46, TrendTimer.com wrote:
>
>
> So have you spent much time looking into the H2 startup time? When I
> launch my application about half the startup time is getting H2
> started. It's not terrible, but perhaps you could figure out ways to
> improve this. :)

There are a couple of things you can try here:
(*) run SHUTDOWN COMPACT to compact the data, which will reduce the
amount of IO
(*) start H2 up in parallel with the rest of your application, using a
separate thread
(*) run a profiler and show us the trace so we can see where it's slow
in your use case (it's pretty fast for me)

[Thomas Mueller]

Hi,

How long is the startup about, in seconds? A long startup time could mean there is a long running transaction (not sure).

I guess creating a reproducible test case isn't easy, but could you send me a database file of an unclosed database file? Just use your application for a few minutes (the longer the better, the more active use the better), wait a few seconds, and copy the database file while the database is open. There might be some clue in the transaction log. In the database file you sent, the transaction log was empty, which is normal after opening the database.

Regards,

Thomas