Re: [tip:perf/urgent] perf probe: Support signedness casting
From: Arnaldo Carvalho de Melo
Date: Wed Aug 10 2016 - 14:04:39 EST
Em Wed, Aug 10, 2016 at 07:28:08AM +0900, Masami Hiramatsu escreveu:
> Hi Ingo,
>
> Could you add my Acked-by for this patch?
> (I thought I've sent it...)
Sorry about that, I usually put those acks diligently, but this one
slipped by... I saw the discussion, waited for it to settle and you ack
to be provided, but then, while testing it and editing the log, I forgot
to collect the ack.
- Arnaldo
> Thank you,
>
> On Tue, 9 Aug 2016 12:19:02 -0700
> tip-bot for Naohiro Aota <tipbot@xxxxxxxxx> wrote:
>
> > Commit-ID: 19f00b011729417f69e4df53cc3fe5ecc25134a4
> > Gitweb: http://git.kernel.org/tip/19f00b011729417f69e4df53cc3fe5ecc25134a4
> > Author: Naohiro Aota <naohiro.aota@xxxxxxxx>
> > AuthorDate: Tue, 9 Aug 2016 11:40:08 +0900
> > Committer: Arnaldo Carvalho de Melo <acme@xxxxxxxxxx>
> > CommitDate: Tue, 9 Aug 2016 10:52:22 -0300
> >
> > perf probe: Support signedness casting
> >
> > The 'perf probe' tool detects a variable's type and use the detected
> > type to add a new probe. Then, kprobes prints its variable in
> > hexadecimal format if the variable is unsigned and prints in decimal if
> > it is signed.
> >
> > We sometimes want to see unsigned variable in decimal format (i.e.
> > sector_t or size_t). In that case, we need to investigate the variable's
> > size manually to specify just signedness.
> >
> > This patch add signedness casting support. By specifying "s" or "u" as a
> > type, perf-probe will investigate variable size as usual and use the
> > specified signedness.
> >
> > E.g. without this:
> >
> > $ perf probe -a 'submit_bio bio->bi_iter.bi_sector'
> > Added new event:
> > probe:submit_bio (on submit_bio with bi_sector=bio->bi_iter.bi_sector)
> > You can now use it in all perf tools, such as:
> > perf record -e probe:submit_bio -aR sleep 1
> > $ cat trace_pipe|head
> > dbench-9692 [003] d..1 971.096633: submit_bio: (submit_bio+0x0/0x140) bi_sector=0x3a3d00
> > dbench-9692 [003] d..1 971.096685: submit_bio: (submit_bio+0x0/0x140) bi_sector=0x1a3d80
> > dbench-9692 [003] d..1 971.096687: submit_bio: (submit_bio+0x0/0x140) bi_sector=0x3a3d80
> > ...
> > // need to investigate the variable size
> > $ perf probe -a 'submit_bio bio->bi_iter.bi_sector:s64'
> > Added new event:
> > probe:submit_bio (on submit_bio with bi_sector=bio->bi_iter.bi_sector:s64)
> > You can now use it in all perf tools, such as:
> > perf record -e probe:submit_bio -aR sleep 1
> >
> > With this:
> >
> > // just use "s" to cast its signedness
> > $ perf probe -v -a 'submit_bio bio->bi_iter.bi_sector:s'
> > Added new event:
> > probe:submit_bio (on submit_bio with bi_sector=bio->bi_iter.bi_sector:s)
> > You can now use it in all perf tools, such as:
> > perf record -e probe:submit_bio -aR sleep 1
> > $ cat trace_pipe|head
> > dbench-9689 [001] d..1 1212.391237: submit_bio: (submit_bio+0x0/0x140) bi_sector=128
> > dbench-9689 [001] d..1 1212.391252: submit_bio: (submit_bio+0x0/0x140) bi_sector=131072
> > dbench-9697 [006] d..1 1212.398611: submit_bio: (submit_bio+0x0/0x140) bi_sector=30208
> >
> > This commit also update perf-probe.txt to describe "types". Most parts
> > are based on existing documentation: Documentation/trace/kprobetrace.txt
> >
> > Committer note:
> >
> > Testing using 'perf trace':
> >
> > # perf probe -a 'submit_bio bio->bi_iter.bi_sector'
> > Added new event:
> > probe:submit_bio (on submit_bio with bi_sector=bio->bi_iter.bi_sector)
> >
> > You can now use it in all perf tools, such as:
> >
> > perf record -e probe:submit_bio -aR sleep 1
> >
> > # trace --no-syscalls --ev probe:submit_bio
> > 0.000 probe:submit_bio:(ffffffffac3aee00) bi_sector=0xc133c0)
> > 3181.861 probe:submit_bio:(ffffffffac3aee00) bi_sector=0x6cffb8)
> > 3181.881 probe:submit_bio:(ffffffffac3aee00) bi_sector=0x6cffc0)
> > 3184.488 probe:submit_bio:(ffffffffac3aee00) bi_sector=0x6cffc8)
> > <SNIP>
> > 4717.927 probe:submit_bio:(ffffffffac3aee00) bi_sector=0x4dc7a88)
> > 4717.970 probe:submit_bio:(ffffffffac3aee00) bi_sector=0x4dc7880)
> > ^C[root@jouet ~]#
> >
> > Now, using this new feature:
> >
> > [root@jouet ~]# perf probe -a 'submit_bio bio->bi_iter.bi_sector:s'
> > Added new event:
> > probe:submit_bio (on submit_bio with bi_sector=bio->bi_iter.bi_sector:s)
> >
> > You can now use it in all perf tools, such as:
> >
> > perf record -e probe:submit_bio -aR sleep 1
> >
> > [root@jouet ~]# trace --no-syscalls --ev probe:submit_bio
> > 0.000 probe:submit_bio:(ffffffffac3aee00) bi_sector=7145704)
> > 0.017 probe:submit_bio:(ffffffffac3aee00) bi_sector=7145712)
> > 0.019 probe:submit_bio:(ffffffffac3aee00) bi_sector=7145720)
> > 2.567 probe:submit_bio:(ffffffffac3aee00) bi_sector=7145728)
> > 5631.919 probe:submit_bio:(ffffffffac3aee00) bi_sector=0)
> > 5631.941 probe:submit_bio:(ffffffffac3aee00) bi_sector=8)
> > 5631.945 probe:submit_bio:(ffffffffac3aee00) bi_sector=16)
> > 5631.948 probe:submit_bio:(ffffffffac3aee00) bi_sector=24)
> > ^C#
> >
> > With callchains:
> >
> > # trace --no-syscalls --ev probe:submit_bio/max-stack=10/
> > 0.000 probe:submit_bio:(ffffffffac3aee00) bi_sector=50662544)
> > submit_bio+0xa8200001 ([kernel.kallsyms])
> > submit_bh+0xa8200013 ([kernel.kallsyms])
> > jbd2_journal_commit_transaction+0xa8200691 ([kernel.kallsyms])
> > kjournald2+0xa82000ca ([kernel.kallsyms])
> > kthread+0xa82000d8 ([kernel.kallsyms])
> > ret_from_fork+0xa820001f ([kernel.kallsyms])
> > 0.023 probe:submit_bio:(ffffffffac3aee00) bi_sector=50662552)
> > submit_bio+0xa8200001 ([kernel.kallsyms])
> > submit_bh+0xa8200013 ([kernel.kallsyms])
> > jbd2_journal_commit_transaction+0xa8200691 ([kernel.kallsyms])
> > kjournald2+0xa82000ca ([kernel.kallsyms])
> > kthread+0xa82000d8 ([kernel.kallsyms])
> > ret_from_fork+0xa820001f ([kernel.kallsyms])
> > 0.027 probe:submit_bio:(ffffffffac3aee00) bi_sector=50662560)
> > submit_bio+0xa8200001 ([kernel.kallsyms])
> > submit_bh+0xa8200013 ([kernel.kallsyms])
> > jbd2_journal_commit_transaction+0xa8200691 ([kernel.kallsyms])
> > kjournald2+0xa82000ca ([kernel.kallsyms])
> > kthread+0xa82000d8 ([kernel.kallsyms])
> > ret_from_fork+0xa820001f ([kernel.kallsyms])
> > 2.593 probe:submit_bio:(ffffffffac3aee00) bi_sector=50662568)
> > submit_bio+0xa8200001 ([kernel.kallsyms])
> > submit_bh+0xa8200013 ([kernel.kallsyms])
> > journal_submit_commit_record+0xa82001ac ([kernel.kallsyms])
> > jbd2_journal_commit_transaction+0xa82012e8 ([kernel.kallsyms])
> > kjournald2+0xa82000ca ([kernel.kallsyms])
> > kthread+0xa82000d8 ([kernel.kallsyms])
> > ret_from_fork+0xa820001f ([kernel.kallsyms])
> > ^C#
> >
> > Signed-off-by: Naohiro Aota <naohiro.aota@xxxxxxxx>
> > Tested-by: Arnaldo Carvalho de Melo <acme@xxxxxxxxxx>
> > Cc: Alexander Shishkin <alexander.shishkin@xxxxxxxxxxxxxxx>
> > Cc: Hemant Kumar <hemant@xxxxxxxxxxxxxxxxxx>
> > Cc: Masami Hiramatsu <mhiramat@xxxxxxxxxx>
> > Cc: Peter Zijlstra <peterz@xxxxxxxxxxxxx>
> > Cc: Wang Nan <wangnan0@xxxxxxxxxx>
> > Link: http://lkml.kernel.org/r/1470710408-23515-1-git-send-email-naohiro.aota@xxxxxxxx
> > Signed-off-by: Arnaldo Carvalho de Melo <acme@xxxxxxxxxx>
> > ---
> > tools/perf/Documentation/perf-probe.txt | 10 +++++++++-
> > tools/perf/util/probe-finder.c | 15 ++++++++++++---
> > 2 files changed, 21 insertions(+), 4 deletions(-)
> >
> > diff --git a/tools/perf/Documentation/perf-probe.txt b/tools/perf/Documentation/perf-probe.txt
> > index 736da44..b303bcd 100644
> > --- a/tools/perf/Documentation/perf-probe.txt
> > +++ b/tools/perf/Documentation/perf-probe.txt
> > @@ -176,10 +176,18 @@ Each probe argument follows below syntax.
> >
> > 'NAME' specifies the name of this argument (optional). You can use the name of local variable, local data structure member (e.g. var->field, var.field2), local array with fixed index (e.g. array[1], var->array[0], var->pointer[2]), or kprobe-tracer argument format (e.g. $retval, %ax, etc). Note that the name of this argument will be set as the last member name if you specify a local data structure member (e.g. field2 for 'var->field1.field2'.)
> > '$vars' and '$params' special arguments are also available for NAME, '$vars' is expanded to the local variables (including function parameters) which can access at given probe point. '$params' is expanded to only the function parameters.
> > -'TYPE' casts the type of this argument (optional). If omitted, perf probe automatically set the type based on debuginfo. You can specify 'string' type only for the local variable or structure member which is an array of or a pointer to 'char' or 'unsigned char' type.
> > +'TYPE' casts the type of this argument (optional). If omitted, perf probe automatically set the type based on debuginfo. Currently, basic types (u8/u16/u32/u64/s8/s16/s32/s64), signedness casting (u/s), "string" and bitfield are supported. (see TYPES for detail)
> >
> > On x86 systems %REG is always the short form of the register: for example %AX. %RAX or %EAX is not valid.
> >
> > +TYPES
> > +-----
> > +Basic types (u8/u16/u32/u64/s8/s16/s32/s64) are integer types. Prefix 's' and 'u' means those types are signed and unsigned respectively. Traced arguments are shown in decimal (signed) or hex (unsigned). You can also use 's' or 'u' to specify only signedness and leave its size auto-detected by perf probe.
> > +String type is a special type, which fetches a "null-terminated" string from kernel space. This means it will fail and store NULL if the string container has been paged out. You can specify 'string' type only for the local variable or structure member which is an array of or a pointer to 'char' or 'unsigned char' type.
> > +Bitfield is another special type, which takes 3 parameters, bit-width, bit-offset, and container-size (usually 32). The syntax is;
> > +
> > + b<bit-width>@<bit-offset>/<container-size>
> > +
> > LINE SYNTAX
> > -----------
> > Line range is described by following syntax.
> > diff --git a/tools/perf/util/probe-finder.c b/tools/perf/util/probe-finder.c
> > index f2d9ff0..5c290c6 100644
> > --- a/tools/perf/util/probe-finder.c
> > +++ b/tools/perf/util/probe-finder.c
> > @@ -297,10 +297,13 @@ static int convert_variable_type(Dwarf_Die *vr_die,
> > char sbuf[STRERR_BUFSIZE];
> > int bsize, boffs, total;
> > int ret;
> > + char sign;
> >
> > /* TODO: check all types */
> > - if (cast && strcmp(cast, "string") != 0) {
> > + if (cast && strcmp(cast, "string") != 0 &&
> > + strcmp(cast, "s") != 0 && strcmp(cast, "u") != 0) {
> > /* Non string type is OK */
> > + /* and respect signedness cast */
> > tvar->type = strdup(cast);
> > return (tvar->type == NULL) ? -ENOMEM : 0;
> > }
> > @@ -361,6 +364,13 @@ static int convert_variable_type(Dwarf_Die *vr_die,
> > return (tvar->type == NULL) ? -ENOMEM : 0;
> > }
> >
> > + if (cast && (strcmp(cast, "u") == 0))
> > + sign = 'u';
> > + else if (cast && (strcmp(cast, "s") == 0))
> > + sign = 's';
> > + else
> > + sign = die_is_signed_type(&type) ? 's' : 'u';
> > +
> > ret = dwarf_bytesize(&type);
> > if (ret <= 0)
> > /* No size ... try to use default type */
> > @@ -373,8 +383,7 @@ static int convert_variable_type(Dwarf_Die *vr_die,
> > dwarf_diename(&type), MAX_BASIC_TYPE_BITS);
> > ret = MAX_BASIC_TYPE_BITS;
> > }
> > - ret = snprintf(buf, 16, "%c%d",
> > - die_is_signed_type(&type) ? 's' : 'u', ret);
> > + ret = snprintf(buf, 16, "%c%d", sign, ret);
> >
> > formatted:
> > if (ret < 0 || ret >= 16) {
>
>
> --
> Masami Hiramatsu <mhiramat@xxxxxxxxxx>