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

[Miles Chen]

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.