Concurrent operations on LOBs

[Michał Grzejszczak]

Hello everyone,

I've been working with H2 for some time and recently encountered some
problems with operations on CLOBs in multiple threads. Using embedded
H2 and local connections I try to write to a table containing CLOBs
but in multiple threads on multiple connections at once.
From what I can see in the code a connection for creating CLOBs (or
BLOBs) is shared and whenever any thread tries to, for instance,
create a CLOB it tries to use the same connection/prepared statement/
result set without any synchronization. I wonder if that is a known
limitation, I do something wrong or there is a workaround.

I attach a simple test case that immediately throws exceptions
(usually NullPointer, but "no data" and "object is closed" can be seen
too) when executed. In the test case I just create a CLOB in a loop in
two threads. Each thread has its own connection. I tried it with
different versions of H2 from 1.2 and 1.3 streams with same results.


package transaction;

import java.sql.Connection;
import java.sql.SQLException;

import javax.sql.DataSource;

import org.h2.jdbcx.JdbcDataSource;

public class ErrorCreatingClobsConcurrently {

public static void main(String[] args) throws SQLException {
JdbcDataSource dataSource = createDatasource();
final Connection connection1 = createConnection(dataSource);
final Connection connection2 = createConnection(dataSource);

try {
// assertThat(table).isNotEmpty();
new Thread(new Runnable() {
@Override
public void run() {
try {
while (true)
connection1.createClob();
} catch (SQLException e) {
throw new RuntimeException(e);
}
}
}).start();
new Thread(new Runnable() {
@Override
public void run() {
try {
while (true)
connection2.createClob();
} catch (SQLException e) {
throw new RuntimeException(e);
}
}
}).start();
} finally {
closeConnections(connection1, connection2);
}
}

private static JdbcDataSource createDatasource() {
JdbcDataSource dataSource = new JdbcDataSource();
dataSource.setURL("jdbc:h2:mem:test;LOCK_MODE=3;MVCC=TRUE");
dataSource.setUser("sa");
return dataSource;
}

private static Connection createConnection(DataSource dataSource)
throws SQLException {
Connection connection2 = dataSource.getConnection();
connection2.setAutoCommit(false);
return connection2;
}

private static void closeConnections(Connection... connections)
throws SQLException {
for (Connection connection : connections) {
closeConnection(connection);
}
}

private static void closeConnection(Connection connection) throws
SQLException {
if (connection != null)
connection.close();
}
}

[Michał Grzejszczak]

Sorry, I just noticed the test case is wrong. I will post a better one
shortly.

[Thomas Mueller]

Hi,

Thanks a lot! You are right, this is a bug. The main problem is that
Connection.createBlob / createClob are not synchronized, but you are
right, the synchronization should be on a lower level. I will fix this
problem for the next release (this weekend). The work

Regards,
Thomas

[Thomas Mueller]

Hi,

If wrote my own test case and fixed it in the trunk. If you have a
better test case then please let me know!

Regards,
Thomas

[Michał Grzejszczak]

Hi,

Actually my test case is not much better. I think that yours should
suffice.
In any case I discovered that setting "h2.lobInDatabase", which
restores behavior from 1.2, seems to help as my test cases pass. Maybe
that will help someone.

Thanks for help and answer Thomas!

[Nick99]

hi,

I think I bumped into a similar bug. I have a multithreaded app; an instance of some class is updated; then it is loaded and an NPE is thrown by H2. I use #169, Windows 7, NTFS.

I cannot provide a test case at the moment; nor can I reproduce it again.

Could you please look what can be wrong?

Thank you.

Appendix 1

database.driverclass=org.h2.Driver

database.url=jdbc\:h2\:userdata/db/product01;MVCC\=TRUE;MULTI_THREADED\=0;LOCK_MODE\=3;LOCK_TIMEOUT\=20000

database.dialect=org.hibernate.dialect.H2Dialect

database.usr=

database.pass=

Appendix 2

