ArrayIndexOutOfBoundsException with H2 1.4.184

[Daniele Renda]

Hi,
I'm using h2 db with my application.
This is the connection string:

jdbc:h2:{database};AUTO_SERVER=TRUE;MV_STORE=FALSE;MVCC=TRUE;DEFRAG_ALWAYS=TRUE;


I'm using this approach to avoid problems I had in the past with mv store as you suggested me.
All worked fine in this 3 weeks; my db has 56 tables and now there are many rows (about 125.000).

Unfortunally I see that now the db is 1.3GB!!!! I'm sure that data inside are not so big, so I think there is some problem with lob in h2.

To make a test I run 'SCRIPT TO 'C:\backup.sql'. The first time the command worked and I get a sql file of about 75Mb. Because it was just a test I removed that file and I repeated the comman but now I've this Exception:

Caused by: java.lang.ArrayIndexOutOfBoundsException
12-31 11:54:04 jdbc[3]: exception
org.h2.jdbc.JdbcSQLException: IO Exception: "java.io.IOException: java.lang.ArrayIndexOutOfBoundsException"; "lob: null table: 62 id: 753781"; SQL statement:
SCRIPT TO 'C:\backup.sql' [90031-184]
    at org.h2.message.DbException.getJdbcSQLException(DbException.java:345)
    at org.h2.message.DbException.get(DbException.java:168)
    at org.h2.message.DbException.convertIOException(DbException.java:330)
    at org.h2.value.ValueLobDb.getInputStream(ValueLobDb.java:394)
    at org.h2.value.ValueLobDb.getReader(ValueLobDb.java:377)
    at org.h2.value.ValueLobDb.getString(ValueLobDb.java:292)
    at org.h2.value.ValueLobDb.getSQL(ValueLobDb.java:416)
    at org.h2.command.dml.ScriptCommand.generateInsertValues(ScriptCommand.java:426)
    at org.h2.command.dml.ScriptCommand.query(ScriptCommand.java:300)
    at org.h2.command.CommandContainer.query(CommandContainer.java:90)
    at org.h2.command.Command.executeQuery(Command.java:197)
    at org.h2.jdbc.JdbcStatement.executeInternal(JdbcStatement.java:179)
    at org.h2.jdbc.JdbcStatement.execute(JdbcStatement.java:158)
    at org.jkiss.dbeaver.model.impl.jdbc.exec.JDBCStatementImpl.execute(JDBCStatementImpl.java:369)
    at org.jkiss.dbeaver.model.impl.jdbc.exec.JDBCStatementImpl.executeStatement(JDBCStatementImpl.java:155)
    at org.jkiss.dbeaver.runtime.sql.SQLQueryJob.executeSingleQuery(SQLQueryJob.java:363)
    at org.jkiss.dbeaver.runtime.sql.SQLQueryJob.extractData(SQLQueryJob.java:633)
    at org.jkiss.dbeaver.ui.editors.sql.SQLEditor$QueryResultsProvider.readData(SQLEditor.java:1169)
    at org.jkiss.dbeaver.ui.controls.resultset.ResultSetDataPumpJob.run(ResultSetDataPumpJob.java:132)
    at org.jkiss.dbeaver.runtime.AbstractJob.run(AbstractJob.java:91)
    at org.eclipse.core.internal.jobs.Worker.run(Worker.java:54)
Caused by: java.io.IOException: java.lang.ArrayIndexOutOfBoundsException
    at org.h2.message.DbException.convertToIOException(DbException.java:364)
    at org.h2.store.LobStorageBackend.getInputStream(LobStorageBackend.java:345)
    at org.h2.value.ValueLobDb.getInputStream(ValueLobDb.java:392)
    ... 17 more
Caused by: java.lang.ArrayIndexOutOfBoundsException

At this point I've 2 questions:

1. There is a way to make a sql backup of the actual db?
2. Why the db is 1.3Gb and the first sql backup was only 75Mb? 

Thanks very much

Daniele Renda

[Thomas Mueller]

Hi,

I think part of the exception stack trace is missing (after the last "caused by"). Could you post it as well?

> Unfortunally I see that now the db is 1.3GB

Did you try using the Recover tool? Could you run it, and post the last 20 lines of the resulting *.sql file please?

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

[Thomas Mueller]

Hi,

As why the database is so large:

