Re: [PATCH] vsprintf: Make %pGp print the hex value

[Matthew Wilcox <willy@infradead.org>]

On Tue, Oct 12, 2021 at 01:57:09PM +0200, Rasmus Villemoes wrote:
> On 12/10/2021 13.32, Matthew Wilcox wrote:
> > On Tue, Oct 12, 2021 at 11:55:50AM +0200, Rasmus Villemoes wrote:
> >> ...default_flag_spec has '.flags = SPECIAL | SMALL,', i.e. what one
> >> would get from %#x . I'm guessing that's what upsets 0-day.
> >>
> >> Geez it would be nice if 0day actually reported the "Expected foo, but
> >> bar was emitted to the buffer".
> > 
> > It's there; you just have to dive into the dmesg.xz to get it:
> > 
> > [   48.607787][ T1214] test_printf: vsnprintf(buf, 256, "%pGp", ...) returned 33, expected 29
> > [   48.616106][ T1214] test_printf: vsnprintf(buf, 18, "%pGp", ...) returned 33, expected 29
> > [   48.624292][ T1214] test_printf: vsnprintf(buf, 0, "%pGp", ...) returned 33, expected 29
> > [   48.632403][ T1214] test_printf: kvasprintf(..., "%pGp", ...) returned '0x0(node=0|zone=0|lastcpupid=0x0)', expected 'node=0|zone=0|lastcpupid=0x0)'
> > [   48.645741][ T1214] test_printf: vsnprintf(buf, 256, "%pGp", ...) returned 33, expected 29
> > [   48.654023][ T1214] test_printf: vsnprintf(buf, 23, "%pGp", ...) returned 33, expected 29
> > [   48.662218][ T1214] test_printf: vsnprintf(buf, 0, "%pGp", ...) returned 33, expected 29
> > [   48.670327][ T1214] test_printf: kvasprintf(..., "%pGp", ...) returned '0x0(node=0|zone=0|lastcpupid=0x0)', expected 'node=0|zone=0|lastcpupid=0x0)'
> > [   48.683670][ T1214] test_printf: vsnprintf(buf, 256, "%pGp", ...) returned 88, expected 71
> > [   48.691937][ T1214] test_printf: vsnprintf(buf, 64, "%pGp", ...) returned 88, expected 71
> > [   48.700128][ T1214] test_printf: vsnprintf(buf, 0, "%pGp", ...) returned 88, expected 71
> > [   48.708249][ T1214] test_printf: kvasprintf(..., "%pGp", ...) returned '0x4fffffc008003c(uptodate|dirty|lru|active|swapbacked|node=1|zone=1|lastcpupid=0x1fffff)', expected 'uptodate|dirty|lru|active|swapbacked|node=1|zone=1|lastcpupid=0x1fffff)'
> > [   48.730275][ T1214] test_printf: failed 12 out of 420 tests
> > 
> > So you're right, it's missing the 0x, 
> 
> Ah, it's actually missing the whole '0xfoo(' because you're not updating
> 'size' after the first
> 
> +	snprintf(cmp_buf + size, BUF_SIZE - size, "%x(", flags);
> 
> so the next write to cmp_buf overwrites whatever you wrote here.
> 
> > but I still don't know how to run this self-test.
> 
> Neither do I, when I created test_printf.c I made sure it ran on boot if
> built-in, and that's certainly how I've been testing vsprintf.c patches
> in the past. Maybe the kstm crowd can explain how to get that to work as
> expected.

Got it.  It was running; just wasn't being captured by the kernel
messages output on my test system.  If I ssh in to the test system and
examine dmesg, it's there.

Now, this isn't quite enough;

-       snprintf(cmp_buf + size, BUF_SIZE - size, "%x(", flags);
+       snprintf(cmp_buf + size, BUF_SIZE - size, "%#x(", flags);
+       size = strlen(cmp_buf);

The problem is that the test suite doesn't pass in a full flags.
It passes in some pageflags and then ORs in the zone, nid, etc
after printing some of the flags.  So I had to restructure the
test a bit to print the full hex number.  What do you think?

+++ b/lib/test_printf.c
@@ -610,11 +610,15 @@ page_flags_test(int section, int node, int zone, int last_cpupid,
 {
        unsigned long values[] = {section, node, zone, last_cpupid, kasan_tag};
        unsigned long page_flags = 0;
+       unsigned long test_flags = flags & PAGEFLAGS_MASK;
        unsigned long size = 0;
        bool append = false;
        int i;

-       snprintf(cmp_buf + size, BUF_SIZE - size, "%x(", flags);
+       for (i = 0; i < ARRAY_SIZE(values); i++)
+               test_flags |= (values[i] & pft[i].mask) << pft[i].shift;
+       snprintf(cmp_buf + size, BUF_SIZE - size, "%#lx(", test_flags);
+       size = strlen(cmp_buf);
        flags &= PAGEFLAGS_MASK;
        if (flags) {
                page_flags |= flags;

It's a bit duplicative of what's below, and I'm far from sure about the
testing of bits that fall outside PAGEFLAGS_MASK.  It doesn't feel like a
great test in that it's not testing how pGp would get used.  Maybe that
points to a small defect in pGp -- shouldn't it print something for
unknown bits being set?