NetBSD Problem Report #43884

From www@NetBSD.org  Thu Sep 16 09:47:35 2010
Return-Path: <www@NetBSD.org>
Received: from mail.netbsd.org (mail.netbsd.org [204.152.190.11])
	by www.NetBSD.org (Postfix) with ESMTP id A9FE663B96E
	for <gnats-bugs@gnats.NetBSD.org>; Thu, 16 Sep 2010 09:47:35 +0000 (UTC)
Message-Id: <20100916094735.758E463B966@www.NetBSD.org>
Date: Thu, 16 Sep 2010 09:47:35 +0000 (UTC)
From: Christoph_Egger@gmx.de
Reply-To: Christoph_Egger@gmx.de
To: gnats-bugs@NetBSD.org
Subject: subr_log.c: Mutex error: lockdebug_wantlock: locking against myself
X-Send-Pr-Version: www-1.0

>Number:         43884
>Category:       kern
>Synopsis:       subr_log.c: Mutex error: lockdebug_wantlock: locking against myself
>Confidential:   no
>Severity:       serious
>Priority:       medium
>Responsible:    kern-bug-people
>State:          open
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Thu Sep 16 09:50:00 +0000 2010
>Last-Modified:  Sun Oct 10 02:35:01 +0000 2010
>Originator:     Christoph Egger
>Release:        NeBSD-current
>Organization:
>Environment:
>Description:

I got this LOCKDEBUG panic:

Mutex error: lockdebug_wantlock: locking against myself

lock address : 0xffffffff80cb2a90 type     :               spin
initialized  : 0xffffffff805bd764
shared holds :                  0 exclusive:                  1
shares wanted:                  0 exclusive:                  1
current cpu  :                  0 last held:                  0
current lwp  : 0xffffa0002591f640 last held: 0xffffa0002591f640
last locked  : 0xffffffff805bd5e2 unlocked : 0xffffffff805bd35a
owner field  : 0x0000000000010600 wait/spin:                0/1

panic: LOCKDEBUG

'last locked' points to function sys/kern/subr_log.c:logread

mutex_spin_enter(&log_lock);

'unlocked' points to function sys/kern/subr_log.c:filt_logread

mutex_spin_exit(&log_lock);

The backtrace:

breakpoint() at netbsd:breakpoint+0x5
panic() at netbsd:panic+0x28f
lockdebug_more() at netbsd:lockdebug_more
mutex_enter() at netbsd:mutex_enter+0x263
logputchar() at netbsd:logputchar+0x68
putchar() at netbsd:putchar+0x95
kprintf() at netbsd:kprintf+0x1d2
printf() at netbsd:printf+0xb7


The 'logputchar+0x68' points to sys/kern/subr_log.c:logputchar

  mutex_spin_enter(&log_lock);


>How-To-Repeat:

>Fix:

>Audit-Trail:
From: David Holland <dholland-bugs@netbsd.org>
To: gnats-bugs@NetBSD.org
Cc: 
Subject: Re: kern/43884: subr_log.c: Mutex error: lockdebug_wantlock:
 locking against myself
Date: Mon, 27 Sep 2010 02:21:10 +0000

 On Thu, Sep 16, 2010 at 09:50:00AM +0000, Christoph_Egger@gmx.de wrote:
  > breakpoint() at netbsd:breakpoint+0x5
  > panic() at netbsd:panic+0x28f
  > lockdebug_more() at netbsd:lockdebug_more
  > mutex_enter() at netbsd:mutex_enter+0x263
  > logputchar() at netbsd:logputchar+0x68
  > putchar() at netbsd:putchar+0x95
  > kprintf() at netbsd:kprintf+0x1d2
  > printf() at netbsd:printf+0xb7

 Where did the printf come from?

 -- 
 David A. Holland
 dholland@netbsd.org

From: "Christoph Egger" <Christoph_Egger@gmx.de>
To: gnats-bugs@NetBSD.org, netbsd-bugs@netbsd.org, gnats-admin@netbsd.org,
 kern-bug-people@netbsd.org
Cc: 
Subject: Re: kern/43884: subr_log.c: Mutex error: lockdebug_wantlock: locking
 against myself
Date: Tue, 28 Sep 2010 11:56:50 +0200

 > The following reply was made to PR kern/43884; it has been noted by GNATS.
 > 
 > From: David Holland <dholland-bugs@netbsd.org>
 > To: gnats-bugs@NetBSD.org
 > Cc: 
 > Subject: Re: kern/43884: subr_log.c: Mutex error: lockdebug_wantlock:
 >  locking against myself
 > Date: Mon, 27 Sep 2010 02:21:10 +0000
 > 
 >  On Thu, Sep 16, 2010 at 09:50:00AM +0000, Christoph_Egger@gmx.de wrote:
 >   > breakpoint() at netbsd:breakpoint+0x5
 >   > panic() at netbsd:panic+0x28f
 >   > lockdebug_more() at netbsd:lockdebug_more
 >   > mutex_enter() at netbsd:mutex_enter+0x263
 >   > logputchar() at netbsd:logputchar+0x68
 >   > putchar() at netbsd:putchar+0x95
 >   > kprintf() at netbsd:kprintf+0x1d2
 >   > printf() at netbsd:printf+0xb7
 >  
 >  Where did the printf come from?

 From sys/arch/xen/xen/evtchn.c:evtchn_do_event()
 line 276

 Christoph

From: David Holland <dholland-bugs@netbsd.org>
To: gnats-bugs@NetBSD.org
Cc: 
Subject: Re: kern/43884: subr_log.c: Mutex error: lockdebug_wantlock:
 locking against myself
Date: Sun, 10 Oct 2010 02:31:44 +0000

 On Tue, Sep 28, 2010 at 10:00:08AM +0000, Christoph Egger wrote:
  >  >   > breakpoint() at netbsd:breakpoint+0x5
  >  >   > panic() at netbsd:panic+0x28f
  >  >   > lockdebug_more() at netbsd:lockdebug_more
  >  >   > mutex_enter() at netbsd:mutex_enter+0x263
  >  >   > logputchar() at netbsd:logputchar+0x68
  >  >   > putchar() at netbsd:putchar+0x95
  >  >   > kprintf() at netbsd:kprintf+0x1d2
  >  >   > printf() at netbsd:printf+0xb7
  >  >  
  >  >  Where did the printf come from?
  >  
  >  From sys/arch/xen/xen/evtchn.c:evtchn_do_event()
  >  line 276

 Yes, and before that? The question is why it's printing while already
 holding the message buffer lock, and the answer appears to be that
 it's printing in an interrupt handler above IPL_VM. That or interrupt
 masking isn't working right, but if that were the case you'd be
 getting a lot more fireworks.

 -- 
 David A. Holland
 dholland@netbsd.org

NetBSD Home
NetBSD PR Database Search

(Contact us) $NetBSD: query-full-pr,v 1.39 2013/11/01 18:47:49 spz Exp $
$NetBSD: gnats_config.sh,v 1.8 2006/05/07 09:23:38 tsutsui Exp $
Copyright © 1994-2007 The NetBSD Foundation, Inc. ALL RIGHTS RESERVED.