* [PATCH 0/5] nilfs2: introduce tracepoints
@ 2015-10-06 17:50 Ryusuke Konishi
2015-10-06 17:50 ` [PATCH 1/5] nilfs2: add a tracepoint for tracking stage transition of segment construction Ryusuke Konishi
` (4 more replies)
0 siblings, 5 replies; 6+ messages in thread
From: Ryusuke Konishi @ 2015-10-06 17:50 UTC (permalink / raw)
To: Andrew Morton
Cc: Hitoshi Mitake, Steven Rostedt, linux-nilfs, LKML, Ryusuke Konishi
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(-)
^ permalink raw reply [flat|nested] 6+ messages in thread
* [PATCH 1/5] nilfs2: add a tracepoint for tracking stage transition of segment construction
2015-10-06 17:50 [PATCH 0/5] nilfs2: introduce tracepoints Ryusuke Konishi
@ 2015-10-06 17:50 ` Ryusuke Konishi
2015-10-06 17:50 ` [PATCH 2/5] nilfs2: add a tracepoint for transaction events Ryusuke Konishi
` (3 subsequent siblings)
4 siblings, 0 replies; 6+ messages in thread
From: Ryusuke Konishi @ 2015-10-06 17:50 UTC (permalink / raw)
To: Andrew Morton
Cc: Hitoshi Mitake, Steven Rostedt, linux-nilfs, LKML, Ryusuke Konishi
From: Hitoshi Mitake <mitake.hitoshi@lab.ntt.co.jp>
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 = ffff8800ce6de000 stage = ST_INIT
segctord-14875 [003] ...1 28311.068139: nilfs2_collection_stage_transition: sci = ffff8800ce6de000 stage = ST_GC
segctord-14875 [003] ...1 28311.068139: nilfs2_collection_stage_transition: sci = ffff8800ce6de000 stage = ST_FILE
segctord-14875 [003] ...1 28311.068486: nilfs2_collection_stage_transition: sci = ffff8800ce6de000 stage = ST_IFILE
segctord-14875 [003] ...1 28311.068540: nilfs2_collection_stage_transition: sci = ffff8800ce6de000 stage = ST_CPFILE
segctord-14875 [003] ...1 28311.068561: nilfs2_collection_stage_transition: sci = ffff8800ce6de000 stage = ST_SUFILE
segctord-14875 [003] ...1 28311.068565: nilfs2_collection_stage_transition: sci = ffff8800ce6de000 stage = ST_DAT
segctord-14875 [003] ...1 28311.068573: nilfs2_collection_stage_transition: sci = ffff8800ce6de000 stage = ST_SR
segctord-14875 [003] ...1 28311.068574: nilfs2_collection_stage_transition: sci = ffff8800ce6de000 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 <mitake.hitoshi@lab.ntt.co.jp>
Signed-off-by: Ryusuke Konishi <konishi.ryusuke@lab.ntt.co.jp>
Cc: Steven Rostedt <rostedt@goodmis.org>
---
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 <trace/events/nilfs2.h>
+
+/*
+ * 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;
+ nilfs_sc_cstage_set(sci, NILFS_ST_DAT);
goto dat_stage;
}
- sci->sc_stage.scnt++; /* Fall through */
+ nilfs_sc_cstage_inc(sci); /* Fall through */
case NILFS_ST_GC:
if (nilfs_doing_gc()) {
head = &sci->sc_gc_inodes;
@@ -1103,7 +1133,7 @@ static int nilfs_segctor_collect_blocks(struct nilfs_sc_info *sci, int mode)
}
sci->sc_stage.gc_inode_ptr = NULL;
}
- sci->sc_stage.scnt++; /* Fall through */
+ nilfs_sc_cstage_inc(sci); /* Fall through */
case NILFS_ST_FILE:
head = &sci->sc_dirty_files;
ii = list_prepare_entry(sci->sc_stage.dirty_file_ptr, head,
@@ -1125,10 +1155,10 @@ static int nilfs_segctor_collect_blocks(struct nilfs_sc_info *sci, int mode)
}
sci->sc_stage.dirty_file_ptr = NULL;
if (mode == SC_FLUSH_FILE) {
- sci->sc_stage.scnt = NILFS_ST_DONE;
+ nilfs_sc_cstage_set(sci, NILFS_ST_DONE);
return 0;
}
- sci->sc_stage.scnt++;
+ nilfs_sc_cstage_inc(sci);
sci->sc_stage.flags |= NILFS_CF_IFILE_STARTED;
/* Fall through */
case NILFS_ST_IFILE:
@@ -1136,7 +1166,7 @@ static int nilfs_segctor_collect_blocks(struct nilfs_sc_info *sci, int mode)
&nilfs_sc_file_ops);
if (unlikely(err))
break;
- sci->sc_stage.scnt++;
+ nilfs_sc_cstage_inc(sci);
/* Creating a checkpoint */
err = nilfs_segctor_create_checkpoint(sci);
if (unlikely(err))
@@ -1147,7 +1177,7 @@ static int nilfs_segctor_collect_blocks(struct nilfs_sc_info *sci, int mode)
&nilfs_sc_file_ops);
if (unlikely(err))
break;
- sci->sc_stage.scnt++; /* Fall through */
+ nilfs_sc_cstage_inc(sci); /* Fall through */
case NILFS_ST_SUFILE:
err = nilfs_sufile_freev(nilfs->ns_sufile, sci->sc_freesegs,
sci->sc_nfreesegs, &ndone);
@@ -1163,7 +1193,7 @@ static int nilfs_segctor_collect_blocks(struct nilfs_sc_info *sci, int mode)
&nilfs_sc_file_ops);
if (unlikely(err))
break;
- sci->sc_stage.scnt++; /* Fall through */
+ nilfs_sc_cstage_inc(sci); /* Fall through */
case NILFS_ST_DAT:
dat_stage:
err = nilfs_segctor_scan_file(sci, nilfs->ns_dat,
@@ -1171,10 +1201,10 @@ static int nilfs_segctor_collect_blocks(struct nilfs_sc_info *sci, int mode)
if (unlikely(err))
break;
if (mode == SC_FLUSH_DAT) {
- sci->sc_stage.scnt = NILFS_ST_DONE;
+ nilfs_sc_cstage_set(sci, NILFS_ST_DONE);
return 0;
}
- sci->sc_stage.scnt++; /* Fall through */
+ nilfs_sc_cstage_inc(sci); /* Fall through */
case NILFS_ST_SR:
if (mode == SC_LSEG_SR) {
/* Appending a super root */
@@ -1184,7 +1214,7 @@ static int nilfs_segctor_collect_blocks(struct nilfs_sc_info *sci, int mode)
}
/* End of a logical segment */
sci->sc_curseg->sb_sum.flags |= NILFS_SS_LOGEND;
- sci->sc_stage.scnt = NILFS_ST_DONE;
+ nilfs_sc_cstage_set(sci, NILFS_ST_DONE);
return 0;
case NILFS_ST_DSYNC:
dsync_mode:
@@ -1197,7 +1227,7 @@ static int nilfs_segctor_collect_blocks(struct nilfs_sc_info *sci, int mode)
if (unlikely(err))
break;
sci->sc_curseg->sb_sum.flags |= NILFS_SS_LOGEND;
- sci->sc_stage.scnt = NILFS_ST_DONE;
+ nilfs_sc_cstage_set(sci, NILFS_ST_DONE);
return 0;
case NILFS_ST_DONE:
return 0;
@@ -1442,7 +1472,8 @@ static int nilfs_segctor_collect(struct nilfs_sc_info *sci,
goto failed;
/* The current segment is filled up */
- if (mode != SC_LSEG_SR || sci->sc_stage.scnt < NILFS_ST_CPFILE)
+ if (mode != SC_LSEG_SR ||
+ nilfs_sc_cstage_get(sci) < NILFS_ST_CPFILE)
break;
nilfs_clear_logs(&sci->sc_segbufs);
@@ -1946,7 +1977,7 @@ static int nilfs_segctor_do_construct(struct nilfs_sc_info *sci, int mode)
struct the_nilfs *nilfs = sci->sc_super->s_fs_info;
int err;
- sci->sc_stage.scnt = NILFS_ST_INIT;
+ nilfs_sc_cstage_set(sci, NILFS_ST_INIT);
sci->sc_cno = nilfs->ns_cno;
err = nilfs_segctor_collect_dirty_files(sci, nilfs);
@@ -1974,7 +2005,7 @@ static int nilfs_segctor_do_construct(struct nilfs_sc_info *sci, int mode)
goto failed;
/* Avoid empty segment */
- if (sci->sc_stage.scnt == NILFS_ST_DONE &&
+ if (nilfs_sc_cstage_get(sci) == NILFS_ST_DONE &&
nilfs_segbuf_empty(sci->sc_curseg)) {
nilfs_segctor_abort_construction(sci, nilfs, 1);
goto out;
@@ -1988,7 +2019,7 @@ static int nilfs_segctor_do_construct(struct nilfs_sc_info *sci, int mode)
nilfs_segctor_fill_in_file_bmap(sci);
if (mode == SC_LSEG_SR &&
- sci->sc_stage.scnt >= NILFS_ST_CPFILE) {
+ nilfs_sc_cstage_get(sci) >= NILFS_ST_CPFILE) {
err = nilfs_segctor_fill_in_checkpoint(sci);
if (unlikely(err))
goto failed_to_write;
@@ -2007,7 +2038,7 @@ static int nilfs_segctor_do_construct(struct nilfs_sc_info *sci, int mode)
if (unlikely(err))
goto failed_to_write;
- if (sci->sc_stage.scnt == NILFS_ST_DONE ||
+ if (nilfs_sc_cstage_get(sci) == NILFS_ST_DONE ||
nilfs->ns_blocksize_bits != PAGE_CACHE_SHIFT) {
/*
* At this point, we avoid double buffering
@@ -2020,7 +2051,7 @@ static int nilfs_segctor_do_construct(struct nilfs_sc_info *sci, int mode)
if (err)
goto failed_to_write;
}
- } while (sci->sc_stage.scnt != NILFS_ST_DONE);
+ } while (nilfs_sc_cstage_get(sci) != NILFS_ST_DONE);
out:
nilfs_segctor_drop_written_files(sci, nilfs);
diff --git a/fs/nilfs2/segment.h b/fs/nilfs2/segment.h
index a48d6de..0408b9b 100644
--- a/fs/nilfs2/segment.h
+++ b/fs/nilfs2/segment.h
@@ -67,7 +67,8 @@ struct nilfs_recovery_info {
/**
* struct nilfs_cstage - Context of collection stage
- * @scnt: Stage count
+ * @scnt: Stage count, must be accessed via wrappers:
+ * nilfs_sc_cstage_inc(), nilfs_sc_cstage_set(), nilfs_sc_cstage_get()
* @flags: State flags
* @dirty_file_ptr: Pointer on dirty_files list, or inode of a target file
* @gc_inode_ptr: Pointer on the list of gc-inodes
diff --git a/include/trace/events/nilfs2.h b/include/trace/events/nilfs2.h
new file mode 100644
index 0000000..573da00
--- /dev/null
+++ b/include/trace/events/nilfs2.h
@@ -0,0 +1,50 @@
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM nilfs2
+
+#if !defined(_TRACE_NILFS2_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_NILFS2_H
+
+#include <linux/tracepoint.h>
+
+struct nilfs_sc_info;
+
+#define show_collection_stage(type) \
+ __print_symbolic(type, \
+ { NILFS_ST_INIT, "ST_INIT" }, \
+ { NILFS_ST_GC, "ST_GC" }, \
+ { NILFS_ST_FILE, "ST_FILE" }, \
+ { NILFS_ST_IFILE, "ST_IFILE" }, \
+ { NILFS_ST_CPFILE, "ST_CPFILE" }, \
+ { NILFS_ST_SUFILE, "ST_SUFILE" }, \
+ { NILFS_ST_DAT, "ST_DAT" }, \
+ { NILFS_ST_SR, "ST_SR" }, \
+ { NILFS_ST_DSYNC, "ST_DSYNC" }, \
+ { NILFS_ST_DONE, "ST_DONE"})
+
+TRACE_EVENT(nilfs2_collection_stage_transition,
+
+ TP_PROTO(struct nilfs_sc_info *sci),
+
+ TP_ARGS(sci),
+
+ TP_STRUCT__entry(
+ __field(void *, sci)
+ __field(int, stage)
+ ),
+
+ TP_fast_assign(
+ __entry->sci = sci;
+ __entry->stage = sci->sc_stage.scnt;
+ ),
+
+ TP_printk("sci = %p stage = %s",
+ __entry->sci,
+ show_collection_stage(__entry->stage))
+);
+
+#endif /* _TRACE_NILFS2_H */
+
+/* This part must be outside protection */
+#undef TRACE_INCLUDE_FILE
+#define TRACE_INCLUDE_FILE nilfs2
+#include <trace/define_trace.h>
--
1.8.3.1
^ permalink raw reply related [flat|nested] 6+ messages in thread
* [PATCH 2/5] nilfs2: add a tracepoint for transaction events
2015-10-06 17:50 [PATCH 0/5] nilfs2: introduce tracepoints Ryusuke Konishi
2015-10-06 17:50 ` [PATCH 1/5] nilfs2: add a tracepoint for tracking stage transition of segment construction Ryusuke Konishi
@ 2015-10-06 17:50 ` Ryusuke Konishi
2015-10-06 17:50 ` [PATCH 3/5] nilfs2: add tracepoints for analyzing sufile manipulation Ryusuke Konishi
` (2 subsequent siblings)
4 siblings, 0 replies; 6+ messages in thread
From: Ryusuke Konishi @ 2015-10-06 17:50 UTC (permalink / raw)
To: Andrew Morton
Cc: Hitoshi Mitake, Steven Rostedt, linux-nilfs, LKML, Ryusuke Konishi
From: Hitoshi Mitake <mitake.hitoshi@lab.ntt.co.jp>
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] ...1 63.266220: nilfs2_transaction_transition: sb = ffff8802112b8800 ti = ffff8800bf5ccc58 count = 1 flags = 9 state = BEGIN
cp-4457 [000] ...1 63.266221: nilfs2_transaction_transition: sb = ffff8802112b8800 ti = ffff8800bf5ccc58 count = 0 flags = 9 state = COMMIT
cp-4457 [000] ...1 63.266221: nilfs2_transaction_transition: sb = ffff8802112b8800 ti = ffff8800bf5ccc58 count = 0 flags = 9 state = COMMIT
segctord-4371 [001] ...1 68.261196: nilfs2_transaction_transition: sb = ffff8802112b8800 ti = ffff8800b889bdf8 count = 0 flags = 10 state = TRYLOCK
segctord-4371 [001] ...1 68.261280: nilfs2_transaction_transition: sb = ffff8802112b8800 ti = ffff8800b889bdf8 count = 0 flags = 10 state = LOCK
segctord-4371 [001] ...1 68.261877: nilfs2_transaction_transition: sb = ffff8802112b8800 ti = ffff8800b889bdf8 count = 1 flags = 10 state = BEGIN
segctord-4371 [001] ...1 68.262116: nilfs2_transaction_transition: sb = ffff8802112b8800 ti = ffff8800b889bdf8 count = 0 flags = 18 state = COMMIT
segctord-4371 [001] ...1 68.265032: nilfs2_transaction_transition: sb = ffff8802112b8800 ti = ffff8800b889bdf8 count = 0 flags = 18 state = UNLOCK
segctord-4371 [001] ...1 132.376847: nilfs2_transaction_transition: sb = ffff8802112b8800 ti = ffff8800b889bdf8 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 <mitake.hitoshi@lab.ntt.co.jp>
Signed-off-by: Ryusuke Konishi <konishi.ryusuke@lab.ntt.co.jp>
Cc: Steven Rostedt <rostedt@goodmis.org>
---
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,
+ ti->ti_flags, TRACE_NILFS2_TRANSACTION_ABORT);
+
current->journal_info = ti->ti_save;
if (ti->ti_flags & NILFS_TI_DYNAMIC_ALLOC)
kmem_cache_free(nilfs_transaction_cachep, ti);
@@ -339,6 +361,9 @@ static void nilfs_transaction_lock(struct super_block *sb,
current->journal_info = ti;
for (;;) {
+ trace_nilfs2_transaction_transition(sb, ti, ti->ti_count,
+ ti->ti_flags, TRACE_NILFS2_TRANSACTION_TRYLOCK);
+
down_write(&nilfs->ns_segctor_sem);
if (!test_bit(NILFS_SC_PRIOR_FLUSH, &sci->sc_flags))
break;
@@ -350,6 +375,9 @@ static void nilfs_transaction_lock(struct super_block *sb,
}
if (gcflag)
ti->ti_flags |= NILFS_TI_GC;
+
+ trace_nilfs2_transaction_transition(sb, ti, ti->ti_count,
+ ti->ti_flags, TRACE_NILFS2_TRANSACTION_LOCK);
}
static void nilfs_transaction_unlock(struct super_block *sb)
@@ -362,6 +390,9 @@ static void nilfs_transaction_unlock(struct super_block *sb)
up_write(&nilfs->ns_segctor_sem);
current->journal_info = ti->ti_save;
+
+ trace_nilfs2_transaction_transition(sb, ti, ti->ti_count,
+ ti->ti_flags, TRACE_NILFS2_TRANSACTION_UNLOCK);
}
static void *nilfs_segctor_map_segsum_entry(struct nilfs_sc_info *sci,
diff --git a/include/trace/events/nilfs2.h b/include/trace/events/nilfs2.h
index 573da00..e5649ac 100644
--- a/include/trace/events/nilfs2.h
+++ b/include/trace/events/nilfs2.h
@@ -42,6 +42,59 @@ TRACE_EVENT(nilfs2_collection_stage_transition,
show_collection_stage(__entry->stage))
);
+#ifndef TRACE_HEADER_MULTI_READ
+enum nilfs2_transaction_transition_state {
+ TRACE_NILFS2_TRANSACTION_BEGIN,
+ TRACE_NILFS2_TRANSACTION_COMMIT,
+ TRACE_NILFS2_TRANSACTION_ABORT,
+ TRACE_NILFS2_TRANSACTION_TRYLOCK,
+ TRACE_NILFS2_TRANSACTION_LOCK,
+ TRACE_NILFS2_TRANSACTION_UNLOCK,
+};
+#endif
+
+#define show_transaction_state(type) \
+ __print_symbolic(type, \
+ { TRACE_NILFS2_TRANSACTION_BEGIN, "BEGIN" }, \
+ { TRACE_NILFS2_TRANSACTION_COMMIT, "COMMIT" }, \
+ { TRACE_NILFS2_TRANSACTION_ABORT, "ABORT" }, \
+ { TRACE_NILFS2_TRANSACTION_TRYLOCK, "TRYLOCK" }, \
+ { TRACE_NILFS2_TRANSACTION_LOCK, "LOCK" }, \
+ { TRACE_NILFS2_TRANSACTION_UNLOCK, "UNLOCK" })
+
+TRACE_EVENT(nilfs2_transaction_transition,
+ TP_PROTO(struct super_block *sb,
+ struct nilfs_transaction_info *ti,
+ int count,
+ unsigned int flags,
+ enum nilfs2_transaction_transition_state state),
+
+ TP_ARGS(sb, ti, count, flags, state),
+
+ TP_STRUCT__entry(
+ __field(void *, sb)
+ __field(void *, ti)
+ __field(int, count)
+ __field(unsigned int, flags)
+ __field(int, state)
+ ),
+
+ TP_fast_assign(
+ __entry->sb = sb;
+ __entry->ti = ti;
+ __entry->count = count;
+ __entry->flags = flags;
+ __entry->state = state;
+ ),
+
+ TP_printk("sb = %p ti = %p count = %d flags = %x state = %s",
+ __entry->sb,
+ __entry->ti,
+ __entry->count,
+ __entry->flags,
+ show_transaction_state(__entry->state))
+);
+
#endif /* _TRACE_NILFS2_H */
/* This part must be outside protection */
--
1.8.3.1
^ permalink raw reply related [flat|nested] 6+ messages in thread
* [PATCH 3/5] nilfs2: add tracepoints for analyzing sufile manipulation
2015-10-06 17:50 [PATCH 0/5] nilfs2: introduce tracepoints Ryusuke Konishi
2015-10-06 17:50 ` [PATCH 1/5] nilfs2: add a tracepoint for tracking stage transition of segment construction Ryusuke Konishi
2015-10-06 17:50 ` [PATCH 2/5] nilfs2: add a tracepoint for transaction events Ryusuke Konishi
@ 2015-10-06 17:50 ` Ryusuke Konishi
2015-10-06 17:50 ` [PATCH 4/5] nilfs2: add tracepoints for analyzing reading and writing metadata files Ryusuke Konishi
2015-10-06 17:50 ` [PATCH 5/5] MAINTAINERS: nilfs2: add header file for tracing Ryusuke Konishi
4 siblings, 0 replies; 6+ messages in thread
From: Ryusuke Konishi @ 2015-10-06 17:50 UTC (permalink / raw)
To: Andrew Morton
Cc: Hitoshi Mitake, Steven Rostedt, linux-nilfs, LKML,
Ryusuke Konishi, Benixon Dhas, TK Kato
From: Hitoshi Mitake <mitake.hitoshi@lab.ntt.co.jp>
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 = ffff880054f908a8 segnum = 2
segctord-17800 [002] ...1 10675.073477: nilfs2_segment_usage_allocated: sufile = ffff880054f908a8 segnum = 3
Cc: Benixon Dhas <benixon.dhas@wdc.com>
Cc: TK Kato <TK.Kato@wdc.com>
Signed-off-by: Hitoshi Mitake <mitake.hitoshi@lab.ntt.co.jp>
Signed-off-by: Ryusuke Konishi <konishi.ryusuke@lab.ntt.co.jp>
Cc: Steven Rostedt <rostedt@goodmis.org>
---
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 <trace/events/nilfs2.h>
+
/**
* 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
^ permalink raw reply related [flat|nested] 6+ messages in thread
* [PATCH 4/5] nilfs2: add tracepoints for analyzing reading and writing metadata files
2015-10-06 17:50 [PATCH 0/5] nilfs2: introduce tracepoints Ryusuke Konishi
` (2 preceding siblings ...)
2015-10-06 17:50 ` [PATCH 3/5] nilfs2: add tracepoints for analyzing sufile manipulation Ryusuke Konishi
@ 2015-10-06 17:50 ` Ryusuke Konishi
2015-10-06 17:50 ` [PATCH 5/5] MAINTAINERS: nilfs2: add header file for tracing Ryusuke Konishi
4 siblings, 0 replies; 6+ messages in thread
From: Ryusuke Konishi @ 2015-10-06 17:50 UTC (permalink / raw)
To: Andrew Morton
Cc: Hitoshi Mitake, Steven Rostedt, linux-nilfs, LKML,
Ryusuke Konishi, TK Kato
From: Hitoshi Mitake <mitake.hitoshi@lab.ntt.co.jp>
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 = ffff88022a8d0178 ino = 3 block = 155
cp-14635 [000] ...1 30598.199520: nilfs2_mdt_insert_new_block: inode = ffff88022a8d0178 ino = 3 block = 5
cp-14635 [000] ...1 30598.200828: nilfs2_mdt_insert_new_block: inode = ffff88022a8d0178 ino = 3 block = 253
Cc: TK Kato <TK.Kato@wdc.com>
Signed-off-by: Hitoshi Mitake <mitake.hitoshi@lab.ntt.co.jp>
Signed-off-by: Ryusuke Konishi <konishi.ryusuke@lab.ntt.co.jp>
Cc: Steven Rostedt <rostedt@goodmis.org>
---
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 <trace/events/nilfs2.h>
#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
^ permalink raw reply related [flat|nested] 6+ messages in thread
* [PATCH 5/5] MAINTAINERS: nilfs2: add header file for tracing
2015-10-06 17:50 [PATCH 0/5] nilfs2: introduce tracepoints Ryusuke Konishi
` (3 preceding siblings ...)
2015-10-06 17:50 ` [PATCH 4/5] nilfs2: add tracepoints for analyzing reading and writing metadata files Ryusuke Konishi
@ 2015-10-06 17:50 ` Ryusuke Konishi
4 siblings, 0 replies; 6+ messages in thread
From: Ryusuke Konishi @ 2015-10-06 17:50 UTC (permalink / raw)
To: Andrew Morton
Cc: Hitoshi Mitake, Steven Rostedt, linux-nilfs, LKML, Ryusuke Konishi
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 <konishi.ryusuke@lab.ntt.co.jp>
Cc: Hitoshi Mitake <mitake.hitoshi@lab.ntt.co.jp>
---
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 <yokota@netlab.is.tsukuba.ac.jp>
--
1.8.3.1
^ permalink raw reply related [flat|nested] 6+ messages in thread
end of thread, other threads:[~2015-10-06 17:57 UTC | newest]
Thread overview: 6+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2015-10-06 17:50 [PATCH 0/5] nilfs2: introduce tracepoints Ryusuke Konishi
2015-10-06 17:50 ` [PATCH 1/5] nilfs2: add a tracepoint for tracking stage transition of segment construction Ryusuke Konishi
2015-10-06 17:50 ` [PATCH 2/5] nilfs2: add a tracepoint for transaction events Ryusuke Konishi
2015-10-06 17:50 ` [PATCH 3/5] nilfs2: add tracepoints for analyzing sufile manipulation Ryusuke Konishi
2015-10-06 17:50 ` [PATCH 4/5] nilfs2: add tracepoints for analyzing reading and writing metadata files Ryusuke Konishi
2015-10-06 17:50 ` [PATCH 5/5] MAINTAINERS: nilfs2: add header file for tracing Ryusuke Konishi
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).