Bug 1024936 - Data put to index enabled cache with Infinispan Directory provider using Async. JDBC StringBased CacheStore fails
Data put to index enabled cache with Infinispan Directory provider using Asyn...
Status: CLOSED WORKSFORME
Product: JBoss Data Grid 6
Classification: JBoss
Component: unspecified (Show other bugs)
unspecified
Unspecified Unspecified
unspecified Severity high
: ---
: 6.2.0
Assigned To: Tristan Tarrant
Martin Gencur
:
Depends On:
Blocks: 1017190
  Show dependency treegraph
 
Reported: 2013-10-30 11:29 EDT by Martin Gencur
Modified: 2013-12-09 07:12 EST (History)
1 user (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2013-12-09 07:12:01 EST
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)


External Trackers
Tracker ID Priority Status Summary Last Updated
JBoss Issue Tracker ISPN-3432 Critical Closed Data put to index enabled cache with Infinispan Directory provider using Async. JDBC StringBased CacheStore fails 2014-01-09 04:28:58 EST

  None (edit)
Description Martin Gencur 2013-10-30 11:29:35 EDT

    
Comment 2 JBoss JIRA Server 2013-12-02 03:18:59 EST
Adrian Nistor <anistor@redhat.com> made a comment on jira ISPN-3432

There are two problems here:

#1 I re-analyzed the bug and it seems the myriad of "org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after..." were fixed some time ago by ISPN-2815. This can be confirmed by reverting the commit for ISPN-2815 from master; then we get lots of lock acquire exceptions. When running on latest master they no longer appear.

#2 The attached config contains a major problem with the jdbc config. Each of the 4 nodes has 3 cachestores that all write in the _same_ h2 database. This leads to lots of:

{noformat}
2013-12-02 10:01:58,094 ERROR [JdbcStringBasedStore] (AsyncStoreProcessor-LuceneIndexesData_custom-6) ISPN008024: Error while storing string key to database; key: 'segments_3|0|16384|person'
org.h2.jdbc.JdbcSQLException: Unique index or primary key violation: "PRIMARY_KEY_7 ON PUBLIC.""ISPN_STRING_TABLE_LuceneIndexesData_custom""(ID_COLUMN)"; SQL statement:
INSERT INTO "ISPN_STRING_TABLE_LuceneIndexesData_custom" (DATA_COLUMN, TIMESTAMP_COLUMN, ID_COLUMN) VALUES(?,?,?) [23505-166]
	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.index.BaseIndex.getDuplicateKeyException(BaseIndex.java:81)
	at org.h2.index.TreeIndex.add(TreeIndex.java:62)
	at org.h2.table.RegularTable.addRow(RegularTable.java:121)
	at org.h2.command.dml.Insert.insertRows(Insert.java:124)
	at org.h2.command.dml.Insert.update(Insert.java:84)
	at org.h2.command.CommandContainer.update(CommandContainer.java:73)
	at org.h2.command.Command.executeUpdate(Command.java:226)
	at org.h2.jdbc.JdbcPreparedStatement.executeUpdateInternal(JdbcPreparedStatement.java:143)
	at org.h2.jdbc.JdbcPreparedStatement.executeUpdate(JdbcPreparedStatement.java:129)
	at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeUpdate(NewProxyPreparedStatement.java:105)
	at org.infinispan.persistence.jdbc.stringbased.JdbcStringBasedStore.write(JdbcStringBasedStore.java:166)
	at org.infinispan.persistence.async.AsyncCacheWriter.applyModificationsSync(AsyncCacheWriter.java:154)
	at org.infinispan.persistence.async.AsyncCacheWriter$AsyncStoreProcessor.retryWork(AsyncCacheWriter.java:329)
	at org.infinispan.persistence.async.AsyncCacheWriter$AsyncStoreProcessor.run(AsyncCacheWriter.java:313)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at java.lang.Thread.run(Thread.java:724)
{noformat}

and

