I'm sort of at a loss on this one. I did some cursory profiling work with perf top and nothing lit up. @danielmewes is going to do some more in depth profiling.

@linuxdynasty -- approximately how much data is in the DB? This might have to do with disk access rather than CPU.

Also, if you run the queries twice (i.e. run query A, then query B, then query A, then query B), what does the performance look like? It might be that query A warms up the cache so it takes longer, and then query B operates entirely in RAM. What happens if you run them twice (A, B, A, B) or reverse the order (B, A)?

@coffeemug Both @jdoliner and me could reproduce this on the data that @linuxdynasty provided to us. It doesn't seem to be an issue of the cache warming up, and the performance difference is consistent regardless the order.

Current status: Somehow the profiler has stopped doing its job since I've last used it a week ago. I'm trying to get it working again...

Preliminary results after profiling: In the first query, we seem to spend significant time on constructing in-memory secondary index data structures over and over.

More specifically, the rdb_read_visitor_t::operator(const rget_read_t &) in protocol.cc, line 1127 appears to be relatively expensive.
Inside of this operator, most time is spent in the call to acquire_sindex_superblock_for_read(), and in deserializing the ql::wire_func_t for the sindex function. Additional time is spent on destructing the ~reql_func_t() again and in rdb_rget_secondary_slice().

Apart from an analogon to rdb_rget_secondary_slice(), we have none of this overhead when using the primary key in the eq_join.

It seems that the problem here is that we call the operator over and over for each document that we want to join. We should change the code to keep the in-memory structures around instead of deserializing them over and over again for each single document in the eq_join.

Interesting, the optimization you suggest is definitely a good one and would fix this problem. How much more time is spent in the deserializing functions in the slow case? It seems weird to me that a slightly more complicated function has any reasonable difference. Also why on earth is the destructor that much more complicated?

I'm not sure if I was clear in my description. The reql_func_t destructor and deserialization I was talking about were both inside of rdb_read_visitor_t::operator(const rget_read_t &). I assume that this is the deserialization / destruction of the sindex_mapping, which is deserialized from disk. Not the function given to eq_join in the query.

PS: So to answer your question: This deserialization does not happen at all in the fast case.

Deserializing and compiling ReQL functions is expensive. We could probably make it better, but I think for most queries you only have to do it a small number of times. If we're currently compiling one function per row, we should almost certainly change that.

If somebody wants to take a closer look:
kcachegrind /home/daniel/1526_db/calltree-1.out on newton for the slow query variant
kcachegrind /home/daniel/1526_db/calltree-2.out on newton for the fast one

@jdoliner: A general question: When we do a get_all on a secondary index, do we have to go to all hash shards? Just wondering if that might also contribute to variant 1's relative slowness.

@danielmewes yes. that's a good point actually.

Actually, another thought: if we made get_all variadic, we could change eq_join to send batches rather than one read query per row, which might help with optimization.

@mlucy -- why would get_all have to variadic for that to happen?

@mlucy: Funny, I just had the same thought. :-)
I think that would be the best solution. It would also improve the efficiency of eq_join on primary keys.

@coffeemug -- eq_join is a rewrite rule that uses get_all.

Ah, I see.

We should also do batching for the other joins at the same time.

Wait, that made no sense at all. Ignore me.

... isn't get_all already variadic?

Apparently I'm just grossly misinformed.

@danielmewes, could I take this one?

@mlucy sure, go ahead!

@mlucy -- is this be related to #1328? (I.e. just rewriting to get_all doesn't get you much unless get_all does things concurrently).

@coffeemug -- the goal is to send batches, not for parallelism but to avoid incurring per-query overhead (like compiling secondary index functions) for every row.

So, I'm not sure that batches work well here. We use range gets for get_all with an index because there can be arbitrarily many things with that index, so we'd have to send batches of ranges, which smells really bad to me.

The workaround involving batches would require some thought, and might just end up being terrible. If anyone else wants to take this before I get to it, feel free.

Actually, I just had another thought: if we made it so that we only load and compile the function the first time we see a truncated key, then the vast majority of these queries would never need to do it. (We only need the function to disambiguate truncated keys.)

I guess that might be a very easy change which would solve about half of the problem.

Note that acquire_sindex_superblock_for_read() also takes significant CPU time. The profiling suggested that acquire_sindex_superblock_for_read() and compiling+destructing the sindex function are responsible for roughly 30-40% of the CPU time spent in the index lookup each. So fixing any one of them should save ~30%.

(actually not sure about it being a "very easy" change, ignore that. I have no clue how difficult or easy it would actually be)

hi

Working on this.

An optimization for caching secondary index functions is in CR 3171.
I'm going to look into batching multi-key gets next, because it has shown up as a bottleneck in context of plain getAll as well.

After taking a brief look, I think I might need @mlucy's help on this one...

Assigning @mlucy for the multi-key get_all optimization.

I'll be taking over the multi-key get_all optimisation.

The get_all optimization is in CR 3240 by @danielmewes .

(It turned out that what we were doing in @VeXocide's branch wasn't actually sufficient for a few edge cases (truncated keys and multiple copies of the same datum in the get_all), and the changes were significant enough I think they warrant a new review.)

It turns out this was branched off of next, so once the review's complete there's still a merge step, but it should be pretty trivial.

This is in next and 2.1.x, will ship with RethinkDB 2.1.5.