org.h2.jdbc.JdbcSQLException: General error: "java.lang.RuntimeException: page[5528] data leaf table

[Sanjeev Gour]

Recently we saw the "data leaf table" related error in our environment and not sure what could have cause it. We are using the following options-

DB_CLOSE_ON_EXIT=FALSE;LOCK_TIMEOUT=10000;CACHE_SIZE=131072;CACHE_TYPE=SOFT_LRU;MVCC=TRUE

We are using it under JBoss and due to this error the JBoss data source was unable to connect to this DB. Here is the complete stack trace taken from the trace file-

09-04 11:41:46 jdbc[381]: exception
org.h2.jdbc.JdbcSQLException: General error: "java.lang.RuntimeException: page[5528] data leaf table:25 ACTION_AUDIT entries:23 parent:901 keys:[204462, 204463, 204464, 204465, 204466, 204467, 204468, 204469, 204470, 204471, 204472, 204473, 204474, 204475, 204476, 204477, 204478, 204479, 204480, 204481, 204482, 204483, 204484] offsets:[1987, 1926, 1865, 1804, 1743, 1682, 1621, 1560, 1499, 1438, 1377, 1316, 1256, 1195, 1134, 1073, 1012, 951, 890, 829, 768, 707, 646] parent 901 expected 4718"; SQL statement:
SELECT OBJFKEYXML, RULESTATE FROM actions.PREVIOUS_RULE_STATE WHERE POLICYFKEYXML like ? [50000-168]
    at org.h2.message.DbException.getJdbcSQLException(DbException.java:329)
    at org.h2.message.DbException.get(DbException.java:158)
    at org.h2.message.DbException.convert(DbException.java:281)
    at org.h2.command.Command.executeQuery(Command.java:195)
    at org.h2.jdbc.JdbcPreparedStatement.executeQuery(JdbcPreparedStatement.java:109)
    at org.jboss.jca.adapters.jdbc.WrappedPreparedStatement.executeQuery(WrappedPreparedStatement.java:462)
    at com.ca.chorus.db.DbExecutor.withResultSet(DbExecutor.java:380)
    at com.ca.chorus.db.DbExecutor.gatherResults(DbExecutor.java:893)
    at com.ca.chorus.db.DbExecutor.gatherResults(DbExecutor.java:886)
    at com.ca.chorus.actions.startup.RuleStateMonitor.retrieveRuleStatesForPolicy(RuleStateMonitor.java:541)
    at com.ca.chorus.actions.startup.RuleStateMonitor.access$200(RuleStateMonitor.java:46)
    at com.ca.chorus.actions.startup.RuleStateMonitor$2.<init>(RuleStateMonitor.java:167)
    at com.ca.chorus.actions.startup.RuleStateMonitor.checkRuleStateAndInvokeAction(RuleStateMonitor.java:157)
    at com.ca.chorus.actions.startup.RuleStateMonitor.access$100(RuleStateMonitor.java:46)
    at com.ca.chorus.actions.startup.RuleStateMonitor$1.onTuple(RuleStateMonitor.java:128)
    at com.ca.chorus.db.ExecuteAsyncStatementCallback.onRow(ExecuteAsyncStatementCallback.java:79)
    at com.ca.chorus.db.PerformanceInstrumentedStatementCallbackDecorator.onRow(PerformanceInstrumentedStatementCallbackDecorator.java:78)
    at com.ca.chorus.db.DbExecutor$12.onRow(DbExecutor.java:1396)
    at org.teiid.jdbc.NonBlockingRowProcessor.processRow(NonBlockingRowProcessor.java:117)
    at org.teiid.jdbc.NonBlockingRowProcessor$1.run(NonBlockingRowProcessor.java:83)
    at org.teiid.jdbc.NonBlockingRowProcessor$1$1.onCompletion(NonBlockingRowProcessor.java:76)
    at org.teiid.client.util.ResultsFuture.done(ResultsFuture.java:130)
    at org.teiid.client.util.ResultsFuture.access$200(ResultsFuture.java:37)
    at org.teiid.client.util.ResultsFuture$1.receiveResults(ResultsFuture.java:75)
    at org.teiid.jdbc.ResultSetImpl$1.onCompletion(ResultSetImpl.java:231)
    at org.teiid.client.util.ResultsFuture.done(ResultsFuture.java:130)
    at org.teiid.client.util.ResultsFuture.access$200(ResultsFuture.java:37)
    at org.teiid.client.util.ResultsFuture$1.receiveResults(ResultsFuture.java:75)
    at org.teiid.dqp.internal.process.RequestWorkItem.sendResultsIfNeeded(RequestWorkItem.java:757)
    at org.teiid.dqp.internal.process.RequestWorkItem$1.flushBatchDirect(RequestWorkItem.java:557)
    at org.teiid.query.processor.BatchCollector.flushBatch(BatchCollector.java:191)
    at org.teiid.query.processor.BatchCollector.collectTuples(BatchCollector.java:166)
    at org.teiid.dqp.internal.process.RequestWorkItem.processMore(RequestWorkItem.java:382)
    at org.teiid.dqp.internal.process.RequestWorkItem.process(RequestWorkItem.java:291)
    at org.teiid.dqp.internal.process.AbstractWorkItem.run(AbstractWorkItem.java:51)
    at org.teiid.dqp.internal.process.RequestWorkItem.run(RequestWorkItem.java:219)
    at org.teiid.dqp.internal.process.DQPWorkContext.runInContext(DQPWorkContext.java:249)
    at org.teiid.dqp.internal.process.ThreadReuseExecutor$RunnableWrapper.run(ThreadReuseExecutor.java:123)
    at org.teiid.dqp.internal.process.ThreadReuseExecutor$3.run(ThreadReuseExecutor.java:298)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1121)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:614)
    at java.lang.Thread.run(Thread.java:779)
