Lucene error : Too Many Open File ??

[#1]

Hello,

We are working with Alfresco 1.4. And I think that our index is corrupted because I can see a lot of error in alfresco log file and we can't add more file since see a dump error.

Error log :

00:03:43,186 ERROR [org.alfresco.repo.search.impl.lucene.LuceneBase2] Errorjava.io.FileNotFoundException: ./alf_data/lucene-indexes/workspace/SpacesStore/0e3909ea-79a7-11db-946d-3bededff6578/IndexInfoDeletions (Too many open files)
        at java.io.FileInputStream.open(Native Method)
        at java.io.FileInputStream.<init>(FileInputStream.java:106)        at org.alfresco.repo.search.impl.lucene.index.IndexInfo.getDeletions(IndexInfo.java:648)
        at org.alfresco.repo.search.impl.lucene.index.IndexInfo.createMainIndexReader(IndexInfo.java:1377)
        at org.alfresco.repo.search.impl.lucene.index.IndexInfo.getMainIndexReferenceCountingReadOnlyIndexReader(IndexInfo.java:748)
        at org.alfresco.repo.search.impl.lucene.LuceneBase2.getSearcher(LuceneBase2.java:156)
        at org.alfresco.repo.search.impl.lucene.LuceneIndexerImpl2.updateFullTextSearch(LuceneIndexerImpl2.java:1772)
        at org.alfresco.repo.search.impl.lucene.fts.FullTextSearchIndexerImpl.index(FullTextSearchIndexerImpl.java:172)
        at sun.reflect.GeneratedMethodAccessor503.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:585)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:335)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:181)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:148)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:170)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:176)
        at $Proxy4.index(Unknown Source)
        at org.alfresco.repo.search.impl.lucene.fts.FTSIndexerJob.execute(FTSIndexerJob.java:36)
        at org.quartz.core.JobRunShell.run(JobRunShell.java:191)
        at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:516)


00:03:43,193 ERROR [org.quartz.core.JobRunShell] Job DEFAULT.ftsIndexerJobDetail threw an unhandled Exception:
org.alfresco.repo.search.impl.lucene.LuceneIndexException: Failed FTS update
        at org.alfresco.repo.search.impl.lucene.LuceneIndexerImpl2.updateFullTextSearch(LuceneIndexerImpl2.java:1897)
        at org.alfresco.repo.search.impl.lucene.fts.FullTextSearchIndexerImpl.index(FullTextSearchIndexerImpl.java:172)
        at sun.reflect.GeneratedMethodAccessor503.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:585)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:335)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:181)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:148)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:170)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:176)
        at $Proxy4.index(Unknown Source)
        at org.alfresco.repo.search.impl.lucene.fts.FTSIndexerJob.execute(FTSIndexerJob.java:36)
        at org.quartz.core.JobRunShell.run(JobRunShell.java:191)        at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:516)Caused by: org.alfresco.repo.search.impl.lucene.LuceneIndexException: Failed to open IndexSarcher for ./alf_data/lucene-indexes/workspace/SpacesStore/
        at org.alfresco.repo.search.impl.lucene.LuceneBase2.getSearcher(LuceneBase2.java:172)
        at org.alfresco.repo.search.impl.lucene.LuceneIndexerImpl2.updateFullTextSearch(LuceneIndexerImpl2.java:1772)
        … 14 moreCaused by: java.io.FileNotFoundException: ./alf_data/lucene-indexes/workspace/SpacesStore/0e3909ea-79a7-11db-946d-3bededff6578/IndexInfoDeletions (Too many open files)
        at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:282)
        at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:744)
        at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:674)
        at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:866)
        at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
        at java.lang.Thread.run(Thread.java:595)