I got the large database and ran the Recover tool on it. The main problem seems to be a huge number of references to a small LOB (130 bytes). Such small LOBs should be inlined, which means there would be no reference. I'm not quite sure, but I think I fixed this / changed the behavior in version 1.4.184 such that LOBs are always inlined now. Could you try again with version 1.4.184 if the database still gets that big? If yes, we would need to know LOBs are created. Are you using anything special, for example the JDBC API Connection.createBlob / createClob?

Details:

> CREATE_BUILD 182

So, the database was created with version 1.4.182.

> grep "INSERT INTO O_" ecall.h2.sql | wc -l

> 33'057'364

The number of "insert" statements: 33 millions.

Those are the LOB tables:

> INSERT INTO INFORMATION_SCHEMA.LOBS SELECT * FROM O_2;

> INSERT INTO INFORMATION_SCHEMA.LOB_MAP SELECT * FROM O_6;

> INSERT INTO INFORMATION_SCHEMA.LOB_DATA SELECT * FROM O_10;

> grep "INSERT INTO O_10 " ecall.h2.sql | wc -l

> 3269

So, actually not much LOB_DATA.

> grep "INSERT INTO O_6 " ecall.h2.sql | wc -l

> 16'471'645

> grep "INSERT INTO O_2 " ecall.h2.sql | wc -l

> 16'456'153

Those are references to LOBs: a huge number (16 million references). It looks like most of those LOBs are very very small (130 bytes I think), and are temporary LOBs (type = -3).

------------

As for the ArrayIndexOutOfBoundsException: the root cause is:

Caused by: java.lang.ArrayIndexOutOfBoundsException: 0

at org.h2.index.PageDataLeaf.getRowAt(PageDataLeaf.java:332)

at org.h2.index.PageDataCursor.nextRow(PageDataCursor.java:101)

at org.h2.index.PageDataCursor.next(PageDataCursor.java:67)

at org.h2.result.ResultTempTable.next(ResultTempTable.java:271)

at org.h2.result.LocalResult.next(LocalResult.java:242)

at org.h2.jdbc.JdbcResultSet.nextRow(JdbcResultSet.java:3231)

at org.h2.jdbc.JdbcResultSet.next(JdbcResultSet.java:122)

There seems to be a a corruption in the database file (PageStore). I didn't further analyze this yet, I think the "large database file" issue is more urgent in this case.

Regards,

Thomas

[Daniele Renda]

Hi Thomas,
thanks for your reply and for your time.
I'm using H2 1.4.184 from the day you released it. So I'm yet using it, but the db grows every day. Now it is 2.9Gb, Argh!!!
I'm using Hibernate 4.3.7.Final in my application.

Can you suggest me what I can do to help you to fix the problem and avoid my production db collaps?!

Thanks very much!

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

--

Daniele Renda

[Noel Grandin]

On 2015-01-14 09:31 AM, Daniele Renda wrote:
> Hi Thomas,
> thanks for your reply and for your time.
> I'm using H2 1.4.184 from the day you released it. So I'm yet using it, but the db grows every day. Now it is 2.9Gb, Argh!!!
> I'm using Hibernate 4.3.7.Final in my application.
>
> Can you suggest me what I can do to help you to fix the problem and avoid my production db collaps?!

This combination
MV_STORE=FALSE;MVCC=TRUE
is not well tested.

I would suggest turning MVCC off.

[Daniele Renda]

Argh,

my application needs mvcc because there is a bit of concorrency and I'm using pessimistic write. Turning off MVCC I suppose I would have many LockException and this is a problem for how my application is designed.

Any other idea to try to resolve the problem of the db's size?

Thanks

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

--

Daniele Renda

[Noel Grandin]

Are you sure it won't work? H2 is quite efficient with it's locking, it's worth trying.

On 2015-01-14 09:53 AM, Daniele Renda wrote:
> Argh,
> my application needs mvcc because there is a bit of concorrency and I'm using pessimistic write. Turning off MVCC I
> suppose I would have many LockException and this is a problem for how my application is designed.
>
> Any other idea to try to resolve the problem of the db's size?
>
> Thanks
>

> 2015-01-14 8:50 GMT+01:00 Noel Grandin <noelg...@gmail.com <mailto:noelg...@gmail.com>>:

