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?
