efmarshall / h2database

Automatically exported from code.google.com/p/h2database
0 stars 0 forks source link

Database corruption when using MULTI_THREADED=1 #539

Open GoogleCodeExporter opened 9 years ago

GoogleCodeExporter commented 9 years ago
The database becomes corrupted occasionally when running H2 in multi threaded 
mode.

This has been discussed on the forum: 
https://groups.google.com/forum/#!topic/h2-database/MEYujXqbZYI

What steps will reproduce the problem?
(simple SQL scripts or simple standalone applications are preferred)
1. Start the attached application. It continously adds/deletes rows to/from 
some tables while other statements perform queries on these tables.

What is the expected output? What do you see instead?
The application should run fine without problems forever.

With 1.3.174 usually after ~10 minutes an exception is thrown:
General error: "java.lang.RuntimeException: Undo entry not written"; SQL 
statement:

What version of the product are you using? On what operating system, file
system, and virtual machine?
Linux 3.6 kernel, H2 1.3.174

Do you know a workaround?
Do not use H2 in multi threaded mode.

What is your use case, meaning why do you need this feature?
Some queries in my application need quite a long time which means users with 
small quick queries have to wait for this long running queries. Using the 
database in non multi threaded mode is possible but slows down the overall 
performance.

Original issue reported on code.google.com by u.wiel...@gematronik.com on 9 Jan 2014 at 9:16

Attachments:

GoogleCodeExporter commented 9 years ago
This issue also occurs in our application, but not very frequently. Even the 
rare occurences are big issue for us, because it requires re-filling the 
database with all data from our primary data storage. This procedure takes 
about 30 hours in our production environment.

We are using multi-threaded mode as well for performance reasons (same as 
mentioned by the author of this issue).

Last occurences happened with version 1.3.172 on CentOS 6.3.

We were not able to reproduce the issue in developer's workspace on Windows 7 
using the attached code.

Original comment by radek.kr...@gmail.com on 3 Feb 2014 at 12:36

GoogleCodeExporter commented 9 years ago
H2MultiThreadTest1: I tested before, but was not able to reproduce then. Now I 
tested again and got the exception("Undo entry not written"). I will 
investigate.

I also tried with the MVStore (append ";MV_STORE=TRUE" to the database URL), in 
the current trunk, and so far could not see a problem. But the MVStore is not 
ready for production yet.

Original comment by thomas.t...@gmail.com on 21 Feb 2014 at 5:10

GoogleCodeExporter commented 9 years ago
The problem seens to be: between writing the undo entry and writing the change, 
a checkpoint is written. This is unexpected, and therefore an exception is 
thrown. I'm not sure yet how to best solve this (I would like to avoid 
additional synchronization or locking), but I'm working on it.

Original comment by thomas.t...@gmail.com on 22 Feb 2014 at 6:52

GoogleCodeExporter commented 9 years ago
Please note this is only an issue for H2 version 1.3.x. With version 1.4.x, 
this code path is not used.

Original comment by thomas.t...@gmail.com on 16 Apr 2014 at 5:14

GoogleCodeExporter commented 9 years ago
The issue with "undo entry not written" still rarely occurs with version 
1.4.180. Last occurrence produced the following stacktrace. Other information 
from my comment #1 are still valid.

2014-07-23 11:33:51,457 [TP-Processor7 | u:xxx | sql: SELECT * FROM WORKITEM 
WHERE C_TYPE='defect' AND NOT C_SEVERITY='critical'] ERROR 
com.polarion.platform.sql.internal.runtime.Database  - General error: 
"java.lang.RuntimeException: Undo entry not written" [50000-180]
org.h2.jdbc.JdbcSQLException: General error: "java.lang.RuntimeException: Undo 
entry not written" [50000-180]
    at org.h2.message.DbException.getJdbcSQLException(DbException.java:345)
    at org.h2.message.DbException.get(DbException.java:168)
    at org.h2.message.DbException.convert(DbException.java:295)
    at org.h2.message.DbException.toSQLException(DbException.java:268)
    at org.h2.message.TraceObject.logAndConvert(TraceObject.java:352)
    at org.h2.jdbc.JdbcResultSet.next(JdbcResultSet.java:125)
