Re: kern/59339: heartbeat watchdog fires since 10.99.14

[Taylor R Campbell <riastradh%NetBSD.org@localhost>]

New patch!  More diagnostics, more potential problems avoided.

diff -r 55a6ded9e19e -r a27cadc62a5e 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
 }
 
 /*
+ * 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 = &it->it_time.it_interval;
+	const struct timespec * const next = &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 == CLOCK_MONOTONIC) {
+			getnanouptime(&now1);
+		} else {
+			getnanotime(&now1);
+		}
+		if (timespeccmp(next, &now1, <=)) {
+			printf("PR kern/59339 (heartbeat watchdog fires"
+			    " since 10.99.14) would fire:"
+			    " [clock %u]"
+			    " [now=%lld.%09ld -> %lld.%09ld],"
+			    " last=%lld.%09ld + interval=%lld.%09ld"
+			    " -> next=%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=%lld.%09ld,"
+		    " last=%lld.%09ld + interval=%lld.%09ld"
+		    " -> next=%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=%lld.%09ld, last=%lld.%09ld + interval=%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 = it->it_time.it_interval; /* overflow */
+	}
+	ticks = tstohz(&delta);
+	if (delta.tv_sec == 0 && delta.tv_nsec < 1000) {
+		printf("[clock %u]"
+		    " now=%lld.%09ld,"
+		    " last=%lld.%09ld + interval=%lld.%09ld"
+		    " -> next=%lld.%09ld;"
+		    " delta=%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=%lld.%09ld,"
+	    " last=%lld.%09ld + interval=%lld.%09ld -> next=%lld.%09ld;"
+	    " delta=%lld.%09ld ticks=%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 = arg;
 	int overruns;
 
@@ -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 = it->it_time.it_value;
 	itimer_transition(&it->it_time, &now, &next, &overruns);
+	KASSERTMSG(timespeccmp(&now, &next, <),
+	    "[clock %u]"
+	    " it->it_time.it_value=%lld.%09ld"
+	    " it->it_time.it_interval=%lld.%09ld"
+	    " now=%lld.%09ld next=%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 = next;
 	it->it_overruns += overruns;
 
@@ -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();
 }
 
diff -r 55a6ded9e19e -r a27cadc62a5e 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,28 @@ tshztoup(const struct timespec *tsp)
 
 /*
  * Compute number of ticks in the specified amount of time.
+ *
+ * Round up.  Return 0 iff ts <= 0.
  */
 int
 tstohz(const struct timespec *ts)
 {
 	struct timeval tv;
 
+	KASSERT(ts->tv_sec >= 0);
+	KASSERT(ts->tv_nsec >= 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 = ts->tv_sec;
+	tv.tv_usec = (ts->tv_nsec + 999)/1000;
+	if (tv.tv_usec >= 1000000) {
+		tv.tv_sec++;
+		tv.tv_usec -= 1000000;
+	}
 	return tvtohz(&tv);
 }