From 051d25250b55c215a2254a0130d46fbd38bcbcc0 Mon Sep 17 00:00:00 2001 From: David Howells Date: Thu, 20 Jun 2019 18:12:16 +0100 Subject: [PATCH] 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 --- fs/afs/callback.c | 16 ++++++++--- fs/afs/dir.c | 4 +-- fs/afs/inode.c | 17 +++++++----- fs/afs/internal.h | 8 +++--- include/trace/events/afs.h | 69 ++++++++++++++++++++++++++++++++++++++++++++++ 5 files changed, 97 insertions(+), 17 deletions(-) diff --git a/fs/afs/callback.c b/fs/afs/callback.c index 9150104..d66cd03 100644 --- 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..e8c58c94 100644 --- 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 --- 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 --- 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 --- 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 */ -- 2.7.4