2.4.0-test6 kaboom: USB storage: Scheduling in interrupt.

From: Frank van Maarseveen (F.vanMaarseveen@inter.NL.net)
Date: Sat Aug 12 2000 - 11:29:26 EST


linux/drivers/usb/storage/usb.c has been updated by a little patch
(see below) to make it recognize a Casio QV-3000 digital camera, which,
according to supplied Windows 2000 info should behave as a USB storage
device. However, after recognizing the storage device the system
invariably drops dead after 10..20 seconds without having to touch
the keyboard. It is always the swapper process and the kernel message
starts with:

        Scheduling in interrupt

followed by either

        kernel BUG at sched.c:683

or

        NMI watchdog detected LOCKUP on CPU 0

I've written down the stack trace and entered it back in an editor after
rebooting the system (I knew this was going to happen so that's why I
bought that camera ya know ;-)

ksymoops 2.3.3 on i686 2.4.0-test6-x16. Options used
     -V (default)
     -k /proc/ksyms (default)
     -l /proc/modules (default)
     -o /lib/modules/2.4.0-test6-x16/ (default)
     -m /boot/System.map-2.4.0-test6-x16 (specified)

NMI watchdog detected LOCKUP on CPU 0
CPU: 0
EIP: 0010 [<c021996d>]
Using defaults from ksymoops -t elf32-i386 -a i386
EFLAGS: 00000086
Process swapper (pid: 0, stackpage=c028d000)
Call Trace: [<c010bf56>] [<c010c149>] [<c010a858>] [<c011a297>] [<c0116efa>] [<c02249fe>] [<c0109264>]
        [<c01ab320>] [<c01093f0>] [<c021a0b3>] [<c01ab353>] [<c012120f>] [<c011dfd2>] [<c011deb5>] [<c011dd5a>]
        [<c010c18a>] [<c0108a10>] [<c0108a10>] [<c010a858>] [<c0108a10>] [<c0108a10>] [<c0100018>] [<c0108a3d>]
        [<c0108aa2>] [<c0105000>] [<c01001d1>]
Code: 80 3d 44 96 27 c0 00 f3 90 7e f5 e9 d6 17 f8 ff e8 66 fa ee

>>EIP; c021996d <stext_lock+3d69/8bc0> <=====
Trace; c010bf56 <handle_IRQ_event+4e/78>
Trace; c010c149 <do_IRQ+99/ec>
Trace; c010a858 <ret_from_intr+0/20>
Trace; c011a297 <printk+177/194>
Trace; c0116efa <schedule+9c2/9e8>
Trace; c02249fe <call_spurious_interrupt+587a/7528>
Trace; c0109264 <__down+70/c4>
Trace; c01ab320 <scsi_eh_times_out+0/98>
Trace; c01093f0 <__down_failed+8/c>
Trace; c021a0b3 <stext_lock+44af/8bc0>
Trace; c01ab353 <scsi_eh_times_out+33/98>
Trace; c012120f <timer_bh+257/2b4>
Trace; c011dfd2 <bh_action+4e/b0>
Trace; c011deb5 <tasklet_hi_action+51/7c>
Trace; c011dd5a <do_softirq+5a/88>
Trace; c010c18a <do_IRQ+da/ec>
Trace; c0108a10 <default_idle+0/34>
Trace; c0108a10 <default_idle+0/34>
Trace; c010a858 <ret_from_intr+0/20>
Trace; c0108a10 <default_idle+0/34>
Trace; c0108a10 <default_idle+0/34>
Trace; c0100018 <startup_32+18/cc>
Trace; c0108a3d <default_idle+2d/34>
Trace; c0108aa2 <cpu_idle+3e/54>
Trace; c0105000 <empty_bad_page+0/1000>
Trace; c01001d1 <L6+0/2>
Code; c021996d <stext_lock+3d69/8bc0>
00000000 <_EIP>:
Code; c021996d <stext_lock+3d69/8bc0> <=====
   0: 80 3d 44 96 27 c0 00 cmpb $0x0,0xc0279644 <=====
Code; c0219974 <stext_lock+3d70/8bc0>
   7: f3 90 repz nop
Code; c0219976 <stext_lock+3d72/8bc0>
   9: 7e f5 jle 0 <_EIP>
