Cannot open database due key violation SYS_ID

[GoogleCodeExporter]

Linux 2.6.19-gentoo-r5
JRE 1.6.0_05-b13
Ext3 filesystem on normal hard drives (local filesystem)
databases created with H2 version 1.0.79
opened with error on  1.0.79 and 1.1.107

Unique index or primary key violation: SYS_ID  ON PUBLIC.SYS(ID) [23001-79]
23001/23001 (Help)
org.h2.jdbc.JdbcSQLException: Unique index or primary key violation: SYS_ID  ON
PUBLIC.SYS(ID) [23001-79]
    at org.h2.message.Message.getSQLException(Message.java:103)
    at org.h2.message.Message.getSQLException(Message.java:114)
    at org.h2.message.Message.getSQLException(Message.java:77)
    at org.h2.index.BaseIndex.getDuplicateKeyException(BaseIndex.java:160)
    at org.h2.index.TreeIndex.add(TreeIndex.java:58)
    at org.h2.table.TableData.addRowsToIndex(TableData.java:278)
    at org.h2.table.TableData.addIndex(TableData.java:210)
    at org.h2.engine.Database.open(Database.java:553)
    at org.h2.engine.Database.<init>(Database.java:210)
    at org.h2.engine.Engine.openSession(Engine.java:57)
    at org.h2.engine.Engine.openSession(Engine.java:126)
    at org.h2.engine.Engine.getSession(Engine.java:109) 

H2 running in embedded mode in java se application
Bug cannot be reproduced intentionally
Transaction log was not disabled (LOG=2)
Databases in simple binary mode
database user 'sa' password empty string ''
Database with error and trace file attached to issue
trace file contains detailed stack trace

deleting index file does not worked

When deleted transaction log or run with RECOVERY=1
 I got another problem

org.h2.jdbc.JdbcSQLException: General error: java.lang.RuntimeException:
double allocation in file D:\provisioning-1.2\default.data.db page 1 blocks
64-127 [50000-107]
    at org.h2.message.Message.getSQLException(Message.java:103)
    at org.h2.message.Message.convert(Message.java:274)
    at org.h2.engine.Database.<init>(Database.java:235)
    at org.h2.engine.Engine.openSession(Engine.java:57)
    at org.h2.engine.Engine.openSession(Engine.java:126)
    at org.h2.engine.Engine.getSession(Engine.java:109)
    at
org.h2.engine.SessionFactoryEmbedded.createSession(SessionFactoryEmbedded.java:1
7)
    at
org.h2.engine.SessionRemote.connectEmbeddedOrServer(SessionRemote.java:251)
    at org.h2.engine.SessionRemote.createSession(SessionRemote.java:229)
    at org.h2.jdbc.JdbcConnection.<init>(JdbcConnection.java:111)
    at org.h2.jdbc.JdbcConnection.<init>(JdbcConnection.java:95)
    at org.h2.Driver.connect(Driver.java:58)
    at org.h2.server.web.WebServer.getConnection(WebServer.java:631)
    at org.h2.server.web.WebThread$1LoginTask.run(WebThread.java:1175)
    at java.lang.Thread.run(Unknown Source)
Caused by: java.lang.RuntimeException: double allocation in file
D:\troubles\UPS\.private\easysoft.persistence\provisioning-1.2\default.data.db
page 1 blocks 64-127
    at org.h2.message.Message.throwInternalError(Message.java:182)
    at org.h2.store.DiskFile.setPageOwner(DiskFile.java:798)
    at org.h2.store.DiskFile.setBlockOwner(DiskFile.java:681)
    at org.h2.store.DiskFile.init(DiskFile.java:429)
    at org.h2.engine.Database.open(Database.java:505)
    at org.h2.engine.Database.<init>(Database.java:210)
    ... 12 more 

I have run recover tool and it generated script.
I attached it too

Original issue reported on code.google.com by e.lucash@gmail.com on 19 Feb 2009 at 1:27

[GoogleCodeExporter]

Most likely the problem was fixed in version 1.1.108 (2009-02-28).
See http://www.h2database.com/html/changelog.html
"When the shutdown hook closed the database, the last log file was deleted too 
early.
This could cause uncommitted changes to be persisted."

After the bug was fixed, I also found out it could cause database corruption.

If the problem still occurs with newer versions, please re-open this bug or 
create a
new one.

Original comment by thomas.t...@gmail.com on 3 Apr 2009 at 12:36

• Changed state: Accepted

[GoogleCodeExporter]

I will close this bug for now.

Original comment by thomas.t...@gmail.com on 3 Apr 2009 at 12:37

• Changed state: Fixed

[GoogleCodeExporter]

We are still getting this error in version 1.1.110.  The full stack trace is
attached.  Let me know if you'd like a copy of the database.

