lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Hoss Man (JIRA)" <j...@apache.org>
Subject [jira] Updated: (SOLR-1911) File descriptor leak while indexing, may cause index corruption
Date Sat, 15 May 2010 00:29:42 GMT

     [ https://issues.apache.org/jira/browse/SOLR-1911?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]

Hoss Man updated SOLR-1911:
---------------------------

    Description: 
While adding documents to an already existing index using this build, the number of open file
descriptors increases dramatically until the open file per-process limit is reached (1024)
, at which point there are error messages in the log to that effect. If the server is restarted
the index may be corrupt

commits are handled by autocommit every 60 seconds or 500 documents (usually the time limit
is reached first). 
mergeFactor is 10.

It looks as though each time a commit takes place, the number of open files  (obtained from
" lsof -p `cat solr.pid` | egrep ' [0-9]+r ' ") increases by 40, There are several open file
descriptors associated with each file in the index.

Rerunning the same index updates with an older Solr (built from trunk in Feb 2010) doesn't
show this problem - the number of open files fluctuates up and down as segments are created
and merged, but stays basically constant.


  was:
While adding documents to an already existing index using this build, the number of open file
descriptors increases dramatically until the open file per-process limit is reached (1024)
, at which point there are error messages in the log to that effect. If the server is restarted
the index may be corrupt

the solr log reports:

May 13, 2010 12:37:04 PM org.apache.solr.update.DirectUpdateHandler2 commit
INFO: start commit(optimize=false,waitFlush=true,waitSearcher=true,expungeDeletes=false)
May 13, 2010 12:37:04 PM org.apache.solr.update.DirectUpdateHandler2$CommitTracker run
SEVERE: auto commit error...
java.io.FileNotFoundException: /home/simon/rig2/solr/core1/data/index/_j2.nrm (Too many open
files)
	at java.io.RandomAccessFile.open(Native Method)
	at java.io.RandomAccessFile.<init>(RandomAccessFile.java:212)
	at org.apache.lucene.store.SimpleFSDirectory$SimpleFSIndexInput$Descriptor.<init>(SimpleFSDirectory.java:69)
	at org.apache.lucene.store.SimpleFSDirectory$SimpleFSIndexInput.<init>(SimpleFSDirectory.java:90)
	at org.apache.lucene.store.NIOFSDirectory$NIOFSIndexInput.<init>(NIOFSDirectory.java:80)
	at org.apache.lucene.store.NIOFSDirectory.openInput(NIOFSDirectory.java:67)
	at org.apache.lucene.index.SegmentReader.openNorms(SegmentReader.java:1093)
	at org.apache.lucene.index.SegmentReader.get(SegmentReader.java:532)
	at org.apache.lucene.index.IndexWriter$ReaderPool.get(IndexWriter.java:634)
	at org.apache.lucene.index.IndexWriter$ReaderPool.get(IndexWriter.java:610)
	at org.apache.lucene.index.DocumentsWriter.applyDeletes(DocumentsWriter.java:1012)
	at org.apache.lucene.index.IndexWriter.applyDeletes(IndexWriter.java:4563)
	at org.apache.lucene.index.IndexWriter.doFlushInternal(IndexWriter.java:3775)
	at org.apache.lucene.index.IndexWriter.doFlush(IndexWriter.java:3623)
	at org.apache.lucene.index.IndexWriter.flush(IndexWriter.java:3614)
	at org.apache.lucene.index.IndexWriter.closeInternal(IndexWriter.java:1769)
	at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:1732)
	at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:1696)
	at org.apache.solr.update.SolrIndexWriter.close(SolrIndexWriter.java:230)
	at org.apache.solr.update.DirectUpdateHandler2.closeWriter(DirectUpdateHandler2.java:181)
	at org.apache.solr.update.DirectUpdateHandler2.commit(DirectUpdateHandler2.java:409)
	at org.apache.solr.update.DirectUpdateHandler2$CommitTracker.run(DirectUpdateHandler2.java:602)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
	at java.util.concurrent.FutureTask.run(FutureTask.java:138)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:207)
	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:619)
