Details

    • Type: Bug Bug
    • Status: Open
    • Priority: Major Major
    • Resolution: Unresolved
    • Affects Version/s: 2.9.1
    • Fix Version/s: None
    • Component/s: core/index
    • Labels:
      None
    • Environment:

      Windows

    • Lucene Fields:
      New

      Description

      Hi,
      We use lucene 2.9.1 version.
      We see the following OutOfMemory error in our environment, I think This is happening at a significant high load. Have you observed this anytime? Please let me know your thoughts on this.

      org.apache.lucene.index.MergePolicy$MergeException: java.lang.OutOfMemoryError: PermGen space
      at org.apache.lucene.index.ConcurrentMergeScheduler.handleMergeException(ConcurrentMergeScheduler.java:351)
      at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:315)
      Caused by: java.lang.OutOfMemoryError: PermGen space
      at java.lang.String.$$YJP$$intern(Native Method)
      at java.lang.String.intern(Unknown Source)
      at org.apache.lucene.util.SimpleStringInterner.intern(SimpleStringInterner.java:74)
      at org.apache.lucene.util.StringHelper.intern(StringHelper.java:36)
      at org.apache.lucene.index.FieldInfos.read(FieldInfos.java:356)
      at org.apache.lucene.index.FieldInfos.<init>(FieldInfos.java:71)
      at org.apache.lucene.index.SegmentReader$CoreReaders.<init>(SegmentReader.java:116)
      at org.apache.lucene.index.SegmentReader.get(SegmentReader.java:638)
      at org.apache.lucene.index.SegmentReader.get(SegmentReader.java:608)
      at org.apache.lucene.index.IndexWriter$ReaderPool.get(IndexWriter.java:686)
      at org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4979)
      at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:4614)
      at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:235)
      at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:291)

        Activity

        Hide
        Shivender Devarakonda added a comment -

        I did not see any infostream output when it had gone OOM. I see the same exception trace that I posted above. Do you think I missed anything?

        Show
        Shivender Devarakonda added a comment - I did not see any infostream output when it had gone OOM. I see the same exception trace that I posted above. Do you think I missed anything?
        Hide
        Michael McCandless added a comment -

        Hmm but the above infoStream output shows no exception... I'm confused.

        Show
        Michael McCandless added a comment - Hmm but the above infoStream output shows no exception... I'm confused.
        Hide
        Shivender Devarakonda added a comment -

        Yes I set infostream on all writers.

        Show
        Shivender Devarakonda added a comment - Yes I set infostream on all writers.
        Hide
        Michael McCandless added a comment -

        Hmm are you sure you're setting infoStream on all writers you create? The above output just shows an IW that was opened, not used for anything (no deletions, additions), and then closed.

        And eg the OOME in the opening here during a merge should result in some details being posted to the infoStream.

        Show
        Michael McCandless added a comment - Hmm are you sure you're setting infoStream on all writers you create? The above output just shows an IW that was opened, not used for anything (no deletions, additions), and then closed. And eg the OOME in the opening here during a merge should result in some details being posted to the infoStream.
        Hide
        Shivender Devarakonda added a comment -

        I saw the following infostream ouptut when I started our product but after that there was no infostream output and I saw the same OOM error again. Did I miss anything?

        IFD [main]: setInfoStream deletionPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy@1cbf655
        IW 0 [main]: setInfoStream: dir=org.apache.lucene.store.SimpleFSDirectory@C:\Program Files (x86)\CA Wily\Introscope9.0d595\traces\index autoCommit=false mergePolicy=org.apache.lucene.index.LogByteSizeMergePolicy@1996d53 mergeScheduler=org.apache.lucene.index.ConcurrentMergeScheduler@1d882b6 ramBufferSizeMB=16.0 maxBufferedDocs=-1 maxBuffereDeleteTerms=-1 maxFieldLength=10000 index=_2r5:c16187 _570:c40197 _7mt:c41371 _9yq:c42466 _cml:c45324 _fgk:c46186 _i63:c45931 _kz8:c46568 _ntr:c47071 _qiq:c46080 _qin:c18 _qip:c1 _qir:c4 _qit:c19 _qiv:c1 _qix:c51 _qiz:c2
        IW 0 [main]: now flush at close
        IW 0 [main]: flush: segment=null docStoreSegment=null docStoreOffset=0 flushDocs=false flushDeletes=true flushDocStores=false numDocs=0 numBufDelTerms=0
        IW 0 [main]: index before flush _2r5:c16187 _570:c40197 _7mt:c41371 _9yq:c42466 _cml:c45324 _fgk:c46186 _i63:c45931 _kz8:c46568 _ntr:c47071 _qiq:c46080 _qin:c18 _qip:c1 _qir:c4 _qit:c19 _qiv:c1 _qix:c51 _qiz:c2
        IW 0 [main]: CMS: now merge
        IW 0 [main]: CMS: index: _2r5:c16187 _570:c40197 _7mt:c41371 _9yq:c42466 _cml:c45324 _fgk:c46186 _i63:c45931 _kz8:c46568 _ntr:c47071 _qiq:c46080 _qin:c18 _qip:c1 _qir:c4 _qit:c19 _qiv:c1 _qix:c51 _qiz:c2
        IW 0 [main]: CMS: no more merges pending; now return
        IW 0 [main]: now call final commit()
        IW 0 [main]: startCommit(): start sizeInBytes=0
        IW 0 [main]: skip startCommit(): no changes pending
        IW 0 [main]: commit: pendingCommit == null; skip
        IW 0 [main]: commit: done
        IW 0 [main]: at close: _2r5:c16187 _570:c40197 _7mt:c41371 _9yq:c42466 _cml:c45324 _fgk:c46186 _i63:c45931 _kz8:c46568 _ntr:c47071 _qiq:c46080 _qin:c18 _qip:c1 _qir:c4 _qit:c19 _qiv:c1 _qix:c51 _qiz:c2

        Show
        Shivender Devarakonda added a comment - I saw the following infostream ouptut when I started our product but after that there was no infostream output and I saw the same OOM error again. Did I miss anything? IFD [main] : setInfoStream deletionPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy@1cbf655 IW 0 [main] : setInfoStream: dir=org.apache.lucene.store.SimpleFSDirectory@C:\Program Files (x86)\CA Wily\Introscope9.0d595\traces\index autoCommit=false mergePolicy=org.apache.lucene.index.LogByteSizeMergePolicy@1996d53 mergeScheduler=org.apache.lucene.index.ConcurrentMergeScheduler@1d882b6 ramBufferSizeMB=16.0 maxBufferedDocs=-1 maxBuffereDeleteTerms=-1 maxFieldLength=10000 index=_2r5:c16187 _570:c40197 _7mt:c41371 _9yq:c42466 _cml:c45324 _fgk:c46186 _i63:c45931 _kz8:c46568 _ntr:c47071 _qiq:c46080 _qin:c18 _qip:c1 _qir:c4 _qit:c19 _qiv:c1 _qix:c51 _qiz:c2 IW 0 [main] : now flush at close IW 0 [main] : flush: segment=null docStoreSegment=null docStoreOffset=0 flushDocs=false flushDeletes=true flushDocStores=false numDocs=0 numBufDelTerms=0 IW 0 [main] : index before flush _2r5:c16187 _570:c40197 _7mt:c41371 _9yq:c42466 _cml:c45324 _fgk:c46186 _i63:c45931 _kz8:c46568 _ntr:c47071 _qiq:c46080 _qin:c18 _qip:c1 _qir:c4 _qit:c19 _qiv:c1 _qix:c51 _qiz:c2 IW 0 [main] : CMS: now merge IW 0 [main] : CMS: index: _2r5:c16187 _570:c40197 _7mt:c41371 _9yq:c42466 _cml:c45324 _fgk:c46186 _i63:c45931 _kz8:c46568 _ntr:c47071 _qiq:c46080 _qin:c18 _qip:c1 _qir:c4 _qit:c19 _qiv:c1 _qix:c51 _qiz:c2 IW 0 [main] : CMS: no more merges pending; now return IW 0 [main] : now call final commit() IW 0 [main] : startCommit(): start sizeInBytes=0 IW 0 [main] : skip startCommit(): no changes pending IW 0 [main] : commit: pendingCommit == null; skip IW 0 [main] : commit: done IW 0 [main] : at close: _2r5:c16187 _570:c40197 _7mt:c41371 _9yq:c42466 _cml:c45324 _fgk:c46186 _i63:c45931 _kz8:c46568 _ntr:c47071 _qiq:c46080 _qin:c18 _qip:c1 _qir:c4 _qit:c19 _qiv:c1 _qix:c51 _qiz:c2
        Hide
        Shivender Devarakonda added a comment -

        1 - Yes it is 100.

        2 - I am not sure on this statement, I need to reachout to the original author of this code, will update you once I get a reply from the author. Do you think it will caues any issue?

        3- We had some OOM issues realted to SUNJVM issue that is where we have used this call.

        4- This issue is not always reproducible, I will post the infostream output once I get it reproduced again.

        Show
        Shivender Devarakonda added a comment - 1 - Yes it is 100. 2 - I am not sure on this statement, I need to reachout to the original author of this code, will update you once I get a reply from the author. Do you think it will caues any issue? 3- We had some OOM issues realted to SUNJVM issue that is where we have used this call. 4- This issue is not always reproducible, I will post the infostream output once I get it reproduced again.
        Hide
        Michael McCandless added a comment -

        OK, thanks. Is batchSize always 100?

        Why are you using NoLockFactory? That's generally very dangerous.

        Also, why do you call FSDir's setReadChunkSizeMB?

        Can you post the infoStream output?

        Show
        Michael McCandless added a comment - OK, thanks. Is batchSize always 100? Why are you using NoLockFactory? That's generally very dangerous. Also, why do you call FSDir's setReadChunkSizeMB? Can you post the infoStream output?
        Hide
        Shivender Devarakonda added a comment - - edited

        Thanks for helping us on this.

        We create a Daemon Thread that does the index updating functionality.

        1- Create a IndexDir like this:
        fDirectoryName = new File(tracesDir, relativeIndexDir);
        fIndexDir = FSDirectory.open(fDirectoryName, NoLockFactory.getNoLockFactory());

        fIndexDir.setReadChunkSize(8192);

        2- The Index inserter thread does the following functionality, The new writer is invoked for a batch size of 100.

        IndexWriter writer = null;

        try

        { writer = new IndexWriter(fIndexDir, this.getAnalyzer(), !this.indexExists(), IndexWriter.MaxFieldLength.LIMITED); writer.setMaxBufferedDocs(batchSize); writer.addDocument(doc); // while we're open and there's more in the queue, add more numInserted += addMore(writer, luceneQueue, batchSize); }

        finally

        { Utils.close(writer); insertionTime = MasterClock.currentTimeMillis() - startTime; }

        We do not set any RAMBufferSize in this case.

        Please let me know if you need anything on this.

        Show
        Shivender Devarakonda added a comment - - edited Thanks for helping us on this. We create a Daemon Thread that does the index updating functionality. 1- Create a IndexDir like this: fDirectoryName = new File(tracesDir, relativeIndexDir); fIndexDir = FSDirectory.open(fDirectoryName, NoLockFactory.getNoLockFactory()); fIndexDir.setReadChunkSize(8192); 2- The Index inserter thread does the following functionality, The new writer is invoked for a batch size of 100. IndexWriter writer = null; try { writer = new IndexWriter(fIndexDir, this.getAnalyzer(), !this.indexExists(), IndexWriter.MaxFieldLength.LIMITED); writer.setMaxBufferedDocs(batchSize); writer.addDocument(doc); // while we're open and there's more in the queue, add more numInserted += addMore(writer, luceneQueue, batchSize); } finally { Utils.close(writer); insertionTime = MasterClock.currentTimeMillis() - startTime; } We do not set any RAMBufferSize in this case. Please let me know if you need anything on this.
        Hide
        Michael McCandless added a comment -

        Can you share some details on how you're using Lucene? What's IndexWriters ramBufferSizeMB? How much heap are you giving the JVM? Are you calling commit (or closing/opening a new IndexWriter) frequently or rarely?

        Can you enable IndexWriter's infoStream and post the output?

        Show
        Michael McCandless added a comment - Can you share some details on how you're using Lucene? What's IndexWriters ramBufferSizeMB? How much heap are you giving the JVM? Are you calling commit (or closing/opening a new IndexWriter) frequently or rarely? Can you enable IndexWriter's infoStream and post the output?
        Hide
        Shivender Devarakonda added a comment -

        The stack trace is the same in other cases too. Basically, We have load that continuously pushes specific objects and we index each incoming object. . If we do not put that load then it is working fine.

        Show
        Shivender Devarakonda added a comment - The stack trace is the same in other cases too. Basically, We have load that continuously pushes specific objects and we index each incoming object. . If we do not put that load then it is working fine.
        Hide
        Earwin Burrfoot added a comment -

        20 is absolutely ok. Does exception always have this stacktrace? Maybe someone else litters in PermGen?

        Show
        Earwin Burrfoot added a comment - 20 is absolutely ok. Does exception always have this stacktrace? Maybe someone else litters in PermGen?
        Hide
        Shivender Devarakonda added a comment - - edited

        I am sure we have less than 20 fields in the document. Do you think it still causes this issue?

        Show
        Shivender Devarakonda added a comment - - edited I am sure we have less than 20 fields in the document. Do you think it still causes this issue?
        Hide
        Earwin Burrfoot added a comment -

        Basically, my bet is you're using a truckload of unique field names. Lucene interns them for speed, as it does quite a lot of field name comparisons, and the whole thing explodes.
        Unless you fill up your PermGen in some other manner, and Lucene just happens to hit the consequences.

        The strange thing is - last time I tested String.intern(), it failed to cause OOMs being bombarded by random strings, like it did in java 1.4.something.

        Show
        Earwin Burrfoot added a comment - Basically, my bet is you're using a truckload of unique field names. Lucene interns them for speed, as it does quite a lot of field name comparisons, and the whole thing explodes. Unless you fill up your PermGen in some other manner, and Lucene just happens to hit the consequences. The strange thing is - last time I tested String.intern(), it failed to cause OOMs being bombarded by random strings, like it did in java 1.4.something.
        Hide
        Shivender Devarakonda added a comment -

        java 6 update 18. Yes it happens without the profiler also.

        Thanks

        Show
        Shivender Devarakonda added a comment - java 6 update 18. Yes it happens without the profiler also. Thanks
        Hide
        Earwin Burrfoot added a comment -

        Also, are you running under profiler? Does that happen without it?

        Show
        Earwin Burrfoot added a comment - Also, are you running under profiler? Does that happen without it?
        Hide
        Earwin Burrfoot added a comment -

        Which JVM is that?

        Show
        Earwin Burrfoot added a comment - Which JVM is that?

          People

          • Assignee:
            Unassigned
            Reporter:
            Shivender Devarakonda
          • Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

            Dates

            • Created:
              Updated:

              Development