lkml.org 
[lkml]   [2009]   [May]   [12]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
Patch in this message
/
Date
From
SubjectRe: [RFC PATCH dm-ioband] Added in blktrace msgs for dm-ioband
CC more people on tracing issue

Ryo Tsuruta wrote:
> Hi Li,
>
> From: Li Zefan <lizf@cn.fujitsu.com>
> Subject: Re: [RFC PATCH dm-ioband] Added in blktrace msgs for dm-ioband
> Date: Tue, 12 May 2009 11:49:07 +0800
>
>> Ryo Tsuruta wrote:
>>> Hi Li,
>>>
>>> From: Ryo Tsuruta <ryov@valinux.co.jp>
>>> Subject: Re: [RFC PATCH dm-ioband] Added in blktrace msgs for dm-ioband
>>> Date: Thu, 07 May 2009 09:23:22 +0900 (JST)
>>>
>>>> Hi Li,
>>>>
>>>> From: Li Zefan <lizf@cn.fujitsu.com>
>>>> Subject: Re: [RFC PATCH dm-ioband] Added in blktrace msgs for dm-ioband
>>>> Date: Mon, 04 May 2009 11:24:27 +0800
>>>>
>>>>> Ryo Tsuruta wrote:
>>>>>> Hi Alan,
>>>>>>
>>>>>>> Hi Ryo -
>>>>>>>
>>>>>>> I don't know if you are taking in patches, but whilst trying to uncover
>>>>>>> some odd behavior I added some blktrace messages to dm-ioband-ctl.c. If
>>>>>>> you're keeping one code base for old stuff (2.6.18-ish RHEL stuff) and
>>>>>>> upstream you'll have to #if around these (the blktrace message stuff
>>>>>>> came in around 2.6.26 or 27 I think).
>>>>>>>
>>>>>>> My test case was to take a single 400GB storage device, put two 200GB
>>>>>>> partitions on it and then see what the "penalty" or overhead for adding
>>>>>>> dm-ioband on top. To do this I simply created an ext2 FS on each
>>>>>>> partition in parallel (two processes each doing a mkfs to one of the
>>>>>>> partitions). Then I put two dm-ioband devices on top of the two
>>>>>>> partitions (setting the weight to 100 in both cases - thus they should
>>>>>>> have equal access).
>>>>>>>
>>>>>>> Using default values I was seeing /very/ large differences - on the
>>>>>>> order of 3X. When I bumped the number of tokens to a large number
>>>>>>> (10,240) the timings got much closer (<2%). I have found that using
>>>>>>> weight-iosize performs worse than weight (closer to 5% penalty).
>>>>>> I could reproduce similar results. One dm-ioband device seems to stop
>>>>>> issuing I/Os for a few seconds at times. I'll investigate more on that.
>>>>>>
>>>>>>> I'll try to formalize these results as I go forward and report out on
>>>>>>> them. In any event, I thought I'd share this patch with you if you are
>>>>>>> interested...
>>>>>> Thanks. I'll include your patche into the next release.
>>>>>>
>>>>> IMO we should use TRACE_EVENT instead of adding new blk_add_trace_msg().
>>>> Thanks for your suggestion. I'll use TRACE_EVENT instead.
>>> blk_add_trace_msg() supports both blktrace and tracepoints. I can
>>> get messages from dm-ioband through debugfs. Could you expain why
>>> should we use TRACE_EVENT instead?
>>>
>> Actually blk_add_trace_msg() has nothing to do with tracepoints..
>>
>> If we use blk_add_trace_msg() is dm, we can use it in md, various block
>> drivers and even ext4. So the right thing is, if a subsystem wants to add
>> trace facility, it should use tracepoints/TRACE_EVENT.
>>
>> With TRACE_EVENT, you can get output through debugfs too, and it can be used
>> together with blktrace:
>>
>> # echo 1 > /sys/block/dm/trace/enable
>> # echo blk > /debugfs/tracing/current_tracer
>> # echo dm-ioband-foo > /debugfs/tracing/tracing/set_event
>> # cat /deubgfs/tracing/trace_pipe
>>
>> And you can enable dm-ioband-foo while disabling dm-ioband-bar, and you can
>> use filter feature too.
>
> Thanks for explaining.
> The base kernel of current dm tree (2.6.30-rc4) has not supported
> dm-device tracing yet. I'll consider using TRACE_EVENT when the base
> kernel supports dm-device tracing.
>

I think we don't have any plan on dm-device tracing support, do we? And you
don't need that.

I downloaded dm-ioband 1.10.4, and applied it to latest tip-tree, and made
a patch to convert those blktrace msgs to trace events.