>
>
> On 2015-01-14 09:31 AM, Daniele Renda wrote:
>
> Hi Thomas,
> thanks for your reply and for your time.
> I'm using H2 1.4.184 from the day you released it. So I'm yet using it, but the db grows every day. Now it is
> 2.9Gb, Argh!!!
> I'm using Hibernate 4.3.7.Final in my application.
>
> Can you suggest me what I can do to help you to fix the problem and avoid my production db collaps?!
>
>
> This combination
> MV_STORE=FALSE;MVCC=TRUE
> is not well tested.
>
> I would suggest turning MVCC off.
>
>
> --
> 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/ZVCOE0QErOo/__unsubscribe
> <https://groups.google.com/d/topic/h2-database/ZVCOE0QErOo/unsubscribe>.
> To unsubscribe from this group and all its topics, send an email to h2-database+unsubscribe@__googlegroups.com
> <mailto:h2-database%2Bunsu...@googlegroups.com>.
> To post to this group, send email to h2-da...@googlegroups.com <mailto:h2-da...@googlegroups.com>.
> Visit this group at http://groups.google.com/__group/h2-database <http://groups.google.com/group/h2-database>.
> For more options, visit https://groups.google.com/d/__optout <https://groups.google.com/d/optout>.
>
>
>
>
> --
> Daniele Renda
>
> --
> 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 <mailto:h2-database...@googlegroups.com>.
> To post to this group, send email to h2-da...@googlegroups.com <mailto:h2-da...@googlegroups.com>.

[Thomas Mueller]

Hi,

We would need to know LOBs are created. I don't think this is related to MVCC. Are you using anything special, for example the JDBC API Connection.createBlob / createClob? Basically we would need a reproducible test case.

Regards,

Thomas

[Daniele Renda]

Well,

I'm using org.apache.tomcat.jdbc.pool.DataSource with Hibernate. So I never use Connection.createBlob / createClob but I don't know if then Hibernate do it internally. Make a reproducible test case is quite hard because the application is quite complex.

I'm thinking if Sql logs would be useful for you.....what do you think?

Thanks

[Noel Grandin]

On 2015-01-14 11:18 AM, Daniele Renda wrote:
> Well,
> I'm using org.apache.tomcat.jdbc.pool.DataSource with Hibernate. So I never use Connection.createBlob / createClob but I
> don't know if then Hibernate do it internally. Make a reproducible test case is quite hard because the application is
> quite complex.
> I'm thinking if Sql logs would be useful for you.....what do you think?
>

Sorry, that's not particularly useful. Blobs are weird, and the API for reading and writing them is also a little weird,
so it's not hard to find edge cases where things go wrong.

[Daniele Renda]

Ok,

the only thing I do in my code is this:

EmailContent emailContent = new EmailContent();
                emailContent.setBody(testoEmail);
                emailContent.setEmail(email);
                entityManager.persist(emailContent);

where "body" is a @Lob. So I don't do anything strange. I haven't the idea how I can make a test case to reproduce the problem. It is an hard challenge.

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

--

Daniele Renda

[Thomas Mueller]

Hi,

Could you append ";trace_level_file=3" to the database URL, then run your test case against a new database (version 1.4.184), and then post the resulting database and *.trace.db file? The test case should be minimal in this case, so that the database doesn't get big (a few MB is enough for this). And most importantly, the *.trace.db file should stay small (also only a few MB). But still the test case should execute as much as possible from your application. That should be enough to get one of those very small (but not inlined) LOB values, and we can see what caused it.

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

[Daniele Renda]

Is needed a new db (version 1.4.184) or I can use the actual db? Because in that case I should copy all data from the actual db to the newer one...and I've the problem that the emailcontent table can't be copied.

Thanks very much

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

--

Daniele Renda

[Thomas Mueller]

Hi,

Is needed a new db (version 1.4.184) or I can use the actual db?

You would need a new database file. Using an old (existing) database doesn't make sense, because it may already contain the problematic data. That way, we couldn't get a reproducible test case. But we need one.

Because in that case I should copy all data from the actual db to the newer one...and I've the problem that the emailcontent table can't be copied.

Simply create a SQL script from the old database, delete the database file, and run that SQL script against a new database.

Regards,

Thomas

[Daniele Renda]

Hi Thomas,

1. ok for the new db

2. unfortunally the SCRIPT don't work with the production db because I've an ArrayIndexOutOfBound (you should yet seen this exception in my db). I'm asking is removing the emailContent table can reduce the size of the db

3.now I try to make what you wrote in local with a real execution of the app.

Thanks

--

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

--

Daniele Renda

[Thomas Mueller]

Hi,

