3 p.m.
Dear all,
I have written a small application for stress testing my CassandraCacheStore
in conjunction with the InfinispanDirectory.
Purpose of the test, inspired by a blog I've seen on Lucene performance, is
to index a dump of English Wikipedia (see
http://download.wikimedia.org/enwiki/latest/enwiki-latest-pages-articles....
).
The dump is 27GB of XML text for 3.5M articles. I read all the pages and for
each one I create a Lucene Document with three fields: the ID, the Title and
the Text of each (ID and Title are also Stored Fields). I open one
IndexWriter for the entire session and commit every 100 documents. I am
using the following infinispan.xml:
<namedCache name="cassandraCache">
<eviction strategy="LIRS" maxEntries="10000" />
<invocationBatching enabled="true" />
<loaders passivation="false" shared="true"
preload="false">
<loader
class="net.dataforte.infinispan.loaders.cassandra.CassandraCacheStore"
fetchPersistentState="false" ignoreModifications="false"
purgeOnStartup="false">
<properties>
<property name="host" value="localhost" />
<property name="keySpace" value="Infinispan" />
</properties>
<async />
</loader>
</loaders>
</namedCache>
Everything goes smoothly for a while, until I get a TimeoutException when
attempting to acquire the lock. This is during the IndexWriter commit() and,
depending on the run, it is caused either within the InfinispanDirectory
locking or within the Eviction thread. I have tried both with 4.1.0.FINAL
and with 4.2.0.ALPHA2, and also replacing my CacheStore with the basic
FileCacheStore but the result is the same.
Basically, at some point the commit() hangs indefinitely, and after a while
it breaks. Here is the stack trace:
47927> Job
47928> Battle of Naissus
47929> Strange loop
47930> Gloucester (disambiguation)
Committing...2010-10-01 14:48:55 EvictionManagerImpl [WARN] Could not
acquire lock for eviction of _56.cfs|1518|wikiIndex
2010-10-01 14:48:55 EvictionManagerImpl [WARN] Could not acquire lock for
eviction of _78.cfs|6|wikiIndex
2010-10-01 14:48:56 CommitLogSegment [INFO] Creating new commitlog segment
/tmp/infiniwiki/commitlog/CommitLog-1285937336075.log
2010-10-01 14:49:05 InvocationContextInterceptor [ERROR] Execution error:
org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock
after [10 seconds] on key [_7w.tis|RL|wikiIndex] for requestor
[Thread[main,5,main]]! Lock held by [GlobalTransaction:<null>:66883:local]
at
org.infinispan.container.EntryFactoryImpl.acquireLock(EntryFactoryImpl.java:218)
at
org.infinispan.container.EntryFactoryImpl.wrapEntryForWriting(EntryFactoryImpl.java:153)
at
org.infinispan.container.EntryFactoryImpl.wrapEntryForWriting(EntryFactoryImpl.java:106)
at
org.infinispan.interceptors.LockingInterceptor.visitPutKeyValueCommand(LockingInterceptor.java:234)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at
org.infinispan.interceptors.CacheStoreInterceptor.visitPutKeyValueCommand(CacheStoreInterceptor.java:194)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at
org.infinispan.interceptors.CacheLoaderInterceptor.visitPutKeyValueCommand(CacheLoaderInterceptor.java:79)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at
org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
at
org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:57)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at
org.infinispan.interceptors.TxInterceptor.enlistWriteAndInvokeNext(TxInterceptor.java:172)
at
org.infinispan.interceptors.TxInterceptor.visitPutKeyValueCommand(TxInterceptor.java:120)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:79)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:56)
at
org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:57)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at
org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:76)
at
org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:57)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
at
org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:273)
at org.infinispan.CacheDelegate.putIfAbsent(CacheDelegate.java:436)
at org.infinispan.CacheSupport.putIfAbsent(CacheSupport.java:40)
at
org.infinispan.lucene.readlocks.DistributedSegmentReadLocker.aquireReadLock(DistributedSegmentReadLocker.java:130)
at
org.infinispan.lucene.InfinispanDirectory.openInput(InfinispanDirectory.java:269)
at
org.apache.lucene.index.CompoundFileWriter.copyFile(CompoundFileWriter.java:221)
at
org.apache.lucene.index.CompoundFileWriter.close(CompoundFileWriter.java:184)
at
org.apache.lucene.index.DocumentsWriter.createCompoundFile(DocumentsWriter.java:672)
at
org.apache.lucene.index.IndexWriter.doFlushInternal(IndexWriter.java:4418)
at org.apache.lucene.index.IndexWriter.doFlush(IndexWriter.java:4264)
at org.apache.lucene.index.IndexWriter.flush(IndexWriter.java:4255)
at org.apache.lucene.index.IndexWriter.prepareCommit(IndexWriter.java:4133)
at org.apache.lucene.index.IndexWriter.commit(IndexWriter.java:4206)
at org.apache.lucene.index.IndexWriter.commit(IndexWriter.java:4179)
at net.dataforte.infiniwiki.WikiHandler.endElement(WikiHandler.java:90)
at
com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.endElement(AbstractSAXParser.java:601)
at
com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.scanEndElement(XMLDocumentFragmentScannerImpl.java:1782)
at
com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl$FragmentContentDriver.next(XMLDocumentFragmentScannerImpl.java:2938)
at
com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl.next(XMLDocumentScannerImpl.java:648)
at
com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.scanDocument(XMLDocumentFragmentScannerImpl.java:511)
at
com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:808)
at
com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:737)
at
com.sun.org.apache.xerces.internal.parsers.XMLParser.parse(XMLParser.java:119)
at
com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse(AbstractSAXParser.java:1205)
at
com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl$JAXPSAXParser.parse(SAXParserImpl.java:522)
at javax.xml.parsers.SAXParser.parse(SAXParser.java:395)
at javax.xml.parsers.SAXParser.parse(SAXParser.java:198)
at net.dataforte.infiniwiki.InfiniWiki.doIndex(InfiniWiki.java:126)
at net.dataforte.infiniwiki.InfiniWiki.main(InfiniWiki.java:152)
Tristan
4:26 p.m.
Hi Tristan,
two quick notes:
1) Until I fix ISPN-680 you shouldn't use eviction on a cache backing
the Lucene Directory, I'll fix it this weekend, maybe today.
2) you seem to have a lot of chunks, from your log
"_56.cfs|1518|wikiIndex" this means that the _56.cfs file is
fragmented in at least 1518 pieces, likely more.
Please set a quite-higher chunk value using the alternative constructor
InfinispanDirectory(Cache cache, String indexName, int chunkSize)
The default for chunkSize is quite small (16K) to optimize network I/O
during distribution/replication, but with such large indexes you
likely want higher chunks.
For Scarlet I'm defaulting to 7MB - be aware that you might need to
tune network/IO, in my case I had to rise the MySQL allowed max packet
size too, no idea if you have to configure something on Cassandra.
About the TimeoutException, I don't know, I hope someone from
Infinispan core could provide some hints;
if you can share this test I'll be glad to look into it, assuming it's
not complex to setup Cassandra, or a patch for an automated unit test
would be better.
Cheers,
Sanne
2010/10/1 Tristan Tarrant <tristan.tarrant(a)gmail.com>:
Dear all,
I have written a small application for stress testing my CassandraCacheStore
in conjunction with the InfinispanDirectory.
Purpose of the test, inspired by a blog I've seen on Lucene performance, is
to index a dump of English Wikipedia
(see http://download.wikimedia.org/enwiki/latest/enwiki-latest-pages-artic...).
The dump is 27GB of XML text for 3.5M articles. I read all the pages and for
each one I create a Lucene Document with three fields: the ID, the Title and
the Text of each (ID and Title are also Stored Fields). I open one
IndexWriter for the entire session and commit every 100 documents. I am
using the following infinispan.xml:
<namedCache name="cassandraCache">
<eviction strategy="LIRS" maxEntries="10000" />
<invocationBatching enabled="true" />
<loaders passivation="false" shared="true"
preload="false">
<loader
class="net.dataforte.infinispan.loaders.cassandra.CassandraCacheStore"
fetchPersistentState="false" ignoreModifications="false"
purgeOnStartup="false">
<properties>
<property name="host" value="localhost" />
<property name="keySpace" value="Infinispan" />
</properties>
<async />
</loader>
</loaders>
</namedCache>
Everything goes smoothly for a while, until I get a TimeoutException when
attempting to acquire the lock. This is during the IndexWriter commit() and,
depending on the run, it is caused either within the InfinispanDirectory
locking or within the Eviction thread. I have tried both with 4.1.0.FINAL
and with 4.2.0.ALPHA2, and also replacing my CacheStore with the basic
FileCacheStore but the result is the same.
Basically, at some point the commit() hangs indefinitely, and after a while
it breaks. Here is the stack trace:
47927> Job
47928> Battle of Naissus
47929> Strange loop
47930> Gloucester (disambiguation)
Committing...2010-10-01 14:48:55 EvictionManagerImpl [WARN] Could not
acquire lock for eviction of _56.cfs|1518|wikiIndex
2010-10-01 14:48:55 EvictionManagerImpl [WARN] Could not acquire lock for
eviction of _78.cfs|6|wikiIndex
2010-10-01 14:48:56 CommitLogSegment [INFO] Creating new commitlog segment
/tmp/infiniwiki/commitlog/CommitLog-1285937336075.log
2010-10-01 14:49:05 InvocationContextInterceptor [ERROR] Execution error:
org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock
after [10 seconds] on key [_7w.tis|RL|wikiIndex] for requestor
[Thread[main,5,main]]! Lock held by [GlobalTransaction:<null>:66883:local]
at
org.infinispan.container.EntryFactoryImpl.acquireLock(EntryFactoryImpl.java:218)
at
org.infinispan.container.EntryFactoryImpl.wrapEntryForWriting(EntryFactoryImpl.java:153)
at
org.infinispan.container.EntryFactoryImpl.wrapEntryForWriting(EntryFactoryImpl.java:106)
at
org.infinispan.interceptors.LockingInterceptor.visitPutKeyValueCommand(LockingInterceptor.java:234)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at
org.infinispan.interceptors.CacheStoreInterceptor.visitPutKeyValueCommand(CacheStoreInterceptor.java:194)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at
org.infinispan.interceptors.CacheLoaderInterceptor.visitPutKeyValueCommand(CacheLoaderInterceptor.java:79)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at
org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
at
org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:57)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at
org.infinispan.interceptors.TxInterceptor.enlistWriteAndInvokeNext(TxInterceptor.java:172)
at
org.infinispan.interceptors.TxInterceptor.visitPutKeyValueCommand(TxInterceptor.java:120)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:79)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:56)
at
org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:57)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at
org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:76)
at
org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:57)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
at
org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:273)
at org.infinispan.CacheDelegate.putIfAbsent(CacheDelegate.java:436)
at org.infinispan.CacheSupport.putIfAbsent(CacheSupport.java:40)
at
org.infinispan.lucene.readlocks.DistributedSegmentReadLocker.aquireReadLock(DistributedSegmentReadLocker.java:130)
at
org.infinispan.lucene.InfinispanDirectory.openInput(InfinispanDirectory.java:269)
at
org.apache.lucene.index.CompoundFileWriter.copyFile(CompoundFileWriter.java:221)
at
org.apache.lucene.index.CompoundFileWriter.close(CompoundFileWriter.java:184)
at
org.apache.lucene.index.DocumentsWriter.createCompoundFile(DocumentsWriter.java:672)
at
org.apache.lucene.index.IndexWriter.doFlushInternal(IndexWriter.java:4418)
at org.apache.lucene.index.IndexWriter.doFlush(IndexWriter.java:4264)
at org.apache.lucene.index.IndexWriter.flush(IndexWriter.java:4255)
at org.apache.lucene.index.IndexWriter.prepareCommit(IndexWriter.java:4133)
at org.apache.lucene.index.IndexWriter.commit(IndexWriter.java:4206)
at org.apache.lucene.index.IndexWriter.commit(IndexWriter.java:4179)
at net.dataforte.infiniwiki.WikiHandler.endElement(WikiHandler.java:90)
at
com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.endElement(AbstractSAXParser.java:601)
at
com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.scanEndElement(XMLDocumentFragmentScannerImpl.java:1782)
at
com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl$FragmentContentDriver.next(XMLDocumentFragmentScannerImpl.java:2938)
at
com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl.next(XMLDocumentScannerImpl.java:648)
at
com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.scanDocument(XMLDocumentFragmentScannerImpl.java:511)
at
com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:808)
at
com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:737)
at
com.sun.org.apache.xerces.internal.parsers.XMLParser.parse(XMLParser.java:119)
at
com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse(AbstractSAXParser.java:1205)
at
com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl$JAXPSAXParser.parse(SAXParserImpl.java:522)
at javax.xml.parsers.SAXParser.parse(SAXParser.java:395)
at javax.xml.parsers.SAXParser.parse(SAXParser.java:198)
at net.dataforte.infiniwiki.InfiniWiki.doIndex(InfiniWiki.java:126)
at net.dataforte.infiniwiki.InfiniWiki.main(InfiniWiki.java:152)
Tristan
_______________________________________________
infinispan-dev mailing list
infinispan-dev(a)lists.jboss.org
https://lists.jboss.org/mailman/listinfo/infinispan-dev
4:37 p.m.
Hi Sanne,
On Fri, Oct 1, 2010 at 16:26, Sanne Grinovero <sanne.grinovero(a)gmail.com>wrote:
1) Until I fix ISPN-680 you shouldn't use eviction on a cache
backing
the Lucene Directory, I'll fix it this weekend, maybe today.
Excellent.
2) you seem to have a lot of chunks, from your log
tune network/IO, in my case I had to rise the MySQL allowed max packet
size too, no idea if you have to configure something on Cassandra.
It shouldn't be a problem
The thing is self-contained running embedded Cassandra in a separate thread
on the same JVM. I will commit it somewhere so you can have a look. You'll
have to fetch the Wikipedia dump yourself though :)
Tristan
4:53 p.m.
On Fri, Oct 1, 2010 at 16:37, Tristan Tarrant <tristan.tarrant(a)gmail.com>wrote:
Hi Sanne,
On Fri, Oct 1, 2010 at 16:26, Sanne Grinovero <sanne.grinovero(a)gmail.com>wrote:
> 1) Until I fix ISPN-680 you shouldn't use eviction on a cache backing
> the Lucene Directory, I'll fix it this weekend, maybe today.
>
Excellent.
What if I use PIGGYBACK mode for the eviction ?
Tristan
5 p.m.
2010/10/1 Tristan Tarrant <tristan.tarrant(a)gmail.com>:
The thing is self-contained running embedded Cassandra in a separate
thread on the same JVM. I will commit it somewhere so you can have a look. You'll have
to fetch the Wikipedia dump yourself though :)
I might still have it around, similar tests done :)
On Fri, Oct 1, 2010 at 16:37, Tristan Tarrant
<tristan.tarrant(a)gmail.com>
wrote:
>
> Hi Sanne,
>
> On Fri, Oct 1, 2010 at 16:26, Sanne Grinovero <sanne.grinovero(a)gmail.com>
> wrote:
>>
>> 1) Until I fix ISPN-680 you shouldn't use eviction on a cache backing
>> the Lucene Directory, I'll fix it this weekend, maybe today.
>
> Excellent.
What if I use PIGGYBACK mode for the eviction ?
Hem, never heard of PIGGYBACK? where is that defined?
Sanne
7:10 p.m.
On 2010-10-01, at 11:00 AM, Sanne Grinovero wrote:
Hem, never heard of PIGGYBACK? where is that defined?
http://docs.jboss.org/infinispan/4.1/apidocs/config.html#ce_default_eviction
PIGGYBACK will most likely be the only and hence the default eviction policy starting with
4.2, it effectively is in 4.1 as well.
7:22 p.m.
2010/10/1 Vladimir Blagojevic <vblagoje(a)redhat.com>:
On 2010-10-01, at 11:00 AM, Sanne Grinovero wrote:
>
> Hem, never heard of PIGGYBACK? where is that defined?
>
http://docs.jboss.org/infinispan/4.1/apidocs/config.html#ce_default_eviction
PIGGYBACK will most likely be the only and hence the default eviction policy starting
with 4.2, it effectively is in 4.1 as well.
from the code in org.infinispan.container.DefaultDataContainer (branch
4.2) it seems to me it's just an alias for the DEFAULT (one and only)
policy ?
switch (policy) {
case PIGGYBACK:
case DEFAULT:
evictionListener = new DefaultEvictionListener();
break;
default:
throw new IllegalArgumentException("No such eviction
thread policy " + strategy);
}
Sanne
7:27 p.m.
On 2010-10-01, at 1:22 PM, Sanne Grinovero wrote:
2010/10/1 Vladimir Blagojevic <vblagoje(a)redhat.com>:
>
> On 2010-10-01, at 11:00 AM, Sanne Grinovero wrote:
>>
>> Hem, never heard of PIGGYBACK? where is that defined?
>>
>
> http://docs.jboss.org/infinispan/4.1/apidocs/config.html#ce_default_eviction
> PIGGYBACK will most likely be the only and hence the default eviction policy starting
with 4.2, it effectively is in 4.1 as well.
from the code in org.infinispan.container.DefaultDataContainer (branch
4.2) it seems to me it's just an alias for the DEFAULT (one and only)
policy ?
switch (policy) {
case PIGGYBACK:
case DEFAULT:
evictionListener = new DefaultEvictionListener();
break;
default:
throw new IllegalArgumentException("No such eviction
thread policy " + strategy);
}
Exactly. Manik and I did not see a way to accommodate old DEFAULT policy so as things
stand right now eviction thread policy will always be piggyback.
3:24 p.m.
Tristan,
Not sure what the cause of the TimeoutException is but if you the test again, can you
generate a thread dump when the first TE is reported so that we can see what the other
threads are doing?
We might be able to see what the thread holding the lock is doing.
Cheers,
On Oct 1, 2010, at 3:00 PM, Tristan Tarrant wrote:
Dear all,
I have written a small application for stress testing my CassandraCacheStore in
conjunction with the InfinispanDirectory.
Purpose of the test, inspired by a blog I've seen on Lucene performance, is to index
a dump of English Wikipedia (see
http://download.wikimedia.org/enwiki/latest/enwiki-latest-pages-articles....).
The dump is 27GB of XML text for 3.5M articles. I read all the pages and for each one I
create a Lucene Document with three fields: the ID, the Title and the Text of each (ID and
Title are also Stored Fields). I open one IndexWriter for the entire session and commit
every 100 documents. I am using the following infinispan.xml:
<namedCache name="cassandraCache">
<eviction strategy="LIRS" maxEntries="10000" />
<invocationBatching enabled="true" />
<loaders passivation="false" shared="true"
preload="false">
<loader class="net.dataforte.infinispan.loaders.cassandra.CassandraCacheStore"
fetchPersistentState="false" ignoreModifications="false"
purgeOnStartup="false">
<properties>
<property name="host" value="localhost" />
<property name="keySpace" value="Infinispan" />
</properties>
<async />
</loader>
</loaders>
</namedCache>
Everything goes smoothly for a while, until I get a TimeoutException when attempting to
acquire the lock. This is during the IndexWriter commit() and, depending on the run, it is
caused either within the InfinispanDirectory locking or within the Eviction thread. I have
tried both with 4.1.0.FINAL and with 4.2.0.ALPHA2, and also replacing my CacheStore with
the basic FileCacheStore but the result is the same.
Basically, at some point the commit() hangs indefinitely, and after a while it breaks.
Here is the stack trace:
47927> Job
47928> Battle of Naissus
47929> Strange loop
47930> Gloucester (disambiguation)
Committing...2010-10-01 14:48:55 EvictionManagerImpl [WARN] Could not acquire lock for
eviction of _56.cfs|1518|wikiIndex
2010-10-01 14:48:55 EvictionManagerImpl [WARN] Could not acquire lock for eviction of
_78.cfs|6|wikiIndex
2010-10-01 14:48:56 CommitLogSegment [INFO] Creating new commitlog segment
/tmp/infiniwiki/commitlog/CommitLog-1285937336075.log
2010-10-01 14:49:05 InvocationContextInterceptor [ERROR] Execution error:
org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [10
seconds] on key [_7w.tis|RL|wikiIndex] for requestor [Thread[main,5,main]]! Lock held by
[GlobalTransaction:<null>:66883:local]
at org.infinispan.container.EntryFactoryImpl.acquireLock(EntryFactoryImpl.java:218)
at
org.infinispan.container.EntryFactoryImpl.wrapEntryForWriting(EntryFactoryImpl.java:153)
at
org.infinispan.container.EntryFactoryImpl.wrapEntryForWriting(EntryFactoryImpl.java:106)
at
org.infinispan.interceptors.LockingInterceptor.visitPutKeyValueCommand(LockingInterceptor.java:234)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at
org.infinispan.interceptors.CacheStoreInterceptor.visitPutKeyValueCommand(CacheStoreInterceptor.java:194)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at
org.infinispan.interceptors.CacheLoaderInterceptor.visitPutKeyValueCommand(CacheLoaderInterceptor.java:79)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at
org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
at
org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:57)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at
org.infinispan.interceptors.TxInterceptor.enlistWriteAndInvokeNext(TxInterceptor.java:172)
at
org.infinispan.interceptors.TxInterceptor.visitPutKeyValueCommand(TxInterceptor.java:120)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:79)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:56)
at
org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:57)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at
org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:76)
at
org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:57)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:273)
at org.infinispan.CacheDelegate.putIfAbsent(CacheDelegate.java:436)
at org.infinispan.CacheSupport.putIfAbsent(CacheSupport.java:40)
at
org.infinispan.lucene.readlocks.DistributedSegmentReadLocker.aquireReadLock(DistributedSegmentReadLocker.java:130)
at org.infinispan.lucene.InfinispanDirectory.openInput(InfinispanDirectory.java:269)
at org.apache.lucene.index.CompoundFileWriter.copyFile(CompoundFileWriter.java:221)
at org.apache.lucene.index.CompoundFileWriter.close(CompoundFileWriter.java:184)
at org.apache.lucene.index.DocumentsWriter.createCompoundFile(DocumentsWriter.java:672)
at org.apache.lucene.index.IndexWriter.doFlushInternal(IndexWriter.java:4418)
at org.apache.lucene.index.IndexWriter.doFlush(IndexWriter.java:4264)
at org.apache.lucene.index.IndexWriter.flush(IndexWriter.java:4255)
at org.apache.lucene.index.IndexWriter.prepareCommit(IndexWriter.java:4133)
at org.apache.lucene.index.IndexWriter.commit(IndexWriter.java:4206)
at org.apache.lucene.index.IndexWriter.commit(IndexWriter.java:4179)
at net.dataforte.infiniwiki.WikiHandler.endElement(WikiHandler.java:90)
at
com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.endElement(AbstractSAXParser.java:601)
at
com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.scanEndElement(XMLDocumentFragmentScannerImpl.java:1782)
at
com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl$FragmentContentDriver.next(XMLDocumentFragmentScannerImpl.java:2938)
at
com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl.next(XMLDocumentScannerImpl.java:648)
at
com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.scanDocument(XMLDocumentFragmentScannerImpl.java:511)
at
com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:808)
at
com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:737)
at com.sun.org.apache.xerces.internal.parsers.XMLParser.parse(XMLParser.java:119)
at
com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse(AbstractSAXParser.java:1205)
at
com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl$JAXPSAXParser.parse(SAXParserImpl.java:522)
at javax.xml.parsers.SAXParser.parse(SAXParser.java:395)
at javax.xml.parsers.SAXParser.parse(SAXParser.java:198)
at net.dataforte.infiniwiki.InfiniWiki.doIndex(InfiniWiki.java:126)
at net.dataforte.infiniwiki.InfiniWiki.main(InfiniWiki.java:152)
Tristan
_______________________________________________
infinispan-dev mailing list
infinispan-dev(a)lists.jboss.org
https://lists.jboss.org/mailman/listinfo/infinispan-dev
--
Galder Zamarreño
Sr. Software Engineer
Infinispan, JBoss Cache
1:43 p.m.
Guys
Do you still have this issue with the latest ALPHAs?
Cheers
Manik
On 6 Oct 2010, at 14:24, Galder Zamarreño wrote:
Tristan,
Not sure what the cause of the TimeoutException is but if you the test again, can you
generate a thread dump when the first TE is reported so that we can see what the other
threads are doing?
We might be able to see what the thread holding the lock is doing.
Cheers,
On Oct 1, 2010, at 3:00 PM, Tristan Tarrant wrote:
> Dear all,
>
> I have written a small application for stress testing my CassandraCacheStore in
conjunction with the InfinispanDirectory.
>
> Purpose of the test, inspired by a blog I've seen on Lucene performance, is to
index a dump of English Wikipedia (see
http://download.wikimedia.org/enwiki/latest/enwiki-latest-pages-articles....).
> The dump is 27GB of XML text for 3.5M articles. I read all the pages and for each one
I create a Lucene Document with three fields: the ID, the Title and the Text of each (ID
and Title are also Stored Fields). I open one IndexWriter for the entire session and
commit every 100 documents. I am using the following infinispan.xml:
>
> <namedCache name="cassandraCache">
> <eviction strategy="LIRS" maxEntries="10000" />
> <invocationBatching enabled="true" />
> <loaders passivation="false" shared="true"
preload="false">
>
<loader class="net.dataforte.infinispan.loaders.cassandra.CassandraCacheStore"
> fetchPersistentState="false" ignoreModifications="false"
> purgeOnStartup="false">
> <properties>
> <property name="host" value="localhost" />
> <property name="keySpace" value="Infinispan" />
> </properties>
> <async />
> </loader>
> </loaders>
> </namedCache>
>
> Everything goes smoothly for a while, until I get a TimeoutException when attempting
to acquire the lock. This is during the IndexWriter commit() and, depending on the run, it
is caused either within the InfinispanDirectory locking or within the Eviction thread. I
have tried both with 4.1.0.FINAL and with 4.2.0.ALPHA2, and also replacing my CacheStore
with the basic FileCacheStore but the result is the same.
> Basically, at some point the commit() hangs indefinitely, and after a while it
breaks. Here is the stack trace:
>
> 47927> Job
> 47928> Battle of Naissus
> 47929> Strange loop
> 47930> Gloucester (disambiguation)
> Committing...2010-10-01 14:48:55 EvictionManagerImpl [WARN] Could not acquire lock
for eviction of _56.cfs|1518|wikiIndex
> 2010-10-01 14:48:55 EvictionManagerImpl [WARN] Could not acquire lock for eviction of
_78.cfs|6|wikiIndex
> 2010-10-01 14:48:56 CommitLogSegment [INFO] Creating new commitlog segment
/tmp/infiniwiki/commitlog/CommitLog-1285937336075.log
> 2010-10-01 14:49:05 InvocationContextInterceptor [ERROR] Execution error:
> org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [10
seconds] on key [_7w.tis|RL|wikiIndex] for requestor [Thread[main,5,main]]! Lock held by
[GlobalTransaction:<null>:66883:local]
> at org.infinispan.container.EntryFactoryImpl.acquireLock(EntryFactoryImpl.java:218)
> at
org.infinispan.container.EntryFactoryImpl.wrapEntryForWriting(EntryFactoryImpl.java:153)
> at
org.infinispan.container.EntryFactoryImpl.wrapEntryForWriting(EntryFactoryImpl.java:106)
> at
org.infinispan.interceptors.LockingInterceptor.visitPutKeyValueCommand(LockingInterceptor.java:234)
> at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
> at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
> at
org.infinispan.interceptors.CacheStoreInterceptor.visitPutKeyValueCommand(CacheStoreInterceptor.java:194)
> at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
> at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
> at
org.infinispan.interceptors.CacheLoaderInterceptor.visitPutKeyValueCommand(CacheLoaderInterceptor.java:79)
> at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
> at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
> at
org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
> at
org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:57)
> at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
> at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
> at
org.infinispan.interceptors.TxInterceptor.enlistWriteAndInvokeNext(TxInterceptor.java:172)
> at
org.infinispan.interceptors.TxInterceptor.visitPutKeyValueCommand(TxInterceptor.java:120)
> at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
> at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
> at
org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:79)
> at
org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:56)
> at
org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:57)
> at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
> at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
> at
org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:76)
> at
org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:57)
> at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
> at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:273)
> at org.infinispan.CacheDelegate.putIfAbsent(CacheDelegate.java:436)
> at org.infinispan.CacheSupport.putIfAbsent(CacheSupport.java:40)
> at
org.infinispan.lucene.readlocks.DistributedSegmentReadLocker.aquireReadLock(DistributedSegmentReadLocker.java:130)
> at
org.infinispan.lucene.InfinispanDirectory.openInput(InfinispanDirectory.java:269)
> at org.apache.lucene.index.CompoundFileWriter.copyFile(CompoundFileWriter.java:221)
> at org.apache.lucene.index.CompoundFileWriter.close(CompoundFileWriter.java:184)
> at
org.apache.lucene.index.DocumentsWriter.createCompoundFile(DocumentsWriter.java:672)
> at org.apache.lucene.index.IndexWriter.doFlushInternal(IndexWriter.java:4418)
> at org.apache.lucene.index.IndexWriter.doFlush(IndexWriter.java:4264)
> at org.apache.lucene.index.IndexWriter.flush(IndexWriter.java:4255)
> at org.apache.lucene.index.IndexWriter.prepareCommit(IndexWriter.java:4133)
> at org.apache.lucene.index.IndexWriter.commit(IndexWriter.java:4206)
> at org.apache.lucene.index.IndexWriter.commit(IndexWriter.java:4179)
> at net.dataforte.infiniwiki.WikiHandler.endElement(WikiHandler.java:90)
> at
com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.endElement(AbstractSAXParser.java:601)
> at
com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.scanEndElement(XMLDocumentFragmentScannerImpl.java:1782)
> at
com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl$FragmentContentDriver.next(XMLDocumentFragmentScannerImpl.java:2938)
> at
com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl.next(XMLDocumentScannerImpl.java:648)
> at
com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.scanDocument(XMLDocumentFragmentScannerImpl.java:511)
> at
com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:808)
> at
com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:737)
> at com.sun.org.apache.xerces.internal.parsers.XMLParser.parse(XMLParser.java:119)
> at
com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse(AbstractSAXParser.java:1205)
> at
com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl$JAXPSAXParser.parse(SAXParserImpl.java:522)
> at javax.xml.parsers.SAXParser.parse(SAXParser.java:395)
> at javax.xml.parsers.SAXParser.parse(SAXParser.java:198)
> at net.dataforte.infiniwiki.InfiniWiki.doIndex(InfiniWiki.java:126)
> at net.dataforte.infiniwiki.InfiniWiki.main(InfiniWiki.java:152)
>
> Tristan
>
> _______________________________________________
> infinispan-dev mailing list
> infinispan-dev(a)lists.jboss.org
> https://lists.jboss.org/mailman/listinfo/infinispan-dev
--
Galder Zamarreño
Sr. Software Engineer
Infinispan, JBoss Cache
_______________________________________________
infinispan-dev mailing list
infinispan-dev(a)lists.jboss.org
https://lists.jboss.org/mailman/listinfo/infinispan-dev
--
Manik Surtani
manik(a)jboss.org
Lead, Infinispan
Lead, JBoss Cache
http://www.infinispan.org
http://www.jbosscache.org
5120
days inactive
5144
days old
infinispan-dev@lists.jboss.org
10 comments
5 participants
participants (5)
-
Galder Zamarreño -
Manik Surtani -
Sanne Grinovero -
Tristan Tarrant -
Vladimir Blagojevic