On Thu, Jun 26, 2025 at 08:48:57AM +1000, Dave Chinner wrote:
> From: Dave Chinner <dchinner@xxxxxxxxxx>
>
> I needed more insight into how stale inodes were getting stuck on
> the AIL after a forced shutdown when running fsstress. These are the
> tracepoints I added for that purpose.
>
> Signed-off-by: Dave Chinner <dchinner@xxxxxxxxxx>
I actually used something similar recently, (although temporarily with
trace_printk), I can see how useful those can be.
Reviewed-by: Carlos Maiolino <cmaiolino@xxxxxxxxxx>
> ---
> fs/xfs/xfs_inode_item.c | 5 ++++-
> fs/xfs/xfs_log_cil.c | 4 +++-
> fs/xfs/xfs_trace.h | 9 ++++++++-
> fs/xfs/xfs_trans.c | 4 +++-
> 4 files changed, 18 insertions(+), 4 deletions(-)
>
> diff --git a/fs/xfs/xfs_inode_item.c b/fs/xfs/xfs_inode_item.c
> index c6cb0b6b9e46..285e27ff89e2 100644
> --- a/fs/xfs/xfs_inode_item.c
> +++ b/fs/xfs/xfs_inode_item.c
> @@ -758,11 +758,14 @@ xfs_inode_item_push(
> * completed and items removed from the AIL before the next push
> * attempt.
> */
> + trace_xfs_inode_push_stale(ip, _RET_IP_);
> return XFS_ITEM_PINNED;
> }
>
> - if (xfs_ipincount(ip) > 0 || xfs_buf_ispinned(bp))
> + if (xfs_ipincount(ip) > 0 || xfs_buf_ispinned(bp)) {
> + trace_xfs_inode_push_pinned(ip, _RET_IP_);
> return XFS_ITEM_PINNED;
> + }
>
> if (xfs_iflags_test(ip, XFS_IFLUSHING))
> return XFS_ITEM_FLUSHING;
> diff --git a/fs/xfs/xfs_log_cil.c b/fs/xfs/xfs_log_cil.c
> index f66d2d430e4f..a80cb6b9969a 100644
> --- a/fs/xfs/xfs_log_cil.c
> +++ b/fs/xfs/xfs_log_cil.c
> @@ -793,8 +793,10 @@ xlog_cil_ail_insert(
> struct xfs_log_item *lip = lv->lv_item;
> xfs_lsn_t item_lsn;
>
> - if (aborted)
> + if (aborted) {
> + trace_xlog_ail_insert_abort(lip);
> set_bit(XFS_LI_ABORTED, &lip->li_flags);
> + }
>
> if (lip->li_ops->flags & XFS_ITEM_RELEASE_WHEN_COMMITTED) {
> lip->li_ops->iop_release(lip);
> diff --git a/fs/xfs/xfs_trace.h b/fs/xfs/xfs_trace.h
> index 9f0d6bc966b7..ba45d801df1c 100644
> --- a/fs/xfs/xfs_trace.h
> +++ b/fs/xfs/xfs_trace.h
> @@ -1146,6 +1146,7 @@ DECLARE_EVENT_CLASS(xfs_iref_class,
> __field(xfs_ino_t, ino)
> __field(int, count)
> __field(int, pincount)
> + __field(unsigned long, iflags)
> __field(unsigned long, caller_ip)
> ),
> TP_fast_assign(
> @@ -1153,13 +1154,15 @@ DECLARE_EVENT_CLASS(xfs_iref_class,
> __entry->ino = ip->i_ino;
> __entry->count = atomic_read(&VFS_I(ip)->i_count);
> __entry->pincount = atomic_read(&ip->i_pincount);
> + __entry->iflags = ip->i_flags;
> __entry->caller_ip = caller_ip;
> ),
> - TP_printk("dev %d:%d ino 0x%llx count %d pincount %d caller %pS",
> + TP_printk("dev %d:%d ino 0x%llx count %d pincount %d iflags 0x%lx caller %pS",
> MAJOR(__entry->dev), MINOR(__entry->dev),
> __entry->ino,
> __entry->count,
> __entry->pincount,
> + __entry->iflags,
> (char *)__entry->caller_ip)
> )
>
> @@ -1249,6 +1252,8 @@ DEFINE_IREF_EVENT(xfs_irele);
> DEFINE_IREF_EVENT(xfs_inode_pin);
> DEFINE_IREF_EVENT(xfs_inode_unpin);
> DEFINE_IREF_EVENT(xfs_inode_unpin_nowait);
> +DEFINE_IREF_EVENT(xfs_inode_push_pinned);
> +DEFINE_IREF_EVENT(xfs_inode_push_stale);
>
> DECLARE_EVENT_CLASS(xfs_namespace_class,
> TP_PROTO(struct xfs_inode *dp, const struct xfs_name *name),
> @@ -1653,6 +1658,8 @@ DEFINE_LOG_ITEM_EVENT(xfs_ail_flushing);
> DEFINE_LOG_ITEM_EVENT(xfs_cil_whiteout_mark);
> DEFINE_LOG_ITEM_EVENT(xfs_cil_whiteout_skip);
> DEFINE_LOG_ITEM_EVENT(xfs_cil_whiteout_unpin);
> +DEFINE_LOG_ITEM_EVENT(xlog_ail_insert_abort);
> +DEFINE_LOG_ITEM_EVENT(xfs_trans_free_abort);
>
> DECLARE_EVENT_CLASS(xfs_ail_class,
> TP_PROTO(struct xfs_log_item *lip, xfs_lsn_t old_lsn, xfs_lsn_t new_lsn),
> diff --git a/fs/xfs/xfs_trans.c b/fs/xfs/xfs_trans.c
> index c6657072361a..b4a07af513ba 100644
> --- a/fs/xfs/xfs_trans.c
> +++ b/fs/xfs/xfs_trans.c
> @@ -742,8 +742,10 @@ xfs_trans_free_items(
>
> list_for_each_entry_safe(lip, next, &tp->t_items, li_trans) {
> xfs_trans_del_item(lip);
> - if (abort)
> + if (abort) {
> + trace_xfs_trans_free_abort(lip);
> set_bit(XFS_LI_ABORTED, &lip->li_flags);
> + }
> if (lip->li_ops->iop_release)
> lip->li_ops->iop_release(lip);
> }
> --
> 2.45.2
>
>
