Re: [PATCH] mm: slub: print_hex_dump() with DUMP_PREFIX_OFFSET

Miles Chen
2019-09-22T17:05:08Z

On Sat, 2019-09-21 at 09:00 -0700, Matthew Wilcox wrote:
> On Sat, Sep 21, 2019 at 02:08:59AM -0700, David Rientjes wrote:
> > On Fri, 20 Sep 2019, Miles Chen wrote:
> >
> > > Since commit ad67b74d2469d9b8 ("printk: hash addresses printed with %p"),
> > > The use DUMP_PREFIX_OFFSET instead of DUMP_PREFIX_ADDRESS with
> > > print_hex_dump() can generate more useful messages.
> > >
> > > In the following example, it's easier get the offset of incorrect poison
> > > value with DUMP_PREFIX_OFFSET.
> > >
> > > Before:
> > > Object 00000000e817b73b: 00 00 00 00 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b
> > > Object 00000000816f4601: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b
> > > Object 00000000169d2bb8: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b
> > > Object 00000000f4c38716: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b
> > > Object 00000000917e3491: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b
> > > Object 00000000c0e33738: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b
> > > Object 000000001755ddd1: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b
> > >
> > > After:
> > > Object 00000000: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b
> > > Object 00000010: 63 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b
> > > Object 00000020: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b
> > > Object 00000030: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b a5
> >
> > I agree it looks nicer for poisoning, I'm not sure that every caller of
> > print_section() is the same, however. For example trace() seems better
> > off as DUMP_PREFIX_ADDRESS since it already specifies the address of the
> > object being allocated or freed and offset here wouldn't really be useful,
> > no?
>
> While it looks nicer, it might be less useful for debugging. The point of
> obfuscated %p is that you can compare two "pointer" values for equality.
> So if you know that you freed object 00000000e817b73b from an earlier
> printk, then you can match it up to this dump. It's obviously not
> perfect since we're only getting the pointers at addresses that are
> multiples of 16, but it's a help.

Thanks for the reply.

The value of 00000000e817b73b dump and the value earlier printk should
be the same, Otherwise we have a serious problem because:

printf("%p", bad_ptr);
print_hex_dump(bad_ptr);

and we see a different hashed address of bad_ptr in print_hex_dump().
I think it's a rare case but we still have a chance to see that case.
DUMP_PREFIX_ADDRESS is useful for that case.

On the other hand, DUMP_PREFIX_OFFSET is useful for finding the offset
of incorrect poison value easier.
Maybe I can print the offset of the bad poison value in
check_bytes_and_report(). e.g.,

@@ -736,6 +736,7 @@ static int check_bytes_and_report(struct kmem_cache
*s, struct page *page,
{
u8 *fault;
u8 *end;
+ u8 *addr = page_address(page);

metadata_access_enable();
fault = memchr_inv(start, value, bytes);
@@ -748,8 +749,9 @@ static int check_bytes_and_report(struct kmem_cache
*s, struct page *page,
end--;

slab_bug(s, "%s overwritten", what);
- pr_err("INFO: 0x%p-0x%p. First byte 0x%x instead of 0x%x\n",
- fault, end - 1, fault[0],
value);
+ pr_err("INFO: 0x%p-0x%p. First byte 0x%x instead of 0x%x,
offset=%tu\n",
+ fault, end - 1, fault[0], value,
fault -
+ addr);

and we can see the offset printed out:

=============================================================================
BUG kmalloc-1k (Tainted: G B ): Poison overwritten
-----------------------------------------------------------------------------

INFO: 0x(____ptrval____)-0x(____ptrval____). First byte 0x63 instead of
0x6b, offset=7052
INFO: Object 0x(____ptrval____) @offset=6272 fp=0x(____ptrval____)

and we can get the offset by: 7052 - 6272 = 780.