NullPointerException with split:nioMapped

[Borja]

Hi,

We're using H2 (version 1.2.140) with connection string
"jdbc:h2:split:nioMapped:/
testDB;LOCK_MODE=3;CACHE_SIZE=262144;TRACE_LEVEL_FILE=0;DB_CLOSE_ON_EXIT=FALSE;MVCC=TRUE"
and we have a NullPointerException with this stack:

2010-08-06 10:34:25,895 WARN
[org.jboss.messaging.core.impl.JDBCSupport] (http-0.0.0.0-8080-5)
SQLException caught, SQLState HY000 code:50000- assuming deadlock
detected, try:9
org.h2.jdbc.JdbcSQLException: General error:
"java.lang.NullPointerException"; SQL statement:
INSERT INTO JBM_MSG_REF_CJQ (CHANNEL_ID, MESSAGE_ID, TRANSACTION_ID,
STATE, ORD, PAGE_ORD, DELIVERY_COUNT, SCHED_DELIVERY) VALUES
(?, ?, ?, ?, ?, ?, ?, ?) [50000-140]
at
org.h2.message.DbException.getJdbcSQLException(DbException.java:327)
at org.h2.message.DbException.get(DbException.java:156)
at org.h2.message.DbException.convert(DbException.java:279)
at org.h2.table.RegularTable.addRow(RegularTable.java:134)
at org.h2.command.dml.Insert.insertRows(Insert.java:120)
at org.h2.command.dml.Insert.update(Insert.java:82)
at
org.h2.command.CommandContainer.update(CommandContainer.java:70)
at org.h2.command.Command.executeUpdate(Command.java:199)
at
org.h2.jdbc.JdbcPreparedStatement.executeUpdateInternal(JdbcPreparedStatement.java:
141)
at
org.h2.jdbc.JdbcPreparedStatement.executeUpdate(JdbcPreparedStatement.java:
127)
[...]
Caused by: java.lang.NullPointerException
at
org.h2.store.fs.FileObjectDiskMapped.readFully(FileObjectDiskMapped.java:
140)
at org.h2.store.fs.FileObjectSplit.read(FileObjectSplit.java:
52)
at
org.h2.store.fs.FileObjectSplit.readFully(FileObjectSplit.java:59)
at org.h2.store.FileStore.readFully(FileStore.java:281)
at org.h2.store.PageStore.readPage(PageStore.java:1097)
at org.h2.store.PageStore.getPage(PageStore.java:561)
at org.h2.store.PageStore.getFreeList(PageStore.java:922)
at org.h2.store.PageStore.allocatePage(PageStore.java:989)
at org.h2.store.PageStore.allocatePage(PageStore.java:977)
at org.h2.index.PageDataLeaf.split(PageDataLeaf.java:356)
at org.h2.index.PageDataNode.addRowTry(PageDataNode.java:151)
at org.h2.index.PageDataIndex.addTry(PageDataIndex.java:159)
at org.h2.index.PageDataIndex.add(PageDataIndex.java:124)
at org.h2.table.RegularTable.addRow(RegularTable.java:116)

