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 <ian.ziemba@hpe.com>
Change-Id: I5506329086e6284e04ec7b609485d582a35ca0b5
Reviewed-on: https://review.whamcloud.com/c/fs/lustre-release/+/51784
Tested-by: jenkins <devops@whamcloud.com>
Tested-by: Maloo <maloo@whamcloud.com>
Reviewed-by: Ron Gredvig <ron.gredvig@hpe.com>
Reviewed-by: Oleg Drokin <green@whamcloud.com>

diff --git a/lnet/klnds/kfilnd/kfilnd.h b/lnet/klnds/kfilnd/kfilnd.h
index 3e26405..cead25b 100644 (file)
--- 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 (file)
--- 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 (file)
--- 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 2fa0a25..a895579 100644 (file)
--- 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);
 }
 
 /**