Add some tracepoints around various multigrain timestamp events.
Reviewed-by: Josef Bacik <josef@toxicpanda.com>
Reviewed-by: Darrick J. Wong <djwong@kernel.org>
Reviewed-by: Jan Kara <jack@suse.cz>
Signed-off-by: Jeff Layton <jlayton@kernel.org>
---
fs/inode.c | 6 ++
fs/stat.c | 3 +
include/trace/events/timestamp.h | 124 +++++++++++++++++++++++++++++++++++++++
3 files changed, 133 insertions(+)
diff --git a/fs/inode.c b/fs/inode.c
index 260a8a1c1096..d19f70422a5d 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"
/*
@@ -2598,6 +2601,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;
@@ -2683,6 +2687,7 @@ struct timespec64 inode_set_ctime_current(struct inode *inode)
/* No need to cmpxchg if it's exactly the same */
if (cns == now.tv_nsec && inode->i_ctime_sec == now.tv_sec)
+ trace_ctime_xchg_skip(inode, &now);
goto out;
cur = cns;
retry:
@@ -2690,6 +2695,7 @@ struct timespec64 inode_set_ctime_current(struct inode *inode)
if (try_cmpxchg(&inode->i_ctime_nsec, &cur, now.tv_nsec)) {
/* If swap occurred, then we're (mostly) done */
inode->i_ctime_sec = now.tv_sec;
+ trace_ctime_ns_xchg(inode, cns, now.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 a449626fd460..9eb6d9b2d010 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"
@@ -52,6 +54,7 @@ void fill_mg_cmtime(struct kstat *stat, u32 request_mask, struct inode *inode)
if (!(stat->ctime.tv_nsec & I_CTIME_QUERIED))
stat->ctime.tv_nsec = ((u32)atomic_fetch_or(I_CTIME_QUERIED, pcn));
stat->ctime.tv_nsec &= ~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.46.0
On Fri, 2024-09-13 at 09:54 -0400, Jeff Layton wrote: > Add some tracepoints around various multigrain timestamp events. > > Reviewed-by: Josef Bacik <josef@toxicpanda.com> > Reviewed-by: Darrick J. Wong <djwong@kernel.org> > Reviewed-by: Jan Kara <jack@suse.cz> > Signed-off-by: Jeff Layton <jlayton@kernel.org> > --- > fs/inode.c | 6 ++ > fs/stat.c | 3 + > include/trace/events/timestamp.h | 124 +++++++++++++++++++++++++++++++++++++++ > 3 files changed, 133 insertions(+) > > diff --git a/fs/inode.c b/fs/inode.c > index 260a8a1c1096..d19f70422a5d 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" > > /* > @@ -2598,6 +2601,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; > @@ -2683,6 +2687,7 @@ struct timespec64 inode_set_ctime_current(struct inode *inode) > > /* No need to cmpxchg if it's exactly the same */ > if (cns == now.tv_nsec && inode->i_ctime_sec == now.tv_sec) > + trace_ctime_xchg_skip(inode, &now); > goto out; I just realized I sent out an earlier version that has the above bug in it (missing curly braces). The version I tested, and the version in my public tree have this bug fixed. > cur = cns; > retry: > @@ -2690,6 +2695,7 @@ struct timespec64 inode_set_ctime_current(struct inode *inode) > if (try_cmpxchg(&inode->i_ctime_nsec, &cur, now.tv_nsec)) { > /* If swap occurred, then we're (mostly) done */ > inode->i_ctime_sec = now.tv_sec; > + trace_ctime_ns_xchg(inode, cns, now.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 a449626fd460..9eb6d9b2d010 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" > > @@ -52,6 +54,7 @@ void fill_mg_cmtime(struct kstat *stat, u32 request_mask, struct inode *inode) > if (!(stat->ctime.tv_nsec & I_CTIME_QUERIED)) > stat->ctime.tv_nsec = ((u32)atomic_fetch_or(I_CTIME_QUERIED, pcn)); > stat->ctime.tv_nsec &= ~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> > -- Jeff Layton <jlayton@kernel.org>
© 2016 - 2024 Red Hat, Inc.