afs: Add some callback management tracepoints

Add a couple of tracepoints to track callback management:

 (1) afs_cb_miss - Logs when we were unable to apply a callback, either due
     to the inode being discarded or due to a competing thread applying a
     callback first.

 (2) afs_cb_break - Logs when we attempted to clear the noted callback
     promise, either due to the server explicitly breaking the callback,
     the callback promise lapsing or a local event obsoleting it.

Signed-off-by: David Howells <dhowells@redhat.com>

diff --git a/fs/afs/callback.c b/fs/afs/callback.c
index 9150104..d66cd03 100644 (file)
--- a/fs/afs/callback.c
+++ b/fs/afs/callback.c
@@ -212,7 +212,7 @@ void afs_init_callback_state(struct afs_server *server)
 /*
  * actually break a callback
  */
-void __afs_break_callback(struct afs_vnode *vnode)
+void __afs_break_callback(struct afs_vnode *vnode, enum afs_cb_break_reason reason)
 {
        _enter("");
 
@@ -223,13 +223,17 @@ void __afs_break_callback(struct afs_vnode *vnode)
 
                if (vnode->lock_state == AFS_VNODE_LOCK_WAITING_FOR_CB)
                        afs_lock_may_be_available(vnode);
+
+               trace_afs_cb_break(&vnode->fid, vnode->cb_break, reason, true);
+       } else {
+               trace_afs_cb_break(&vnode->fid, vnode->cb_break, reason, false);
        }
 }
 
-void afs_break_callback(struct afs_vnode *vnode)
+void afs_break_callback(struct afs_vnode *vnode, enum afs_cb_break_reason reason)
 {
        write_seqlock(&vnode->cb_lock);
-       __afs_break_callback(vnode);
+       __afs_break_callback(vnode, reason);
        write_sequnlock(&vnode->cb_lock);
 }
 
@@ -277,6 +281,8 @@ static void afs_break_one_callback(struct afs_server *server,
 
                        write_lock(&volume->cb_v_break_lock);
                        volume->cb_v_break++;
+                       trace_afs_cb_break(fid, volume->cb_v_break,
+                                          afs_cb_break_for_volume_callback, false);
                        write_unlock(&volume->cb_v_break_lock);
                } else {
                        data.volume = NULL;
@@ -285,8 +291,10 @@ static void afs_break_one_callback(struct afs_server *server,
                                                afs_iget5_test, &data);
                        if (inode) {
                                vnode = AFS_FS_I(inode);
-                               afs_break_callback(vnode);
+                               afs_break_callback(vnode, afs_cb_break_for_callback);
                                iput(inode);
+                       } else {
+                               trace_afs_cb_miss(fid, afs_cb_break_for_callback);
                        }
                }
        }

