From 8ade935971b05c4530806c1070e03327670d6733 Mon Sep 17 00:00:00 2001 From: Vamsi Ponnekanti Date: Sat, 23 Feb 2013 11:11:16 -0800 Subject: [PATCH] [Report the #gets and #founds in db_stress] Summary: Also added some comments and fixed some bugs in stats reporting. Now the stats seem to match what is expected. Test Plan: [nponnekanti@dev902 /data/users/nponnekanti/rocksdb] ./db_stress --test_batches_snapshots=1 --ops_per_thread=1000 --threads=1 --max_key=320 LevelDB version : 1.5 Number of threads : 1 Ops per thread : 1000 Read percentage : 10 Delete percentage : 30 Max key : 320 Ratio #ops/#keys : 3 Num times DB reopens: 10 Batches/snapshots : 1 Num keys per lock : 4 Compression : snappy ------------------------------------------------ No lock creation because test_batches_snapshots set 2013/03/04-15:58:56 Starting database operations 2013/03/04-15:58:56 Reopening database for the 1th time 2013/03/04-15:58:56 Reopening database for the 2th time 2013/03/04-15:58:56 Reopening database for the 3th time 2013/03/04-15:58:56 Reopening database for the 4th time Created bg thread 0x7f4542bff700 2013/03/04-15:58:56 Reopening database for the 5th time 2013/03/04-15:58:56 Reopening database for the 6th time 2013/03/04-15:58:56 Reopening database for the 7th time 2013/03/04-15:58:57 Reopening database for the 8th time 2013/03/04-15:58:57 Reopening database for the 9th time 2013/03/04-15:58:57 Reopening database for the 10th time 2013/03/04-15:58:57 Reopening database for the 11th time 2013/03/04-15:58:57 Limited verification already done during gets Stress Test : 1811.551 micros/op 552 ops/sec : Wrote 0.10 MB (0.05 MB/sec) (598% of 1011 ops) : Wrote 6050 times : Deleted 3050 times : 500/900 gets found the key : Got errors 0 times [nponnekanti@dev902 /data/users/nponnekanti/rocksdb] ./db_stress --ops_per_thread=1000 --threads=1 --max_key=320 LevelDB version : 1.5 Number of threads : 1 Ops per thread : 1000 Read percentage : 10 Delete percentage : 30 Max key : 320 Ratio #ops/#keys : 3 Num times DB reopens: 10 Batches/snapshots : 0 Num keys per lock : 4 Compression : snappy ------------------------------------------------ Creating 80 locks 2013/03/04-15:58:17 Starting database operations 2013/03/04-15:58:17 Reopening database for the 1th time 2013/03/04-15:58:17 Reopening database for the 2th time 2013/03/04-15:58:17 Reopening database for the 3th time 2013/03/04-15:58:17 Reopening database for the 4th time Created bg thread 0x7fc0f5bff700 2013/03/04-15:58:17 Reopening database for the 5th time 2013/03/04-15:58:17 Reopening database for the 6th time 2013/03/04-15:58:18 Reopening database for the 7th time 2013/03/04-15:58:18 Reopening database for the 8th time 2013/03/04-15:58:18 Reopening database for the 9th time 2013/03/04-15:58:18 Reopening database for the 10th time 2013/03/04-15:58:18 Reopening database for the 11th time 2013/03/04-15:58:18 Starting verification Stress Test : 1836.258 micros/op 544 ops/sec : Wrote 0.01 MB (0.01 MB/sec) (59% of 1011 ops) : Wrote 605 times : Deleted 305 times : 50/90 gets found the key : Got errors 0 times 2013/03/04-15:58:18 Verification successful Revert Plan: OK Task ID: # Reviewers: emayanke, dhruba Reviewed By: emayanke CC: leveldb Differential Revision: https://reviews.facebook.net/D9081 --- tools/db_stress.cc | 57 ++++++++++++++++++++++++++++++++++------------ 1 file changed, 43 insertions(+), 14 deletions(-) diff --git a/tools/db_stress.cc b/tools/db_stress.cc index 2725d4ca3..75648ba71 100644 --- a/tools/db_stress.cc +++ b/tools/db_stress.cc @@ -1,7 +1,7 @@ // Copyright (c) 2011 The LevelDB Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. See the AUTHORS file for names of contributors. - +// //The test uses an array to compare against values written to the database. //Keys written to the array are in 1:1 correspondence to the actual values in //the database according to the formula in the functino GenerateValue @@ -11,6 +11,8 @@ //the positions in the array. Therefore to shorten/elongate the amount of time //that this test runs for, you should change the settings: //FLAGS_max_key, FLAGS_ops_per_thread, (sometimes also FLAGS_threads) +//NOTE that if FLAGS_test_batches_snapshots is set, the test behaves a little +//differently. See comment header for the flag. #include #include @@ -178,6 +180,7 @@ class Stats { long done_; long writes_; long deletes_; + long gets_; long founds_; long errors_; int next_report_; @@ -194,6 +197,7 @@ class Stats { done_ = 0; writes_ = 0; deletes_ = 0; + gets_ = 0; founds_ = 0; errors_ = 0; bytes_ = 0; @@ -208,6 +212,9 @@ class Stats { done_ += other.done_; writes_ += other.writes_; deletes_ += other.deletes_; + gets_ += other.gets_; + founds_ += other.founds_; + errors_ += other.errors_; bytes_ += other.bytes_; seconds_ += other.seconds_; if (other.start_ < start_) start_ = other.start_; @@ -254,8 +261,9 @@ class Stats { deletes_ += n; } - void AddFounds(int n) { - founds_ += n; + void AddGets(int ngets, int nfounds) { + founds_ += nfounds; + gets_ += ngets; } void AddErrors(int n) { @@ -279,8 +287,9 @@ class Stats { seconds_ * 1e6 / done_, (long)throughput); fprintf(stdout, "%-12s: Wrote %.2f MB (%.2f MB/sec) (%ld%% of %ld ops)\n", "", bytes_mb, rate, (100*writes_)/done_, done_); + fprintf(stdout, "%-12s: Wrote %ld times\n", "", writes_); fprintf(stdout, "%-12s: Deleted %ld times\n", "", deletes_); - fprintf(stdout, "%-12s: Found lookups %ld times\n", "", founds_); + fprintf(stdout, "%-12s: %ld/%ld gets found the key\n", "", founds_, gets_); fprintf(stdout, "%-12s: Got errors %ld times\n", "", errors_); if (FLAGS_histogram) { @@ -512,8 +521,13 @@ class StressTest { } now = FLAGS_env->NowMicros(); - fprintf(stdout, "%s Starting verification\n", - FLAGS_env->TimeToString((uint64_t) now/1000000).c_str()); + if (FLAGS_test_batches_snapshots) { + fprintf(stdout, "%s Limited verification already done during gets\n", + FLAGS_env->TimeToString((uint64_t) now/1000000).c_str()); + } else { + fprintf(stdout, "%s Starting verification\n", + FLAGS_env->TimeToString((uint64_t) now/1000000).c_str()); + } shared.SetStartVerify(); shared.GetCondVar()->SignalAll(); @@ -532,9 +546,10 @@ class StressTest { threads[i] = nullptr; } double now = FLAGS_env->NowMicros(); - fprintf(stdout, "%s Verification successful\n", - FLAGS_env->TimeToString((uint64_t) now/1000000).c_str()); - + if (!FLAGS_test_batches_snapshots) { + fprintf(stdout, "%s Verification successful\n", + FLAGS_env->TimeToString((uint64_t) now/1000000).c_str()); + } PrintStatistics(); } @@ -666,6 +681,7 @@ class StressTest { // find more errors if any } else if (s.IsNotFound()) { values[i] = ""; + thread->stats.AddGets(1, 0); } else { values[i] = *value; @@ -676,7 +692,7 @@ class StressTest { expected_prefix, actual_prefix); } (values[i])[0] = ' '; // blank out the differing character - thread->stats.AddFounds(1); + thread->stats.AddGets(1, 1); } } db_->ReleaseSnapshot(readoptionscopy.snapshot); @@ -720,7 +736,8 @@ class StressTest { else { thread->shared->GetCondVar()->Wait(); } - thread->stats.Start(); + // Commenting this out as we don't want to reset stats on each open. + // thread->stats.Start(); } } @@ -730,9 +747,21 @@ class StressTest { unsigned int probability_operation = thread->rand.Uniform(100); if (probability_operation < FLAGS_readpercent) { // read load - FLAGS_test_batches_snapshots ? - MultiGet(thread, read_opts, key, &from_db) : - db_->Get(read_opts, key, &from_db); + if (!FLAGS_test_batches_snapshots) { + Status s = db_->Get(read_opts, key, &from_db); + if (s.ok()) { + // found case + thread->stats.AddGets(1, 1); + } else if (s.IsNotFound()) { + // not found case + thread->stats.AddGets(1, 0); + } else { + // errors case + thread->stats.AddErrors(1); + } + } else { + MultiGet(thread, read_opts, key, &from_db); + } } else if (probability_operation < FLAGS_delpercent + FLAGS_readpercent) { //introduce delete load if (!FLAGS_test_batches_snapshots) {