Caused by: java.lang.RuntimeException: page[5528] data leaf table:25 ACTION_AUDIT entries:23 parent:901 keys:[204462, 204463, 204464, 204465, 204466, 204467, 204468, 204469, 204470, 204471, 204472, 204473, 204474, 204475, 204476, 204477, 204478, 204479, 204480, 204481, 204482, 204483, 204484] offsets:[1987, 1926, 1865, 1804, 1743, 1682, 1621, 1560, 1499, 1438, 1377, 1316, 1256, 1195, 1134, 1073, 1012, 951, 890, 829, 768, 707, 646] parent 901 expected 4718
    at org.h2.message.DbException.throwInternalError(DbException.java:228)
    at org.h2.index.PageDataIndex.getPage(PageDataIndex.java:239)
    at org.h2.index.PageDataNode.getNextPage(PageDataNode.java:226)
    at org.h2.index.PageDataLeaf.getNextPage(PageDataLeaf.java:392)
    at org.h2.index.PageDataCursor.nextRow(PageDataCursor.java:90)
    at org.h2.index.PageDataCursor.next(PageDataCursor.java:64)
    at org.h2.index.IndexCursor.next(IndexCursor.java:238)
    at org.h2.table.TableFilter.next(TableFilter.java:353)
    at org.h2.command.dml.Select.queryFlat(Select.java:513)
    at org.h2.command.dml.Select.queryWithoutCache(Select.java:618)
    at org.h2.command.dml.Query.query(Query.java:307)
    at org.h2.command.dml.Query.query(Query.java:277)
    at org.h2.command.dml.Query.query(Query.java:36)
    at org.h2.command.CommandContainer.query(CommandContainer.java:86)
    at org.h2.command.Command.executeQuery(Command.java:191)
    ... 38 more

Any clue on what could have cause it and how we can avoid encountering it would help.

Thanks.
Sanjeev

[Sanjeev Gour]

Update: We are using version 1.3.168.

[Noel Grandin]

There are three things you could try
(1) upgrade to the latest version
(2) turn off MVCC
(3) see if you reproduce the problem and then generate a standalone test case

In particular, MVCC is still a little bit experimental.
It works for some people, but not for others, and we're no longer actively working on the feature, so your chances of a bugfix are slim.

[Sanjeev Gour]

