Missing LOB issue

[Eoin Byrne]

Hi

I'm getting an Exception during a very long set of tests - the issue
sometimes doesn't happen and sometimes happens in different places but
the end result is always the same.

The setup:

H2 is started programatically by a host process in server mode, this
process does the buulk of the access. We have other processes that
connect and disconnect through out the tests for various different
reasons and an application server that also uses the DB.

One of the processes is a bulk load process that makes a number of
inserts into H2 and this process seesm to be the issue. It runs
without issue but afterwards the host process can no longer access the
DB.

We generally get 1 or 2 instances of:

org.h2.message.DbException: IO Exception: "java.io.IOException:
org.h2.jdbc.JdbcSQLException: IO Exception: ""Missing lob:
6008"" [90028-167]" [90028-167]
at org.h2.message.DbException.convert(DbException.java:269)
at org.h2.engine.SessionRemote.done(SessionRemote.java:572)
at org.h2.engine.SessionRemote.readLob(SessionRemote.java:701)
at org.h2.store.LobStorage$RemoteInputStream.read(LobStorage.java:
318)
at java.io.BufferedInputStream.read1(BufferedInputStream.java:256)
at java.io.BufferedInputStream.read(BufferedInputStream.java:317)
at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:264)
at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:306)
at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:158)
at java.io.InputStreamReader.read(InputStreamReader.java:167)
at java.io.BufferedReader.read1(BufferedReader.java:185)
at java.io.BufferedReader.read(BufferedReader.java:261)
at java.io.BufferedReader.fill(BufferedReader.java:136)
at java.io.BufferedReader.read1(BufferedReader.java:187)
at java.io.BufferedReader.read(BufferedReader.java:261)
at java.io.Reader.read(Reader.java:123)
.....
Caused by: org.h2.jdbc.JdbcSQLException: IO Exception:
"java.io.IOException: org.h2.jdbc.JdbcSQLException: IO Exception:
""Missing lob: 6008"" [90028-167]" [90028-167]
at org.h2.message.DbException.getJdbcSQLException(DbException.java:
329)
at org.h2.message.DbException.get(DbException.java:158)
at org.h2.message.DbException.convert(DbException.java:273)
at org.h2.server.TcpServerThread.sendError(TcpServerThread.java:211)
at org.h2.server.TcpServerThread.run(TcpServerThread.java:151)
at java.lang.Thread.run(Thread.java:619)
Caused by: java.io.IOException: org.h2.jdbc.JdbcSQLException: IO
Exception: "Missing lob: 6008" [90028-167]
at org.h2.message.DbException.convertToIOException(DbException.java:
348)
at org.h2.store.LobStorage.getInputStream(LobStorage.java:571)
at org.h2.server.TcpServerThread.process(TcpServerThread.java:407)
at org.h2.server.TcpServerThread.run(TcpServerThread.java:149)
... 1 more
Caused by: org.h2.jdbc.JdbcSQLException: IO Exception: "Missing lob:
6008" [90028-167]
at org.h2.message.DbException.getJdbcSQLException(DbException.java:
329)
at org.h2.message.DbException.get(DbException.java:169)
at org.h2.message.DbException.get(DbException.java:146)
at org.h2.store.LobStorage.getInputStream(LobStorage.java:566)
... 3 more

Followed by this everytime we try to access H2:

rg.h2.jdbc.JdbcSQLException: Database is already closed (to disable
automatic closing at VM shutdown, add ";DB_CLOSE_ON_EXIT=FALSE" to the
db URL) [90121-167]
at org.h2.message.DbException.getJdbcSQLException(DbException.java:
329)
at org.h2.message.DbException.get(DbException.java:169)
at org.h2.message.DbException.get(DbException.java:146)
at org.h2.message.DbException.get(DbException.java:135)
at org.h2.jdbc.JdbcConnection.checkClosed(JdbcConnection.java:1386)
at org.h2.jdbc.JdbcStatement.checkClosed(JdbcStatement.java:927)
at
org.h2.jdbc.JdbcPreparedStatement.checkClosed(JdbcPreparedStatement.java:
1523)
at org.h2.jdbc.JdbcStatement.checkClosed(JdbcStatement.java:901)
at
org.h2.jdbc.JdbcPreparedStatement.executeQuery(JdbcPreparedStatement.java:
102)

