From f5177c761ffb256ecba3ddb9c1af3bc52a105cca Mon Sep 17 00:00:00 2001 From: Islam AbdelRahman Date: Mon, 13 Jun 2016 16:22:14 -0700 Subject: [PATCH] Remove wasteful instrumentation in FullMerge (stacked on D59577) Summary: [ This diff is stacked on top of D59577 ] We keep calling timer.ElapsedNanos() on every call to MergeOperator::FullMerge even when statistics are disabled, this is wasteful. I run the readseq benchmark on a DB containing 100K merge operands for 100K keys (1 operand per key) with 1GB block cache I see slight performance improvment Original results ``` $ ./db_bench --benchmarks="readseq,readseq,readseq,readseq,readseq,readseq,readseq,readseq,readseq" --merge_operator="max" --merge_keys=100000 --num=100000 --db="/dev/shm/100K_merge_compacted/" --cache_size=1073741824 --use_existing_db --disable_auto_compactions ------------------------------------------------ DB path: [/dev/shm/100K_merge_compacted/] readseq : 0.498 micros/op 2006597 ops/sec; 222.0 MB/s DB path: [/dev/shm/100K_merge_compacted/] readseq : 0.295 micros/op 3393627 ops/sec; 375.4 MB/s DB path: [/dev/shm/100K_merge_compacted/] readseq : 0.285 micros/op 3511155 ops/sec; 388.4 MB/s DB path: [/dev/shm/100K_merge_compacted/] readseq : 0.286 micros/op 3500470 ops/sec; 387.2 MB/s DB path: [/dev/shm/100K_merge_compacted/] readseq : 0.283 micros/op 3530751 ops/sec; 390.6 MB/s DB path: [/dev/shm/100K_merge_compacted/] readseq : 0.289 micros/op 3464811 ops/sec; 383.3 MB/s DB path: [/dev/shm/100K_merge_compacted/] readseq : 0.277 micros/op 3612814 ops/sec; 399.7 MB/s DB path: [/dev/shm/100K_merge_compacted/] readseq : 0.283 micros/op 3539640 ops/sec; 391.6 MB/s DB path: [/dev/shm/100K_merge_compacted/] readseq : 0.285 micros/op 3503766 ops/sec; 387.6 MB/s ``` After patch ``` $ ./db_bench --benchmarks="readseq,readseq,readseq,readseq,readseq,readseq,readseq,readseq,readseq" --merge_operator="max" --merge_keys=100000 --num=100000 --db="/dev/shm/100K_merge_compacted/" --cache_size=1073741824 --use_existing_db --disable_auto_compactions ------------------------------------------------ DB path: [/dev/shm/100K_merge_compacted/] readseq : 0.476 micros/op 2100119 ops/sec; 232.3 MB/s DB path: [/dev/shm/100K_merge_compacted/] readseq : 0.278 micros/op 3600887 ops/sec; 398.4 MB/s DB path: [/dev/shm/100K_merge_compacted/] readseq : 0.275 micros/op 3636698 ops/sec; 402.3 MB/s DB path: [/dev/shm/100K_merge_compacted/] readseq : 0.271 micros/op 3691661 ops/sec; 408.4 MB/s DB path: [/dev/shm/100K_merge_compacted/] readseq : 0.273 micros/op 3661534 ops/sec; 405.1 MB/s DB path: [/dev/shm/100K_merge_compacted/] readseq : 0.276 micros/op 3627106 ops/sec; 401.3 MB/s DB path: [/dev/shm/100K_merge_compacted/] readseq : 0.272 micros/op 3682635 ops/sec; 407.4 MB/s DB path: [/dev/shm/100K_merge_compacted/] readseq : 0.266 micros/op 3758331 ops/sec; 415.8 MB/s DB path: [/dev/shm/100K_merge_compacted/] readseq : 0.266 micros/op 3761907 ops/sec; 416.2 MB/s ``` Test Plan: make check -j64 Reviewers: yhchiang, sdong Reviewed By: sdong Subscribers: andrewkr, dhruba Differential Revision: https://reviews.facebook.net/D59583 --- db/merge_helper.cc | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/db/merge_helper.cc b/db/merge_helper.cc index f87b5ee37..2ba22d977 100644 --- a/db/merge_helper.cc +++ b/db/merge_helper.cc @@ -39,7 +39,8 @@ Status MergeHelper::TimedFullMerge(const MergeOperator* merge_operator, // Do the merge success = merge_operator->FullMerge(key, value, operands, result, logger); - RecordTick(statistics, MERGE_OPERATION_TOTAL_TIME, timer.ElapsedNanos()); + RecordTick(statistics, MERGE_OPERATION_TOTAL_TIME, + statistics ? timer.ElapsedNanos() : 0); } if (!success) { @@ -254,7 +255,7 @@ Status MergeHelper::MergeUntil(InternalIterator* iter, std::deque(operands_.begin(), operands_.end()), &merge_result, logger_); RecordTick(stats_, MERGE_OPERATION_TOTAL_TIME, - timer.ElapsedNanosSafe()); + stats_ ? timer.ElapsedNanosSafe() : 0); } if (merge_success) { // Merging of operands (associative merge) was successful.