node 2 hang in nsc_async queue handling mouse interrupt (was RE : [SSI-users] succesful "startx" on 2nd node (RH9))

[John H. <jo...@Ca...>]

Here's my latest trace:

start_kernel
Linux version 2.4.20-20.9_ssi_9ssi (root@a.baltic.CalvaEDI.COM) (gcc
version 3.2
.2 20030222 (Red Hat Linux 3.2.2-5)) #1 SMP Tue Nov 4 11:00:45 CET 2003

A kernel built from source I got from cvs today.

NMI: IOCK error (debug interrupt?)
iptable_filter ip_tables ide-cd sr_mod cdrom ext3 jbd e100 8390 mii
sd_mod scsi_
mod
CPU:    0
EIP:    0060:[<c0239e28>]    Not tainted
EFLAGS: 00200086

EIP is at .text.lock.nsc_async [kernel] 0x0 (2.4.20-20.9_ssi_9ssi)
eax: c17eb620   ebx: 00000000   ecx: 00000002   edx: cb830000
esi: cb831da4   edi: cb831de0   ebp: cb831d88   esp: cb831d74
ds: 0068   es: 0068   ss: 0068
Process nsc_async (pid: 196656, stackpage=3Dcb831000)
Stack: c17eb628 00000000 00000000 c17eb620 cb831de0 cb831e00 c01bd793
c17eb620
       c01bd6c0 cb831da4 00000048 00000002 000304b0 00000000 00000001
00020001
       00000007 00000000 00000000 0000001d 00000001 00200282 00000002
00000001
Call Trace:
[<c01bd793>] dpvproc_sigproc_async_queue [kernel] 0x63 (0xcb831d8c)
[<c01bd6c0>] dpvproc_sigproc_async_handler [kernel] 0x0 (0xcb831d94)
[<c01c762a>] vpsop_sigproc_pid [kernel] 0x1a (0xcb831e04)
[<c0165d59>] send_sigio [kernel] 0x49 (0xcb831e20)
[<c0131a8c>] send_sig_info [kernel] 0x3c (0xcb831e70)
[<c0165ea1>] __kill_fasync [kernel] 0x31 (0xcb831e84)
[<c0165ef5>] kill_fasync [kernel] 0x25 (0xcb831ea4)
[<c0264ecd>] handle_mouse_event [kernel] 0x6d (0xcb831eb8)
[<c0264364>] handle_kbd_event [kernel] 0x34 (0xcb831ed0)
[<c026440e>] keyboard_interrupt [kernel] 0x1e (0xcb831ee8)
[<c010cbe3>] handle_IRQ_event [kernel] 0x63 (0xcb831ef0)
[<c010ce00>] do_IRQ [kernel] 0xb0 (0xcb831f10)
[<c0110d48>] call_do_IRQ [kernel] 0x5 (0xcb831f38)
[<c0120068>] wake_up_forked_process [kernel] 0x8 (0xcb831f5c)
[<c0122b13>] add_wait_queue_exclusive [kernel] 0x33 (0xcb831f64)
[<c0239cc5>] ssi_wait_softirq_condition [kernel] 0x65 (0xcb831f80)
[<c02395c0>] nsc_async_daemon [kernel] 0x60 (0xcb831fbc)
[<c0239560>] nsc_async_daemon [kernel] 0x0 (0xcb831fe0)
[<c010782d>] kernel_thread_helper [kernel] 0x5 (0xcb831ff0)

Code: 80 78 08 00 f3 90 7e f8 e9 70 f2 ff ff 50 51 52 e8 43 16 ef

Entering kdb (current=3D0xcb830000, pid 196656) on processor 0 due to
NonMaskable
Interrupt @ 0xc0239e28
eax =3D 0xc17eb620 ebx =3D 0x00000000 ecx =3D 0x00000002 edx =3D =
0xcb830000
esi =3D 0xcb831da4 edi =3D 0xcb831de0 esp =3D 0xcb831d74 eip =3D =
0xc0239e28
ebp =3D 0xcb831d88 xss =3D 0x00000068 xcs =3D 0x00000060 eflags =3D =
0x00200086
xds =3D 0xcb750068 xes =3D 0xcb830068 origeax =3D 0xc17eb620 &regs =3D
0xcb831d40

