Not all events are pc (packet command) events. An event is a pc
event only if it has BLK_TC_PC bit set.
Signed-off-by: Li Zefan <[email protected]>
---
kernel/trace/blktrace.c | 2 +-
1 files changed, 1 insertions(+), 1 deletions(-)
diff --git a/kernel/trace/blktrace.c b/kernel/trace/blktrace.c
index 947c5b3..464a6e5 100644
--- a/kernel/trace/blktrace.c
+++ b/kernel/trace/blktrace.c
@@ -1181,7 +1181,7 @@ static enum print_line_t print_one_line(struct trace_iterator *iter,
}
if (unlikely(what == 0 || what >= ARRAY_SIZE(what2act)))
- ret = trace_seq_printf(s, "Bad pc action %x\n", what);
+ ret = trace_seq_printf(s, "Unknown action %x\n", what);
else {
ret = log_action(iter, what2act[what].act[long_act]);
if (ret)
--
1.5.4.rc3
BLK_TC_PC events should be treated differently with BLK_TC_FS events.
Before this patch:
# echo 1 > /sys/block/sda/sda1/trace/enable
# echo pc > /sys/block/sda/sda1/trace/act_mask
# echo blk > /debugfs/tracing/current_tracer
# (generate some BLK_TC_PC events)
# cat trace
bash-2184 [000] 1774.275413: 8,7 I N [bash]
bash-2184 [000] 1774.275435: 8,7 D N [bash]
bash-2184 [000] 1774.275540: 8,7 I R [bash]
bash-2184 [000] 1774.275547: 8,7 D R [bash]
ksoftirqd/0-4 [000] 1774.275580: 8,7 C N 0 [0]
bash-2184 [000] 1774.275648: 8,7 I R [bash]
bash-2184 [000] 1774.275653: 8,7 D R [bash]
ksoftirqd/0-4 [000] 1774.275682: 8,7 C N 0 [0]
bash-2184 [000] 1774.275739: 8,7 I R [bash]
bash-2184 [000] 1774.275744: 8,7 D R [bash]
ksoftirqd/0-4 [000] 1774.275771: 8,7 C N 0 [0]
bash-2184 [000] 1774.275804: 8,7 I R [bash]
bash-2184 [000] 1774.275808: 8,7 D R [bash]
ksoftirqd/0-4 [000] 1774.275836: 8,7 C N 0 [0]
After this patch:
# cat trace
bash-2263 [000] 366.782149: 8,7 I N 0 (00 ..) [bash]
bash-2263 [000] 366.782323: 8,7 D N 0 (00 ..) [bash]
bash-2263 [000] 366.782557: 8,7 I R 8 (25 00 ..) [bash]
bash-2263 [000] 366.782560: 8,7 D R 8 (25 00 ..) [bash]
ksoftirqd/0-4 [000] 366.782582: 8,7 C N (25 00 ..) [0]
bash-2263 [000] 366.782648: 8,7 I R 8 (5a 00 3f 00) [bash]
bash-2263 [000] 366.782650: 8,7 D R 8 (5a 00 3f 00) [bash]
ksoftirqd/0-4 [000] 366.782669: 8,7 C N (5a 00 3f 00) [0]
bash-2263 [000] 366.782710: 8,7 I R 8 (5a 00 08 00) [bash]
bash-2263 [000] 366.782713: 8,7 D R 8 (5a 00 08 00) [bash]
ksoftirqd/0-4 [000] 366.782730: 8,7 C N (5a 00 08 00) [0]
bash-2263 [000] 366.783375: 8,7 I R 36 (5a 00 08 00) [bash]
bash-2263 [000] 366.783379: 8,7 D R 36 (5a 00 08 00) [bash]
ksoftirqd/0-4 [000] 366.783404: 8,7 C N (5a 00 08 00) [0]
This is what we do with PC events in user-space blktrace.
Signed-off-by: Li Zefan <[email protected]>
---
kernel/trace/blktrace.c | 88 ++++++++++++++++++++++++++++++++++++++++++----
1 files changed, 80 insertions(+), 8 deletions(-)
diff --git a/kernel/trace/blktrace.c b/kernel/trace/blktrace.c
index 464a6e5..fd1ff49 100644
--- a/kernel/trace/blktrace.c
+++ b/kernel/trace/blktrace.c
@@ -970,6 +970,16 @@ static inline const void *pdu_start(const struct trace_entry *ent)
return te_blk_io_trace(ent) + 1;
}
+static inline u32 t_action(const struct trace_entry *ent)
+{
+ return te_blk_io_trace(ent)->action;
+}
+
+static inline u32 t_bytes(const struct trace_entry *ent)
+{
+ return te_blk_io_trace(ent)->bytes;
+}
+
static inline u32 t_sec(const struct trace_entry *ent)
{
return te_blk_io_trace(ent)->bytes >> 9;
@@ -1030,25 +1040,87 @@ static int blk_log_action(struct trace_iterator *iter, const char *act)
MAJOR(t->device), MINOR(t->device), act, rwbs);
}
+static int blk_log_dump_pdu(struct trace_seq *s, const struct trace_entry *ent)
+{
+ const char *pdu_buf;
+ int pdu_len;
+ int i, end, ret;
+
+ pdu_buf = pdu_start(ent);
+ pdu_len = te_blk_io_trace(ent)->pdu_len;
+
+ if (!pdu_len)
+ return 1;
+
+ /* find the last zero that needs to be printed */
+ for (end = pdu_len - 1; end >= 0; end--)
+ if (pdu_buf[end])
+ break;
+ end++;
+
+ if (!trace_seq_putc(s, '('))
+ return 0;
+
+ for (i = 0; i < pdu_len; i++) {
+
+ ret = trace_seq_printf(s, "%s%02x",
+ i == 0 ? "" : " ", pdu_buf[i]);
+ if (!ret)
+ return ret;
+
+ /*
+ * stop when the rest is just zeroes and indicate so
+ * with a ".." appended
+ */
+ if (i == end && end != pdu_len - 1)
+ return trace_seq_puts(s, " ..) ");
+ }
+
+ return trace_seq_puts(s, ") ");
+}
+
static int blk_log_generic(struct trace_seq *s, const struct trace_entry *ent)
{
char cmd[TASK_COMM_LEN];
trace_find_cmdline(ent->pid, cmd);
- if (t_sec(ent))
- return trace_seq_printf(s, "%llu + %u [%s]\n",
- t_sector(ent), t_sec(ent), cmd);
- return trace_seq_printf(s, "[%s]\n", cmd);
+ if (t_action(ent) & BLK_TC_ACT(BLK_TC_PC)) {
+ int ret;
+
+ ret = trace_seq_printf(s, "%u ", t_bytes(ent));
+ if (!ret)
+ return 0;
+ ret = blk_log_dump_pdu(s, ent);
+ if (!ret)
+ return 0;
+ return trace_seq_printf(s, "[%s]\n", cmd);
+ } else {
+ if (t_sec(ent))
+ return trace_seq_printf(s, "%llu + %u [%s]\n",
+ t_sector(ent), t_sec(ent), cmd);
+ return trace_seq_printf(s, "[%s]\n", cmd);
+ }
}
static int blk_log_with_error(struct trace_seq *s,
const struct trace_entry *ent)
{
- if (t_sec(ent))
- return trace_seq_printf(s, "%llu + %u [%d]\n", t_sector(ent),
- t_sec(ent), t_error(ent));
- return trace_seq_printf(s, "%llu [%d]\n", t_sector(ent), t_error(ent));
+ if (t_action(ent) & BLK_TC_ACT(BLK_TC_PC)) {
+ int ret;
+
+ ret = blk_log_dump_pdu(s, ent);
+ if (ret)
+ return trace_seq_printf(s, "[%d]\n", t_error(ent));
+ return 0;
+ } else {
+ if (t_sec(ent))
+ return trace_seq_printf(s, "%llu + %u [%d]\n",
+ t_sector(ent),
+ t_sec(ent), t_error(ent));
+ return trace_seq_printf(s, "%llu [%d]\n",
+ t_sector(ent), t_error(ent));
+ }
}
static int blk_log_remap(struct trace_seq *s, const struct trace_entry *ent)
--
1.5.4.rc3
* Li Zefan <[email protected]> wrote:
> BLK_TC_PC events should be treated differently with BLK_TC_FS events.
>
> Before this patch:
>
> # echo 1 > /sys/block/sda/sda1/trace/enable
> # echo pc > /sys/block/sda/sda1/trace/act_mask
> # echo blk > /debugfs/tracing/current_tracer
> # (generate some BLK_TC_PC events)
> # cat trace
> bash-2184 [000] 1774.275413: 8,7 I N [bash]
> bash-2184 [000] 1774.275435: 8,7 D N [bash]
> bash-2184 [000] 1774.275540: 8,7 I R [bash]
> bash-2184 [000] 1774.275547: 8,7 D R [bash]
> ksoftirqd/0-4 [000] 1774.275580: 8,7 C N 0 [0]
> bash-2184 [000] 1774.275648: 8,7 I R [bash]
> bash-2184 [000] 1774.275653: 8,7 D R [bash]
> ksoftirqd/0-4 [000] 1774.275682: 8,7 C N 0 [0]
> bash-2184 [000] 1774.275739: 8,7 I R [bash]
> bash-2184 [000] 1774.275744: 8,7 D R [bash]
> ksoftirqd/0-4 [000] 1774.275771: 8,7 C N 0 [0]
> bash-2184 [000] 1774.275804: 8,7 I R [bash]
> bash-2184 [000] 1774.275808: 8,7 D R [bash]
> ksoftirqd/0-4 [000] 1774.275836: 8,7 C N 0 [0]
>
> After this patch:
>
> # cat trace
> bash-2263 [000] 366.782149: 8,7 I N 0 (00 ..) [bash]
> bash-2263 [000] 366.782323: 8,7 D N 0 (00 ..) [bash]
> bash-2263 [000] 366.782557: 8,7 I R 8 (25 00 ..) [bash]
> bash-2263 [000] 366.782560: 8,7 D R 8 (25 00 ..) [bash]
> ksoftirqd/0-4 [000] 366.782582: 8,7 C N (25 00 ..) [0]
> bash-2263 [000] 366.782648: 8,7 I R 8 (5a 00 3f 00) [bash]
> bash-2263 [000] 366.782650: 8,7 D R 8 (5a 00 3f 00) [bash]
> ksoftirqd/0-4 [000] 366.782669: 8,7 C N (5a 00 3f 00) [0]
> bash-2263 [000] 366.782710: 8,7 I R 8 (5a 00 08 00) [bash]
> bash-2263 [000] 366.782713: 8,7 D R 8 (5a 00 08 00) [bash]
> ksoftirqd/0-4 [000] 366.782730: 8,7 C N (5a 00 08 00) [0]
> bash-2263 [000] 366.783375: 8,7 I R 36 (5a 00 08 00) [bash]
> bash-2263 [000] 366.783379: 8,7 D R 36 (5a 00 08 00) [bash]
> ksoftirqd/0-4 [000] 366.783404: 8,7 C N (5a 00 08 00) [0]
>
> This is what we do with PC events in user-space blktrace.
>
> Signed-off-by: Li Zefan <[email protected]>
> ---
> kernel/trace/blktrace.c | 88 ++++++++++++++++++++++++++++++++++++++++++----
> 1 files changed, 80 insertions(+), 8 deletions(-)
>
> diff --git a/kernel/trace/blktrace.c b/kernel/trace/blktrace.c
> index 464a6e5..fd1ff49 100644
> --- a/kernel/trace/blktrace.c
> +++ b/kernel/trace/blktrace.c
> @@ -970,6 +970,16 @@ static inline const void *pdu_start(const struct trace_entry *ent)
> return te_blk_io_trace(ent) + 1;
> }
>
> +static inline u32 t_action(const struct trace_entry *ent)
> +{
> + return te_blk_io_trace(ent)->action;
> +}
> +
> +static inline u32 t_bytes(const struct trace_entry *ent)
> +{
> + return te_blk_io_trace(ent)->bytes;
> +}
> +
> static inline u32 t_sec(const struct trace_entry *ent)
> {
> return te_blk_io_trace(ent)->bytes >> 9;
> @@ -1030,25 +1040,87 @@ static int blk_log_action(struct trace_iterator *iter, const char *act)
> MAJOR(t->device), MINOR(t->device), act, rwbs);
> }
>
> +static int blk_log_dump_pdu(struct trace_seq *s, const struct trace_entry *ent)
> +{
> + const char *pdu_buf;
> + int pdu_len;
> + int i, end, ret;
> +
> + pdu_buf = pdu_start(ent);
> + pdu_len = te_blk_io_trace(ent)->pdu_len;
> +
> + if (!pdu_len)
> + return 1;
> +
> + /* find the last zero that needs to be printed */
> + for (end = pdu_len - 1; end >= 0; end--)
> + if (pdu_buf[end])
> + break;
> + end++;
> +
> + if (!trace_seq_putc(s, '('))
> + return 0;
> +
> + for (i = 0; i < pdu_len; i++) {
> +
> + ret = trace_seq_printf(s, "%s%02x",
> + i == 0 ? "" : " ", pdu_buf[i]);
> + if (!ret)
> + return ret;
> +
> + /*
> + * stop when the rest is just zeroes and indicate so
> + * with a ".." appended
> + */
> + if (i == end && end != pdu_len - 1)
> + return trace_seq_puts(s, " ..) ");
> + }
> +
> + return trace_seq_puts(s, ") ");
> +}
> +
> static int blk_log_generic(struct trace_seq *s, const struct trace_entry *ent)
> {
> char cmd[TASK_COMM_LEN];
>
> trace_find_cmdline(ent->pid, cmd);
>
> - if (t_sec(ent))
> - return trace_seq_printf(s, "%llu + %u [%s]\n",
> - t_sector(ent), t_sec(ent), cmd);
> - return trace_seq_printf(s, "[%s]\n", cmd);
> + if (t_action(ent) & BLK_TC_ACT(BLK_TC_PC)) {
> + int ret;
> +
> + ret = trace_seq_printf(s, "%u ", t_bytes(ent));
> + if (!ret)
> + return 0;
> + ret = blk_log_dump_pdu(s, ent);
> + if (!ret)
> + return 0;
> + return trace_seq_printf(s, "[%s]\n", cmd);
> + } else {
> + if (t_sec(ent))
> + return trace_seq_printf(s, "%llu + %u [%s]\n",
> + t_sector(ent), t_sec(ent), cmd);
> + return trace_seq_printf(s, "[%s]\n", cmd);
> + }
> }
>
> static int blk_log_with_error(struct trace_seq *s,
> const struct trace_entry *ent)
> {
> - if (t_sec(ent))
> - return trace_seq_printf(s, "%llu + %u [%d]\n", t_sector(ent),
> - t_sec(ent), t_error(ent));
> - return trace_seq_printf(s, "%llu [%d]\n", t_sector(ent), t_error(ent));
> + if (t_action(ent) & BLK_TC_ACT(BLK_TC_PC)) {
> + int ret;
> +
> + ret = blk_log_dump_pdu(s, ent);
> + if (ret)
> + return trace_seq_printf(s, "[%d]\n", t_error(ent));
> + return 0;
> + } else {
> + if (t_sec(ent))
> + return trace_seq_printf(s, "%llu + %u [%d]\n",
> + t_sector(ent),
> + t_sec(ent), t_error(ent));
> + return trace_seq_printf(s, "%llu [%d]\n",
> + t_sector(ent), t_error(ent));
> + }
> }
>
> static int blk_log_remap(struct trace_seq *s, const struct trace_entry *ent)
Neat shortcut - packet command requests can be quite large in
special cases, right?
Sidenote. Right now we reserve the full packet length in the trace
buffer, then copy the full packet into the trace buffer:
if (pdu_len)
memcpy((void *) t + sizeof(*t), pdu_data, pdu_len);
... just to scan it a second time during output and discard much of
it later on if it has a lot of trailing zeroes.
It might make sense to pre-compress: by extending the trace record
format with a trailing-zeroes field.
But that would make it more complex and key to tracers is simplicity
of data acquisition.
Dunno, probably not worth it, except if data stream bloat becomes a
real issue (which i'd not expect them to become in this case).
Anyway - Jens, the two patches look good to me, do they look fine to
you too?
Ingo
Em Wed, Apr 01, 2009 at 04:18:53PM +0800, Li Zefan escreveu:
> Not all events are pc (packet command) events. An event is a pc
> event only if it has BLK_TC_PC bit set.
>
> Signed-off-by: Li Zefan <[email protected]>
> ---
> kernel/trace/blktrace.c | 2 +-
> 1 files changed, 1 insertions(+), 1 deletions(-)
>
> diff --git a/kernel/trace/blktrace.c b/kernel/trace/blktrace.c
> index 947c5b3..464a6e5 100644
> --- a/kernel/trace/blktrace.c
> +++ b/kernel/trace/blktrace.c
> @@ -1181,7 +1181,7 @@ static enum print_line_t print_one_line(struct trace_iterator *iter,
> }
>
> if (unlikely(what == 0 || what >= ARRAY_SIZE(what2act)))
> - ret = trace_seq_printf(s, "Bad pc action %x\n", what);
> + ret = trace_seq_printf(s, "Unknown action %x\n", what);
> else {
> ret = log_action(iter, what2act[what].act[long_act]);
> if (ret)
Looks ok,
Acked-by: Arnaldo Carvalho de Melo <[email protected]>
Em Wed, Apr 01, 2009 at 01:00:16PM +0200, Ingo Molnar escreveu:
>
> * Li Zefan <[email protected]> wrote:
>
> > + } else {
> > + if (t_sec(ent))
> > + return trace_seq_printf(s, "%llu + %u [%d]\n",
> > + t_sector(ent),
> > + t_sec(ent), t_error(ent));
> > + return trace_seq_printf(s, "%llu [%d]\n",
> > + t_sector(ent), t_error(ent));
> > + }
> > }
> >
> > static int blk_log_remap(struct trace_seq *s, const struct trace_entry *ent)
>
> Neat shortcut - packet command requests can be quite large in
> special cases, right?
>
> Sidenote. Right now we reserve the full packet length in the trace
> buffer, then copy the full packet into the trace buffer:
>
> if (pdu_len)
> memcpy((void *) t + sizeof(*t), pdu_data, pdu_len);
>
> ... just to scan it a second time during output and discard much of
> it later on if it has a lot of trailing zeroes.
>
> It might make sense to pre-compress: by extending the trace record
> format with a trailing-zeroes field.
You mean something like asking, at tracer registration time to do this
kind of compression and have it done on the core tracing code? Looks
worthy if we can find a second tracer that would benefit from the space
savings at the cost of using more CPU at each event.
But perhaps providing a "memcpy" replacement to be used in such things
and leaving this to the user to decide, i.e. it may be interesting in
certain scenarios to be able to do:
echo 1 > /sys/kernel/debug/tracing/options/compress
And have the payload compressed.
> But that would make it more complex and key to tracers is simplicity
> of data acquisition.
>
> Dunno, probably not worth it, except if data stream bloat becomes a
> real issue (which i'd not expect them to become in this case).
>
> Anyway - Jens, the two patches look good to me, do they look fine to
> you too?
To me too,
Acked-by: Arnaldo Carvalho de Melo <[email protected]>
to this one too.
- Arnaldo
Hi Ingo,
I would like to ask what's the status of these 2 patches.
Arnaldo acked on them.
Li Zefan wrote:
> BLK_TC_PC events should be treated differently with BLK_TC_FS events.
>
> Before this patch:
>
> # echo 1 > /sys/block/sda/sda1/trace/enable
> # echo pc > /sys/block/sda/sda1/trace/act_mask
> # echo blk > /debugfs/tracing/current_tracer
> # (generate some BLK_TC_PC events)
> # cat trace
> bash-2184 [000] 1774.275413: 8,7 I N [bash]
> bash-2184 [000] 1774.275435: 8,7 D N [bash]
> bash-2184 [000] 1774.275540: 8,7 I R [bash]
> bash-2184 [000] 1774.275547: 8,7 D R [bash]
> ksoftirqd/0-4 [000] 1774.275580: 8,7 C N 0 [0]
> bash-2184 [000] 1774.275648: 8,7 I R [bash]
> bash-2184 [000] 1774.275653: 8,7 D R [bash]
> ksoftirqd/0-4 [000] 1774.275682: 8,7 C N 0 [0]
> bash-2184 [000] 1774.275739: 8,7 I R [bash]
> bash-2184 [000] 1774.275744: 8,7 D R [bash]
> ksoftirqd/0-4 [000] 1774.275771: 8,7 C N 0 [0]
> bash-2184 [000] 1774.275804: 8,7 I R [bash]
> bash-2184 [000] 1774.275808: 8,7 D R [bash]
> ksoftirqd/0-4 [000] 1774.275836: 8,7 C N 0 [0]
>
> After this patch:
>
> # cat trace
> bash-2263 [000] 366.782149: 8,7 I N 0 (00 ..) [bash]
> bash-2263 [000] 366.782323: 8,7 D N 0 (00 ..) [bash]
> bash-2263 [000] 366.782557: 8,7 I R 8 (25 00 ..) [bash]
> bash-2263 [000] 366.782560: 8,7 D R 8 (25 00 ..) [bash]
> ksoftirqd/0-4 [000] 366.782582: 8,7 C N (25 00 ..) [0]
> bash-2263 [000] 366.782648: 8,7 I R 8 (5a 00 3f 00) [bash]
> bash-2263 [000] 366.782650: 8,7 D R 8 (5a 00 3f 00) [bash]
> ksoftirqd/0-4 [000] 366.782669: 8,7 C N (5a 00 3f 00) [0]
> bash-2263 [000] 366.782710: 8,7 I R 8 (5a 00 08 00) [bash]
> bash-2263 [000] 366.782713: 8,7 D R 8 (5a 00 08 00) [bash]
> ksoftirqd/0-4 [000] 366.782730: 8,7 C N (5a 00 08 00) [0]
> bash-2263 [000] 366.783375: 8,7 I R 36 (5a 00 08 00) [bash]
> bash-2263 [000] 366.783379: 8,7 D R 36 (5a 00 08 00) [bash]
> ksoftirqd/0-4 [000] 366.783404: 8,7 C N (5a 00 08 00) [0]
>
> This is what we do with PC events in user-space blktrace.
>
> Signed-off-by: Li Zefan <[email protected]>
> ---
* Li Zefan <[email protected]> wrote:
> Hi Ingo,
>
> I would like to ask what's the status of these 2 patches.
>
> Arnaldo acked on them.
They looked good to me - but i'm waiting for an Ack from Jens. Jens
has complained about seeing un-ack-ed patches in the blktrace code,
so i've started serializing any new patches on acks from Jens. The
workflow would be more efficient i suspect if Jens
nominated/declared you and Arnaldo as blktrace co-maintainers too -
most of the patches come from you two.
Ingo
On Sun, Apr 12 2009, Ingo Molnar wrote:
>
> * Li Zefan <[email protected]> wrote:
>
> > Hi Ingo,
> >
> > I would like to ask what's the status of these 2 patches.
> >
> > Arnaldo acked on them.
>
> They looked good to me - but i'm waiting for an Ack from Jens. Jens
> has complained about seeing un-ack-ed patches in the blktrace code,
> so i've started serializing any new patches on acks from Jens. The
> workflow would be more efficient i suspect if Jens
> nominated/declared you and Arnaldo as blktrace co-maintainers too -
> most of the patches come from you two.
I'd be fine with listing Li Zefan as co-maintainer of the blktrace bits.
He knows what he is doing and is also a user of blktrace, so I think he
would be fine. Li, what do you think?
--
Jens Axboe
* Jens Axboe <[email protected]> wrote:
> On Sun, Apr 12 2009, Ingo Molnar wrote:
> >
> > * Li Zefan <[email protected]> wrote:
> >
> > > Hi Ingo,
> > >
> > > I would like to ask what's the status of these 2 patches.
> > >
> > > Arnaldo acked on them.
> >
> > They looked good to me - but i'm waiting for an Ack from Jens. Jens
> > has complained about seeing un-ack-ed patches in the blktrace code,
> > so i've started serializing any new patches on acks from Jens. The
> > workflow would be more efficient i suspect if Jens
> > nominated/declared you and Arnaldo as blktrace co-maintainers too -
> > most of the patches come from you two.
>
> I'd be fine with listing Li Zefan as co-maintainer of the blktrace
> bits. He knows what he is doing and is also a user of blktrace, so
> I think he would be fine. Li, what do you think?
Cool ... i've also taken this as an implicit approval from you of Li
sending blktrace patches so i have queued the two up.
The next big (and nice!) step would be the blktrace events in
TRACE_EVENT() style. That would integrate the blktrace tracepoints
with all the others, in one coherent framework.
Thanks,
Ingo
Jens Axboe wrote:
> On Sun, Apr 12 2009, Ingo Molnar wrote:
>> * Li Zefan <[email protected]> wrote:
>>
>>> Hi Ingo,
>>>
>>> I would like to ask what's the status of these 2 patches.
>>>
>>> Arnaldo acked on them.
>> They looked good to me - but i'm waiting for an Ack from Jens. Jens
>> has complained about seeing un-ack-ed patches in the blktrace code,
>> so i've started serializing any new patches on acks from Jens. The
>> workflow would be more efficient i suspect if Jens
>> nominated/declared you and Arnaldo as blktrace co-maintainers too -
>> most of the patches come from you two.
>
> I'd be fine with listing Li Zefan as co-maintainer of the blktrace bits.
> He knows what he is doing and is also a user of blktrace, so I think he
> would be fine. Li, what do you think?
>
Thanks. It's fine for me too.
--
Zefan
Ingo Molnar wrote:
> * Jens Axboe <[email protected]> wrote:
>
>> On Sun, Apr 12 2009, Ingo Molnar wrote:
>>> * Li Zefan <[email protected]> wrote:
>>>
>>>> Hi Ingo,
>>>>
>>>> I would like to ask what's the status of these 2 patches.
>>>>
>>>> Arnaldo acked on them.
>>> They looked good to me - but i'm waiting for an Ack from Jens. Jens
>>> has complained about seeing un-ack-ed patches in the blktrace code,
>>> so i've started serializing any new patches on acks from Jens. The
>>> workflow would be more efficient i suspect if Jens
>>> nominated/declared you and Arnaldo as blktrace co-maintainers too -
>>> most of the patches come from you two.
>> I'd be fine with listing Li Zefan as co-maintainer of the blktrace
>> bits. He knows what he is doing and is also a user of blktrace, so
>> I think he would be fine. Li, what do you think?
>
> Cool ... i've also taken this as an implicit approval from you of Li
> sending blktrace patches so i have queued the two up.
>
Thanks!
> The next big (and nice!) step would be the blktrace events in
> TRACE_EVENT() style. That would integrate the blktrace tracepoints
> with all the others, in one coherent framework.
>
As I mentioned in another mail thread, this is what we are planning
to do. :)
--
Zefan
Commit-ID: 66de7792c02693b49671afe58c771fde3b092fc7
Gitweb: http://git.kernel.org/tip/66de7792c02693b49671afe58c771fde3b092fc7
Author: Li Zefan <[email protected]>
AuthorDate: Wed, 1 Apr 2009 16:19:19 +0800
Committer: Ingo Molnar <[email protected]>
CommitDate: Sun, 12 Apr 2009 15:32:46 +0200
blktrace: fix output of BLK_TC_PC events
BLK_TC_PC events should be treated differently with BLK_TC_FS events.
Before this patch:
# echo 1 > /sys/block/sda/sda1/trace/enable
# echo pc > /sys/block/sda/sda1/trace/act_mask
# echo blk > /debugfs/tracing/current_tracer
# (generate some BLK_TC_PC events)
# cat trace
bash-2184 [000] 1774.275413: 8,7 I N [bash]
bash-2184 [000] 1774.275435: 8,7 D N [bash]
bash-2184 [000] 1774.275540: 8,7 I R [bash]
bash-2184 [000] 1774.275547: 8,7 D R [bash]
ksoftirqd/0-4 [000] 1774.275580: 8,7 C N 0 [0]
bash-2184 [000] 1774.275648: 8,7 I R [bash]
bash-2184 [000] 1774.275653: 8,7 D R [bash]
ksoftirqd/0-4 [000] 1774.275682: 8,7 C N 0 [0]
bash-2184 [000] 1774.275739: 8,7 I R [bash]
bash-2184 [000] 1774.275744: 8,7 D R [bash]
ksoftirqd/0-4 [000] 1774.275771: 8,7 C N 0 [0]
bash-2184 [000] 1774.275804: 8,7 I R [bash]
bash-2184 [000] 1774.275808: 8,7 D R [bash]
ksoftirqd/0-4 [000] 1774.275836: 8,7 C N 0 [0]
After this patch:
# cat trace
bash-2263 [000] 366.782149: 8,7 I N 0 (00 ..) [bash]
bash-2263 [000] 366.782323: 8,7 D N 0 (00 ..) [bash]
bash-2263 [000] 366.782557: 8,7 I R 8 (25 00 ..) [bash]
bash-2263 [000] 366.782560: 8,7 D R 8 (25 00 ..) [bash]
ksoftirqd/0-4 [000] 366.782582: 8,7 C N (25 00 ..) [0]
bash-2263 [000] 366.782648: 8,7 I R 8 (5a 00 3f 00) [bash]
bash-2263 [000] 366.782650: 8,7 D R 8 (5a 00 3f 00) [bash]
ksoftirqd/0-4 [000] 366.782669: 8,7 C N (5a 00 3f 00) [0]
bash-2263 [000] 366.782710: 8,7 I R 8 (5a 00 08 00) [bash]
bash-2263 [000] 366.782713: 8,7 D R 8 (5a 00 08 00) [bash]
ksoftirqd/0-4 [000] 366.782730: 8,7 C N (5a 00 08 00) [0]
bash-2263 [000] 366.783375: 8,7 I R 36 (5a 00 08 00) [bash]
bash-2263 [000] 366.783379: 8,7 D R 36 (5a 00 08 00) [bash]
ksoftirqd/0-4 [000] 366.783404: 8,7 C N (5a 00 08 00) [0]
This is what we do with PC events in user-space blktrace.
Signed-off-by: Li Zefan <[email protected]>
Acked-by: Arnaldo Carvalho de Melo <[email protected]>
Cc: Jens Axboe <[email protected]>
Cc: Steven Rostedt <[email protected]>
Cc: Frederic Weisbecker <[email protected]>
LKML-Reference: <[email protected]>
Signed-off-by: Ingo Molnar <[email protected]>
---
kernel/trace/blktrace.c | 88 ++++++++++++++++++++++++++++++++++++++++++----
1 files changed, 80 insertions(+), 8 deletions(-)
diff --git a/kernel/trace/blktrace.c b/kernel/trace/blktrace.c
index e45e1af..2b98195 100644
--- a/kernel/trace/blktrace.c
+++ b/kernel/trace/blktrace.c
@@ -971,6 +971,16 @@ static inline const void *pdu_start(const struct trace_entry *ent)
return te_blk_io_trace(ent) + 1;
}
+static inline u32 t_action(const struct trace_entry *ent)
+{
+ return te_blk_io_trace(ent)->action;
+}
+
+static inline u32 t_bytes(const struct trace_entry *ent)
+{
+ return te_blk_io_trace(ent)->bytes;
+}
+
static inline u32 t_sec(const struct trace_entry *ent)
{
return te_blk_io_trace(ent)->bytes >> 9;
@@ -1031,25 +1041,87 @@ static int blk_log_action(struct trace_iterator *iter, const char *act)
MAJOR(t->device), MINOR(t->device), act, rwbs);
}
+static int blk_log_dump_pdu(struct trace_seq *s, const struct trace_entry *ent)
+{
+ const char *pdu_buf;
+ int pdu_len;
+ int i, end, ret;
+
+ pdu_buf = pdu_start(ent);
+ pdu_len = te_blk_io_trace(ent)->pdu_len;
+
+ if (!pdu_len)
+ return 1;
+
+ /* find the last zero that needs to be printed */
+ for (end = pdu_len - 1; end >= 0; end--)
+ if (pdu_buf[end])
+ break;
+ end++;
+
+ if (!trace_seq_putc(s, '('))
+ return 0;
+
+ for (i = 0; i < pdu_len; i++) {
+
+ ret = trace_seq_printf(s, "%s%02x",
+ i == 0 ? "" : " ", pdu_buf[i]);
+ if (!ret)
+ return ret;
+
+ /*
+ * stop when the rest is just zeroes and indicate so
+ * with a ".." appended
+ */
+ if (i == end && end != pdu_len - 1)
+ return trace_seq_puts(s, " ..) ");
+ }
+
+ return trace_seq_puts(s, ") ");
+}
+
static int blk_log_generic(struct trace_seq *s, const struct trace_entry *ent)
{
char cmd[TASK_COMM_LEN];
trace_find_cmdline(ent->pid, cmd);
- if (t_sec(ent))
- return trace_seq_printf(s, "%llu + %u [%s]\n",
- t_sector(ent), t_sec(ent), cmd);
- return trace_seq_printf(s, "[%s]\n", cmd);
+ if (t_action(ent) & BLK_TC_ACT(BLK_TC_PC)) {
+ int ret;
+
+ ret = trace_seq_printf(s, "%u ", t_bytes(ent));
+ if (!ret)
+ return 0;
+ ret = blk_log_dump_pdu(s, ent);
+ if (!ret)
+ return 0;
+ return trace_seq_printf(s, "[%s]\n", cmd);
+ } else {
+ if (t_sec(ent))
+ return trace_seq_printf(s, "%llu + %u [%s]\n",
+ t_sector(ent), t_sec(ent), cmd);
+ return trace_seq_printf(s, "[%s]\n", cmd);
+ }
}
static int blk_log_with_error(struct trace_seq *s,
const struct trace_entry *ent)
{
- if (t_sec(ent))
- return trace_seq_printf(s, "%llu + %u [%d]\n", t_sector(ent),
- t_sec(ent), t_error(ent));
- return trace_seq_printf(s, "%llu [%d]\n", t_sector(ent), t_error(ent));
+ if (t_action(ent) & BLK_TC_ACT(BLK_TC_PC)) {
+ int ret;
+
+ ret = blk_log_dump_pdu(s, ent);
+ if (ret)
+ return trace_seq_printf(s, "[%d]\n", t_error(ent));
+ return 0;
+ } else {
+ if (t_sec(ent))
+ return trace_seq_printf(s, "%llu + %u [%d]\n",
+ t_sector(ent),
+ t_sec(ent), t_error(ent));
+ return trace_seq_printf(s, "%llu [%d]\n",
+ t_sector(ent), t_error(ent));
+ }
}
static int blk_log_remap(struct trace_seq *s, const struct trace_entry *ent)
Commit-ID: b78825d608f30a47e3154ab6872a03f0de0c9d45
Gitweb: http://git.kernel.org/tip/b78825d608f30a47e3154ab6872a03f0de0c9d45
Author: Li Zefan <[email protected]>
AuthorDate: Wed, 1 Apr 2009 16:18:53 +0800
Committer: Ingo Molnar <[email protected]>
CommitDate: Sun, 12 Apr 2009 15:32:45 +0200
blktrace: fix output of unknown events
Not all events are pc (packet command) events. An event is a pc
event only if it has BLK_TC_PC bit set.
Signed-off-by: Li Zefan <[email protected]>
Acked-by: Arnaldo Carvalho de Melo <[email protected]>
Cc: Jens Axboe <[email protected]>
Cc: Steven Rostedt <[email protected]>
Cc: Frederic Weisbecker <[email protected]>
LKML-Reference: <[email protected]>
Signed-off-by: Ingo Molnar <[email protected]>
---
kernel/trace/blktrace.c | 2 +-
1 files changed, 1 insertions(+), 1 deletions(-)
diff --git a/kernel/trace/blktrace.c b/kernel/trace/blktrace.c
index 921ef5d..e45e1af 100644
--- a/kernel/trace/blktrace.c
+++ b/kernel/trace/blktrace.c
@@ -1182,7 +1182,7 @@ static enum print_line_t print_one_line(struct trace_iterator *iter,
}
if (unlikely(what == 0 || what >= ARRAY_SIZE(what2act)))
- ret = trace_seq_printf(s, "Bad pc action %x\n", what);
+ ret = trace_seq_printf(s, "Unknown action %x\n", what);
else {
ret = log_action(iter, what2act[what].act[long_act]);
if (ret)