lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Anshum Gupta <ans...@anshumgupta.net>
Subject Re: Understanding performance degradation in range queries between Solr 5.2.1 and 4.10.4
Date Tue, 04 Aug 2015 01:07:45 GMT
Guess bypassing that check and always returning true instead would help
confirm that. If that's the case, we should just initialize the timeout to
Long.MAX_VALUE and check for that to short-circuit?

On Mon, Aug 3, 2015 at 3:50 PM, Tomás Fernández Löbbe <tomasflobbe@gmail.com
> wrote:

> Yes, I saw that, but thought it could be the underlying implementation,
> not the "ExitableTermsEnum" wrapper. Maybe it's related to the calls to
> System.nanoTime then...
>
> On Mon, Aug 3, 2015 at 3:11 PM, Adrien Grand <jpountz@gmail.com> wrote:
>
>> Thanks for sharing the traces, it looks like my intuition was wrong.
>> :) They seem to point to
>> ExitableDirectoryReader$ExitableTermsEnum.next, which checks whether
>> the time is out before delegating.
>>
>> On Mon, Aug 3, 2015 at 7:21 PM, Tomás Fernández Löbbe
>> <tomasflobbe@gmail.com> wrote:
>> > Thanks Adrien,
>> > I'll run the tests with 5.3 snapshot and post the results here. In case
>> this
>> > helps, this is the hprof samples output
>> > (-Xrunhprof:cpu=samples,depth=3,file=/home/ec2-user/hprof_output.txt)
>> for
>> > 4.10.4 and 5.2.1 in my test:
>> >
>> > Solr 4.10.4:
>> > CPU SAMPLES BEGIN (total = 243525) Fri Jul 31 22:29:06 2015
>> > rank   self  accum   count trace method
>> >    1 75.07% 75.07%  182812 300523 java.net.PlainSocketImpl.socketAccept
>> >    2  4.27% 79.34%   10408 301576
>> > org.apache.lucene.codecs.blocktree.SegmentTermsEnumFrame.decodeMetaData
>> >    3  4.15% 83.49%   10108 301585
>> > org.apache.lucene.index.FilteredTermsEnum.docs
>> >    4  3.46% 86.95%    8419 301582
>> > org.apache.lucene.index.FilteredTermsEnum.next
>> >    5  2.49% 89.44%    6070 301573 java.net.SocketInputStream.socketRead0
>> >    6  1.99% 91.43%    4848 301599
>> > org.apache.lucene.search.MultiTermQueryWrapperFilter.getDocIdSet
>> >    7  1.98% 93.42%    4824 301583
>> > org.apache.lucene.search.MultiTermQueryWrapperFilter.getDocIdSet
>> >    8  1.57% 94.99%    3824 301589
>> > org.apache.lucene.search.Weight$DefaultBulkScorer.scoreAll
>> >    9  1.44% 96.42%    3504 301594
>> >
>> org.apache.lucene.codecs.lucene41.Lucene41PostingsReader$BlockDocsEnum.refillDocs
>> >   10  1.09% 97.51%    2655 301581 java.nio.Bits.copyToArray
>> >   11  0.98% 98.50%    2388 301598
>> >
>> org.apache.lucene.codecs.lucene41.Lucene41PostingsReader$BlockDocsEnum.nextDoc
>> >   12  0.62% 99.12%    1522 301600
>> org.apache.lucene.store.DataInput.readVInt
>> >   13  0.21% 99.33%     500 301612
>> > org.apache.lucene.codecs.blocktree.SegmentTermsEnum.docs
>> >   14  0.07% 99.39%     167 301601
>> > org.apache.lucene.codecs.blocktree.SegmentTermsEnumFrame.next
>> >   15  0.06% 99.45%     139 301619 java.lang.System.identityHashCode
>> >   16  0.05% 99.50%     114 301632
>> > org.apache.lucene.codecs.lucene41.ForUtil.readBlock
>> >   17  0.04% 99.54%      92 300708 java.util.zip.Inflater.inflateBytes
>> >   18  0.03% 99.57%      76 301624
>> >
>> org.apache.lucene.codecs.blocktree.SegmentTermsEnumFrame.loadNextFloorBlock
>> >   19  0.03% 99.59%      68 300613 java.lang.ClassLoader.defineClass1
>> >   20  0.03% 99.62%      68 301615
>> > org.apache.lucene.codecs.blocktree.SegmentTermsEnum.next
>> >   21  0.03% 99.65%      62 301635
>> > org.apache.solr.search.SolrIndexSearcher.getDocSetNC
>> >   22  0.02% 99.66%      41 301664
>> > org.apache.lucene.codecs.blocktree.SegmentTermsEnum.next
>> >   23  0.01% 99.68%      31 301629
>> org.apache.lucene.util.FixedBitSet.<init>
>> > CPU SAMPLES END
>> >
>> > Solr 5.2.1:
>> > CPU SAMPLES BEGIN (total = 235415) Fri Jul 31 22:42:06 2015
>> > rank   self  accum   count trace method
>> >    1 51.38% 51.38%  120954 301291 sun.nio.ch.EPollArrayWrapper.epollWait
>> >    2 25.69% 77.07%   60477 301292
>> sun.nio.ch.ServerSocketChannelImpl.accept0
>> >    3 10.59% 87.66%   24923 301369
>> > org.apache.lucene.index.ExitableDirectoryReader$ExitableTermsEnum.next
>> >    4  2.20% 89.86%    5182 301414
>> > org.apache.lucene.codecs.blocktree.SegmentTermsEnum.postings
>> >    5  2.01% 91.87%    4742 301384
>> > org.apache.lucene.index.FilterLeafReader$FilterTermsEnum.postings
>> >    6  1.25% 93.12%    2944 301434
>> > java.lang.ThreadLocal$ThreadLocalMap.getEntryAfterMiss
>> >    7  1.11% 94.23%    2612 301367
>> > org.apache.lucene.search.MultiTermQueryConstantScoreWrapper$1.rewrite
>> >    8  0.94% 95.17%    2204 301390 org.apache.lucene.util.BitSet.or
>> >    9  0.93% 96.10%    2190 301383 java.nio.Bits.copyToArray
>> >   10  0.78% 96.87%    1825 301449
>> >
>> org.apache.lucene.codecs.lucene50.Lucene50PostingsReader$BlockDocsEnum.refillDocs
>> >   11  0.73% 97.60%    1717 301378
>> > org.apache.lucene.search.Weight$DefaultBulkScorer.scoreAll
>> >   12  0.73% 98.33%    1715 301374 org.apache.lucene.util.BitSet.or
>> >   13  0.33% 98.66%     787 301387
>> >
>> org.apache.lucene.codecs.lucene50.Lucene50PostingsReader$BlockDocsEnum.nextDoc
>> >   14  0.16% 98.82%     374 301426
>> >
>> org.apache.lucene.codecs.lucene50.Lucene50PostingsReader$BlockDocsEnum.nextDoc
>> >   15  0.10% 98.93%     245 301382 org.apache.lucene.util.BitSet.or
>> >   16  0.09% 99.02%     219 301381
>> > org.apache.lucene.codecs.blocktree.SegmentTermsEnumFrame.next
>> >   17  0.09% 99.11%     207 301370 org.apache.lucene.util.BitSet.or
>> >   18  0.06% 99.17%     153 301416 org.apache.lucene.util.BitSet.or
>> >   19  0.06% 99.24%     151 301427 org.apache.lucene.util.BitSet.or
>> >   20  0.06% 99.30%     151 301441
>> org.apache.lucene.store.DataInput.readVInt
>> >   21  0.06% 99.36%     147 301389 java.lang.System.identityHashCode
>> >   22  0.06% 99.42%     140 301375
>> > org.apache.lucene.codecs.blocktree.SegmentTermsEnum.next
>> >   23  0.04% 99.47%     104 301425 org.apache.lucene.util.BitSet.or
>> >   24  0.03% 99.50%      76 301423
>> >
>> org.apache.lucene.codecs.lucene50.Lucene50PostingsReader$BlockDocsEnum.nextDoc
>> >   25  0.03% 99.53%      74 301454
>> > org.apache.lucene.search.MultiTermQueryConstantScoreWrapper$1.rewrite
>> >   26  0.03% 99.56%      65 301432
>> > org.apache.lucene.util.BitDocIdSet$Builder.or
>> >   27  0.02% 99.58%      53 301456 org.apache.lucene.util.FixedBitSet.or
>> >   28  0.02% 99.60%      52 300077 java.lang.ClassLoader.defineClass1
>> >   29  0.02% 99.63%      50 301464
>> > org.apache.lucene.codecs.lucene50.ForUtil.readBlock
>> >   30  0.02% 99.64%      39 301438
>> > org.apache.lucene.codecs.blocktree.SegmentTermsEnum.next
>> >   31  0.02% 99.66%      37 301465
>> >
>> org.apache.lucene.codecs.blocktree.SegmentTermsEnumFrame.loadNextFloorBlock
>> >   32  0.02% 99.67%      36 301419
>> >
>> org.apache.lucene.codecs.lucene50.Lucene50PostingsReader$BlockDocsEnum.nextDoc
>> > CPU SAMPLES END
>> >
>> > On Fri, Jul 31, 2015 at 4:23 PM, Adrien Grand <jpountz@gmail.com>
>> wrote:
>> >>
>> >> Hi Tomás,
>> >>
>> >> I suspect this might be related to LUCENE-5938. We changed the default
>> >> rewrite method for multi-term queries to load documents into a sparse
>> >> bit set first first, and only upgrade to a dense bit set when we know
>> >> many documents match. When there are lots of terms to intersect, then
>> >> we end up spending significant cpu time to build the sparse bit set to
>> >> eventually upgrade to a dense bit set like before. This might be what
>> >> you are seeing.
>> >>
>> >> You might see the issue less with the population field because it has
>> >> fewer unique values, so postings lists are longer and the DocIdSet
>> >> building logic can upgrade quicker to a dense bit set.
>> >>
>> >> Mike noticed this slowness when working on BDK trees and we changed
>> >> this first phase to use a plain int[] array that we sort and
>> >> deduplicate instead of a more fancy sparse bit set (LUCENE-6645),
>> >> which seemed to make things faster. Would it be possible for you to
>> >> also check a 5.3 snapshot?
>> >>
>> >>
>> >>
>> >>
>> >> On Fri, Jul 31, 2015 at 10:51 PM, Tomás Fernández Löbbe
>> >> <tomasflobbe@gmail.com> wrote:
>> >> > Hi, I'm seeing some query performance degradation between 4.10.4 and
>> >> > 5.2.1.
>> >> > It doesn't happen with all the queries, but for queries like range
>> >> > queries
>> >> > on fields with many different values the average time in 5.2.1 is
>> worse
>> >> > than
>> >> > in 4.10.4. Is anyone seeing something similar?
>> >> >
>> >> > Test Details:
>> >> > * Single thread running queries continuously. I run the test twice
>> for
>> >> > each
>> >> > Solr version.
>> >> > * JMeter running on my laptop, Solr running on EC2, on an m3.xlarge
>> >> > instance
>> >> > with all the defaults but with 5G heap. Index in local disk (SSD)
>> >> > * Plain Solr releases, nothing custom. Single Solr core, not in
>> >> > SolrCloud
>> >> > mode, no distributed search.
>> >> > * "allCountries" geonames dataset (~8M small docs). No updates during
>> >> > the
>> >> > test. Index Size is around 1.1GB for Solr 5.2.1 and 1.3GB for Solr
>> >> > 4.10.4
>> >> > (fits entirely in RAM)
>> >> > * jdk1.8.0_45
>> >> >
>> >> > Queries: 3k boolean queries (generated with terms from the dataset)
>> with
>> >> > range queries as filters on "tlongitude" and "tlatitude" fields with
>> >> > randomly generated bounds, e.g.
>> >> > q=name:foo OR name:bar&fq=tlongitude:[W TO X]&fq=tlatitude:[Y
TO Z]
>> >> >
>> >> > Fields are:
>> >> > <field name="tlatitude" type="tdouble"/>
>> >> > <field name="tlongitude" type="tdouble"/>
>> >> > Field Type:
>> >> > <fieldType name="tdouble" class="solr.TrieDoubleField"
>> precisionStep="8"
>> >> > positionIncrementGap="0"/>
>> >> >
>> >> > In this case, Solr 4.10.4 was between 20% to 30% faster than 5.2.1
in
>> >> > average.
>> >> >
>> >> > http://snag.gy/2yPPM.jpg
>> >> >
>> >> > Doing only the boolean queries show no performance difference between
>> >> > 4.10
>> >> > and 5.2, same thing if I do filters on a string field instead of the
>> >> > range
>> >> > queries.
>> >> >
>> >> > When using "double" field type (precisionStep="0"), the difference
>> was
>> >> > bigger:
>> >> >
>> >> > longitude/latitude fields:
>> >> > <field name="longitude" type="double" docValues="true"/>
>> >> > <field name="latitude" type="double" docValues="true"/>
>> >> > <fieldType name="double" class="solr.TrieDoubleField"
>> precisionStep="0"
>> >> > positionIncrementGap="0"/>
>> >> >
>> >> > http://snag.gy/Vi5uk.jpg
>> >> > I understand this is not the best field type definition for range
>> >> > queries,
>> >> > I'm just trying to understand the difference between the two versions
>> >> > and
>> >> > why.
>> >> >
>> >> > Performance was OK when doing range queries on the "population" field
>> >> > (long), but that field doesn't have many different values, only 300k
>> out
>> >> > of
>> >> > the 8.3M docs have the population field with a value different to 0.
>> On
>> >> > the
>> >> > other hand, doing range queries on the _version_ field did show a
>> graph
>> >> > similar to the previous one:
>> >> >
>> >> > <field name="_version_" type="long" indexed="true" stored="true"/>
>> >> > <fieldType name="long" class="solr.TrieLongField" precisionStep="0"
>> >> > positionIncrementGap="0"/>
>> >> >
>> >> > http://snag.gy/4tc7e.jpg
>> >> >
>> >> > Any idea what could be causing this? Is this expected after some
>> known
>> >> > change?
>> >> >
>> >> > With Solr 4.10, a single CPU core remains high during the test
>> (close to
>> >> > 100%), but with Solr 5.2, different cores go up and down in
>> utilization
>> >> > continuously. That's probably because of the different Jetty version
>> I
>> >> > suppose.
>> >> > GC pattern looks similar in both. For both Solr versions I'm using
>> the
>> >> > settings that ship with Solr (in solr.in.sh) except for Xmx and Xms
>> >> >
>> >>
>> >>
>> >>
>> >> --
>> >> Adrien
>> >>
>> >> ---------------------------------------------------------------------
>> >> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
>> >> For additional commands, e-mail: dev-help@lucene.apache.org
>> >>
>> >
>>
>>
>>
>> --
>> Adrien
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
>> For additional commands, e-mail: dev-help@lucene.apache.org
>>
>>
>


-- 
Anshum Gupta

Mime
View raw message