2.6.9-mm1, kernel Ooops in visor_open

2.6.9-mm1, kernel Ooops in visor_open

[Norbert Preining]

Hi Andrew, USB developers, list!

With:
	linux-2.6.9-mm1
	debian/sid
I get the following kernel warning:

usb 4-2: new full speed USB device using address 2
usbcore: registered new driver usbserial
drivers/usb/serial/usb-serial.c: USB Serial Driver core v2.0
drivers/usb/serial/usb-serial.c: USB Serial support registered for Handspring Visor / Palm OS
drivers/usb/serial/usb-serial.c: USB Serial support registered for Sony Clie 3.5
drivers/usb/serial/usb-serial.c: USB Serial support registered for Sony Clie 5.0
visor 4-2:1.0: Handspring Visor / Palm OS converter detected
usb 4-2: Handspring Visor / Palm OS converter now attached to ttyUSB0
usb 4-2: Handspring Visor / Palm OS converter now attached to ttyUSB1
usbcore: registered new driver visor
drivers/usb/serial/visor.c: USB HandSpring Visor / Palm OS driver v2.1
Unable to handle kernel NULL pointer dereference at virtual address 00000008
 printing eip:
e09eb036
*pde = 00000000
Oops: 0002 [#1]
PREEMPT 
Modules linked in: visor usbserial radeon irtty_sir sir_dev irda crc_ccitt eth1394 sd_mod ehci_hcd ohci1394 ieee1394 yenta_socket pcmcia_core snd_intel8x0m i2c_i801 usbhid usb_storage uhci_hcd usbcore joydev acerhk intel_agp agpgart orinoco_pci orinoco hermes b44 evdev
CPU:    0
EIP:    0060:[<e09eb036>]    Not tainted VLI
EFLAGS: 00010002   (2.6.9-mm1) 
EIP is at visor_open+0x36/0x1c6 [visor]
eax: 00000282   ebx: 00000000   ecx: d888a580   edx: d13e4000
esi: c3cf8ec0   edi: cba9b600   ebp: 00000000   esp: d13e5eb4
ds: 007b   es: 007b   ss: 0068
Process jpilot (pid: 12278, threadinfo=d13e4000 task=d205b0a0)
Stack: 00000001 00000000 00000000 d13e5ee8 00000000 00000001 c3cf8ec0 cba9b600 
       e09c7369 d5843400 d9405100 00000000 d5218580 ffffffed c4d30000 d5218580 
       00000000 c01ea00e 08028ad6 0bc00001 c4d30000 00000001 d13e4000 c788a804 
Call Trace:
 [<e09c7369>] serial_open+0xbc/0x14f [usbserial]
 [<c01ea00e>] tty_open+0x211/0x288
 [<c015894a>] chrdev_open+0xe9/0x1c2
 [<c014ffdd>] dentry_open+0x134/0x210
 [<c014fea7>] filp_open+0x4c/0x4e
 [<c01500e5>] get_unused_fd+0x2c/0xce
 [<c0150239>] sys_open+0x3c/0x76
 [<c0105ecb>] syscall_call+0x7/0xb
Code: 98 ec 00 00 00 a1 80 f1 9e e0 85 c0 0f 85 80 01 00 00 8b 4f 20 85 c9 0f 84 40 01 00 00 9c 58 fa ba 00 e0 ff ff 21 e2 83 42 14 01 <c7> 43 08 00 00 00 00 c7 03 00 00 00 00 c7 43 04 00 00 00 00 50 
 <6>note: jpilot[12278] exited with preempt_count 1
scheduling while atomic: jpilot/0x10000001/12278
 [<c02e4a6c>] schedule+0x50c/0x511
 [<c02e4ed2>] cond_resched+0x2d/0x43
 [<c0142585>] unmap_vmas+0x19e/0x1f7
 [<c01466e5>] exit_mmap+0x78/0x143
 [<c011a8f5>] mmput+0x2f/0xb6
 [<c011e840>] do_exit+0x149/0x41e
 [<c0107045>] do_divide_error+0x0/0x10e
 [<c0117d2b>] do_page_fault+0x0/0x5aa
 [<c0117d2b>] do_page_fault+0x0/0x5aa
 [<c0117ff1>] do_page_fault+0x2c6/0x5aa
 [<c0187a1a>] ext3_mark_inode_dirty+0x39/0x3b
 [<c0139a90>] buffered_rmqueue+0xf0/0x1b3
 [<c0139d78>] __alloc_pages+0x225/0x3a1
 [<c01b7cc2>] vsnprintf+0x24b/0x4b9
 [<c0117d2b>] do_page_fault+0x0/0x5aa
 [<c0106919>] error_code+0x2d/0x38
 [<c01e007b>] pnp_device_probe+0x74/0x94
 [<e09eb036>] visor_open+0x36/0x1c6 [visor]
 [<e09c7369>] serial_open+0xbc/0x14f [usbserial]
 [<c01ea00e>] tty_open+0x211/0x288
 [<c015894a>] chrdev_open+0xe9/0x1c2
 [<c014ffdd>] dentry_open+0x134/0x210
 [<c014fea7>] filp_open+0x4c/0x4e
 [<c01500e5>] get_unused_fd+0x2c/0xce
 [<c0150239>] sys_open+0x3c/0x76
 [<c0105ecb>] syscall_call+0x7/0xb
usb 4-2: USB disconnect, address 2
visor 4-2:1.0: device disconnected

Best wishes

Norbert

-------------------------------------------------------------------------------
Norbert Preining <preining AT logic DOT at>         Technische Universität Wien
gpg DSA: 0x09C5B094      fp: 14DF 2E6C 0307 BE6D AD76  A9C0 D2BF 4AA3 09C5 B094
-------------------------------------------------------------------------------
CORSTORPHINE (n.)
A very short peremptory service held in monasteries prior to teatime
to offer thanks for the benediction of digestive biscuits.
			--- Douglas Adams, The Meaning of Liff

Re: 2.6.9-mm1, kernel Ooops in visor_open

[Greg KH]

On Mon, Oct 25, 2004 at 04:48:46PM +0200, Norbert Preining wrote:
> Hi Andrew, USB developers, list!
> 
> With:
> 	linux-2.6.9-mm1
> 	debian/sid
> I get the following kernel warning:

Crud, you aren't the only one reporting this...  I'll test this out with
my visor later tomorrow and look into it.

thanks,

greg k-h

Re: 2.6.9-mm1, kernel Ooops in visor_open

[Norbert Preining]

Hi Greg!

On Mon, 25 Okt 2004, Greg KH wrote:
> > 	linux-2.6.9-mm1
> > 	debian/sid
> > I get the following kernel warning:
> 
> Crud, you aren't the only one reporting this...  I'll test this out with
> my visor later tomorrow and look into it.

Did you find anything related to this Oops? Do you have a fix for it?

Best wishes

Norbert

-------------------------------------------------------------------------------
Norbert Preining <preining AT logic DOT at>         Technische Universität Wien
gpg DSA: 0x09C5B094      fp: 14DF 2E6C 0307 BE6D AD76  A9C0 D2BF 4AA3 09C5 B094
-------------------------------------------------------------------------------
HASSOP (n.)
The pocket down the back of an armchair used for storing two-shilling
bits and pieces of Lego.
			--- Douglas Adams, The Meaning of Liff

Re: 2.6.9-mm1, kernel Ooops in visor_open

[Greg KH]

On Tue, Nov 02, 2004 at 07:38:36AM +0100, Norbert Preining wrote:
> Hi Greg!
> 
> On Mon, 25 Okt 2004, Greg KH wrote:
> > > 	linux-2.6.9-mm1
> > > 	debian/sid
> > > I get the following kernel warning:
> > 
> > Crud, you aren't the only one reporting this...  I'll test this out with
> > my visor later tomorrow and look into it.
> 
> Did you find anything related to this Oops? Do you have a fix for it?

I can't get my visor to work at all, it's a very old one (first
generation.)  I'm going to need some debugging help from others here...

thanks,

greg k-h

Re: 2.6.9-mm1, kernel Ooops in visor_open

[Norbert Preining]

On Fre, 05 Nov 2004, Greg KH wrote:
> generation.)  I'm going to need some debugging help from others here...

