tools/rados: use the monotonic clock in rados bench

Use the steady (CLOCK_MONOTONIC) clock in the bencher. The clock is used
to measure the passage of time between events, making the monotonic clock
more suited. The system clock is affected by all changes to the system's wall
clock time, which makes it unfit to compare events times relatively to each
other.

Fixes http://tracker.ceph.com/issues/21375

Signed-off-by: Mohamad Gebai <mgebai@suse.com>

diff --git a/src/common/obj_bencher.cc b/src/common/obj_bencher.cc
index 18c85c3b895e8d366d1505e6e661cb122fffeb3b..befdefe6710810b08e3cfcde5c5414427bb2f015 100644 (file)
--- a/src/common/obj_bencher.cc
+++ b/src/common/obj_bencher.cc
@@ -83,21 +83,22 @@ void *ObjBencher::status_printer(void *_bencher) {
   int cycleSinceChange = 0;
   double bandwidth;
   int iops = 0;
-  utime_t ONE_SECOND;
-  ONE_SECOND.set_from_double(1.0);
+  mono_clock::duration ONE_SECOND = std::chrono::seconds(1);
   bencher->lock.Lock();
   if (formatter)
     formatter->open_array_section("datas");
   while(!data.done) {
-    utime_t cur_time = ceph_clock_now();
+    mono_time cur_time = mono_clock::now();
+    utime_t t = ceph_clock_now();
 
     if (i % 20 == 0 && !formatter) {
       if (i > 0)
-        cur_time.localtime(cout) << " min lat: " << data.min_latency
+        t.localtime(cout)
+          << " min lat: " << data.min_latency
           << " max lat: " << data.max_latency
           << " avg lat: " << data.avg_latency << std::endl;
       //I'm naughty and don't reset the fill
-      bencher->out(cout, cur_time) << setfill(' ')
+      bencher->out(cout, t) << setfill(' ')
           << setw(5) << "sec"
           << setw(8) << "Cur ops"
           << setw(10) << "started"
@@ -142,13 +143,15 @@ void *ObjBencher::status_printer(void *_bencher) {
     if (formatter)
       formatter->open_object_section("data");
 
+    // elapsed will be in seconds, by default
+    std::chrono::duration<double> elapsed = cur_time - data.start_time;
     double avg_bandwidth = (double) (data.op_size) * (data.finished)
-      / (double)(cur_time - data.start_time) / (1024*1024);
+      / elapsed.count() / (1024*1024);
     if (previous_writes != data.finished) {
       previous_writes = data.finished;
       cycleSinceChange = 0;
       if (!formatter) {
-        bencher->out(cout, cur_time)
+        bencher->out(cout, t)
          << setfill(' ')
           << setw(5) << i
          << ' ' << setw(7) << data.in_flight
@@ -156,7 +159,7 @@ void *ObjBencher::status_printer(void *_bencher) {
           << ' ' << setw(9) << data.finished
           << ' ' << setw(9) << avg_bandwidth
           << ' ' << setw(9) << bandwidth
-          << ' ' << setw(11) << (double)data.cur_latency
+          << ' ' << setw(11) << (double)data.cur_latency.count()
           << ' ' << setw(11) << data.avg_latency << std::endl;
       } else {
         formatter->dump_format("sec", "%d", i);
@@ -165,13 +168,13 @@ void *ObjBencher::status_printer(void *_bencher) {
         formatter->dump_format("finished", "%d", data.finished);
         formatter->dump_format("avg_bw", "%f", avg_bandwidth);
         formatter->dump_format("cur_bw", "%f", bandwidth);
-        formatter->dump_format("last_lat", "%f", (double)data.cur_latency);
+        formatter->dump_format("last_lat", "%f", (double)data.cur_latency.count());
         formatter->dump_format("avg_lat", "%f", data.avg_latency);
       }
     }
     else {
       if (!formatter) {
-        bencher->out(cout, cur_time)
+        bencher->out(cout, t)
          << setfill(' ')
           << setw(5) << i
          << ' ' << setw(7) << data.in_flight
@@ -203,8 +206,8 @@ void *ObjBencher::status_printer(void *_bencher) {
   if (formatter)
     formatter->close_section(); //datas
   if (iops < 0) {
-    auto runtime = ceph_clock_now() - data.start_time;
-    data.idata.min_iops = data.idata.max_iops = data.finished / runtime;
+    std::chrono::duration<double> runtime = mono_clock::now() - data.start_time;
+    data.idata.min_iops = data.idata.max_iops = data.finished / runtime.count();
   }
   bencher->lock.Unlock();
   return NULL;
@@ -224,7 +227,7 @@ int ObjBencher::aio_bench(
   int num_objects = 0;
   int r = 0;
   int prevPid = 0;
-  utime_t runtime;
+  std::chrono::duration<double> timePassed;
 
   // default metadata object is used if user does not specify one
   const std::string run_name_meta = (run_name.empty() ? BENCH_LASTRUN_METADATA : run_name);
@@ -286,14 +289,14 @@ int ObjBencher::aio_bench(
       goto out;
     }
 
-    data.start_time = ceph_clock_now();
+    data.start_time = mono_clock::now();
     out(cout) << "Cleaning up (deleting benchmark objects)" << std::endl;
 
     r = clean_up(num_objects, prevPid, concurrentios);
     if (r != 0) goto out;
 
-    runtime = ceph_clock_now() - data.start_time;
-    out(cout) << "Clean up completed and total clean up time :" << runtime << std::endl;
+    timePassed = mono_clock::now() - data.start_time;
+    out(cout) << "Clean up completed and total clean up time :" << timePassed.count() << std::endl;
 
     // lastrun file
     r = sync_remove(run_name_meta);
@@ -407,14 +410,13 @@ int ObjBencher::write_bench(int secondsToRun,
   std::vector<string> name(concurrentios);
   std::string newName;
   bufferlist* contents[concurrentios];
-  double total_latency = 0;
-  std::vector<utime_t> start_times(concurrentios);
-  utime_t stopTime;
   int r = 0;
   bufferlist b_write;
   lock_cond lc(&lock);
-  utime_t runtime;
-  utime_t timePassed;
+  double total_latency = 0;
+  std::vector<mono_time> start_times(concurrentios);
+  mono_time stopTime;
+  std::chrono::duration<double> timePassed;
 
   unsigned writes_per_object = 1;
   if (data.op_size)
@@ -436,10 +438,10 @@ int ObjBencher::write_bench(int secondsToRun,
   ceph_pthread_setname(print_thread, "write_stat");
   lock.Lock();
   data.finished = 0;
-  data.start_time = ceph_clock_now();
+  data.start_time = mono_clock::now();
   lock.Unlock();
   for (int i = 0; i<concurrentios; ++i) {
-    start_times[i] = ceph_clock_now();
+    start_times[i] = mono_clock::now();
     r = create_completion(i, _aio_cb, (void *)&lc);
     if (r < 0)
       goto ERR;
@@ -460,11 +462,10 @@ int ObjBencher::write_bench(int secondsToRun,
 
   //don't need locking for reads because other thread doesn't write
 
-  runtime.set_from_double(secondsToRun);
-  stopTime = data.start_time + runtime;
+  stopTime = data.start_time + std::chrono::seconds(secondsToRun);
   slot = 0;
   lock.Lock();
-  while (secondsToRun && ceph_clock_now() < stopTime) {
+  while (secondsToRun && mono_clock::now() < stopTime) {
     bool found = false;
     while (1) {
       int old_slot = slot;
@@ -497,20 +498,21 @@ int ObjBencher::write_bench(int secondsToRun,
       lock.Unlock();
       goto ERR;
     }
-    data.cur_latency = ceph_clock_now() - start_times[slot];
-    data.history.latency.push_back(data.cur_latency);
-    total_latency += data.cur_latency;
-    if( data.cur_latency > data.max_latency) data.max_latency = data.cur_latency;
-    if (data.cur_latency < data.min_latency) data.min_latency = data.cur_latency;
+    data.cur_latency = mono_clock::now() - start_times[slot];
+    data.history.latency.push_back(data.cur_latency.count());
+    total_latency += data.cur_latency.count();
+    if( data.cur_latency.count() > data.max_latency)
+      data.max_latency = data.cur_latency.count();
+    if (data.cur_latency.count() < data.min_latency)
+      data.min_latency = data.cur_latency.count();
     ++data.finished;
     data.avg_latency = total_latency / data.finished;
     --data.in_flight;
     lock.Unlock();
     release_completion(slot);
-    timePassed = ceph_clock_now() - data.start_time;
 
     //write new stuff to backend
-    start_times[slot] = ceph_clock_now();
+    start_times[slot] = mono_clock::now();
     r = create_completion(slot, _aio_cb, &lc);
     if (r < 0)
       goto ERR;
@@ -539,11 +541,13 @@ int ObjBencher::write_bench(int secondsToRun,
       lock.Unlock();
       goto ERR;
     }
-    data.cur_latency = ceph_clock_now() - start_times[slot];
-    data.history.latency.push_back(data.cur_latency);
-    total_latency += data.cur_latency;
-    if (data.cur_latency > data.max_latency) data.max_latency = data.cur_latency;
-    if (data.cur_latency < data.min_latency) data.min_latency = data.cur_latency;
+    data.cur_latency = mono_clock::now() - start_times[slot];
+    data.history.latency.push_back(data.cur_latency.count());
+    total_latency += data.cur_latency.count();
+    if (data.cur_latency.count() > data.max_latency)
+      data.max_latency = data.cur_latency.count();
+    if (data.cur_latency.count() < data.min_latency)
+      data.min_latency = data.cur_latency.count();
     ++data.finished;
     data.avg_latency = total_latency / data.finished;
     --data.in_flight;
@@ -553,7 +557,7 @@ int ObjBencher::write_bench(int secondsToRun,
     contents[slot] = 0;
   }
 
-  timePassed = ceph_clock_now() - data.start_time;
+  timePassed = mono_clock::now() - data.start_time;
   lock.Lock();
   data.done = true;
   lock.Unlock();
@@ -561,11 +565,12 @@ int ObjBencher::write_bench(int secondsToRun,
   pthread_join(print_thread, NULL);
 
   double bandwidth;
-  bandwidth = ((double)data.finished)*((double)data.op_size)/(double)timePassed;
+  bandwidth = ((double)data.finished)*((double)data.op_size) /
+       timePassed.count();
   bandwidth = bandwidth/(1024*1024); // we want it in MB/sec
 
   if (!formatter) {
-    out(cout) << "Total time run:         " << timePassed << std::endl
+    out(cout) << "Total time run:         " << timePassed.count() << std::endl
        << "Total writes made:      " << data.finished << std::endl
        << "Write size:             " << data.op_size << std::endl
        << "Object size:            " << data.object_size << std::endl      
@@ -573,7 +578,7 @@ int ObjBencher::write_bench(int secondsToRun,
        << "Stddev Bandwidth:       " << vec_stddev(data.history.bandwidth) << std::endl
        << "Max bandwidth (MB/sec): " << data.idata.max_bandwidth << std::endl
        << "Min bandwidth (MB/sec): " << data.idata.min_bandwidth << std::endl
-       << "Average IOPS:           " << (int)(data.finished/timePassed) << std::endl
+       << "Average IOPS:           " << (int)(data.finished/timePassed.count()) << std::endl
        << "Stddev IOPS:            " << vec_stddev(data.history.iops) << std::endl
        << "Max IOPS:               " << data.idata.max_iops << std::endl
        << "Min IOPS:               " << data.idata.min_iops << std::endl
@@ -582,7 +587,7 @@ int ObjBencher::write_bench(int secondsToRun,
        << "Max latency(s):         " << data.max_latency << std::endl
        << "Min latency(s):         " << data.min_latency << std::endl;
   } else {
-    formatter->dump_format("total_time_run", "%f", (double)timePassed);
+    formatter->dump_format("total_time_run", "%f", timePassed.count());
     formatter->dump_format("total_writes_made", "%d", data.finished);
     formatter->dump_format("write_size", "%d", data.op_size);
     formatter->dump_format("object_size", "%d", data.object_size);
@@ -590,7 +595,7 @@ int ObjBencher::write_bench(int secondsToRun,
     formatter->dump_format("stddev_bandwidth", "%f", vec_stddev(data.history.bandwidth));
     formatter->dump_format("max_bandwidth", "%f", data.idata.max_bandwidth);
     formatter->dump_format("min_bandwidth", "%f", data.idata.min_bandwidth);
-    formatter->dump_format("average_iops", "%d", (int)(data.finished/timePassed));
+    formatter->dump_format("average_iops", "%d", (int)(data.finished/timePassed.count()));
     formatter->dump_format("stddev_iops", "%d", vec_stddev(data.history.iops));
     formatter->dump_format("max_iops", "%d", data.idata.max_iops);
     formatter->dump_format("min_iops", "%d", data.idata.min_iops);
@@ -638,13 +643,11 @@ int ObjBencher::seq_read_bench(int seconds_to_run, int num_objects, int concurre
   bufferlist* contents[concurrentios];
   int index[concurrentios];
   int errors = 0;
-  utime_t start_time;
-  std::vector<utime_t> start_times(concurrentios);
-  utime_t time_to_run;
-  time_to_run.set_from_double(seconds_to_run);
   double total_latency = 0;
   int r = 0;
-  utime_t runtime;
+  std::vector<mono_time> start_times(concurrentios);
+  mono_clock::duration time_to_run = std::chrono::seconds(seconds_to_run);
+  std::chrono::duration<double> timePassed;
   sanitize_object_contents(&data, data.op_size); //clean it up once; subsequent
   //changes will be safe because string length should remain the same
 
@@ -664,18 +667,18 @@ int ObjBencher::seq_read_bench(int seconds_to_run, int num_objects, int concurre
 
   lock.Lock();
   data.finished = 0;
-  data.start_time = ceph_clock_now();
+  data.start_time = mono_clock::now();
   lock.Unlock();
 
   pthread_t print_thread;
   pthread_create(&print_thread, NULL, status_printer, (void *)this);
   ceph_pthread_setname(print_thread, "seq_read_stat");
 
-  utime_t finish_time = data.start_time + time_to_run;
+  mono_time finish_time = data.start_time + time_to_run;
   //start initial reads
   for (int i = 0; i < concurrentios; ++i) {
     index[i] = i;
-    start_times[i] = ceph_clock_now();
+    start_times[i] = mono_clock::now();
     create_completion(i, _aio_cb, (void *)&lc);
     r = aio_read(name[i], i, contents[i], data.op_size,
                 data.op_size * (i % writes_per_object));
@@ -694,7 +697,7 @@ int ObjBencher::seq_read_bench(int seconds_to_run, int num_objects, int concurre
   bufferlist *cur_contents;
 
   slot = 0;
-  while ((seconds_to_run && ceph_clock_now() < finish_time) &&
+  while ((seconds_to_run && mono_clock::now() < finish_time) &&
         num_objects > data.started) {
     lock.Lock();
     int old_slot = slot;
@@ -717,7 +720,7 @@ int ObjBencher::seq_read_bench(int seconds_to_run, int num_objects, int concurre
     }
 
     // calculate latency here, so memcmp doesn't inflate it
-    data.cur_latency = ceph_clock_now() - start_times[slot];
+    data.cur_latency = mono_clock::now() - start_times[slot];
 
     cur_contents = contents[slot];
     int current_index = index[slot];
@@ -745,9 +748,11 @@ int ObjBencher::seq_read_bench(int seconds_to_run, int num_objects, int concurre
       lock.Unlock();
       goto ERR;
     }
-    total_latency += data.cur_latency;
-    if (data.cur_latency > data.max_latency) data.max_latency = data.cur_latency;
-    if (data.cur_latency < data.min_latency) data.min_latency = data.cur_latency;
+    total_latency += data.cur_latency.count();
+    if (data.cur_latency.count() > data.max_latency)
+      data.max_latency = data.cur_latency.count();
+    if (data.cur_latency.count() < data.min_latency)
+      data.min_latency = data.cur_latency.count();
     ++data.finished;
     data.avg_latency = total_latency / data.finished;
     --data.in_flight;
@@ -755,7 +760,7 @@ int ObjBencher::seq_read_bench(int seconds_to_run, int num_objects, int concurre
     release_completion(slot);
 
     //start new read and check data if requested
-    start_times[slot] = ceph_clock_now();
+    start_times[slot] = mono_clock::now();
     create_completion(slot, _aio_cb, (void *)&lc);
     r = aio_read(newName, slot, contents[slot], data.op_size,
                 data.op_size * (data.started % writes_per_object));
@@ -780,10 +785,12 @@ int ObjBencher::seq_read_bench(int seconds_to_run, int num_objects, int concurre
       lock.Unlock();
       goto ERR;
     }
-    data.cur_latency = ceph_clock_now() - start_times[slot];
-    total_latency += data.cur_latency;
-    if (data.cur_latency > data.max_latency) data.max_latency = data.cur_latency;
-    if (data.cur_latency < data.min_latency) data.min_latency = data.cur_latency;
+    data.cur_latency = mono_clock::now() - start_times[slot];
+    total_latency += data.cur_latency.count();
+    if (data.cur_latency.count() > data.max_latency)
+      data.max_latency = data.cur_latency.count();
+    if (data.cur_latency.count() < data.min_latency)
+      data.min_latency = data.cur_latency.count();
     ++data.finished;
     data.avg_latency = total_latency / data.finished;
     --data.in_flight;
@@ -802,7 +809,7 @@ int ObjBencher::seq_read_bench(int seconds_to_run, int num_objects, int concurre
     delete contents[slot];
   }
 
-  runtime = ceph_clock_now() - data.start_time;
+  timePassed = mono_clock::now() - data.start_time;
   lock.Lock();
   data.done = true;
   lock.Unlock();
@@ -810,16 +817,16 @@ int ObjBencher::seq_read_bench(int seconds_to_run, int num_objects, int concurre
   pthread_join(print_thread, NULL);
 
   double bandwidth;
-  bandwidth = ((double)data.finished)*((double)data.op_size)/(double)runtime;
+  bandwidth = ((double)data.finished)*((double)data.op_size)/timePassed.count();
   bandwidth = bandwidth/(1024*1024); // we want it in MB/sec
 
   if (!formatter) {
-    out(cout) << "Total time run:       " << runtime << std::endl
+    out(cout) << "Total time run:       " << timePassed.count() << std::endl
        << "Total reads made:     " << data.finished << std::endl
        << "Read size:            " << data.op_size << std::endl
        << "Object size:          " << data.object_size << std::endl
        << "Bandwidth (MB/sec):   " << setprecision(6) << bandwidth << std::endl
-       << "Average IOPS:         " << (int)(data.finished/runtime) << std::endl
+       << "Average IOPS:         " << (int)(data.finished/timePassed.count()) << std::endl
        << "Stddev IOPS:          " << vec_stddev(data.history.iops) << std::endl
        << "Max IOPS:             " << data.idata.max_iops << std::endl
        << "Min IOPS:             " << data.idata.min_iops << std::endl
@@ -827,12 +834,12 @@ int ObjBencher::seq_read_bench(int seconds_to_run, int num_objects, int concurre
        << "Max latency(s):       " << data.max_latency << std::endl
        << "Min latency(s):       " << data.min_latency << std::endl;
   } else {
-    formatter->dump_format("total_time_run", "%f", (double)runtime);
+    formatter->dump_format("total_time_run", "%f", timePassed.count());
     formatter->dump_format("total_reads_made", "%d", data.finished);
     formatter->dump_format("read_size", "%d", data.op_size);
     formatter->dump_format("object_size", "%d", data.object_size);
     formatter->dump_format("bandwidth", "%f", bandwidth);
-    formatter->dump_format("average_iops", "%d", (int)(data.finished/runtime));
+    formatter->dump_format("average_iops", "%d", (int)(data.finished/timePassed.count()));
     formatter->dump_format("stddev_iops", "%d", vec_stddev(data.history.iops));
     formatter->dump_format("max_iops", "%d", data.idata.max_iops);
     formatter->dump_format("min_iops", "%d", data.idata.min_iops);
@@ -865,13 +872,11 @@ int ObjBencher::rand_read_bench(int seconds_to_run, int num_objects, int concurr
   bufferlist* contents[concurrentios];
   int index[concurrentios];
   int errors = 0;
-  utime_t start_time;
-  std::vector<utime_t> start_times(concurrentios);
-  utime_t time_to_run;
-  time_to_run.set_from_double(seconds_to_run);
-  double total_latency = 0;
   int r = 0;
-  utime_t runtime;
+  double total_latency = 0;
+  std::vector<mono_time> start_times(concurrentios);
+  mono_clock::duration time_to_run = std::chrono::seconds(seconds_to_run);
+  std::chrono::duration<double> timePassed;
   sanitize_object_contents(&data, data.op_size); //clean it up once; subsequent
   //changes will be safe because string length should remain the same
 
@@ -893,18 +898,18 @@ int ObjBencher::rand_read_bench(int seconds_to_run, int num_objects, int concurr
 
   lock.Lock();
   data.finished = 0;
-  data.start_time = ceph_clock_now();
+  data.start_time = mono_clock::now();
   lock.Unlock();
 
   pthread_t print_thread;
   pthread_create(&print_thread, NULL, status_printer, (void *)this);
   ceph_pthread_setname(print_thread, "rand_read_stat");
 
-  utime_t finish_time = data.start_time + time_to_run;
+  mono_time finish_time = data.start_time + time_to_run;
   //start initial reads
   for (int i = 0; i < concurrentios; ++i) {
     index[i] = i;
-    start_times[i] = ceph_clock_now();
+    start_times[i] = mono_clock::now();
     create_completion(i, _aio_cb, (void *)&lc);
     r = aio_read(name[i], i, contents[i], data.op_size,
                 data.op_size * (i % writes_per_object));
@@ -924,7 +929,7 @@ int ObjBencher::rand_read_bench(int seconds_to_run, int num_objects, int concurr
   int rand_id;
 
   slot = 0;
-  while ((seconds_to_run && ceph_clock_now() < finish_time)) {
+  while ((seconds_to_run && mono_clock::now() < finish_time)) {
     lock.Lock();
     int old_slot = slot;
     bool found = false;
@@ -946,7 +951,7 @@ int ObjBencher::rand_read_bench(int seconds_to_run, int num_objects, int concurr
     }
 
     // calculate latency here, so memcmp doesn't inflate it
-    data.cur_latency = ceph_clock_now() - start_times[slot];
+    data.cur_latency = mono_clock::now() - start_times[slot];
 
     lock.Unlock();
 
@@ -961,9 +966,11 @@ int ObjBencher::rand_read_bench(int seconds_to_run, int num_objects, int concurr
       goto ERR;
     }
 
-    total_latency += data.cur_latency;
-    if (data.cur_latency > data.max_latency) data.max_latency = data.cur_latency;
-    if (data.cur_latency < data.min_latency) data.min_latency = data.cur_latency;
+    total_latency += data.cur_latency.count();
+    if (data.cur_latency.count() > data.max_latency)
+      data.max_latency = data.cur_latency.count();
+    if (data.cur_latency.count() < data.min_latency)
+      data.min_latency = data.cur_latency.count();
     ++data.finished;
     data.avg_latency = total_latency / data.finished;
     --data.in_flight;
@@ -987,7 +994,7 @@ int ObjBencher::rand_read_bench(int seconds_to_run, int num_objects, int concurr
     cur_contents->invalidate_crc();
 
     //start new read and check data if requested
-    start_times[slot] = ceph_clock_now();
+    start_times[slot] = mono_clock::now();
     create_completion(slot, _aio_cb, (void *)&lc);
     r = aio_read(newName, slot, contents[slot], data.op_size,
                 data.op_size * (rand_id % writes_per_object));
@@ -1013,10 +1020,12 @@ int ObjBencher::rand_read_bench(int seconds_to_run, int num_objects, int concurr
       lock.Unlock();
       goto ERR;
     }
-    data.cur_latency = ceph_clock_now() - start_times[slot];
-    total_latency += data.cur_latency;
-    if (data.cur_latency > data.max_latency) data.max_latency = data.cur_latency;
-    if (data.cur_latency < data.min_latency) data.min_latency = data.cur_latency;
+    data.cur_latency = mono_clock::now() - start_times[slot];
+    total_latency += data.cur_latency.count();
+    if (data.cur_latency.count() > data.max_latency)
+      data.max_latency = data.cur_latency.count();
+    if (data.cur_latency.count() < data.min_latency)
+      data.min_latency = data.cur_latency.count();
     ++data.finished;
     data.avg_latency = total_latency / data.finished;
     --data.in_flight;
@@ -1035,7 +1044,7 @@ int ObjBencher::rand_read_bench(int seconds_to_run, int num_objects, int concurr
     delete contents[slot];
   }
 
-  runtime = ceph_clock_now() - data.start_time;
+  timePassed = mono_clock::now() - data.start_time;
   lock.Lock();
   data.done = true;
   lock.Unlock();
@@ -1043,16 +1052,16 @@ int ObjBencher::rand_read_bench(int seconds_to_run, int num_objects, int concurr
   pthread_join(print_thread, NULL);
 
   double bandwidth;
-  bandwidth = ((double)data.finished)*((double)data.op_size)/(double)runtime;
+  bandwidth = ((double)data.finished)*((double)data.op_size)/timePassed.count();
   bandwidth = bandwidth/(1024*1024); // we want it in MB/sec
 
   if (!formatter) {
-    out(cout) << "Total time run:       " << runtime << std::endl
+    out(cout) << "Total time run:       " << timePassed.count() << std::endl
        << "Total reads made:     " << data.finished << std::endl
        << "Read size:            " << data.op_size << std::endl
        << "Object size:          " << data.object_size << std::endl
        << "Bandwidth (MB/sec):   " << setprecision(6) << bandwidth << std::endl
-       << "Average IOPS:         " << (int)(data.finished/runtime) << std::endl
+       << "Average IOPS:         " << (int)(data.finished/timePassed.count()) << std::endl
        << "Stddev IOPS:          " << vec_stddev(data.history.iops) << std::endl
        << "Max IOPS:             " << data.idata.max_iops << std::endl
        << "Min IOPS:             " << data.idata.min_iops << std::endl
@@ -1060,12 +1069,12 @@ int ObjBencher::rand_read_bench(int seconds_to_run, int num_objects, int concurr
        << "Max latency(s):       " << data.max_latency << std::endl
        << "Min latency(s):       " << data.min_latency << std::endl;
   } else {
-    formatter->dump_format("total_time_run", "%f", (double)runtime);
+    formatter->dump_format("total_time_run", "%f", timePassed.count());
     formatter->dump_format("total_reads_made", "%d", data.finished);
     formatter->dump_format("read_size", "%d", data.op_size);
     formatter->dump_format("object_size", "%d", data.object_size);
     formatter->dump_format("bandwidth", "%f", bandwidth);
-    formatter->dump_format("average_iops", "%d", (int)(data.finished/runtime));
+    formatter->dump_format("average_iops", "%d", (int)(data.finished/timePassed.count()));
     formatter->dump_format("stddev_iops", "%d", vec_stddev(data.history.iops));
     formatter->dump_format("max_iops", "%d", data.idata.max_iops);
     formatter->dump_format("min_iops", "%d", data.idata.min_iops);
@@ -1159,7 +1168,6 @@ int ObjBencher::clean_up(int num_objects, int prevPid, int concurrentios) {
   std::vector<string> name(concurrentios);
   std::string newName;
   int r = 0;
-  utime_t runtime;
   int slot = 0;
 
   lock.Lock();
@@ -1324,7 +1332,6 @@ int ObjBencher::clean_up_slow(const std::string& prefix, int concurrentios) {
   std::vector<Object> name(concurrentios);
   Object newName;
   int r = 0;
-  utime_t runtime;
   int slot = 0;
   std::list<Object> objects;
   bool objects_remain = true;

diff --git a/src/common/obj_bencher.h b/src/common/obj_bencher.h
index 8dad8e6ddf9c53fe9dc3e60b2b10f490aa933887..7f8363cab11bd1d6f19e17a4ca6dcc70d9e69a58 100644 (file)
--- a/src/common/obj_bencher.h
+++ b/src/common/obj_bencher.h
@@ -17,8 +17,11 @@
 
 #include "common/ceph_context.h"
 #include "common/Formatter.h"
+#include "ceph_time.h"
 #include <cfloat>
 
+using ceph::mono_clock;
+
 struct bench_interval_data {
   double min_bandwidth = DBL_MAX;
   double max_bandwidth = 0;
@@ -46,8 +49,8 @@ struct bench_data {
   double avg_latency;
   struct bench_interval_data idata; // data that is updated by time intervals and not by events
   struct bench_history history; // data history, used to calculate stddev
-  utime_t cur_latency; //latency of last completed transaction
-  utime_t start_time; //start time for benchmark
+  std::chrono::duration<double> cur_latency; //latency of last completed transaction - in seconds by default
+  mono_time start_time; //start time for benchmark - use the monotonic clock as we'll measure the passage of time
   char *object_contents; //pointer to the contents written to each object
 };