May 13, 2010 12:37:04 PM org.apache.solr.update.processor.LogUpdateProcessor finish
INFO: {} 0 1
May 13, 2010 12:37:04 PM org.apache.solr.common.SolrException log
SEVERE: java.io.IOException: directory '/home/simon/rig2/solr/core1/data/index' exists and
is a directory, but cannot be listed: list() returned null
	at org.apache.lucene.store.FSDirectory.listAll(FSDirectory.java:223)
	at org.apache.lucene.store.FSDirectory.listAll(FSDirectory.java:234)
	at org.apache.lucene.index.SegmentInfos$FindSegmentsFile.run(SegmentInfos.java:582)
	at org.apache.lucene.index.SegmentInfos$FindSegmentsFile.run(SegmentInfos.java:535)
	at org.apache.lucene.index.SegmentInfos.read(SegmentInfos.java:316)
	at org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:1129)
	at org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:999)
	at org.apache.solr.update.SolrIndexWriter.<init>(SolrIndexWriter.java:191)
	at org.apache.solr.update.UpdateHandler.createMainIndexWriter(UpdateHandler.java:99)
	at org.apache.solr.update.DirectUpdateHandler2.openWriter(DirectUpdateHandler2.java:173)
	at org.apache.solr.update.DirectUpdateHandler2.addDoc(DirectUpdateHandler2.java:220)
	at org.apache.solr.update.processor.RunUpdateProcessor.processAdd(RunUpdateProcessorFactory.java:61)
	at org.apache.solr.handler.XMLLoader.processUpdate(XMLLoader.java:139)
	at org.apache.solr.handler.XMLLoader.load(XMLLoader.java:69)
	at org.apache.solr.handler.ContentStreamHandlerBase.handleRequestBody(ContentStreamHandlerBase.java:54)
	at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:131)
	at org.apache.solr.core.SolrCore.execute(SolrCore.java:1321)
	at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:341)
	at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:244)
	at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1089)
	at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:365)
	at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
	at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:181)
	at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:712)
	at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:405)
	at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:211)
	at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
	at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:139)
	at org.mortbay.jetty.Server.handle(Server.java:285)
	at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:502)
	at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:835)
	at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:641)
	at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:208)
	at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:378)
	at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:368)
	at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:442)


commits are handled by autocommit every 60 seconds or 500 documents (usually the time limit
is reached first). 
mergeFactor is 10.

It looks as though each time a commit takes place, the number of open files  (obtained from
" lsof -p `cat solr.pid` | egrep ' [0-9]+r ' ") increases by 40, There are several open file
descriptors associated with each file in the index.

Rerunning the same index updates with an older Solr (built from trunk in Feb 2010) doesn't
show this problem - the number of open files fluctuates up and down as segments are created
and merged, but stays basically constant.



Moving log dump out of problem description and into a comment...

{noformat}

May 13, 2010 12:37:04 PM org.apache.solr.update.DirectUpdateHandler2 commit
INFO: start commit(optimize=false,waitFlush=true,waitSearcher=true,expungeDeletes=false)
May 13, 2010 12:37:04 PM org.apache.solr.update.DirectUpdateHandler2$CommitTracker run
SEVERE: auto commit error...
java.io.FileNotFoundException: /home/simon/rig2/solr/core1/data/index/_j2.nrm (Too many open
files)
	at java.io.RandomAccessFile.open(Native Method)
	at java.io.RandomAccessFile.<init>(RandomAccessFile.java:212)
	at org.apache.lucene.store.SimpleFSDirectory$SimpleFSIndexInput$Descriptor.<init>(SimpleFSDirectory.java:69)
	at org.apache.lucene.store.SimpleFSDirectory$SimpleFSIndexInput.<init>(SimpleFSDirectory.java:90)
	at org.apache.lucene.store.NIOFSDirectory$NIOFSIndexInput.<init>(NIOFSDirectory.java:80)
	at org.apache.lucene.store.NIOFSDirectory.openInput(NIOFSDirectory.java:67)
	at org.apache.lucene.index.SegmentReader.openNorms(SegmentReader.java:1093)
	at org.apache.lucene.index.SegmentReader.get(SegmentReader.java:532)
	at org.apache.lucene.index.IndexWriter$ReaderPool.get(IndexWriter.java:634)
	at org.apache.lucene.index.IndexWriter$ReaderPool.get(IndexWriter.java:610)
	at org.apache.lucene.index.DocumentsWriter.applyDeletes(DocumentsWriter.java:1012)
	at org.apache.lucene.index.IndexWriter.applyDeletes(IndexWriter.java:4563)
	at org.apache.lucene.index.IndexWriter.doFlushInternal(IndexWriter.java:3775)
	at org.apache.lucene.index.IndexWriter.doFlush(IndexWriter.java:3623)
	at org.apache.lucene.index.IndexWriter.flush(IndexWriter.java:3614)
	at org.apache.lucene.index.IndexWriter.closeInternal(IndexWriter.java:1769)
	at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:1732)
	at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:1696)
	at org.apache.solr.update.SolrIndexWriter.close(SolrIndexWriter.java:230)
	at org.apache.solr.update.DirectUpdateHandler2.closeWriter(DirectUpdateHandler2.java:181)
	at org.apache.solr.update.DirectUpdateHandler2.commit(DirectUpdateHandler2.java:409)
	at org.apache.solr.update.DirectUpdateHandler2$CommitTracker.run(DirectUpdateHandler2.java:602)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
	at java.util.concurrent.FutureTask.run(FutureTask.java:138)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:207)
	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:619)