The host process lives on for a few hours and every access gets the DB
closed message.

There are a few other things worth mentioning - the host process uses
only a single connection so I guess the missing lob issue is causing
the connection to get closed or at least the session object to get
marked as closed, I could reset the connection when I've gotten the
above error but thats just working around the real problem.

Some other info:

There is some info in the trace log:
06-13 01:09:38 pageStore: Transaction log could not be truncated;
size: 16 MB
So - on to my questions :)

And saving the best for last:

The issue only happens on one of the 2 test machines we are using, one
is a Solaris X86 box which has no issues the other is a RHL x86 box
that is showing the issue. The DB file size on the problem box is
just under 500MB while the healthy one is 71 MB. This isn't really
comparing like with like because the healthy box has had more tests
run on it because it didn't fail early but its definitley worth
mentioning. The log entries on both boxes have the same "cant
truncate the transaction log" errors.

I'm not aware of any client differences caused by the different envs
and while there is some C code in play here all the code I suspect
(all the inserting clients and the host process itself) is all java.

Both systems are using local hard disks for the DB and the connection
string we are using is:

jdbc:h2:tcp://host:port//file
path;AUTO_RECONNECT=TRUE;MVCC=TRUE;JMX=TRUE;LOCK_TIMEOUT=10000;


Has anyone any idea how to fix the missing lob issue or what kind of
application behaviour might be causing the problem? This code is from
a very large project being ported over from Oracle so we are certain
it works but obviously there need to be a few more changes made.

In addition to this - from a H2 perspective it might be worth
considering changing the error message a little, the JVM is definitley
not shutting down in the above case and afaik the connection has not
been closed by the application although I havn't had a chance to 100%
confirm that.

If you made it this far - thanks for reading :)

[Eoin Byrne]

One other thing - we are setting 2 proerties before we start the server inside the host process:

                System.setProperty("h2.serverCachedObjects", 20000);
                System.setProperty("h2.serverResultSetFetchSize", 40000);

This was in response to something we saw in a changelog that seemed like it might be related

[Eoin Byrne]

Is it possible that turning MVCC off could solve the issue?  It is possible to use a read committed isolation level without MVCC?

[Noel Grandin]

This is a known issue.
Pretty much all you can do right now is to limit the number LOBs per
ResultSet that you try and fetch.

I have a fix in mind that involves HMAC and cryptographic cookies, but I
won't have time to fix it in the near future.

[Eoin Byrne]

Is there any guidance on what the max number of lobs I can bring back per ResultSet?  It it related to a cache size?

One other thing to mention for others who might hit this issue is that turning off MVCC seems to have fixed the bloated file problem, with MVCC enabled the DB is around 450 MB after the tests and I get that "DB Closed" error message after the "Missnig LOB".  Without MVCC the DB is about 70 MB at the end of the tests with no "DB Closed" errors however I am getting a number of table lock timeouts now.

[Noel Grandin]

On 2012-06-14 10:52, Eoin Byrne wrote:
> Is there any guidance on what the max number of lobs I can bring back
> per ResultSet? It it related to a cache size?
>

The number of CLOB / BLOB values that are cached on the server is now
the maximum of: 5 times the SERVER_RESULT_SET_FETCH_SIZE (which is 100
by default), and SysProperties.SERVER_CACHED_OBJECTS.

> One other thing to mention for others who might hit this issue is that
> turning off MVCC seems to have fixed the bloated file problem, with
> MVCC enabled the DB is around 450 MB after the tests and I get that
> "DB Closed" error message after the "Missnig LOB". Without MVCC the
> DB is about 70 MB at the end of the tests with no "DB Closed" errors
> however I am getting a number of table lock timeouts now.
>