...
Caused by: java.lang.RuntimeException: Undo entry not written
    at org.h2.message.DbException.throwInternalError(DbException.java:242)
    at org.h2.store.PageLog.addUndo(PageLog.java:501)
    at org.h2.store.PageStore.free(PageStore.java:1254)
    at org.h2.store.PageStore.free(PageStore.java:1237)
    at org.h2.index.PageDataIndex.remove(PageDataIndex.java:372)
    at org.h2.table.RegularTable.removeChildrenAndResources(RegularTable.java:723)
    at org.h2.result.ResultTempTable.dropTable(ResultTempTable.java:222)
    at org.h2.result.ResultTempTable.close(ResultTempTable.java:191)
    at org.h2.result.LocalResult.close(LocalResult.java:390)
    at org.h2.jdbc.JdbcResultSet.nextRow(JdbcResultSet.java:3234)
    at org.h2.jdbc.JdbcResultSet.next(JdbcResultSet.java:123)
    ... 78 more 

Original comment by radek.kr...@gmail.com on 23 Jul 2014 at 1:17

GoogleCodeExporter commented 9 years ago
I observed the "undo entry not written" problem with 1.4.187. 
The database file was initially created with 1.3.176. 
The database URL is 
jdbc:h2:test/data;LOCK_TIMEOUT=86400000;WRITE_DELAY=10000;MAX_MEMORY_ROWS=100000
0;MAX_OPERATION_MEMORY=50000000;MV_STORE=FALSE;MVCC=FALSE;MULTI_THREADED=TRUE

12.05.2015 07:22:06,452: ERROR [Quartz_uw_an-1] (Updater.executeUpdate:260) - 
unable to execute 'executeUpdate(   

insert into TABLE1(id)
select id from TABLE2
minus
select id from TABLE1;
    )'
org.h2.jdbc.JdbcSQLException: Allgemeiner Fehler: "java.lang.RuntimeException: 
Undo entry not written"
General error: "java.lang.RuntimeException: Undo entry not written" [50000-187]
    at org.h2.message.DbException.getJdbcSQLException(DbException.java:345)
    at org.h2.message.DbException.get(DbException.java:168)
    at org.h2.message.DbException.convert(DbException.java:295)
    at org.h2.table.RegularTable.removeRow(RegularTable.java:407)
    at org.h2.engine.UndoLogRecord.undo(UndoLogRecord.java:96)
    at org.h2.engine.Session.rollbackTo(Session.java:634)
    at org.h2.command.Command.executeUpdate(Command.java:278)
    at org.h2.jdbc.JdbcStatement.executeInternal(JdbcStatement.java:184)
    at org.h2.jdbc.JdbcStatement.execute(JdbcStatement.java:158)
    at org.myapp.Updater.execute(Updater.java:88)
    at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.RuntimeException: Undo entry not written
    at org.h2.message.DbException.throwInternalError(DbException.java:242)
    at org.h2.store.PageLog.addUndo(PageLog.java:501)
    at org.h2.store.PageStore.update(PageStore.java:1092)
    at org.h2.index.PageDataLeaf.remove(PageDataLeaf.java:430)
    at org.h2.index.PageDataNode.remove(PageDataNode.java:248)
    at org.h2.index.PageDataIndex.remove(PageDataIndex.java:344)
    at org.h2.table.RegularTable.removeRow(RegularTable.java:389)
    ... 13 more
