2.4.17,2.4.18 ide-scsi+usb-storage+devfs Oops

2.4.17,2.4.18 ide-scsi+usb-storage+devfs Oops

[Sandino Araico Sánchez]

The Oops happens after I use the ide-scsi module with my CDRW and then I
plug the Zip USB in.

To reproduce the oops:
1. Boot the machine (usbmgr should be started at boot)
2. rmod ide-cd ; rmmod ide-scsi ; rmmod sr_mod ; rmmod cdrom
3. modprobe ide-scsi
    /dev/scsi/host2/bus0/target0/lun0/generic is created
4. modprobe sr_mod
    /dev/scsi/host2/bus0/target0/lun0/cd is created
    /dev/cdroms/cdrom0 -> /dev/scsi/host2/bus0/target0/lun0/cd
5. Plug the Zip in the USB
    usb-storage is loaded
    /dev/scsi/host2/bus0/target0/lun0/disc is created
    /dev/scsi/host2/bus0/target0/lun0/part4 is created
    /dev/scsi/host2/bus0/target0/lun0/cd disappears
    /dev/cdroms/cdrom0 becomes broken link
    /dev/scsi/host2/bus0/target0/lun0/generic changes from the CDRW
generic device to the Zip generic device
6. Unplug the Zip
    /dev/scsi/host2/bus0/target0/lun0 disappears, I can only reach to
/dev/scsi/host2/bus0/target0
    usb-storage is unloaded
7. different ways of provoking the Oops
    7.1 umount /mnt/cdrom
    7.2 rmmod sr_mod
    7.3 rmmod ide-scsi
    7.4 Any kind of trying to read or write the CD

The Oops does not happen if I unload ide-scsi, sr_mod, cdrom before
pluging the Zip in and if I unplug the Zip before modprobe ide-scsi and
modprobe sr_mod.


--
Sandino Araico Sánchez
>drop table internet;
OK, 135454265363565609860398636678346496 rows affected.
"oh fuck" --fluxrad

Re: 2.4.17,2.4.18 ide-scsi+usb-storage+devfs Oops

[Greg KH]

On Thu, Feb 28, 2002 at 03:57:31PM -0600, Sandino Araico Sánchez wrote:
> The Oops happens after I use the ide-scsi module with my CDRW and then I
> plug the Zip USB in.

Can you run the oops through ksymoops and send it to us?

thanks,

greg k-h

Re: 2.4.17,2.4.18 ide-scsi+usb-storage+devfs Oops

[Sandino Araico Sánchez]