00:03:43,186 ERROR [org.alfresco.repo.search.impl.lucene.LuceneBase2] Error
java.io.FileNotFoundException: ./alf_data/lucene-indexes/workspace/SpacesStore/0e3909ea-79a7-11db-946d-3bededff6578/IndexInfoDeletions (Too many open files)
        at java.io.FileInputStream.open(Native Method)
        at java.io.FileInputStream.<init>(FileInputStream.java:106)
        at org.alfresco.repo.search.impl.lucene.index.IndexInfo.getDeletions(IndexInfo.java:648)
        at org.alfresco.repo.search.impl.lucene.index.IndexInfo.createMainIndexReader(IndexInfo.java:1377)
        at org.alfresco.repo.search.impl.lucene.index.IndexInfo.getMainIndexReferenceCountingReadOnlyIndexReader(IndexInfo.java:748)
        at org.alfresco.repo.search.impl.lucene.LuceneBase2.getSearcher(LuceneBase2.java:156)
        at org.alfresco.repo.search.impl.lucene.LuceneIndexerImpl2.updateFullTextSearch(LuceneIndexerImpl2.java:1772)
        at org.alfresco.repo.search.impl.lucene.fts.FullTextSearchIndexerImpl.index(FullTextSearchIndexerImpl.java:172)
        at sun.reflect.GeneratedMethodAccessor503.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:585)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:335)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:181)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:148)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:170)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:176)
        at $Proxy4.index(Unknown Source)
        at org.alfresco.repo.search.impl.lucene.fts.FTSIndexerJob.execute(FTSIndexerJob.java:36)
        at org.quartz.core.JobRunShell.run(JobRunShell.java:191)
        at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:516)

We tried to increase the number of files that can be opened simultaneously : ulimit -n 65535

But It's still the same.

If I check the number of file open by lucene, this is what I see :

[root@fidji alfresco]# lsof | grep luc | wc -l
845

With this command, I can see that lucene seams working on deleted file.

[root@fidji alfresco]# lsof | grep luc
java      3930    root  807r      REG        9,0     21298   18677931 /data/alfresco/alf_data/lucene-indexes/workspace/lightWeightVersionStore/d9838a8f-79a6-11db-946d-3bededff6578/_m.cfs (deleted)
java      3930    root  808r      REG        9,0     18657   18678420 /data/alfresco/alf_data/lucene-indexes/workspace/lightWeightVersionStore/f7a4dc0a-79a6-11db-946d-3bededff6578/_j.cfs (deleted)
java      3930    root  809r      REG        9,0     22366   18678493 /data/alfresco/alf_data/lucene-indexes/workspace/lightWeightVersionStore/0f1efd2e-79a7-11db-946d-3bededff6578/_n.cfs (deleted)
java      3930    root  810r      REG        9,0     21296   18564073 /data/alfresco/alf_data/lucene-indexes/workspace/lightWeightVersionStore/286aab1d-79a7-11db-946d-3bededff6578/_m.cfs (deleted)
java      3930    root  811r      REG        9,0      5789   18678520 /data/alfresco/alf_data/lucene-indexes/workspace/SpacesStore/a3bbbacb-79a7-11db-946d-3bededff6578/_4.cfs
java      3930    root  812r      REG        9,0     22409   18678521 /data/alfresco/alf_data/lucene-indexes/workspace/lightWeightVersionStore/34e16e87-79a7-11db-946d-3bededff6578/_n.cfs
java      3930    root  813r      REG        9,0      4019   18678523 /data/alfresco/alf_data/lucene-indexes/workspace/SpacesStore/a4082d21-79a7-11db-946d-3bededff6578/_2.cfs
java      3930    root  814r      REG        9,0     18656   18678536 /data/alfresco/alf_data/lucene-indexes/workspace/lightWeightVersionStore/a4d8eaac-79a7-11db-946d-3bededff6578/_j.cfs
java      3930    root  815r      REG        9,0     23181   18678553 /data/alfresco/alf_data/lucene-indexes/workspace/lightWeightVersionStore/11c3e8ff-79a8-11db-946d-3bededff6578/_o.cfs

What can I do ?
Is it possible to recreate the index ?

Thanks
Regards,
Chris

[ribz33]

me too, with increasing ulimit no more problem 

[nuga]

this is a tomcat issue.. when a thread has too many open open files in tomcat  ( the limit is 1056)

just google  too many open files tomcat


similar problem different app..
"Total number of open file
descriptors on ARIA rose by the dozen to over 800.  When the total number
of file descriptors reached 1024, tomcat would crash.  After modifying the
servlet to properly dispose of processes, within several minutes of
starting up tomcat and reloading the DownloadServlet page dozens of times,
the number of open file descriptors was maintained between 30 and 40.
Several hours later, this number is at 30."

and still another..