Tell me how I can help you!

Best wishes

Norbert

-------------------------------------------------------------------------------
Norbert Preining <preining AT logic DOT at>         Technische Universität Wien
gpg DSA: 0x09C5B094      fp: 14DF 2E6C 0307 BE6D AD76  A9C0 D2BF 4AA3 09C5 B094
-------------------------------------------------------------------------------
BERY POMEROY
1. The shape of a gourmet's lips. 2. The droplet of saliva which hangs
   from them.
			--- Douglas Adams, The Meaning of Liff

cannot eject drive using pktcdvd

[Vince]

I see the following bug since I've enabled packet writing for my dvd 
drive (using the udftools package):

- eject won't open the tray unless I'm root

- whether I'm root or not, I get the following error when running eject:
     "eject: unable to eject, last error: Invalid argument"
   and in the system logs:
"program eject is using a deprecated SCSI ioctl, please convert it to SG_IO"

The command: pktsetup dvd /dev/cdrom ; eject
should allow anyone with a cd/dvd writer to reproduce this bug.

Disabling packet writing ("pktsetup -d dvd") solves the problem and 
everything works fine (no strange message in the logs).

I _think_ this could be related to Redhat bug 137349 
(https://bugzilla.redhat.com/bugzilla/show_bug.cgi?id=137349),
but I could be wrong...

Regards,

Vince

(Please CC: me as I'm not subscribed)

Re: cannot eject drive using pktcdvd

[Peter Osterlund]

Vince <fuzzy77@free.fr> writes:

> I see the following bug since I've enabled packet writing for my dvd
> drive (using the udftools package):
> 
> - eject won't open the tray unless I'm root
> 
> - whether I'm root or not, I get the following error when running eject:
>      "eject: unable to eject, last error: Invalid argument"
>    and in the system logs:
> "program eject is using a deprecated SCSI ioctl, please convert it to SG_IO"
> 
> The command: pktsetup dvd /dev/cdrom ; eject
> should allow anyone with a cd/dvd writer to reproduce this bug.
> 
> Disabling packet writing ("pktsetup -d dvd") solves the problem and
> everything works fine (no strange message in the logs).

I can't reproduce any of these problems on my laptop. I run FC3 and
kernel 2.6.10-rc3-bk6. I tried both with a USB CDRW drive and an IDE
DVD+RW drive.

More info is needed. What distribution? What kernel? And please
provide strace logs from eject when it fails.

-- 
Peter Osterlund - petero2@telia.com
http://web.telia.com/~u89404340

Re: cannot eject drive using pktcdvd

[Norbert Preining]

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

Hi Peter, hi list!

Peter Osterlund wrote:
> I can't reproduce any of these problems on my laptop. I run FC3 and
> kernel 2.6.10-rc3-bk6. I tried both with a USB CDRW drive and an IDE
> DVD+RW drive.

I can reproduce this problem, in fact I experienced it myself and
disabled udftools.

> More info is needed. What distribution? What kernel? And please
> provide strace logs from eject when it fails.

kernel:		2.6.10-rc3-mm1
distribution:	debian/sid

I have straced the eject command for normal user (failed) and root
(succeeded) and the diff is short and simple:

--- strace.eject.user   2004-12-23 12:26:05.000000000 +0100
+++ strace.eject.root   2004-12-23 12:26:19.000000000 +0100
@@ -62,7 +62,10 @@
 munmap(0xb7c9a000, 4096)                = 0
 open("/dev/hdc", O_RDONLY|O_NONBLOCK)   = 3
 ioctl(3, CDROMEJECT, 0xbffffb68)        = -1 EIO (Input/output error)
-ioctl(3, FIBMAP, 0xbffffa10)            = -1 EPERM (Operation not permitted)
+ioctl(3, FIBMAP, 0xbffffa10)            = 0
+ioctl(3, FIBMAP, 0xbffffa10)            = 0
+ioctl(3, FIBMAP, 0xbffffa10)            = 0
+ioctl(3, BLKRRPART, 0xbffffa10)         = -1 EINVAL (Invalid argument)
 ioctl(3, FDEJECT, 0xbffffb68)           = -1 EINVAL (Invalid argument)

But in both cases I get
	eject: unable to eject, last error: Invalid argument
although as root it did work.

The complete strace.eject.user is attached.


Best wishes

Norbert

-------------------------------------------------------------------------------
Norbert Preining <preining AT logic DOT at>         Technische Universität Wien
sip:preining@at43.tuwien.ac.at                             +43 (0) 59966-690018
gpg DSA: 0x09C5B094      fp: 14DF 2E6C 0307 BE6D AD76  A9C0 D2BF 4AA3 09C5 B094
-------------------------------------------------------------------------------
AHENNY (adj.)
The way people stand when examining other people's bookshelves.
			--- Douglas Adams, The Meaning of Liff

[-- Attachment #2: strace.eject.user --]
[-- Type: text/plain, Size: 4535 bytes --]

execve("/usr/bin/eject", ["eject", "/dev/hdc"], [/* 27 vars */]) = 0
uname({sys="Linux", node="gandalf", ...}) = 0
brk(0)                                  = 0x804e000
old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fe9000
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/etc/ld.so.preload", O_RDONLY)    = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY)      = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=99507, ...}) = 0
old_mmap(NULL, 99507, PROT_READ, MAP_PRIVATE, 3, 0) = 0xb7fd0000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/tls/libc.so.6", O_RDONLY)    = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\360Y\1"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0644, st_size=1253924, ...}) = 0
old_mmap(NULL, 1260140, PROT_READ|PROT_EXEC, MAP_PRIVATE, 3, 0) = 0xb7e9c000
old_mmap(0xb7fc5000, 32768, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED, 3, 0x129000) = 0xb7fc5000
old_mmap(0xb7fcd000, 10860, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xb7fcd000
close(3)                                = 0
old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7e9b000
set_thread_area({entry_number:-1 -> 6, base_addr:0xb7e9b460, limit:1048575, seg_32bit:1, contents:0, read_exec_only:0, limit_in_pages:1, seg_not_present:0, useable:1}) = 0
munmap(0xb7fd0000, 99507)               = 0
open("/usr/lib/locale/locale-archive", O_RDONLY|O_LARGEFILE) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=2093808, ...}) = 0
mmap2(NULL, 2093808, PROT_READ, MAP_PRIVATE, 3, 0) = 0xb7c9b000
close(3)                                = 0
brk(0)                                  = 0x804e000
brk(0x806f000)                          = 0x806f000
brk(0)                                  = 0x806f000
access("/dev/hdc", F_OK)                = 0
readlink("/dev/hdc", 0xbfffeb10, 4095)  = -1 EINVAL (Invalid argument)
stat64("/dev/hdc", {st_mode=S_IFBLK|0660, st_rdev=makedev(22, 0), ...}) = 0
open("/etc/mtab", O_RDONLY)             = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=424, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7c9a000
read(3, "/dev/hda4 / ext3 rw,errors=remou"..., 4096) = 424
stat64("/dev/hda4", {st_mode=S_IFBLK|0660, st_rdev=makedev(3, 4), ...}) = 0
stat64("proc", 0xbfffedfc)              = -1 ENOENT (No such file or directory)
stat64("sysfs", 0xbfffedfc)             = -1 ENOENT (No such file or directory)
stat64("devpts", 0xbfffedfc)            = -1 ENOENT (No such file or directory)
stat64("tmpfs", 0xbfffedfc)             = -1 ENOENT (No such file or directory)
stat64("/dev/hda1", {st_mode=S_IFBLK|0660, st_rdev=makedev(3, 1), ...}) = 0
stat64("/dev/hda2", {st_mode=S_IFBLK|0660, st_rdev=makedev(3, 2), ...}) = 0
stat64("/dev", {st_mode=S_IFDIR|0755, st_size=3620, ...}) = 0
stat64("none", 0xbfffedfc)              = -1 ENOENT (No such file or directory)
stat64("usbfs", 0xbfffedfc)             = -1 ENOENT (No such file or directory)
read(3, "", 4096)                       = 0
close(3)                                = 0
munmap(0xb7c9a000, 4096)                = 0
open("/etc/fstab", O_RDONLY)            = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=936, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7c9a000
read(3, "# /etc/fstab: static file system"..., 4096) = 936
read(3, "", 4096)                       = 0
close(3)                                = 0
munmap(0xb7c9a000, 4096)                = 0
open("/etc/mtab", O_RDONLY)             = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=424, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7c9a000
read(3, "/dev/hda4 / ext3 rw,errors=remou"..., 4096) = 424
read(3, "", 4096)                       = 0
close(3)                                = 0
munmap(0xb7c9a000, 4096)                = 0
open("/dev/hdc", O_RDONLY|O_NONBLOCK)   = 3
ioctl(3, CDROMEJECT, 0xbffffb68)        = -1 EIO (Input/output error)
ioctl(3, FIBMAP, 0xbffffa10)            = -1 EPERM (Operation not permitted)
ioctl(3, FDEJECT, 0xbffffb68)           = -1 EINVAL (Invalid argument)
ioctl(3, MGSL_IOCGPARAMS or MTIOCTOP or SNDCTL_MIDI_MPUMODE, 0xbffffb20) = -1 EINVAL (Invalid argument)
write(2, "eject: unable to eject, last err"..., 53eject: unable to eject, last error: Invalid argument
) = 53
exit_group(1)                           = ?

