2024-04-12 18:33:46

by Namhyung Kim

[permalink] [raw]
Subject: [PATCH 1/4] perf annotate-data: Improve debug message with location info

To verify it found the correct variable, let's add the location
expression to the debug message.

$ perf --debug type-profile annotate --data-type
...
-----------------------------------------------------------
find data type for 0xaf0(reg15) at schedule+0xeb
CU for kernel/sched/core.c (die:0x1180523)
frame base: cfa=0 fbreg=6
found "rq" in scope=3/4 (die: 0x11b6a00) type_offset=0xaf0
variable location: reg15
type='struct rq' size=0xfc0 (die:0x11892e2)
-----------------------------------------------------------
find data type for 0x7bc(reg3) at tcp_get_info+0x62
CU for net/ipv4/tcp.c (die:0x7b5f516)
frame base: cfa=0 fbreg=6
offset: 1980 is bigger than size: 760
check variable "sk" failed (die: 0x7b92b2c)
variable location: reg3
type='struct sock' size=0x2f8 (die:0x7b63c3a)
-----------------------------------------------------------
...

The first case is fine. It looked up a data type in r15 with offset of
0xaf0 at the schedule+0xeb. It found CU die and the frame base info and
the variable "rq" was found in the scope 3/4. Its location is the r15
register and the type size is 0xfc0 which includes 0xaf0.

But the second case is not good. It looked up a data type in rbx (reg3)
with offset 0x7bc. It found a CU and the frame base which is good so
far. And it also found a variable "sk" but the access offset is bigger
than the type size (1980 vs. 760 or 0x7bc vs. 0x2f8). The variable has
the right location (reg3) but I need to figure out why it accesses
beyond what it's supposed to.

Signed-off-by: Namhyung Kim <[email protected]>
---
tools/perf/util/annotate-data.c | 99 +++++++++++++++++++++++++++------
1 file changed, 82 insertions(+), 17 deletions(-)

diff --git a/tools/perf/util/annotate-data.c b/tools/perf/util/annotate-data.c
index 1cd857400038..c6eb5b2cc4d5 100644
--- a/tools/perf/util/annotate-data.c
+++ b/tools/perf/util/annotate-data.c
@@ -46,6 +46,7 @@ static void pr_debug_type_name(Dwarf_Die *die, enum type_state_kind kind)
{
struct strbuf sb;
char *str;
+ Dwarf_Word size = 0;

if (!debug_type_profile && verbose < 3)
return;
@@ -72,13 +73,67 @@ static void pr_debug_type_name(Dwarf_Die *die, enum type_state_kind kind)
break;
}

+ dwarf_aggregate_size(die, &size);
+
strbuf_init(&sb, 32);
die_get_typename_from_type(die, &sb);
str = strbuf_detach(&sb, NULL);
- pr_info(" type=%s (die:%lx)\n", str, (long)dwarf_dieoffset(die));
+ pr_info(" type='%s' size=%#lx (die:%#lx)\n",
+ str, (long)size, (long)dwarf_dieoffset(die));
free(str);
}

