Re: [PATCH RFC] nilfs2: add a tracepoint for tracking stage transition of segment construction

2014-09-04 Thread Hitoshi Mitake
On Thu, Sep 4, 2014 at 3:23 AM, Ryusuke Konishi
 wrote:
> Hi Mitake-san,
> On Tue,  2 Sep 2014 21:19:39 +0900, Mitake Hitoshi wrote:
>> 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 renames the member scnt
>> of nilfs_cstage and adds wrappers for the member. With this change,
>> every transition of the stage can produce trace event in a correct
>> manner.
>>
>> Of course the tracepoint added by this patch is very limited, so we
>> need to add more points for detailed analysis. This patch is something
>> like demonstration. If this concept is acceptable for the nilfs
>> community, I'd like to add more tracepoints and prepare analysis
>> tools.
>
> Great!
>
> This tracepoint support looks to be what I wanted to introduce to
> nilfs2 to help debugging and performance analysis. I felt it's really
> nice after I tried this patch with the perf-tools though I am not
> familiar with the manner of the tracepoints.
>
> Could you proceed this work from what you think useful ?  I will help
> sending this work to upstream step by step, and would like to extend
> it learning various tracepoint features.

Sure, I'd like to work on improving the tracepoints for better
analysis and debugging.

>
> By the way, your mail addresses differ between the author line (from
> line) and the sob line.  Can you include a "From" line so that the
> mail addresses match between them.

Sorry, I'll fix the mismatch in v2. Thanks for your pointing.

Thanks,
Hitoshi

>
> Thanks,
> Ryusuke Konishi
>
>> Signed-off-by: Hitoshi Mitake 
>> ---
>>  fs/nilfs2/segment.c   | 70 
>> ++-
>>  fs/nilfs2/segment.h   |  5 ++--
>>  include/trace/events/nilfs2.h | 50 +++
>>  3 files changed, 103 insertions(+), 22 deletions(-)
>>  create mode 100644 include/trace/events/nilfs2.h
>>
>> diff --git a/fs/nilfs2/segment.c b/fs/nilfs2/segment.c
>> index a1a1916..e841e22 100644
>> --- a/fs/nilfs2/segment.c
>> +++ b/fs/nilfs2/segment.c
>> @@ -76,6 +76,35 @@ 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 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_sta

Re: [PATCH RFC] nilfs2: add a tracepoint for tracking stage transition of segment construction

2014-09-03 Thread Ryusuke Konishi
Hi Mitake-san,
On Tue,  2 Sep 2014 21:19:39 +0900, Mitake Hitoshi wrote:
> 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 renames the member scnt
> of nilfs_cstage and adds wrappers for the member. With this change,
> every transition of the stage can produce trace event in a correct
> manner.
> 
> Of course the tracepoint added by this patch is very limited, so we
> need to add more points for detailed analysis. This patch is something
> like demonstration. If this concept is acceptable for the nilfs
> community, I'd like to add more tracepoints and prepare analysis
> tools.

Great!

This tracepoint support looks to be what I wanted to introduce to
nilfs2 to help debugging and performance analysis. I felt it's really
nice after I tried this patch with the perf-tools though I am not
familiar with the manner of the tracepoints.

Could you proceed this work from what you think useful ?  I will help
sending this work to upstream step by step, and would like to extend
it learning various tracepoint features.

By the way, your mail addresses differ between the author line (from
line) and the sob line.  Can you include a "From" line so that the
mail addresses match between them.

Thanks,
Ryusuke Konishi

> Signed-off-by: Hitoshi Mitake 
> ---
>  fs/nilfs2/segment.c   | 70 
> ++-
>  fs/nilfs2/segment.h   |  5 ++--
>  include/trace/events/nilfs2.h | 50 +++
>  3 files changed, 103 insertions(+), 22 deletions(-)
>  create mode 100644 include/trace/events/nilfs2.h
> 
> diff --git a/fs/nilfs2/segment.c b/fs/nilfs2/segment.c
> index a1a1916..e841e22 100644
> --- a/fs/nilfs2/segment.c
> +++ b/fs/nilfs2/segment.c
> @@ -76,6 +76,35 @@ 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 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_NODE0x0001  /* Collecting node blocks */
>  #define NILFS_CF_IFILE_STARTED   0x0002  /* IFILE stage has started */
> @@

[PATCH RFC] nilfs2: add a tracepoint for tracking stage transition of segment construction

2014-09-02 Thread Hitoshi Mitake
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 renames the member scnt
of nilfs_cstage and adds wrappers for the member. With this change,
every transition of the stage can produce trace event in a correct
manner.

Of course the tracepoint added by this patch is very limited, so we
need to add more points for detailed analysis. This patch is something
like demonstration. If this concept is acceptable for the nilfs
community, I'd like to add more tracepoints and prepare analysis
tools.

Signed-off-by: Hitoshi Mitake 
---
 fs/nilfs2/segment.c   | 70 ++-
 fs/nilfs2/segment.h   |  5 ++--
 include/trace/events/nilfs2.h | 50 +++
 3 files changed, 103 insertions(+), 22 deletions(-)
 create mode 100644 include/trace/events/nilfs2.h

diff --git a/fs/nilfs2/segment.c b/fs/nilfs2/segment.c
index a1a1916..e841e22 100644
--- a/fs/nilfs2/segment.c
+++ b/fs/nilfs2/segment.c
@@ -76,6 +76,35 @@ 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 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 */
@@ -1055,7 +1084,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;
@@ -1064,7 +1093,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;
}
}
@@ -1072,10 +1101,10 @@ static int nilfs_segctor_collect_blocks(struct