Yeah, in general MVCC mode is still experimental. I would not use it for
production work.

[Thomas Mueller]

Hi,

I'm not sure (well, I don't think) the problem here is the limit on the number of LOBs per result set. It might be something completely different.

Is it reproducible with a newly created database? If it's an existing database, could you find out which version was used to create the database? To find out, run

SELECT * FROM INFORMATION_SCHEMA.SETTINGS
where name='CREATE_BUILD'

> "cant truncate the transaction log"

I know this error message is written to the log sometimes, even thought the transaction log could be truncated. I'm currently investigating that. I think it's also not related to the problem - it's just an bug this message is logged.

> the connection has not been closed

Well, maybe it was closed / has closed, but since you are using AUTO_RECONNECT=TRUE is might have been re-opened automatically. Could you try not using the auto-reconnect feature? Just to reduce the complexity of the problem... The auto re-connect might have an influence.

I'm not sure if it could be related to MVCC. If you can reproduce the problem (with a fresh database), but only with MVCC enabled, then we need to investigate in that.

Regards,
Thomas

> --
> You received this message because you are subscribed to the Google Groups
> "H2 Database" group.
> To post to this group, send email to h2-da...@googlegroups.com.
> To unsubscribe from this group, send email to
> h2-database...@googlegroups.com.
> For more options, visit this group at
> http://groups.google.com/group/h2-database?hl=en.
>

[Eoin Byrne]

The database is created from scratch at the start of the test run.  The version of H2 (from the manifest) is:

Export-Package: org.h2;version="1.3.167",
 org.h2.api;version="1.3.167",
 org.h2.fulltext;version="1.3.167",
 org.h2.jdbcx;version="1.3.167",
 org.h2.tools;version="1.3.167",
 org.h2.util;version="1.3.167"

And the SQL gives the same output: 167

I'll try it again without the reconect but it will take a day or so before I'm able to get the results.

From what I know so far:

The database closed issue seems to be related to the missing lob issue, I've never seen it without the misisng lob first but I have seen the missing lob error without the DB being closed. I've seen these errors on both solaris x86 and rhl x86 and with and without MVCC. 

Turning off MVCC seems to have fixed the growing file size problem, I found a long lived connection in our code that has auto commit disabled so I thought that might be the casue so I enabled it and database still growns but all the tests I've run without MVCC have held to a max of 70MB.  I have a better test scheduled that should confirm this tomorrow

Is there any other info you need?

[Thomas Mueller]

Hi,

Is there any other info you need?

Hm, a simple, reproducible test case would be great... ;-)

Regards,

Thomas

[Eoin Byrne]

heh - tell me about it, having to wait 8 hours to see if a fix works can make things difficult :)

[Eoin Byrne]

We tested a change last night which broke up the select * on the lob table to select in batches of 1000 entries and it seems to have fixed the "Missing LOB" error.  There were no "DB closed" errors either.  Because the problem seems intermittent that's no guarantee that the issue has been fixed but it looks good so far.

It looks like we will have to turn MVCC back on because we are now hitting a large number of table lock timeouts but thats going to reintroduce the DB file growth issue.  I know this feature is experimental but I guess my question is how experimental is it? and assuming the growth is down to long lived connections - is there any way to find out what selects / updates are still pending commits from the DB logs?

[Noel Grandin]

On 2012-06-15 09:54, Eoin Byrne wrote:
> It looks like we will have to turn MVCC back on because we are now
> hitting a large number of table lock timeouts but thats going to
> reintroduce the DB file growth issue. I know this feature is
> experimental but I guess my question is how experimental is it?

It works fine for some people, but others experience problems. The
bottom line is that we're just not sure. The people having problems have
never been able to produce us a decent test case, so it's kind of hard
to fix.

> and assuming the growth is down to long lived connections - is there
> any way to find out what selects / updates are still pending commits
> from the DB logs?
>