+static void pr_debug_location(Dwarf_Die *die, u64 pc, int reg)
+{
+ ptrdiff_t off = 0;
+ Dwarf_Attribute attr;
+ Dwarf_Addr base, start, end;
+ Dwarf_Op *ops;
+ size_t nops;
+
+ if (!debug_type_profile && verbose < 3)
+ return;
+
+ if (dwarf_attr(die, DW_AT_location, &attr) == NULL)
+ return;
+
+ while ((off = dwarf_getlocations(&attr, off, &base, &start, &end, &ops, &nops)) > 0) {
+ if (reg != DWARF_REG_PC && end < pc)
+ continue;
+ if (reg != DWARF_REG_PC && start > pc)
+ break;
+
+ pr_info(" variable location: ");
+ switch (ops->atom) {
+ case DW_OP_reg0 ...DW_OP_reg31:
+ pr_info("reg%d\n", ops->atom - DW_OP_reg0);
+ break;
+ case DW_OP_breg0 ...DW_OP_breg31:
+ pr_info("base=reg%d, offset=%#lx\n",
+ ops->atom - DW_OP_breg0, ops->number);
+ break;
+ case DW_OP_regx:
+ pr_info("reg%ld\n", ops->number);
+ break;
+ case DW_OP_bregx:
+ pr_info("base=reg%ld, offset=%#lx\n",
+ ops->number, ops->number2);
+ break;
+ case DW_OP_fbreg:
+ pr_info("use frame base, offset=%#lx\n", ops->number);
+ break;
+ case DW_OP_addr:
+ pr_info("address=%#lx\n", ops->number);
+ break;
+ default:
+ pr_info("unknown: code=%#x, number=%#lx\n",
+ ops->atom, ops->number);
+ break;
+ }
+ break;
+ }
+}
+
/*
* Type information in a register, valid when @ok is true.
* The @caller_saved registers are invalidated after a function call.
@@ -1404,7 +1459,7 @@ static int find_data_type_block(struct data_loc_info *dloc, int reg,
found = find_data_type_insn(dloc, reg, &basic_blocks, var_types,
cu_die, type_die);
if (found > 0) {
- pr_debug_dtp("found by insn track: %#x(reg%d) type-offset=%#x",
+ pr_debug_dtp("found by insn track: %#x(reg%d) type-offset=%#x\n",
dloc->op->offset, reg, dloc->type_offset);
pr_debug_type_name(type_die, TSR_KIND_TYPE);
ret = 0;
@@ -1440,16 +1495,16 @@ static int find_data_type_die(struct data_loc_info *dloc, Dwarf_Die *type_die)
char buf[64];

if (dloc->op->multi_regs)
- snprintf(buf, sizeof(buf), " or reg%d", dloc->op->reg2);
+ snprintf(buf, sizeof(buf), "reg%d, reg%d", dloc->op->reg1, dloc->op->reg2);
else if (dloc->op->reg1 == DWARF_REG_PC)
- snprintf(buf, sizeof(buf), " (PC)");
+ snprintf(buf, sizeof(buf), "PC");
else
- buf[0] = '\0';
+ snprintf(buf, sizeof(buf), "reg%d", dloc->op->reg1);

pr_debug_dtp("-----------------------------------------------------------\n");
- pr_debug_dtp("%s [%"PRIx64"] for reg%d%s offset=%#x in %s\n",
- __func__, dloc->ip - dloc->ms->sym->start,
- dloc->op->reg1, buf, dloc->op->offset, dloc->ms->sym->name);
+ pr_debug_dtp("find data type for %#x(%s) at %s+%#"PRIx64"\n",
+ dloc->op->offset, buf, dloc->ms->sym->name,
+ dloc->ip - dloc->ms->sym->start);

/*
* IP is a relative instruction address from the start of the map, as
@@ -1468,14 +1523,15 @@ static int find_data_type_die(struct data_loc_info *dloc, Dwarf_Die *type_die)
reg = loc->reg1;
offset = loc->offset;

- pr_debug_dtp("CU die offset: %#lx\n", (long)dwarf_dieoffset(&cu_die));
+ pr_debug_dtp("CU for %s (die:%#lx)\n",
+ dwarf_diename(&cu_die), (long)dwarf_dieoffset(&cu_die));

if (reg == DWARF_REG_PC) {
if (get_global_var_type(&cu_die, dloc, dloc->ip, dloc->var_addr,
&offset, type_die)) {
dloc->type_offset = offset;

- pr_debug_dtp("found PC-rel by addr=%#"PRIx64" offset=%#x",
+ pr_debug_dtp("found by addr=%#"PRIx64" type_offset=%#x\n",
dloc->var_addr, offset);
pr_debug_type_name(type_die, TSR_KIND_TYPE);
ret = 0;
@@ -1537,13 +1593,22 @@ static int find_data_type_die(struct data_loc_info *dloc, Dwarf_Die *type_die)
pr_debug_dtp("found \"%s\" in scope=%d/%d (die: %#lx) ",
dwarf_diename(&var_die), i+1, nr_scopes,
(long)dwarf_dieoffset(&scopes[i]));
- if (reg == DWARF_REG_PC)
- pr_debug_dtp("%#x(PC) offset=%#x", loc->offset, offset);
- else if (reg == DWARF_REG_FB || is_fbreg)
- pr_debug_dtp("%#x(reg%d) stack fb_offset=%#x offset=%#x",
- loc->offset, reg, fb_offset, offset);
- else
- pr_debug_dtp("%#x(reg%d)", loc->offset, reg);
+ if (reg == DWARF_REG_PC) {
+ pr_debug_dtp("addr=%#"PRIx64" type_offset=%#x\n",
+ dloc->var_addr, offset);
+ } else if (reg == DWARF_REG_FB || is_fbreg) {
+ pr_debug_dtp("stack_offset=%#x type_offset=%#x\n",
+ fb_offset, offset);
+ } else {
+ pr_debug_dtp("type_offset=%#x\n", offset);
+ }
+ pr_debug_location(&var_die, pc, reg);
+ pr_debug_type_name(type_die, TSR_KIND_TYPE);
+ } else {
+ pr_debug_dtp("check variable \"%s\" failed (die: %#lx)\n",
+ dwarf_diename(&var_die),
+ (long)dwarf_dieoffset(&var_die));
+ pr_debug_location(&var_die, pc, reg);
pr_debug_type_name(type_die, TSR_KIND_TYPE);
}
dloc->type_offset = offset;
--
2.44.0.683.g7961c838ac-goog



2024-04-16 14:51:44

by Arnaldo Carvalho de Melo

[permalink] [raw]
Subject: Re: [PATCH 1/4] perf annotate-data: Improve debug message with location info

On Fri, Apr 12, 2024 at 11:33:07AM -0700, Namhyung Kim wrote:
> To verify it found the correct variable, let's add the location
> expression to the debug message.

Added the patch below, following your existing convention of casting
Dwarf_Offset/Darf_Word to long.

- Arnaldo

diff --git a/tools/perf/util/annotate-data.c b/tools/perf/util/annotate-data.c
index c6eb5b2cc4d50d79..e53d66c46c540b75 100644
--- a/tools/perf/util/annotate-data.c
+++ b/tools/perf/util/annotate-data.c
@@ -110,24 +110,24 @@ static void pr_debug_location(Dwarf_Die *die, u64 pc, int reg)
break;
case DW_OP_breg0 ...DW_OP_breg31:
pr_info("base=reg%d, offset=%#lx\n",
- ops->atom - DW_OP_breg0, ops->number);
+ ops->atom - DW_OP_breg0, (long)ops->number);
break;
case DW_OP_regx:
- pr_info("reg%ld\n", ops->number);
+ pr_info("reg%ld\n", (long)ops->number);
break;
case DW_OP_bregx:
pr_info("base=reg%ld, offset=%#lx\n",
- ops->number, ops->number2);
+ (long)ops->number, (long)ops->number2);
break;
case DW_OP_fbreg:
- pr_info("use frame base, offset=%#lx\n", ops->number);
+ pr_info("use frame base, offset=%#lx\n", (long)ops->number);
break;
case DW_OP_addr:
- pr_info("address=%#lx\n", ops->number);
+ pr_info("address=%#lx\n", (long)ops->number);
break;
default:
pr_info("unknown: code=%#x, number=%#lx\n",
- ops->atom, ops->number);
+ ops->atom, (long)ops->number);
break;
}
break;