Source-Changes-HG archive
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index][Old Index]
[src/trunk]: src/sys/kern Switch from ad-hoc logging to dtrace probes.
details: https://anonhg.NetBSD.org/src/rev/024341fc47e7
branches: trunk
changeset: 848792:024341fc47e7
user: riastradh <riastradh%NetBSD.org@localhost>
date: Sun Feb 09 22:57:39 2020 +0000
description:
Switch from ad-hoc logging to dtrace probes.
diffstat:
sys/kern/kern_threadpool.c | 172 ++++++++++++++++++++++++++++++++------------
1 files changed, 126 insertions(+), 46 deletions(-)
diffs (truncated from 415 to 300 lines):
diff -r 252c5beaae67 -r 024341fc47e7 sys/kern/kern_threadpool.c
--- a/sys/kern/kern_threadpool.c Sun Feb 09 22:57:26 2020 +0000
+++ b/sys/kern/kern_threadpool.c Sun Feb 09 22:57:39 2020 +0000
@@ -1,4 +1,4 @@
-/* $NetBSD: kern_threadpool.c,v 1.16 2020/02/09 22:57:26 riastradh Exp $ */
+/* $NetBSD: kern_threadpool.c,v 1.17 2020/02/09 22:57:39 riastradh Exp $ */
/*-
* Copyright (c) 2014, 2018 The NetBSD Foundation, Inc.
@@ -81,7 +81,7 @@
*/
#include <sys/cdefs.h>
-__KERNEL_RCSID(0, "$NetBSD: kern_threadpool.c,v 1.16 2020/02/09 22:57:26 riastradh Exp $");
+__KERNEL_RCSID(0, "$NetBSD: kern_threadpool.c,v 1.17 2020/02/09 22:57:39 riastradh Exp $");
#include <sys/types.h>
#include <sys/param.h>
@@ -97,10 +97,82 @@
#include <sys/pool.h>
#include <sys/proc.h>
#include <sys/queue.h>
-#include <sys/systm.h>
+#include <sys/sdt.h>
#include <sys/sysctl.h>
+#include <sys/systm.h>
#include <sys/threadpool.h>
+/* Probes */
+
+SDT_PROBE_DEFINE1(sdt, kernel, threadpool, get,
+ "pri_t"/*pri*/);
+SDT_PROBE_DEFINE1(sdt, kernel, threadpool, get__create,
+ "pri_t"/*pri*/);
+SDT_PROBE_DEFINE1(sdt, kernel, threadpool, get__race,
+ "pri_t"/*pri*/);
+SDT_PROBE_DEFINE2(sdt, kernel, threadpool, put,
+ "struct threadpool *"/*pool*/, "pri_t"/*pri*/);
+SDT_PROBE_DEFINE2(sdt, kernel, threadpool, put__destroy,
+ "struct threadpool *"/*pool*/, "pri_t"/*pri*/);
+
+SDT_PROBE_DEFINE1(sdt, kernel, threadpool, percpu__get,
+ "pri_t"/*pri*/);
+SDT_PROBE_DEFINE1(sdt, kernel, threadpool, percpu__get__create,
+ "pri_t"/*pri*/);
+SDT_PROBE_DEFINE1(sdt, kernel, threadpool, percpu__get__race,
+ "pri_t"/*pri*/);
+SDT_PROBE_DEFINE2(sdt, kernel, threadpool, percpu__put,
+ "struct threadpool *"/*pool*/, "pri_t"/*pri*/);
+SDT_PROBE_DEFINE2(sdt, kernel, threadpool, percpu__put__destroy,
+ "struct threadpool *"/*pool*/, "pri_t"/*pri*/);
+
+SDT_PROBE_DEFINE2(sdt, kernel, threadpool, create,
+ "struct cpu_info *"/*ci*/, "pri_t"/*pri*/);
+SDT_PROBE_DEFINE3(sdt, kernel, threadpool, create__success,
+ "struct cpu_info *"/*ci*/, "pri_t"/*pri*/, "struct threadpool *"/*pool*/);
+SDT_PROBE_DEFINE3(sdt, kernel, threadpool, create__failure,
+ "struct cpu_info *"/*ci*/, "pri_t"/*pri*/, "int"/*error*/);
+SDT_PROBE_DEFINE1(sdt, kernel, threadpool, destroy,
+ "struct threadpool *"/*pool*/);
+SDT_PROBE_DEFINE2(sdt, kernel, threadpool, destroy__wait,
+ "struct threadpool *"/*pool*/, "uint64_t"/*refcnt*/);
+
+SDT_PROBE_DEFINE2(sdt, kernel, threadpool, schedule__job,
+ "struct threadpool *"/*pool*/, "struct threadpool_job *"/*job*/);
+SDT_PROBE_DEFINE2(sdt, kernel, threadpool, schedule__job__running,
+ "struct threadpool *"/*pool*/, "struct threadpool_job *"/*job*/);
+SDT_PROBE_DEFINE2(sdt, kernel, threadpool, schedule__job__overseer,
+ "struct threadpool *"/*pool*/, "struct threadpool_job *"/*job*/);
+SDT_PROBE_DEFINE3(sdt, kernel, threadpool, schedule__job__thread,
+ "struct threadpool *"/*pool*/,
+ "struct threadpool_job *"/*job*/,
+ "struct lwp *"/*thread*/);
+
+SDT_PROBE_DEFINE1(sdt, kernel, threadpool, overseer__start,
+ "struct threadpool *"/*pool*/);
+SDT_PROBE_DEFINE1(sdt, kernel, threadpool, overseer__dying,
+ "struct threadpool *"/*pool*/);
+SDT_PROBE_DEFINE1(sdt, kernel, threadpool, overseer__spawn,
+ "struct threadpool *"/*pool*/);
+SDT_PROBE_DEFINE2(sdt, kernel, threadpool, overseer__race,
+ "struct threadpool *"/*pool*/,
+ "struct threadpool_job *"/*job*/);
+SDT_PROBE_DEFINE3(sdt, kernel, threadpool, overseer__assign,
+ "struct threadpool *"/*pool*/,
+ "struct threadpool_job *"/*job*/,
+ "struct lwp *"/*thread*/);
+SDT_PROBE_DEFINE1(sdt, kernel, threadpool, overseer__exit,
+ "struct threadpool *"/*pool*/);
+
+SDT_PROBE_DEFINE1(sdt, kernel, threadpool, thread__start,
+ "struct threadpool *"/*pool*/);
+SDT_PROBE_DEFINE1(sdt, kernel, threadpool, thread__dying,
+ "struct threadpool *"/*pool*/);
+SDT_PROBE_DEFINE2(sdt, kernel, threadpool, thread__job,
+ "struct threadpool *"/*pool*/, "struct threadpool_job *"/*job*/);
+SDT_PROBE_DEFINE1(sdt, kernel, threadpool, thread__exit,
+ "struct threadpool *"/*pool*/);
+
/* Data structures */
TAILQ_HEAD(job_head, threadpool_job);
@@ -224,12 +296,6 @@
LIST_REMOVE(tpp, tpp_link);
}
-#ifdef THREADPOOL_VERBOSE
-#define TP_LOG(x) printf x
-#else
-#define TP_LOG(x) /* nothing */
-#endif /* THREADPOOL_VERBOSE */
-
static int
sysctl_kern_threadpool_idle_ms(SYSCTLFN_ARGS)
{
@@ -308,6 +374,8 @@
KASSERT(threadpool_pri_is_valid(pri));
+ SDT_PROBE2(sdt, kernel, threadpool, create, ci, pri);
+
mutex_init(&pool->tp_lock, MUTEX_DEFAULT, IPL_VM);
/* XXX overseer */
TAILQ_INIT(&pool->tp_jobs);
@@ -337,6 +405,7 @@
cv_broadcast(&pool->tp_overseer.tpt_cv);
mutex_spin_exit(&pool->tp_lock);
+ SDT_PROBE3(sdt, kernel, threadpool, create__success, ci, pri, pool);
return 0;
fail0: KASSERT(error);
@@ -349,6 +418,7 @@
KASSERT(!cv_has_waiters(&pool->tp_overseer.tpt_cv));
cv_destroy(&pool->tp_overseer.tpt_cv);
mutex_destroy(&pool->tp_lock);
+ SDT_PROBE3(sdt, kernel, threadpool, create__failure, ci, pri, error);
return error;
}
@@ -359,6 +429,8 @@
{
struct threadpool_thread *thread;
+ SDT_PROBE1(sdt, kernel, threadpool, destroy, pool);
+
/* Mark the pool dying and wait for threads to commit suicide. */
mutex_spin_enter(&pool->tp_lock);
KASSERT(TAILQ_EMPTY(&pool->tp_jobs));
@@ -367,8 +439,8 @@
TAILQ_FOREACH(thread, &pool->tp_idle_threads, tpt_entry)
cv_broadcast(&thread->tpt_cv);
while (0 < pool->tp_refcnt) {
- TP_LOG(("%s: draining %" PRIu64 " references...\n", __func__,
- pool->tp_refcnt));
+ SDT_PROBE2(sdt, kernel, threadpool, destroy__wait,
+ pool, pool->tp_refcnt);
cv_wait(&pool->tp_overseer.tpt_cv, &pool->tp_lock);
}
mutex_spin_exit(&pool->tp_lock);
@@ -413,6 +485,8 @@
ASSERT_SLEEPABLE();
+ SDT_PROBE1(sdt, kernel, threadpool, get, pri);
+
if (! threadpool_pri_is_valid(pri))
return EINVAL;
@@ -420,8 +494,7 @@
tpu = threadpool_lookup_unbound(pri);
if (tpu == NULL) {
mutex_exit(&threadpools_lock);
- TP_LOG(("%s: No pool for pri=%d, creating one.\n",
- __func__, (int)pri));
+ SDT_PROBE1(sdt, kernel, threadpool, get__create, pri);
tmp = kmem_zalloc(sizeof(*tmp), KM_SLEEP);
error = threadpool_create(&tmp->tpu_pool, NULL, pri);
if (error) {
@@ -431,11 +504,11 @@
mutex_enter(&threadpools_lock);
tpu = threadpool_lookup_unbound(pri);
if (tpu == NULL) {
- TP_LOG(("%s: Won the creation race for pri=%d.\n",
- __func__, (int)pri));
tpu = tmp;
tmp = NULL;
threadpool_insert_unbound(tpu);
+ } else {
+ SDT_PROBE1(sdt, kernel, threadpool, get__race, pri);
}
}
KASSERT(tpu != NULL);
@@ -459,15 +532,15 @@
container_of(pool, struct threadpool_unbound, tpu_pool);
ASSERT_SLEEPABLE();
+ KASSERT(threadpool_pri_is_valid(pri));
- KASSERT(threadpool_pri_is_valid(pri));
+ SDT_PROBE2(sdt, kernel, threadpool, put, pool, pri);
mutex_enter(&threadpools_lock);
KASSERT(tpu == threadpool_lookup_unbound(pri));
KASSERT(0 < tpu->tpu_refcnt);
if (--tpu->tpu_refcnt == 0) {
- TP_LOG(("%s: Last reference for pri=%d, destroying pool.\n",
- __func__, (int)pri));
+ SDT_PROBE2(sdt, kernel, threadpool, put__destroy, pool, pri);
threadpool_remove_unbound(tpu);
} else {
tpu = NULL;
@@ -490,6 +563,8 @@
ASSERT_SLEEPABLE();
+ SDT_PROBE1(sdt, kernel, threadpool, percpu__get, pri);
+
if (! threadpool_pri_is_valid(pri))
return EINVAL;
@@ -497,8 +572,7 @@
pool_percpu = threadpool_lookup_percpu(pri);
if (pool_percpu == NULL) {
mutex_exit(&threadpools_lock);
- TP_LOG(("%s: No pool for pri=%d, creating one.\n",
- __func__, (int)pri));
+ SDT_PROBE1(sdt, kernel, threadpool, percpu__get__create, pri);
error = threadpool_percpu_create(&tmp, pri);
if (error)
return error;
@@ -506,11 +580,12 @@
mutex_enter(&threadpools_lock);
pool_percpu = threadpool_lookup_percpu(pri);
if (pool_percpu == NULL) {
- TP_LOG(("%s: Won the creation race for pri=%d.\n",
- __func__, (int)pri));
pool_percpu = tmp;
tmp = NULL;
threadpool_insert_percpu(pool_percpu);
+ } else {
+ SDT_PROBE1(sdt, kernel, threadpool, percpu__get__race,
+ pri);
}
}
KASSERT(pool_percpu != NULL);
@@ -533,12 +608,14 @@
KASSERT(threadpool_pri_is_valid(pri));
+ SDT_PROBE2(sdt, kernel, threadpool, percpu__put, pool_percpu, pri);
+
mutex_enter(&threadpools_lock);
KASSERT(pool_percpu == threadpool_lookup_percpu(pri));
KASSERT(0 < pool_percpu->tpp_refcnt);
if (--pool_percpu->tpp_refcnt == 0) {
- TP_LOG(("%s: Last reference for pri=%d, destroying pool.\n",
- __func__, (int)pri));
+ SDT_PROBE2(sdt, kernel, threadpool, percpu__put__destroy,
+ pool_percpu, pri);
threadpool_remove_percpu(pool_percpu);
} else {
pool_percpu = NULL;
@@ -768,6 +845,8 @@
KASSERT(mutex_owned(job->job_lock));
+ SDT_PROBE2(sdt, kernel, threadpool, schedule__job, pool, job);
+
/*
* If the job's already running, let it keep running. The job
* is guaranteed by the interlock not to end early -- if it had
@@ -775,8 +854,8 @@
* to NULL under the interlock.
*/
if (__predict_true(job->job_thread != NULL)) {
- TP_LOG(("%s: job '%s' already runnining.\n",
- __func__, job->job_name));
+ SDT_PROBE2(sdt, kernel, threadpool, schedule__job__running,
+ pool, job);
return;
}
@@ -786,15 +865,15 @@
mutex_spin_enter(&pool->tp_lock);
if (__predict_false(TAILQ_EMPTY(&pool->tp_idle_threads))) {
/* Nobody's idle. Give it to the overseer. */
- TP_LOG(("%s: giving job '%s' to overseer.\n",
- __func__, job->job_name));
+ SDT_PROBE2(sdt, kernel, threadpool, schedule__job__overseer,
+ pool, job);
job->job_thread = &pool->tp_overseer;
TAILQ_INSERT_TAIL(&pool->tp_jobs, job, job_entry);
} else {
/* Assign it to the first idle thread. */
job->job_thread = TAILQ_FIRST(&pool->tp_idle_threads);
- TP_LOG(("%s: giving job '%s' to idle thread %p.\n",
- __func__, job->job_name, job->job_thread));
+ SDT_PROBE3(sdt, kernel, threadpool, schedule__job__thread,
+ pool, job, job->job_thread->tpt_lwp);
Home |
Main Index |
Thread Index |
Old Index