crimson/os/seastore: per-stage do_transaction breakdown for tail txns

on hot shards a small fraction of transactions dominate latency,collecting
one histogram for all is not enough.

Add two more histograms of the same strcutre for txns that take more
than 5ms and more than 10ms.

Signed-off-by: Matan Breizman <mbreizma@redhat.com>
This commit is contained in:
Matan Breizman 2026-06-24 12:59:13 +00:00
parent 824e267a33
commit 3ba4b80f67
2 changed files with 73 additions and 35 deletions

View File

@ -227,27 +227,38 @@ void SeaStore::Shard::register_metrics(store_index_t store_index)
{txn_stage_t::SUBMIT_PREPARE_RECORD, sm::label_instance("stage", "submit_prepare_record")},
{txn_stage_t::SUBMIT_JOURNAL, sm::label_instance("stage", "submit_journal")},
};
for (auto& [stage, label] : labels_by_stage) {
auto idx = static_cast<std::size_t>(stage);
auto& hist = stats.stage_lat[idx];
hist.buckets.resize(STAGE_LAT_BUCKETS_US.size());
for (std::size_t i = 0; i < STAGE_LAT_BUCKETS_US.size(); ++i) {
hist.buckets[i].upper_bound = STAGE_LAT_BUCKETS_US[i];
hist.buckets[i].count = 0;
}
metrics.add_group(
"seastore",
{
sm::make_histogram(
"do_transaction_stage_lat",
[this, idx]() -> seastar::metrics::histogram& {
return stats.stage_lat[idx];
},
sm::description("per-stage latency (microseconds) of do_transaction"),
{label, sm::label_instance("shard_store_index", std::to_string(store_index))}
)
// Three tiers of the same per-stage histograms
std::pair<std::array<seastar::metrics::histogram, STAGE_MAX>*, const char*>
tail_tiers[] = {
{&stats.stage_lat, "all"},
{&stats.stage_lat_slow, "slow"},
{&stats.stage_lat_very_slow, "very_slow"},
};
for (auto& [arr_ptr, tail] : tail_tiers) {
for (auto& [stage, label] : labels_by_stage) {
auto idx = static_cast<std::size_t>(stage);
auto& hist = (*arr_ptr)[idx];
hist.buckets.resize(STAGE_LAT_BUCKETS_US.size());
for (std::size_t i = 0; i < STAGE_LAT_BUCKETS_US.size(); ++i) {
hist.buckets[i].upper_bound = STAGE_LAT_BUCKETS_US[i];
hist.buckets[i].count = 0;
}
);
metrics.add_group(
"seastore",
{
sm::make_histogram(
"do_transaction_stage_lat",
[arr_ptr, idx]() -> seastar::metrics::histogram& {
return (*arr_ptr)[idx];
},
sm::description("per-stage latency (microseconds) of do_transaction"),
{label,
sm::label_instance("tail", tail),
sm::label_instance("shard_store_index", std::to_string(store_index))}
)
}
);
}
}
metrics.add_group(
@ -1820,21 +1831,39 @@ seastar::future<> SeaStore::Shard::do_transaction_no_callbacks(
DEBUGT("done", *ctx.transaction);
add_conflict_replay_sample(ctx.transaction->get_num_replays());
add_stage_latency_sample(txn_stage_t::COLLOCK_WAIT, collock_wait);
add_stage_latency_sample(txn_stage_t::COLLOCK_HOLD,
ctx.transaction->get_handle().get_lock_hold_time());
add_stage_latency_sample(txn_stage_t::THROTTLER_WAIT, throttler_wait);
add_stage_latency_sample(txn_stage_t::BUILD, ctx.build_time);
add_stage_latency_sample(txn_stage_t::BUILD_GET_ONODE, ctx.get_onode_time);
add_stage_latency_sample(txn_stage_t::SUBMIT_TOTAL, ctx.submit_time);
{
auto& pd = ctx.transaction->get_phase_durations();
add_stage_latency_sample(txn_stage_t::SUBMIT_RESERVE, pd.reserve);
add_stage_latency_sample(txn_stage_t::SUBMIT_OOL_WRITE, pd.ool_write);
add_stage_latency_sample(txn_stage_t::SUBMIT_LBA_UPDATE, pd.lba_update);
add_stage_latency_sample(txn_stage_t::SUBMIT_PREPARE_ENTER, pd.prepare_enter);
add_stage_latency_sample(txn_stage_t::SUBMIT_PREPARE_RECORD, pd.prepare_record);
add_stage_latency_sample(txn_stage_t::SUBMIT_JOURNAL, pd.journal);
auto total = std::chrono::steady_clock::now() - ctx.begin_timestamp;
auto total_us = static_cast<uint64_t>(
std::chrono::duration_cast<std::chrono::microseconds>(total).count());
const std::array<
std::pair<txn_stage_t, std::chrono::steady_clock::duration>, STAGE_MAX>
stage_samples = {{
{txn_stage_t::COLLOCK_WAIT, collock_wait},
{txn_stage_t::COLLOCK_HOLD, ctx.transaction->get_handle().get_lock_hold_time()},
{txn_stage_t::THROTTLER_WAIT, throttler_wait},
{txn_stage_t::BUILD, ctx.build_time},
{txn_stage_t::BUILD_GET_ONODE, ctx.get_onode_time},
{txn_stage_t::SUBMIT_TOTAL, ctx.submit_time},
{txn_stage_t::SUBMIT_RESERVE, pd.reserve},
{txn_stage_t::SUBMIT_OOL_WRITE, pd.ool_write},
{txn_stage_t::SUBMIT_LBA_UPDATE, pd.lba_update},
{txn_stage_t::SUBMIT_PREPARE_ENTER, pd.prepare_enter},
{txn_stage_t::SUBMIT_PREPARE_RECORD, pd.prepare_record},
{txn_stage_t::SUBMIT_JOURNAL, pd.journal},
}};
for (auto& [stage, dur] : stage_samples) {
add_stage_latency_sample(stats.stage_lat, stage, dur);
if (total_us > TAIL_SLOW_US) {
add_stage_latency_sample(stats.stage_lat_slow, stage, dur);
}
if (total_us > TAIL_VERY_SLOW_US) {
add_stage_latency_sample(stats.stage_lat_very_slow, stage, dur);
}
}
add_latency_sample(op_type_t::DO_TRANSACTION, total);
}
add_latency_sample(
op_type_t::DO_TRANSACTION,

View File

@ -462,6 +462,9 @@ public:
10000, 15000, 20000, 30000, 50000, 100000
};
static constexpr uint64_t TAIL_SLOW_US = 5000; // 5 ms
static constexpr uint64_t TAIL_VERY_SLOW_US = 10000; // 10 ms
struct {
std::array<seastar::metrics::histogram, LAT_MAX> op_lat;
seastar::metrics::histogram conflict_replays;
@ -473,6 +476,10 @@ public:
uint64_t onode_updates = 0;
uint64_t onode_erases = 0;
int64_t onode_extents_delta = 0;
// same metrics collected two more times for high tail txns.
std::array<seastar::metrics::histogram, STAGE_MAX> stage_lat_slow;
std::array<seastar::metrics::histogram, STAGE_MAX> stage_lat_very_slow;
} stats;
void add_onode_tree_sample(const Transaction::tree_stats_t& ts) {
@ -528,9 +535,11 @@ public:
// Record the latency of one do_transaction stage (microseconds). Buckets are
// non-cumulative (bucket = first upper_bound >= value); values above the top
// bound aren't bucketed but still land in sample_count/sample_sum.
void add_stage_latency_sample(txn_stage_t stage,
void add_stage_latency_sample(
std::array<seastar::metrics::histogram, STAGE_MAX>& arr,
txn_stage_t stage,
std::chrono::steady_clock::duration dur) {
auto& hist = stats.stage_lat[static_cast<std::size_t>(stage)];
auto& hist = arr[static_cast<std::size_t>(stage)];
if (hist.buckets.empty()) {
// register_metrics() did not run (store inactive); nothing to record.
return;