"This error comes from the OS, when there are too many open file or socket descriptors (usually more than 1024 on a linux standard kernel).

Check that any socket or file objects are being closed correctly."


Since the socket/file objects being closed is on the alfresco side (they provide the client and the web service).  I hope they really do stress test this issue because it has happened to me as well.  At first i thought it was the number of sessions created.. (i regularly get 5k sessions) but the # of session dont' correspond with the # of open files

As for any user of alfresco .. make sure you are calling AuthenticationUtils.endSession();

[nuga]

increasing the file limit .. is just a bandaid prolonging the envitable if indeed flies aren't being closed properly for somereason

[waschbecken]

hello,
I also had some troubles with the ulimit.
Currently it is set to 4096.

After removing the lucene-indexes folder and setting index.recovery.mode=FULL I get the following exception:

1:06:29,444 INFO  [FullIndexRecoveryComponent]         10 % complete.
11:06:42,304 INFO  [FullIndexRecoveryComponent]         20 % complete.
11:06:55,576 INFO  [FullIndexRecoveryComponent]         30 % complete.
11:07:06,838 INFO  [FullIndexRecoveryComponent]         40 % complete.
11:07:24,431 INFO  [FullIndexRecoveryComponent]         50 % complete.
11:07:43,816 INFO  [FullIndexRecoveryComponent]         60 % complete.
11:07:48,621 ERROR [JobRunShell] Job DEFAULT.org.springframework.scheduling.quartz.JobDetailBean#e75a11 threw an unhandled Exception:
org.springframework.dao.DataIntegrityViolationException: Non-root node has no primary parent:
   child: workspace://lightWeightVersionStore/237a93f1-cb1c-11db-9f31-8bd2e10a4a3a
        at org.alfresco.repo.node.db.hibernate.HibernateNodeDaoServiceImpl.getPrimaryParentAssoc(HibernateNodeDaoServiceImpl.java:833)
        at sun.reflect.GeneratedMethodAccessor207.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:585)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:335)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:181)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:148)
        at org.alfresco.repo.transaction.TransactionalDaoInterceptor.invoke(TransactionalDaoInterceptor.java:60)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:170)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:176)
        at $Proxy132.getPrimaryParentAssoc(Unknown Source)
        at org.alfresco.repo.node.db.DbNodeServiceImpl.getPrimaryParent(DbNodeServiceImpl.java:1093)
        at sun.reflect.GeneratedMethodAccessor206.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:585)
        at org.alfresco.repo.service.StoreRedirectorProxyFactory$RedirectorInvocationHandler.invoke(StoreRedirectorProxyFactory.java:213)
        at $Proxy133.getPrimaryParent(Unknown Source)
        at org.alfresco.repo.node.index.FullIndexRecoveryComponent$1.doWork(FullIndexRecoveryComponent.java:266)
        at org.alfresco.repo.transaction.TransactionUtil.executeInTransaction(TransactionUtil.java:168)
        at org.alfresco.repo.transaction.TransactionUtil.executeInNonPropagatingUserTransaction(TransactionUtil.java:126)
        at org.alfresco.repo.node.index.FullIndexRecoveryComponent.reindexTransaction(FullIndexRecoveryComponent.java:275)
        at org.alfresco.repo.node.index.FullIndexRecoveryComponent.performFullRecovery(FullIndexRecoveryComponent.java:198)
        at org.alfresco.repo.node.index.FullIndexRecoveryComponent.reindexImpl(FullIndexRecoveryComponent.java:157)
        at org.alfresco.repo.node.index.AbstractReindexComponent$1.doWork(AbstractReindexComponent.java:209)
        at org.alfresco.repo.transaction.TransactionUtil.executeInTransaction(TransactionUtil.java:168)
        at org.alfresco.repo.transaction.TransactionUtil.executeInUserTransaction(TransactionUtil.java:74)
        at org.alfresco.repo.node.index.AbstractReindexComponent.reindex(AbstractReindexComponent.java:213)
        at org.alfresco.repo.node.index.IndexRecoveryJob.execute(IndexRecoveryJob.java:31)
        at org.quartz.core.JobRunShell.run(JobRunShell.java:191)
        at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:516)