Re: cannot eject drive using pktcdvd

[Peter Osterlund]

Norbert Preining <preining@logic.at> writes:

> Peter Osterlund wrote:
> > I can't reproduce any of these problems on my laptop. I run FC3 and
> > kernel 2.6.10-rc3-bk6. I tried both with a USB CDRW drive and an IDE
> > DVD+RW drive.
> 
> I can reproduce this problem, in fact I experienced it myself and
> disabled udftools.
> 
> > More info is needed. What distribution? What kernel? And please
> > provide strace logs from eject when it fails.
> 
> kernel:		2.6.10-rc3-mm1
> distribution:	debian/sid
...
>  open("/dev/hdc", O_RDONLY|O_NONBLOCK)   = 3
>  ioctl(3, CDROMEJECT, 0xbffffb68)        = -1 EIO (Input/output error)

I got a similar problem on FC3, but it doesn't have anything to do
with pktcdvd. The hal daemon is leaking a file descriptor when
checking a data DVD that doesn't contain a file system.

The effect is that /dev/hdc is kept open which makes eject attempts
from non-root users fail.

Here is a patch to fix the leak. I think it will apply also to the hal
cvs tree.

--- hal-0.4.2/hald/linux/block_class_device.c.old	2004-12-29 23:51:17.200288832 +0100
+++ hal-0.4.2/hald/linux/block_class_device.c	2004-12-29 23:51:23.040401000 +0100
@@ -1055,6 +1055,7 @@
 				if (is_cdrom) {
 					/* volume_id cannot probe blank/audio discs etc,
 					 * so don't fail for them, just set vid to NULL */
+					volume_id_close (vid);
 					vid = NULL;
 				} else {
 					g_object_unref (child);

-- 
Peter Osterlund - petero2@telia.com
http://web.telia.com/~u89404340