2012-11-12 13:01:53,412 [err] org.hibernate.exception.GenericJDBCException: could not load an entity: [com.company.product.Instance#1]

[...]

2012-11-12 13:01:53,412 [err] Caused by: org.h2.jdbc.JdbcSQLException: General error: "java.lang.NullPointerException" [50000-169]

2012-11-12 13:01:53,412 [err] at org.h2.message.DbException.getJdbcSQLException(DbException.java:329)

2012-11-12 13:01:53,412 [err] at org.h2.message.DbException.get(DbException.java:158)

2012-11-12 13:01:53,412 [err] at org.h2.message.DbException.convert(DbException.java:281)

2012-11-12 13:01:53,412 [err] at org.h2.message.DbException.toSQLException(DbException.java:254)

2012-11-12 13:01:53,412 [err] at org.h2.message.TraceObject.logAndConvert(TraceObject.java:368)

2012-11-12 13:01:53,412 [err] at org.h2.jdbc.JdbcResultSet.getString(JdbcResultSet.java:293)

2012-11-12 13:01:53,412 [err] at com.mchange.v2.c3p0.impl.NewProxyResultSet.getString(NewProxyResultSet.java:3342)

2012-11-12 13:01:53,412 [err] at org.hibernate.type.descriptor.sql.VarcharTypeDescriptor$2.doExtract(VarcharTypeDescriptor.java:61)

2012-11-12 13:01:53,412 [err] at org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:64)

2012-11-12 13:01:53,412 [err] at org.hibernate.type.AbstractStandardBasicType.nullSafeGet(AbstractStandardBasicType.java:254)

2012-11-12 13:01:53,412 [err] at org.hibernate.type.AbstractStandardBasicType.nullSafeGet(AbstractStandardBasicType.java:250)

2012-11-12 13:01:53,412 [err] at org.hibernate.type.AbstractStandardBasicType.nullSafeGet(AbstractStandardBasicType.java:230)

2012-11-12 13:01:53,412 [err] at org.hibernate.type.AbstractStandardBasicType.hydrate(AbstractStandardBasicType.java:331)

2012-11-12 13:01:53,412 [err] at org.hibernate.persister.entity.AbstractEntityPersister.hydrate(AbstractEntityPersister.java:2283)

2012-11-12 13:01:53,412 [err] at org.hibernate.loader.Loader.loadFromResultSet(Loader.java:1527)

2012-11-12 13:01:53,412 [err] at org.hibernate.loader.Loader.instanceNotYetLoaded(Loader.java:1455)

2012-11-12 13:01:53,412 [err] at org.hibernate.loader.Loader.getRow(Loader.java:1355)

2012-11-12 13:01:53,412 [err] at org.hibernate.loader.Loader.getRowFromResultSet(Loader.java:611)

2012-11-12 13:01:53,412 [err] at org.hibernate.loader.Loader.doQuery(Loader.java:829)

2012-11-12 13:01:53,412 [err] at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:274)

2012-11-12 13:01:53,412 [err] at org.hibernate.loader.Loader.loadEntity(Loader.java:2037)

2012-11-12 13:01:53,412 [err] ... 54 more

2012-11-12 13:01:53,412 [err] Caused by: java.lang.NullPointerException

2012-11-12 13:01:53,412 [err] at org.h2.value.ValueLobDb.getInputStream(ValueLobDb.java:291)

2012-11-12 13:01:53,412 [err] at org.h2.value.ValueLobDb.getReader(ValueLobDb.java:277)

2012-11-12 13:01:53,412 [err] at org.h2.value.ValueLobDb.getString(ValueLobDb.java:198)

2012-11-12 13:01:53,412 [err] at org.h2.jdbc.JdbcResultSet.getString(JdbcResultSet.java:291)

2012-11-12 13:01:53,412 [err] ... 69 more

[Thomas Mueller]

Hi,

It seems the CLOB is closed, but I'm not sure why that would be, because the result set is still open it seems. I'm afraid I don't know what could be the problem in this case.

Regards,

