You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@lucene.apache.org by "DaveCTurner (via GitHub)" <gi...@apache.org> on 2024/05/09 10:31:31 UTC
[I] Merges sometimes do lots of work even after being aborted [lucene]
DaveCTurner opened a new issue, #13354:
URL: https://github.com/apache/lucene/issues/13354
### Description
We see some Lucene indices taking many seconds (occasionally minutes) to abort merges during rollback, doing a lot of now-pointless IO, with the merge thread spending all its time within a call to one of the various `checkIntegrity` methods that reads a file from beginning to end. For instance:
```
⋮
app/org.apache.lucene.core@9.10.0/org.apache.lucene.store.BufferedChecksumIndexInput.readBytes(BufferedChecksumIndexInput.java:46)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.store.DataInput.readBytes(DataInput.java:73)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.store.ChecksumIndexInput.skipByReading(ChecksumIndexInput.java:79)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.store.ChecksumIndexInput.seek(ChecksumIndexInput.java:64)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.codecs.CodecUtil.checksumEntireFile(CodecUtil.java:619)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.codecs.lucene90.compressing.Lucene90CompressingStoredFieldsReader.checkIntegrity(Lucene90CompressingStoredFieldsReader.java:725)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.codecs.lucene90.compressing.Lucene90CompressingStoredFieldsWriter.merge(Lucene90CompressingStoredFieldsWriter.java:609)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.index.SegmentMerger.mergeFields(SegmentMerger.java:234)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.index.SegmentMerger$$Lambda/0x00000080029f0c00.merge(Unknown Source)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.index.SegmentMerger.mergeWithLogging(SegmentMerger.java:273)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:110)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:5252)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:4740)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.index.IndexWriter$IndexWriterMergeSource.merge(IndexWriter.java:6541)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:639)
app/org.elasticsearch.server@8.15.0/org.elasticsearch.index.engine.ElasticsearchConcurrentMergeScheduler.doMerge(ElasticsearchConcurrentMergeScheduler.java:118)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:700)
```
Also here, although this is using a `org.elasticsearch.index.codec.postings.ES812PostingsReader` it doesn't look to be doing anything different from `org.elasticsearch.xpack.lucene.bwc.codecs.lucene50.Lucene50PostingsReader#checkIntegrity`:
```
⋮
app/org.apache.lucene.core@9.10.0/org.apache.lucene.store.BufferedChecksumIndexInput.readBytes(BufferedChecksumIndexInput.java:46)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.store.DataInput.readBytes(DataInput.java:73)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.store.ChecksumIndexInput.skipByReading(ChecksumIndexInput.java:79)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.store.ChecksumIndexInput.seek(ChecksumIndexInput.java:64)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.codecs.CodecUtil.checksumEntireFile(CodecUtil.java:619)
app/org.elasticsearch.server@8.15.0/org.elasticsearch.index.codec.postings.ES812PostingsReader.checkIntegrity(ES812PostingsReader.java:1975)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.codecs.lucene90.blocktree.Lucene90BlockTreeTermsReader.checkIntegrity(Lucene90BlockTreeTermsReader.java:338)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.codecs.perfield.PerFieldPostingsFormat$FieldsReader.checkIntegrity(PerFieldPostingsFormat.java:370)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.codecs.perfield.PerFieldMergeState$FilterFieldsProducer.checkIntegrity(PerFieldMergeState.java:296)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.codecs.FieldsConsumer.merge(FieldsConsumer.java:83)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.codecs.perfield.PerFieldPostingsFormat$FieldsWriter.merge(PerFieldPostingsFormat.java:205)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.index.SegmentMerger.mergeTerms(SegmentMerger.java:209)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.index.SegmentMerger$$Lambda/0x0000007802b71ab8.merge(Unknown Source)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.index.SegmentMerger.mergeWithLogging(SegmentMerger.java:298)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:137)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:5252)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:4740)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.index.IndexWriter$IndexWriterMergeSource.merge(IndexWriter.java:6541)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:639)
app/org.elasticsearch.server@8.15.0/org.elasticsearch.index.engine.ElasticsearchConcurrentMergeScheduler.doMerge(ElasticsearchConcurrentMergeScheduler.java:118)
app/org.apache.lucene.core@9.10.0/org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:700)
```
The data in these cases is in rather cold storage so we would expect it to take quite some time (possibly minutes) to complete this end-to-end read. That's ok, we don't need such merges to complete especially quickly, but it is rather troublesome that it takes so long to react to the abort signal in these situations. Is there something we can do to abort this read more promptly? For instance, could we add an abort-sensitive wrapper to the `DataInput` that's reading the data?
### Version and environment details
Lucene 9.10 embedded in Elasticsearch (here the `main` branch, currently targetting `8.15.0-SNAPSHOT`) but this behaviour does not seem to be at all new.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: issues-unsubscribe@lucene.apache.org.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: issues-unsubscribe@lucene.apache.org
For additional commands, e-mail: issues-help@lucene.apache.org
Re: [I] Merges sometimes do lots of work even after being aborted [lucene]
Posted by "rmuir (via GitHub)" <gi...@apache.org>.
rmuir closed issue #13354: Merges sometimes do lots of work even after being aborted
URL: https://github.com/apache/lucene/issues/13354
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: issues-unsubscribe@lucene.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: issues-unsubscribe@lucene.apache.org
For additional commands, e-mail: issues-help@lucene.apache.org
Re: [I] Merges sometimes do lots of work even after being aborted [lucene]
Posted by "romseygeek (via GitHub)" <gi...@apache.org>.
romseygeek commented on issue #13354:
URL: https://github.com/apache/lucene/issues/13354#issuecomment-4496304423
IIUC merge abort is currently implemented via RateLimiters, and only applies to the write side eg IndexOutput, but the issues we are seeing are in the read side in checkIntegrity. So maybe we need to build a RateLimitedIndexInput and add that to the FilterDirectory in ConcurrentMergeScheduler?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: issues-unsubscribe@lucene.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: issues-unsubscribe@lucene.apache.org
For additional commands, e-mail: issues-help@lucene.apache.org
Re: [I] Merges sometimes do lots of work even after being aborted [lucene]
Posted by "DaveCTurner (via GitHub)" <gi...@apache.org>.
DaveCTurner commented on issue #13354:
URL: https://github.com/apache/lucene/issues/13354#issuecomment-4490313048
> How large are your files? Did you alter Lucene's default (5 GB) max merged segment size?
I don't think so in this case, tho it's been a couple of years so I don't have access to the details any more. It would have been coming from something like S3 via a sequence of `GetObject` calls which does occasionally have a bit of a wobble manifesting as some very high latency reads.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: issues-unsubscribe@lucene.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: issues-unsubscribe@lucene.apache.org
For additional commands, e-mail: issues-help@lucene.apache.org
Re: [I] Merges sometimes do lots of work even after being aborted [lucene]
Posted by "mikemccand (via GitHub)" <gi...@apache.org>.
mikemccand commented on issue #13354:
URL: https://github.com/apache/lucene/issues/13354#issuecomment-4490633871
Maybe we could dream up a `Monster`/`Nightly` unit test that randomly gets big merges going (index from `LineFileDocs` -- nightly get a a biggish corpus), then randomly `IW.rollback()`, then counts how many nanoseconds / bytes (`LongAdder` tracking how many bytes the various threads are writing in total) it took before `rollback()` finished. It's sort of like measuring stopping distance for a race car going 300 kph. Not sure how the test could binarize (pass/fail) that reliably but we could start with that test and run it for a long time and see if there are surprises...
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: issues-unsubscribe@lucene.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: issues-unsubscribe@lucene.apache.org
For additional commands, e-mail: issues-help@lucene.apache.org
Re: [I] Merges sometimes do lots of work even after being aborted [lucene]
Posted by "mikemccand (via GitHub)" <gi...@apache.org>.
mikemccand commented on issue #13354:
URL: https://github.com/apache/lucene/issues/13354#issuecomment-4490115342
Minutes is surprising, especially if it's `checkIntegrity` taking that long. How large are your files? Did you alter Lucene's default (5 GB) max merged segment size?
We should clearly fix this -- looks like that's in progress at #16086.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: issues-unsubscribe@lucene.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: issues-unsubscribe@lucene.apache.org
For additional commands, e-mail: issues-help@lucene.apache.org