Got LockObtainFailedException error under heavy load
dungleonhart Dec 29, 2011 11:11 AMHi,
I'm using Hibernate Search with Infinispan and JGroups in my project. When doing load testing (about several hundred requests within 10 seconds) with 2 nodes (same configurations), I found some errors and tried to apply a few tunning tips like:
- Increase the lock & replication timeout (to 120000)
- Set useLockStriping=false and increase the concurrencyLevel (to 5000)
- Modify rmem_max & wmem_max of Linux.
- Use distribution mode instead of replication mode
But poor me, I still got these logs (2 nodes):
Node 1:
2011-12-29 15:17:57,731 [Hibernate Search: Directory writer-1] ERROR org.hibernate.search.exception.impl.LogErrorHandler - Exception occurred org.apache.lucene.store.LockObtainFailedException: Lock obtain timed out: org.infinispan.lucene.locking.BaseLuceneLock@13782ef
Primary Failure:
Entity tc.model.TestCase Id 10144 Work Type org.hibernate.search.backend.AddLuceneWork
org.apache.lucene.store.LockObtainFailedException: Lock obtain timed out: org.infinispan.lucene.locking.BaseLuceneLock@13782ef
at org.apache.lucene.store.Lock.obtain(Lock.java:84)
at org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:1097)
at org.hibernate.search.backend.Workspace.createNewIndexWriter(Workspace.java:202)
at org.hibernate.search.backend.Workspace.getIndexWriter(Workspace.java:180)
at org.hibernate.search.backend.impl.lucene.PerDPQueueProcessor.run(PerDPQueueProcessor.java:103)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
2011-12-29 15:17:57,731 [Hibernate Search: Directory writer-1] ERROR org.hibernate.search.backend.impl.lucene.PerDPQueueProcessor - Unexpected error in Lucene Backend:
java.lang.NullPointerException
at org.hibernate.search.backend.impl.lucene.works.AddWorkDelegate.performWork(AddWorkDelegate.java:76)
at org.hibernate.search.backend.impl.lucene.PerDPQueueProcessor.run(PerDPQueueProcessor.java:106)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
2011-12-29 15:17:57,731 [Hibernate Search: Directory writer-1] ERROR org.hibernate.search.exception.impl.LogErrorHandler - Exception occurred java.lang.NullPointerException
Primary Failure:
Entity tc.model.TestCase Id 10144 Work Type org.hibernate.search.backend.AddLuceneWork
java.lang.NullPointerException
at org.hibernate.search.backend.impl.lucene.works.AddWorkDelegate.performWork(AddWorkDelegate.java:76)
at org.hibernate.search.backend.impl.lucene.PerDPQueueProcessor.run(PerDPQueueProcessor.java:106)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
2011-12-29 15:18:00,308 [Hibernate Search: Directory writer-1] ERROR org.hibernate.search.exception.impl.LogErrorHandler - Exception occurred org.apache.lucene.store.LockObtainFailedException: Lock obtain timed out: org.infinispan.lucene.locking.BaseLuceneLock@13782ef
Primary Failure:
Entity tc.model.TestCase Id 10145 Work Type org.hibernate.search.backend.AddLuceneWork
org.apache.lucene.store.LockObtainFailedException: Lock obtain timed out: org.infinispan.lucene.locking.BaseLuceneLock@13782ef
at org.apache.lucene.store.Lock.obtain(Lock.java:84)
at org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:1097)
at org.hibernate.search.backend.Workspace.createNewIndexWriter(Workspace.java:202)
at org.hibernate.search.backend.Workspace.getIndexWriter(Workspace.java:180)
at org.hibernate.search.backend.impl.lucene.PerDPQueueProcessor.run(PerDPQueueProcessor.java:103)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
2011-12-29 15:18:00,308 [Hibernate Search: Directory writer-1] ERROR org.hibernate.search.backend.impl.lucene.PerDPQueueProcessor - Unexpected error in Lucene Backend:
java.lang.NullPointerException
at org.hibernate.search.backend.impl.lucene.works.AddWorkDelegate.performWork(AddWorkDelegate.java:76)
at org.hibernate.search.backend.impl.lucene.PerDPQueueProcessor.run(PerDPQueueProcessor.java:106)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
2011-12-29 15:18:00,309 [Hibernate Search: Directory writer-1] ERROR org.hibernate.search.exception.impl.LogErrorHandler - Exception occurred java.lang.NullPointerException
Primary Failure:
Entity tc.model.TestCase Id 10145 Work Type org.hibernate.search.backend.AddLuceneWork
java.lang.NullPointerException
at org.hibernate.search.backend.impl.lucene.works.AddWorkDelegate.performWork(AddWorkDelegate.java:76)
at org.hibernate.search.backend.impl.lucene.PerDPQueueProcessor.run(PerDPQueueProcessor.java:106)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
...
---------------------------
Node 2:
2011-12-29 15:18:00,353 [Hibernate Search: Directory writer-1] ERROR org.hibernate.search.exception.impl.LogErrorHandler - Exception occurred java.io.FileNotFoundException: Error loading medatada for index file: _b1.cfs|M|tc.model.TestCase
Primary Failure:
Entity tc.model.TestCase Id 10099 Work Type org.hibernate.search.backend.AddLuceneWork
java.io.FileNotFoundException: Error loading medatada for index file: _b1.cfs|M|tc.model.TestCase
at org.infinispan.lucene.InfinispanDirectory.openInput(InfinispanDirectory.java:300)
at org.apache.lucene.store.Directory.openInput(Directory.java:139)
at org.apache.lucene.index.CompoundFileReader.<init>(CompoundFileReader.java:66)
at org.apache.lucene.index.CompoundFileReader.<init>(CompoundFileReader.java:55)
at org.apache.lucene.index.IndexWriter.getFieldInfos(IndexWriter.java:1193)
at org.apache.lucene.index.IndexWriter.getCurrentFieldInfos(IndexWriter.java:1213)
at org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:1149)
at org.hibernate.search.backend.Workspace.createNewIndexWriter(Workspace.java:202)
at org.hibernate.search.backend.Workspace.getIndexWriter(Workspace.java:180)
at org.hibernate.search.backend.impl.lucene.PerDPQueueProcessor.run(PerDPQueueProcessor.java:103)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
2011-12-29 15:18:00,355 [Hibernate Search: Directory writer-1] ERROR org.hibernate.search.backend.impl.lucene.PerDPQueueProcessor - Unexpected error in Lucene Backend:
java.lang.NullPointerException
at org.hibernate.search.backend.impl.lucene.works.AddWorkDelegate.performWork(AddWorkDelegate.java:76)
at org.hibernate.search.backend.impl.lucene.PerDPQueueProcessor.run(PerDPQueueProcessor.java:106)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
2011-12-29 15:18:00,355 [Hibernate Search: Directory writer-1] ERROR org.hibernate.search.exception.impl.LogErrorHandler - Exception occurred java.lang.NullPointerException
Primary Failure:
Entity tc.model.TestCase Id 10099 Work Type org.hibernate.search.backend.AddLuceneWork
java.lang.NullPointerException
at org.hibernate.search.backend.impl.lucene.works.AddWorkDelegate.performWork(AddWorkDelegate.java:76)
at org.hibernate.search.backend.impl.lucene.PerDPQueueProcessor.run(PerDPQueueProcessor.java:106)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
...
--------------------------
Here're my configurations:
1. Jars:
* hibernate-search-3.4.1.Final.jar
* hibernate-search-infinispan-3.4.1.Final.jar
* infinispan-core-4.2.1.FINAL.jar
* infinispan-lucene-directory-4.2.1.FINAL.jar
* jgroups-2.11.1.Final.jar
2. Hibernate:
<bean id="sessionFactory" class="org.springframework.orm.hibernate3.annotation.AnnotationSessionFactoryBean">
<property name="hibernateProperties">
<props>
<prop key="hibernate.dialect">org.hibernate.dialect.MySQLDialect</prop>
<prop key="hibernate.search.default.directory_provider">infinispan</prop>
<prop key="hibernate.search.infinispan.configuration_resourcename">hibernate-search-infinispan.xml</prop>
<prop key="hibernate.search.worker.backend">jgroupsMaster</prop>
<prop key="hibernate.search.worker.execution">async</prop>
</props>
</property>
</bean>
3. Configuration files: hibernate-search-infinispan.xml & jdbc_ping.xml (please find them in the attachments)
Please give me some advices to overcome this problem.
By the way, I just think that the Master/Slave model can fix this issue since the Master node is the only one who takes care of the indexed data. (Am I correct?). But I'm having difficulty in configuring that model (as I wrote in this thread http://community.jboss.org/message/643577#643577).
Thanks a lot, Infinispan team. You're all great guys.
-
jdbc_ping.xml 1.9 KB