{noformat}
2013-12-02 10:02:01,890 ERROR [JdbcStringBasedStore] (persistence-thread-0,NodeJ) ISPN008007: SQL error while fetching all StoredEntries
org.h2.jdbc.JdbcSQLException: Table "ISPN_STRING_TABLE_LuceneIndexesMetadata_custom" not found; SQL statement:
SELECT DATA_COLUMN,ID_COLUMN, TIMESTAMP_COLUMN FROM "ISPN_STRING_TABLE_LuceneIndexesMetadata_custom" WHERE TIMESTAMP_COLUMN > ? OR TIMESTAMP_COLUMN < 0 [42102-166]
	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.command.Parser.readTableOrView(Parser.java:4757)
	at org.h2.command.Parser.readTableFilter(Parser.java:1084)
	at org.h2.command.Parser.parseSelectSimpleFromPart(Parser.java:1690)
	at org.h2.command.Parser.parseSelectSimple(Parser.java:1797)
	at org.h2.command.Parser.parseSelectSub(Parser.java:1684)
	at org.h2.command.Parser.parseSelectUnion(Parser.java:1527)
	at org.h2.command.Parser.parseSelect(Parser.java:1515)
	at org.h2.command.Parser.parsePrepared(Parser.java:405)
	at org.h2.command.Parser.parse(Parser.java:279)
	at org.h2.command.Parser.parse(Parser.java:251)
	at org.h2.command.Parser.prepareCommand(Parser.java:217)
	at org.h2.engine.Session.prepareLocal(Session.java:415)
	at org.h2.engine.Session.prepareCommand(Session.java:364)
	at org.h2.jdbc.JdbcConnection.prepareCommand(JdbcConnection.java:1111)
	at org.h2.jdbc.JdbcPreparedStatement.<init>(JdbcPreparedStatement.java:71)
	at org.h2.jdbc.JdbcConnection.prepareStatement(JdbcConnection.java:266)
	at com.mchange.v2.c3p0.impl.NewProxyConnection.prepareStatement(NewProxyConnection.java:213)
	at org.infinispan.persistence.jdbc.stringbased.JdbcStringBasedStore$2.call(JdbcStringBasedStore.java:321)
	at org.infinispan.persistence.jdbc.stringbased.JdbcStringBasedStore$2.call(JdbcStringBasedStore.java:309)
	at java.util.concurrent.FutureTask.run(FutureTask.java:262)
        ...
{noformat}

The 4 nodes should not share the database in this case. By giving each node's database a unique name (instead of all being connectionUrl="jdbc:h2:mem:infinispan_string_based") the above jdbc errors disappear.

Since Anna supplied a config file by node java code, I've tested this using a variation of ClusteredCacheWithAsyncDirTest and then DistributedMassIndexingTest with the supplied config.
Please note these tests do not use multiple threads to cause the errors. Just one thread is enough to trigger the exceptions I mentioned.

I can no longer access the log file mentioned: https://jenkins.mw.lab.eng.bos.redhat.com/hudson/view/JDG/view/PERF-LIB/job/jdg-radargun-clustered-query/128/console-edg-perf10/

I think this issue can be closed as a consequence of ISPN-2815, but before doing so it would be good to run the radargun "performance tests for Index enabled Infinispan cache" Anna mentioned just to make sure the no problems surface under bigger load.
Comment 3 JBoss JIRA Server 2013-12-02 12:17:58 EST
Adrian Nistor <anistor@redhat.com> made a comment on jira ISPN-3432

There's also Anna's comment that by adding InfinispanIndexManager the locking issue disappears. I think using InfinispanIndexManager is the normal case. The other might just work, but there are no guarantees.
Comment 4 JBoss JIRA Server 2013-12-02 12:18:41 EST
Adrian Nistor <anistor@redhat.com> updated the status of jira ISPN-3432 to Closed
Comment 5 JBoss JIRA Server 2013-12-02 12:27:55 EST
Adrian Nistor <anistor@redhat.com> made a comment on jira ISPN-3432

This should be validated by QE by running radargun suite https://jenkins.mw.lab.eng.bos.redhat.com/hudson/view/JDG/view/PERF-LIB/job/jdg-radargun-clustered-query/ with Anna's config (file is attached) + the necessary fixes to make the config 6.0.Final compatible (replace <loaders> with <persistence>).
Comment 6 Martin Gencur 2013-12-09 07:12:01 EST
I executed the tests with updated configs and did not see the aforementioned exception.

Note You need to log in before you can comment on or make changes to this bug.