[PATCH 0/5] nilfs2: introduce tracepoints
Hi Andrew, Please queue the following changes for the next merge window: Hitoshi Mitake (4): nilfs2: add a tracepoint for tracking stage transition of segment construction nilfs2: add a tracepoint for transaction events nilfs2: add tracepoints for analyzing sufile manipulation nilfs2: add tracepoints for analyzing reading and writing metadata files Ryusuke Konishi (1): MAINTAINERS: nilfs2: add header file for tracing These introduces some tracepoints to nilfs2 to help tracking its behavior for bottleneck detection, debugging, etc. Thanks, Ryusuke Konishi -- MAINTAINERS | 1 + fs/nilfs2/mdt.c | 6 ++ fs/nilfs2/segment.c | 104 fs/nilfs2/segment.h | 3 +- fs/nilfs2/sufile.c| 8 ++ include/trace/events/nilfs2.h | 224 ++ 6 files changed, 324 insertions(+), 22 deletions(-) -- To unsubscribe from this list: send the line "unsubscribe linux-nilfs" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
[PATCH 3/5] nilfs2: add tracepoints for analyzing sufile manipulation
From: Hitoshi Mitake
This patch adds tracepoints which would be useful for analyzing
segment usage from a perspective of high level sufile manipulation
(check, alloc, free). sufile is an important in-place updated metadata
file, so analyzing the behavior would be useful for performance
turning.
example of usage (a case of allocation):
$ sudo bin/tpoint nilfs2:nilfs2_segment_usage_allocated
Tracing nilfs2:nilfs2_segment_usage_allocated. Ctrl-C to end.
segctord-17800 [002] ...1 10671.867294: nilfs2_segment_usage_allocated:
sufile = 880054f908a8 segnum = 2
segctord-17800 [002] ...1 10675.073477: nilfs2_segment_usage_allocated:
sufile = 880054f908a8 segnum = 3
Cc: Benixon Dhas
Cc: TK Kato
Signed-off-by: Hitoshi Mitake
Signed-off-by: Ryusuke Konishi
Cc: Steven Rostedt
---
fs/nilfs2/sufile.c| 8 ++
include/trace/events/nilfs2.h | 67 +++
2 files changed, 75 insertions(+)
diff --git a/fs/nilfs2/sufile.c b/fs/nilfs2/sufile.c
index 2a869c3..7ff8f15 100644
--- a/fs/nilfs2/sufile.c
+++ b/fs/nilfs2/sufile.c
@@ -30,6 +30,8 @@
#include "mdt.h"
#include "sufile.h"
+#include
+
/**
* struct nilfs_sufile_info - on-memory private data of sufile
* @mi: on-memory private data of metadata file
@@ -358,6 +360,7 @@ int nilfs_sufile_alloc(struct inode *sufile, __u64 *segnump)
break; /* never happens */
}
}
+ trace_nilfs2_segment_usage_check(sufile, segnum, cnt);
ret = nilfs_sufile_get_segment_usage_block(sufile, segnum, 1,
&su_bh);
if (ret < 0)
@@ -388,6 +391,9 @@ int nilfs_sufile_alloc(struct inode *sufile, __u64 *segnump)
nilfs_mdt_mark_dirty(sufile);
brelse(su_bh);
*segnump = segnum;
+
+ trace_nilfs2_segment_usage_allocated(sufile, segnum);
+
goto out_header;
}
@@ -490,6 +496,8 @@ void nilfs_sufile_do_free(struct inode *sufile, __u64
segnum,
NILFS_SUI(sufile)->ncleansegs++;
nilfs_mdt_mark_dirty(sufile);
+
+ trace_nilfs2_segment_usage_freed(sufile, segnum);
}
/**
diff --git a/include/trace/events/nilfs2.h b/include/trace/events/nilfs2.h
index e5649ac..1b65ba6 100644
--- a/include/trace/events/nilfs2.h
+++ b/include/trace/events/nilfs2.h
@@ -95,6 +95,73 @@ TRACE_EVENT(nilfs2_transaction_transition,
show_transaction_state(__entry->state))
);
+TRACE_EVENT(nilfs2_segment_usage_check,
+ TP_PROTO(struct inode *sufile,
+__u64 segnum,
+unsigned long cnt),
+
+ TP_ARGS(sufile, segnum, cnt),
+
+ TP_STRUCT__entry(
+ __field(struct inode *, sufile)
+ __field(__u64, segnum)
+ __field(unsigned long, cnt)
+ ),
+
+ TP_fast_assign(
+ __entry->sufile = sufile;
+ __entry->segnum = segnum;
+ __entry->cnt = cnt;
+ ),
+
+ TP_printk("sufile = %p segnum = %llu cnt = %lu",
+ __entry->sufile,
+ __entry->segnum,
+ __entry->cnt)
+);
+
+TRACE_EVENT(nilfs2_segment_usage_allocated,
+ TP_PROTO(struct inode *sufile,
+__u64 segnum),
+
+ TP_ARGS(sufile, segnum),
+
+ TP_STRUCT__entry(
+ __field(struct inode *, sufile)
+ __field(__u64, segnum)
+ ),
+
+ TP_fast_assign(
+ __entry->sufile = sufile;
+ __entry->segnum = segnum;
+ ),
+
+ TP_printk("sufile = %p segnum = %llu",
+ __entry->sufile,
+ __entry->segnum)
+);
+
+TRACE_EVENT(nilfs2_segment_usage_freed,
+ TP_PROTO(struct inode *sufile,
+__u64 segnum),
+
+ TP_ARGS(sufile, segnum),
+
+ TP_STRUCT__entry(
+ __field(struct inode *, sufile)
+ __field(__u64, segnum)
+ ),
+
+ TP_fast_assign(
+ __entry->sufile = sufile;
+ __entry->segnum = segnum;
+ ),
+
+ TP_printk("sufile = %p segnum = %llu",
+ __entry->sufile,
+ __entry->segnum)
+);
+
#endif /* _TRACE_NILFS2_H */
/* This part must be outside protection */
--
1.8.3.1
--
To unsubscribe from this list: send the line "unsubscribe linux-nilfs" in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
[PATCH 2/5] nilfs2: add a tracepoint for transaction events
From: Hitoshi Mitake
This patch adds a tracepoint for transaction events of nilfs. With the
tracepoint, these events can be tracked: begin, abort, commit,
trylock, lock, and unlock. Basically, these events have corresponding
functions e.g. begin event corresponds nilfs_transaction_begin(). The
unlock event is an exception. It corresponds to the iteration in
nilfs_transaction_lock().
Only one tracepoint is introcued: nilfs2_transaction_transition. The
above events are distinguished with newly introduced enum. With this
tracepoint, we can analyse a critical section of segment constructoin.
Sample output by tpoint of perf-tools:
cp-4457 [000] ...163.266220: nilfs2_transaction_transition:
sb = 8802112b8800 ti = 8800bf5ccc58 count = 1 flags = 9 state = BEGIN
cp-4457 [000] ...163.266221: nilfs2_transaction_transition:
sb = 8802112b8800 ti = 8800bf5ccc58 count = 0 flags = 9 state = COMMIT
cp-4457 [000] ...163.266221: nilfs2_transaction_transition:
sb = 8802112b8800 ti = 8800bf5ccc58 count = 0 flags = 9 state = COMMIT
segctord-4371 [001] ...168.261196: nilfs2_transaction_transition:
sb = 8802112b8800 ti = 8800b889bdf8 count = 0 flags = 10 state = TRYLOCK
segctord-4371 [001] ...168.261280: nilfs2_transaction_transition:
sb = 8802112b8800 ti = 8800b889bdf8 count = 0 flags = 10 state = LOCK
segctord-4371 [001] ...168.261877: nilfs2_transaction_transition:
sb = 8802112b8800 ti = 8800b889bdf8 count = 1 flags = 10 state = BEGIN
segctord-4371 [001] ...168.262116: nilfs2_transaction_transition:
sb = 8802112b8800 ti = 8800b889bdf8 count = 0 flags = 18 state = COMMIT
segctord-4371 [001] ...168.265032: nilfs2_transaction_transition:
sb = 8802112b8800 ti = 8800b889bdf8 count = 0 flags = 18 state = UNLOCK
segctord-4371 [001] ...1 132.376847: nilfs2_transaction_transition:
sb = 8802112b8800 ti = 8800b889bdf8 count = 0 flags = 10 state = TRYLOCK
This patch also does trivial cleaning of comma usage in collection
stage transition event for consistent coding style.
Signed-off-by: Hitoshi Mitake
Signed-off-by: Ryusuke Konishi
Cc: Steven Rostedt
---
fs/nilfs2/segment.c | 33 ++-
include/trace/events/nilfs2.h | 53 +++
2 files changed, 85 insertions(+), 1 deletion(-)
diff --git a/fs/nilfs2/segment.c b/fs/nilfs2/segment.c
index ef35404..3fc4732 100644
--- a/fs/nilfs2/segment.c
+++ b/fs/nilfs2/segment.c
@@ -214,11 +214,18 @@ int nilfs_transaction_begin(struct super_block *sb,
{
struct the_nilfs *nilfs;
int ret = nilfs_prepare_segment_lock(ti);
+ struct nilfs_transaction_info *trace_ti;
if (unlikely(ret < 0))
return ret;
- if (ret > 0)
+ if (ret > 0) {
+ trace_ti = current->journal_info;
+
+ trace_nilfs2_transaction_transition(sb, trace_ti,
+ trace_ti->ti_count, trace_ti->ti_flags,
+ TRACE_NILFS2_TRANSACTION_BEGIN);
return 0;
+ }
sb_start_intwrite(sb);
@@ -229,6 +236,11 @@ int nilfs_transaction_begin(struct super_block *sb,
ret = -ENOSPC;
goto failed;
}
+
+ trace_ti = current->journal_info;
+ trace_nilfs2_transaction_transition(sb, trace_ti, trace_ti->ti_count,
+ trace_ti->ti_flags,
+ TRACE_NILFS2_TRANSACTION_BEGIN);
return 0;
failed:
@@ -261,6 +273,8 @@ int nilfs_transaction_commit(struct super_block *sb)
ti->ti_flags |= NILFS_TI_COMMIT;
if (ti->ti_count > 0) {
ti->ti_count--;
+ trace_nilfs2_transaction_transition(sb, ti, ti->ti_count,
+ ti->ti_flags, TRACE_NILFS2_TRANSACTION_COMMIT);
return 0;
}
if (nilfs->ns_writer) {
@@ -272,6 +286,9 @@ int nilfs_transaction_commit(struct super_block *sb)
nilfs_segctor_do_flush(sci, 0);
}
up_read(&nilfs->ns_segctor_sem);
+ trace_nilfs2_transaction_transition(sb, ti, ti->ti_count,
+ ti->ti_flags, TRACE_NILFS2_TRANSACTION_COMMIT);
+
current->journal_info = ti->ti_save;
if (ti->ti_flags & NILFS_TI_SYNC)
@@ -290,10 +307,15 @@ void nilfs_transaction_abort(struct super_block *sb)
BUG_ON(ti == NULL || ti->ti_magic != NILFS_TI_MAGIC);
if (ti->ti_count > 0) {
ti->ti_count--;
+ trace_nilfs2_transaction_transition(sb, ti, ti->ti_count,
+ ti->ti_flags, TRACE_NILFS2_TRANSACTION_ABORT);
return;
}
up_read(&nilfs->ns_segctor_sem);
+ trace_nilfs2_transaction_transition(sb, ti, ti->ti_count,
[PATCH 4/5] nilfs2: add tracepoints for analyzing reading and writing metadata files
From: Hitoshi Mitake
This patch adds tracepoints for analyzing requests of reading and
writing metadata files. The tracepoints cover every in-place mdt files
(cpfile, sufile, and datfile).
Example of tracing mdt_insert_new_block():
cp-14635 [000] ...1 30598.199309: nilfs2_mdt_insert_new_block:
inode = 88022a8d0178 ino = 3 block = 155
cp-14635 [000] ...1 30598.199520: nilfs2_mdt_insert_new_block:
inode = 88022a8d0178 ino = 3 block = 5
cp-14635 [000] ...1 30598.200828: nilfs2_mdt_insert_new_block:
inode = 88022a8d0178 ino = 3 block = 253
Cc: TK Kato
Signed-off-by: Hitoshi Mitake
Signed-off-by: Ryusuke Konishi
Cc: Steven Rostedt
---
fs/nilfs2/mdt.c | 6 +
include/trace/events/nilfs2.h | 54 +++
2 files changed, 60 insertions(+)
diff --git a/fs/nilfs2/mdt.c b/fs/nilfs2/mdt.c
index dee34d9..1125f40 100644
--- a/fs/nilfs2/mdt.c
+++ b/fs/nilfs2/mdt.c
@@ -33,6 +33,7 @@
#include "page.h"
#include "mdt.h"
+#include
#define NILFS_MDT_MAX_RA_BLOCKS(16 - 1)
@@ -68,6 +69,9 @@ nilfs_mdt_insert_new_block(struct inode *inode, unsigned long
block,
set_buffer_uptodate(bh);
mark_buffer_dirty(bh);
nilfs_mdt_mark_dirty(inode);
+
+ trace_nilfs2_mdt_insert_new_block(inode, inode->i_ino, block);
+
return 0;
}
@@ -158,6 +162,8 @@ nilfs_mdt_submit_block(struct inode *inode, unsigned long
blkoff,
get_bh(bh);
submit_bh(mode, bh);
ret = 0;
+
+ trace_nilfs2_mdt_submit_block(inode, inode->i_ino, blkoff, mode);
out:
get_bh(bh);
*out_bh = bh;
diff --git a/include/trace/events/nilfs2.h b/include/trace/events/nilfs2.h
index 1b65ba6..c780581 100644
--- a/include/trace/events/nilfs2.h
+++ b/include/trace/events/nilfs2.h
@@ -162,6 +162,60 @@ TRACE_EVENT(nilfs2_segment_usage_freed,
__entry->segnum)
);
+TRACE_EVENT(nilfs2_mdt_insert_new_block,
+ TP_PROTO(struct inode *inode,
+unsigned long ino,
+unsigned long block),
+
+ TP_ARGS(inode, ino, block),
+
+ TP_STRUCT__entry(
+ __field(struct inode *, inode)
+ __field(unsigned long, ino)
+ __field(unsigned long, block)
+ ),
+
+ TP_fast_assign(
+ __entry->inode = inode;
+ __entry->ino = ino;
+ __entry->block = block;
+ ),
+
+ TP_printk("inode = %p ino = %lu block = %lu",
+ __entry->inode,
+ __entry->ino,
+ __entry->block)
+);
+
+TRACE_EVENT(nilfs2_mdt_submit_block,
+ TP_PROTO(struct inode *inode,
+unsigned long ino,
+unsigned long blkoff,
+int mode),
+
+ TP_ARGS(inode, ino, blkoff, mode),
+
+ TP_STRUCT__entry(
+ __field(struct inode *, inode)
+ __field(unsigned long, ino)
+ __field(unsigned long, blkoff)
+ __field(int, mode)
+ ),
+
+ TP_fast_assign(
+ __entry->inode = inode;
+ __entry->ino = ino;
+ __entry->blkoff = blkoff;
+ __entry->mode = mode;
+ ),
+
+ TP_printk("inode = %p ino = %lu blkoff = %lu mode = %x",
+ __entry->inode,
+ __entry->ino,
+ __entry->blkoff,
+ __entry->mode)
+);
+
#endif /* _TRACE_NILFS2_H */
/* This part must be outside protection */
--
1.8.3.1
--
To unsubscribe from this list: send the line "unsubscribe linux-nilfs" in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
[PATCH 5/5] MAINTAINERS: nilfs2: add header file for tracing
This adds header file "include/trace/events/nilfs2.h" to maintainer-ship of nilfs2 so that updates to the nilfs2 header file go to the mailing list of nilfs2. Signed-off-by: Ryusuke Konishi Cc: Hitoshi Mitake --- MAINTAINERS | 1 + 1 file changed, 1 insertion(+) diff --git a/MAINTAINERS b/MAINTAINERS index 797236b..6b15b7a 100644 --- a/MAINTAINERS +++ b/MAINTAINERS @@ -7371,6 +7371,7 @@ S:Supported F: Documentation/filesystems/nilfs2.txt F: fs/nilfs2/ F: include/linux/nilfs2_fs.h +F: include/trace/events/nilfs2.h NINJA SCSI-3 / NINJA SCSI-32Bi (16bit/CardBus) PCMCIA SCSI HOST ADAPTER DRIVER M: YOKOTA Hiroshi -- 1.8.3.1 -- To unsubscribe from this list: send the line "unsubscribe linux-nilfs" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
[PATCH 1/5] nilfs2: add a tracepoint for tracking stage transition of segment construction
From: Hitoshi Mitake
This patch adds a tracepoint for tracking stage transition of block
collection in segment construction. With the tracepoint, we can
analysis the behavior of segment construction in depth. It would be
useful for bottleneck detection and debugging, etc.
The tracepoint is created with the standard trace API of linux (like
ext3, ext4, f2fs and btrfs). So we can analysis with existing tools
easily. Of course, more detailed analysis will be possible if we can
create nilfs specific analysis tools.
Below is an example of event dump with Brendan Gregg's perf-tools
(https://github.com/brendangregg/perf-tools). Time consumption between
each stage can be obtained.
$ sudo bin/tpoint nilfs2:nilfs2_collection_stage_transition
Tracing nilfs2:nilfs2_collection_stage_transition. Ctrl-C to end.
segctord-14875 [003] ...1 28311.067794:
nilfs2_collection_stage_transition: sci = 8800ce6de000 stage = ST_INIT
segctord-14875 [003] ...1 28311.068139:
nilfs2_collection_stage_transition: sci = 8800ce6de000 stage = ST_GC
segctord-14875 [003] ...1 28311.068139:
nilfs2_collection_stage_transition: sci = 8800ce6de000 stage = ST_FILE
segctord-14875 [003] ...1 28311.068486:
nilfs2_collection_stage_transition: sci = 8800ce6de000 stage = ST_IFILE
segctord-14875 [003] ...1 28311.068540:
nilfs2_collection_stage_transition: sci = 8800ce6de000 stage = ST_CPFILE
segctord-14875 [003] ...1 28311.068561:
nilfs2_collection_stage_transition: sci = 8800ce6de000 stage = ST_SUFILE
segctord-14875 [003] ...1 28311.068565:
nilfs2_collection_stage_transition: sci = 8800ce6de000 stage = ST_DAT
segctord-14875 [003] ...1 28311.068573:
nilfs2_collection_stage_transition: sci = 8800ce6de000 stage = ST_SR
segctord-14875 [003] ...1 28311.068574:
nilfs2_collection_stage_transition: sci = 8800ce6de000 stage = ST_DONE
For capturing transition correctly, this patch adds wrappers for the
member scnt of nilfs_cstage. With this change, every transition of the
stage can produce trace event in a correct manner.
Signed-off-by: Hitoshi Mitake
Signed-off-by: Ryusuke Konishi
Cc: Steven Rostedt
---
fs/nilfs2/segment.c | 71 +++
fs/nilfs2/segment.h | 3 +-
include/trace/events/nilfs2.h | 50 ++
3 files changed, 103 insertions(+), 21 deletions(-)
create mode 100644 include/trace/events/nilfs2.h
diff --git a/fs/nilfs2/segment.c b/fs/nilfs2/segment.c
index c6abbad9..ef35404 100644
--- a/fs/nilfs2/segment.c
+++ b/fs/nilfs2/segment.c
@@ -77,6 +77,36 @@ enum {
NILFS_ST_DONE,
};
+#define CREATE_TRACE_POINTS
+#include
+
+/*
+ * nilfs_sc_cstage_inc(), nilfs_sc_cstage_set(), nilfs_sc_cstage_get() are
+ * wrapper functions of stage count (nilfs_sc_info->sc_stage.scnt). Users of
+ * the variable must use them because transition of stage count must involve
+ * trace events (trace_nilfs2_collection_stage_transition).
+ *
+ * nilfs_sc_cstage_get() isn't required for the above purpose because it
doesn't
+ * produce tracepoint events. It is provided just for making the intention
+ * clear.
+ */
+static inline void nilfs_sc_cstage_inc(struct nilfs_sc_info *sci)
+{
+ sci->sc_stage.scnt++;
+ trace_nilfs2_collection_stage_transition(sci);
+}
+
+static inline void nilfs_sc_cstage_set(struct nilfs_sc_info *sci, int
next_scnt)
+{
+ sci->sc_stage.scnt = next_scnt;
+ trace_nilfs2_collection_stage_transition(sci);
+}
+
+static inline int nilfs_sc_cstage_get(struct nilfs_sc_info *sci)
+{
+ return sci->sc_stage.scnt;
+}
+
/* State flags of collection */
#define NILFS_CF_NODE 0x0001 /* Collecting node blocks */
#define NILFS_CF_IFILE_STARTED 0x0002 /* IFILE stage has started */
@@ -1062,7 +1092,7 @@ static int nilfs_segctor_collect_blocks(struct
nilfs_sc_info *sci, int mode)
size_t ndone;
int err = 0;
- switch (sci->sc_stage.scnt) {
+ switch (nilfs_sc_cstage_get(sci)) {
case NILFS_ST_INIT:
/* Pre-processes */
sci->sc_stage.flags = 0;
@@ -1071,7 +1101,7 @@ static int nilfs_segctor_collect_blocks(struct
nilfs_sc_info *sci, int mode)
sci->sc_nblk_inc = 0;
sci->sc_curseg->sb_sum.flags = NILFS_SS_LOGBGN;
if (mode == SC_LSEG_DSYNC) {
- sci->sc_stage.scnt = NILFS_ST_DSYNC;
+ nilfs_sc_cstage_set(sci, NILFS_ST_DSYNC);
goto dsync_mode;
}
}
@@ -1079,10 +1109,10 @@ static int nilfs_segctor_collect_blocks(struct
nilfs_sc_info *sci, int mode)
sci->sc_stage.dirty_file_ptr = NULL;
sci->sc_stage.gc_inode_ptr = NULL;
if (mode == SC_FLUSH_DAT) {
- sci->sc_stage.scnt = NILFS_ST_DAT;
+
