Error opening database: "Lock file recently modified"

[Kenton Garner]

It is not uncommon for us to have problems starting or stopping H2 Database Connections. 

Typically it happens when we are starting multiple applications at the same time that share a common database ( AUTO_SERVER=TRUE ).
Most often the exception is states that the connection was unsuccessful and will be retried in (n) seconds. - This exception is common but typically recovers without issue.

However more and more often, we have experienced the database hanging on shutdown when reading or writing Clobs to the same database table from multiple applications. 
This has been known to corrupt our DB file.

We have updated to the newest beta version hoping for some cure to our hanging shutdown because I noticed in the change logs that some work was done around the lob area.


The exception that I am posting today is new to us.  Could this be something that was introduced with this latest version?

Thanks as always for your work and quick responses,
Kent

java.sql.SQLException: Unable to open a test connection to the given database. JDBC url = jdbc:h2:../data/audit/msgfwd;COMPRESS=TRUE;AUTOCOMMIT=ON;MVCC=TRUE;DB_CLOSE_ON_EXIT=FALSE;MV_STORE=FALSE;AUTO_SERVER=TRUE;AUTO_SERVER_PORT=7799, username = XX. Terminating connection pool (set lazyInit to true if you expect to start your database after your app).

Original Exception: ------
org.h2.jdbc.JdbcSQLException: Error opening database: "Lock file recently modified" [8000-182]
    at org.h2.message.DbException.getJdbcSQLException(DbException.java:345)
    at org.h2.message.DbException.get(DbException.java:168)
    at org.h2.store.FileLock.getExceptionFatal(FileLock.java:456)
    at org.h2.store.FileLock.waitUntilOld(FileLock.java:310)
    at org.h2.store.FileLock.lockFile(FileLock.java:347)
    at org.h2.store.FileLock.lock(FileLock.java:135)
    at org.h2.engine.Database.open(Database.java:631)
    at org.h2.engine.Database.openDatabase(Database.java:266)
    at org.h2.engine.Database.<init>(Database.java:260)
    at org.h2.engine.Engine.openSession(Engine.java:60)
    at org.h2.engine.Engine.openSession(Engine.java:167)
    at org.h2.engine.Engine.createSessionAndValidate(Engine.java:145)
    at org.h2.engine.Engine.createSession(Engine.java:128)
    at org.h2.engine.Engine.createSession(Engine.java:26)
    at org.h2.engine.SessionRemote.connectEmbeddedOrServer(SessionRemote.java:347)
    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 java.sql.DriverManager.getConnection(DriverManager.java:571)
    at java.sql.DriverManager.getConnection(DriverManager.java:215)
    at com.jolbox.bonecp.BoneCP.obtainRawInternalConnection(BoneCP.java:363)
    at com.jolbox.bonecp.BoneCP.<init>(BoneCP.java:416)
    at com.jolbox.bonecp.BoneCPDataSource.getConnection(BoneCPDataSource.java:120)
    at com.issinc.cds.db.H2JDBCBoneCP.getConnection(H2JDBCBoneCP.java:80)
    at com.issinc.cds.sb.h2.CdsMsgFwdDbConnection.initializeH2DB(CdsMsgFwdDbConnection.java:35)
    at com.issinc.cds.sb.h2.AbstractH2DbConnection.createNewConnection(AbstractH2DbConnection.java:77)
    at com.issinc.cds.sb.h2.AbstractH2DbConnection.<init>(AbstractH2DbConnection.java:39)
    at com.issinc.cds.sb.h2.CdsMsgFwdDbConnection.<init>(CdsMsgFwdDbConnection.java:19)
    at com.issinc.cds.sb.mfwd.impl.FwdMsgQueueManager.<init>(FwdMsgQueueManager.java:62)
    at com.issinc.cds.sbsend.main.impl.SendDataSyncXMLEngine.initMessageForwardingOutput(SendDataSyncXMLEngine.java:489)
    at com.issinc.cds.sbsend.main.impl.SendDataSyncXMLEngine.start(SendDataSyncXMLEngine.java:245)
    at com.issinc.cds.sbsend.main.Main.main(Main.java:170)

[Noel Grandin]

Hmmm, MVCC=TRUE and LOB's are likely to run into some edge conditions in our code, since that feature is still a little
experimental, and in fact, is unnecessary with the MVStore engine (since that is inherently MVCC).

If you had a small reproducible test case, I might be able to track it down.

Also, I note that you have AUTO_SERVER=TRUE and DB_CLOSE_ON_EXIT=FALSE
That seems like an odd combination.
Are you manually shutting down the DB when the VM exits?

[Kenton Garner]

Noel,

"If you had a small reproducible test case"... unfortunately I do not.  I have been meaning to try and see if I can find one, but I have not been able to reproduce it on demand yet.

DB_CLOSE_ON_EXIT... We have shutdown logic in our application that handles this.  I do not remember when we changed it to FALSE, but I think we were getting into a timing issue between your shutdown hook and ours.  To be specific we are currently using BoneCP for our connection pool and we make sure that is shutdown when we exit.

Looking for your recommendations here... Since we are using MVCC=TRUE should we

1. Set MVCC = FALSE

2. Switch our CLOB's to VARCHAR since H2 allows for very large strings

3. Make the move to MVSTORE.  ( we have been avoiding because of the database file sizes get so large )

--
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/R5Cy0e1Ikvw/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]

I would suggest turning off MVCC for now.
It that is too much of a performance hit, try switching your CLOBs to VARCHAR.

[Thomas Mueller]

Hi,

What file system do you use?

I think the problem might be related to the usage of the auto-server mode. The exception "Lock file recently modified" means the database file locking is not working as expected. It could be a race condition (multiple processes try to concurrently open the database file and lock it).

Regards,

Thomas

On Wed, Oct 22, 2014 at 8:19 PM, Noel Grandin <noelg...@gmail.com> wrote:

I would suggest turning off MVCC for now.
It that is too much of a performance hit, try switching your CLOBs to VARCHAR.

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

[Kenton Garner]

Thanks both of you.

Thomas,

We have been doing the majority of our testing on Solaris 10 (sparc).   I definitely agree that it is a race condition.  This particular exception occurred at start-up when we programmatically kick-off three separate application that all try and connect to the database at roughly the same time.  As I said before, most often we the exception that the database connection failed possibly because it is currently in use and will retry in (n) seconds.  This exception recovers and continues successfully on the next retry.

--
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/R5Cy0e1Ikvw/unsubscribe.
To unsubscribe from this group and all its topics, send an email to h2-database...@googlegroups.com.

[Kenton Garner]

Just a quick note:  I am still not able to reproduce this exception on command, however, It has happen two more times; And it is worth noting that I have never seen this particular exception prior to the 182 version.

Thomas, I think there is no question that there is a race condition occurring when multiple process are started simultaneously and trying to access the same H2 server via AUTO_SERVER mode.

[Thomas Mueller]

Hi,

There was no change in the FileLock class since a long time. I think there is either a different reason, or it's just bad luck.

But anyway, what file system do you use? Is it NFS?

Regards,

Thomas

On Fri, Oct 24, 2014 at 3:31 AM, Kenton Garner <kenton...@gmail.com> wrote:

Just a quick note:  I am still not able to reproduce this exception on command, however, It has happen two more times; And it is worth noting that I have never seen this particular exception prior to the 182 version.

Thomas, I think there is no question that there is a race condition occurring when multiple process are started simultaneously and trying to access the same H2 server via AUTO_SERVER mode.

--