sysctl(2): add KERN_TIMEOUT_STATS: timeout(9) status and statistics.

With these totals one can track the throughput of the timeout(9) layer
from userspace.

With input from mpi@.

ok mpi@

5 files changed, 76 insertions, 7 deletions

diff --git a/sbin/sysctl/sysctl.c b/sbin/sysctl/sysctl.c
index 4fdf53b706b..42a2846cd66 100644
--- a/sbin/sysctl/sysctl.c
+++ b/sbin/sysctl/sysctl.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: sysctl.c,v 1.245 2019/07/03 10:32:33 dlg Exp $	*/
+/*	$OpenBSD: sysctl.c,v 1.246 2019/07/12 00:04:59 cheloha Exp $	*/
 /*	$NetBSD: sysctl.c,v 1.9 1995/09/30 07:12:50 thorpej Exp $	*/
 
 /*
@@ -183,6 +183,7 @@ time_t boottime;
 #define	SENSORS		0x00002000
 #define	SMALLBUF	0x00004000
 #define	HEX		0x00008000
+#define	TIMEOUT		0x00010000
 
 /* prototypes */
 void debuginit(void);
@@ -527,6 +528,9 @@ parse(char *string, int flags)
 				return;
 			warnx("use pfctl to view %s information", string);
 			return;
+		case KERN_TIMEOUT_STATS:
+			special |= TIMEOUT;
+			break;
 		}
 		break;
 
@@ -1027,6 +1031,23 @@ parse(char *string, int flags)
 		}
 		return;
 	}
+	if (special & TIMEOUT) {
+		struct timeoutstat *tstat = (struct timeoutstat *)buf;
+
+		if (!nflag)
+			printf("%s%s", string, equ);
+		printf("added = %llu, cancelled = %llu, deleted = %llu, "
+		    "late = %llu, pending = %llu, readded = %llu, "
+		    "rescheduled = %llu, run_softclock = %llu, "
+		    "run_thread = %llu, softclocks = %llu, "
+		    "thread_wakeups = %llu\n",
+		    tstat->tos_added, tstat->tos_cancelled, tstat->tos_deleted,
+		    tstat->tos_late, tstat->tos_pending, tstat->tos_readded,
+		    tstat->tos_rescheduled, tstat->tos_run_softclock,
+		    tstat->tos_run_thread, tstat->tos_softclocks,
+		    tstat->tos_thread_wakeups);
+		return;
+	}
 	switch (type) {
 	case CTLTYPE_INT:
 		if (newsize == 0) {
diff --git a/sys/kern/kern_sysctl.c b/sys/kern/kern_sysctl.c
index 06eb7803191..53b5d9e878f 100644
--- a/sys/kern/kern_sysctl.c
+++ b/sys/kern/kern_sysctl.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: kern_sysctl.c,v 1.361 2019/07/10 16:43:19 anton Exp $	*/
+/*	$OpenBSD: kern_sysctl.c,v 1.362 2019/07/12 00:04:59 cheloha Exp $	*/
 /*	$NetBSD: kern_sysctl.c,v 1.17 1996/05/20 17:49:05 mrg Exp $	*/
 
 /*-
@@ -673,6 +673,8 @@ kern_sysctl(int *name, u_int namelen, void *oldp, size_t *oldlenp, void *newp,
 	case KERN_PFSTATUS:
 		return (pf_sysctl(oldp, oldlenp, newp, newlen));
 #endif
+	case KERN_TIMEOUT_STATS:
+		return (timeout_sysctl(oldp, oldlenp, newp, newlen));
 	default:
 		return (EOPNOTSUPP);
 	}
diff --git a/sys/kern/kern_timeout.c b/sys/kern/kern_timeout.c
index 93eabb3dd6b..9931cec9c69 100644
--- a/sys/kern/kern_timeout.c
+++ b/sys/kern/kern_timeout.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: kern_timeout.c,v 1.55 2019/04/23 13:35:12 visa Exp $	*/
+/*	$OpenBSD: kern_timeout.c,v 1.56 2019/07/12 00:04:59 cheloha Exp $	*/
 /*
  * Copyright (c) 2001 Thomas Nordin <nordin@openbsd.org>
  * Copyright (c) 2000-2001 Artur Grabowski <art@openbsd.org>
@@ -32,6 +32,7 @@
 #include <sys/mutex.h>
 #include <sys/kernel.h>
 #include <sys/queue.h>			/* _Q_INVALIDATE */
+#include <sys/sysctl.h>
 #include <sys/witness.h>
 
 #ifdef DDB
@@ -92,6 +93,8 @@ timeout_from_circq(struct circq *p)
  */
 struct mutex timeout_mutex = MUTEX_INITIALIZER(IPL_HIGH);
 
+struct timeoutstat tostat;
+
 /*
  * Circular queue definitions.
  */
@@ -106,6 +109,7 @@ struct mutex timeout_mutex = MUTEX_INITIALIZER(IPL_HIGH);
         (elem)->next = (list);                  \
         (list)->prev->next = (elem);            \
         (list)->prev = (elem);                  \
+        tostat.tos_pending++;                   \
 } while (0)
 
 #define CIRCQ_APPEND(fst, snd) do {             \
@@ -123,6 +127,7 @@ struct mutex timeout_mutex = MUTEX_INITIALIZER(IPL_HIGH);
         (elem)->prev->next = (elem)->next;      \
 	_Q_INVALIDATE((elem)->prev);		\
 	_Q_INVALIDATE((elem)->next);		\
+	tostat.tos_pending--;			\
 } while (0)
 
 #define CIRCQ_FIRST(elem) ((elem)->next)
