[
https://issues.jboss.org/browse/ISPN-3432?page=com.atlassian.jira.plugin....
]
Adrian Nistor commented on 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/j...
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.
Data put to index enabled cache with Infinispan Directory provider
using Async. JDBC StringBased CacheStore fails
-----------------------------------------------------------------------------------------------------------------
Key: ISPN-3432
URL:
https://issues.jboss.org/browse/ISPN-3432
Project: Infinispan
Issue Type: Bug
Components: Querying
Affects Versions: 6.0.0.Alpha1
Reporter: Anna Manukyan
Assignee: Adrian Nistor
Priority: Critical
Labels: 620
Fix For: 6.1.0.Final
Attachments: async-config.xml
Hi,
this issue is related to the ISPN-3090, but I thought to specify this case separately for
bringing detailed explanation for the configuration and thrown exceptions.
The issue relates to the performance tests for Index enabled Infinispan cache, with
configured Infinispan directory and Async JDBC. String Based Cache store.
The tests are running on 4 nodes and performing puts/gets on all nodes with many threads.
The problem is that, during data put, the following exceptions are thrown continuously:
{code}
04:04:05,633 ERROR [org.hibernate.search.exception.impl.LogErrorHandler] (Hibernate
Search: Index updates queue processor for index query-1) HSEARCH000058: Exception occurred
org.apache.lucene.index.IndexNotFoundException: no segments* file found in
InfinispanDirectory{indexName='query'}: files: []
Primary Failure:
Entity org.radargun.cachewrappers.InfinispanQueryWrapper$QueryableData Id
S:_InstallBenchmarkStage_0 Work Type org.hibernate.search.backend.UpdateLuceneWork
org.apache.lucene.index.IndexNotFoundException: no segments* file found in
InfinispanDirectory{indexName='query'}: files: []
at org.apache.lucene.index.SegmentInfos$FindSegmentsFile.run(SegmentInfos.java:667)
at org.apache.lucene.index.SegmentInfos$FindSegmentsFile.run(SegmentInfos.java:554)
at org.apache.lucene.index.SegmentInfos.read(SegmentInfos.java:359)
at org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:1138)
at
org.hibernate.search.backend.impl.lucene.IndexWriterHolder.createNewIndexWriter(IndexWriterHolder.java:148)
at
org.hibernate.search.backend.impl.lucene.IndexWriterHolder.getIndexWriter(IndexWriterHolder.java:115)
at
org.hibernate.search.backend.impl.lucene.AbstractWorkspaceImpl.getIndexWriter(AbstractWorkspaceImpl.java:117)
at
org.hibernate.search.backend.impl.lucene.LuceneBackendQueueTask.applyUpdates(LuceneBackendQueueTask.java:101)
at
org.hibernate.search.backend.impl.lucene.LuceneBackendQueueTask.run(LuceneBackendQueueTask.java:67)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
at java.util.concurrent.FutureTask.run(FutureTask.java:166)
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)
......
04:14:21,605 ERROR [org.hibernate.search.exception.impl.LogErrorHandler] (Hibernate
Search: Index updates queue processor for index query-1) HSEARCH000058: Exception occurred
org.apache.lucene.index.IndexNotFoundException: no segments* file found in
InfinispanDirectory{indexName='query'}: files: []
Primary Failure:
Entity org.radargun.cachewrappers.InfinispanQueryWrapper$QueryableData Id
S:key_0_0_0000000000000017 Work Type org.hibernate.search.backend.UpdateLuceneWork
org.apache.lucene.index.IndexNotFoundException: no segments* file found in
InfinispanDirectory{indexName='query'}: files: []
at org.apache.lucene.index.SegmentInfos$FindSegmentsFile.run(SegmentInfos.java:667)
at org.apache.lucene.index.SegmentInfos$FindSegmentsFile.run(SegmentInfos.java:554)
at org.apache.lucene.index.SegmentInfos.read(SegmentInfos.java:359)
at org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:1138)
at
org.hibernate.search.backend.impl.lucene.IndexWriterHolder.createNewIndexWriter(IndexWriterHolder.java:148)
at
org.hibernate.search.backend.impl.lucene.IndexWriterHolder.getIndexWriter(IndexWriterHolder.java:115)
at
org.hibernate.search.backend.impl.lucene.AbstractWorkspaceImpl.getIndexWriter(AbstractWorkspaceImpl.java:117)
at
org.hibernate.search.backend.impl.lucene.LuceneBackendQueueTask.applyUpdates(LuceneBackendQueueTask.java:101)
at
org.hibernate.search.backend.impl.lucene.LuceneBackendQueueTask.run(LuceneBackendQueueTask.java:67)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
at java.util.concurrent.FutureTask.run(FutureTask.java:166)
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)
{code}
You can find the cache configuration attached.
Yet another thing to mention:
if the following line is added to the cache configuration:
{code}
<property name="default.indexmanager"
value="org.infinispan.query.indexmanager.InfinispanIndexManager" />
{code}
then the issue is gone - no lock issue appears then.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see:
http://www.atlassian.com/software/jira