Thank you you response.

There are three things you could try

(1) upgrade to the latest version - We might not be able to do this immediately as this would require good testing of the application as it is already running in the production environment.

(2) turn off MVCC - Would it cause the read/write to the database to become noticeably slow?

(3) see if you reproduce the problem and then generate a standalone test case - Right now we don't have a standalone test case to reproduce that as we don't know under what circumstance it occurs. It just occurred once and a JBoss restart could recover from the problem.

Regards-
Sanjeev.

[Noel Grandin]

On 2013-09-06 11:43, Sanjeev Gour wrote:
>
> (2) turn off MVCC - Would it cause the read/write to the database to
> become noticeably slow?
>

It shouldn't.
We're pretty fast even in our default mode.

MVCC is mostly useful for applications with very high concurrency
requirements and where the read/write ratio is very high.

Thomas is working on a replacement engine, and when that is ready, we
will deprecate the existing engine and remove the MVCC option.

[Sanjeev Gour]

Ok, we shall try removing that to avoid even a rare case of databacse corruption.

[Devesh Mishra]

We have MVCC as false and still see the same problem appearing today. The database is corrupt now and we are required to go afresh :( 

Any suggestions would be really helpful. Thanks in advance

[Noel Grandin]

On 2014-06-26 01:37 PM, Devesh Mishra wrote:
> We have MVCC as false and still see the same problem appearing today. The database is corrupt now and we are required to
> go afresh :(
>

Please post the latest exception.

[Sanjeev Gour]

Here it is-

Caused by: org.h2.jdbc.JdbcSQLException: General error: "java.lang.RuntimeException: page[30284] data node table:167 entries:168 [1438, 1437, 2679, 2706, 2709, 2711, 2713, 2716, 3690, 3706, 3709, 4481, 12184, 16323, 16364, 16368, 16370, 16372, 16528, 16531, 16545, 16547, 16601, 16604, 16608, 16609, 16612, 16615, 16617, 16726, 16730, 16732, 17165, 17168, 17170, 17173, 17176, 17179, 17180, 17185, 17254, 17256, 17259, 17261, 17264, 17267, 17280, 17282, 17287, 17309, 17310, 17344, 17346, 17348, 17390, 17392, 17396, 17422, 17429, 17432, 17434, 17449, 17563, 17604, 17605, 17608, 17611, 17614, 17616, 17625, 17627, 17631, 17636, 17638, 17642, 17645, 17646, 17649, 17663, 17665, 17667, 17669, 17672, 17707, 17911, 17913, 17930, 17933, 18010, 18028, 18050, 18068, 18072, 18084, 18087, 18090, 18093, 18096, 18097, 18111, 18172, 18174, 18176, 18180, 18183, 18186, 18189, 18191, 18194, 18198, 18201, 18202, 18206, 18209, 18211, 18215, 18217, 18219, 18222, 18229, 18233, 18234, 18237, 18260, 18261, 18266, 18274, 18302, 18304, 18307, 18309, 18325, 18328, 18330, 18333, 18339, 18342, 18345, 18347, 18349, 18393, 18395, 18400, 18402, 18682, 18767, 18770, 18773, 18775, 18778, 18781, 18783, 18787, 18799, 18804, 18806, 18826, 18887, 18890, 18988, 19603, 19604, 20961, 21033, 21036, 21038, 21043, 21047, 22223] parent 148311 expected 5" [50000-168]

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

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

        at org.h2.message.DbException.convert(DbException.java:281)

        at org.h2.engine.Database.openDatabase(Database.java:252)

        at org.h2.engine.Database.<init>(Database.java:217)

        at org.h2.engine.Engine.openSession(Engine.java:56)

        at org.h2.engine.Engine.openSession(Engine.java:159)

Regards-
Sanjeev.

--
You received this message because you are subscribed to a topic in the Google Groups "H2 Database" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/h2-database/-Qq_JzYsjjY/unsubscribe.
To unsubscribe from this group and all its topics, send an email to h2-database+unsubscribe@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.
For more options, visit https://groups.google.com/d/optout.

[Noel Grandin]

On 2014-06-26 02:14 PM, Sanjeev Gour wrote:
> Here it is-

You chopped off the most important part of the exception.

[Devesh Mishra]

Here is the full log.

Caused by: org.h2.jdbc.JdbcSQLException: General error: "java.lang.RuntimeException: page[30284] data node table:167 entries:168 [1438, 1437, 2679, 2706, 2709, 2711, 2713, 2716, 3690, 3706, 3709, 4481, 12184, 16323, 16364, 16368, 16370, 16372, 16528, 16531, 16545, 16547, 16601, 16604, 16608, 16609, 16612, 16615, 16617, 16726, 16730, 16732, 17165, 17168, 17170, 17173, 17176, 17179, 17180, 17185, 17254, 17256, 17259, 17261, 17264, 17267, 17280, 17282, 17287, 17309, 17310, 17344, 17346, 17348, 17390, 17392, 17396, 17422, 17429, 17432, 17434, 17449, 17563, 17604, 17605, 17608, 17611, 17614, 17616, 17625, 17627, 17631, 17636, 17638, 17642, 17645, 17646, 17649, 17663, 17665, 17667, 17669, 17672, 17707, 17911, 17913, 17930, 17933, 18010, 18028, 18050, 18068, 18072, 18084, 18087, 18090, 18093, 18096, 18097, 18111, 18172, 18174, 18176, 18180, 18183, 18186, 18189, 18191, 18194, 18198, 18201, 18202, 18206, 18209, 18211, 18215, 18217, 18219, 18222, 18229, 18233, 18234, 18237, 18260, 18261, 18266, 18274, 18302, 18304, 18307, 18309, 18325, 18328, 18330, 18333, 18339, 18342, 18345, 18347, 18349, 18393, 18395, 18400, 18402, 18682, 18767, 18770, 18773, 18775, 18778, 18781, 18783, 18787, 18799, 18804, 18806, 18826, 18887, 18890, 18988, 19603, 19604, 20961, 21033, 21036, 21038, 21043, 21047, 22223] parent 148311 expected 5" [50000-168]
at org.h2.message.DbException.getJdbcSQLException(DbException.java:329)
at org.h2.message.DbException.get(DbException.java:158)
at org.h2.message.DbException.convert(DbException.java:281)
at org.h2.engine.Database.openDatabase(Database.java:252)
at org.h2.engine.Database.<init>(Database.java:217)
at org.h2.engine.Engine.openSession(Engine.java:56)
at org.h2.engine.Engine.openSession(Engine.java:159)

at org.h2.engine.Engine.createSessionAndValidate(Engine.java:138)
at org.h2.engine.Engine.createSession(Engine.java:121)
at org.h2.engine.Engine.createSession(Engine.java:28)
at org.h2.engine.SessionRemote.connectEmbeddedOrServer(SessionRemote.java:305)
at org.h2.jdbc.JdbcConnection.<init>(JdbcConnection.java:108)
at org.h2.jdbc.JdbcConnection.<init>(JdbcConnection.java:92)
at org.h2.Driver.connect(Driver.java:72)
at org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory.getLocalManagedConnection(LocalManagedConnectionFactory.java:249)
... 36 more
Caused by: java.lang.RuntimeException: page[30284] data node table:167 entries:168 [1438, 1437, 2679, 2706, 2709, 2711, 2713, 2716, 3690, 3706, 3709, 4481, 12184, 16323, 16364, 16368, 16370, 16372, 16528, 16531, 16545, 16547, 16601, 16604, 16608, 16609, 16612, 16615, 16617, 16726, 16730, 16732, 17165, 17168, 17170, 17173, 17176, 17179, 17180, 17185, 17254, 17256, 17259, 17261, 17264, 17267, 17280, 17282, 17287, 17309, 17310, 17344, 17346, 17348, 17390, 17392, 17396, 17422, 17429, 17432, 17434, 17449, 17563, 17604, 17605, 17608, 17611, 17614, 17616, 17625, 17627, 17631, 17636, 17638, 17642, 17645, 17646, 17649, 17663, 17665, 17667, 17669, 17672, 17707, 17911, 17913, 17930, 17933, 18010, 18028, 18050, 18068, 18072, 18084, 18087, 18090, 18093, 18096, 18097, 18111, 18172, 18174, 18176, 18180, 18183, 18186, 18189, 18191, 18194, 18198, 18201, 18202, 18206, 18209, 18211, 18215, 18217, 18219, 18222, 18229, 18233, 18234, 18237, 18260, 18261, 18266, 18274, 18302, 18304, 18307, 18309, 18325, 18328, 18330, 18333, 18339, 18342, 18345, 18347, 18349, 18393, 18395, 18400, 18402, 18682, 18767, 18770, 18773, 18775, 18778, 18781, 18783, 18787, 18799, 18804, 18806, 18826, 18887, 18890, 18988, 19603, 19604, 20961, 21033, 21036, 21038, 21043, 21047, 22223] parent 148311 expected 5

at org.h2.message.DbException.throwInternalError(DbException.java:228)
at org.h2.index.PageDataIndex.getPage(PageDataIndex.java:239)

at org.h2.index.PageDataNode.find(PageDataNode.java:164)
at org.h2.index.PageDataIndex.find(PageDataIndex.java:274)
at org.h2.table.RegularTable.addIndex(RegularTable.java:244)
at org.h2.store.PageStore.addMeta(PageStore.java:1685)
at org.h2.store.PageStore.readMetaData(PageStore.java:1590)
at org.h2.store.PageStore.recover(PageStore.java:1364)
at org.h2.store.PageStore.openExisting(PageStore.java:361)
at org.h2.store.PageStore.open(PageStore.java:285)
at org.h2.engine.Database.getPageStore(Database.java:2118)
at org.h2.engine.Database.open(Database.java:577)
at org.h2.engine.Database.openDatabase(Database.java:222)

[Noel Grandin]

For starters, I would suggest updating to 1.3.176.
You appear to be running 1.3.168, which is a couple of versions out of date, and we've fixed a lot of issues since then.

[Thomas Mueller]

Hi,

If the database is already corrupt, then I'm afraid you will need to re-create it (for example, via export to SQL script and re-import).

Bug fixed since version 1.3.168: With version 1.3.171 and older: when using local temporary tables and not dropping them manually before closing the session, and then killing the process could result in a database that couldn't be opened.

Regards,

Thomas

--
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+unsubscribe@googlegroups.com.

[Devesh Mishra]

Hi Thomas,

We have upgrade to 1.3.176 and are getting another error which is discussed in https://groups.google.com/forum/#!msg/h2-database/LfJX1m2h56g/533vOn5KjMMJ. Which version do you suggest us, 174 ? ?

Thanks,

Devesh

On Friday, June 27, 2014 3:50:16 PM UTC+5:30, Thomas Mueller wrote:

Hi,

If the database is already corrupt, then I'm afraid you will need to re-create it (for example, via export to SQL script and re-import).

Bug fixed since version 1.3.168: With version 1.3.171 and older: when using local temporary tables and not dropping them manually before closing the session, and then killing the process could result in a database that couldn't be opened.

Regards,

Thomas

On Fri, Jun 27, 2014 at 12:11 PM, Noel Grandin <noelg...@gmail.com> wrote:

For starters, I would suggest updating to 1.3.176.
You appear to be running 1.3.168, which is a couple of versions out of date, and we've fixed a lot of issues since then.

On 2014-06-27 10:15 AM, Noel Grandin wrote:

On 2014-06-26 02:14 PM, Sanjeev Gour wrote:

Here it is-

You chopped off the most important part of the exception.

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

[Thomas Mueller]

Hi,

As I wrote, you have two options:  One workaround is to not upgrade to version 1.3.176 if the database was created with an earlier version (use whatever version you are already using). Another workaround is to export the database file to a SQL script and re-create it. 

Regards,

Thomas

[Devesh Mishra]

We currently are using 168 version, which has the RunTImeException problem, we tried to move to 176 which has the upgrade issue. I would like to understand, would 174 be the right version ?

Thanks,

Devesh