Re: kern/59339: heartbeat watchdog fires since 10.99.14

["Taylor R Campbell via gnats" <gnats-admin%NetBSD.org@localhost>]

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

From: Taylor R Campbell <riastradh%NetBSD.org@localhost>
To: Thomas Klausner <wiz%NetBSD.org@localhost>, Patrick Welche <prlw1%welche.eu@localhost>
Cc: gnats-bugs%NetBSD.org@localhost, netbsd-bugs%NetBSD.org@localhost
Subject: Re: kern/59339: heartbeat watchdog fires since 10.99.14
Date: Sat, 10 May 2025 13:03:37 +0000

 This is a multi-part message in MIME format.
 --=_rQ5/ZdmDD9MmXcsf79EVgs7gGkvXK6eU
 
 > Date: Sat, 10 May 2025 11:29:01 +0200
 > From: Thomas Klausner <wiz%NetBSD.org@localhost>
 > 
 > On Sat, May 10, 2025 at 08:41:06AM +0000, Taylor R Campbell wrote:
 > > New patch!  More diagnostics, more potential problems avoided.
 > 
 > Much worse, two panics in less than 5 minutes each.
 
 Sorry -- that assertion I added to tstohz is wrong, nix it.
 Replacement patch attached.
 
 --=_rQ5/ZdmDD9MmXcsf79EVgs7gGkvXK6eU
 Content-Type: text/plain; charset="ISO-8859-1"; name="pr59339-itimercalloutassert-v5"
 Content-Transfer-Encoding: quoted-printable
 Content-Disposition: attachment; filename="pr59339-itimercalloutassert-v5.patch"
 
 diff -r 55a6ded9e19e -r f01484399631 sys/kern/kern_time.c
 --- a/sys/kern/kern_time.c	Thu May 08 20:51:40 2025 +0000
 +++ b/sys/kern/kern_time.c	Sat May 10 08:36:45 2025 +0000
 @@ -837,6 +837,105 @@ itimer_arm_real(struct itimer * const it
  }
 =20
  /*
 + * itimer_rearm_real:
 + *
 + *	Re-arm a non-virtual timer, given the current clock readout.
 + */
 +static void
 +itimer_rearm_real(struct itimer * const it, const struct timespec * const =
 now,
 +    const struct timespec * const last)
 +{
 +	const struct timespec * const interval =3D &it->it_time.it_interval;
 +	const struct timespec * const next =3D &it->it_time.it_value;
 +	struct timespec delta;
 +	int ticks;
 +
 +	KASSERT(!it->it_dying);
 +	KASSERT(!CLOCK_VIRTUAL_P(it->it_clockid));
 +	KASSERT(!callout_pending(&it->it_ch));
 +
 +	if (__predict_true(timespecisset(next))) {
 +		struct timespec now1;
 +
 +		if (it->it_clockid =3D=3D CLOCK_MONOTONIC) {
 +			getnanouptime(&now1);
 +		} else {
 +			getnanotime(&now1);
 +		}
 +		if (timespeccmp(next, &now1, <=3D)) {
 +			printf("PR kern/59339 (heartbeat watchdog fires"
 +			    " since 10.99.14) would fire:"
 +			    " [clock %u]"
 +			    " [now=3D%lld.%09ld -> %lld.%09ld],"
 +			    " last=3D%lld.%09ld + interval=3D%lld.%09ld"
 +			    " -> next=3D%lld.%09ld\n",
 +			    it->it_clockid,
 +			    (long long)now->tv_sec, (long)now->tv_nsec,
 +			    (long long)now1.tv_sec, (long)now1.tv_nsec,
 +			    (long long)last->tv_sec, (long)last->tv_nsec,
 +			    (long long)interval->tv_sec,
 +			    (long)interval->tv_nsec,
 +			    (long long)next->tv_sec, (long)next->tv_nsec);
 +		}
 +
 +		KASSERTMSG(timespeccmp(now, next, <),
 +		    "[clock %u]"
 +		    " now=3D%lld.%09ld,"
 +		    " last=3D%lld.%09ld + interval=3D%lld.%09ld"
 +		    " -> next=3D%lld.%09ld",
 +		    it->it_clockid,
 +		    (long long)now->tv_sec, (long)now->tv_nsec,
 +		    (long long)last->tv_sec, (long)last->tv_nsec,
 +		    (long long)interval->tv_sec, (long)interval->tv_nsec,
 +		    (long long)next->tv_sec, (long)next->tv_nsec);
 +		timespecsub(next, now, &delta);
 +	} else {
 +		/*
 +		 * If the arithmetic overflowed, just take the interval
 +		 * as the time to wait.  This is unlikely to happen
 +		 * unless you are messing with your clock to set it
 +		 * ahead by hundreds of years.
 +		 */
 +		printf("[clock %u]"
 +		    " itimer arithmetic overflowed:"
 +		    " now=3D%lld.%09ld, last=3D%lld.%09ld + interval=3D%lld.%09ld\n",
 +		    it->it_clockid,
 +		    (long long)now->tv_sec, (long)now->tv_nsec,
 +		    (long long)last->tv_sec, (long)last->tv_nsec,
 +		    (long long)interval->tv_sec, (long)interval->tv_nsec);
 +		delta =3D it->it_time.it_interval; /* overflow */
 +	}
 +	ticks =3D tstohz(&delta);
 +	if (delta.tv_sec =3D=3D 0 && delta.tv_nsec < 1000) {
 +		printf("[clock %u]"
 +		    " now=3D%lld.%09ld,"
 +		    " last=3D%lld.%09ld + interval=3D%lld.%09ld"
 +		    " -> next=3D%lld.%09ld;"
 +		    " delta=3D%lld.%09ld ticks rounded to %d",
 +		    it->it_clockid,
 +		    (long long)now->tv_sec, (long)now->tv_nsec,
 +		    (long long)last->tv_sec, (long)last->tv_nsec,
 +		    (long long)interval->tv_sec, (long)interval->tv_nsec,
 +		    (long long)next->tv_sec, (long)next->tv_nsec,
 +		    (long long)delta.tv_sec, (long)delta.tv_nsec,
 +		    ticks);
 +	}
 +	KASSERTMSG(ticks > 0,
 +	    "[clock %u]"
 +	    " now=3D%lld.%09ld,"
 +	    " last=3D%lld.%09ld + interval=3D%lld.%09ld -> next=3D%lld.%09ld;"
 +	    " delta=3D%lld.%09ld ticks=3D%d",
 +	    it->it_clockid,
 +	    (long long)now->tv_sec, (long)now->tv_nsec,
 +	    (long long)last->tv_sec, (long)last->tv_nsec,
 +	    (long long)interval->tv_sec, (long)interval->tv_nsec,
 +	    (long long)next->tv_sec, (long)next->tv_nsec,
 +	    (long long)delta.tv_sec, (long)delta.tv_nsec,
 +	    ticks);
 +	callout_schedule(&it->it_ch, ticks);
 +}
 +
 +/*
   * itimer_callout:
   *
   *	Callout to expire a non-virtual timer.  Queue it up for processing,
 @@ -848,7 +947,7 @@ itimer_arm_real(struct itimer * const it
  static void
  itimer_callout(void *arg)
  {
 -	struct timespec now, next;
 +	struct timespec last, now, next;
  	struct itimer * const it =3D arg;
  	int overruns;
 =20
 @@ -871,7 +970,20 @@ itimer_callout(void *arg)
  	 * Given the current itimer value and interval and the time
  	 * now, compute the next itimer value and count overruns.
  	 */
 +	last =3D it->it_time.it_value;
  	itimer_transition(&it->it_time, &now, &next, &overruns);
 +	KASSERTMSG(timespeccmp(&now, &next, <),
 +	    "[clock %u]"
 +	    " it->it_time.it_value=3D%lld.%09ld"
 +	    " it->it_time.it_interval=3D%lld.%09ld"
 +	    " now=3D%lld.%09ld next=3D%lld.%09ld",
 +	    it->it_clockid,
 +	    (long long)it->it_time.it_value.tv_sec,
 +	    (long)it->it_time.it_value.tv_nsec,
 +	    (long long)it->it_time.it_interval.tv_sec,
 +	    (long)it->it_time.it_interval.tv_nsec,
 +	    (long long)now.tv_sec, (long)now.tv_nsec,
 +	    (long long)next.tv_sec, (long)next.tv_nsec);
  	it->it_time.it_value =3D next;
  	it->it_overruns +=3D overruns;
 =20
 @@ -879,7 +991,7 @@ itimer_callout(void *arg)
  	 * Reset the callout, if it's not going away.
  	 */
  	if (!it->it_dying)
 -		itimer_arm_real(it);
 +		itimer_rearm_real(it, &now, &last);
  	itimer_unlock();
  }
 =20
 diff -r 55a6ded9e19e -r f01484399631 sys/kern/subr_time.c
 --- a/sys/kern/subr_time.c	Thu May 08 20:51:40 2025 +0000
 +++ b/sys/kern/subr_time.c	Sat May 10 08:36:45 2025 +0000
 @@ -86,17 +86,27 @@ tshztoup(const struct timespec *tsp)
 =20
  /*
   * Compute number of ticks in the specified amount of time.
 + *
 + * Round up.  Return 0 iff ts <=3D 0.
   */
  int
  tstohz(const struct timespec *ts)
  {
  	struct timeval tv;
 =20
 +	KASSERT(ts->tv_nsec >=3D 0);
 +	KASSERT(ts->tv_nsec < 1000000000);
 +
  	/*
  	 * usec has great enough resolution for hz, so convert to a
  	 * timeval and use tvtohz() above.
  	 */
 -	TIMESPEC_TO_TIMEVAL(&tv, ts);
 +	tv.tv_sec =3D ts->tv_sec;
 +	tv.tv_usec =3D (ts->tv_nsec + 999)/1000;
 +	if (tv.tv_usec >=3D 1000000) {
 +		tv.tv_sec++;
 +		tv.tv_usec -=3D 1000000;
 +	}
  	return tvtohz(&tv);
  }
 =20
 
 --=_rQ5/ZdmDD9MmXcsf79EVgs7gGkvXK6eU--