From: Ian Ziemba Date: Wed, 22 Feb 2023 23:56:21 +0000 (-0600) Subject: LU-16992 kfilnd: Expand debugfs to record min/max X-Git-Tag: 2.15.58~87 X-Git-Url: https://git.whamcloud.com/?a=commitdiff_plain;h=d6fce67afdc120683215cbebd50dec109bc2c1e0;p=fs%2Flustre-release.git LU-16992 kfilnd: Expand debugfs to record min/max This will be useful in determining how long kfilnd transactions take when underlying NIC gets congested. Test-Parameters: trivial HPE-bug-id: LUS-11497 Signed-off-by: Ian Ziemba Change-Id: I5506329086e6284e04ec7b609485d582a35ca0b5 Reviewed-on: https://review.whamcloud.com/c/fs/lustre-release/+/51784 Tested-by: jenkins Tested-by: Maloo Reviewed-by: Ron Gredvig Reviewed-by: Oleg Drokin --- diff --git a/lnet/klnds/kfilnd/kfilnd.h b/lnet/klnds/kfilnd/kfilnd.h index 3e26405..cead25b 100644 --- a/lnet/klnds/kfilnd/kfilnd.h +++ b/lnet/klnds/kfilnd/kfilnd.h @@ -122,6 +122,8 @@ #define KFILND_BASE_ADDR(addr) \ ((addr) & ((1UL << (64 - KFILND_FAB_RX_CTX_BITS)) - 1)) +#define MIN_DURATION_RESET 0x7fffffffffffffffLL + /* States used by all kfilnd structures */ enum kfilnd_object_states { KFILND_STATE_UNINITIALIZED, @@ -368,6 +370,8 @@ enum tn_states { struct kfilnd_tn_duration_stat { atomic64_t accumulated_duration; atomic_t accumulated_count; + atomic64_t max_duration; + atomic64_t min_duration; }; /* Transaction state stats group into 22 buckets. Bucket zero corresponds to diff --git a/lnet/klnds/kfilnd/kfilnd_debugfs.c b/lnet/klnds/kfilnd/kfilnd_debugfs.c index 21504c5..43f6525 100644 --- a/lnet/klnds/kfilnd/kfilnd_debugfs.c +++ b/lnet/klnds/kfilnd/kfilnd_debugfs.c @@ -32,7 +32,7 @@ #include "kfilnd_dev.h" #define TIME_MAX 0xFFFFFFFFFFFF -static s64 print_duration(struct kfilnd_tn_duration_stat *stat) +static s64 get_ave_duration(struct kfilnd_tn_duration_stat *stat) { s64 duration; @@ -45,6 +45,16 @@ static s64 print_duration(struct kfilnd_tn_duration_stat *stat) return min_t(s64, duration, TIME_MAX); } +static s64 get_min_duration(struct kfilnd_tn_duration_stat *stat) +{ + s64 min; + + min = atomic64_read(&stat->min_duration); + if (min == MIN_DURATION_RESET) + return 0; + return min; +} + static void seq_print_tn_state_stats(struct seq_file *s, struct kfilnd_dev *dev, bool initiator) { @@ -65,18 +75,18 @@ static void seq_print_tn_state_stats(struct seq_file *s, struct kfilnd_dev *dev, for (data_size = 0; data_size < KFILND_DATA_SIZE_BUCKETS; data_size++) { seq_printf(s, "%-20lu %-20llu %-20llu %-20llu %-20llu %-20llu %-20llu %-20llu %-20llu %-20llu %-20llu %-20llu %-20llu\n", data_size == 0 ? 0 : BIT(data_size - 1), - print_duration(&state_stats->state[TN_STATE_IDLE].data_size[data_size]), - print_duration(&state_stats->state[TN_STATE_WAIT_TAG_COMP].data_size[data_size]), - print_duration(&state_stats->state[TN_STATE_IMM_SEND].data_size[data_size]), - print_duration(&state_stats->state[TN_STATE_TAGGED_RECV_POSTED].data_size[data_size]), - print_duration(&state_stats->state[TN_STATE_SEND_FAILED].data_size[data_size]), - print_duration(&state_stats->state[TN_STATE_WAIT_COMP].data_size[data_size]), - print_duration(&state_stats->state[TN_STATE_WAIT_TIMEOUT_COMP].data_size[data_size]), - print_duration(&state_stats->state[TN_STATE_WAIT_SEND_COMP].data_size[data_size]), - print_duration(&state_stats->state[TN_STATE_WAIT_TIMEOUT_TAG_COMP].data_size[data_size]), - print_duration(&state_stats->state[TN_STATE_FAIL].data_size[data_size]), - print_duration(&state_stats->state[TN_STATE_IMM_RECV].data_size[data_size]), - print_duration(&state_stats->state[TN_STATE_WAIT_TAG_RMA_COMP].data_size[data_size])); + get_ave_duration(&state_stats->state[TN_STATE_IDLE].data_size[data_size]), + get_ave_duration(&state_stats->state[TN_STATE_WAIT_TAG_COMP].data_size[data_size]), + get_ave_duration(&state_stats->state[TN_STATE_IMM_SEND].data_size[data_size]), + get_ave_duration(&state_stats->state[TN_STATE_TAGGED_RECV_POSTED].data_size[data_size]), + get_ave_duration(&state_stats->state[TN_STATE_SEND_FAILED].data_size[data_size]), + get_ave_duration(&state_stats->state[TN_STATE_WAIT_COMP].data_size[data_size]), + get_ave_duration(&state_stats->state[TN_STATE_WAIT_TIMEOUT_COMP].data_size[data_size]), + get_ave_duration(&state_stats->state[TN_STATE_WAIT_SEND_COMP].data_size[data_size]), + get_ave_duration(&state_stats->state[TN_STATE_WAIT_TIMEOUT_TAG_COMP].data_size[data_size]), + get_ave_duration(&state_stats->state[TN_STATE_FAIL].data_size[data_size]), + get_ave_duration(&state_stats->state[TN_STATE_IMM_RECV].data_size[data_size]), + get_ave_duration(&state_stats->state[TN_STATE_WAIT_TAG_RMA_COMP].data_size[data_size])); } } @@ -137,12 +147,15 @@ static void seq_print_tn_stats(struct seq_file *s, struct kfilnd_dev *dev, else stats = &dev->target_stats; - seq_printf(s, "%-16s %-16s\n", "MSG_SIZE", "DURATION"); + seq_printf(s, "%16s %16s %16s %16s\n", "MSG_SIZE", "MIN", "MAX", + "AVE"); for (data_size = 0; data_size < KFILND_DATA_SIZE_BUCKETS; data_size++) { - seq_printf(s, "%-16lu %-16llu\n", + seq_printf(s, "%16lu %16llu %16llu %16llu\n", data_size == 0 ? 0 : BIT(data_size - 1), - print_duration(&stats->data_size[data_size])); + get_min_duration(&stats->data_size[data_size]), + atomic64_read(&stats->data_size[data_size].max_duration), + get_ave_duration(&stats->data_size[data_size])); } } diff --git a/lnet/klnds/kfilnd/kfilnd_dev.c b/lnet/klnds/kfilnd/kfilnd_dev.c index a1a3059..3f20036 100644 --- a/lnet/klnds/kfilnd/kfilnd_dev.c +++ b/lnet/klnds/kfilnd/kfilnd_dev.c @@ -304,7 +304,6 @@ err: return ERR_PTR(rc); } - void kfilnd_dev_reset_stats(struct kfilnd_dev *dev) { unsigned int data_size; @@ -315,19 +314,27 @@ void kfilnd_dev_reset_stats(struct kfilnd_dev *dev) stat = &dev->initiator_stats.data_size[data_size]; atomic64_set(&stat->accumulated_duration, 0); atomic_set(&stat->accumulated_count, 0); + atomic64_set(&stat->max_duration, 0); + atomic64_set(&stat->min_duration, MIN_DURATION_RESET); stat = &dev->target_stats.data_size[data_size]; atomic64_set(&stat->accumulated_duration, 0); atomic_set(&stat->accumulated_count, 0); + atomic64_set(&stat->max_duration, 0); + atomic64_set(&stat->min_duration, MIN_DURATION_RESET); for (state = 0; state < TN_STATE_MAX; state++) { stat = &dev->initiator_state_stats.state[state].data_size[data_size]; atomic64_set(&stat->accumulated_duration, 0); atomic_set(&stat->accumulated_count, 0); + atomic64_set(&stat->max_duration, 0); + atomic64_set(&stat->min_duration, MIN_DURATION_RESET); stat = &dev->target_state_stats.state[state].data_size[data_size]; atomic64_set(&stat->accumulated_duration, 0); atomic_set(&stat->accumulated_count, 0); + atomic64_set(&stat->max_duration, 0); + atomic64_set(&stat->min_duration, MIN_DURATION_RESET); } } } diff --git a/lnet/klnds/kfilnd/kfilnd_tn.c b/lnet/klnds/kfilnd/kfilnd_tn.c index 2fa0a25c..a895579 100644 --- a/lnet/klnds/kfilnd/kfilnd_tn.c +++ b/lnet/klnds/kfilnd/kfilnd_tn.c @@ -266,15 +266,29 @@ static void kfilnd_tn_record_state_change(struct kfilnd_transaction *tn) unsigned int data_size_bucket = kfilnd_msg_len_to_data_size_bucket(tn->lnet_msg_len); struct kfilnd_tn_duration_stat *stat; + s64 time; + s64 cur; if (tn->is_initiator) stat = &tn->tn_ep->end_dev->initiator_state_stats.state[tn->tn_state].data_size[data_size_bucket]; else stat = &tn->tn_ep->end_dev->target_state_stats.state[tn->tn_state].data_size[data_size_bucket]; - atomic64_add(ktime_to_ns(ktime_sub(ktime_get(), tn->tn_state_ts)), - &stat->accumulated_duration); + time = ktime_to_ns(ktime_sub(ktime_get(), tn->tn_state_ts)); + atomic64_add(time, &stat->accumulated_duration); atomic_inc(&stat->accumulated_count); + + do { + cur = atomic64_read(&stat->max_duration); + if (time <= cur) + break; + } while (atomic64_cmpxchg(&stat->max_duration, cur, time) != cur); + + do { + cur = atomic64_read(&stat->min_duration); + if (time >= cur) + break; + } while (atomic64_cmpxchg(&stat->min_duration, cur, time) != cur); } static void kfilnd_tn_state_change(struct kfilnd_transaction *tn, @@ -388,15 +402,29 @@ static void kfilnd_tn_record_duration(struct kfilnd_transaction *tn) unsigned int data_size_bucket = kfilnd_msg_len_to_data_size_bucket(tn->lnet_msg_len); struct kfilnd_tn_duration_stat *stat; + s64 time; + s64 cur; if (tn->is_initiator) stat = &tn->tn_ep->end_dev->initiator_stats.data_size[data_size_bucket]; else stat = &tn->tn_ep->end_dev->target_stats.data_size[data_size_bucket]; - atomic64_add(ktime_to_ns(ktime_sub(ktime_get(), tn->tn_alloc_ts)), - &stat->accumulated_duration); + time = ktime_to_ns(ktime_sub(ktime_get(), tn->tn_alloc_ts)); + atomic64_add(time, &stat->accumulated_duration); atomic_inc(&stat->accumulated_count); + + do { + cur = atomic64_read(&stat->max_duration); + if (time <= cur) + break; + } while (atomic64_cmpxchg(&stat->max_duration, cur, time) != cur); + + do { + cur = atomic64_read(&stat->min_duration); + if (time >= cur) + break; + } while (atomic64_cmpxchg(&stat->min_duration, cur, time) != cur); } /**