In my experience this should be very fast:
search(graph-october,
q="outs:tokenA",
fl="id,token",
sort="id asc",
qt="/export",
wt=javabin)
When the DocValues cache is statically warmed for the two output fields I
would see somewhere around 500,000 docs per second exported from a single
node.
You have sixteen shards which would give you 16 times the throughput. But
off course the data is being sent back through the single aggregator node
so your throughput is only as fast as the aggregator node can process the
results.
This does not explain the slowness that you are seeing. I see a couple of
possible reasons:
1) The memory on the system is not tuned optimally. You allocated a large
amount of memory to the heap and are not providing enough memory to OS
filesystem. Lucene DocValues use the OS filesystem cache for the DocValues
caches. So I would bump down the size of heap considerably.
2) Are you indexing while querying at all? If you are you would need to be
statically warming the DocValues caches for the id field which is used for
sorting. Following each commit there is a top level docvalues cache that is
rebuilt for sorting on string fields. If you use a static warming query it
will warm the cache before making the new searcher live for searchers. I
would also pause indexing if possible and run queries only to see how it
runs without indexing.
3) Try running a query directly to /export handler on each node. Possibly
one of your nodes is slow for some reason and that is causing the entire
query to respond slowly.
Joel Bernstein
http://joelsolr.blogspot.com/
On Thu, Nov 9, 2017 at 2:22 PM, Lanny Ripple <la...@spotright.com> wrote:
> Happy to do so. I am testing streams for the first time so we don't have
> any 5.x experience. The collection I'm testing was loaded after going to
> 6.6.1 and fixing up the solrconfig for lucene_version and removing the
> /export clause. The indexes run 57G per replica. We are using 64G hosts
> with 48G heaps using G1GC but this isn't our only large collection. This
> morning as I'm running these our cluster is quiet. I realize some of the
> performance we are seeing is going to be our data size so not expecting any
> silver bullets.
>
> We are storing 858M documents that are basically
>
> id: String
> token: String
> outs: String[]
> outsCount: Int
>
> All stored=true, docvalues=true.
>
> The `outs` reference a select number of tokens (1.26M). Here are current
> percentiles of our outsCount
>
> `outsCount`
> 50% 12
> 85% 127
> 98% 937
> 99.9% 16,284
>
> I'll display the /stream query but I'm setting up the same thing in solrj.
> I'm going to name our small result set "tokenA" and our large one "tokenV".
>
> search(graph-october,
> q="outs:tokenA",
> fl="id,token",
> sort="id asc",
> qt="/export",
> wt=javabin)
>
> I've placed this in file /tmp/expr and invoke with
>
> curl -sSN -m 3600 --data-urlencode expr@/tmp/expr
> http://host/solr/graph-october/stream
>
> The large resultset query replaces "tokenA" with "tokenV".
>
> My /select query is
>
> curl -sSN -m 3600 -d wt=csv -d rows=10000 -d q="outs:tokenA" -d
> fl="id,token" http://host/solr/graph-october/select
>
> So the behavior I'm seeing (times are with running the commands back to
> back)
>
> /select tokenA 0.296s
> /search tokenA 8.787s
> /search tokenA 8.513s
> /select tokenA 0.292s
>
> I was going to get some "tokenV" times here but curl is hitting "Truncated
> chunk" errors.
>
> I can pick a "tokenB" which hasn't been run but from the originating data I
> know has a resultset size of about 5800. Times are
>
> /search tokenB 11.486s
> /search tokenB 0.960s
> /select tokenB 2.534s
> /select tokenB 2.117s
> /search tokenB 1.208s
>
> So that's closer to the behavior I'd expect and desire. Back to "tokenA".
>
> /search tokenA 0.289s
> /search tokenA 0.249s
> /select tokenA 0.342s
> /select tokenA 0.329s
> /search tokenA 11.848s
>
> Here's "tokenV" out of a solrj couting job.
>
> _run1_
> Token tokenV has 3497203 outs.
> Time to first read: PT37.577S
> Runtime: PT1M43.822S
>
> _run2_
> Token tokenV has 3497203 outs.
> Time to first read: PT18.764S
> Runtime: PT1M16.655S
>
> So hmm. Given this I'd hazard there's nothing unexpected about /stream and
> the problem is the load on our cluster.
>
> So I thought I'd run "tokenA" though the count job.
>
> _run1_
> Token tokenA has 513* outs.
> Time to first read: PT12.105S
> Runtime: PT12.114S
>
> * The correct count. Last post I also counted csv header (514) then
> transposed the digits. :/
>
> _run2_
> Token tokenA has 513 outs.
> Time to first read: PT7.85S
> Runtime: PT7.86S
>
> _run3_
> /select tokenA 0.229s
>
> _run4_
> Token tokenA has 513 outs.
> Time to first read: PT11.485S
> Runtime: PT11.495S
>
> And we are back to not nearly as fast.
>
> Here's my counting code.
> https://gist.github.com/LannyRipple/8e47769155c766b33bf37bcf901b17e9
>
> On Thu, Nov 9, 2017 at 11:17 AM Joel Bernstein <joels...@gmail.com> wrote:
>
> > Can you post the exact streaming query you are using? The size of the
> index
> > and field types will help understand the issue as well. Also are you
> seeing
> > different performance behaviors after the upgrade or just testing the
> > streaming for the first time on 6.6.1?
> >
> > When using the /export handler to stream, the results are pulled from the
> > DocValues caches which have in-memory structures that need to be built.
> If
> > your query returns a large number of string fields you could see a delay
> as
> > those cashes are built for the first time or rebuilt following a commit.
> > You can use static warming queries to warm the fields in the background
> > following a commit. After caches are built the queries should start
> > streaming immediately on subsequent queries. The 70 second response time
> > with only 541 tuples sounds like it might be caused by the caches being
> > rebuilt.
> >
> > In general though the /export handler will slow down as you add more
> fields
> > to the field list and sort list. But if you post your query and
> information
> > on what types the fields are in the field list I can give you an idea of
> > the type of performance I would expect.
> >
> > Joel Bernstein
> > http://joelsolr.blogspot.com/
> >
> > On Thu, Nov 9, 2017 at 9:54 AM, Lanny Ripple <la...@spotright.com>
> wrote:
> >
> > > We've recently upgraded our SolrCloud (16 shards, 2 replicas) to 6.6.1
> on
> > > our way to 7 and I'm getting surprising /stream results.
> > >
> > > In one example I /select (wt=csv) and /stream [using
> > > search(...,wt=javabin)] with a query that gives a resultset size of 541
> > > tuples. The select comes back in under a second. The stream takes 70
> > > seconds. Should I expect this much difference?
> > >
> > > I then /select and /stream over a query with a resultset size of 3.5M
> > > documents. The select takes 14 minutes. The stream takes just under 7
> > > minutes using `curl`. When I use solrj I get
> > >
> > > Truncated chunk ( expected size: 32768; actual size:
> > > 13830)","trace":"org.apache.http.TruncatedChunkException: Truncated
> chunk
> > > (
> > > expected size: 32768; actual size: 13830)
> > > at
> > > org.apache.http.impl.io.ChunkedInputStream.read(
> > > ChunkedInputStream.java:200)
> > > at
> > > org.apache.http.impl.io.ChunkedInputStream.read(
> > > ChunkedInputStream.java:215)
> > > at
> > > org.apache.http.impl.io.ChunkedInputStream.close(
> > > ChunkedInputStream.java:316)
> > > at
> > > org.apache.http.conn.BasicManagedEntity.streamClosed(
> > > BasicManagedEntity.java:164)
> > > at
> > > org.apache.http.conn.EofSensorInputStream.checkClose(
> > > EofSensorInputStream.java:228)
> > > ...
> > >
> > > I found a reference to this being from a timeout of the HTTP session in
> > > CloudSolrStream but couldn't find a bug in Jira on the topic. Digging
> > > around in the source (yay OSS) I found that I could get hold of the
> > > ClouldSolrClient and up the SOTimeout so that's working now.
> > >
> > > The documentation describes /stream as "returning data as soon as
> > > available" but there seems to be a HUGE startup latency. Any thoughts
> on
> > > how to reduce that?
> > >
> >
>
