Re: [RFC 6/9] ext4: Add commit tid info in ext4_fc_commit_start/stop trace events

From: Jan Kara
Date: Wed Feb 23 2022 - 04:44:27 EST


On Wed 23-02-22 02:04:14, Ritesh Harjani wrote:
> This adds commit_tid info in ext4_fc_commit_start/stop which is helpful
> in debugging fast_commit issues.
>
> For e.g. issues where due to jbd2 journal full commit, FC miss to commit
> updates to a file.
>
> Also improves TP_prink format string i.e. all ext4 and jbd2 trace events
> starts with "dev MAjOR,MINOR". Let's follow the same convention while we
> are still at it.
>
> Signed-off-by: Ritesh Harjani <riteshh@xxxxxxxxxxxxx>

Looks good. Feel free to add:

Reviewed-by: Jan Kara <jack@xxxxxxx>

Honza

> ---
> fs/ext4/fast_commit.c | 4 ++--
> include/trace/events/ext4.h | 21 +++++++++++++--------
> 2 files changed, 15 insertions(+), 10 deletions(-)
>
> diff --git a/fs/ext4/fast_commit.c b/fs/ext4/fast_commit.c
> index ee32aac0cbbf..8803ba087b07 100644
> --- a/fs/ext4/fast_commit.c
> +++ b/fs/ext4/fast_commit.c
> @@ -1150,7 +1150,7 @@ static void ext4_fc_update_stats(struct super_block *sb, int status,
> } else {
> stats->fc_skipped_commits++;
> }
> - trace_ext4_fc_commit_stop(sb, nblks, status);
> + trace_ext4_fc_commit_stop(sb, nblks, status, commit_tid);
> }
>
> /*
> @@ -1171,7 +1171,7 @@ int ext4_fc_commit(journal_t *journal, tid_t commit_tid)
> if (!test_opt2(sb, JOURNAL_FAST_COMMIT))
> return jbd2_complete_transaction(journal, commit_tid);
>
> - trace_ext4_fc_commit_start(sb);
> + trace_ext4_fc_commit_start(sb, commit_tid);
>
> start_time = ktime_get();
>
> diff --git a/include/trace/events/ext4.h b/include/trace/events/ext4.h
> index cd09dccea502..6e66cb7ce624 100644
> --- a/include/trace/events/ext4.h
> +++ b/include/trace/events/ext4.h
> @@ -2685,26 +2685,29 @@ TRACE_EVENT(ext4_fc_replay,
> );
>
> TRACE_EVENT(ext4_fc_commit_start,
> - TP_PROTO(struct super_block *sb),
> + TP_PROTO(struct super_block *sb, tid_t commit_tid),
>
> - TP_ARGS(sb),
> + TP_ARGS(sb, commit_tid),
>
> TP_STRUCT__entry(
> __field(dev_t, dev)
> + __field(tid_t, tid)
> ),
>
> TP_fast_assign(
> __entry->dev = sb->s_dev;
> + __entry->tid = commit_tid;
> ),
>
> - TP_printk("fast_commit started on dev %d,%d",
> - MAJOR(__entry->dev), MINOR(__entry->dev))
> + TP_printk("dev %d,%d tid %u", MAJOR(__entry->dev), MINOR(__entry->dev),
> + __entry->tid)
> );
>
> TRACE_EVENT(ext4_fc_commit_stop,
> - TP_PROTO(struct super_block *sb, int nblks, int reason),
> + TP_PROTO(struct super_block *sb, int nblks, int reason,
> + tid_t commit_tid),
>
> - TP_ARGS(sb, nblks, reason),
> + TP_ARGS(sb, nblks, reason, commit_tid),
>
> TP_STRUCT__entry(
> __field(dev_t, dev)
> @@ -2713,6 +2716,7 @@ TRACE_EVENT(ext4_fc_commit_stop,
> __field(int, num_fc)
> __field(int, num_fc_ineligible)
> __field(int, nblks_agg)
> + __field(tid_t, tid)
> ),
>
> TP_fast_assign(
> @@ -2723,12 +2727,13 @@ TRACE_EVENT(ext4_fc_commit_stop,
> __entry->num_fc_ineligible =
> EXT4_SB(sb)->s_fc_stats.fc_ineligible_commits;
> __entry->nblks_agg = EXT4_SB(sb)->s_fc_stats.fc_numblks;
> + __entry->tid = commit_tid;
> ),
>
> - TP_printk("fc on [%d,%d] nblks %d, reason %d, fc = %d, ineligible = %d, agg_nblks %d",
> + TP_printk("dev %d,%d nblks %d, reason %d, fc = %d, ineligible = %d, agg_nblks %d, tid %u",
> MAJOR(__entry->dev), MINOR(__entry->dev),
> __entry->nblks, __entry->reason, __entry->num_fc,
> - __entry->num_fc_ineligible, __entry->nblks_agg)
> + __entry->num_fc_ineligible, __entry->nblks_agg, __entry->tid)
> );
>
> #define FC_REASON_NAME_STAT(reason) \
> --
> 2.31.1
>
--
Jan Kara <jack@xxxxxxxx>
SUSE Labs, CR