Re: [PATCH v6 2/9] fs: tracepoints around multigrain timestamp events

From: Darrick J. Wong
Date: Mon Jul 15 2024 - 14:29:30 EST

On Mon, Jul 15, 2024 at 08:48:53AM -0400, Jeff Layton wrote:
> Add some tracepoints around various multigrain timestamp events.
>
> Reviewed-by: Josef Bacik <josef@xxxxxxxxxxxxxx>
> Signed-off-by: Jeff Layton <jlayton@xxxxxxxxxx>

Woot!
Reviewed-by: Darrick J. Wong <djwong@xxxxxxxxxx>

--D

> ---
> fs/inode.c | 9 ++-
> fs/stat.c | 3 +
> include/trace/events/timestamp.h | 124 +++++++++++++++++++++++++++++++++++++++
> 3 files changed, 135 insertions(+), 1 deletion(-)
>
> diff --git a/fs/inode.c b/fs/inode.c
> index 417acbeabef3..869994285e87 100644
> --- a/fs/inode.c
> +++ b/fs/inode.c
> @@ -22,6 +22,9 @@
> #include <linux/iversion.h>
> #include <linux/rw_hint.h>
> #include <trace/events/writeback.h>
> +#define CREATE_TRACE_POINTS
> +#include <trace/events/timestamp.h>
> +
> #include "internal.h"
>
> /*
> @@ -2569,6 +2572,7 @@ EXPORT_SYMBOL(inode_nohighmem);
>
> struct timespec64 inode_set_ctime_to_ts(struct inode *inode, struct timespec64 ts)
> {
> + trace_inode_set_ctime_to_ts(inode, &ts);
> set_normalized_timespec64(&ts, ts.tv_sec, ts.tv_nsec);
> inode->i_ctime_sec = ts.tv_sec;
> inode->i_ctime_nsec = ts.tv_nsec;
> @@ -2668,13 +2672,16 @@ struct timespec64 inode_set_ctime_current(struct inode *inode)
> cur = cns;
>
> /* No need to cmpxchg if it's exactly the same */
> - if (cns == now_ts.tv_nsec && inode->i_ctime_sec == now_ts.tv_sec)
> + if (cns == now_ts.tv_nsec && inode->i_ctime_sec == now_ts.tv_sec) {
> + trace_ctime_xchg_skip(inode, &now_ts);
> goto out;
> + }
> retry:
> /* Try to swap the nsec value into place. */
> if (try_cmpxchg(&inode->i_ctime_nsec, &cur, now_ts.tv_nsec)) {
> /* If swap occurred, then we're (mostly) done */
> inode->i_ctime_sec = now_ts.tv_sec;
> + trace_ctime_ns_xchg(inode, cns, now_ts.tv_nsec, cur);
> } else {
> /*
> * Was the change due to someone marking the old ctime QUERIED?
> diff --git a/fs/stat.c b/fs/stat.c
> index df7fdd3afed9..552dfd67688b 100644
> --- a/fs/stat.c
> +++ b/fs/stat.c
> @@ -23,6 +23,8 @@
> #include <linux/uaccess.h>
> #include <asm/unistd.h>
>
> +#include <trace/events/timestamp.h>
> +
> #include "internal.h"
> #include "mount.h"
>
> @@ -49,6 +51,7 @@ void fill_mg_cmtime(struct kstat *stat, u32 request_mask, struct inode *inode)
> stat->mtime = inode_get_mtime(inode);
> stat->ctime.tv_sec = inode->i_ctime_sec;
> stat->ctime.tv_nsec = ((u32)atomic_fetch_or(I_CTIME_QUERIED, pcn)) & ~I_CTIME_QUERIED;
> + trace_fill_mg_cmtime(inode, &stat->ctime, &stat->mtime);
> }
> EXPORT_SYMBOL(fill_mg_cmtime);
>
> diff --git a/include/trace/events/timestamp.h b/include/trace/events/timestamp.h
> new file mode 100644
> index 000000000000..c9e5ec930054
> --- /dev/null
> +++ b/include/trace/events/timestamp.h
> @@ -0,0 +1,124 @@
> +/* SPDX-License-Identifier: GPL-2.0 */
> +#undef TRACE_SYSTEM
> +#define TRACE_SYSTEM timestamp
> +
> +#if !defined(_TRACE_TIMESTAMP_H) || defined(TRACE_HEADER_MULTI_READ)
> +#define _TRACE_TIMESTAMP_H
> +
> +#include <linux/tracepoint.h>
> +#include <linux/fs.h>
> +
> +#define CTIME_QUERIED_FLAGS \
> + { I_CTIME_QUERIED, "Q" }
> +
> +DECLARE_EVENT_CLASS(ctime,
> + TP_PROTO(struct inode *inode,
> + struct timespec64 *ctime),
> +
> + TP_ARGS(inode, ctime),
> +
> + TP_STRUCT__entry(
> + __field(dev_t, dev)
> + __field(ino_t, ino)
> + __field(time64_t, ctime_s)
> + __field(u32, ctime_ns)
> + __field(u32, gen)
> + ),
> +
> + TP_fast_assign(
> + __entry->dev = inode->i_sb->s_dev;
> + __entry->ino = inode->i_ino;
> + __entry->gen = inode->i_generation;
> + __entry->ctime_s = ctime->tv_sec;
> + __entry->ctime_ns = ctime->tv_nsec;
> + ),
> +
> + TP_printk("ino=%d:%d:%ld:%u ctime=%lld.%u",
> + MAJOR(__entry->dev), MINOR(__entry->dev), __entry->ino, __entry->gen,
> + __entry->ctime_s, __entry->ctime_ns
> + )
> +);
> +
> +DEFINE_EVENT(ctime, inode_set_ctime_to_ts,
> + TP_PROTO(struct inode *inode,
> + struct timespec64 *ctime),
> + TP_ARGS(inode, ctime));
> +
> +DEFINE_EVENT(ctime, ctime_xchg_skip,
> + TP_PROTO(struct inode *inode,
> + struct timespec64 *ctime),
> + TP_ARGS(inode, ctime));
> +
> +TRACE_EVENT(ctime_ns_xchg,
> + TP_PROTO(struct inode *inode,
> + u32 old,
> + u32 new,
> + u32 cur),
> +
> + TP_ARGS(inode, old, new, cur),
> +
> + TP_STRUCT__entry(
> + __field(dev_t, dev)
> + __field(ino_t, ino)
> + __field(u32, gen)
> + __field(u32, old)
> + __field(u32, new)
> + __field(u32, cur)
> + ),
> +
> + TP_fast_assign(
> + __entry->dev = inode->i_sb->s_dev;
> + __entry->ino = inode->i_ino;
> + __entry->gen = inode->i_generation;
> + __entry->old = old;
> + __entry->new = new;
> + __entry->cur = cur;
> + ),
> +
> + TP_printk("ino=%d:%d:%ld:%u old=%u:%s new=%u cur=%u:%s",
> + MAJOR(__entry->dev), MINOR(__entry->dev), __entry->ino, __entry->gen,
> + __entry->old & ~I_CTIME_QUERIED,
> + __print_flags(__entry->old & I_CTIME_QUERIED, "|", CTIME_QUERIED_FLAGS),
> + __entry->new,
> + __entry->cur & ~I_CTIME_QUERIED,
> + __print_flags(__entry->cur & I_CTIME_QUERIED, "|", CTIME_QUERIED_FLAGS)
> + )
> +);
> +
> +TRACE_EVENT(fill_mg_cmtime,
> + TP_PROTO(struct inode *inode,
> + struct timespec64 *ctime,
> + struct timespec64 *mtime),
> +
> + TP_ARGS(inode, ctime, mtime),
> +
> + TP_STRUCT__entry(
> + __field(dev_t, dev)
> + __field(ino_t, ino)
> + __field(time64_t, ctime_s)
> + __field(time64_t, mtime_s)
> + __field(u32, ctime_ns)
> + __field(u32, mtime_ns)
> + __field(u32, gen)
> + ),
> +
> + TP_fast_assign(
> + __entry->dev = inode->i_sb->s_dev;
> + __entry->ino = inode->i_ino;
> + __entry->gen = inode->i_generation;
> + __entry->ctime_s = ctime->tv_sec;
> + __entry->mtime_s = mtime->tv_sec;
> + __entry->ctime_ns = ctime->tv_nsec;
> + __entry->mtime_ns = mtime->tv_nsec;
> + ),
> +
> + TP_printk("ino=%d:%d:%ld:%u ctime=%lld.%u mtime=%lld.%u",
> + MAJOR(__entry->dev), MINOR(__entry->dev), __entry->ino, __entry->gen,
> + __entry->ctime_s, __entry->ctime_ns,
> + __entry->mtime_s, __entry->mtime_ns
> + )
> +);
> +#endif /* _TRACE_TIMESTAMP_H */
> +
> +/* This part must be outside protection */
> +#include <trace/define_trace.h>
>
> --
> 2.45.2
>
>