Re: overflows in Dwfl_Thread_Callbacks::memory_read callback

[Mark Wielaard <mark at klomp dot org>]

On Thu, 2017-06-01 at 22:46 +0200, Milian Wolff wrote:
> in the perfparser that Ulf wrote, and to which I'm contributing too, we often 
> see abnormal data being passed to the memory_read callback we define. 
> 
> I.e. our callback gets invoked with addr=0xFFFFFFFFFFFFFFFF which clearly 
> isn't an expected or valid address. So far we ignored this, as things seem to 
> work okayish, but I still suspect something is wrong somewhere... Out of 
> interest, I would like to ask if anyone has ever seen something like that?

Yes, you sometimes see that some register or location value is zero for
some reason, but the expression parser wants to read some memory at an
offset from that register. e.g. the SP being zero and trying to read at
SP +/- offset to get some value from the stack.

Maybe the expression parser should notice this situation and not even
invoke the memory_read callback in that case since it is obvious it will
fail.

> I can easily reproduce this problem. I recorded a session with rr and then 
> investigated what is going on. Below is a "screenshot" of my rr replay 
> session:
> 
> ~~~~~~~~~~~~~~
> 
> warning: perfparser/memoryRead: Invalid memory read requested by dwfl 
> 18446744073709551615 [/home/milian/projects/kdab/rnd/hotspot/3rdparty/
> perfparser/app/perfsymboltable.cpp:150/pid=31690]
> 
> Breakpoint 1, memoryRead (dwfl=0x1baaa80, addr=18446744073709551615, 
> result=0x7ffe83f69fe8, arg=0x7ffe83f6c278) at /home/milian/projects/kdab/rnd/
> hotspot/3rdparty/perfparser/app/perfsymboltable.cpp:151
> 151             ui->firstGuessedFrame = ui->frames.length();
> (rr) up
> #1  0x00007fd107ff7345 in expr_eval (state=state@entry=0x1bca010, 
> frame=0x1bcbdf0, ops=0x7ffe83f69ff0, nops=2, 
> result=result@entry=0x7ffe83f69fe8, bias=bias@entry=140092229857280)
>     at /home/milian/projects/src/elfutils/libdwfl/frame_unwind.c:501
> 501           if (! process->callbacks->memory_read (process->dwfl, *result, 
> result,
> (rr) watch -l *result
> Hardware watchpoint 2: -location *result
> (rr) reverse-continue 
> Continuing.
> 
> Hardware watchpoint 2: -location *result
> 
> Old value = 18446744073709551615
> New value = 18446744073709551575
> 0x00007fd107ff72fe in do_pop (stack=0x7ffe83f69f20, stack=0x7ffe83f69f20, 
> val=0x7ffe83f69fe8) at /home/milian/projects/src/elfutils/libdwfl/
> frame_unwind.c:139
> 139       *val = stack->addrs[--stack->used];
> (rr) print stack->used
> $1 = 0
> (rr) reverse-step
> 139       *val = stack->addrs[--stack->used];
> (rr) print stack->used
> $2 = 1
> (rr) print stack->addrs[0]
> $3 = 18446744073709551615
> (rr) print stack->addrs[1]
> $4 = 140535749912192
> (rr) print stack->addrs[0]
> $5 = 18446744073709551615
> (rr) watch -l stack->addrs[0]
> Hardware watchpoint 3: -location stack->addrs[0]
> (rr) reverse-conQuit
> (rr) del 2
> (rr) reverse-continue 
> Continuing.
> 
> Hardware watchpoint 3: -location stack->addrs[0]
> 
> Old value = 18446744073709551615
> New value = 15
> 0x00007fd107ff6e8a in do_push (stack=0x7ffe83f69f20, val=18446744073709551615) 
> at /home/milian/projects/src/elfutils/libdwfl/frame_unwind.c:127
> 127       stack->addrs[stack->used++] = val;
> (rr) print val
> $6 = 18446744073709551615
> (rr) up
> #1  0x00007fd107ff7a4f in expr_eval (state=state@entry=0x1bca010, 
> frame=0x1bcbdf0, ops=0x7ffe83f69ff0, nops=2, 
> result=result@entry=0x7ffe83f69fe8, bias=bias@entry=140092229857280)
>     at /home/milian/projects/src/elfutils/libdwfl/frame_unwind.c:361
> 361               if (! pop (&val1) || ! push (val1 + op->number))
> (rr) print val1
> $7 = 15
> (rr) print op->number
> $8 = 18446744073709551600
> (rr) watch -l op->number
> Hardware watchpoint 4: -location op->number
> (rr) del 3
> (rr) reverse-continue 
> Continuing.
> 
> Hardware watchpoint 4: -location op->number
> 
> Old value = 18446744073709551600
> New value = 0
> 0x00007fd107fe06e8 in dwarf_frame_register (fs=0x1bcbdf0, regno=regno@entry=6, 
> ops_mem=ops_mem@entry=0x7ffe83f69ff0, ops=ops@entry=0x7ffe83f69fd8, 
> nops=nops@entry=0x7ffe83f69fe0)
>     at /home/milian/projects/src/elfutils/libdw/dwarf_frame_register.c:80
> 80              ops_mem[(*nops)++] = (Dwarf_Op) { .atom = DW_OP_plus_uconst,
> (rr) list
> 75
> 76          case reg_offset:
> 77          case reg_val_offset:
> 78            ops_mem[(*nops)++] = (Dwarf_Op) { .atom = DW_OP_call_frame_cfa 
> };
> 79            if (reg->value != 0)
> 80              ops_mem[(*nops)++] = (Dwarf_Op) { .atom = DW_OP_plus_uconst,
> 81                                                .number = reg->value };
> 82            if (reg->rule == reg_val_offset)
> 83              /* A value, not a location.  */
> 84              ops_mem[(*nops)++] = (Dwarf_Op) { .atom = DW_OP_stack_value };
> (rr) print reg->value
> $9 = -16
> (rr) watch -l reg->value
> Hardware watchpoint 5: -location reg->value
> (rr) reverse-continue 
> Continuing.
> 
> Hardware watchpoint 4: -location op->number
> 
> Old value = 0
> New value = 18446744073709551560
> dwarf_frame_register (fs=0x1bcbdf0, regno=regno@entry=6, 
> ops_mem=ops_mem@entry=0x7ffe83f69ff0, ops=ops@entry=0x7ffe83f69fd8, 
> nops=nops@entry=0x7ffe83f69fe0)
>     at /home/milian/projects/src/elfutils/libdw/dwarf_frame_register.c:80
> 80              ops_mem[(*nops)++] = (Dwarf_Op) { .atom = DW_OP_plus_uconst,
> (rr) del 4
> (rr) reverse-continue 
> Continuing.
> 
> Hardware watchpoint 5: -location reg->value
> 
> Old value = -16
> New value = 0
> 0x00007fd107fddf17 in execute_cfi (cache=cache@entry=0x1bb5b00, cie=0x1b9d100, 
> state=state@entry=0x7ffe83f69ed0, program=<optimized out>, end=0x7fd108039778 
> ",", abi_cfi=abi_cfi@entry=false, loc=21649, 
>     find_pc=23177) at /home/milian/projects/src/elfutils/libdw/cfi.c:260
> 260               register_rule (operand, val_offset, offset);
> (rr) list
> 255               get_uleb128 (operand, program, end);
> 256               cfi_assert (program < end);
> 257               get_uleb128 (offset, program, end);
> 258               offset *= cie->data_alignment_factor;
> 259             val_offset:
> 260               register_rule (operand, val_offset, offset);
> 261               continue;
> 262
> 263             case DW_CFA_val_offset_sf:
> 264               get_uleb128 (operand, program, end);
> (rr) print offset
> $10 = <optimized out>
> (rr) print val_offset
> No symbol "val_offset" in current context.
> (rr) print operand
> $11 = <optimized out>
> (rr) print operand
> $12 = <optimized out>
> 
> ~~~~~~~~~~~~~~
> 
> So from the above I notice a couple of... "interesting" behavior:
> 
> - op->number is an unsigned value, but gets the signed value -16 written to 
> it, thereby producing the large value 0xFFFFFFFFFFFFFFF0
> 
> - even if the above would be signed, the expression "15 - 16" is always going 
> to result in a bogus address
> 
> - has anyone a clue of what may be going wrong here? Is one of our callbacks 
> returning wrong values before? Is the DWARF info broken? Is there any kind of 
> DWARF validator or anything like that which I could use here to check? I 
> notice that this issue often arises with frames in libc and ld.so. But, so 
> far, I have not come up with a good way to write a MWE that reliably tests 
> this behavior... Is there maybe something in the elfutils source code repo 
> that I could use as a basis?

I am not following the above trace completely, but what is going on
seems to be that we have CFI and want to get a register value. So we
call dwarf_frame_register to determine the DWARF expression operations
that we need to execute to get the register value. dwarf_frame_register
determines that that the register is described by a register offset
value rule, so it generates operations saying see an the CFA
(DW_OP_call_frame_cfa) plus some offset (DW_OP_plus_uconst) as a value
(so read the value from cfa + offset, which is somewhere on the stack).
But then the cfa comes out as 15? That is obviously bogus. But I don't
really understand how that happened. It should be a value somewhere near
the current stack. Then reading 15 - offset (16) clearly fails.

Cheers,

Mark