[-- Attachment #1: Type: text/plain, Size: 409 bytes --]

Greg KH wrote:

> On Thu, Feb 28, 2002 at 03:57:31PM -0600, Sandino Araico Sánchez wrote:
> > The Oops happens after I use the ide-scsi module with my CDRW and then I
> > plug the Zip USB in.
>
> Can you run the oops through ksymoops and send it to us?
>

ksymoops output attached.

--
Sandino Araico Sánchez
>drop table internet;
OK, 135454265363565609860398636678346496 rows affected.
"oh fuck" --fluxrad



[-- Attachment #2: Oops-2002-03-04.ksymoops --]
[-- Type: text/plain, Size: 4261 bytes --]

ksymoops 2.3.4 on i686 2.4.18.  Options used
     -V (default)
     -k /proc/ksyms (default)
     -l /proc/modules (default)
     -o /lib/modules/2.4.18/ (default)
     -m /usr/src/linux/System.map (default)

Warning: You did not tell me where to find symbol information.  I will
assume that the log matches the kernel and modules that are running
right now and I'll use the default options above for symbol resolution.
If the current kernel and/or modules do not match the log, you can get
more accurate output by telling me the kernel version and where to find
map, modules, ksyms etc.  ksymoops -h explains the options.

Warning (expand_objects): object /lib/modules/2.4.18/kernel/sound/acore/oss/snd-pcm-oss.o for module snd-pcm-oss has changed since load
Warning (expand_objects): object /lib/modules/2.4.18/kernel/sound/acore/snd-pcm.o for module snd-pcm has changed since load
Warning (expand_objects): object /lib/modules/2.4.18/kernel/sound/acore/seq/oss/snd-seq-oss.o for module snd-seq-oss has changed since load
Warning (expand_objects): object /lib/modules/2.4.18/kernel/sound/acore/seq/snd-seq-midi-event.o for module snd-seq-midi-event has changed since load
Warning (expand_objects): object /lib/modules/2.4.18/kernel/sound/acore/seq/snd-seq.o for module snd-seq has changed since load
Warning (expand_objects): object /lib/modules/2.4.18/kernel/sound/acore/snd-timer.o for module snd-timer has changed since load
Warning (expand_objects): object /lib/modules/2.4.18/kernel/sound/acore/seq/snd-seq-device.o for module snd-seq-device has changed since load
Warning (expand_objects): object /lib/modules/2.4.18/kernel/sound/acore/oss/snd-mixer-oss.o for module snd-mixer-oss has changed since load
Warning (expand_objects): object /lib/modules/2.4.18/kernel/sound/acore/snd.o for module snd has changed since load
Warning (compare_ksyms_lsmod): module sr_mod is in lsmod but not in ksyms, probably no symbols exported
Warning (compare_maps): ksyms_base symbol acpi_fadt_R__ver_acpi_fadt not found in System.map.  Ignoring ksyms_base entry
Warning (compare_maps): ksyms_base symbol acpi_gbl_FADT_R__ver_acpi_gbl_FADT not found in System.map.  Ignoring ksyms_base entry
Invalid operand: 0000
CPU:    0
EIP: 0010: [<c01565f0>] Not tainted
Using defaults from ksymoops -t elf32-i386 -a i386
EFLAGS: 00010282
eax: 0000000d ebx: d010d8e0 ecx: dd384000 edx: 00000001
esi: cd0d1a14 edi: c49a7d60 ebp: bfffe4cc esp: c1b7bf18
ds: 0018 es: 0018 ss: 0018
Process rmmod (pid: 24039, stackpage=c1b76000)
Stack: c0244807 c02447ea c02447e0 d010d8e0 d010d8e0 c01575d8 d010d8e0 d010d2e0
        d010d8e0 cd0d1a14 e090b362 d010d8e0 cd0d1a00 00000000 e0d5d3be cd0d1a14
        00000600 00000000 c49a7d60 d010dee0 e0d5ea80 c01c544a c49a7d60 e0d5c000
Call Trace: [<c01575d8>] [<e0d5d424>] [<e0d5d3be>] [<e0d5ea80>] [<c01c544a>] [<c01c555e>] [<e0d5ea80>] [<e0d5d424>] [<e0d5ea80>] [<c011980f>] [<c0118b12>]
        [<c0106e23>]
Code: 0f 0b 83 c4 10 f0 ff 4b 04 0f 94 c0 84 c0 0f 84 93 00 00 00 

>>EIP; c01565f0 <devfs_put+30/dc>   <=====
Trace; c01575d8 <devfs_unregister+30/38>
Trace; e0d5d424 <[usb-uhci]__module_license+9099/fcd5>
Trace; e0d5d3be <[usb-uhci]__module_license+9033/fcd5>
Trace; e0d5ea80 <[usb-uhci]__module_license+a6f5/fcd5>
Trace; c01c544a <scsi_unregister_device+52/d4>
Trace; c01c555e <scsi_unregister_module+36/3c>
Trace; e0d5ea80 <[usb-uhci]__module_license+a6f5/fcd5>
Trace; e0d5d424 <[usb-uhci]__module_license+9099/fcd5>
Trace; e0d5ea80 <[usb-uhci]__module_license+a6f5/fcd5>
Trace; c011980f <free_module+17/b4>
Trace; c0118b12 <sys_delete_module+126/234>
Trace; c0106e23 <system_call+33/38>
Code;  c01565f0 <devfs_put+30/dc>
00000000 <_EIP>:
Code;  c01565f0 <devfs_put+30/dc>   <=====
   0:   0f 0b                     ud2a      <=====
Code;  c01565f2 <devfs_put+32/dc>
   2:   83 c4 10                  add    $0x10,%esp
Code;  c01565f5 <devfs_put+35/dc>
   5:   f0 ff 4b 04               lock decl 0x4(%ebx)
Code;  c01565f9 <devfs_put+39/dc>
   9:   0f 94 c0                  sete   %al
Code;  c01565fc <devfs_put+3c/dc>
   c:   84 c0                     test   %al,%al
Code;  c01565fe <devfs_put+3e/dc>
   e:   0f 84 93 00 00 00         je     a7 <_EIP+0xa7> c0156697 <devfs_put+d7/dc>


13 warnings issued.  Results may not be reliable.

Re: 2.4.17,2.4.18 ide-scsi+usb-storage+devfs Oops

[Richard Gooch]

[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #1: Type: text/plain, Size: 2108 bytes --]

Sandino Araico writes:
> Greg KH wrote:
> 
> > On Thu, Feb 28, 2002 at 03:57:31PM -0600, Sandino Araico Sánchez wrote:
> > > The Oops happens after I use the ide-scsi module with my CDRW and then I
> > > plug the Zip USB in.
> >
> > Can you run the oops through ksymoops and send it to us?
> 
> ksymoops output attached.
> Invalid operand: 0000
> CPU:    0
> EIP: 0010: [<c01565f0>] Not tainted
> Using defaults from ksymoops -t elf32-i386 -a i386
> EFLAGS: 00010282
> eax: 0000000d ebx: d010d8e0 ecx: dd384000 edx: 00000001
> esi: cd0d1a14 edi: c49a7d60 ebp: bfffe4cc esp: c1b7bf18
> ds: 0018 es: 0018 ss: 0018
> Process rmmod (pid: 24039, stackpage=c1b76000)
> Stack: c0244807 c02447ea c02447e0 d010d8e0 d010d8e0 c01575d8 d010d8e0 d010d2e0
>         d010d8e0 cd0d1a14 e090b362 d010d8e0 cd0d1a00 00000000 e0d5d3be cd0d1a14
>         00000600 00000000 c49a7d60 d010dee0 e0d5ea80 c01c544a c49a7d60 e0d5c000
> Call Trace: [<c01575d8>] [<e0d5d424>] [<e0d5d3be>] [<e0d5ea80>] [<c01c544a>] [<c01c555e>] [<e0d5ea80>] [<e0d5d424>] [<e0d5ea80>] [<c011980f>] [<c0118b12>]
>         [<c0106e23>]
> Code: 0f 0b 83 c4 10 f0 ff 4b 04 0f 94 c0 84 c0 0f 84 93 00 00 00 
> 
> >>EIP; c01565f0 <devfs_put+30/dc>   <=====
> Trace; c01575d8 <devfs_unregister+30/38>
> Trace; e0d5d424 <[usb-uhci]__module_license+9099/fcd5>
> Trace; e0d5d3be <[usb-uhci]__module_license+9033/fcd5>
> Trace; e0d5ea80 <[usb-uhci]__module_license+a6f5/fcd5>
> Trace; c01c544a <scsi_unregister_device+52/d4>
> Trace; c01c555e <scsi_unregister_module+36/3c>
> Trace; e0d5ea80 <[usb-uhci]__module_license+a6f5/fcd5>
> Trace; e0d5d424 <[usb-uhci]__module_license+9099/fcd5>
> Trace; e0d5ea80 <[usb-uhci]__module_license+a6f5/fcd5>
> Trace; c011980f <free_module+17/b4>
> Trace; c0118b12 <sys_delete_module+126/234>
> Trace; c0106e23 <system_call+33/38>

I suspect the USB-UHCI driver is doing a double-unregister on a devfs
entry. Please set CONFIG_DEVFS_DEBUG=y, recompile and boot the new
kernel. Send the new Oops (passed through ksymoops, of course).

				Regards,

					Richard....
Permanent: rgooch@atnf.csiro.au
Current:   rgooch@ras.ucalgary.ca

Re: 2.4.17,2.4.18 ide-scsi+usb-storage+devfs Oops

[Greg KH]

On Tue, Mar 05, 2002 at 10:28:43PM -0700, Richard Gooch wrote:
> 
> I suspect the USB-UHCI driver is doing a double-unregister on a devfs
> entry. Please set CONFIG_DEVFS_DEBUG=y, recompile and boot the new
> kernel. Send the new Oops (passed through ksymoops, of course).

None of the USB host controller drivers (like usb-uhci.c) call any devfs
functions.

thanks,

greg k-h

Re: 2.4.17,2.4.18 ide-scsi+usb-storage+devfs Oops

[Richard Gooch]

Greg KH writes:
> On Tue, Mar 05, 2002 at 10:28:43PM -0700, Richard Gooch wrote:
> > 
> > I suspect the USB-UHCI driver is doing a double-unregister on a devfs
> > entry. Please set CONFIG_DEVFS_DEBUG=y, recompile and boot the new
> > kernel. Send the new Oops (passed through ksymoops, of course).
> 
> None of the USB host controller drivers (like usb-uhci.c) call any
> devfs functions.

Well, usb-uhci was in the call trace. Perhaps ksymoops was being given
bogus input?

				Regards,

					Richard....
Permanent: rgooch@atnf.csiro.au
Current:   rgooch@ras.ucalgary.ca

Re: 2.4.17,2.4.18 ide-scsi+usb-storage+devfs Oops

[Greg KH]

On Tue, Mar 05, 2002 at 10:45:58PM -0700, Richard Gooch wrote:
> Greg KH writes:
> > On Tue, Mar 05, 2002 at 10:28:43PM -0700, Richard Gooch wrote:
> > > 
> > > I suspect the USB-UHCI driver is doing a double-unregister on a devfs
> > > entry. Please set CONFIG_DEVFS_DEBUG=y, recompile and boot the new
> > > kernel. Send the new Oops (passed through ksymoops, of course).
> > 
> > None of the USB host controller drivers (like usb-uhci.c) call any
> > devfs functions.
> 
> Well, usb-uhci was in the call trace. Perhaps ksymoops was being given
> bogus input?

I agree, with symbols like:
	<[usb-uhci]__module_license+9099/fcd5>
it looks like this is the case.

thanks,

greg k-h

Re: 2.4.17,2.4.18 ide-scsi+usb-storage+devfs Oops

[Sandino Araico Sánchez]

Greg KH wrote:

> On Tue, Mar 05, 2002 at 10:45:58PM -0700, Richard Gooch wrote:
> > Greg KH writes:
> > > On Tue, Mar 05, 2002 at 10:28:43PM -0700, Richard Gooch wrote:
> > > >
> > > > I suspect the USB-UHCI driver is doing a double-unregister on a devfs
> > > > entry. Please set CONFIG_DEVFS_DEBUG=y, recompile and boot the new
> > > > kernel. Send the new Oops (passed through ksymoops, of course).
> > >
> > > None of the USB host controller drivers (like usb-uhci.c) call any
> > > devfs functions.
> >
> > Well, usb-uhci was in the call trace. Perhaps ksymoops was being given
> > bogus input?
>
> I agree, with symbols like:
>         <[usb-uhci]__module_license+9099/fcd5>
> it looks like this is the case.
>

I had to copy the Oops trace by hand to a paper. Gpm is not working correctly
on my machine. Is there another way to send the Oops trace to a file?

--
Sandino Araico Sánchez
>drop table internet;
OK, 135454265363565609860398636678346496 rows affected.
"oh fuck" --fluxrad

Re: 2.4.17,2.4.18 ide-scsi+usb-storage+devfs Oops

[Juan Quintela]

>>>>> "sandino" == Sandino Araico Sánchez <sandino@sandino.net> writes:

sandino> I had to copy the Oops trace by hand to a paper. Gpm is not working correctly
sandino> on my machine. Is there another way to send the Oops trace to a file?


dmesg > file

normally works.

Later, Juan.


-- 
In theory, practice and theory are the same, but in practice they 
are different -- Larry McVoy

Re: 2.4.17,2.4.18 ide-scsi+usb-storage+devfs Oops

[Sandino Araico Sánchez]

[-- Attachment #1: Type: text/plain, Size: 1322 bytes --]

Juan Quintela wrote:

> >>>>> "sandino" == Sandino Araico Sánchez <sandino@sandino.net> writes:
>
> sandino> I had to copy the Oops trace by hand to a paper. Gpm is not working correctly
> sandino> on my machine. Is there another way to send the Oops trace to a file?
>
> dmesg > file
>

Sorry about being so late, but I have another ksymoops.

This time the Oops was reproduced as follows:

1. I ran this script
#!/bin/sh
killall -9 wmcdplay
rmmod sr_mod
rmmod ide-scsi
modprobe ide-cd
ls -la /dev/cdroms/cdrom0
/etc/rc.d/init.d/usbmgr start

2. I ran this script
#!/bin/sh
/etc/rc.d/init.d/usbmgr stop
killall -9 wmcdplay
rmmod ide-cd
modprobe ide-scsi
modprobe sr_mod
ls -la /dev/cdroms/cdrom0

lr-xr-xr-x    1 root     root           34 dic 31  1969 /dev/cdroms/cdrom0 ->
../scsi/host2/bus0/target0/lun0/cd

3. I mounted the cdrom
mount  /dev/scsi/host2/bus0/target0/lun0/cd /mnt/cdrom

4. I started the usbmgr

5. I inserted the zip drive in the usb port

6. I don't remember when the Oops happened, when I unmounted the CD or after unmounting
it when I ran eject.


This time I'm sure the ksymoops is correct because I did dmesg > file and after rebooting
ksymoops < file > file.ksymoops.

--
Sandino Araico Sánchez
>drop table internet;
OK, 135454265363565609860398636678346496 rows affected.
"oh fuck" --fluxrad



[-- Attachment #2: Oops-2002-04-03-cdrom.ksymoops --]
[-- Type: text/plain, Size: 3099 bytes --]

ksymoops 2.3.4 on i686 2.4.18.  Options used
     -V (default)
     -k /proc/ksyms (default)
     -l /proc/modules (default)
     -o /lib/modules/2.4.18/ (default)
     -m /usr/src/linux/System.map (default)

Warning: You did not tell me where to find symbol information.  I will
assume that the log matches the kernel and modules that are running
right now and I'll use the default options above for symbol resolution.
If the current kernel and/or modules do not match the log, you can get
more accurate output by telling me the kernel version and where to find
map, modules, ksyms etc.  ksymoops -h explains the options.

Warning (compare_maps): ksyms_base symbol acpi_fadt_R__ver_acpi_fadt not found in System.map.  Ignoring ksyms_base entry
Warning (compare_maps): ksyms_base symbol acpi_gbl_FADT_R__ver_acpi_gbl_FADT not found in System.map.  Ignoring ksyms_base entry
Unable to handle kernel paging request at virtual address 0120000c
c01575bb
*pde = 00000000
Oops: 0002
CPU:    0
EIP:    0010:[<c01575bb>]    Not tainted
Using defaults from ksymoops -t elf32-i386 -a i386
EFLAGS: 00010206
eax: 0120000c   ebx: d40dd8e0   ecx: c1846d60   edx: 00000000
esi: d0820a14   edi: d9e5bbe0   ebp: bfffe4ec   esp: da36ff3c
ds: 0018   es: 0018   ss: 0018
Process rmmod (pid: 3239, stackpage=da36f000)
Stack: d0820a14 e08e4362 d40dd8e0 d0820a00 00000000 e08f13be d0820a14 00000b00 
       00000000 d9e5bbe0 df0ff720 e08f2a80 c01c544a d9e5bbe0 e08f0000 fffffff0 
       e08f0000 c01c555e e08f2a80 e08f1424 00000004 e08f2a80 c011980f e08f0000 
Call Trace: [<e08e4362>] [<e08f13be>] [<e08f2a80>] [<c01c544a>] [<c01c555e>] 
   [<e08f2a80>] [<e08f1424>] [<e08f2a80>] [<c011980f>] [<c0118b12>] [<c0106e23>] 
Code: f0 81 28 00 00 00 01 0f 85 72 22 00 00 53 8b 43 20 50 e8 46 

>>EIP; c01575bb <devfs_unregister+13/38>   <=====
Trace; e08e4362 <[cdrom]unregister_cdrom+8a/bc>
Trace; e08f13be <[ide-cd]cdrom_analyze_sense_data+2c2/31c>
Trace; e08f2a80 <[ide-cd]cdrom_lockdoor+1c/e0>
Trace; c01c544a <scsi_unregister_device+52/d4>
Trace; c01c555e <scsi_unregister_module+36/3c>
Trace; e08f2a80 <[ide-cd]cdrom_lockdoor+1c/e0>
Trace; e08f1424 <[ide-cd]cdrom_queue_request_sense+c/90>
Trace; e08f2a80 <[ide-cd]cdrom_lockdoor+1c/e0>
Trace; c011980f <free_module+17/b4>
Trace; c0118b12 <sys_delete_module+126/234>
Trace; c0106e23 <system_call+33/38>
Code;  c01575bb <devfs_unregister+13/38>
00000000 <_EIP>:
Code;  c01575bb <devfs_unregister+13/38>   <=====
   0:   f0 81 28 00 00 00 01      lock subl $0x1000000,(%eax)   <=====
Code;  c01575c2 <devfs_unregister+1a/38>
   7:   0f 85 72 22 00 00         jne    227f <_EIP+0x227f> c015983a <_text_lock_base+75/12f>
Code;  c01575c8 <devfs_unregister+20/38>
   d:   53                        push   %ebx
Code;  c01575c9 <devfs_unregister+21/38>
   e:   8b 43 20                  mov    0x20(%ebx),%eax
Code;  c01575cc <devfs_unregister+24/38>
  11:   50                        push   %eax
Code;  c01575cd <devfs_unregister+25/38>
  12:   e8 46 00 00 00            call   5d <_EIP+0x5d> c0157618 <devfs_do_symlink+38/17c>


3 warnings issued.  Results may not be reliable.

Re: 2.4.17,2.4.18 ide-scsi+usb-storage+devfs Oops

[Richard Gooch]

[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #1: Type: text/plain, Size: 517 bytes --]

Sandino Araico writes:
> Juan Quintela wrote:
> 
> > >>>>> "sandino" == Sandino Araico Sánchez <sandino@sandino.net> writes:
> >
> > sandino> I had to copy the Oops trace by hand to a paper. Gpm is not working correctly
> > sandino> on my machine. Is there another way to send the Oops trace to a file?
> >
> > dmesg > file
> >
> 
> Sorry about being so late, but I have another ksymoops.

Please send me your .config.

				Regards,

					Richard....
Permanent: rgooch@atnf.csiro.au
Current:   rgooch@ras.ucalgary.ca

Re: 2.4.17,2.4.18 ide-scsi+usb-storage+devfs Oops

[Sandino Araico Sánchez]

Richard Gooch wrote:

>
> I suspect the USB-UHCI driver is doing a double-unregister on a devfs
> entry.

The usb-storage is using the devfs entries previously registered by the ide-scsi driver, it doesn't create new entries. When the  usb-storage module is
unloaded it unregisters such entries.

> Please set CONFIG_DEVFS_DEBUG=y,

CONFIG_DEVFS_DEBUG=y was already set before passing the trace to ksymoops. If you need me to search into the system log just tellme what to search for.

> recompile and boot the new
> kernel. Send the new Oops (passed through ksymoops, of course).
>
>

> --
> Sandino Araico Sánchez
> >drop table internet;
> OK, 135454265363565609860398636678346496 rows affected.
> "oh fuck" --fluxrad