Thomas

--
You received this message because you are subscribed to the Google Groups "H2 Database" group.

To view this discussion on the web visit https://groups.google.com/d/msg/h2-database/-/SUnfsf55Dk0J.

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.

[Nick99]

I think I can more or less reproduce the problem. It [sometimes, ~10%] happens when I load a fairly complex Hibernate-wired object 2 times with very low delay between loads (sub 50ms).

On the 2d read I managed to break at #291 of ValueLobDb.java when lobStorage==null. "this" dump:

• this = {org.h2.value.ValueLobDb@9968}"lob: null table: -1 id: 158"
• type = 16
• precision = 1670
• tableId = -1
• hash = 0
• lobStorage = null
• lobId = 158
• hmac = null
• small = null
• handler = null
• tempFile = null
• fileName = null 

I'll keep you posted.

[Nick99]

 The resultset returned by

com.mchange.v2.c3p0.impl.NewProxyPreparedStatement

public final java.sql.ResultSet executeQuery() throws java.sql.SQLException { /* compiled code */ } 

has

• currentRow = {org.h2.value.Value[125]@13167}
• [0] = {org.h2.value.ValueLong@13177}"34"
• [1] = {org.h2.value.ValueString@13178}"'---------------'"
• [2] = {org.h2.value.ValueString@13178}"' --------------- '"
• [3] = {org.h2.value.ValueString@13179}"'2012-320T16:03:34.250'"
• [4] = {org.h2.value.ValueString@13180}"' --------------- "
• [5] = {org.h2.value.ValueBoolean@13181}"TRUE"
• [6] = {org.h2.value.ValueBoolean@13181}"TRUE"
• [7] = {org.h2.value.ValueLong@13182}"37"
• [8] = {org.h2.value.ValueBoolean@13181}"TRUE"
• [9] = {org.h2.value.ValueBoolean@13181}"TRUE"
• [10] = {org.h2.value.ValueLobDb@13183}"lob: null table: 0 id: 0"
• [11] = {org.h2.value.ValueLobDb@13184}"lob: null table: 0 id: 0"
• [12] = {org.h2.value.ValueBoolean@13181}"TRUE"
• [13] = {org.h2.value.ValueString@13185}" --------------- "
• [14] = {org.h2.value.ValueInt@13186}"3"
• [15] = {org.h2.value.ValueBoolean@13181}"TRUE"
• [16] = {org.h2.value.ValueLobDb@9968}"lob: null table: -1 id: 158" 

 

[Nick99]

Okay, it seems I've isolated the source of missing lobs/LOB NPEs/missing lob entry problems. At this point I cannot attach a compilable project, just the test code and the trace log.

Environment:

2-core CPU

Java x32 1.6.27

h2-1.3.169 (embedded)
c3p0-0.9.1.2
hibernate-core-3.6.10

spring 3.1.2

The test cases creates an instance of a certain db-mapped class. The class contains a CLOB field along with some dummy field.
The test then starts 2 threads: the first one is reading the instance periodically, the other is updating it (periodically too). The CLOB field is not updated - the issue seems to not depend on it.

After about 1-5s of test run something bad happens (NPE/missing LOB/etc).

I'm attaching the trace log (lvl 3), the database (state: the java process was stopped from IDE after the exception), the test case. The db2.zip is the same stuff but with the failure happening almost immediately after start.

The test case requires some initial Spring/Hibernate/C3P0 configuration (e.g. hibernate.hbm2ddl.auto=update, etc), so if that's too much - I can to create a standalone project with all the deps included & send it. It may also be possible to recreate the test using plain JDBC, not the full Spring stack.

HTH; this (or similar) issue seems to be pretty popular recently.

Thank you.

[Noel Grandin]

Judging from the code paths involved, your code is

(1) opening a ResultSet
(2) calling commit() on that connection
(3) reading from that ResultSet

which is illegal.

In general, multi-thread apps should be using one connection per thread.