Your current best bet is to instrument the H2 code yourself.
I suggest these methods
org.h2.engine.Session#commit()
org.h2.engine.Session#begin()
And then you should be able to track the problem sessions down.

[Jason Pell]

We finally got sick of this issue and migrated to HSQLDB for MVCC and no more missing lob issues.  We still use H2, but only for storing configuration stuff that does not need to be updated concurrently.  It's a shame more attention has not been shown to this issue, because it was certainly frustrating having to change over to HSQLDB.

[Andrew Gaul]

On Friday, June 15, 2012 1:08:53 AM UTC-7, Noel Grandin wrote:

It works fine for some people, but others experience problems.  The
bottom line is that we're just not sure. The people having problems have
never been able to produce us a decent test case, so it's kind of hard
to fix.

I provided a test case for a simple MVCC bug here:

https://code.google.com/p/h2database/issues/detail?id=367

[Noel Grandin]

On 2013-05-30 00:34, Jason Pell wrote:
> We finally got sick of this issue and migrated to HSQLDB for MVCC and
> no more missing lob issues. We still use H2, but only for storing
> configuration stuff that does not need to be updated concurrently.
> It's a shame more attention has not been shown to this issue, because
> it was certainly frustrating having to change over to HSQLDB.

It's an open-source project, so I guess the problem would be yours for
failing to provide a fix.

(Nobody on this project, to my knowledge, is being paid to work on it).

Now, if you want to provide a test-case for your non-MVCC table lock
timeout problem, I could maybe help you there, but the MVCC code is
still experimental, so I'm not touching that, especially since we're
going to drop it when Thomas' new MVStore engine reaches maturity.

[Jason Pell]

I can't argue with you there, and I can understand that this one is a difficult problem, but from what I have read it's been around a while and still is an open problem.
I find it strange that more attention has not been paid to it is all.

[Ryan How]

I'm using MVCC and the only problems I've come across appear to be with
LOBS (that's ok for me, don't really need them for my use case).

What I mean is that it may have been less work for you to try and fix
the H2 source (Seeing the issues seem to all be with LOBS) rather than
change to hsqldb (And there would have been other people benefit from
that also). Isn't that meant to be one of the good things about open source?