I'm afraid we are a bit stuck here. I can see what's wrong in the database file, but I don't know how to create such a database file, so I'm not sure how to solve the problem. I would need a reproducible test case.

What's wrong in the database file: there are only a few LOBs, but one of them is referenced thousands of times. It is actually a very small LOB (130 bytes). Such a small LOB should be inlined, and not stored on its own. It gets referenced whenever you run a "select" statement. This is to ensure the LOB is not removed immediately when another transaction concurrently runs a "delete" statement.

I would need a reproducible test case that creates those references and doesn't clean them up. I will try to write such a test case, but I'm not sure if I can reproduce the problem that way, and even if I can and find a solution, I'm not sure if that matches what your application is doing.

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

[Thomas Mueller]

Hi,

How is possibile that that lob is referenced 16millios of times when that value is only readed from other transactions in the application?

Each time you query the LOB (select * from test), the LOB is copied to a session-scope value. This is because the row with the LOB might be removed in the meantime (delete from test). If you close the result set or the database, the LOB should be removed.

In your case, the question is why does a value with only 130 bytes get stored as a LOB, and not inlined (as it should be).

Without reproducible test case, I'm afraid I don't know what the problem might be. Looking at databases or partial .trace.db file does not help now I'm afraid. It did help somewhat to understand what is in the database, but now, it doesn't help any longer.

Regards,

Thomas

[Thomas Mueller]

Hi,

Please don't send mails to me directly, send them to the Google Group.

> why does a value with only 130 bytes get stored as a LOB

If you create a LOB, for example using a prepared statement "insert into ... values(?, ?,...)", then small LOB objects are inlined. I thought the limit is around 1000 bytes, but I was wrong and you are right, in fact the limit is 128 bytes. That explains why the 130 bytes object was _not_ inlined in your case!

I think the default limit of 128 bytes is too small, specially for your case. I think I will change it to 256 bytes. You can change it manually using "SET MAX_LENGTH_INPLACE_LOB 256"

The second question is, why are there around 1 million references to the LOB. A new reference (marked as temporary, table id -3) is created whenever you run "select * from ..." that includes a LOB object. This is because the result set could be kept open, but in the meantime the row could be removed. This is "copy on read" or actually "copy the reference on read". Each reference uses some space. The references are supposed to be removed if the result set is closed, or if the connection is closed, or if the database is closed (whatever comes first). However, in your case, I'm not sure if the result set is not closed, and the connection is not closed, or maybe there is a bug in the database that doesn't remove the reference even if things _are_ closed. This I can test. I can look at the trace files you sent (which do contain the "select" statements and all the JDBC calls).

Thanks a lot for your help! I think we have a workaround (changing MAX_LENGTH_INPLACE_LOB; unfortunately this will only take effect for new LOB objects / new databases), and I know now what I need to investigate to fully solve the problem.

Regards,
Thomas

On Thu, Jan 22, 2015 at 10:36 PM, Daniele Renda <daniel...@gmail.com> wrote:

Thanks for the reply Thomas. Every time a new piece of the puzzle is more clear!

About your question "why does a value with only 130 bytes get stored as a LOB....." I don't understand if you mean that this should be managed by h2 and it don't work in my case, or if the fact to store the 130bytes inline or as a LOB should be managed by me (Hibernate). Can you clarify please?

In the first case - maybe I'm saying something stupid - is not because MAX_LENGTH_INPLACE_LOB default value is 128?  And so 130 > 128

 In the end, there is a doc that explains as I can see these "session-scope values"  autonomously in order to understand when the problems happens and try to make a reproducible tests seeing these values and when they are created?

Thanks very much




--

Daniele Renda

[Daniele Renda]

Thanks Thomas,
of course I'll increase the limit to 256.

About the problem of 1 milion of references to the LOB: I'm almost sure all result set as correctly closed. Infact I'm using Spring JPA so this is managed automatically from Spring. I'm using @Transactional in all my methods so I don't open or close manually the connection. Therefore, I rule out a problem of failure to close the resultset. And in any case I closed the db many times during my tests.

About the increasing the MAX_LENGTH_INPLACE_LOB would be a good idea create a sql of the actual db (SCRIPT DROP TO....) and then create a new db with the MAX_LENGTH_INPLACE_LOB to 256 and run RUNSCRIPT FROM? In this case all lob should be put inline, right?

Thanks very much to you!

[Ram K]

hi Thomas and Team,

why the recovery step is creating table names with O_NUMBER pattern, instead of actual table name?