From experience, I can tell you that Hibernate is not a good match for a desktop-style multi-threaded application (I build lots of them).

For that reason, we use SimpleORM as our mapping layer to the database.

--
You received this message because you are subscribed to the Google Groups "H2 Database" group.

To view this discussion on the web visit https://groups.google.com/d/msg/h2-database/-/d9jyaefh7XsJ.

[Nick99]

> (3) reading from that ResultSet 

Do you mean doTask4()? The following code

                tx.commit();

                session.close();

                session = sessionFactory.openSession();

commits the session, and then opens it again (in a new connection, perhaps). The other thread (doTask3()) just reads from another session (connection?). There is some pooling involved, so I'm not sure if session=connection here.

[Nick99]

I've crafted a pure-JDBC example that fails on my case.

The only deps are lib\h2-1.3.170.jar & jdk 1.6.37. The test creates initial schema & data; then runs in 2 threads to read and read+write to the same row.

Could you please look at it. 

HTH

[Noel Grandin]

Nice work on creating the test case!

Interesting, this is a genuine bug somewhere in the LOB code, and it
manifests even with MVCC=false.

The only short-term fix I can see is to set your transaction isolation
to TRANSACTION_REPEATABLE_READ.

Thomas, I further reduced the test-case, and I'm including it here.
Note that (for me) it did not fail every single time. I normally let it
run for about 15 seconds, and then terminate and try again.
I get a failure rate of about 50%.


package test.TestCase1;

import java.io.File;
import java.sql.Connection;
import java.sql.DriverManager;
import java.sql.PreparedStatement;
import java.sql.ResultSet;
import java.sql.SQLException;
import java.sql.Statement;

