Bug 4418

Summary: PREEMPT error when I switch off a device using USB ACM driver
Product: Drivers Reporter: Salvador Fandino (sfandino)
Component: USBAssignee: Greg Kroah-Hartman (greg)
Status: REJECTED DUPLICATE    
Severity: normal CC: kernel-bugs, nacc
Priority: P2    
Hardware: i386   
OS: Linux   
Kernel Version: 2.6.10 Subsystem:
Regression: --- Bisected commit-id:
Attachments: ksymooops for similar error
2.6.12's .config
lspci's output

Description Salvador Fandino 2005-03-29 11:19:13 UTC 
Distribution: Debian Unstable
Hardware Environment: Toshiba Portega 3410CT (Celeron 400MHz laptop) and Nokia
3660 3G mobile phone.

Software Environment: Linux Debian unstable, Linux version 2.6.10-1-686 (from
original Debian package, no custom compilation)

Problem Description:
PREEMPT error message on messages log.

I have a 3G Nokia 3660 mobile phone that I use to connect to the internet via
ppp through an USB cable. It uses the ACM driver. Sometimes the mobile modem
stops responding and I have to switch it off and on again to get it working, but
yesterday (March 29) I upgraded my computer to the latest kernel package
available for Debian and today when I switched the mobile off *just after
invoking pppd on it* I got the error below.

Steps to reproduce:

switch ACM device off while pppd is using it.


Full /var/log/messages for the session follows, the error report is at the end:

