rocksdb/util/perf_step_timer.h
Mike Kolupaev ec7a944360 more times in perf_context and iostats_context
Summary:
We occasionally get write stalls (>1s Write() calls) on HDD under read load. The following timers explain almost all of the stalls:
 - perf_context.db_mutex_lock_nanos
 - perf_context.db_condition_wait_nanos
 - iostats_context.open_time
 - iostats_context.allocate_time
 - iostats_context.write_time
 - iostats_context.range_sync_time
 - iostats_context.logger_time

In my experiments each of these occasionally takes >1s on write path under some workload. There are rare cases when Write() takes long but none of these takes long.

Test Plan: Added code to our application to write the listed timings to log for slow writes. They usually add up to almost exactly the time Write() call took.

Reviewers: rven, yhchiang, sdong

Reviewed By: sdong

Subscribers: march, dhruba, tnovak

Differential Revision: https://reviews.facebook.net/D39177
2015-06-02 02:07:58 -07:00

55 lines
1.1 KiB
C++

// Copyright (c) 2013, Facebook, Inc. All rights reserved.
// This source code is licensed under the BSD-style license found in the
// LICENSE file in the root directory of this source tree. An additional grant
// of patent rights can be found in the PATENTS file in the same directory.
//
#pragma once
#include "rocksdb/env.h"
#include "util/perf_level_imp.h"
#include "util/stop_watch.h"
namespace rocksdb {
class PerfStepTimer {
public:
PerfStepTimer(uint64_t* metric)
: enabled_(perf_level >= PerfLevel::kEnableTime),
env_(enabled_ ? Env::Default() : nullptr),
start_(0),
metric_(metric) {
}
~PerfStepTimer() {
Stop();
}
void Start() {
if (enabled_) {
start_ = env_->NowNanos();
}
}
void Measure() {
if (start_) {
uint64_t now = env_->NowNanos();
*metric_ += now - start_;
start_ = now;
}
}
void Stop() {
if (start_) {
*metric_ += env_->NowNanos() - start_;
start_ = 0;
}
}
private:
const bool enabled_;
Env* const env_;
uint64_t start_;
uint64_t* metric_;
};
} // namespace rocksdb