@@ -250,11 +255,13 @@ timeout_add(struct timeout *new, int to_ticks)
 			CIRCQ_REMOVE(&new->to_list);
 			CIRCQ_INSERT(&new->to_list, &timeout_todo);
 		}
+		tostat.tos_readded++;
 		ret = 0;
 	} else {
 		new->to_flags |= TIMEOUT_ONQUEUE;
 		CIRCQ_INSERT(&new->to_list, &timeout_todo);
 	}
+	tostat.tos_added++;
 	mtx_leave(&timeout_mutex);
 
 	return (ret);
@@ -360,9 +367,11 @@ timeout_del(struct timeout *to)
 	if (to->to_flags & TIMEOUT_ONQUEUE) {
 		CIRCQ_REMOVE(&to->to_list);
 		to->to_flags &= ~TIMEOUT_ONQUEUE;
+		tostat.tos_cancelled++;
 		ret = 1;
 	}
 	to->to_flags &= ~TIMEOUT_TRIGGERED;
+	tostat.tos_deleted++;
 	mtx_leave(&timeout_mutex);
 
 	return (ret);
@@ -490,17 +499,22 @@ softclock(void *arg)
 		if (delta > 0) {
 			bucket = &BUCKET(delta, to->to_time);
 			CIRCQ_INSERT(&to->to_list, bucket);
+			tostat.tos_rescheduled++;
 		} else if (to->to_flags & TIMEOUT_NEEDPROCCTX) {
 			CIRCQ_INSERT(&to->to_list, &timeout_proc);
 			needsproc = 1;
 		} else {
+			if (delta < 0) {
+				tostat.tos_late++;
 #ifdef DEBUG
-			if (delta < 0)
 				printf("timeout delayed %d\n", delta);
 #endif
+			}
 			timeout_run(to);
+			tostat.tos_run_softclock++;
 		}
 	}
+	tostat.tos_softclocks++;
 	mtx_leave(&timeout_mutex);
 
 	if (needsproc)
@@ -541,7 +555,9 @@ softclock_thread(void *arg)
 			to = timeout_from_circq(CIRCQ_FIRST(&timeout_proc));
 			CIRCQ_REMOVE(&to->to_list);
 			timeout_run(to);
+			tostat.tos_run_thread++;
 		}
+		tostat.tos_thread_wakeups++;
 		mtx_leave(&timeout_mutex);
 	}
 }
