Subject: Re: port-i386/37637: MP kernel hangs before starting init
To: None <port-i386-maintainer@netbsd.org, gnats-admin@netbsd.org,>
From: Bernd Ernesti <pr200709@veego.de>
List: netbsd-bugs
Date: 12/30/2007 10:55:02
The following reply was made to PR port-i386/37637; it has been noted by GNATS.

From: Bernd Ernesti <pr200709@veego.de>
To: gnats-bugs@NetBSD.org
Cc: 
Subject: Re: port-i386/37637: MP kernel hangs before starting init
Date: Sun, 30 Dec 2007 11:51:07 +0100

 Adding two prinfts around
         for (pdev = pdevinit; pdev->pdev_attach != NULL; pdev++)
                 (*pdev->pdev_attach)(pdev->pdev_count);
 shows that it really stops here.
 
 This time while it was in the middle of the crypto one:
 
 Before pseudo-devices attachments
 crypto: assign driver 0, flags 2
 crypto: driver 0 registers alg 1 flags 0 maxoplen 0
 crypto: driver 0 registers alg 2 flags 0 maxoplen 0
 crypto: driver 0 registers alg 3 flags 0 maxoplen 0
 crypto: driver 0 registers alg 4 flags 0 maxoplen 0
 crypto: driver 0 registers alg 5 flags 0 maxoplen 0
 crypto: driver 0 registers alg 17 flags 0 maxoplen 0
 crypto: driver 0 registers alg 6 flags 0 maxoplen 0
 crypto: driver 0 registers alg 7 flags 0 maxoplen 0
 crypto: driver 0 registers alg 15 flags 0 maxoplen 0
 crypto: driver
 
 I assume it is ok to use 'DELAY(250000)' to issue some sleep befor the
 printf here in this function to make sure it is really there.
 
 I got a panic when I used DELAY(1000000):
 
 Kernel lock error: _kernel_lock: spinout
 
 lock address : 0x00000000c08aaa80 type     :               spin
 shared holds :                  0 exclusive:                  1
 shares wanted:                  0 exclusive:                  1
 current cpu  :                  1 last held:                  0
 current lwp  : 0x00000000cc36b020 last held: 0x00000000c08382e0
 last locked  : 0x00000000c03d80ca unlocked : 0x00000000c04091f7
 initialized  : 0x00000000c03d7f69
 curcpu holds :                  0 wanted by: 0x00000000cc36b020
 
 panic: LOCKDEBUG
 Stopped in pid 0.17 (system) at netbsd:breakpoint+0x1:  ret
 db{1}> bt
 breakpoint(c07c8a5f,c07c45e8,c06b5677,c07c4587,c08b7be0) at netbsd:breakpoint+0x1
 lockdebug_abort1(c07c4587,1,ffdb820,5,0) at netbsd:lockdebug_abort1+0x6b
 lockdebug_abort(c08aaa80,c0837b84,c06b5677,c07c4587,cc36b0dc) at netbsd:lockdebug_abort+0x74
 _kernel_lock(1,cc36b020,0,3e8,c079812f) at netbsd:_kernel_lock+0x244
 sleepq_block(3e8,0,c079812f,3e8,0) at netbsd:sleepq_block+0xd1
 iic_smbus_intr_thread(c31d6388,0,c01002bd,0,c01002bd) at netbsd:iic_smbus_intr_thread+0x92
 
 Maybe that was too long.
 
 The above was from while doing a verbose boot with boot -v.
 Could it be that the verbose output on a serial console with 9600bps of the boot
 messages cause a too long delay?
 
 
 Booting without -v seems to work, but fails when I try to reboot via
 shutdown -r now:
 
 Kernel lock error: _kernel_lock: spinout
 
 lock address : 0x00000000c08aaa80 type     :               spin
 shared holds :                  0 exclusive:                  1
 shares wanted:                  0 exclusive:                  2
 current cpu  :                  0 last held:                  1
 current lwp  : 0x00000000cc365780 last held: 0x00000000d01e4780
 last locked  : 0x00000000c04050a1 unlocked : 0x00000000c04c61df
 initialized  : 0x00000000c03d7f69
 curcpu holds :                  0 wanted by: 0x00000000cc365780
 
 panic: LOCKDEBUG
 Stopped in pid 0.5 (system) at  netbsd:breakpoint+0x1:  ret
 db{0}> bt
 breakpoint(c07c899b,c07c4524,c06b5617,c07c44c3,c08b7be0) at netbsd:breakpoint+0x1
 lockdebug_abort1(c07c44c3,1,cea1cfcc,ffc7702,5) at netbsd:lockdebug_abort1+0x6b
 lockdebug_abort(c08aaa80,c0837b84,c06b5617,c07c44c3,c088d6a8) at netbsd:lockdebug_abort+0x74
 _kernel_lock(1,0,cea1cfec,c0410587,2e4) at netbsd:_kernel_lock+0x244
 intr_biglock_wrapper(c319c640,cea05bb4,0,0,0) at netbsd:intr_biglock_wrapper+0x1c
 DDB lost frame for netbsd:Xintr_legacy7+0xbb, trying 0xcea1cff4
 Xintr_legacy7() at netbsd:Xintr_legacy7+0xbb
 --- interrupt ---
 --- switch to interrupt stack ---
 _kernel_lock(1,cc365780,cea05c70,c03f734d,c083cd20) at netbsd:_kernel_lock+0x20c
 callout_softclock(0,10,30,10,cc360010) at netbsd:callout_softclock+0x259
 softint_dispatch(cc365d20,1,0,0,0) at netbsd:softint_dispatch+0xb7
 DDB lost frame for netbsd:Xsoftintr+0x3d, trying 0xcea05cb8
 Xsoftintr() at netbsd:Xsoftintr+0x3d
 --- interrupt ---
 
 Kernel lock error: _kernel_lock: spinout
 
 lock address : 0x00000000c08aaa80 type     :               spin
 shared holds :                  0 exclusive:                  1
 shares wanted:                  0 exclusive:                  2
 current cpu  :                  0 last held:                  1
 current lwp  : 0x00000000cc365780 last held: 0x00000000d01e4780
 last locked  : 0x00000000c04050a1 unlocked : 0x00000000c04c61df
 initialized  : 0x00000000c03d7f69
 curcpu holds :                  0 wanted by: 0x00000000cc365780
 
 panic: LOCKDEBUG
 Stopped in pid 0.5 (system) at  netbsd:breakpoint+0x1:  ret
 db{0}> mach cpu 1
 using CPU 1
 db{0}> bt
 lapic_gettick(1e8480,0,d024eb3c,c0407d8a,0) at netbsd:lapic_gettick+0x6
 pmf_system_shutdown(7,0,0,0,0) at netbsd:pmf_system_shutdown+0x107
 cpu_reboot(0,0,0,0,0) at netbsd:cpu_reboot+0x1c
 sys_reboot(d01e4780,d024ec30,d024ec58,bbb5f038,bbb5f000) at netbsd:sys_reboot+0x68
 syscall(d024ec78,b3,ab,1f,1f) at netbsd:syscall+0x154
 
 Wow, getting another lockdebug panic while issuing a bt is not nice.
 
 Bernd