12.05.2015 07:22:06,576: ERROR [Quartz_uw_an-1] (Updater.rollback:133) - 
org.h2.jdbc.JdbcSQLException: Allgemeiner Fehler: 
"java.lang.ArrayIndexOutOfBoundsException"
General error: "java.lang.ArrayIndexOutOfBoundsException"; SQL statement:
ROLLBACK [50000-187]
org.h2.jdbc.JdbcSQLException: Allgemeiner Fehler: 
"java.lang.ArrayIndexOutOfBoundsException"
General error: "java.lang.ArrayIndexOutOfBoundsException"; SQL statement:
ROLLBACK [50000-187]
    at org.h2.message.DbException.getJdbcSQLException(DbException.java:345)
    at org.h2.message.DbException.get(DbException.java:168)
    at org.h2.message.DbException.convert(DbException.java:295)
    at org.h2.table.RegularTable.removeRow(RegularTable.java:407)
    at org.h2.engine.UndoLogRecord.undo(UndoLogRecord.java:96)
    at org.h2.engine.Session.rollbackTo(Session.java:634)
    at org.h2.engine.Session.rollback(Session.java:602)
    at org.h2.command.dml.TransactionCommand.update(TransactionCommand.java:49)
    at org.h2.command.CommandContainer.update(CommandContainer.java:78)
    at org.h2.command.Command.executeUpdate(Command.java:254)
    at org.h2.jdbc.JdbcConnection.rollbackInternal(JdbcConnection.java:1501)
    at org.h2.jdbc.JdbcConnection.rollback(JdbcConnection.java:489)
    at org.myapp.Updater.rollback(Updater.java:128)
    at org.myapp.Updater.execute(Updater.java:88)
    at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.ArrayIndexOutOfBoundsException
    at org.h2.index.PageDataLeaf.removeRow(PageDataLeaf.java:304)
    at org.h2.index.PageDataLeaf.remove(PageDataLeaf.java:429)
    at org.h2.index.PageDataNode.remove(PageDataNode.java:248)
    at org.h2.index.PageDataIndex.remove(PageDataIndex.java:344)
    at org.h2.table.RegularTable.removeRow(RegularTable.java:389)
    ... 17 more

Original comment by u.wiel...@gematronik.com on 12 May 2015 at 7:44

GoogleCodeExporter commented 9 years ago
The problem also still appears with the testcase and 1.4.187.

org.h2.jdbc.JdbcSQLException: Allgemeiner Fehler: "java.lang.RuntimeException: 
Undo entry not written"
General error: "java.lang.RuntimeException: Undo entry not written"; SQL 
statement:
SELECT 28253713151973  "time", ifnull(v1.value, v.c1) "label1", 
ifnull(v2.value, v.c1) "label2"  FROM values('-nc-') v LEFT OUTER JOIN (     
SELECT vi1.value     FROM values_1 vi1     WHERE vi1.time = (SELECT min(time) 
FROM values_1 WHERE timeend > 28253713151973) AND vi1.time < 28253713151973 ) 
v1 ON 1=1 LEFT OUTER JOIN (     SELECT vi2.value     FROM values_1 vi2     
WHERE vi2.time = (SELECT min(time) FROM values_1 WHERE timeend > 
28253713151973) AND vi2.time < 28253713151973 ) v2 ON 1=1 UNION SELECT 
times.time, v1.value "label1", v2.value "label2" FROM   (    SELECT DISTINCT 
v.time    FROM values_1 v    WHERE v.time BETWEEN 28253713151973 and 
28423713151973    UNION    SELECT DISTINCT v.time    FROM values_1 v    WHERE 
v.time BETWEEN 28253713151973 and 28423713151973   ) AS times LEFT OUTER JOIN   
  values_1 v1     ON times.time=v1.time AND v1.time BETWEEN 28253713151973 AND 
28423713151973 LEFT OUTER JOIN     values_1 v2     ON times.time=v2.time AND 
v2.time BETWEEN 28253713151973 AND 28423713151973 ORDER BY "time"  LIMIT 500000 
 [50000-187]
org.h2.jdbc.JdbcSQLException: Allgemeiner Fehler: "java.lang.RuntimeException: 
Undo entry not written"
General error: "java.lang.RuntimeException: Undo entry not written"; SQL 
statement:
SELECT 28253713151973  "time", ifnull(v1.value, v.c1) "label1", 
ifnull(v2.value, v.c1) "label2"  FROM values('-nc-') v LEFT OUTER JOIN (     
SELECT vi1.value     FROM values_1 vi1     WHERE vi1.time = (SELECT min(time) 
FROM values_1 WHERE timeend > 28253713151973) AND vi1.time < 28253713151973 ) 
v1 ON 1=1 LEFT OUTER JOIN (     SELECT vi2.value     FROM values_1 vi2     
WHERE vi2.time = (SELECT min(time) FROM values_1 WHERE timeend > 
28253713151973) AND vi2.time < 28253713151973 ) v2 ON 1=1 UNION SELECT 
times.time, v1.value "label1", v2.value "label2" FROM   (    SELECT DISTINCT 
v.time    FROM values_1 v    WHERE v.time BETWEEN 28253713151973 and 
28423713151973    UNION    SELECT DISTINCT v.time    FROM values_1 v    WHERE 
v.time BETWEEN 28253713151973 and 28423713151973   ) AS times LEFT OUTER JOIN   
  values_1 v1     ON times.time=v1.time AND v1.time BETWEEN 28253713151973 AND 
