This adds two more tracepoints for ext4_fc_track_template() &
ext4_fc_cleanup() which are helpful in debugging some fast_commit issues.
Signed-off-by: Ritesh Harjani <[email protected]>
---
fs/ext4/fast_commit.c | 3 ++
include/trace/events/ext4.h | 67 +++++++++++++++++++++++++++++++++++++
2 files changed, 70 insertions(+)
diff --git a/fs/ext4/fast_commit.c b/fs/ext4/fast_commit.c
index 5ac594e03402..bf70879bb4fe 100644
--- a/fs/ext4/fast_commit.c
+++ b/fs/ext4/fast_commit.c
@@ -386,6 +386,8 @@ static int ext4_fc_track_template(
if (ext4_test_mount_flag(inode->i_sb, EXT4_MF_FC_INELIGIBLE))
return -EINVAL;
+ trace_ext4_fc_track_template(handle, inode, __fc_track_fn, enqueue);
+
tid = handle->h_transaction->t_tid;
mutex_lock(&ei->i_fc_lock);
if (tid == ei->i_sync_tid) {
@@ -1241,6 +1243,7 @@ static void ext4_fc_cleanup(journal_t *journal, int full, tid_t tid)
if (full && sbi->s_fc_bh)
sbi->s_fc_bh = NULL;
+ trace_ext4_fc_cleanup(journal, full, tid);
jbd2_fc_release_bufs(journal);
spin_lock(&sbi->s_fc_lock);
diff --git a/include/trace/events/ext4.h b/include/trace/events/ext4.h
index 17fb9c506e8a..cd09dccea502 100644
--- a/include/trace/events/ext4.h
+++ b/include/trace/events/ext4.h
@@ -2855,6 +2855,73 @@ TRACE_EVENT(ext4_fc_track_range,
__entry->end)
);
+TRACE_EVENT(ext4_fc_track_template,
+ TP_PROTO(handle_t *handle, struct inode *inode,
+ void *__fc_track_fn, int enqueue),
+
+ TP_ARGS(handle, inode, __fc_track_fn, enqueue),
+
+ TP_STRUCT__entry(
+ __field(dev_t, dev)
+ __field(tid_t, t_tid)
+ __field(ino_t, i_ino)
+ __field(tid_t, i_sync_tid)
+ __field(void *, __fc_track_fn)
+ __field(int, enqueue)
+ __field(bool, jbd2_ongoing)
+ __field(bool, fc_ongoing)
+ ),
+
+ TP_fast_assign(
+ struct ext4_sb_info *sbi = EXT4_SB(inode->i_sb);
+ struct ext4_inode_info *ei = EXT4_I(inode);
+
+ __entry->dev = inode->i_sb->s_dev;
+ __entry->t_tid = handle->h_transaction->t_tid;
+ __entry->i_ino = inode->i_ino;
+ __entry->i_sync_tid = ei->i_sync_tid;
+ __entry->__fc_track_fn = __fc_track_fn;
+ __entry->enqueue = enqueue;
+ __entry->jbd2_ongoing =
+ sbi->s_journal->j_flags & JBD2_FULL_COMMIT_ONGOING;
+ __entry->fc_ongoing =
+ sbi->s_journal->j_flags & JBD2_FAST_COMMIT_ONGOING;
+ ),
+
+ TP_printk("dev %d,%d, t_tid %u, ino %lu, i_sync_tid %u, "
+ "track_fn %pS, enqueue %d, jbd2_ongoing %d, fc_ongoing %d",
+ MAJOR(__entry->dev), MINOR(__entry->dev),
+ __entry->t_tid, __entry->i_ino, __entry->i_sync_tid,
+ (void *)__entry->__fc_track_fn, __entry->enqueue,
+ __entry->jbd2_ongoing, __entry->fc_ongoing)
+ );
+
+TRACE_EVENT(ext4_fc_cleanup,
+ TP_PROTO(journal_t *journal, int full, tid_t tid),
+
+ TP_ARGS(journal, full, tid),
+
+ TP_STRUCT__entry(
+ __field(dev_t, dev)
+ __field(int, j_fc_off)
+ __field(int, full)
+ __field(tid_t, tid)
+ ),
+
+ TP_fast_assign(
+ struct super_block *sb = journal->j_private;
+
+ __entry->dev = sb->s_dev;
+ __entry->j_fc_off = journal->j_fc_off;
+ __entry->full = full;
+ __entry->tid = tid;
+ ),
+
+ TP_printk("dev %d,%d, j_fc_off %d, full %d, tid %u",
+ MAJOR(__entry->dev), MINOR(__entry->dev),
+ __entry->j_fc_off, __entry->full, __entry->tid)
+ );
+
TRACE_EVENT(ext4_update_sb,
TP_PROTO(struct super_block *sb, ext4_fsblk_t fsblk,
unsigned int flags),
--
2.31.1
On Wed 23-02-22 02:04:11, Ritesh Harjani wrote:
> This adds two more tracepoints for ext4_fc_track_template() &
> ext4_fc_cleanup() which are helpful in debugging some fast_commit issues.
>
> Signed-off-by: Ritesh Harjani <[email protected]>
So why is this more useful than trace_ext4_fc_track_range() and other
tracepoints? I don't think it provides any more information? What am I
missing?
Honza
> ---
> fs/ext4/fast_commit.c | 3 ++
> include/trace/events/ext4.h | 67 +++++++++++++++++++++++++++++++++++++
> 2 files changed, 70 insertions(+)
>
> diff --git a/fs/ext4/fast_commit.c b/fs/ext4/fast_commit.c
> index 5ac594e03402..bf70879bb4fe 100644
> --- a/fs/ext4/fast_commit.c
> +++ b/fs/ext4/fast_commit.c
> @@ -386,6 +386,8 @@ static int ext4_fc_track_template(
> if (ext4_test_mount_flag(inode->i_sb, EXT4_MF_FC_INELIGIBLE))
> return -EINVAL;
>
> + trace_ext4_fc_track_template(handle, inode, __fc_track_fn, enqueue);
> +
> tid = handle->h_transaction->t_tid;
> mutex_lock(&ei->i_fc_lock);
> if (tid == ei->i_sync_tid) {
> @@ -1241,6 +1243,7 @@ static void ext4_fc_cleanup(journal_t *journal, int full, tid_t tid)
> if (full && sbi->s_fc_bh)
> sbi->s_fc_bh = NULL;
>
> + trace_ext4_fc_cleanup(journal, full, tid);
> jbd2_fc_release_bufs(journal);
>
> spin_lock(&sbi->s_fc_lock);
> diff --git a/include/trace/events/ext4.h b/include/trace/events/ext4.h
> index 17fb9c506e8a..cd09dccea502 100644
> --- a/include/trace/events/ext4.h
> +++ b/include/trace/events/ext4.h
> @@ -2855,6 +2855,73 @@ TRACE_EVENT(ext4_fc_track_range,
> __entry->end)
> );
>
> +TRACE_EVENT(ext4_fc_track_template,
> + TP_PROTO(handle_t *handle, struct inode *inode,
> + void *__fc_track_fn, int enqueue),
> +
> + TP_ARGS(handle, inode, __fc_track_fn, enqueue),
> +
> + TP_STRUCT__entry(
> + __field(dev_t, dev)
> + __field(tid_t, t_tid)
> + __field(ino_t, i_ino)
> + __field(tid_t, i_sync_tid)
> + __field(void *, __fc_track_fn)
> + __field(int, enqueue)
> + __field(bool, jbd2_ongoing)
> + __field(bool, fc_ongoing)
> + ),
> +
> + TP_fast_assign(
> + struct ext4_sb_info *sbi = EXT4_SB(inode->i_sb);
> + struct ext4_inode_info *ei = EXT4_I(inode);
> +
> + __entry->dev = inode->i_sb->s_dev;
> + __entry->t_tid = handle->h_transaction->t_tid;
> + __entry->i_ino = inode->i_ino;
> + __entry->i_sync_tid = ei->i_sync_tid;
> + __entry->__fc_track_fn = __fc_track_fn;
> + __entry->enqueue = enqueue;
> + __entry->jbd2_ongoing =
> + sbi->s_journal->j_flags & JBD2_FULL_COMMIT_ONGOING;
> + __entry->fc_ongoing =
> + sbi->s_journal->j_flags & JBD2_FAST_COMMIT_ONGOING;
> + ),
> +
> + TP_printk("dev %d,%d, t_tid %u, ino %lu, i_sync_tid %u, "
> + "track_fn %pS, enqueue %d, jbd2_ongoing %d, fc_ongoing %d",
> + MAJOR(__entry->dev), MINOR(__entry->dev),
> + __entry->t_tid, __entry->i_ino, __entry->i_sync_tid,
> + (void *)__entry->__fc_track_fn, __entry->enqueue,
> + __entry->jbd2_ongoing, __entry->fc_ongoing)
> + );
> +
> +TRACE_EVENT(ext4_fc_cleanup,
> + TP_PROTO(journal_t *journal, int full, tid_t tid),
> +
> + TP_ARGS(journal, full, tid),
> +
> + TP_STRUCT__entry(
> + __field(dev_t, dev)
> + __field(int, j_fc_off)
> + __field(int, full)
> + __field(tid_t, tid)
> + ),
> +
> + TP_fast_assign(
> + struct super_block *sb = journal->j_private;
> +
> + __entry->dev = sb->s_dev;
> + __entry->j_fc_off = journal->j_fc_off;
> + __entry->full = full;
> + __entry->tid = tid;
> + ),
> +
> + TP_printk("dev %d,%d, j_fc_off %d, full %d, tid %u",
> + MAJOR(__entry->dev), MINOR(__entry->dev),
> + __entry->j_fc_off, __entry->full, __entry->tid)
> + );
> +
> TRACE_EVENT(ext4_update_sb,
> TP_PROTO(struct super_block *sb, ext4_fsblk_t fsblk,
> unsigned int flags),
> --
> 2.31.1
>
--
Jan Kara <[email protected]>
SUSE Labs, CR
On 22/02/23 12:53PM, Jan Kara wrote:
> On Wed 23-02-22 15:41:59, Ritesh Harjani wrote:
> > On 22/02/23 10:40AM, Jan Kara wrote:
> > > On Wed 23-02-22 02:04:11, Ritesh Harjani wrote:
> > > > This adds two more tracepoints for ext4_fc_track_template() &
> > > > ext4_fc_cleanup() which are helpful in debugging some fast_commit issues.
> > > >
> > > > Signed-off-by: Ritesh Harjani <[email protected]>
> > >
> > > So why is this more useful than trace_ext4_fc_track_range() and other
> > > tracepoints? I don't think it provides any more information? What am I
> > > missing?
> >
> > Thanks Jan for all the reviews.
> >
> > So ext4_fc_track_template() adds almost all required information
> > (including the caller info) in this one trace point along with transaction tid
> > which is useful for tracking issue similar to what is mentioned in Patch-9.
> >
> > (race with if inode is part of two transactions tid where jbd2 full commit
> > may begin for txn n-1 while inode is still in sbi->s_fc_q[MAIN])
>
> I understand commit tid is interesting but cannot we just add it to
> tracepoints like trace_ext4_fc_track_range() directly? It would seem useful
> to have it there and when it is there, the need for
> ext4_fc_track_template() is not really big. I don't care too much but
Yes make sense. Sure, I will look into adding this info to existing trace
points then. With that I think trace_ext4_fc_track_template() won't be required.
Will add those changes in V2.
> this tracepoint looked a bit superfluous to me.
>
> > And similarly ext4_fc_cleanup() helps with that information about which tid
> > completed and whether it was called from jbd2 full commit or from fast_commit.
>
> Yeah, that one is clear.
Will retain trace_ext4_fc_cleanup() then.
-ritesh
>
> Honza
> --
> Jan Kara <[email protected]>
> SUSE Labs, CR
On Wed 23-02-22 15:41:59, Ritesh Harjani wrote:
> On 22/02/23 10:40AM, Jan Kara wrote:
> > On Wed 23-02-22 02:04:11, Ritesh Harjani wrote:
> > > This adds two more tracepoints for ext4_fc_track_template() &
> > > ext4_fc_cleanup() which are helpful in debugging some fast_commit issues.
> > >
> > > Signed-off-by: Ritesh Harjani <[email protected]>
> >
> > So why is this more useful than trace_ext4_fc_track_range() and other
> > tracepoints? I don't think it provides any more information? What am I
> > missing?
>
> Thanks Jan for all the reviews.
>
> So ext4_fc_track_template() adds almost all required information
> (including the caller info) in this one trace point along with transaction tid
> which is useful for tracking issue similar to what is mentioned in Patch-9.
>
> (race with if inode is part of two transactions tid where jbd2 full commit
> may begin for txn n-1 while inode is still in sbi->s_fc_q[MAIN])
I understand commit tid is interesting but cannot we just add it to
tracepoints like trace_ext4_fc_track_range() directly? It would seem useful
to have it there and when it is there, the need for
ext4_fc_track_template() is not really big. I don't care too much but
this tracepoint looked a bit superfluous to me.
> And similarly ext4_fc_cleanup() helps with that information about which tid
> completed and whether it was called from jbd2 full commit or from fast_commit.
Yeah, that one is clear.
Honza
--
Jan Kara <[email protected]>
SUSE Labs, CR