The backtrace:

[0]kdb> bt
Stack traceback for pid 196656
0xcb830000   196656        2  1    0   S  0xcb830420 *nsc_async
EBP        EIP        Function (args)
           0xc0239e28 .text.lock.nsc_async
                               kernel .text 0xc0100000 0xc0239e28
0xc0239fc0
0xcb831d88 0xc02390a5 nsc_async_queue+0x45 (0xc17eb620, 0xc01bd6c0,
0xcb831da4,
0x48, 0x2)
                               kernel .text 0xc0100000 0xc0239060
0xc02392f0
0xcb831e00 0xc01bd793 dpvproc_sigproc_async_queue+0x63 (0x304b0, 0x0,
0xcb831e34
, 0x400, 0x0)
                               kernel .text 0xc0100000 0xc01bd730
0xc01bd7c0
0xcb831e1c 0xc01c762a vpsop_sigproc_pid+0x1a (0x304b0, 0x0, 0xcb831e34,
0x400, 0
x1)
                               kernel .text 0xc0100000 0xc01c7610
0xc01c7630
0xcb831e80 0xc0165d59 send_sigio+0x49 (0xca8b799c, 0x7, 0x20001, 0x0,
0x0)
                               kernel .text 0xc0100000 0xc0165d10
0xc0165d80
0xcb831ea0 0xc0165ea1 __kill_fasync+0x31 (0xc9c2bb10, 0x1d, 0x20001)
                               kernel .text 0xc0100000 0xc0165e70
0xc0165ed0
0xcb831eb4 0xc0165ef5 kill_fasync+0x25 (0xc1818014, 0x1d, 0x20001, 0x20)
                               kernel .text 0xc0100000 0xc0165ed0
0xc0165f00
0xcb831ecc 0xc0264ecd handle_mouse_event+0x6d (0x0, 0xc9b50f40,
0x4000001, 0x0)
                               kernel .text 0xc0100000 0xc0264e60
0xc0264f3e
0xcb831ee4 0xc0264364 handle_kbd_event+0x34
                               kernel .text 0xc0100000 0xc0264330
0xc02643f0
0xcb831eec 0xc026440e keyboard_interrupt+0x1e (0xc, 0xc1818000,
0xcb831f3c, 0xc0
53e980, 0xc)
[0]more>
                               kernel .text 0xc0100000 0xc02643f0
0xc0264420
0xcb831f0c 0xc010cbe3 handle_IRQ_event+0x63 (0xc, 0xcb831f3c,
0xc9b50f40, 0x180,
 0x0)
                               kernel .text 0xc0100000 0xc010cb80
0xc010cc20
0xcb831f34 0xc010ce00 do_IRQ+0xb0 (0xcb831fa4, 0xc17eb634, 0xcb831f00,
0xcb7bffa
4, 0x200202)
                               kernel .text 0xc0100000 0xc010cd50
0xc010ce80
0xcb831f7c 0xc0110d48 call_do_IRQ+0x5
                               kernel .text 0xc0100000 0xc0110d43
0xc0110d50
           0xc010782d kernel_thread_helper+0x5
                               kernel .text 0xc0100000 0xc0107828
0xc0107840

Looking at the "async queue structure":

[0]kdb> md 0xc17eb620
0xc17eb620 00000000 00000000 000000ff cb830000   ........=FF......=CB
0xc17eb630 00000001 cb7cffa4 cb831fa4 ffffffff   =
....=A4=FF|=CB=A4..=CB=FF=FF=FF=FF
0xc17eb640 00000000 00000000 00000001 00000001   ................
0xc17eb650 00000000 00000000 00000000 00000000   ................
0xc17eb660 00000000 c1742d60 d500a8c0 d500a8c0   =
....`-t=C1=C0=A8.=D5=C0=A8.=D5
0xc17eb670 00ffffff ff00a8c0 00000000 65180000   =
=FF=FF=FF.=C0=A8.=FF.......e
0xc17eb680 00306874 00000000 00000000 00000000   th0.............
0xc17eb690 00000000 00000000 00000000 00000000   ................

So it's task cb830000 that holds the lock, but that's the current task.

Looks like this lock is being taken with interrupts enabled somewhere,
no?