@@ -578,6 +594,18 @@ timeout_adjust_ticks(int adj)
 }
 #endif
 
+int
+timeout_sysctl(void *oldp, size_t *oldlenp, void *newp, size_t newlen)
+{
+	struct timeoutstat status;
+
+	mtx_enter(&timeout_mutex);
+	memcpy(&status, &tostat, sizeof(status));
+	mtx_leave(&timeout_mutex);
+
+	return sysctl_rdstruct(oldp, oldlenp, newp, &status, sizeof(status));
+}
+
 #ifdef DDB
 void db_show_callout_bucket(struct circq *);
 
diff --git a/sys/sys/sysctl.h b/sys/sys/sysctl.h
index 836aeeb91f9..958cd4c9bb6 100644
--- a/sys/sys/sysctl.h
+++ b/sys/sys/sysctl.h
@@ -1,4 +1,4 @@
-/*	$OpenBSD: sysctl.h,v 1.193 2019/07/03 10:19:45 dlg Exp $	*/
+/*	$OpenBSD: sysctl.h,v 1.194 2019/07/12 00:04:59 cheloha Exp $	*/
 /*	$NetBSD: sysctl.h,v 1.16 1996/04/09 20:55:36 cgd Exp $	*/
 
 /*
@@ -187,7 +187,8 @@ struct ctlname {
 #define	KERN_AUDIO		84	/* struct: audio properties */
 #define	KERN_CPUSTATS		85	/* struct: cpu statistics */
 #define	KERN_PFSTATUS		86	/* struct: pf status and stats */
-#define	KERN_MAXID		87	/* number of valid kern ids */
+#define	KERN_TIMEOUT_STATS	87	/* struct: timeout status and stats */
+#define	KERN_MAXID		88	/* number of valid kern ids */
 
 #define	CTL_KERN_NAMES { \
 	{ 0, 0 }, \
@@ -277,6 +278,7 @@ struct ctlname {
 	{ "audio", CTLTYPE_STRUCT }, \
 	{ "cpustats", CTLTYPE_STRUCT }, \
 	{ "pfstatus", CTLTYPE_STRUCT }, \
+	{ "timeout_stats", CTLTYPE_STRUCT }, \
 }
 
 /*
diff --git a/sys/sys/timeout.h b/sys/sys/timeout.h
index 0e38ce8a588..f21f58deb82 100644
--- a/sys/sys/timeout.h
+++ b/sys/sys/timeout.h
@@ -1,4 +1,4 @@
-/*	$OpenBSD: timeout.h,v 1.28 2019/04/14 08:51:31 visa Exp $	*/
+/*	$OpenBSD: timeout.h,v 1.29 2019/07/12 00:04:59 cheloha Exp $	*/
 /*
  * Copyright (c) 2000-2001 Artur Grabowski <art@openbsd.org>
  * All rights reserved. 
@@ -72,7 +72,23 @@ struct timeout {
 #define TIMEOUT_INITIALIZED	4	/* timeout is initialized */
 #define TIMEOUT_TRIGGERED	8	/* timeout is running or ran */
 
+struct timeoutstat {
+	uint64_t tos_added;		/* timeout_add*(9) calls */
+	uint64_t tos_cancelled;		/* dequeued during timeout_del*(9) */
+	uint64_t tos_deleted;		/* timeout_del*(9) calls */
+	uint64_t tos_late;		/* run after deadline */
+	uint64_t tos_pending;		/* number currently ONQUEUE */
+	uint64_t tos_readded;		/* timeout_add*(9) + already ONQUEUE */
+	uint64_t tos_rescheduled;	/* requeued from softclock() */
+	uint64_t tos_run_softclock;	/* run from softclock() */
+	uint64_t tos_run_thread;	/* run from softclock_thread() */
+	uint64_t tos_softclocks;	/* softclock() calls */
+	uint64_t tos_thread_wakeups;	/* wakeups in softclock_thread() */
+};
+
 #ifdef _KERNEL
+int timeout_sysctl(void *, size_t *, void *, size_t);
+
 /*
  * special macros
  *