2009-04-22 13:47:36,362 INFO  
[com.anfcorp.stores.pos.common.startup.StartupContext]
[main] org.springframework.jdbc.CannotGetJdbcConnectionException: Could not get 
JDBC
Connection; nested exception is org.apache.commons.dbcp.SQLNestedException: 
Cannot
create PoolableConnectionFactory (General error: java.lang.RuntimeException: 
double
allocation in file /work/anf-pos/POSDB.index.db page 37 blocks 2368-2431 
[50000-110])
    at
org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtil
s.java:82)
    at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:331)
    at
com.anfcorp.stores.db.install.AbstractDatabaseSupport.getDbProductName(AbstractD
atabaseSupport.java:61)
    at
com.anfcorp.stores.db.install.AbstractDatabaseSupport.getPlatform(AbstractDataba
seSupport.java:39)
    at com.anfcorp.stores.db.install.DatabaseInstaller.install(DatabaseInstaller.java:61)
    at
com.anfcorp.stores.db.install.MultipleDatabaseInstaller.install(MultipleDatabase
Installer.java:22)
    at
com.anfcorp.stores.pos.common.startup.DatabaseStartupTask.doCurrentTask(Database
StartupTask.java:33)
    at
com.anfcorp.stores.pos.common.startup.StartupController.doList(StartupController
.java:42)
    at
com.anfcorp.stores.pos.common.startup.StartupController.start(StartupController.
java:33)
    at com.anfcorp.stores.pos.startup.POSStartup.main(POSStartup.java:10)
Caused by: org.apache.commons.dbcp.SQLNestedException: Cannot create
PoolableConnectionFactory (General error: java.lang.RuntimeException: double
allocation in file /work/anf-pos/POSDB.index.db page 37 blocks 2368-2431 
[50000-110])
    at org.apache.commons.dbcp.BasicDataSource.createDataSource(BasicDataSource.java:855)
    at org.apache.commons.dbcp.BasicDataSource.getConnection(BasicDataSource.java:540)
    at
org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUt
ils.java:113)
    at
org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtil
s.java:79)
    ... 9 more
Caused by: org.h2.jdbc.JdbcSQLException: General error: 
java.lang.RuntimeException:
double allocation in file /work/anf-pos/POSDB.index.db page 37 blocks 2368-2431
[50000-110]
    at org.h2.message.Message.getSQLException(Message.java:107)
    at org.h2.message.Message.convert(Message.java:279)
    at org.h2.engine.Database.open(Database.java:569)
    at org.h2.engine.Database.openDatabase(Database.java:223)
    at org.h2.engine.Database.<init>(Database.java:218)
    at org.h2.engine.Engine.openSession(Engine.java:57)
    at org.h2.engine.Engine.openSession(Engine.java:139)
    at org.h2.engine.Engine.getSession(Engine.java:119)
    at org.h2.engine.SessionFactoryEmbedded.createSession(SessionFactoryEmbedded.java:17)
    at org.h2.engine.SessionRemote.connectEmbeddedOrServer(SessionRemote.java:248)
    at org.h2.engine.SessionRemote.createSession(SessionRemote.java:226)
    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:58)
    at
org.apache.commons.dbcp.DriverConnectionFactory.createConnection(DriverConnectio
nFactory.java:37)
    at
org.apache.commons.dbcp.PoolableConnectionFactory.makeObject(PoolableConnectionF
actory.java:290)
    at
org.apache.commons.dbcp.BasicDataSource.validateConnectionFactory(BasicDataSourc
e.java:877)
    at org.apache.commons.dbcp.BasicDataSource.createDataSource(BasicDataSource.java:851)
    ... 12 more
Caused by: java.lang.RuntimeException: double allocation in file
/work/anf-pos/POSDB.index.db page 37 blocks 2368-2431
    at org.h2.message.Message.throwInternalError(Message.java:187)
    at org.h2.store.DiskFile.setPageOwner(DiskFile.java:786)
    at org.h2.store.DiskFile.setBlockOwner(DiskFile.java:669)
    at org.h2.store.DiskFile.init(DiskFile.java:417)
    at org.h2.engine.Database.open(Database.java:555)
    ... 27 more

Original comment by mrupt...@gmail.com on 22 Apr 2009 at 6:00

[GoogleCodeExporter]

Hi,

Sorry for the delay! Could you send me a copy of the database? Please use the 
email
address dbsupport -at- h2database -dot- com. I have some more questions:

- What is your database URL?
- Do you use Tomcat or another web server? Do you unload or reload the 
  web application?
- What version H2 are you using?
- Did you use multiple connections?
- Do you use any settings or special features (for example, the setting LOG=0,
    or two phase commit, linked tables, cache settings)?
- Is the application multi-threaded?
- What operating system, file system, and virtual machine
    (java -version) do you use?
- Is it (or was it at some point) a networked file system?
- Is the database usually closed normally, or is process terminated forcefully
    or the computer switched off?
- Is it possible to reproduce this problem using a fresh database
    (sometimes, or always)?

Original comment by thomas.t...@gmail.com on 27 Apr 2009 at 6:40

• Changed state: Accepted

[GoogleCodeExporter]

Closed due to no activity since one month.
Please re-open if necessary.

