Ranges on t.key > const are not handled efficiently

[spetrunia]

(This is a part of patch for issue #16)

Ranges that start with t.key > const are not handled efficiently. One can observe this as follows:

create table ten(a int);
insert into ten values (0),(1),(2),(3),(4),(5),(6),(7),(8),(9);

create table one_k(a int);
insert into one_k select A.a + B.a* 10 + C.a * 100 from ten A, ten B, ten C;

create table t1 (
  pk int primary key,
  a int,
  col1 int,
  key(a)
) engine=rocksdb; 

insert into t1 select a,a,123 from one_k;

insert into t1 
select 1000 + A.a + 1000*B.a, 100, 1234 
from one_k A, one_k B where B.a<100;

explain  select * from t1 where a>100 and a < 105;
+----+-------------+-------+-------+---------------+------+---------+------+------+-------------+
| id | select_type | table | type  | possible_keys | key  | key_len | ref  | rows | Extra       |
+----+-------------+-------+-------+---------------+------+---------+------+------+-------------+
|  1 | SIMPLE      | t1    | range | a             | a    | 5       | NULL |   10 | Using where |
+----+-------------+-------+-------+---------------+------+---------+------+------+-------------+

Now, set two breakpoints in ha_rocksdb::index_read_map:

• a breakpoint at io_perf_start() call
• a breakpoint at the last io_perf_end_and_record() call.

run

select * from t1 where a>100 and a < 105;

and see

  Breakpoint 6, ha_rocksdb::index_read_map (this=0x7fffa40af3f0, buf=0x7fffa40b7f50 "\377", key=0x7fffa41c8948 "", keypart_map=1, find_flag=HA_READ_AFTER_KEY) at /home/psergey/dev-git/mysql-5.6-rocksdb-look/storage/rocksdb/ha_rocksdb.cc:2631
(gdb) p rocksdb::perf_context.find_next_user_entry_time
  $45 = 654578691779
(gdb) p rocksdb::perf_context.internal_key_skipped_count
  $46 = 707050
(gdb) c
  Continuing.

  Breakpoint 7, ha_rocksdb::index_read_map (this=0x7fffa40af3f0, buf=0x7fffa40b7f50 "\371e", key=0x7fffa41c8948 "", keypart_map=1, find_flag=HA_READ_AFTER_KEY) at /home/psergey/dev-git/mysql-5.6-rocksdb-look/storage/rocksdb/ha_rocksdb.cc:2935
(gdb) p rocksdb::perf_context.find_next_user_entry_time
  $47 = 654591615526
(gdb) p rocksdb::perf_context.internal_key_skipped_count
  $48 = 807051
(gdb) p $48 - $46
  $49 = 100001

So we have enumerated 100K rows in order to return 5 rows.

[spetrunia]

It is not possible to observe the issue via counters or status variables exposed by MyRocks. Only through performance measurements or in debugger.

[hermanlee]

Should we instrument Apply_changes_iter on invocations to Next() and Prev() to track the number of rows we examine internally during the query or export out the rest of the perf_context stats somehow? How useful would this be in general to track down these types of performance issues?

[spetrunia]

I think it is general useful to know how many rocksdb::Iterator::Next()/Prev() calls were made.

Instrumenting Apply_changes_iter's invocations of rocksdb::Iterator::Next()/Prev() is a good choice, because it will not count operations made by the background threads (and maybe, it is bad for the same reason - iterator scans that are not made through Apply_changes_iter are not counted)

[spetrunia]

https://reviews.facebook.net/D35103