Why is .sample() slow?

[krzkrzkrz]

Why does $rethinkdb.table(:foobar).sample(1)[0] run slow? Table :foobar only has 10,000 records/documents

Slow, as in a few milliseconds. Close to a second actually. Normally, retrieving a single record from 10k should be instant. At least on other db solutions.

[coffeemug]

I don't remember the details of the sample implementation, so I might be wrong on this (@jdoliner should chime in because he knows it much more intimately). As far as I remember, sample was designed to return a uniform distribution, and doing this right is surprisingly tricky. We picked a simpler implementation that does a linear time shuffle, with the intention of doing a smarter implementation later.

Sorry you're running into this -- we're exclusively working on performance now, and most issues should be ironed out in the next few months. Thank you so much for reporting the bugs and being patient!

[jdoliner]

There are a couple of possible levels of optimization for sample. sample in the general case is a linear time operation and right now we only implement the general case.

The first optimization we can make is rewriting it in terms of map reduce. This requires some anaphoric macro magic but other than that it's not too hard.

The next step would be optimizing sample on tables so that it doesn't read data off disk unless it actually selects the row. This might prove to be a little tricky but shouldn't be impossible.

The last step would be to do a BTree aware optimization which could sample rows in logarithmic time. This one is quite challenging so I don't think it's worth doing any time too soon.

[danielmewes]

It looks like sample is especially slow compared to other linear time operations on tables.

Here are some times reported by @ha1331:

r.table('t').sample(2) 2.51s server time
r.table('t').sum('someField') 82ms server time
r.table('t').count() (result is 70387 rows) 17ms server time

This was on a table with 4 shards.
I think sample currently pulls all data onto a single server/thread first? My suspicion is that that's the reason for the slowness.

Here's a possible algorithm for pushing most of the work down to the shards:
Assume a query table.sample(n). Most likely n is going to be small compared to the table size.
We can now first uniformly sample n elements on each shard. As a side effect we can also get the exact number of scanned documents on the shard for free. Finally on the parsing node, we receive the n elements from each shard, and then sample n out of them with a probability distribution adjusted to the total number of scanned documents from each shard.

As an additional optimization we could avoid loading the data for rejected documents like @jdoliner mentioned, similar to what count does.

[marshall007]

@danielmewes FYI, the results are certainly less pronounced when running against a single shard:

table.sample(1) 320ms server time
table.sum('field') 200ms server time
table.avg('field') 202ms server time
table.count() (38717 rows) 23ms server time

Also note that table.sample(n) takes roughly the same amount of time regardless of the value n (including the special case where n >= total number of rows).

[danielmewes]

Thanks for testing @marshall007 . That would fit with the theory that the costs comes from collecting all data on one server first.

[mlucy]

@danielmewes -- that is in fact how it's implemented, and as far as I can tell there's no reason not to use the algorithm you described instead. (The reason we implemented it the way we did is that we originally assumed users would mostly be sampling arrays rather than whole tables, and at the time shards.cc didn't exist yet so implementing it efficiently for the sharded case would have been about twice as much work.)

[IanCal]

As a bit more information, I'm running a single shard locally and r.table('example').sample(1).run(conn) in the python library takes 60s to complete on a table of about 200k rows, so it might not be the cost of pulling data from one shard to another. The frontend shows this as ~6k/s reads, so I'll have to do a bit more investigation to see if this is rethinkdb or the python lib that's causing the issue.

[danielmewes]

Thanks for the data @IanCal . That's really very slow. I doubt it's Python related, since as far as the client is concerned, that query will only return a single document.

Does your data fit into the cache?
For comparison: How long does it take to run r.table('example').map(r.row).count.run(conn)

[IanCal]

@danielmewes Thanks, that would appear to be it, r.table('example').map(r.row).count().run(conn) was similarly slow.

Setting the cache size to > the disk storage (so the interface now shows a cache usage of ~60%) brings the timings to:

0.6s for r.table('example').map(r.row).count().run(conn)

1.8s for r.table('example').sample(1).run(conn)

The query profiler only has extremely small timings for any sub-task, apart from "Sampling elements." which has a mean time of 0.008ms and so accounts for the majority of the time. If I get a chance I might see if I can compile rethinkdb myself as the time is all being spent in a very small section of code that's pretty clear.

Edit -

So on another machine (ubuntu) I've built and run 2.1.1 with a few changes. Sampling a single item takes ~1.3s which comes down to ~1.1s if I remove the profiling. Removing the core logic of swapping elements around only brings down the time by another 0.05s or so, which means the vast majority of the time is spent iterating over all the elements, and quite a substantial amount of time profiling each element.

[danielmewes]

Yeah the profiler doesn't work too well for some queries. I wouldn't rely on the timings it gives you for this to be honest.

The remaining difference between map.count and sample is likely because of our inefficient sample implementation that was mentioned before, which concentrates all documents on a single thread. map.count on the other hand performs the count on multiple threads in parallel, and then just adds up the subresults.

[coffenbacher]

I'm trying to run .sample(10) on a 2M document db and it takes 4min 34.88s server time!

Why does it seem to take a sample for every document in the db???
{
"description": "Sampling elements." ,
"mean_duration(ms)": 0.130639 ,
"n_samples": 2074151
}