28423713151973 LEFT OUTER JOIN     values_1 v2     ON times.time=v2.time AND 
v2.time BETWEEN 28253713151973 AND 28423713151973 ORDER BY "time"  LIMIT 500000 
 [50000-187]
    at org.h2.message.DbException.getJdbcSQLException(DbException.java:345)
    at org.h2.message.DbException.get(DbException.java:168)
    at org.h2.message.DbException.convert(DbException.java:295)
    at org.h2.table.RegularTable.addRow(RegularTable.java:137)
    at org.h2.result.ResultTempTable.addRow(ResultTempTable.java:153)
    at org.h2.result.ResultTempTable.addRows(ResultTempTable.java:170)
    at org.h2.result.LocalResult.addRow(LocalResult.java:289)
    at org.h2.command.dml.Select.queryFlat(Select.java:585)
    at org.h2.command.dml.Select.queryWithoutCache(Select.java:685)
    at org.h2.command.dml.Query.query(Query.java:322)
    at org.h2.command.dml.Query.query(Query.java:290)
    at org.h2.command.dml.SelectUnion.queryWithoutCache(SelectUnion.java:193)
    at org.h2.command.dml.SelectUnion.query(SelectUnion.java:425)
    at org.h2.command.dml.Query.query(Query.java:290)
    at org.h2.index.ViewIndex.find(ViewIndex.java:272)
    at org.h2.index.ViewIndex.find(ViewIndex.java:177)
    at org.h2.index.BaseIndex.find(BaseIndex.java:127)
    at org.h2.index.IndexCursor.find(IndexCursor.java:159)
    at org.h2.table.TableFilter.next(TableFilter.java:329)
    at org.h2.command.dml.Select.queryFlat(Select.java:573)
    at org.h2.command.dml.Select.queryWithoutCache(Select.java:685)
    at org.h2.command.dml.Query.query(Query.java:322)
    at org.h2.command.dml.Query.query(Query.java:290)
    at org.h2.command.dml.SelectUnion.queryWithoutCache(SelectUnion.java:194)
    at org.h2.command.dml.SelectUnion.query(SelectUnion.java:425)
    at org.h2.command.dml.Query.query(Query.java:290)
    at org.h2.command.dml.Query.query(Query.java:36)
    at org.h2.command.CommandContainer.query(CommandContainer.java:90)
    at org.h2.command.Command.executeQuery(Command.java:197)
    at org.h2.jdbc.JdbcStatement.executeQuery(JdbcStatement.java:79)
    at H2MultiThreadTest1$Selector2.run(H2MultiThreadTest1.java:204)
    at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.RuntimeException: Undo entry not written
    at org.h2.message.DbException.throwInternalError(DbException.java:242)
    at org.h2.store.PageLog.addUndo(PageLog.java:501)
    at org.h2.store.PageStore.update(PageStore.java:1092)
    at org.h2.index.PageDataLeaf.addRowTry(PageDataLeaf.java:208)
    at org.h2.index.PageDataNode.addRowTry(PageDataNode.java:130)
    at org.h2.index.PageDataIndex.addTry(PageDataIndex.java:173)
    at org.h2.index.PageDataIndex.add(PageDataIndex.java:136)
    at org.h2.table.RegularTable.addRow(RegularTable.java:119)
    ... 28 more

Original comment by u.wiel...@gematronik.com on 12 May 2015 at 2:27

GoogleCodeExporter commented 9 years ago
Note that the database URL in the testcase need to be modified so that MVStore 
is not used.
Attached file corrects the test case.

Original comment by u.wiel...@gematronik.com on 12 May 2015 at 2:29

Attachments: