From owner-freebsd-current@FreeBSD.ORG Thu Jun 9 06:45:59 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 D79BD16A41C; Thu, 9 Jun 2005 06:45:59 +0000 (GMT) (envelope-from glebius@FreeBSD.org) Received: from relay.bestcom.ru (relay.bestcom.ru [217.72.144.5]) by mx1.FreeBSD.org (Postfix) with ESMTP id 922A543D5C; Thu, 9 Jun 2005 06:45:58 +0000 (GMT) (envelope-from glebius@FreeBSD.org) Received: from cell.sick.ru (root@cell.sick.ru [217.72.144.68]) by relay.bestcom.ru (8.13.1/8.12.9) with ESMTP id j596jtKY024279 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=FAIL); Thu, 9 Jun 2005 10:45:56 +0400 (MSD) (envelope-from glebius@FreeBSD.org) Received: from cell.sick.ru (glebius@localhost [127.0.0.1]) by cell.sick.ru (8.13.1/8.12.8) with ESMTP id j596jsbF041275 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=NO); Thu, 9 Jun 2005 10:45:55 +0400 (MSD) (envelope-from glebius@FreeBSD.org) Received: (from glebius@localhost) by cell.sick.ru (8.13.1/8.13.1/Submit) id j596jsWH041274; Thu, 9 Jun 2005 10:45:54 +0400 (MSD) (envelope-from glebius@FreeBSD.org) X-Authentication-Warning: cell.sick.ru: glebius set sender to glebius@FreeBSD.org using -f Date: Thu, 9 Jun 2005 10:45:54 +0400 From: Gleb Smirnoff To: Robert Watson Message-ID: <20050609064554.GA41137@cell.sick.ru> References: <20050609010700.V95135@fledge.watson.org> Mime-Version: 1.0 Content-Type: text/plain; charset=koi8-r Content-Disposition: inline In-Reply-To: <20050609010700.V95135@fledge.watson.org> User-Agent: Mutt/1.5.6i X-Virus-Scanned: ClamAV version devel-20050125, clamav-milter version 0.80ff on relay.bestcom.ru X-Virus-Status: Clean Cc: 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 06:46:00 -0000 On Thu, Jun 09, 2005 at 01:11:33AM +0100, Robert Watson wrote: R> I'm running with task queue instrumentation on my notebook, and generate R> warnings when task queues take more than 1/10th of a second to execute. R> Normally the warnings fire only during the boot when tasks start being R> scheduled by ACPI, but the ACPI task queue thread isn't yet being R> scheduled to run because the scheduler hasn't been kicked off yet. I saw R> one this afternoon as follows: R> R> taskqueue_run: warning, queue time of 0.133978201 for context 0xc0687c90 ^^^^^^^^^^^ Is this seconds? A lot. R> On my kernel, this function pointer resolves to: R> R> c0687c90 t do_link_state_change R> R> So it sounds like there's a substantial delay in the link change thread -- R> probably because another task takes a long time to execute, maybe R> blocking or delaying the task thread and preventing another task from R> running. On this box, I'm running with an idle if_xl, and an in-use R> if_wi, which probably went into the associated state about when the R> message was printed. Kernel source date is June 3. Do you have vlans, ng_ether loaded, carp in kernel config, if_bridge? Other idea may be that your syslogd was not running, and you have serial console configured. In this case log(9) prints message to your serial console, and then 0.13 seconds is sane time for this. May be we should move log() from do_link_state_change() to if_link_state_change()? -- Totus tuus, Glebius. GLEBIUS-RIPN GLEB-RIPE