May 13, 2010 12:37:04 PM org.apache.solr.update.processor.LogUpdateProcessor finish
INFO: {} 0 1
May 13, 2010 12:37:04 PM org.apache.solr.common.SolrException log
SEVERE: java.io.IOException: directory '/home/simon/rig2/solr/core1/data/index' exists and
is a directory, but cannot be listed: list() returned null
	at org.apache.lucene.store.FSDirectory.listAll(FSDirectory.java:223)
	at org.apache.lucene.store.FSDirectory.listAll(FSDirectory.java:234)
	at org.apache.lucene.index.SegmentInfos$FindSegmentsFile.run(SegmentInfos.java:582)
	at org.apache.lucene.index.SegmentInfos$FindSegmentsFile.run(SegmentInfos.java:535)
	at org.apache.lucene.index.SegmentInfos.read(SegmentInfos.java:316)
	at org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:1129)
	at org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:999)
	at org.apache.solr.update.SolrIndexWriter.<init>(SolrIndexWriter.java:191)
	at org.apache.solr.update.UpdateHandler.createMainIndexWriter(UpdateHandler.java:99)
	at org.apache.solr.update.DirectUpdateHandler2.openWriter(DirectUpdateHandler2.java:173)
	at org.apache.solr.update.DirectUpdateHandler2.addDoc(DirectUpdateHandler2.java:220)
	at org.apache.solr.update.processor.RunUpdateProcessor.processAdd(RunUpdateProcessorFactory.java:61)
	at org.apache.solr.handler.XMLLoader.processUpdate(XMLLoader.java:139)
	at org.apache.solr.handler.XMLLoader.load(XMLLoader.java:69)
	at org.apache.solr.handler.ContentStreamHandlerBase.handleRequestBody(ContentStreamHandlerBase.java:54)
	at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:131)
	at org.apache.solr.core.SolrCore.execute(SolrCore.java:1321)
	at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:341)
	at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:244)
	at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1089)
	at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:365)
	at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
	at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:181)
	at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:712)
	at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:405)
	at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:211)
	at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
	at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:139)
	at org.mortbay.jetty.Server.handle(Server.java:285)
	at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:502)
	at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:835)
	at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:641)
	at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:208)
	at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:378)
	at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:368)
	at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:442)


{noformat}

> File descriptor leak while indexing, may cause index corruption
> ---------------------------------------------------------------
>
>                 Key: SOLR-1911
>                 URL: https://issues.apache.org/jira/browse/SOLR-1911
>             Project: Solr
>          Issue Type: Bug
>          Components: update
>    Affects Versions: 1.5
>         Environment:         Ubuntu Linux, Java build 1.6.0_16-b01
>         Solr Specification Version: 3.0.0.2010.05.12.16.17.46
> 	Solr Implementation Version: 4.0-dev exported - simon - 2010-05-12 16:17:46  -- bult
from updated trunk
> 	Lucene Specification Version: 4.0-dev
> 	Lucene Implementation Version: 4.0-dev exported - 2010-05-12 16:18:26
> 	Current Time: Thu May 13 12:21:12 EDT 2010
> 	Server Start Time:Thu May 13 11:45:41 EDT 2010
>            Reporter: Simon Rosenthal
>            Priority: Critical
>
> While adding documents to an already existing index using this build, the number of open
file descriptors increases dramatically until the open file per-process limit is reached (1024)
, at which point there are error messages in the log to that effect. If the server is restarted
the index may be corrupt
> commits are handled by autocommit every 60 seconds or 500 documents (usually the time
limit is reached first). 
> mergeFactor is 10.
> It looks as though each time a commit takes place, the number of open files  (obtained
from " lsof -p `cat solr.pid` | egrep ' [0-9]+r ' ") increases by 40, There are several open
file descriptors associated with each file in the index.
> Rerunning the same index updates with an older Solr (built from trunk in Feb 2010) doesn't
show this problem - the number of open files fluctuates up and down as segments are created
and merged, but stays basically constant.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org


Mime
View raw message