Forestdb fdb_get_kvs_info() call can take 90s after compaction

During 2i stale=false performance investigation, notice that sometimes there are pauses for several seconds to over a minute. After adding more timing logs, see that the pause happens in the first call to fdb_get_kvs_info() after compaction is done.

For 2i, there are 3 KVStore within a snigle index fdb file : (1) main index/KVStore (2) back index/KVStore (3) meta/book-keeping KVStore. The meta KVStore is just to keep track of additional metadata for the index. It is kept in the same index file for transactionality. The meta KVStore is relatively very small comparing to the main and back index/KVStore.

Whenver compaction is done, we found that the first call to fdb_get_kvs_info() takes time. In the following log, it shows that "get meta index info time" is 1m21s. This function calls fdb_get_kvs_info() under the cover. Normally, fdb_get_kvs_info() on meta KVStore takes a couple of micro-second. The call to fdb_get_kvs_info() on meta KVStore happens before 2i commit to fdb.

2015-07-29T18:21:12.715Z-07:00 [Info] ForestDBSlice::Commit timings
SliceId 0 IndexInstId 10058744719446249211 total time 1m22.151893638s, flush time 20.267036ms fetch main index info time 11.32µs, fetch back index info time 3.003µs, fetch meta index info time 1m21.869314944s, get meta seq # time 33.229456ms, remove rollback info time 2.694µs, update rollback info time 228.53053ms, commit time 521.329µs, set committed count time 8.467µs