Code; c0219978 <stext_lock+3d74/8bc0>
   b: e9 d6 17 f8 ff jmp fff817e6 <_EIP+0xfff817e6> c019b153 <do_aic7xxx_isr+1b/b0>
Code; c021997d <stext_lock+3d79/8bc0>
  10: e8 66 fa ee 00 call eefa7b <_EIP+0xeefa7b> c11093e8 <_end+e04df8/6520a10>

The problem could be in USB but also in the SCSI subsystem I guess.
More data written down at BUGtime is available (registers, stack).
Here is another BUG but this time I used modules for everything. So,
some addresses (guess the 3 starting with 068) appear to be bogus. This
is the "kernel BUG at sched.c: 683" case:

ksymoops 2.3.3 on i686 2.4.0-test6-x15. Options used
     -V (default)
     -k /proc/ksyms (default)
     -l /proc/modules (default)
     -o /lib/modules/2.4.0-test6-x15/ (default)
     -m /boot/System.map-2.4.0-test6-x15 (specified)

kernel: invalid operand: 0000
kernel: CPU: 0
kernel: EIP: 0010:[<c0116f11>]
Using defaults from ksymoops -t elf32-i386 -a i386
kernel: Call Trace: [<c01d9f89>] [<c01da156>] [<c0109264>] [<c68a0a50>] [<c01093f0>] [<c68b8aa2>] [<c68a0a83>]
kernel: [<c012120f>] [<c011dfd2>] [<c011deb5>] [<c011dd5a>] [<c010c18a>] [<c0108a10>] [<c0108a10>]
kernel: [<c010a858>] [<c0108a10>] [<c0108a10>] [<c0100018>] [<c0108a3d>] [<c0108aa2>] [<c0190cc7>]
Warning (Oops_read): Code line not seen, dumping what data is available

>>EIP; c0116f11 <schedule+9d9/9e8> <=====
Trace; c01d9f89 <call_spurious_interrupt+56a5/7508>
Trace; c01da156 <call_spurious_interrupt+5872/7508>
Trace; c0109264 <__down+70/c4>
Trace; c68a0a50 <[bsd_comp].data.end+cb19/f129>
Trace; c01093f0 <__down_failed+8/c>
Trace; c68b8aa2 <END_OF_CODE+bd63/????>
Trace; c68a0a83 <[bsd_comp].data.end+cb4c/f129>
Trace; c012120f <timer_bh+257/2b4>
Trace; c011dfd2 <bh_action+4e/b0>
Trace; c011deb5 <tasklet_hi_action+51/7c>
Trace; c011dd5a <do_softirq+5a/88>
Trace; c010c18a <do_IRQ+da/ec>
Trace; c0108a10 <default_idle+0/34>
Trace; c0108a10 <default_idle+0/34>
Trace; c010a858 <ret_from_intr+0/20>
Trace; c0108a10 <default_idle+0/34>
Trace; c0108a10 <default_idle+0/34>
Trace; c0100018 <startup_32+18/cc>
Trace; c0108a3d <default_idle+2d/34>
Trace; c0108aa2 <cpu_idle+3e/54>
Trace; c0190cc7 <vgacon_cursor+1db/1e4>

And now the patch which triggers it all...

--- linux/drivers/usb/storage/usb.c.orig Fri Aug 11 20:23:44 2000
+++ linux/drivers/usb/storage/usb.c Sat Aug 12 16:22:37 2000
@@ -289,6 +289,8 @@
                 US_SC_8070, US_PR_BULK, US_FL_ALT_LENGTH},
         { 0x0693, 0x0005, 0x0100, 0x0100, "Hagiwara Flashgate",
                 US_SC_SCSI, US_PR_BULK, US_FL_ALT_LENGTH},
+ { 0x07cf, 0x1001, 0x9009, 0x9009, "Casio digital camera (QV-3000EX/Ir)",
+ US_SC_SCSI, US_PR_BULK, US_FL_ALT_LENGTH},
         { 0 }};
 
 /* Search our ususual device list, based on vendor/product combinations

-- 
Frank

- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo@vger.rutgers.edu Please read the FAQ at http://www.tux.org/lkml/



This archive was generated by hypermail 2b29 : Tue Aug 15 2000 - 21:00:27 EST