diff --git a/kmod/src/lock_server.c b/kmod/src/lock_server.c index 43c1391c..30dacaa8 100644 --- a/kmod/src/lock_server.c +++ b/kmod/src/lock_server.c @@ -626,9 +626,14 @@ out: int scoutfs_lock_server_greeting(struct super_block *sb, u64 rid) { struct scoutfs_key key; + bool pending; int ret; - if (scoutfs_recov_is_pending(sb, rid, SCOUTFS_RECOV_LOCKS)) { + pending = scoutfs_recov_is_pending(sb, rid, SCOUTFS_RECOV_LOCKS); + + trace_scoutfs_lock_server_greeting(sb, rid, pending); + + if (pending) { scoutfs_key_set_zeros(&key); ret = scoutfs_server_lock_recover_request(sb, rid, &key); } else { diff --git a/kmod/src/recov.c b/kmod/src/recov.c index a9e33f68..e8d79b4b 100644 --- a/kmod/src/recov.c +++ b/kmod/src/recov.c @@ -21,6 +21,7 @@ #include "super.h" #include "recov.h" #include "cmp.h" +#include "scoutfs_trace.h" /* * There are a few server messages which can't be processed until they @@ -119,6 +120,9 @@ int scoutfs_recov_prepare(struct super_block *sb, u64 rid, int which) spin_unlock_bh(&recinf->lock); kfree(alloc); + + trace_scoutfs_recov_prepare(sb, rid, which); + return 0; } @@ -135,6 +139,15 @@ static int recov_finished(struct recov_info *recinf) static void timer_callback(struct timer_list *timer) { struct recov_info *recinf = timer_container_of(recinf, timer, timer); + struct recov_pending *pend; + int nr = 0; + + spin_lock(&recinf->lock); + list_for_each_entry(pend, &recinf->pending, head) + nr++; + spin_unlock(&recinf->lock); + + trace_scoutfs_recov_timeout_fire(recinf->sb, nr); recinf->timeout_fn(recinf->sb); } @@ -181,6 +194,8 @@ int scoutfs_recov_finish(struct super_block *sb, u64 rid, int which) { DECLARE_RECOV_INFO(sb, recinf); struct recov_pending *pend; + struct recov_pending *iter; + int remaining = 0; int ret = 0; spin_lock_bh(&recinf->lock); @@ -196,8 +211,13 @@ int scoutfs_recov_finish(struct super_block *sb, u64 rid, int which) } } + list_for_each_entry(iter, &recinf->pending, head) + remaining++; + spin_unlock_bh(&recinf->lock); + trace_scoutfs_recov_finish(sb, rid, which, remaining); + if (ret > 0) del_timer_sync(&recinf->timer); diff --git a/kmod/src/scoutfs_trace.h b/kmod/src/scoutfs_trace.h index c7157352..d53be675 100644 --- a/kmod/src/scoutfs_trace.h +++ b/kmod/src/scoutfs_trace.h @@ -2121,6 +2121,110 @@ DEFINE_EVENT(scoutfs_server_client_count_class, scoutfs_server_client_down, TP_ARGS(sb, rid, nr_clients) ); +TRACE_EVENT(scoutfs_recov_prepare, + TP_PROTO(struct super_block *sb, u64 rid, int which), + + TP_ARGS(sb, rid, which), + + TP_STRUCT__entry( + SCSB_TRACE_FIELDS + __field(__u64, c_rid) + __field(int, which) + ), + + TP_fast_assign( + SCSB_TRACE_ASSIGN(sb); + __entry->c_rid = rid; + __entry->which = which; + ), + + TP_printk(SCSBF" rid %016llx which 0x%x", + SCSB_TRACE_ARGS, __entry->c_rid, __entry->which) +); + +TRACE_EVENT(scoutfs_recov_finish, + TP_PROTO(struct super_block *sb, u64 rid, int which, int remaining), + + TP_ARGS(sb, rid, which, remaining), + + TP_STRUCT__entry( + SCSB_TRACE_FIELDS + __field(__u64, c_rid) + __field(int, which) + __field(int, remaining) + ), + + TP_fast_assign( + SCSB_TRACE_ASSIGN(sb); + __entry->c_rid = rid; + __entry->which = which; + __entry->remaining = remaining; + ), + + TP_printk(SCSBF" rid %016llx which 0x%x remaining %d", + SCSB_TRACE_ARGS, __entry->c_rid, __entry->which, + __entry->remaining) +); + +TRACE_EVENT(scoutfs_recov_timeout_fire, + TP_PROTO(struct super_block *sb, int nr_pending), + + TP_ARGS(sb, nr_pending), + + TP_STRUCT__entry( + SCSB_TRACE_FIELDS + __field(int, nr_pending) + ), + + TP_fast_assign( + SCSB_TRACE_ASSIGN(sb); + __entry->nr_pending = nr_pending; + ), + + TP_printk(SCSBF" nr_pending %d", + SCSB_TRACE_ARGS, __entry->nr_pending) +); + +TRACE_EVENT(scoutfs_recov_fence_rid, + TP_PROTO(struct super_block *sb, u64 rid), + + TP_ARGS(sb, rid), + + TP_STRUCT__entry( + SCSB_TRACE_FIELDS + __field(__u64, c_rid) + ), + + TP_fast_assign( + SCSB_TRACE_ASSIGN(sb); + __entry->c_rid = rid; + ), + + TP_printk(SCSBF" rid %016llx", + SCSB_TRACE_ARGS, __entry->c_rid) +); + +TRACE_EVENT(scoutfs_lock_server_greeting, + TP_PROTO(struct super_block *sb, u64 rid, bool recov_pending), + + TP_ARGS(sb, rid, recov_pending), + + TP_STRUCT__entry( + SCSB_TRACE_FIELDS + __field(__u64, c_rid) + __field(bool, recov_pending) + ), + + TP_fast_assign( + SCSB_TRACE_ASSIGN(sb); + __entry->c_rid = rid; + __entry->recov_pending = recov_pending; + ), + + TP_printk(SCSBF" rid %016llx recov_pending %d", + SCSB_TRACE_ARGS, __entry->c_rid, __entry->recov_pending) +); + DECLARE_EVENT_CLASS(scoutfs_server_commit_users_class, TP_PROTO(struct super_block *sb, int holding, int applying, int nr_holders, u32 budget, diff --git a/kmod/src/server.c b/kmod/src/server.c index ddf405b8..cfe9b782 100644 --- a/kmod/src/server.c +++ b/kmod/src/server.c @@ -4386,6 +4386,8 @@ static void fence_pending_recov_worker(struct work_struct *work) scoutfs_err(sb, "%lu ms recovery timeout expired for client rid %016llx, fencing", SERVER_RECOV_TIMEOUT_MS, rid); + trace_scoutfs_recov_fence_rid(sb, rid); + ret = lookup_mounted_client_addr(sb, rid, &addr); if (ret < 0) { scoutfs_err(sb, "client rid addr lookup err %d, shutting down server", ret);