diff --git a/fs/afs/dir.c b/fs/afs/dir.c
index 93fd51c..e8c58c9 100644 (file)
--- a/fs/afs/dir.c
+++ b/fs/afs/dir.c
@@ -1367,12 +1367,12 @@ static int afs_dir_remove_link(struct afs_vnode *dvnode, struct dentry *dentry,
                        drop_nlink(&vnode->vfs_inode);
                        if (vnode->vfs_inode.i_nlink == 0) {
                                set_bit(AFS_VNODE_DELETED, &vnode->flags);
-                               __afs_break_callback(vnode);
+                               __afs_break_callback(vnode, afs_cb_break_for_unlink);
                        }
                        write_sequnlock(&vnode->cb_lock);
                        ret = 0;
                } else {
-                       afs_break_callback(vnode);
+                       afs_break_callback(vnode, afs_cb_break_for_unlink);
 
                        if (test_bit(AFS_VNODE_DELETED, &vnode->flags))
                                kdebug("AFS_VNODE_DELETED");

diff --git a/fs/afs/inode.c b/fs/afs/inode.c
index 18a50d4..7b1c18c 100644 (file)
--- a/fs/afs/inode.c
+++ b/fs/afs/inode.c
@@ -283,7 +283,7 @@ void afs_vnode_commit_status(struct afs_fs_cursor *fc,
                if (scb->status.abort_code == VNOVNODE) {
                        set_bit(AFS_VNODE_DELETED, &vnode->flags);
                        clear_nlink(&vnode->vfs_inode);
-                       __afs_break_callback(vnode);
+                       __afs_break_callback(vnode, afs_cb_break_for_deleted);
                }
        } else {
                if (scb->have_status)
@@ -594,8 +594,9 @@ bool afs_check_validity(struct afs_vnode *vnode)
        struct afs_cb_interest *cbi;
        struct afs_server *server;
        struct afs_volume *volume = vnode->volume;
+       enum afs_cb_break_reason need_clear = afs_cb_break_no_break;
        time64_t now = ktime_get_real_seconds();
-       bool valid, need_clear = false;
+       bool valid;
        unsigned int cb_break, cb_s_break, cb_v_break;
        int seq = 0;
 
@@ -613,13 +614,13 @@ bool afs_check_validity(struct afs_vnode *vnode)
                            vnode->cb_v_break != cb_v_break) {
                                vnode->cb_s_break = cb_s_break;
                                vnode->cb_v_break = cb_v_break;
-                               need_clear = true;
+                               need_clear = afs_cb_break_for_vsbreak;
                                valid = false;
                        } else if (test_bit(AFS_VNODE_ZAP_DATA, &vnode->flags)) {
-                               need_clear = true;
+                               need_clear = afs_cb_break_for_zap;
                                valid = false;
                        } else if (vnode->cb_expires_at - 10 <= now) {
-                               need_clear = true;
+                               need_clear = afs_cb_break_for_lapsed;
                                valid = false;
                        } else {
                                valid = true;
@@ -635,10 +636,12 @@ bool afs_check_validity(struct afs_vnode *vnode)
 
        done_seqretry(&vnode->cb_lock, seq);
 
-       if (need_clear) {
+       if (need_clear != afs_cb_break_no_break) {
                write_seqlock(&vnode->cb_lock);
                if (cb_break == vnode->cb_break)
-                       __afs_break_callback(vnode);
+                       __afs_break_callback(vnode, need_clear);
+               else
+                       trace_afs_cb_miss(&vnode->fid, need_clear);
                write_sequnlock(&vnode->cb_lock);
                valid = false;
        }

diff --git a/fs/afs/internal.h b/fs/afs/internal.h
index 8252d69..4d9b3e9 100644 (file)
--- a/fs/afs/internal.h
+++ b/fs/afs/internal.h
@@ -848,9 +848,9 @@ extern struct fscache_cookie_def afs_vnode_cache_index_def;
  * callback.c
  */
 extern void afs_init_callback_state(struct afs_server *);
-extern void __afs_break_callback(struct afs_vnode *);
-extern void afs_break_callback(struct afs_vnode *);
-extern void afs_break_callbacks(struct afs_server *, size_t, struct afs_callback_break*);
+extern void __afs_break_callback(struct afs_vnode *, enum afs_cb_break_reason);
+extern void afs_break_callback(struct afs_vnode *, enum afs_cb_break_reason);
+extern void afs_break_callbacks(struct afs_server *, size_t, struct afs_callback_break *);
 
 extern int afs_register_server_cb_interest(struct afs_vnode *,
                                           struct afs_server_list *, unsigned int);
@@ -1438,7 +1438,7 @@ static inline void afs_check_for_remote_deletion(struct afs_fs_cursor *fc,
 {
        if (fc->ac.error == -ENOENT) {
                set_bit(AFS_VNODE_DELETED, &vnode->flags);
-               afs_break_callback(vnode);
+               afs_break_callback(vnode, afs_cb_break_for_deleted);
        }
 }
 

diff --git a/include/trace/events/afs.h b/include/trace/events/afs.h
index 562f854..34628e2 100644 (file)
--- a/include/trace/events/afs.h
+++ b/include/trace/events/afs.h
@@ -195,6 +195,17 @@ enum afs_flock_operation {
        afs_flock_op_wake,
 };
 
+enum afs_cb_break_reason {
+       afs_cb_break_no_break,
+       afs_cb_break_for_callback,
+       afs_cb_break_for_deleted,
+       afs_cb_break_for_lapsed,
+       afs_cb_break_for_unlink,
+       afs_cb_break_for_vsbreak,
+       afs_cb_break_for_volume_callback,
+       afs_cb_break_for_zap,
+};
+
 #endif /* end __AFS_DECLARE_TRACE_ENUMS_ONCE_ONLY */
 
 /*
@@ -374,6 +385,16 @@ enum afs_flock_operation {
        EM(afs_flock_op_unlock,                 "UNLOCK  ")             \
        E_(afs_flock_op_wake,                   "WAKE    ")
 
+#define afs_cb_break_reasons                                           \
+       EM(afs_cb_break_no_break,               "no-break")             \
+       EM(afs_cb_break_for_callback,           "break-cb")             \
+       EM(afs_cb_break_for_deleted,            "break-del")            \
+       EM(afs_cb_break_for_lapsed,             "break-lapsed")         \
+       EM(afs_cb_break_for_unlink,             "break-unlink")         \
+       EM(afs_cb_break_for_vsbreak,            "break-vs")             \
+       EM(afs_cb_break_for_volume_callback,    "break-v-cb")           \
+       E_(afs_cb_break_for_zap,                "break-zap")
+
 /*
  * Export enum symbols via userspace.
  */
@@ -392,6 +413,7 @@ afs_io_errors;
 afs_file_errors;
 afs_flock_types;
 afs_flock_operations;
+afs_cb_break_reasons;
 
 /*
  * Now redefine the EM() and E_() macros to map the enums to the strings that
@@ -1171,6 +1193,53 @@ TRACE_EVENT(afs_get_tree,
                      __entry->cell, __entry->volume, __entry->vid)
            );
 
+TRACE_EVENT(afs_cb_break,
+           TP_PROTO(struct afs_fid *fid, unsigned int cb_break,
+                    enum afs_cb_break_reason reason, bool skipped),
+
+           TP_ARGS(fid, cb_break, reason, skipped),
+
+           TP_STRUCT__entry(
+                   __field_struct(struct afs_fid,      fid             )
+                   __field(unsigned int,               cb_break        )
+                   __field(enum afs_cb_break_reason,   reason          )
+                   __field(bool,                       skipped         )
+                            ),
+
+           TP_fast_assign(
+                   __entry->fid        = *fid;
+                   __entry->cb_break   = cb_break;
+                   __entry->reason     = reason;
+                   __entry->skipped    = skipped;
+                          ),
+
+           TP_printk("%llx:%llx:%x b=%x s=%u %s",
+                     __entry->fid.vid, __entry->fid.vnode, __entry->fid.unique,
+                     __entry->cb_break,
+                     __entry->skipped,
+                     __print_symbolic(__entry->reason, afs_cb_break_reasons))
+           );
+
+TRACE_EVENT(afs_cb_miss,
+           TP_PROTO(struct afs_fid *fid, enum afs_cb_break_reason reason),
+
+           TP_ARGS(fid, reason),
+
+           TP_STRUCT__entry(
+                   __field_struct(struct afs_fid,      fid             )
+                   __field(enum afs_cb_break_reason,   reason          )
+                            ),
+
+           TP_fast_assign(
+                   __entry->fid        = *fid;
+                   __entry->reason     = reason;
+                          ),
+
+           TP_printk(" %llx:%llx:%x %s",
+                     __entry->fid.vid, __entry->fid.vnode, __entry->fid.unique,
+                     __print_symbolic(__entry->reason, afs_cb_break_reasons))
+           );
+
 #endif /* _TRACE_AFS_H */
 
 /* This part must be outside protection */