Hello,
Please find the v3 of this patch series. I have included Reviewed-by tag
on all patches, except in [5-7] which were later added to address review
comments from Jan [1].
Changes since v2
================
v2 -> v3
1. Defined TRACE_DEFINE_ENUM(EXT4_FC_REASON_MAX) in [Patch 02/10]
Changes since RFC
================
RFC -> v2
1. Added new patch-5 ("ext4: Return early for non-eligible fast_commit track events")
2. Removed a trace event in ext4_fc_track_template() (which was added in RFC)
from patch-6 and added patch-7 to add the tid info in callers of
ext4_fc_track_template(). (As per review comments from Jan)
Testing
=========
Tested this with xfstests -g "quick"
Thanks again to Jan, Harshad for helping with reviews and Steve for helping with
TRACE_DEFINE_ENUM part in kernel trace events.
[RFC]: https://lore.kernel.org/linux-ext4/[email protected]/
[v2]: https://lore.kernel.org/linux-ext4/[email protected]/
[1]: https://lore.kernel.org/linux-ext4/[email protected]/
Ritesh Harjani (10):
ext4: Remove unused enum EXT4_FC_COMMIT_FAILED
ext4: Fix ext4_fc_stats trace point
ext4: Convert ext4_fc_track_dentry type events to use event class
ext4: Do not call FC trace event in ext4_fc_commit() if FS does not support FC
ext4: Return early for non-eligible fast_commit track events
ext4: Add new trace event in ext4_fc_cleanup
ext4: Add transaction tid info in fc_track events
ext4: Add commit_tid info in jbd debug log
ext4: Add commit tid info in ext4_fc_commit_start/stop trace events
ext4: Fix remaining two trace events to use same printk convention
fs/ext4/fast_commit.c | 95 ++++++++----
fs/ext4/fast_commit.h | 1 -
include/trace/events/ext4.h | 298 +++++++++++++++++++++++-------------
3 files changed, 258 insertions(+), 136 deletions(-)
--
2.31.1
This patch adds the transaction & inode tid info in trace events for
callers of ext4_fc_track_template(). This is helpful in debugging race
conditions where an inode could belong to two different transaction tids.
It also fixes the checkpatch warnings which says use tabs instead of
spaces.
Signed-off-by: Ritesh Harjani <[email protected]>
---
fs/ext4/fast_commit.c | 10 ++--
include/trace/events/ext4.h | 113 ++++++++++++++++++++++--------------
2 files changed, 73 insertions(+), 50 deletions(-)
diff --git a/fs/ext4/fast_commit.c b/fs/ext4/fast_commit.c
index f4a56298fd88..849fd4dcb825 100644
--- a/fs/ext4/fast_commit.c
+++ b/fs/ext4/fast_commit.c
@@ -487,7 +487,7 @@ void __ext4_fc_track_unlink(handle_t *handle,
ret = ext4_fc_track_template(handle, inode, __track_dentry_update,
(void *)&args, 0);
- trace_ext4_fc_track_unlink(inode, dentry, ret);
+ trace_ext4_fc_track_unlink(handle, inode, dentry, ret);
}
void ext4_fc_track_unlink(handle_t *handle, struct dentry *dentry)
@@ -516,7 +516,7 @@ void __ext4_fc_track_link(handle_t *handle,
ret = ext4_fc_track_template(handle, inode, __track_dentry_update,
(void *)&args, 0);
- trace_ext4_fc_track_link(inode, dentry, ret);
+ trace_ext4_fc_track_link(handle, inode, dentry, ret);
}
void ext4_fc_track_link(handle_t *handle, struct dentry *dentry)
@@ -545,7 +545,7 @@ void __ext4_fc_track_create(handle_t *handle, struct inode *inode,
ret = ext4_fc_track_template(handle, inode, __track_dentry_update,
(void *)&args, 0);
- trace_ext4_fc_track_create(inode, dentry, ret);
+ trace_ext4_fc_track_create(handle, inode, dentry, ret);
}
void ext4_fc_track_create(handle_t *handle, struct dentry *dentry)
@@ -596,7 +596,7 @@ void ext4_fc_track_inode(handle_t *handle, struct inode *inode)
return;
ret = ext4_fc_track_template(handle, inode, __track_inode, NULL, 1);
- trace_ext4_fc_track_inode(inode, ret);
+ trace_ext4_fc_track_inode(handle, inode, ret);
}
struct __track_range_args {
@@ -653,7 +653,7 @@ void ext4_fc_track_range(handle_t *handle, struct inode *inode, ext4_lblk_t star
ret = ext4_fc_track_template(handle, inode, __track_range, &args, 1);
- trace_ext4_fc_track_range(inode, start, end, ret);
+ trace_ext4_fc_track_range(handle, inode, start, end, ret);
}
static void ext4_fc_submit_bh(struct super_block *sb, bool is_tail)
diff --git a/include/trace/events/ext4.h b/include/trace/events/ext4.h
index 20654aaf9495..6bd90df07b5c 100644
--- a/include/trace/events/ext4.h
+++ b/include/trace/events/ext4.h
@@ -2782,32 +2782,41 @@ TRACE_EVENT(ext4_fc_stats,
DECLARE_EVENT_CLASS(ext4_fc_track_dentry,
- TP_PROTO(struct inode *inode, struct dentry *dentry, int ret),
+ TP_PROTO(handle_t *handle, struct inode *inode,
+ struct dentry *dentry, int ret),
- TP_ARGS(inode, dentry, ret),
+ TP_ARGS(handle, inode, dentry, ret),
TP_STRUCT__entry(
__field(dev_t, dev)
+ __field(tid_t, t_tid)
__field(ino_t, i_ino)
+ __field(tid_t, i_sync_tid)
__field(int, error)
),
TP_fast_assign(
+ 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->error = ret;
),
- TP_printk("dev %d,%d, ino %lu, error %d",
+ TP_printk("dev %d,%d, t_tid %u, ino %lu, i_sync_tid %u, error %d",
MAJOR(__entry->dev), MINOR(__entry->dev),
- __entry->i_ino, __entry->error
+ __entry->t_tid, __entry->i_ino, __entry->i_sync_tid,
+ __entry->error
)
);
#define DEFINE_EVENT_CLASS_DENTRY(__type) \
DEFINE_EVENT(ext4_fc_track_dentry, ext4_fc_track_##__type, \
- TP_PROTO(struct inode *inode, struct dentry *dentry, int ret), \
- TP_ARGS(inode, dentry, ret) \
+ TP_PROTO(handle_t *handle, struct inode *inode, \
+ struct dentry *dentry, int ret), \
+ TP_ARGS(handle, inode, dentry, ret) \
)
DEFINE_EVENT_CLASS_DENTRY(create);
@@ -2815,52 +2824,66 @@ DEFINE_EVENT_CLASS_DENTRY(link);
DEFINE_EVENT_CLASS_DENTRY(unlink);
TRACE_EVENT(ext4_fc_track_inode,
- TP_PROTO(struct inode *inode, int ret),
+ TP_PROTO(handle_t *handle, struct inode *inode, int ret),
- TP_ARGS(inode, ret),
+ TP_ARGS(handle, inode, ret),
- TP_STRUCT__entry(
- __field(dev_t, dev)
- __field(int, ino)
- __field(int, error)
- ),
+ TP_STRUCT__entry(
+ __field(dev_t, dev)
+ __field(tid_t, t_tid)
+ __field(ino_t, i_ino)
+ __field(tid_t, i_sync_tid)
+ __field(int, error)
+ ),
- TP_fast_assign(
- __entry->dev = inode->i_sb->s_dev;
- __entry->ino = inode->i_ino;
- __entry->error = ret;
- ),
+ TP_fast_assign(
+ struct ext4_inode_info *ei = EXT4_I(inode);
- TP_printk("dev %d:%d, inode %d, error %d",
- MAJOR(__entry->dev), MINOR(__entry->dev),
- __entry->ino, __entry->error)
+ __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->error = ret;
+ ),
+
+ TP_printk("dev %d:%d, t_tid %u, inode %lu, i_sync_tid %u, error %d",
+ MAJOR(__entry->dev), MINOR(__entry->dev),
+ __entry->t_tid, __entry->i_ino, __entry->i_sync_tid,
+ __entry->error)
);
TRACE_EVENT(ext4_fc_track_range,
- TP_PROTO(struct inode *inode, long start, long end, int ret),
-
- TP_ARGS(inode, start, end, ret),
-
- TP_STRUCT__entry(
- __field(dev_t, dev)
- __field(int, ino)
- __field(long, start)
- __field(long, end)
- __field(int, error)
- ),
-
- TP_fast_assign(
- __entry->dev = inode->i_sb->s_dev;
- __entry->ino = inode->i_ino;
- __entry->start = start;
- __entry->end = end;
- __entry->error = ret;
- ),
-
- TP_printk("dev %d:%d, inode %d, error %d, start %ld, end %ld",
- MAJOR(__entry->dev), MINOR(__entry->dev),
- __entry->ino, __entry->error, __entry->start,
- __entry->end)
+ TP_PROTO(handle_t *handle, struct inode *inode,
+ long start, long end, int ret),
+
+ TP_ARGS(handle, inode, start, end, ret),
+
+ TP_STRUCT__entry(
+ __field(dev_t, dev)
+ __field(tid_t, t_tid)
+ __field(ino_t, i_ino)
+ __field(tid_t, i_sync_tid)
+ __field(long, start)
+ __field(long, end)
+ __field(int, error)
+ ),
+
+ TP_fast_assign(
+ 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->start = start;
+ __entry->end = end;
+ __entry->error = ret;
+ ),
+
+ TP_printk("dev %d:%d, t_tid %u, inode %lu, i_sync_tid %u, error %d, start %ld, end %ld",
+ MAJOR(__entry->dev), MINOR(__entry->dev),
+ __entry->t_tid, __entry->i_ino, __entry->i_sync_tid,
+ __entry->error, __entry->start, __entry->end)
);
TRACE_EVENT(ext4_fc_cleanup,
--
2.31.1
This just puts trace_ext4_fc_commit_start(sb) & ktime_get()
for measuring FC commit time, after the check of whether sb
supports JOURNAL_FAST_COMMIT or not.
Signed-off-by: Ritesh Harjani <[email protected]>
Reviewed-by: Harshad Shirwadkar <[email protected]>
Reviewed-by: Jan Kara <[email protected]>
---
fs/ext4/fast_commit.c | 6 +++---
1 file changed, 3 insertions(+), 3 deletions(-)
diff --git a/fs/ext4/fast_commit.c b/fs/ext4/fast_commit.c
index 5ac594e03402..55d33f296cae 100644
--- a/fs/ext4/fast_commit.c
+++ b/fs/ext4/fast_commit.c
@@ -1165,13 +1165,13 @@ int ext4_fc_commit(journal_t *journal, tid_t commit_tid)
int status = EXT4_FC_STATUS_OK, fc_bufs_before = 0;
ktime_t start_time, commit_time;
+ if (!test_opt2(sb, JOURNAL_FAST_COMMIT))
+ return jbd2_complete_transaction(journal, commit_tid);
+
trace_ext4_fc_commit_start(sb);
start_time = ktime_get();
- if (!test_opt2(sb, JOURNAL_FAST_COMMIT))
- return jbd2_complete_transaction(journal, commit_tid);
-
restart_fc:
ret = jbd2_fc_begin_commit(journal, commit_tid);
if (ret == -EALREADY) {
--
2.31.1
This adds commit_tid argument in ext4_fc_update_stats()
so that we can add this information too in jbd_debug logs.
This is also required in a later patch to pass the commit_tid info in
ext4_fc_commit_start/stop() trace events.
Signed-off-by: Ritesh Harjani <[email protected]>
Reviewed-by: Jan Kara <[email protected]>
Reviewed-by: Harshad Shirwadkar <[email protected]>
---
fs/ext4/fast_commit.c | 15 +++++++++------
1 file changed, 9 insertions(+), 6 deletions(-)
diff --git a/fs/ext4/fast_commit.c b/fs/ext4/fast_commit.c
index 849fd4dcb825..88ed99e670c5 100644
--- a/fs/ext4/fast_commit.c
+++ b/fs/ext4/fast_commit.c
@@ -1164,11 +1164,12 @@ static int ext4_fc_perform_commit(journal_t *journal)
}
static void ext4_fc_update_stats(struct super_block *sb, int status,
- u64 commit_time, int nblks)
+ u64 commit_time, int nblks, tid_t commit_tid)
{
struct ext4_fc_stats *stats = &EXT4_SB(sb)->s_fc_stats;
- jbd_debug(1, "Fast commit ended with status = %d", status);
+ jbd_debug(1, "Fast commit ended with status = %d for tid %u",
+ status, commit_tid);
if (status == EXT4_FC_STATUS_OK) {
stats->fc_num_commits++;
stats->fc_numblks += nblks;
@@ -1218,14 +1219,16 @@ int ext4_fc_commit(journal_t *journal, tid_t commit_tid)
if (atomic_read(&sbi->s_fc_subtid) <= subtid &&
commit_tid > journal->j_commit_sequence)
goto restart_fc;
- ext4_fc_update_stats(sb, EXT4_FC_STATUS_SKIPPED, 0, 0);
+ ext4_fc_update_stats(sb, EXT4_FC_STATUS_SKIPPED, 0, 0,
+ commit_tid);
return 0;
} else if (ret) {
/*
* Commit couldn't start. Just update stats and perform a
* full commit.
*/
- ext4_fc_update_stats(sb, EXT4_FC_STATUS_FAILED, 0, 0);
+ ext4_fc_update_stats(sb, EXT4_FC_STATUS_FAILED, 0, 0,
+ commit_tid);
return jbd2_complete_transaction(journal, commit_tid);
}
@@ -1257,12 +1260,12 @@ int ext4_fc_commit(journal_t *journal, tid_t commit_tid)
* don't react too strongly to vast changes in the commit time
*/
commit_time = ktime_to_ns(ktime_sub(ktime_get(), start_time));
- ext4_fc_update_stats(sb, status, commit_time, nblks);
+ ext4_fc_update_stats(sb, status, commit_time, nblks, commit_tid);
return ret;
fallback:
ret = jbd2_fc_end_commit_fallback(journal);
- ext4_fc_update_stats(sb, status, 0, 0);
+ ext4_fc_update_stats(sb, status, 0, 0, commit_tid);
return ret;
}
--
2.31.1
This adds a new trace event in ext4_fc_cleanup() which is helpful in debugging
some fast_commit issues.
Signed-off-by: Ritesh Harjani <[email protected]>
---
fs/ext4/fast_commit.c | 1 +
include/trace/events/ext4.h | 26 ++++++++++++++++++++++++++
2 files changed, 27 insertions(+)
diff --git a/fs/ext4/fast_commit.c b/fs/ext4/fast_commit.c
index 6990429daa0e..f4a56298fd88 100644
--- a/fs/ext4/fast_commit.c
+++ b/fs/ext4/fast_commit.c
@@ -1280,6 +1280,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 3d48fcb62987..20654aaf9495 100644
--- a/include/trace/events/ext4.h
+++ b/include/trace/events/ext4.h
@@ -2863,6 +2863,32 @@ TRACE_EVENT(ext4_fc_track_range,
__entry->end)
);
+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
One should use DECLARE_EVENT_CLASS for similar event types instead of
defining TRACE_EVENT for each event type. This is helpful in reducing
the text section footprint for e.g. [1]
[1]: https://lwn.net/Articles/381064/
Signed-off-by: Ritesh Harjani <[email protected]>
Reviewed-by: Harshad Shirwadkar <[email protected]>
Reviewed-by: Jan Kara <[email protected]>
---
include/trace/events/ext4.h | 56 ++++++++++++++++++++-----------------
1 file changed, 31 insertions(+), 25 deletions(-)
diff --git a/include/trace/events/ext4.h b/include/trace/events/ext4.h
index 1a0b7030f72a..3d48fcb62987 100644
--- a/include/trace/events/ext4.h
+++ b/include/trace/events/ext4.h
@@ -2780,33 +2780,39 @@ TRACE_EVENT(ext4_fc_stats,
__entry->fc_numblks)
);
-#define DEFINE_TRACE_DENTRY_EVENT(__type) \
- TRACE_EVENT(ext4_fc_track_##__type, \
- TP_PROTO(struct inode *inode, struct dentry *dentry, int ret), \
- \
- TP_ARGS(inode, dentry, ret), \
- \
- TP_STRUCT__entry( \
- __field(dev_t, dev) \
- __field(int, ino) \
- __field(int, error) \
- ), \
- \
- TP_fast_assign( \
- __entry->dev = inode->i_sb->s_dev; \
- __entry->ino = inode->i_ino; \
- __entry->error = ret; \
- ), \
- \
- TP_printk("dev %d:%d, inode %d, error %d, fc_%s", \
- MAJOR(__entry->dev), MINOR(__entry->dev), \
- __entry->ino, __entry->error, \
- #__type) \
+DECLARE_EVENT_CLASS(ext4_fc_track_dentry,
+
+ TP_PROTO(struct inode *inode, struct dentry *dentry, int ret),
+
+ TP_ARGS(inode, dentry, ret),
+
+ TP_STRUCT__entry(
+ __field(dev_t, dev)
+ __field(ino_t, i_ino)
+ __field(int, error)
+ ),
+
+ TP_fast_assign(
+ __entry->dev = inode->i_sb->s_dev;
+ __entry->i_ino = inode->i_ino;
+ __entry->error = ret;
+ ),
+
+ TP_printk("dev %d,%d, ino %lu, error %d",
+ MAJOR(__entry->dev), MINOR(__entry->dev),
+ __entry->i_ino, __entry->error
)
+);
+
+#define DEFINE_EVENT_CLASS_DENTRY(__type) \
+DEFINE_EVENT(ext4_fc_track_dentry, ext4_fc_track_##__type, \
+ TP_PROTO(struct inode *inode, struct dentry *dentry, int ret), \
+ TP_ARGS(inode, dentry, ret) \
+)
-DEFINE_TRACE_DENTRY_EVENT(create);
-DEFINE_TRACE_DENTRY_EVENT(link);
-DEFINE_TRACE_DENTRY_EVENT(unlink);
+DEFINE_EVENT_CLASS_DENTRY(create);
+DEFINE_EVENT_CLASS_DENTRY(link);
+DEFINE_EVENT_CLASS_DENTRY(unlink);
TRACE_EVENT(ext4_fc_track_inode,
TP_PROTO(struct inode *inode, int ret),
--
2.31.1