Mar 29 19:19:54 toledo kernel: Linux version 2.6.10-1-686 (dilinger@mouth) (gcc
version 3.3.5 (Debian 1:3.3.5-8)) #1 Fri Mar 11 03:55:46 EST 2005
Mar 29 19:19:54 toledo kernel: BIOS-provided physical RAM map:
Mar 29 19:19:54 toledo kernel:  BIOS-e820: 0000000000000000 - 000000000009fc00
(usable)
Mar 29 19:19:54 toledo kernel:  BIOS-e820: 000000000009fc00 - 00000000000a0000
(reserved)
Mar 29 19:19:54 toledo kernel:  BIOS-e820: 00000000000ec000 - 0000000000100000
(reserved)
Mar 29 19:19:54 toledo kernel:  BIOS-e820: 0000000000100000 - 000000000bfe0000
(usable)
Mar 29 19:19:54 toledo kernel:  BIOS-e820: 000000000bfe0000 - 000000000bff0000
(ACPI data)
Mar 29 19:19:54 toledo kernel:  BIOS-e820: 000000000bff0000 - 000000000c000000
(reserved)
Mar 29 19:19:54 toledo kernel:  BIOS-e820: 00000000100a0000 - 00000000100b6e00
(reserved)
Mar 29 19:19:54 toledo kernel:  BIOS-e820: 00000000100b6e00 - 00000000100b7000
(ACPI NVS)
Mar 29 19:19:54 toledo kernel:  BIOS-e820: 00000000100b7000 - 0000000010100000
(reserved)
Mar 29 19:19:54 toledo kernel:  BIOS-e820: 00000000fff80000 - 0000000100000000
(reserved)
Mar 29 19:19:54 toledo kernel: 0MB HIGHMEM available.
Mar 29 19:19:54 toledo kernel: 191MB LOWMEM available.
Mar 29 19:19:54 toledo kernel: DMI 2.3 present.
Mar 29 19:19:54 toledo kernel: ACPI: Disabling ACPI support
Mar 29 19:19:54 toledo kernel: Built 1 zonelists
Mar 29 19:19:54 toledo kernel: Kernel command line: root=/dev/hda6 ro 
Mar 29 19:19:54 toledo kernel: Local APIC disabled by BIOS -- you can enable it
with "lapic"
Mar 29 19:19:54 toledo kernel: Initializing CPU#0
Mar 29 19:19:54 toledo kernel: PID hash table entries: 1024 (order: 10, 16384 bytes)
Mar 29 19:19:54 toledo kernel: Detected 400.053 MHz processor.
Mar 29 19:19:54 toledo kernel: Using tsc for high-res timesource
Mar 29 19:19:54 toledo kernel: Console: colour VGA+ 80x25
Mar 29 19:19:54 toledo kernel: Dentry cache hash table entries: 32768 (order: 5,
131072 bytes)
Mar 29 19:19:55 toledo kernel: Inode-cache hash table entries: 16384 (order: 4,
65536 bytes)
Mar 29 19:19:55 toledo kernel: Memory: 186756k/196480k available (1682k kernel
code, 9144k reserved, 703k data, 172k init, 0k highmem)
Mar 29 19:19:55 toledo kernel: Checking if this processor honours the WP bit
even in supervisor mode... Ok.
Mar 29 19:19:55 toledo kernel: Security Framework v1.0.0 initialized
Mar 29 19:19:55 toledo kernel: SELinux:  Disabled at boot.
Mar 29 19:19:55 toledo kernel: Mount-cache hash table entries: 512 (order: 0,
4096 bytes)
Mar 29 19:19:55 toledo kernel: CPU: L1 I cache: 16K, L1 D cache: 16K
Mar 29 19:19:55 toledo kernel: CPU: L2 cache: 128K
Mar 29 19:19:55 toledo kernel: Intel machine check architecture supported.
Mar 29 19:19:55 toledo kernel: Intel machine check reporting enabled on CPU#0.
Mar 29 19:19:55 toledo kernel: CPU: Intel Celeron (Coppermine) stepping 03
Mar 29 19:19:55 toledo kernel: Enabling fast FPU save and restore... done.
Mar 29 19:19:55 toledo kernel: Enabling unmasked SIMD FPU exception support... done.
Mar 29 19:19:55 toledo kernel: Checking 'hlt' instruction... OK.
Mar 29 19:19:55 toledo kernel: checking if image is initramfs...it isn't (bad
gzip magic numbers); looks like an initrd
Mar 29 19:19:55 toledo kernel: Freeing initrd memory: 4596k freed
Mar 29 19:19:55 toledo kernel: NET: Registered protocol family 16
Mar 29 19:19:55 toledo kernel: PCI: PCI BIOS revision 2.10 entry at 0xfed9b,
last bus=21
Mar 29 19:19:55 toledo kernel: PCI: Using configuration type 1
Mar 29 19:19:55 toledo kernel: mtrr: v2.0 (20020519)
Mar 29 19:19:55 toledo kernel: ACPI: Subsystem revision 20041105
Mar 29 19:19:55 toledo kernel: ACPI: Interpreter disabled.
Mar 29 19:19:55 toledo kernel: Linux Plug and Play Support v0.97 (c) Adam Belay
Mar 29 19:19:55 toledo kernel: pnp: PnP ACPI: ACPI disable
Mar 29 19:19:55 toledo kernel: PnPBIOS: Scanning system for PnP BIOS support...
Mar 29 19:19:55 toledo kernel: PnPBIOS: Found PnP BIOS installation structure at
0xc00f9060
Mar 29 19:19:55 toledo kernel: PnPBIOS: PnP BIOS version 1.0, entry
0xf0000:0x94c5, dseg 0x0
Mar 29 19:19:55 toledo kernel: PnPBIOS: 14 nodes reported by PnP BIOS; 14
recorded by driver
Mar 29 19:19:55 toledo kernel: PCI: Probing PCI hardware
Mar 29 19:19:55 toledo kernel: PCI: Probing PCI hardware (bus 00)
Mar 29 19:19:55 toledo kernel: PCI: Using IRQ router PIIX/ICH [8086/7198] at
0000:00:07.0
Mar 29 19:19:55 toledo kernel: PCI: IRQ 0 for device 0000:00:0b.0 doesn't match
PIRQ mask - try pci=usepirqmask
Mar 29 19:19:55 toledo kernel: PCI: Found IRQ 11 for device 0000:00:0b.0
Mar 29 19:19:55 toledo kernel: PCI: IRQ 0 for device 0000:00:0b.1 doesn't match
PIRQ mask - try pci=usepirqmask
Mar 29 19:19:55 toledo kernel: PCI: Found IRQ 11 for device 0000:00:0b.1
Mar 29 19:19:55 toledo kernel: PCI: Sharing IRQ 11 with 0000:00:00.1
Mar 29 19:19:55 toledo kernel: VFS: Disk quotas dquot_6.5.1
Mar 29 19:19:55 toledo kernel: Dquot-cache hash table entries: 1024 (order 0,
4096 bytes)
Mar 29 19:19:55 toledo kernel: devfs: 2004-01-31 Richard Gooch
(rgooch@atnf.csiro.au)
Mar 29 19:19:55 toledo kernel: devfs: boot_options: 0x0
Mar 29 19:19:55 toledo kernel: Initializing Cryptographic API
Mar 29 19:19:55 toledo kernel: isapnp: Scanning for PnP cards...
Mar 29 19:19:55 toledo kernel: isapnp: No Plug & Play device found
Mar 29 19:19:55 toledo kernel: serio: i8042 AUX port at 0x60,0x64 irq 12
Mar 29 19:19:55 toledo kernel: serio: i8042 KBD port at 0x60,0x64 irq 1
Mar 29 19:19:55 toledo kernel: Serial: 8250/16550 driver $Revision: 1.90 $ 48
ports, IRQ sharing enabled
Mar 29 19:19:55 toledo kernel: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
Mar 29 19:19:55 toledo kernel: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
Mar 29 19:19:55 toledo kernel: io scheduler noop registered
Mar 29 19:19:55 toledo kernel: io scheduler anticipatory registered
Mar 29 19:19:55 toledo kernel: io scheduler deadline registered
Mar 29 19:19:55 toledo kernel: io scheduler cfq registered
Mar 29 19:19:55 toledo kernel: RAMDISK driver initialized: 16 RAM disks of 8192K
size 1024 blocksize
Mar 29 19:19:55 toledo kernel: input: AT Translated Set 2 keyboard on isa0060/serio0
Mar 29 19:19:55 toledo kernel: NET: Registered protocol family 2
Mar 29 19:19:55 toledo kernel: IP: routing cache hash table of 1024 buckets, 8Kbytes
Mar 29 19:19:55 toledo kernel: TCP: Hash tables configured (established 16384
bind 32768)
Mar 29 19:19:55 toledo kernel: NET: Registered protocol family 8
Mar 29 19:19:55 toledo kernel: NET: Registered protocol family 20
Mar 29 19:19:55 toledo kernel: RAMDISK: cramfs filesystem found at block 0
Mar 29 19:19:55 toledo kernel: RAMDISK: Loading 4596KiB [1 disk] into ram
disk...
|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^Hdone.
Mar 29 19:19:55 toledo kernel: VFS: Mounted root (cramfs filesystem) readonly.
Mar 29 19:19:55 toledo kernel: Freeing unused kernel memory: 172k freed
Mar 29 19:19:55 toledo kernel: vesafb: probe of vesafb0 failed with error -6
Mar 29 19:19:55 toledo kernel: NET: Registered protocol family 1
Mar 29 19:19:55 toledo kernel: Uniform Multi-Platform E-IDE driver Revision:
7.00alpha2
Mar 29 19:19:55 toledo kernel: ide: Assuming 33MHz system bus speed for PIO
modes; override with idebus=xx
Mar 29 19:19:55 toledo kernel: PIIX4: IDE controller at PCI slot 0000:00:07.1
Mar 29 19:19:55 toledo kernel: PIIX4: chipset revision 0
Mar 29 19:19:55 toledo kernel: PIIX4: not 100%% native mode: will probe irqs later
Mar 29 19:19:55 toledo kernel:     ide0: BM-DMA at 0xf870-0xf877, BIOS settings:
hda:DMA, hdb:pio
Mar 29 19:19:55 toledo kernel: hda: IBM-DJSA-210, ATA DISK drive
Mar 29 19:19:55 toledo kernel: elevator: using anticipatory as default io scheduler
Mar 29 19:19:55 toledo kernel: ide0 at 0x1f0-0x1f7,0x3f6 on irq 14
Mar 29 19:19:55 toledo kernel: hda: max request size: 128KiB
Mar 29 19:19:55 toledo kernel: hda: 19640880 sectors (10056 MB) w/384KiB Cache,
CHS=19485/16/63, UDMA(33)
Mar 29 19:19:55 toledo kernel:  /dev/ide/host0/bus0/target0/lun0: p1 p2 p3 < p5
p6 p7 >
Mar 29 19:19:55 toledo kernel: VFS: Can't find an ext2 filesystem on dev hda6.
Mar 29 19:19:55 toledo kernel: Unable to identify CD-ROM format.
Mar 29 19:19:55 toledo kernel: VFS: Can't find a valid FAT filesystem on dev hda6.
Mar 29 19:19:55 toledo kernel: ReiserFS: hda6: found reiserfs format "3.6" with
standard journal
Mar 29 19:19:55 toledo kernel: ReiserFS: hda6: using ordered data mode
Mar 29 19:19:55 toledo kernel: ReiserFS: hda6: journal params: device hda6, size
8192, journal first block 18, max trans len 1024, max batch 900, max commit age
30, max trans age 30
Mar 29 19:19:55 toledo kernel: ReiserFS: hda6: checking transaction log (hda6)
Mar 29 19:19:55 toledo kernel: ReiserFS: hda6: Using r5 hash to sort names
Mar 29 19:19:55 toledo kernel: Adding 297160k swap on /dev/hda5.  Priority:-1
extents:1
Mar 29 19:19:55 toledo kernel: Capability LSM initialized
Mar 29 19:19:55 toledo kernel: ReiserFS: hda2: found reiserfs format "3.6" with
standard journal
Mar 29 19:19:55 toledo kernel: ReiserFS: hda2: using ordered data mode
Mar 29 19:19:55 toledo kernel: ReiserFS: hda2: journal params: device hda2, size
8192, journal first block 18, max trans len 1024, max batch 900, max commit age
30, max trans age 30
Mar 29 19:19:55 toledo kernel: ReiserFS: hda2: checking transaction log (hda2)
Mar 29 19:19:55 toledo kernel: ReiserFS: hda2: Using r5 hash to sort names
Mar 29 19:19:55 toledo kernel: ReiserFS: hda7: found reiserfs format "3.6" with
standard journal
Mar 29 19:19:55 toledo kernel: ReiserFS: hda7: using ordered data mode
Mar 29 19:19:55 toledo kernel: ReiserFS: hda7: journal params: device hda7, size
8192, journal first block 18, max trans len 1024, max batch 900, max commit age
30, max trans age 30
Mar 29 19:19:55 toledo kernel: ReiserFS: hda7: checking transaction log (hda7)
Mar 29 19:19:55 toledo kernel: ReiserFS: hda7: Using r5 hash to sort names
Mar 29 19:19:55 toledo kernel: Linux Kernel Card Services
Mar 29 19:19:55 toledo kernel:   options:  [pci] [cardbus] [pm]
Mar 29 19:19:55 toledo kernel: PCI: Found IRQ 11 for device 0000:00:0b.0
Mar 29 19:19:55 toledo kernel: Yenta: CardBus bridge found at 0000:00:0b.0
[1179:0001]
Mar 29 19:19:55 toledo kernel: Yenta: ISA IRQ mask 0x0000, PCI irq 11
Mar 29 19:19:55 toledo kernel: Socket status: 30000011
Mar 29 19:19:55 toledo kernel: PCI: Found IRQ 11 for device 0000:00:0b.1
Mar 29 19:19:55 toledo kernel: PCI: Sharing IRQ 11 with 0000:00:00.1
Mar 29 19:19:55 toledo kernel: Yenta: CardBus bridge found at 0000:00:0b.1
[1179:0001]
Mar 29 19:19:55 toledo kernel: Yenta: ISA IRQ mask 0x0000, PCI irq 11
Mar 29 19:19:55 toledo kernel: Socket status: 30000007
Mar 29 19:19:55 toledo kernel: usbcore: registered new driver usbfs
Mar 29 19:19:55 toledo kernel: usbcore: registered new driver hub
Mar 29 19:19:55 toledo kernel: USB Universal Host Controller Interface driver v2.2
Mar 29 19:19:55 toledo kernel: PCI: Found IRQ 11 for device 0000:00:07.2
Mar 29 19:19:55 toledo kernel: PCI: Sharing IRQ 11 with 0000:00:02.0
Mar 29 19:19:55 toledo kernel: uhci_hcd 0000:00:07.2: Intel Corp. 82440MX USB
Universal Host Controller
Mar 29 19:19:55 toledo kernel: uhci_hcd 0000:00:07.2: irq 11, io base 0xf840
Mar 29 19:19:55 toledo kernel: uhci_hcd 0000:00:07.2: new USB bus registered,
assigned bus number 1
Mar 29 19:19:55 toledo kernel: hub 1-0:1.0: USB hub found
Mar 29 19:19:55 toledo kernel: hub 1-0:1.0: 2 ports detected
Mar 29 19:19:55 toledo kernel: usb 1-1: new full speed USB device using uhci_hcd
and address 2
Mar 29 19:19:55 toledo kernel: PCI: Found IRQ 11 for device 0000:00:00.1
Mar 29 19:19:55 toledo kernel: PCI: Sharing IRQ 11 with 0000:00:0b.1
Mar 29 19:19:55 toledo kernel: intel8x0_measure_ac97_clock: measured 49036 usecs
Mar 29 19:19:55 toledo kernel: intel8x0: clocking to 48000
Mar 29 19:19:55 toledo kernel: cdc_acm 1-1:1.8: ttyACM0: USB ACM device
Mar 29 19:19:55 toledo kernel: usbcore: registered new driver cdc_acm
Mar 29 19:19:55 toledo kernel: drivers/usb/class/cdc-acm.c: v0.23:USB Abstract
Control Model driver for USB modems and ISDN adapters
Mar 29 19:19:55 toledo kernel: piix4_smbus 0000:00:07.3: Found 0000:00:07.3 device
Mar 29 19:19:55 toledo kernel: NET: Registered protocol family 23
Mar 29 19:19:55 toledo kernel: PCI: Found IRQ 11 for device 0000:00:09.0
Mar 29 19:19:55 toledo kernel: PCI: Sharing IRQ 11 with 0000:00:04.0
Mar 29 19:19:55 toledo kernel: IrDA: Registered device irda0
Mar 29 19:19:55 toledo kernel: toshoboe: Using multiple tasks, version $Id:
donauboe.c V2.18 ven jan 10 03:14:16 2003$
Mar 29 19:19:55 toledo kernel: input: PC Speaker
Mar 29 19:19:55 toledo kernel: input: ImPS/2 Generic Wheel Mouse on isa0060/serio1
Mar 29 19:19:55 toledo kernel: ts: Compaq touchscreen protocol output
Mar 29 19:19:55 toledo kernel: Real Time Clock Driver v1.12
Mar 29 19:19:55 toledo kernel: mice: PS/2 mouse device common for all mice
Mar 29 19:19:55 toledo kernel: parport: PnPBIOS parport detected.
Mar 29 19:19:55 toledo kernel: parport0: PC-style at 0x378 (0x778), irq 7, dma 3
[PCSPP,TRISTATE,COMPAT,ECP,DMA]
Mar 29 19:19:55 toledo kernel: NET: Registered protocol family 17
Mar 29 19:20:00 toledo lpd[5255]: restarted
Mar 29 19:20:01 toledo kernel: cs: IO port probe 0x0100-0x04ff: excluding
0x4d0-0x4d7
Mar 29 19:20:01 toledo kernel: cs: IO port probe 0x0800-0x08ff: clean.
Mar 29 19:20:01 toledo kernel: cs: IO port probe 0x0c00-0x0cff: clean.
Mar 29 19:20:01 toledo kernel: cs: IO port probe 0x0a00-0x0aff: clean.
Mar 29 19:20:01 toledo kernel: cs: memory probe 0xa0000000-0xa0ffffff: clean.
Mar 29 19:20:03 toledo kernel: NET: Registered protocol family 10
Mar 29 19:20:03 toledo kernel: Disabled Privacy Extensions on device c032abe0(lo)
Mar 29 19:20:03 toledo kernel: IPv6 over IPv4 tunneling driver
Mar 29 19:20:04 toledo xfs: ignoring font path element
/usr/lib/X11/fonts/cyrillic/ (unreadable) 
Mar 29 19:20:04 toledo xfs: ignoring font path element /usr/lib/X11/fonts/CID
(unreadable) 
Mar 29 19:20:06 toledo kernel: eth%%d: autonegotiation failed; using 10mbs
Mar 29 19:20:06 toledo kernel: eth%%d: MII selected
Mar 29 19:20:06 toledo kernel: eth%%d: media 10BaseT, silicon revision 5
Mar 29 19:20:06 toledo kernel: eth0: Xircom: port 0x300, irq 11, hwaddr
00:10:A4:9E:AD:7D
Mar 29 19:20:06 toledo kernel: ttyS3 at I/O 0x2e8 (irq = 11) is a 16550A
Mar 29 19:20:08 toledo Xprt_64: No matching visual for __GLcontextMode with
visual class = 0 (32775), nplanes = 8
Mar 29 19:20:11 toledo kernel: eth0: autonegotiation failed; using 10mbs
Mar 29 19:20:11 toledo kernel: eth0: MII selected
Mar 29 19:20:11 toledo kernel: eth0: media 10BaseT, silicon revision 5
Mar 29 19:20:33 toledo gconfd (salva-5879): starting (version 2.8.1), pid 5879
user 'salva'
Mar 29 19:20:33 toledo gconfd (salva-5879): Resolved address
"xml:readonly:/etc/gconf/gconf.xml.mandatory" to a read-only configuration
source at position 0
Mar 29 19:20:33 toledo gconfd (salva-5879): Resolved address
"xml:readwrite:/home/salva/.gconf" to a writable configuration source at position 1
Mar 29 19:20:33 toledo gconfd (salva-5879): Resolved address
"xml:readonly:/etc/gconf/gconf.xml.defaults" to a read-only configuration source
at position 2
Mar 29 19:20:58 toledo gconfd (salva-5879): Resolved address
"xml:readwrite:/home/salva/.gconf" to a writable configuration source at position 0
Mar 29 19:21:37 toledo kernel: CSLIP: code copyright 1989 Regents of the
University of California
Mar 29 19:21:37 toledo kernel: PPP generic driver version 2.4.2
Mar 29 19:21:38 toledo pppd[6007]: pppd 2.4.2 started by root, uid 0
Mar 29 19:21:39 toledo chat[6041]: abort on (BUSY)
Mar 29 19:21:39 toledo chat[6041]: abort on (NO CARRIER)
Mar 29 19:21:39 toledo chat[6041]: abort on (VOICE)
Mar 29 19:21:39 toledo chat[6041]: abort on (NO DIALTONE)
Mar 29 19:21:39 toledo chat[6041]: send (ATZW2^M)
Mar 29 19:21:39 toledo chat[6041]: expect (OK)
Mar 29 19:22:24 toledo chat[6041]: alarm
Mar 29 19:22:24 toledo chat[6041]: Failed
Mar 29 19:22:25 toledo pppd[6007]: Exit.
Mar 29 19:22:29 toledo pppd[6069]: pppd 2.4.2 started by root, uid 0
Mar 29 19:22:30 toledo chat[6070]: abort on (BUSY)
Mar 29 19:22:30 toledo chat[6070]: abort on (NO CARRIER)
Mar 29 19:22:30 toledo chat[6070]: abort on (VOICE)
Mar 29 19:22:30 toledo chat[6070]: abort on (NO DIALTONE)
Mar 29 19:22:30 toledo chat[6070]: send (ATZW2^M)
Mar 29 19:22:30 toledo chat[6070]: expect (OK)
Mar 29 19:22:51 toledo kernel: usb 1-1: USB disconnect, address 2
Mar 29 19:22:51 toledo chat[6070]: warning: read() on stdin returned 0
Mar 29 19:22:51 toledo chat[6070]: Failed
Mar 29 19:22:51 toledo pppd[6069]: Hangup (SIGHUP)
Mar 29 19:22:52 toledo kernel: c01bb4e6
Mar 29 19:22:52 toledo kernel: PREEMPT 
Mar 29 19:22:52 toledo kernel: Modules linked in: ppp_generic slhc ipv6
serial_cs xirc2ps_cs pcmcia af_packet parport_pc parport mousedev rtc tsdev
psmouse evdev pcspkr donauboe irda crc_ccitt i2c_piix4 i2c_core cdc_acm
snd_intel8x0 snd_ac97_codec snd_pcm_oss snd_mixer_oss snd_pcm snd_timer snd
soundcore snd_page_alloc uhci_hcd usbcore yenta_socket pcmcia_core nls_iso8859_1
nls_cp437 capability commoncap ide_cd cdrom reiserfs vfat fat isofs ext2 ext3
jbd mbcache ide_generic siimage aec62xx trm290 alim15x3 hpt34x hpt366 ide_disk
cmd64x piix rz1000 slc90e66 generic cs5530 cs5520 sc1200 triflex atiixp
pdc202xx_old pdc202xx_new opti621 ns87415 cy82c693 amd74xx sis5513 via82cxxx
serverworks ide_core unix fbcon font bitblit vesafb cfbcopyarea cfbimgblt
cfbfillrect
Mar 29 19:22:52 toledo kernel: CPU:    0
Mar 29 19:22:52 toledo kernel: EIP:    0060:[get_kobj_path_length+38/64]    Not
tainted VLI
Mar 29 19:22:52 toledo kernel: EFLAGS: 00010246   (2.6.10-1-686) 
Mar 29 19:22:52 toledo kernel: EIP is at get_kobj_path_length+0x26/0x40
Mar 29 19:22:52 toledo kernel: eax: 00000000   ebx: 00000000   ecx: ffffffff  
edx: c12de0b8
Mar 29 19:22:52 toledo kernel: esi: 00000001   edi: 00000000   ebp: ffffffff  
esp: c5933d9c
Mar 29 19:22:52 toledo kernel: ds: 007b   es: 007b   ss: 0068
Mar 29 19:22:52 toledo kernel: Process pppd (pid: 6069, threadinfo=c5932000
task=c0e1a570)
Mar 29 19:22:52 toledo kernel: Stack: c0329ee0 c12de094 c97282f8 c12de0b8
c01bb57f c12de0b8 cafb8268 c01bba70 
Mar 29 19:22:52 toledo kernel:        caeaf6e8 c0329ee0 c12de094 c97282f8
c80d96ec c021b3ec c12de0b8 000000d0 
Mar 29 19:22:52 toledo kernel:        c0329ee0 c0329ec8 c5639c29 c97282e0
c01becc8 c5639c29 00000000 00000000 
Mar 29 19:22:52 toledo kernel: Call Trace:
Mar 29 19:22:52 toledo kernel:  [kobject_get_path+31/128] kobject_get_path+0x1f/0x80
Mar 29 19:22:52 toledo kernel:  [kobject_release+0/16] kobject_release+0x0/0x10
Mar 29 19:22:52 toledo kernel:  [class_hotplug+156/416] class_hotplug+0x9c/0x1a0
Mar 29 19:22:52 toledo kernel:  [vsprintf+40/48] vsprintf+0x28/0x30
Mar 29 19:22:52 toledo kernel:  [kobject_hotplug+695/768]
kobject_hotplug+0x2b7/0x300
Mar 29 19:22:52 toledo kernel:  [kobject_del+28/64] kobject_del+0x1c/0x40
Mar 29 19:22:52 toledo kernel:  [class_device_del+152/192]
class_device_del+0x98/0xc0
Mar 29 19:22:52 toledo kernel:  [class_device_unregister+19/48]
class_device_unregister+0x13/0x30
Mar 29 19:22:52 toledo kernel:  [pg0+210036027/1069863936]
acm_tty_close+0xcb/0x110 [cdc_acm]
Mar 29 19:22:52 toledo kernel:  [release_dev+1907/1936] release_dev+0x773/0x790
Mar 29 19:22:52 toledo kernel:  [do_page_fault+956/1502] do_page_fault+0x3bc/0x5de
Mar 29 19:22:52 toledo kernel:  [schedule_timeout+109/192]
schedule_timeout+0x6d/0xc0
Mar 29 19:22:52 toledo kernel:  [tty_release+20/32] tty_release+0x14/0x20
Mar 29 19:22:52 toledo kernel:  [__fput+286/304] __fput+0x11e/0x130
Mar 29 19:22:52 toledo kernel:  [filp_close+89/144] filp_close+0x59/0x90
Mar 29 19:22:52 toledo kernel:  [sys_close+97/160] sys_close+0x61/0xa0
Mar 29 19:22:52 toledo kernel:  [syscall_call+7/11] syscall_call+0x7/0xb
Mar 29 19:22:52 toledo kernel: Code: 90 8d 74 26 00 55 bd ff ff ff ff 57 56 be
01 00 00 00 53 8b 54 24 14 31 db 8d b6 00 00 00 00 8d bf 00 00 00 00 8b 3a 89 e9
89 d8 <f2> ae f7 d1 49 8b 52 24 8d 74 31 01 85 d2 75 ea 5b 89 f0 5e 5f 
Mar 29 19:23:20 toledo kernel:  <3>hub 1-0:1.0: connect-debounce failed, port 1
disabled
Comment 1 Nishanth Aravamudan 2005-04-01 11:09:40 UTC 
Can you try a kernel.org kernel? If not, please file this against debian's bug
system as well. If you do build a custom kernel (it's hard to help otherwise),
please attach .config used, lspci -vvv on boot and lsusb (before and after
switching off device, if possible).

Thanks,
Nish
Comment 2 Alexandre Pereira Nunes 2005-04-11 08:27:38 UTC 
Created attachment 4888 [details]
ksymooops for similar error

Here is a ksymoops report for a similar error. It's from 2.6.12-rc2 from
kernel.org, but the bug seems to be present on almost every 2.6 kernel i tried
since 2.6.8 (I didn't try older ones, and I didn't try 2.4.x).

In spite the kernel naming and being tainted, it's a original 2.6.12-rc2 I
compiled by myself, and the error is reproductible on any 2.6.11.x stock kernel
as well.
Comment 3 Alexandre Pereira Nunes 2005-04-11 08:30:44 UTC 
Created attachment 4889 [details]
2.6.12's .config

the .config for the previously reported kernel.
Comment 4 Alexandre Pereira Nunes 2005-04-11 08:37:49 UTC 
Created attachment 4890 [details]
lspci's output

lspci's output. I cannot do a lsusb right now, since usb is malfunctional after
the oops. I'm using a motorola v300 phone through usb cable, it's recognized as
an acm device. I had reports of other acm devices having the same misbehaviour
when disconnected while the tty device is in use as well, but I had no access
to test that. Feel free to ask more information, if I can help it.
Comment 5 Aleksey Nogin 2005-04-17 16:26:35 UTC 
This looks like a dup of bug 4407. 

I do not have permissions to mark it as a dup; reporter if you argee it's a dup,
please mark it so.
Comment 6 Salvador Fandino 2005-04-18 01:10:54 UTC 

*** This bug has been marked as a duplicate of 4407 ***