11:07:48,626 ERROR [ErrorLogger] Job (DEFAULT.org.springframework.scheduling.quartz.JobDetailBean#e75a11 threw an exception.
org.quartz.SchedulerException: Job threw an unhandled exception. [See nested exception: org.springframework.dao.DataIntegrityViolationException: Non-root node h
as no primary parent:
   child: workspace://lightWeightVersionStore/237a93f1-cb1c-11db-9f31-8bd2e10a4a3a]
        at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
        at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:516)
* Nested Exception (Underlying Cause) —————
org.springframework.dao.DataIntegrityViolationException: Non-root node has no primary parent:
   child: workspace://lightWeightVersionStore/237a93f1-cb1c-11db-9f31-8bd2e10a4a3a
        at org.alfresco.repo.node.db.hibernate.HibernateNodeDaoServiceImpl.getPrimaryParentAssoc(HibernateNodeDaoServiceImpl.java:833)
        at sun.reflect.GeneratedMethodAccessor207.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:585)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:335)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:181)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:148)
        at org.alfresco.repo.transaction.TransactionalDaoInterceptor.invoke(TransactionalDaoInterceptor.java:60)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:170)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:176)
        at $Proxy132.getPrimaryParentAssoc(Unknown Source)
        at org.alfresco.repo.node.db.DbNodeServiceImpl.getPrimaryParent(DbNodeServiceImpl.java:1093)
        at sun.reflect.GeneratedMethodAccessor206.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:585)
        at org.alfresco.repo.service.StoreRedirectorProxyFactory$RedirectorInvocationHandler.invoke(StoreRedirectorProxyFactory.java:213)
        at $Proxy133.getPrimaryParent(Unknown Source)
        at org.alfresco.repo.node.index.FullIndexRecoveryComponent$1.doWork(FullIndexRecoveryComponent.java:266)
        at org.alfresco.repo.transaction.TransactionUtil.executeInTransaction(TransactionUtil.java:168)
        at org.alfresco.repo.transaction.TransactionUtil.executeInNonPropagatingUserTransaction(TransactionUtil.java:126)
        at org.alfresco.repo.node.index.FullIndexRecoveryComponent.reindexTransaction(FullIndexRecoveryComponent.java:275)
        at org.alfresco.repo.node.index.FullIndexRecoveryComponent.performFullRecovery(FullIndexRecoveryComponent.java:198)
        at org.alfresco.repo.node.index.FullIndexRecoveryComponent.reindexImpl(FullIndexRecoveryComponent.java:157)
        at org.alfresco.repo.node.index.AbstractReindexComponent$1.doWork(AbstractReindexComponent.java:209)
        at org.alfresco.repo.transaction.TransactionUtil.executeInTransaction(TransactionUtil.java:168)
        at org.alfresco.repo.transaction.TransactionUtil.executeInUserTransaction(TransactionUtil.java:74)
        at org.alfresco.repo.node.index.AbstractReindexComponent.reindex(AbstractReindexComponent.java:213)
        at org.alfresco.repo.node.index.IndexRecoveryJob.execute(IndexRecoveryJob.java:31)
        at org.quartz.core.JobRunShell.run(JobRunShell.java:191)
        at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:516)‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

Alfresco is still running, but I encouter several troubles like CIFS and Webview are not synchronized (hidden folders and directories in Windows Explorer)

Any hints, what I can try next?

[steve]

Hi,

We have found issues in house with Java 6 and currently wouldn't recommend running Alfresco on it.

Steve

[andy]

Hi

Details on file handle issues can be found here:
http://wiki.alfresco.com/wiki/Search#File_Handles_and_lucene

Which version of the repo gives you the index issue?
What is your alfresco history - which versions have you used and upgraded in the past?

Cheers

Andy

[waschbecken]

Hello,

currently we are using  version 1.4.0 (build-105) schema 21.
No upgrades took place in the past, so far.

I also searched in our MySQL for the given node entry. In the alf_node_assoc table there is an entry for the given node with a target_node_id of an existing node.

[waschbecken]

Unfortunately I can not get rid off these indexrebuilt exception.

Is it a good way to remove this entry from the database? (means deleting from the following tables: node, child_assoc, node_properties, node_status)  :?:

[derek]

Hi, waschbecken

I've answered your identical question in the standalone post.

[arautenberg]

Hi Derk….would be great to get the hint too 😉