This happened only twice since we're using 1.2.140, so I couldn't get
more info debugging (I'll try if I get this error again).

I've been reading the code and I suppose that there's a problem in
org.h2.store.fs.FileObjectSplit.getFileObject(), but I haven't found
anything obvious. Hope you can help.

Thanks!

[Borja]

Hi again,

I could get the problem again, and it seems that it happened due to an
OutOfMemoryError. The stack is this:

org.h2.jdbc.JdbcSQLException: IO Exception: "java.io.IOException: Map
failed"; "split:nioMapped:/opt/jboss-5.0.1.GA/server/outsystems/data/
h2/localDB.h2.db"; SQL statement:
INSERT INTO JBM_MSG_CJQ (MESSAGE_ID, RELIABLE, EXPIRATION, TIMESTAMP,
PRIORITY, TYPE, HEADERS, PAYLOAD) VALUES (?, ?, ?, ?, ?, ?, ?, ?)
[90031-140]

at
org.h2.message.DbException.getJdbcSQLException(DbException.java:327)
at org.h2.message.DbException.get(DbException.java:156)
at

org.h2.message.DbException.convertIOException(DbException.java:313)
at org.h2.store.FileStore.setLength(FileStore.java:397)
at org.h2.store.PageStore.increaseFileSize(PageStore.java:
1020)
at org.h2.store.PageStore.increaseFileSize(PageStore.java:
1011)
at org.h2.store.PageStore.allocatePage(PageStore.java:996)
at org.h2.store.PageStore.allocatePages(PageStore.java:965)
at org.h2.store.PageOutputStream.reserve(PageOutputStream.java:
74)
at org.h2.store.PageOutputStream.write(PageOutputStream.java:
123)
at org.h2.store.PageLog.write(PageLog.java:498)
at org.h2.store.PageLog.logAddOrRemoveRow(PageLog.java:602)
at org.h2.store.PageStore.logAddOrRemoveRow(PageStore.java:
1235)
at org.h2.index.PageDataIndex.addTry(PageDataIndex.java:193)

at org.h2.index.PageDataIndex.add(PageDataIndex.java:124)
at org.h2.table.RegularTable.addRow(RegularTable.java:116)

at org.h2.command.dml.Insert.insertRows(Insert.java:120)
at org.h2.command.dml.Insert.update(Insert.java:82)
at
org.h2.command.CommandContainer.update(CommandContainer.java:70)
at org.h2.command.Command.executeUpdate(Command.java:199)
at
org.h2.jdbc.JdbcPreparedStatement.executeUpdateInternal(JdbcPreparedStatement.java:
141)
at
org.h2.jdbc.JdbcPreparedStatement.executeUpdate(JdbcPreparedStatement.java:
127)
[...]

Caused by: java.io.IOException: Map failed
at sun.nio.ch.FileChannelImpl.map(FileChannelImpl.java:758)
at
org.h2.store.fs.FileObjectDiskMapped.reMap(FileObjectDiskMapped.java:
102)
at
org.h2.store.fs.FileObjectDiskMapped.setFileLength(FileObjectDiskMapped.java:
164)
at
org.h2.store.fs.FileObjectSplit.setFileLength(FileObjectSplit.java:90)
at org.h2.store.FileStore.setLength(FileStore.java:395)
... 111 more
Caused by: java.lang.OutOfMemoryError: Map failed
at sun.nio.ch.FileChannelImpl.map0(Native Method)
at sun.nio.ch.FileChannelImpl.map(FileChannelImpl.java:755)
... 115 more

So the problem is that in org.h2.store.fs.FileObjectDiskMapped.reMap()
the line:
mapped = file.getChannel().map(mode, 0, length);
fails and mapped remains null, causing a lot of NullPointerExceptions
after that.

Maybe adding "if (mapping == null) reMap();" to readFully(), sync()
and write() methods is enough?

Thanks!

[Dario Fassi]

Hi Borja,
Apart from the reported issue, you may tell us about your experience with the use of nioMappedFs ?
I'm interested in base OS used, performance comparison with regular FS and motivation to use it.
Are you using this in production or testing ?

regards
Dario

El 24/08/10 09:22, Borja escribió:

[Borja]

Hi Dario,

We're using H2 as storage back-end for JMS. JBoss uses HSSQL by
default, but we had a lot of problems with it, so we searched many
options to replace it and after some tests we decided to use H2. We're
using it on a Red Hat EL 5 with ext3 as filesystem. I tested several
parameters in the connection string, and for us nioMapped was slightly
faster than nio and much faster than regular fs.

We're using it in production already, appart from little problems it's
behaving quite well. But we're not using it as our main DB, only as
JMS back-end.

I hope this helps.

Regards.

[Dario V. Fassi]

Hi Borja,
Thank you very much for sharing your experiences with us.
Is very useful information for designing the implementation of new projects and save a lot of experimentation.

Your typical JMS load are many small/simple transactions with high peaks over average demand , right ?

In regard with your issue, have you tested with MULTI_THREADED in place of MVCC ?
In general we have smooth performance with MT than MVCC , but both together would be the ideal.

In return I can tell you, that we do have replaced the main (front-end) database with H2 in four mid size web-apps with results that exceeded our expectations.
We use DBCP to run H2 in embedded mode as an application server datasource on SLES11 and other linux all with ext3 fs .
Performance gain, self containment, traffic off-load and integration level with java applications was our main motivation and all our goals has been satisfied.

Regards,
Dario

El 25/08/10 07:10, Borja escribió:

[Thomas Mueller]

Hi,

If you get an out of memory exception then something is wrong... Of
course it's possible to re-try, but I think the out of memory problem
is serious and needs to be solved. What happens if you run this?:

String fileName = "split:nioMapped:~/data/h2database/h2/data/test";
FileSystem m = FileSystem.getInstance(fileName);
m.createNewFile("split:nioMapped:data/test");
for (long l = 16; l <= 16L * 1024 * 1024 * 1024; l+= l) {
FileObject fo = m.openFileObject(fileName, "rw");
System.out.println("length: " + l);
fo.setFileLength(l);
fo.close();
}

Maybe we need to use some other strategy and not map the complete file
in memory...

Regards,
Thomas

[Thomas Mueller]

Hi,

I think what should to be done is catch the out of memory error and
then automatically fall back to regular io (non-mapped).

Regards,
Thomas

[Borja]

Hi,

Sorry for the delay.

I've run that code in the two test machines we have (one 32 bits and
one 64 bits). This problem only happened in the 32 bit machine, and it
also happened in that little test. On the 32 bits machine it ends
with:

length: 1073741824
length: 2147483648
Exception in thread "main" java.io.IOException: Map failed

at sun.nio.ch.FileChannelImpl.map(FileChannelImpl.java:758)
at
org.h2.store.fs.FileObjectDiskMapped.reMap(FileObjectDiskMapped.java:
102)
at
org.h2.store.fs.FileObjectDiskMapped.setFileLength(FileObjectDiskMapped.java:
164)
at
org.h2.store.fs.FileObjectSplit.setFileLength(FileObjectSplit.java:

113)
at
outsystems.hubedition.logservice.LogQueueBulkHandler.main(LogQueueBulkHandler.java:
796)

Caused by: java.lang.OutOfMemoryError: Map failed
at sun.nio.ch.FileChannelImpl.map0(Native Method)
at sun.nio.ch.FileChannelImpl.map(FileChannelImpl.java:755)

... 4 more

And in the 64 bits machine it finishes without problem with length
17179869184. I don't know how difficult it would be to map only part
of the file in memory instead of the whole file, but I think that's a
better solution than falling back to nio (However, it would also solve
our problem).

Regards.

On Aug 27, 12:53 pm, Thomas Mueller <thomas.tom.muel...@gmail.com>
wrote:

[Thomas Mueller]

Hi,

I added a feature request "nioMapped file system: automatically fall
back to regular (non mapped) IO if there is a problem (out of memory
exception for example)." I will also document that "nioMapped" may not
work for databases larger than 2 GB on 32-bit JVMs.

Regards,
Thomas