# ls /debug/tracing/events/dm-ioband
enable ioband_endio ioband_issue_list ioband_urgent_bio
filter ioband_hold_bio ioband_make_request
# echo 1 /debug/tracing/events/dm-ioband/enable
# echo blk /debug/tracing/current_tracer
...

Here is a sample output:

pdflush-237 [001] 1706.377788: ioband_hold_bio: 8,9 ioband 1 hold_nrm 1
pdflush-237 [001] 1706.377795: 254,0 Q W 188832 + 8 [pdflush]
pdflush-237 [001] 1706.377800: ioband_hold_bio: 8,9 ioband 1 hold_nrm 2
pdflush-237 [001] 1706.377806: 254,0 Q W 197032 + 8 [pdflush]
pdflush-237 [001] 1706.377835: 254,0 C W 82232 + 8 [0]
kioband/1-2569 [001] 1706.377922: ioband_issue_list: 8,9 ioband 1 add_iss 1 1
kioband/1-2569 [001] 1706.377923: ioband_issue_list: 8,9 ioband 1 add_iss 0 0
kioband/1-2569 [001] 1706.377925: ioband_make_request: 8,9 ioband 1 pop_iss
kioband/1-2569 [001] 1706.377940: ioband_make_request: 8,9 ioband 1 pop_iss
konsole-2140 [001] 1706.377969: 254,0 C W 90432 + 8 [0]
konsole-2140 [001] 1706.378087: 254,0 C W 98632 + 8 [0]
konsole-2140 [001] 1706.378232: 254,0 C W 106832 + 8 [0]
konsole-2140 [001] 1706.378350: 254,0 C W 115032 + 8 [0]
konsole-2140 [001] 1706.378466: 254,0 C W 123232 + 8 [0]
konsole-2140 [001] 1706.378581: 254,0 C W 131432 + 8 [0]

---
drivers/md/dm-ioband-ctl.c | 19 +++++-
include/trace/events/dm-ioband.h | 134 ++++++++++++++++++++++++++++++++++++++
2 files changed, 150 insertions(+), 3 deletions(-)
create mode 100644 include/trace/events/dm-ioband.h
diff --git a/drivers/md/dm-ioband-ctl.c b/drivers/md/dm-ioband-ctl.c
index 151b178..4033724 100644
--- a/drivers/md/dm-ioband-ctl.c
+++ b/drivers/md/dm-ioband-ctl.c
@@ -17,6 +17,9 @@
#include "md.h"
#include "dm-ioband.h"

+#define CREATE_TRACE_POINTS
+#include <trace/events/dm-ioband.h>
+
#define POLICY_PARAM_START 6
#define POLICY_PARAM_DELIM "=:,"

@@ -632,9 +635,11 @@ static void hold_bio(struct ioband_group *gp, struct bio *bio)
*/
dp->g_prepare_bio(gp, bio, IOBAND_URGENT);
bio_list_add(&dp->g_urgent_bios, bio);
+ trace_ioband_hold_bio(bio, dp, true);
} else {
gp->c_blocked++;
dp->g_hold_bio(gp, bio);
+ trace_ioband_hold_bio(bio, dp, false);
}
}

@@ -675,14 +680,17 @@ static int make_issue_list(struct ioband_group *gp, struct bio *bio,
clear_group_blocked(gp);
wake_up_all(&gp->c_waitq);
}
- if (should_pushback_bio(gp))
+ if (should_pushback_bio(gp)) {
bio_list_add(pushback_list, bio);
+ trace_ioband_issue_list(bio, dp, gp, true);
+ }
else {
int rw = bio_data_dir(bio);

gp->c_stat[rw].deferred++;
gp->c_stat[rw].sectors += bio_sectors(bio);
bio_list_add(issue_list, bio);
+ trace_ioband_issue_list(bio, dp, gp, false);
}
return prepare_to_issue(gp, bio);
}
@@ -702,6 +710,7 @@ static void release_urgent_bios(struct ioband_device *dp,
dp->g_blocked--;
dp->g_issued[bio_data_dir(bio)]++;
bio_list_add(issue_list, bio);
+ trace_ioband_urgent_bio(bio, dp);
}
}

@@ -915,10 +924,14 @@ static void ioband_conduct(struct work_struct *work)

spin_unlock_irqrestore(&dp->g_lock, flags);

- while ((bio = bio_list_pop(&issue_list)))
+ while ((bio = bio_list_pop(&issue_list))) {
+ trace_ioband_make_request(bio, dp);
generic_make_request(bio);
- while ((bio = bio_list_pop(&pushback_list)))
+ }
+ while ((bio = bio_list_pop(&pushback_list))) {
+ trace_ioband_endio(bio, dp);
bio_endio(bio, -EIO);
+ }
}