Original comment by thomas.t...@gmail.com on 29 May 2009 at 4:11

• Changed state: Invalid

[GoogleCodeExporter]

I, as original reporter of this issue can confirm that issue is still valid for 
h2 engine. I have 
upgraded from 1.0.79 to 1.1.111 on about ~1000 of remote kiosk machines (it 
took some time eventually)... As suggested in comment #1, problem might got 
solved. But after month of monitoring 
problem was spotted 17 times on version 1.1.111. Seems that problem appeared 
more often than before. 
As workaround, on startup I just trying to open db, run some queries and if 
something failing 
(opening up db or querying), than just delete broken db and create a new one. 
If some data is lost  
then it got restored by tech stuff using application specific tracing.

Indeed, '...key violation SYS_ID' is not valid description of problem.
Double allocation is real cause. And I have attached corrupted database sample 
in first place.

mruptown (author of comment #3) got same problem independently. It is 
interesting, after inspecting stack trace supplied by him, I saw that he also 
using h2 in similar environment: on kiosk machines 
or alike (presumably some kind Point-Of-Sale terminals).

Now this issue is less relevant for me as I'm in process of writing simplified 
custom storage to 
replace h2 engine, proved unreliable in my specific environment (pretty nasty 
as I discovered).
Sorry for the lack of cooperation, but it is just not possible to supply full 
such environment via 
internet, and I'm not competent enough in H2 internals to fix issue by myself.

Original comment by e.lucash@gmail.com on 30 May 2009 at 1:10

[GoogleCodeExporter]

Hi,

If the problem occurs in the .index.db file, then I suggest to append LOG=2 to 
the
database URL. This will enable logging of index changes. By default, changes in 
the
.index.db file are not logged. 

Also, it is required to ensure that the databases already deployed are not 
corrupted.
To do that, you could run the recovery tool (org.h2.tools.Recover).

> As workaround, on startup I just trying to open db, run some queries and if
> something failing
> (opening up db or querying), than just delete broken db and create a new
> one. 

If the database is relatively small, the 'best' query would be SCRIPT TO
'backup.sql'. This will read all data from the .data.db file. You could delete 
the
.index.db file (specially if you are not sure if it is not corrupted).

If you are still interested to use a database, from what I heard SQLite seems 
to be
reliable. It is a bit more tricky to use from my experience (the JDBC driver is
incomplete, the SQL syntax is different).

Regards,
Thomas

Original comment by thomas.t...@gmail.com on 3 Jun 2009 at 6:01

[GoogleCodeExporter]

Thomas, Thanks for suggestions,
as I will continue to support my current deployment base
for a while, and any insights would be helpful.

> If the problem occurs in the .index.db file, then I suggest to append LOG=2 
to the
> database URL. This will enable logging of index changes. By default, changes 
in the
> .index.db file are not logged.
LOG=2 was already used as you suggested me in Issue 39 (comment #8)

There is combination of problems that beats me down:
* Double allocation
* File ID mismatch
* Read-Only filesystem problems (In form of RuntimeException during data access)
* And that happens randomly in both index.db and data.db (with or without 
cipher)

There is guess that "File ID mismatch" and "Double allocation" are consequences
of handling or recovering from failures in writing data due that nasty 
"Read-Only filesystem".
Apparently that non-permanent "Read-Only filesystem" is related to some bugs
in linux kernel and/or Ext3 (maybe fixed in newer versions).
I wish I could just setup linux with new kernel and razerfs (for example).
Those > 1000 kiosk machines are property of different dealer companies 
(customers of our payments processing centre), and OS reinstall on all station 
would take a really long time (..years). Remotely we can just monitor and 
update our software by 
portions via slow GPRS connection.

My experience with h2 is that although better that other comparable tools
in field of auto recovery functionality, but still those "File ID mismatch"
and "Double allocation" suddenly leaves db broken and unable to write data,
for example update current payment. I'm can imagine some on-the-fly auto 
recovery...

And there is no other choice than to provide some assurance by using some
alternative ways to store data (and there is "Read-Only filesystem" which might
screw up that alternative solution as well)

> the 'best' query would be SCRIPT TO 'backup.sql'.
I'll use that. Now opening db in steps.
1. trial open-query-close
2. if 1 failed RECOVER=1 then open-query-close
3. if 1 and 2 failed then backup/delete old (to recreate)
4. opening db ready for use

P.S. Issue 88 is similar

Regards,
Eugene Lucash

Original comment by e.lucash@gmail.com on 3 Jun 2009 at 11:11

[GoogleCodeExporter]

Hi,

I just found an old mail lying in my drafts folder...:

---

If the problem occurs in the .index.db file, then I suggest to append LOG=2 to 
the
database URL. This will enable logging of index changes. By default, changes in 
the
.index.db file are not logged. 

Also, it is required to ensure that the databases already deployed are not 
corrupted.
To do that, you could run the recovery tool (org.h2.tools.Recover).

---

Original comment by thomas.t...@gmail.com on 10 Aug 2009 at 6:25