From owner-freebsd-current@FreeBSD.ORG Thu Jun 9 00:31:49 2005 Return-Path: X-Original-To: current@freebsd.org Delivered-To: freebsd-current@FreeBSD.ORG Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 0E1DB16A41C; Thu, 9 Jun 2005 00:31:49 +0000 (GMT) (envelope-from rwatson@FreeBSD.org) Received: from cyrus.watson.org (cyrus.watson.org [204.156.12.53]) by mx1.FreeBSD.org (Postfix) with ESMTP id C536243D48; Thu, 9 Jun 2005 00:31:48 +0000 (GMT) (envelope-from rwatson@FreeBSD.org) Received: from fledge.watson.org (fledge.watson.org [204.156.12.50]) by cyrus.watson.org (Postfix) with ESMTP id 4F0BC46B37; Wed, 8 Jun 2005 20:31:48 -0400 (EDT) Date: Thu, 9 Jun 2005 01:32:53 +0100 (BST) From: Robert Watson X-X-Sender: robert@fledge.watson.org To: Sam Leffler In-Reply-To: <42A78C03.3090003@errno.com> Message-ID: <20050609013134.X95135@fledge.watson.org> References: <20050609010700.V95135@fledge.watson.org> <42A78C03.3090003@errno.com> MIME-Version: 1.0 Content-Type: TEXT/PLAIN; charset=US-ASCII; format=flowed Cc: glebius@freebsd.org, current@freebsd.org Subject: Re: link state changes take a "long" time to execute X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Discussions about the use of FreeBSD-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 09 Jun 2005 00:31:49 -0000 On Wed, 8 Jun 2005, Sam Leffler wrote: > I don't think I ever committed the diagnostic code that checks for > long-running tasks so this must be something in your private tree. Yes, I'm running with the attached patch which is more about measuring deadlines on tasks than run times on tasks. I used to have similar diagnostics for run times but appear not to have it anymore. Robert N M Watson Index: sys/_task.h =================================================================== RCS file: /home/ncvs/src/sys/sys/_task.h,v retrieving revision 1.4 diff -u -r1.4 _task.h --- sys/_task.h 24 Apr 2005 16:52:45 -0000 1.4 +++ sys/_task.h 1 Jun 2005 10:33:19 -0000 @@ -45,6 +45,7 @@ u_short ta_priority; /* Priority */ task_fn_t *ta_func; /* task handler */ void *ta_context; /* argument for handler */ + struct timespec ta_queuetime; /* time enqueued */ }; #endif /* !_SYS__TASK_H_ */ Index: kern/subr_taskqueue.c =================================================================== RCS file: /home/ncvs/src/sys/kern/subr_taskqueue.c,v retrieving revision 1.27 diff -u -r1.27 subr_taskqueue.c --- kern/subr_taskqueue.c 1 May 2005 00:38:11 -0000 1.27 +++ kern/subr_taskqueue.c 1 Jun 2005 10:40:08 -0000 @@ -36,10 +36,17 @@ #include #include #include +#include #include #include +#include #include +int tq_in; +SYSCTL_INT(_kern, OID_AUTO, tq_in, CTLFLAG_RD, &tq_in, 0, ""); +int tq_out; +SYSCTL_INT(_kern, OID_AUTO, tq_out, CTLFLAG_RD, &tq_out, 0, ""); + static MALLOC_DEFINE(M_TASKQUEUE, "taskqueue", "Task Queues"); static void *taskqueue_giant_ih; static void *taskqueue_ih; @@ -166,6 +173,9 @@ return 0; } + getnanotime(&task->ta_queuetime); + tq_in++; + /* * Optimise the case when all tasks have the same priority. */ @@ -197,6 +207,7 @@ taskqueue_run(struct taskqueue *queue) { struct task *task; + struct timespec tv; int owned, pending; owned = mtx_owned(&queue->tq_mutex); @@ -211,9 +222,17 @@ STAILQ_REMOVE_HEAD(&queue->tq_queue, ta_link); pending = task->ta_pending; task->ta_pending = 0; + tq_out++; queue->tq_running = task; mtx_unlock(&queue->tq_mutex); + getnanotime(&tv); + timespecsub(&tv, &task->ta_queuetime); + if (tv.tv_nsec >= 50000000) { + printf("taskqueue_run: warning, queue time of %d.%09ld " + "for context %p\n", tv.tv_sec, tv.tv_nsec, + task->ta_func); + } task->ta_func(task->ta_context, pending); mtx_lock(&queue->tq_mutex);