static int ioband_end_io(struct dm_target *ti, struct bio *bio,
diff --git a/include/trace/events/dm-ioband.h b/include/trace/events/dm-ioband.h
new file mode 100644
index 0000000..17dd61c
--- /dev/null
+++ b/include/trace/events/dm-ioband.h
@@ -0,0 +1,134 @@
+#if !defined(_TRACE_DM_IOBAND_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_DM_IOBAND_H
+
+#include <linux/tracepoint.h>
+#include <linux/interrupt.h>
+
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM dm-ioband
+
+TRACE_EVENT(ioband_hold_bio,
+
+ TP_PROTO(struct bio *bio, struct ioband_device *dp, bool urg),
+
+ TP_ARGS(bio, dp, urg),
+
+ TP_STRUCT__entry(
+ __field( dev_t, dev )
+ __field( bool, urg )
+ __field( int, g_blocked )
+ __string( g_name, dp->g_name )
+ ),
+
+ TP_fast_assign(
+ __entry->dev = bio->bi_bdev->bd_dev;
+ __entry->urg = urg;
+ __entry->g_blocked = dp->g_blocked;
+ __assign_str(g_name, dp->g_name);
+ ),
+
+ TP_printk("%d,%d ioband %s hold_%s %d",
+ MAJOR(__entry->dev), MINOR(__entry->dev),
+ __get_str(g_name),
+ __entry->urg ? "urg" : "nrm", __entry->g_blocked)
+);
+
+TRACE_EVENT(ioband_issue_list,
+
+ TP_PROTO(struct bio *bio, struct ioband_device *dp,
+ struct ioband_group *gp, bool pushback),
+
+ TP_ARGS(bio, dp, gp, pushback),
+
+ TP_STRUCT__entry(
+ __field( dev_t, dev )
+ __field( bool, pushback )
+ __field( int, g_blocked )
+ __field( int, c_blocked )
+ __string( g_name, dp->g_name )
+ ),
+
+ TP_fast_assign(
+ __entry->dev = bio->bi_bdev->bd_dev;
+ __entry->pushback = pushback;
+ __entry->g_blocked = dp->g_blocked;
+ __entry->c_blocked = gp->c_blocked;
+ __assign_str(g_name, dp->g_name);
+ ),
+
+ TP_printk("%d,%d ioband %s add_%s %d %d",
+ MAJOR(__entry->dev), MINOR(__entry->dev),
+ __get_str(g_name),
+ __entry->pushback ? "pback" : "iss",
+ __entry->g_blocked, __entry->c_blocked)
+);
+
+TRACE_EVENT(ioband_urgent_bio,
+
+ TP_PROTO(struct bio *bio, struct ioband_device *dp),
+
+ TP_ARGS(bio, dp),
+
+ TP_STRUCT__entry(
+ __field( dev_t, dev )
+ __field( int, g_blocked )
+ __string( g_name, dp->g_name )
+ ),
+
+ TP_fast_assign(
+ __entry->dev = bio->bi_bdev->bd_dev;
+ __entry->g_blocked = dp->g_blocked;
+ __assign_str(g_name, dp->g_name);
+ ),
+
+ TP_printk("%d,%d ioband %s urg_add_iss %d",
+ MAJOR(__entry->dev), MINOR(__entry->dev),
+ __get_str(g_name), __entry->g_blocked)
+);
+
+TRACE_EVENT(ioband_make_request,
+
+ TP_PROTO(struct bio *bio, struct ioband_device *dp),
+
+ TP_ARGS(bio, dp),
+
+ TP_STRUCT__entry(
+ __field( dev_t, dev )
+ __string( g_name, dp->g_name )
+ ),
+
+ TP_fast_assign(
+ __entry->dev = bio->bi_bdev->bd_dev;
+ __assign_str(g_name, dp->g_name);
+ ),
+
+ TP_printk("%d,%d ioband %s pop_iss",
+ MAJOR(__entry->dev), MINOR(__entry->dev), __get_str(g_name))
+);
+
+TRACE_EVENT(ioband_endio,
+
+ TP_PROTO(struct bio *bio, struct ioband_device *dp),
+
+ TP_ARGS(bio, dp),
+
+ TP_STRUCT__entry(
+ __field( dev_t, dev )
+ __string( g_name, dp->g_name )
+ ),
+
+ TP_fast_assign(
+ __entry->dev = bio->bi_bdev->bd_dev;
+ __assign_str(g_name, dp->g_name);
+ ),
+
+ TP_printk("%d,%d ioband %s pop_pback",
+ MAJOR(__entry->dev), MINOR(__entry->dev), __get_str(g_name))
+);
+
+#endif /* _TRACE_DM_IOBAND_H */
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>
+
+
--
1.5.4.rc3


\
 
 \ /
  Last update: 2009-05-12 10:13    [from the cache]
©2003-2011 Jasper Spaans. Advertise on this site