Index | Thread | Search

From:
"Theo de Raadt" <deraadt@openbsd.org>
Subject:
Re: diagprintf(9) aka Syzkaller debugging
To:
tech@openbsd.org
Date:
Thu, 11 Dec 2025 09:42:57 -0700

Download raw body.

Thread
I do not like the way this function works, especially since it is being
added to subr_prf.c

It does not feel like it's being written in a highly generic way; the
buffer supplied is small, and I don't think developers will become
accustomed to using it.

I have written code exactly like this previously to debug something where
I didn't trust the dmesg code.  But I didn't try to push it into subr_prf.c,
because it was just snprintf to a buffer, and advance the buffer forward,
like a ring.  It had no locking, and permitted corruption.  But I always
write in insitu-rather than trying to push it to subr_prf.c

It most definately didn't use the kprintf, it did this using the function
snprintf to make it clear the expectation was a side-effect-free function.
The kprintf TO* flags are internal, so kprintf is the unfamilar thing to use.

Anyways, since this is in DIAGNOSTIC it ends up in every non-RAMDISK kernel.
You call it once.  I think there should be a higher bar before pushing for
a function with this signature to be in subr_prf.c

Martin Pieuchot <mpi@grenadille.net> wrote:

> Thanks to the recently added KASSERT(), syzkaller exposed an
> inconsistency bug where a physical page ends up on a managed list and
> with a non-0 `wired_count':
>   https://syzkaller.appspot.com/bug?extid=f3c3aa16434bc13e3138
>   https://syzkaller.appspot.com/bug?extid=c1461974b88117f479c9
> 
> It's not clear to me how this can happen.  So I'd like to get more
> informations.
> Syzkaller reports anything after 'panic' and I'd like to print per-page
> informations (call uvm_page_printit()).  So I added a new printf(9)-like
> function that prints to a static buffer:
> 
> panic: page on LRU PAGE 0xfffffd8002dd5a58:
>   flags=200004<TABLED,AOBJ>, vers=1, wire_count=0, pa=0x74c7000
>   uobject=0xfffffd8007575f30, uanon=0x0, offset=0x0
>   [page ownership tracking disabled]    vm_page_md 0xfffffd8002dd5ac0
>   checking object list
>   page found on object list
> 
> Comments, ok?
> 
> Index: kern/subr_prf.c
> ===================================================================
> RCS file: /cvs/src/sys/kern/subr_prf.c,v
> diff -u -p -r1.106 subr_prf.c
> --- kern/subr_prf.c	14 Aug 2022 01:58:28 -0000	1.106
> +++ kern/subr_prf.c	11 Dec 2025 13:48:08 -0000
> @@ -115,6 +115,10 @@ int	db_console = 0;
>  #endif
>  #endif
>  
> +#ifdef DIAGNOSTIC
> +char diagbuf[1024];		/* static buffer for diagnostic. */
> +#endif
> +
>  /*
>   * panic on spl assertion failure?
>   */
> @@ -510,6 +514,32 @@ db_vprintf(const char *fmt, va_list ap)
>  }
>  #endif /* DDB */
>  
> +#ifdef DIAGNOSTIC
> +/*
> + * diagprintf: print a message to the static buffer `diagbuf'
> + */
> +int
> +diagprintf(const char *fmt, ...)
> +{
> +	static char *diagp;
> +	int retval;
> +	va_list ap;
> +	char *p;
> +
> +	if (diagp == NULL)
> +		diagp = diagbuf;
> +	p = diagbuf + sizeof(diagbuf) - 1;
> +	/* check for buffer exhaustion */
> +	if (p <= diagp)
> +		return (-1);
> +	va_start(ap, fmt);
> +	retval = kprintf(fmt, TOBUFONLY | TOCOUNT, &p, diagp, ap);
> +	va_end(ap);
> +	*p = '\0';
> +	diagp = p;
> +	return (retval);
> +}
> +#endif /* DIAGNOSTIC */
>  
>  /*
>   * normal kernel printf functions: printf, vprintf, snprintf
> Index: sys/systm.h
> ===================================================================
> RCS file: /cvs/src/sys/sys/systm.h,v
> diff -u -p -r1.177 systm.h
> --- sys/systm.h	28 Jul 2025 05:08:35 -0000	1.177
> +++ sys/systm.h	11 Dec 2025 13:27:59 -0000
> @@ -175,6 +175,11 @@ int	snprintf(char *buf, size_t, const ch
>  struct tty;
>  void	ttyprintf(struct tty *, const char *, ...)
>      __attribute__((__format__(__kprintf__,2,3)));
> +#ifdef DIAGNOSTIC
> +extern char diagbuf[1024];
> +int	diagprintf(const char *, ...)
> +    __attribute__((__format__(__kprintf__,1,2)));
> +#endif
>  
>  void	splassert_fail(int, int, const char *);
>  extern	int splassert_ctl;
> Index: uvm/uvm_map.c
> ===================================================================
> RCS file: /cvs/src/sys/uvm/uvm_map.c,v
> diff -u -p -r1.349 uvm_map.c
> --- uvm/uvm_map.c	10 Dec 2025 08:38:18 -0000	1.349
> +++ uvm/uvm_map.c	11 Dec 2025 11:54:02 -0000
> @@ -2947,7 +2947,7 @@ uvm_object_printit(struct uvm_object *uo
>   */
>  static const char page_flagbits[] =
>  	"\20\1BUSY\2WANTED\3TABLED\4CLEAN\5CLEANCHK\6RELEASED\7FAKE\10RDONLY"
> -	"\11ZERO\12DEV\15PAGER1\21FREE\22INACTIVE\23ACTIVE\25ANON\26AOBJ"
> +	"\11ZERO\12DEV\21FREE\22INACTIVE\23ACTIVE\25ANON\26AOBJ"
>  	"\27ENCRYPT\31PMAP0\32PMAP1\33PMAP2\34PMAP3\35PMAP4\36PMAP5";
>  
>  void
> Index: uvm/uvm_page.c
> ===================================================================
> RCS file: /cvs/src/sys/uvm/uvm_page.c,v
> diff -u -p -r1.184 uvm_page.c
> --- uvm/uvm_page.c	10 Dec 2025 08:38:18 -0000	1.184
> +++ uvm/uvm_page.c	11 Dec 2025 13:55:53 -0000
> @@ -75,6 +75,7 @@
>  #include <sys/smr.h>
>  
>  #include <uvm/uvm.h>
> +#include <uvm/uvm_ddb.h>
>  
>  /*
>   * for object trees
> @@ -1219,6 +1220,19 @@ uvm_pagelookup(struct uvm_object *obj, v
>  	return (pg);
>  }
>  
> +void
> +assert_not_managed(struct vm_page *pg)
> +{
> +#ifdef DIAGNOSTIC
> +	if (pg->pg_flags & (PQ_INACTIVE|PQ_ACTIVE)) {
> +#ifdef DDB
> +		uvm_page_printit(pg, TRUE, diagprintf);
> +#endif
> +		panic("page on LRU %s", diagbuf);
> +	}
> +#endif
> +}
> +
>  /*
>   * uvm_pagewire: wire the page, thus removing it from the daemon's grasp
>   */
> @@ -1233,6 +1247,7 @@ uvm_pagewire(struct vm_page *pg)
>  		uvm_unlock_pageq();
>  		atomic_inc_int(&uvmexp.wired);
>  	}
> +	assert_not_managed(pg);
>  	pg->wire_count++;
>  }
>  
> @@ -1264,7 +1279,7 @@ uvm_pagedeactivate(struct vm_page *pg)
>  	KASSERT(uvm_page_owner_locked_p(pg, FALSE));
>  
>  	if (pg->wire_count > 0) {
> -		KASSERT((pg->pg_flags & (PQ_INACTIVE|PQ_ACTIVE)) == 0);
> +		assert_not_managed(pg);
>  		return;
>  	}
>  
> 
>