I know, I get it from my programmers all the time (They say there is an
issue with the library, so they make their own or work around it, which
usually doesn't work very well anyway), I tell them to fix it upstream!
that is the whole point!

And it is getting lots of attention, the entire file store is being
re-written to accommodate for MVCC right from the start!, that is why
they haven't been giving attention to maintaining the current
experimental MVCC mode (Please correct me if I am wrong)

[Noel Grandin]

On 2013-05-30 08:48, Ryan How wrote:
>
> And it is getting lots of attention, the entire file store is being
> re-written to accommodate for MVCC right from the start!, that is why
> they haven't been giving attention to maintaining the current
> experimental MVCC mode (Please correct me if I am wrong)
>

That is correct. The existing MVCC mode was very much an experiment.
Thomas is busy writing a new engine that is MVCC from the ground up,
instead of being bolted onto the top.

[Noel Grandin]

On 2013-05-30 08:42, Jason Pell wrote:
> I find it strange that more attention has not been paid to it is all.

Mostly because most of us don't use it, we find the normal mode to be
pretty peachy.

Now, I have noticed that over the last year various people have bumped
into locking issues, some of which manifest as LOCK TIMEOUT, and we have
fixed various of those.
So might make sense for you to re-examine your workload on H2 (without
using the MVCC mode).
And if you bump into a LOCK TIMEOUT bug there, I'm willing to look into it.

[jason...@gmail.com]

Hi,

I have a sample of h2 failing when used with spring integration jdbc message channel store that times out on lock. Adding mvcc fixes that particular problem.  I will get a minimum test case that demonstrates this. The real issue is by default h2 locks entire table so only one thread can perform dml stuff this makes it unsuitable for our situation.  And we actually only use h2 in test we use Oracle or sql server in production

[Noel Grandin]

On 2013-05-30 10:56, jason...@gmail.com wrote:
> The real issue is by default h2 locks entire table so only one thread
> can perform dml stuff this makes it unsuitable for our situation. And
> we actually only use h2 in test we use Oracle or sql server in production

H2 is pretty fast, even with it's simple locking strategy.
What are you doing that requires so much speed that single-threaded
access to a table is insufficient?
Especially since you're only using it in test.

[Jason Pell]

Fixing the H2 source is easier said than done, changing to HSQLDB was
actually a few hours of work, granted they were a painful few hours, but when
you use JPA and Hibernate, switching DB's is relatively painless. 

We are still using H2 for a lot of stuff, even in production, we just use HSQLDB
to replace Oracle in test and dev as it behaves concurrently much better.  We
use H2 as a configuration store for lots of stuff that would be overkill to use with
Oracle.

The row level locking is what we really needed and thus because MVCC is experimental
with H2, we had to go with another DB where the MVCC support works well with CLOB. 

I would love to go back to H2 for everything and will certainly keep an eye on MVSTORE.

I do contribute to open source myself - being a committer on Apache CXF, but hacking on
H2 to fix this particular issue is way beyond my capability especially considering
what little time I have.

[Jason Pell]

We are doing integration testing using HSQLDB, we still do full blown integration test with oracle, but on developers PC's Oracle XE is way too heavy, so we have a local build which uses HSQLDB.  This does do stuff that requires reasonable concurrency from the DB and tends to cause timeouts otherwise.

We always suffered either from timeouts or when we went to MVCC, the missing lobs issue.

[Noel Grandin]

On 2013-05-30 12:58, Jason Pell wrote:
>
> The row level locking is what we really needed and thus because MVCC
> is experimental
> with H2, we had to go with another DB where the MVCC support works
> well with CLOB.
>

I doubt that. I suspect that you were just hitting some unfortunate
deadlocks in our locking stuff which went away with MVCC because our
locking is different in that mode.

But hey, you're free to do what floats your boat, this is open-source :-)

[Thomas Mueller]

Hi,

I can't say much about the problem itself (yet). 

But it's good that you can switch databases (Oracle, HSQLDB, H2,...), and are not stuck with one storage backend.

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+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?hl=en.
For more options, visit https://groups.google.com/groups/opt_out.

[Thomas Mueller]

Hi,

> Has there been any update on the missing lob problem in the interim?

I don't think so, sorry. But you should test with the latest version; 1.3.167 is relatively old already.

Also, (as written earlier already) a simple, reproducible test case would be great... ;-)

Regards,

Thomas

On Fri, May 31, 2013 at 5:45 PM, Karlos TheJackal <karlos...@gmail.com> wrote:

I am working on the same code that Eoin previously worked on. The fix for breaking up the select query is still in the code, but recently we have started getting the error again. The "DB closed" errors persist until the process is restarted unfortunately.

Has there been any update on the missing lob problem in the interim?

Thanks.

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?hl=en-US.

[Mark Addleman]

Hi, Thomas -

We are confronting a similar (possibly entirely different) issue described in https://groups.google.com/d/msg/h2-database/awQR6dY5ZPY/74wcsGAWsCcJ  We have a workaround now and I have hopes that MVStore will completely eliminate these two problems.

I'm not familiar with H2 internals at all but would love to provide a test case.  So far, our attempts to replicate the problem in a test case that we can send you haven't been successful.  Obviously, there is some key aspect of the problem that our test case isn't incorporating.  Can you provide some guidance as to related conditions, we might be able to come up with an appropriate test case.  The conditions I'm thinking of are pretty broad like LOBs, high insert rates, using batch inserts, concurrent deletes, indexes (do multicolumn indexes matter?), etc. 

[Noel Grandin]

We've fixed a number of bugs around LOB handling in the last couple of months so updating to the latest version might be worth your while.