Re: kern/60531: looping "vflushbuf: dirty" message

The following reply was made to PR kern/60531; it has been noted by GNATS.

From: Taylor R Campbell <[email protected]>
To: [email protected], [email protected]
Cc: [email protected], [email protected]
Subject: Re: kern/60531: looping "vflushbuf: dirty" message
Date: Mon, 3 Aug 2026 00:38:22 +0000

 This is a multi-part message in MIME format.
 --=_QJyEfqlAfncoM8fB56hLDQdX5vxg3caH
 
 I prepared a pair of patches:
 
 1. WORKAROUND: pr60531-vflushbufdirty-ratelimit.patch works around the
    problem of overwhelming the console by putting the message under
    #ifdef DEBUG, and limiting it to once per call, and globally
    rate-limiting the output under bufcache_lock.
 
    It doesn't fix the underlying problem that the time vflushbuf can
    take is unbounded even if each write completes in bounded time --
    it's just a low-risk change for quick pullup, because this is
    interfering with backups on TNF infrastructure, and probably others
    too.
 
 2. FIX: pr60531-vflushbufdirty-flushgen.patch fixes the problem that
    the time vflushbuf can take is unbounded, not by making the invalid
    assumption that reassignbuf(bp, vp) hold vp's vnode lock, but
    rather by using a global flush generation counter:
 
    - For dirty buffers, reassignbuf(bp, vp) sets bp->b_flushgen to the
      global bufcache_flushgen.
 
    - vflushbuf(vp) grabs the current bufcache_flushgen as f,
      increments bufcache_flushgen, and then waits until all buffers bp
      on vp->v_dirtyblkhd with bp->b_flushgen <= f have completed.
 
    This should properly fix the underlying problem.
 
    (Haven't yet thought about whether vinvalbuf or vtruncbuf need to
    consider flushgen too.)
 
 --=_QJyEfqlAfncoM8fB56hLDQdX5vxg3caH
 Content-Type: text/plain; charset="ISO-8859-1"; name="pr60531-vflushbufdirty-ratelimit"
 Content-Transfer-Encoding: quoted-printable
 Content-Disposition: attachment; filename="pr60531-vflushbufdirty-ratelimit.patch"
 
 # HG changeset patch
 # User Taylor R Campbell <[email protected]>
 # Date 1785716340 0
 #      Mon Aug 03 00:19:00 2026 +0000
 # Branch trunk
 # Node ID 2c597c41062d49e186d14e507ecf9c07b940937f
 # Parent  1f2d855671ed4d4eee9ff4420a357756f04e271a
 # EXP-Topic riastradh-pr60531-vflushbufdirty
 vflushbuf: Print `vflushbuf: dirty' warning only once per call.
 
 And rate-limit it globally.
 
 This can happen when vflushbuf is competing with an onslaught of
 concurrent I/O, which might be happening indefinitely, so we are
 likely to have to print a _lot_ of warnings, potentially overwhelming
 the console, until the underlying problem is fixed by teaching
 vflushbuf to wait only for the writes that began before have
 completed, not also all writes that have begun since.
 
 This stop-gap measure intended to be low-risk for pullup to release
 branches.
 
 PR kern/60531: looping "vflushbuf: dirty" message
 
 diff -r 1f2d855671ed -r 2c597c41062d sys/kern/vfs_subr.c
 --- a/sys/kern/vfs_subr.c	Sat Aug 01 05:12:21 2026 +0000
 +++ b/sys/kern/vfs_subr.c	Mon Aug 03 00:19:00 2026 +0000
 @@ -338,6 +338,9 @@ vflushbuf(struct vnode *vp, int flags)
  	struct buf *bp, *nbp;
  	int error, pflags;
  	bool dirty, sync;
 +#ifdef DEBUG
 +	bool warned =3D false;
 +#endif
 =20
  	sync =3D (flags & FSYNC_WAIT) !=3D 0;
  	pflags =3D PGO_CLEANIT | PGO_ALLPAGES |
 @@ -382,7 +385,18 @@ loop:
  	mutex_exit(vp->v_interlock);
 =20
  	if (dirty) {
 -		vprint("vflushbuf: dirty", vp);
 +#ifdef DEBUG
 +		if (!warned) {
 +			static struct timeval vflushbuf_warntime;
 +			const struct timeval interval =3D {1,0};
 +
 +			mutex_enter(&bufcache_lock);
 +			if (ratecheck(&vflushbuf_warntime, &interval))
 +				vprint("vflushbuf: dirty", vp);
 +			mutex_exit(&bufcache_lock);
 +			warned =3D true;
 +		}
 +#endif
  		goto loop;
  	}
 =20
 
 --=_QJyEfqlAfncoM8fB56hLDQdX5vxg3caH
 Content-Type: text/plain; charset="ISO-8859-1"; name="pr60531-vflushbufdirty-flushgen"
 Content-Transfer-Encoding: quoted-printable
 Content-Disposition: attachment; filename="pr60531-vflushbufdirty-flushgen.patch"
 
 # HG changeset patch
 # User Taylor R Campbell <[email protected]>
 # Date 1785715442 0
 #      Mon Aug 03 00:04:02 2026 +0000
 # Branch trunk
 # Node ID 1946a089abf1ad98fd95ac56d7030395dc4213a3
 # Parent  1f2d855671ed4d4eee9ff4420a357756f04e271a
 # EXP-Topic riastradh-pr60531-vflushbufdirty
 vfs: Fix `vflushbuf: dirty'.
 
 Currently, vflushbuf(vp) requires the caller to hold vp's vnode lock,
 and assumes that reassignbuf(..., vp) is only done while vp's vnode
 lock is held.
 
 Under this assumption, vp->v_dirtyblkhd can never have dirty blocks
 added to it once vflushbuf starts, so the set of block writes that
 vflushbuf must wait for is limited to those dirty blocks that were
 already queued before it began.  Thus, it can safely wait until the
 vnode's number of active block writes (v_numoutput) has gone to zero,
 which it will in bounded time as long as each block write
 independently completes in bounded time.
 
 Unfortunately, this assumption is invalid, in at least two
 circumstances:
 
 - vp is a block device vnode on which another file system is mounted,
   and the file system uses getblk/bread/bwrite on vp to edit file
   system metadata.  These paths do not take vp's vnode lock.  Perhaps
   these could take vp's vnode lock because they will generally only
   hold _another file system's_ vnode lock, but these paths are
   extensively scattered through file system logic and confidently
   finding them and adjusting them to take the vnode lock -- and
   proving that it's safe to do so -- seems likely no small task.
 
 - vp is a snapshot backing store file on ffs (SF_SNAPSHOT).  Data
   copied on write for the snapshot is written with getblk/bwrite.
   This path does not take vp's vnode lock, and taking it might be
   troublesome because the cow logic runs while holding other vnode
   locks, so it is a high risk of deadlocks.
 
 To avoid this assumption, we instead cache a global flush generation
 number in each dirty block as it is queued in reassignbuf.  Each call
 to vflushbuf advances the flush generation.  This way, vflushbuf can
 detect which dirty blocks were already there when it started, and
 which ones are new, and wait only until the ones that were already
 there are done.
 
 Since the buffercache(9) path never has B_PHYS set, I repurposed two
 existing members of struct buf (b_proc, b_saveaddr) that are used
 only for B_PHYS buffers, to make room for for a uint64_t flush
 generation number used only for !B_PHYS buffers.  Using a 64-bit
 generation number guarantees that it will never wrap around in our
 lifetimes, even if we issue sync(8) sequentially once per nanosecond,
 and it completes in that time too.
 
 PR kern/60531: looping "vflushbuf: dirty" message
 
 diff -r 1f2d855671ed -r 1946a089abf1 sys/kern/vfs_subr.c
 --- a/sys/kern/vfs_subr.c	Sat Aug 01 05:12:21 2026 +0000
 +++ b/sys/kern/vfs_subr.c	Mon Aug 03 00:04:02 2026 +0000
 @@ -171,6 +171,8 @@ const int	vttoif_tab[9] =3D {
  	(bp)->b_vnbufs.le_next =3D NOLIST;				\
  }
 =20
 +static uint64_t bufcache_flushgen =3D 1;
 +
  int doforce =3D 1;		/* 1 =3D> permit forcible unmounting */
 =20
  /*
 @@ -329,8 +331,7 @@ restart:
 =20
  /*
   * Flush all dirty buffers from a vnode.
 - * Called with the underlying vnode locked, which should prevent new dirty
 - * buffers from being queued.
 + * Called with the underlying vnode locked.
   */
  int
  vflushbuf(struct vnode *vp, int flags)
 @@ -338,7 +339,11 @@ vflushbuf(struct vnode *vp, int flags)
  	struct buf *bp, *nbp;
  	int error, pflags;
  	bool dirty, sync;
 +	uint64_t flushgen;
 =20
 +	KASSERT(VOP_ISLOCKED(vp));
 +
 +	flushgen =3D 0;
  	sync =3D (flags & FSYNC_WAIT) !=3D 0;
  	pflags =3D PGO_CLEANIT | PGO_ALLPAGES |
  	    (sync ? PGO_SYNCIO : 0) |
 @@ -346,12 +351,20 @@ vflushbuf(struct vnode *vp, int flags)
  	rw_enter(vp->v_uobj.vmobjlock, RW_WRITER);
  	(void) VOP_PUTPAGES(vp, 0, 0, pflags);
 =20
 +	/*
 +	 * Ensure every dirty block associated with this vnode has
 +	 * begun to be written out (BC_BUSY, I/O in progress) -- any
 +	 * delayed writes must delay no longer.
 +	 */
  loop:
  	mutex_enter(&bufcache_lock);
 +	if (flushgen =3D=3D 0)
 +		flushgen =3D bufcache_flushgen++;
  	for (bp =3D LIST_FIRST(&vp->v_dirtyblkhd); bp; bp =3D nbp) {
  		KASSERT(bp->b_vp =3D=3D vp);
 +		KASSERT((bp->b_flags & B_PHYS) =3D=3D 0);
  		nbp =3D LIST_NEXT(bp, b_vnbufs);
 -		if ((bp->b_cflags & BC_BUSY))
 +		if ((bp->b_cflags & BC_BUSY) !=3D 0 || bp->b_flushgen > flushgen)
  			continue;
  		if ((bp->b_oflags & BO_DELWRI) =3D=3D 0)
  			panic("vflushbuf: not dirty, bp %p", bp);
 @@ -375,17 +388,23 @@ loop:
  	if (!sync)
  		return 0;
 =20
 +	/*
 +	 * Wait until all pending writes issued before we incremented
 +	 * bufcache_flushgen have completed.
 +	 */
  	mutex_enter(vp->v_interlock);
 -	while (vp->v_numoutput !=3D 0)
 -		cv_wait(&vp->v_cv, vp->v_interlock);
 -	dirty =3D !LIST_EMPTY(&vp->v_dirtyblkhd);
 +	do {
 +		dirty =3D false;
 +		for (bp =3D LIST_FIRST(&vp->v_dirtyblkhd); bp; bp =3D nbp) {
 +			if (bp->b_flushgen > flushgen)
 +				continue;
 +			dirty =3D true;
 +			cv_wait(&vp->v_cv, vp->v_interlock);
 +			break;
 +		}
 +	} while (dirty);
  	mutex_exit(vp->v_interlock);
 =20
 -	if (dirty) {
 -		vprint("vflushbuf: dirty", vp);
 -		goto loop;
 -	}
 -
  	return 0;
  }
 =20
 @@ -497,6 +516,7 @@ reassignbuf(struct buf *bp, struct vnode
  	KASSERT(bp->b_objlock =3D=3D vp->v_interlock);
  	KASSERT(mutex_owned(vp->v_interlock));
  	KASSERT((bp->b_cflags & BC_BUSY) !=3D 0);
 +	KASSERT((bp->b_flags & B_PHYS) =3D=3D 0);
 =20
  	/*
  	 * Delete from old vnode list, if on one.
 @@ -535,6 +555,7 @@ reassignbuf(struct buf *bp, struct vnode
  			    (vp->v_mount->mnt_flag & MNT_ASYNC) =3D=3D 0)
  				vn_syncer_add_to_worklist(vp, delayx);
  		}
 +		bp->b_flushgen =3D bufcache_flushgen;
  	}
  	bufinsvn(bp, listheadp);
  }
 diff -r 1f2d855671ed -r 1946a089abf1 sys/sys/buf.h
 --- a/sys/sys/buf.h	Sat Aug 01 05:12:21 2026 +0000
 +++ b/sys/sys/buf.h	Mon Aug 03 00:04:02 2026 +0000
 @@ -135,8 +135,15 @@ struct buf {
  						      (partition relative) */
  	daddr_t			b_rawblkno;	/* b: raw physical block number
  						      (volume relative) */
 -	struct proc		*b_proc;	/* b: proc if BB_PHYS */
 -	void			*b_saveaddr;	/* b: saved b_data for physio */
 +	union {
 +		/* B_PHYS */
 +		struct {
 +			struct proc *b_proc;	/* b: proc if B_PHYS */
 +			void	*b_saveaddr;	/* b: saved b_data for physio */
 +		};
 +		/* !B_PHYS */
 +		uint64_t	b_flushgen;	/* b: flush generation */
 +	};
  	struct cpu_info		*b_ci;		/* b: originating CPU */
 =20
  	/*
 
 --=_QJyEfqlAfncoM8fB56hLDQdX5vxg3caH--