From owner-freebsd-current@FreeBSD.ORG Fri Jun 24 20:20:33 2011 Return-Path: Delivered-To: current@FreeBSD.org Received: from mx1.freebsd.org (unknown [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id A6FC01065670; Fri, 24 Jun 2011 20:20:33 +0000 (UTC) (envelope-from gibbs@FreeBSD.org) Received: from aslan.scsiguy.com (www.scsiguy.com [70.89.174.89]) by mx1.freebsd.org (Postfix) with ESMTP id 72F0D8FC15; Fri, 24 Jun 2011 20:20:33 +0000 (UTC) Received: from Justins-MacBook-Pro.local (c-71-235-8-131.hsd1.nh.comcast.net [71.235.8.131]) (authenticated bits=0) by aslan.scsiguy.com (8.14.4/8.14.4) with ESMTP id p5OKLr7H087541 (version=TLSv1/SSLv3 cipher=DHE-RSA-CAMELLIA256-SHA bits=256 verify=NO); Fri, 24 Jun 2011 14:21:54 -0600 (MDT) (envelope-from gibbs@FreeBSD.org) Message-ID: <4E04F188.9030105@FreeBSD.org> Date: Fri, 24 Jun 2011 16:20:24 -0400 From: "Justin T. Gibbs" Organization: The FreeBSD Project User-Agent: Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10.6; en-US; rv:1.9.2.18) Gecko/20110616 Thunderbird/3.1.11 MIME-Version: 1.0 To: Scott Long References: <20110619232307.GA57530@vniz.net> <20110620001912.GA60252@vniz.net> <4DFEAD4F.1040603@FreeBSD.org> <20110620070222.GA74009@vniz.net> <20110620080146.GF48734@deviant.kiev.zoral.com.ua> <20110620114656.GA83524@vniz.net> <20110621161719.GA16166@nargothrond.kdm.org> <20110621204934.GB9877@vniz.net> <20110622035404.GA38834@nargothrond.kdm.org> <20110622041325.GA13754@vniz.net> <20110622200919.GA72504@nargothrond.kdm.org> <4E03FDFD.70203@FreeBSD.org> <55FDA4B1-CA5E-4304-9239-3AAF0FC6FF5F@samsco.org> In-Reply-To: X-Greylist: Sender succeeded SMTP AUTH, not delayed by milter-greylist-4.2.6 (aslan.scsiguy.com [70.89.174.89]); Fri, 24 Jun 2011 14:21:55 -0600 (MDT) Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit X-Content-Filtered-By: Mailman/MimeDel 2.1.5 Cc: Kostik Belousov , Eir Nym , "Kenneth D. Merry" , current@FreeBSD.org, will@FreeBSD.org Subject: Re: Exactly that commit (was Re: Latest -current 100% hang at the late boot stage) X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list Reply-To: gibbs@FreeBSD.org List-Id: Discussions about the use of FreeBSD-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Fri, 24 Jun 2011 20:20:33 -0000 On 6/24/11 3:35 PM, Scott Long wrote: > > On Jun 23, 2011, at 11:18 PM, Scott Long wrote: > > > > > On Jun 23, 2011, at 9:01 PM, Justin T. Gibbs wrote: > > > >> On 6/22/11 4:09 PM, Kenneth D. Merry wrote: > >>> On Wed, Jun 22, 2011 at 08:13:25 +0400, Andrey Chernov wrote: > >>>> On Tue, Jun 21, 2011 at 09:54:04PM -0600, Kenneth D. Merry wrote: > >>>>> These two are interesting: > >>>>> > >>>>>> http://img825.imageshack.us/img825/1249/21062011014m.jpg > >>>>>> http://img839.imageshack.us/img839/3791/21062011015.jpg > >>>>> > >>>>> It looks like the GEOM event thread is stuck inside the cd(4) > >> driver. The > >>>>> cd(4) driver is trying to acquire the peripheral lock, and is sleeping > >>>>> until it gets it. > >>>>> > >>>>> What isn't clear is who is holding it. > >> > >> ... > >> > >>> The GEOM event thread is stuck sleeping in the mtx_sleep() call above. So > >>> that tells me that one of several things is going on: > >>> > >>> - There is a path in the cd(4) driver where it can call cam_periph_hold() > >>> but not cam_periph_unhold(). > >>> > >>> - There is another thread in the system that has called cam_periph_hold(), > >>> and has gotten stuck before it can call cam_periph_unhold(). > >>> > >>> - The hold/unhold logic is broken, and there is a case where a thread > >>> waiting for the lock can miss the wakeup. After looking at the code, I > >>> don't think this is the case, but I may have missed something. > >>> > >>> So it is probably one of the first two cases. > >> > >> ... > >> > >> I have a theory for the cause of this hang. > >> > >> The commit that triggers this problem added calls to g_access() during the > >> geom_dev probe. I believe this hit a race in cdregister() where > >> the periph hold lock is dropped around the changer probe code. Why the > >> periph hold lock is dropped there, I do not know as I haven't fully > >> reviewed the changer probe code. > >> > > > > Are you talking about this? > > > > disk_create(softc->disk, DISK_VERSION); > > cam_periph_lock(periph); > > cam_periph_unhold(periph); > > [...] > > if (((cgd->ccb_h.target_lun > 0) > > && ((softc->quirks & CD_Q_NO_CHANGER) == 0)) > > || ((softc->quirks & CD_Q_CHANGER) != 0)) { > > > > The unhold there compliments the hold that was done prior to disk_create(). > > The hold/unhold is done as a hack around the need to drop the periph/sim > > mutex while calling disk_create(), due to the later's insistence on using > > blocking calls. I've wanted to re-think how that pattern is done (it's > > the same gross hack in nearly all of the periph drivers), but haven't > > gotten around to it. If the 'hold' semaphore needs to be held longer to > > prevent the race that you're theorizing, then it should be possible to > > simply extend its coverage in the code block, but I'm not sure if it'll > > result in an unintended deadlock with the changer enumeration/matching > > code. I _think_ that it'll be ok, but the density of magic in the code > > is a bit overwhelming at this time of night =-) The cd driver is the only one that temporarily drops the periph hold semaphore before scheduling and completing the probe processing. I think the above race could happen but that there is something else causing the current hang ache is experiencing. > Actually, what's probably happening is that the sim/periph lock is being > dropped but the hold semaphore is held, disk_create() is called, which > kicks off GEOM to do GEOM-ish things including the new g_access() call. > It tries to call cdopen(), which grabs the periph/sim mutex in order to > then get the hold semaphore, and winds up sleeping because the semaphore > is already held in cdregister(). If/when disk_create() returns, > cdregister() winds up waiting for the periph lock because it's held by > cdopen(), and now you have a deadlock between the two. The sim mutex is dropped while waiting for the periph hold semaphore, so I don't understand the deadlock you are describing. If there is still a "traditional deadlock" here, I'd expect to find a thread somewhere blocking on a mutex required to release the periph lock semaphore. Ache hasn't reported a substantive change to the ddb output, just that instead of g_eli blocked in open, it is now g_dev. Instead, I believe that either one of the GEOM taste methods is leaking an access reference (so cdclose() is not called), or the CD driver is failing to release the hold semaphore during probing. Setting kern.geom.debugflags to '4' will trace the access calls and allow the GEOM side to be ruled out. If GEOM is exonerated, we can add tracing to cam_perihp_(un)hold to track this down further. -- Justin