public class TestCase1 {
private static final String URL =
"jdbc:h2:db/test01;MVCC=TRUE;MULTI_THREADED=0;LOCK_MODE=3;LOCK_TIMEOUT=20000;";

private static final String LONG_STRING =
"1111111111111111111111111111111111111111111111111111111111111111111"
+
"1111111111111111111111111111111111111111111111111111111111111111111".replace("1",
"1234567890");

public TestCase1() {
}

/**
* Test case start. After about 10s the exceptions will go to the
stdout.
*/
public void start() throws Exception {
final Connection conn = connect();

// Create initial schema (will fail on the second time run
unless the db
// file is deleted)
Statement st = null;
try {
st = conn.createStatement();
st.executeUpdate("CREATE TABLE IF NOT EXISTS TestInstance
(Id BIGINT generated by default as identity, "
+ "Description TEXT NOT NULL, Dummy VARCHAR(255)
NOT NULL, PRIMARY KEY (Id));");
conn.commit();
} catch (Exception e) {
conn.rollback();
e.printStackTrace();
}

// Add initial row
PreparedStatement pst = conn.prepareStatement("INSERT INTO
TestInstance (Description, Dummy) VALUES (?, ?)");
pst.setString(1, LONG_STRING);
pst.setString(2, "dummy");
pst.execute();
conn.commit();

if (st != null) {
st.close();
}

// Start the updater thread
new Thread("updater") {

@Override
public void run() {
try {

doUpdates(connect());
} catch (Exception e) {
e.printStackTrace();
}
}
}.start();

// Do the reading in the current thread
doReads(conn);

if (!conn.isClosed()) {
conn.close();
}
System.out.println("Closed the database");
}

/**
* Reads all rows from the target table.
*/
private void doReads(Connection conn) throws Exception {
while (true) {
try {
final Statement st = conn.createStatement();
final ResultSet rs = st.executeQuery("SELECT * FROM
TestInstance");

while (rs.next()) {
rs.getInt(1);
rs.getString(2);
rs.getString(3);
}

rs.close();
st.close();
} catch (SQLException e) {
e.printStackTrace();
}

conn.commit();
Thread.sleep(50);
}
}

/**
* Reads the 1st row & then updates it.
*/
private void doUpdates(Connection conn) throws Exception {
final PreparedStatement pst = conn
.prepareStatement("UPDATE TestInstance set
Description=?, Dummy=? WHERE id=1");

int i = 0;
while (true) {
// Read the instance
Statement st = conn.createStatement();
ResultSet rs = st.executeQuery("SELECT * FROM TestInstance
WHERE Id=1");

while (rs.next()) {
rs.getInt(1);
rs.getString(2);
rs.getString(3);
}
rs.close();
st.close();

// Update the instance
pst.setString(1, LONG_STRING + i++);
pst.setString(2, "Dummy");
pst.execute();

conn.commit();
Thread.sleep(50);
}
}

/**
* Connects to the db.
*/
private Connection connect() throws Exception {
Class.forName("org.h2.Driver");

System.out.println("Connecting to database");

Connection conn = DriverManager.getConnection(URL);
conn.setAutoCommit(false);
conn.setTransactionIsolation(Connection.TRANSACTION_READ_COMMITTED);

return conn;
}

public static void main(String[] args) throws Exception {
new File("db/test01.h2.db").delete();
new File("db/test01.lock.db").delete();
new File("db/test01.trace.db").delete();
TestCase1 tc1 = new TestCase1();
tc1.start();
}
}

[Noel Grandin]

Hmmm, I think what is happening here is that when in MVCC mode with
transaction isolation level TRANSACTION_READ_COMMITTED, the session is
somehow seeing LOB entries that have already been deleted.

Thomas, does that ring any bells?

I've been through the code paths that end up in LobStorage, but I can't
see any obvious problems.

[Nick99]

It seems the problem is with MVCC.

The test is not failing for 30s on my system with: "jdbc:h2:db/test01;MVCC=FALSE;MULTI_THREADED=0;LOCK_MODE=3;LOCK_TIMEOUT=20000;"

All isolation levels fail for (in the 1-5s timeframe): "jdbc:h2:db/test01;MVCC=TRUE;MULTI_THREADED=0;LOCK_MODE=3;LOCK_TIMEOUT=20000;" 

Connection.TRANSACTION_READ_UNCOMMITTED

Connection.TRANSACTION_READ_COMMITTED

Connection.TRANSACTION_REPEATABLE_READ

Connection.TRANSACTION_SERIALIZABLE

On Tuesday, December 4, 2012 11:01:37 AM U

[Nick99]

Hello,

Any plans for the fix/workaround? 

I can only think of some pretty messy workarounds like moving my CLOB fields to 

a) just VARCHAR(255) /though the docs say The maximum precision is Integer.MAX_VALUE/ 

b) or to BLOB (may behave the same way as CLOB) 

c) or to BINARY (looks promising).

[Ryan How]

Side note: LOCK_MODE has no effect with MVCC.

There is also a FOR UPDATE bug with LOBS in MVCC. My guess is these issues won't get fixed unless you submit a patch as the devs are working on a new storage backend which should solve all the issues.

You could try BINARY? I think it stores the object in memory when you query them? SO make sure you got enough memory to hold all your big objects. Integer.MAXVALUE is 2GB of data if I'm not mistaken?. How big are your BLOBS?

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

[Nick99]

They are basically 1024 unicode chars tops. So keeping them in memory should be ok.

> Integer.MAXVALUE 

I'll try to use VARCHAR(1024); but

>  CLOB
> should be used for documents and texts with arbitrary size such as XML
> or HTML documents, text files, or memo fields of unlimited size.
> VARCHAR should be used for text with relatively short average size
> (for example shorter than 200 characters) 

[Ryan How]

It depends on your use case I think. I recently had 10MB objects reading
into memory... but it wasn't very optimal and I did get OOM errors :).
I'm sure 1024 characters would be fine ;). It's probably faster than
with CLOBS as they'll be inline so one less pointer to follow.

I'd just test it and see how you go. I think CLOB will behave the same
as BLOB. But I guess you have to try it to make sure.

[Nick99]

I can say that the approach with VARCHARs works ok in my case after several months of test/production usage. I'm using up to 10K length VARCHARs.