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

[Frank van Maarseveen]

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