Bug 514918 - nm-modem-probe & BUG: unable to handle kernel NULL pointer dereference at ...
Summary: nm-modem-probe & BUG: unable to handle kernel NULL pointer dereference at ...
Keywords:
Status: CLOSED INSUFFICIENT_DATA
Alias: None
Product: Fedora
Classification: Fedora
Component: NetworkManager
Version: 11
Hardware: x86_64
OS: Linux
low
medium
Target Milestone: ---
Assignee: Dan Williams
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2009-07-31 14:16 UTC by Axel Thimm
Modified: 2010-06-10 04:57 UTC (History)
1 user (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2010-06-10 04:57:08 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)

Description Axel Thimm 2009-07-31 14:16:05 UTC
Description of problem:
I'm trying to attach a ZTE MF 636 USB modem to an up2date Fedora 11/x86_64 system.

The modem has a zerocd function, and the easiest way to switch it from 19d2:2000 (usb storage) to 19d2:0031 is to "eject sr1". But also usb_modemswitch and modem-modeswitch were used. They all trigger the same kernel BUG/oops when nm-modem-probe tries to setup the device

http://www.kerneloops.org/submitresult.php?number=589907
http://www.kerneloops.org/submitresult.php?number=590000
http://www.kerneloops.org/submitresult.php?number=590008
http://www.kerneloops.org/submitresult.php?number=590192

The actual position in the code seems to differ, as does the pointer address (sometimes (null) othertimes a true pointer address). From the last oops:

BUG: unable to handle kernel NULL pointer dereference at (null)
IP: [<(null)>] (null)
PGD 3a4ca067 PUD 3a4c8067 PMD 0 
Oops: 0010 [#1] SMP 
last sysfs file: /sys/devices/system/cpu/cpu0/cpufreq/scaling_cur_freq
CPU 0 
Modules linked in: option usbserial usb_storage fuse bridge stp llc bnep sco l2cap bluetooth sunrpc autofs4 tun ipv6 cpufreq_ondemand acpi_cpufreq freq_table dm_multipath uinput snd_hda_codec_realtek arc4 ecb snd_hda_intel snd_hda_codec rtl8187 snd_hwdep mac80211 snd_pcm iTCO_wdt 8139too serio_raw snd_timer 8139cp eeprom_93cx6 snd iTCO_vendor_support asus_laptop mii joydev cfg80211 soundcore snd_page_alloc i915 drm i2c_algo_bit i2c_core video output [last unloaded: microcode]
Pid: 3882, comm: nm-modem-probe Not tainted 2.6.29.6-213.fc11.x86_64 #1 Satellite L40
RIP: 0010:[<0000000000000000>]  [<(null)>] (null)
RSP: 0018:ffff88003a505c60  EFLAGS: 00010282
RAX: ffff88007f338280 RBX: ffff88007cdd7200 RCX: ffff88007cdd7200
RDX: 00000000fffffffe RSI: ffff88007cdd7200 RDI: ffff88007f338170
RBP: ffff88003a505ca8 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000022 R11: 0000000000000246 R12: ffff88007f338170
R13: 0000000000000000 R14: 00000000fffffffe R15: ffff88003a45c7e8
FS:  00007f74d65e16f0(0000) GS:ffffffff817b7000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000000000000 CR3: 000000003a41e000 CR4: 00000000000006e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process nm-modem-probe (pid: 3882, threadinfo ffff88003a504000, task ffff88003a4a2e00)
Stack:
 ffffffff8129f409 ffff88003a505cd8 ffff88007f338130 ffff88003a505c88
 ffff88007cdd7200 00000000fffffffe 0000000000000000 0000000000000282
 ffff88003a45c7e8 ffff88003a505cd8 ffffffff8129f5bd ffff88007cdd7200
Call Trace:
 [<ffffffff8129f409>] ? unlink1+0xd8/0xed
 [<ffffffff8129f5bd>] usb_hcd_unlink_urb+0x65/0x89
 [<ffffffff812a08a1>] usb_kill_urb+0x59/0xd1
 [<ffffffff813aaafb>] ? mutex_lock+0x27/0x38
 [<ffffffffa02e775c>] option_close+0xa0/0xd4 [option]
 [<ffffffffa02ddcd4>] serial_close+0x9d/0x156 [usbserial]
 [<ffffffff8122c43e>] tty_release_dev+0x198/0x49a
 [<ffffffff8105fbfa>] ? up_read+0xe/0x10
 [<ffffffff813ae74b>] ? do_page_fault+0x5fb/0x9e9
 [<ffffffff8122c75e>] tty_release+0x1e/0x29
 [<ffffffff810d60a0>] __fput+0xf9/0x1a0
 [<ffffffff810d6161>] fput+0x1a/0x1c
 [<ffffffff810d34a1>] filp_close+0x68/0x72
 [<ffffffff810d3557>] sys_close+0xac/0xea
 [<ffffffff8101133a>] system_call_fastpath+0x16/0x1b
Code:  Bad RIP value.
RIP  [<(null)>] (null)
 RSP <ffff88003a505c60>
CR2: 0000000000000000
---[ end trace b9015d92067fec05 ]---


Version-Release number of selected component (if applicable):
kernel-2.6.29.6-213.fc11.x86_64
NetworkManager-0.7.1-8.git20090708.fc11.x86_64

How reproducible:
100%

Steps to Reproduce:
1.plug in modem
2.eject sr1 or usb_modeswitch or /lib/udev/modem-modeswitch -v ...
3.
  
Actual results:
kerneloops
Expected results:
Normal 3g/gsm connect

Additional info:
The provider is Cosmote in Greece, one connection did succeed, NM asked for my PIN and indeed there was a short connection (but w/o a default route - I had to manually add it). But this was just once.

May be related to the kerneloopses reported in bug #507099 *after* the kernel errata was released.

Comment 1 Axel Thimm 2009-07-31 14:18:21 UTC
(In reply to comment #0)
> May be related to the kerneloopses reported in bug #507099 *after* the kernel
> errata was released.  

Sorry, bad cut and paste, the above bug was a duplicate of what I wanted to quote, the CLOSED-ERRATA bug where some more kerneloopses were posted is bug #500954.

Comment 2 Axel Thimm 2009-07-31 22:15:32 UTC
I also tried kernel 2.6.29.6-217.2.3.fc11.x86_64 but there wasn't any change. Just for statistics, here is a grep of all my oopses today:

kernel: BUG: unable to handle kernel NULL pointer dereference at 0000000000000049
kernel: BUG: unable to handle kernel paging request at 00007f70fe9ffb18
kernel: BUG: unable to handle kernel paging request at 0000000100000047
kernel: BUG: unable to handle kernel NULL pointer dereference at (null)
kernel: BUG: unable to handle kernel NULL pointer dereference at (null)
kernel: BUG: unable to handle kernel paging request at 0000000000001068
kernel: BUG: unable to handle kernel NULL pointer dereference at 0000000000000118
kernel: BUG: unable to handle kernel NULL pointer dereference at (null)
kernel: BUG: unable to handle kernel NULL pointer dereference at (null)
kernel: BUG: unable to handle kernel NULL pointer dereference at (null)
kernel: BUG: unable to handle kernel NULL pointer dereference at 000000000000004c
kernel: BUG: unable to handle kernel NULL pointer dereference at 0000000000000049
kernel: BUG: unable to handle kernel NULL pointer dereference at 0000000000000051
kernel: BUG: unable to handle kernel paging request at ffff88007ecacf50
kernel: BUG: unable to handle kernel paging request at ffff88015178a3c8
kernel: BUG: unable to handle kernel paging request at ffff88015178a37a
kernel: BUG: unable to handle kernel NULL pointer dereference at (null)
kernel: BUG: unable to handle kernel NULL pointer dereference at 000000000000004a
kernel: BUG: unable to handle kernel NULL pointer dereference at (null)
kernel: BUG: unable to handle kernel NULL pointer dereference at 000000000000004c
kernel: BUG: unable to handle kernel NULL pointer dereference at (null)
kernel: BUG: unable to handle kernel NULL pointer dereference at 0000000000000049
kernel: BUG: unable to handle kernel NULL pointer dereference at (null)
kernel: BUG: unable to handle kernel NULL pointer dereference at (null)
kernel: BUG: unable to handle kernel NULL pointer dereference at (null)
kernel: BUG: unable to handle kernel NULL pointer dereference at 0000000000000049
kernel: BUG: unable to handle kernel NULL pointer dereference at (null)
kernel: BUG: unable to handle kernel NULL pointer dereference at 0000000000000118

This problem seems to have affected Ubuntu as well:

http://ubuntuforums.org/showthread.php?p=7550364

The resolution was to upgrade to a 2.6.3x kernel. I wanted to give rawhide's kernel a go, but I get

error: Failed dependencies:
	rpmlib(PayloadIsXz) <= 5.2-1 is needed by kernel-2.6.31-0.112.rc4.git3.fc12.x86_64
	rpmlib(PayloadIsXz) <= 5.2-1 is needed by kernel-firmware-2.6.31-0.112.rc4.git3.fc12.noarch

due to rpm's compression changes. I wish there were a forward compatible rpm upgrade in F11.

Comment 3 Axel Thimm 2009-08-02 09:03:35 UTC
I now managed to install 2.6.31-0.112.rc4.git3.fc12.x86_64 on the F11/x86_64 system. Unfortunately the X server flashes and doesn't allow to use NetworkManager in GUI. But I tried on the console.

The result is that it doesn't oops, but still has a "general protection fault: 0000 [#1] SMP".

Aug  2 10:49:25 victor kernel: usb 2-1: new high speed USB device using ehci_hcd and address 2
Aug  2 10:49:25 victor kernel: usb 2-1: New USB device found, idVendor=19d2, idProduct=2000
Aug  2 10:49:25 victor kernel: usb 2-1: New USB device strings: Mfr=3, Product=2, SerialNumber=4
Aug  2 10:49:25 victor kernel: usb 2-1: Product: ZTE CDMA Technologies MSM
Aug  2 10:49:25 victor kernel: usb 2-1: Manufacturer: ZTE,Incorporated
Aug  2 10:49:25 victor kernel: usb 2-1: SerialNumber: 1234567890ABCDEF
Aug  2 10:49:25 victor kernel: usb 2-1: configuration #1 chosen from 1 choice
Aug  2 10:49:25 victor kernel: Initializing USB Mass Storage driver...
Aug  2 10:49:25 victor kernel: scsi5 : SCSI emulation for USB Mass Storage devices
Aug  2 10:49:25 victor kernel: usbcore: registered new interface driver usb-storage
Aug  2 10:49:25 victor kernel: USB Mass Storage support registered.
Aug  2 10:49:25 victor kernel: usbcore: registered new interface driver usbserial
Aug  2 10:49:25 victor kernel: USB Serial support registered for generic
Aug  2 10:49:25 victor kernel: usbcore: registered new interface driver usbserial_generic
Aug  2 10:49:25 victor kernel: usbserial: USB Serial Driver core
Aug  2 10:49:25 victor kernel: USB Serial support registered for GSM modem (1-port)
Aug  2 10:49:25 victor kernel: usbcore: registered new interface driver option
Aug  2 10:49:25 victor kernel: option: v0.7.2:USB Driver for GSM modems
Aug  2 10:49:30 victor kernel: scsi 5:0:0:0: CD-ROM            ZTE      USB SCSI CD-ROM  2.31 PQ: 0 ANSI: 2
Aug  2 10:49:30 victor kernel: sr1: scsi-1 drive
Aug  2 10:49:30 victor kernel: sr 5:0:0:0: Attached scsi generic sg2 type 5

"eject sr1"

Aug  2 10:50:52 victor kernel: usb 2-1: USB disconnect, address 2
Aug  2 10:50:56 victor kernel: usb 2-1: new high speed USB device using ehci_hcd and address 3
Aug  2 10:50:56 victor kernel: usb 2-1: New USB device found, idVendor=19d2, idProduct=0031
Aug  2 10:50:56 victor kernel: usb 2-1: New USB device strings: Mfr=3, Product=2, SerialNumber=4
Aug  2 10:50:56 victor kernel: usb 2-1: Product: ZTE CDMA Technologies MSM
Aug  2 10:50:56 victor kernel: usb 2-1: Manufacturer: ZTE,Incorporated
Aug  2 10:50:56 victor kernel: usb 2-1: SerialNumber: 1234567890ABCDEF
Aug  2 10:50:56 victor kernel: usb 2-1: configuration #1 chosen from 1 choice
Aug  2 10:50:57 victor kernel: option 2-1:1.0: GSM modem (1-port) converter detected
Aug  2 10:50:57 victor kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB0
Aug  2 10:50:57 victor kernel: option 2-1:1.1: GSM modem (1-port) converter detected
Aug  2 10:50:57 victor kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB1
Aug  2 10:50:57 victor kernel: scsi6 : SCSI emulation for USB Mass Storage devices
Aug  2 10:50:57 victor kernel: option 2-1:1.3: GSM modem (1-port) converter detected
Aug  2 10:50:57 victor kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB2
Aug  2 10:51:02 victor kernel: scsi 6:0:0:0: Direct-Access     ZTE      MMC Storage      2.31 PQ: 0 ANSI: 2
Aug  2 10:51:02 victor kernel: scsi 6:0:0:1: CD-ROM            ZTE      USB SCSI CD-ROM  2.31 PQ: 0 ANSI: 2
Aug  2 10:51:02 victor kernel: sd 6:0:0:0: Attached scsi generic sg2 type 0
Aug  2 10:51:02 victor kernel: sd 6:0:0:0: [sdb] Attached SCSI removable disk
Aug  2 10:51:05 victor kernel: option1 ttyUSB0: GSM modem (1-port) converter now disconnected from ttyUSB0
Aug  2 10:51:05 victor kernel: option 2-1:1.0: device disconnected
Aug  2 10:51:05 victor kernel: option1 ttyUSB1: GSM modem (1-port) converter now disconnected from ttyUSB1
Aug  2 10:51:05 victor kernel: option 2-1:1.1: device disconnected
Aug  2 10:51:05 victor kernel: option: option_instat_callback: error -108
Aug  2 10:51:05 victor kernel: option1 ttyUSB2: GSM modem (1-port) converter now disconnected from ttyUSB2
Aug  2 10:51:05 victor kernel: option 2-1:1.3: device disconnected
Aug  2 10:51:05 victor kernel: usb 2-1: reset high speed USB device using ehci_hcd and address 3
Aug  2 10:51:05 victor kernel: option 2-1:1.3: GSM modem (1-port) converter detected
Aug  2 10:51:05 victor kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB3
Aug  2 10:51:05 victor kernel: option 2-1:1.1: GSM modem (1-port) converter detected
Aug  2 10:51:05 victor kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB4
Aug  2 10:51:05 victor kernel: option 2-1:1.0: GSM modem (1-port) converter detected
Aug  2 10:51:05 victor kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB5
Aug  2 10:51:05 victor kernel: sr1: scsi-1 drive
Aug  2 10:51:05 victor kernel: sr 6:0:0:1: Attached scsi generic sg3 type 5
Aug  2 10:51:13 victor kernel: option1 ttyUSB5: GSM modem (1-port) converter now disconnected from ttyUSB5
Aug  2 10:51:13 victor kernel: option 2-1:1.0: device disconnected
Aug  2 10:51:13 victor kernel: option1 ttyUSB4: GSM modem (1-port) converter now disconnected from ttyUSB4
Aug  2 10:51:13 victor kernel: option 2-1:1.1: device disconnected
Aug  2 10:51:13 victor kernel: option: option_instat_callback: error -108
Aug  2 10:51:13 victor kernel: option1 ttyUSB3: GSM modem (1-port) converter now disconnected from ttyUSB3
Aug  2 10:51:13 victor kernel: option 2-1:1.3: device disconnected
Aug  2 10:51:13 victor kernel: usb 2-1: reset high speed USB device using ehci_hcd and address 3
Aug  2 10:51:14 victor kernel: option 2-1:1.3: GSM modem (1-port) converter detected
Aug  2 10:51:14 victor kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB0
Aug  2 10:51:14 victor kernel: option 2-1:1.1: GSM modem (1-port) converter detected
Aug  2 10:51:14 victor kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB1
Aug  2 10:51:14 victor kernel: option 2-1:1.0: GSM modem (1-port) converter detected
Aug  2 10:51:14 victor kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB2
Aug  2 10:51:16 victor NetworkManager: <WARN>  libudev_get_modem_capabilities(): couldn't inspect device '/sys/devices/pci0000:00/0000:00:1d.7/usb2/2-1/2-1:1.0/ttyUSB0/tty/ttyUSB0' with libudev
Aug  2 10:51:16 victor NetworkManager: <WARN>  modem_device_creator(): (ttyUSB0): udev probing failed; using only HAL modem capabilities.
Aug  2 10:51:16 victor NetworkManager: <info>  (ttyUSB0): ignoring due to lack of mobile broadband capabilties
Aug  2 10:51:16 victor NetworkManager: <info>  (ttyUSB1): ignoring due to lack of mobile broadband capabilties
Aug  2 10:51:21 victor kernel: option1 ttyUSB2: GSM modem (1-port) converter now disconnected from ttyUSB2
Aug  2 10:51:21 victor kernel: option 2-1:1.0: device disconnected
Aug  2 10:51:21 victor kernel: option1 ttyUSB1: GSM modem (1-port) converter now disconnected from ttyUSB1
Aug  2 10:51:21 victor kernel: option 2-1:1.1: device disconnected
Aug  2 10:51:21 victor kernel: option: option_instat_callback: error -108
Aug  2 10:51:21 victor kernel: option1 ttyUSB0: GSM modem (1-port) converter now disconnected from ttyUSB0
Aug  2 10:51:21 victor kernel: option 2-1:1.3: device disconnected
Aug  2 10:51:21 victor kernel: usb 2-1: reset high speed USB device using ehci_hcd and address 3
Aug  2 10:51:22 victor kernel: option 2-1:1.3: GSM modem (1-port) converter detected
Aug  2 10:51:22 victor kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB3
Aug  2 10:51:22 victor kernel: option 2-1:1.1: GSM modem (1-port) converter detected
Aug  2 10:51:22 victor kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB4
Aug  2 10:51:22 victor kernel: option 2-1:1.0: GSM modem (1-port) converter detected
Aug  2 10:51:22 victor kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB5
Aug  2 10:51:25 victor NetworkManager: <info>  (ttyUSB4): ignoring due to lack of mobile broadband capabilties
Aug  2 10:51:30 victor kernel: option1 ttyUSB5: GSM modem (1-port) converter now disconnected from ttyUSB5
Aug  2 10:51:30 victor kernel: option 2-1:1.0: device disconnected
Aug  2 10:51:30 victor kernel: option1 ttyUSB4: GSM modem (1-port) converter now disconnected from ttyUSB4
Aug  2 10:51:30 victor kernel: option 2-1:1.1: device disconnected
Aug  2 10:51:30 victor kernel: option: option_instat_callback: error -108
Aug  2 10:51:33 victor NetworkManager: <WARN>  libudev_get_modem_capabilities(): couldn't inspect device '/sys/devices/pci0000:00/0000:00:1d.7/usb2/2-1/2-1:1.3/ttyUSB0/tty/ttyUSB0' with libudev
Aug  2 10:51:33 victor NetworkManager: <WARN>  modem_device_creator(): (ttyUSB0): udev probing failed; using only HAL modem capabilities.
Aug  2 10:51:33 victor NetworkManager: <info>  (ttyUSB0): ignoring due to lack of mobile broadband capabilties
Aug  2 10:51:33 victor NetworkManager: <WARN>  libudev_get_modem_capabilities(): couldn't inspect device '/sys/devices/pci0000:00/0000:00:1d.7/usb2/2-1/2-1:1.0/ttyUSB2/tty/ttyUSB2' with libudev
Aug  2 10:51:33 victor NetworkManager: <WARN>  modem_device_creator(): (ttyUSB2): udev probing failed; using only HAL modem capabilities.
Aug  2 10:51:33 victor NetworkManager: <info>  (ttyUSB2): ignoring due to lack of mobile broadband capabilties
Aug  2 10:51:33 victor NetworkManager: <WARN>  libudev_get_modem_capabilities(): couldn't inspect device '/sys/devices/pci0000:00/0000:00:1d.7/usb2/2-1/2-1:1.1/ttyUSB1/tty/ttyUSB1' with libudev
Aug  2 10:51:33 victor NetworkManager: <WARN>  modem_device_creator(): (ttyUSB1): udev probing failed; using only HAL modem capabilities.
Aug  2 10:51:33 victor NetworkManager: <info>  (ttyUSB1): ignoring due to lack of mobile broadband capabilties
Aug  2 10:51:35 victor kernel: option1 ttyUSB3: GSM modem (1-port) converter now disconnected from ttyUSB3
Aug  2 10:51:35 victor kernel: option 2-1:1.3: device disconnected
Aug  2 10:51:35 victor kernel: usb 2-1: reset high speed USB device using ehci_hcd and address 3
Aug  2 10:51:35 victor kernel: option 2-1:1.3: GSM modem (1-port) converter detected
Aug  2 10:51:35 victor kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB0
Aug  2 10:51:35 victor kernel: option 2-1:1.1: GSM modem (1-port) converter detected
Aug  2 10:51:35 victor kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB1
Aug  2 10:51:35 victor kernel: option 2-1:1.0: GSM modem (1-port) converter detected
Aug  2 10:51:35 victor kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB2
Aug  2 10:51:43 victor kernel: option1 ttyUSB2: GSM modem (1-port) converter now disconnected from ttyUSB2
Aug  2 10:51:43 victor kernel: option 2-1:1.0: device disconnected
Aug  2 10:51:43 victor kernel: option1 ttyUSB1: GSM modem (1-port) converter now disconnected from ttyUSB1
Aug  2 10:51:43 victor kernel: option 2-1:1.1: device disconnected
Aug  2 10:51:43 victor kernel: option: option_instat_callback: error -108
Aug  2 10:51:43 victor kernel: option1 ttyUSB0: GSM modem (1-port) converter now disconnected from ttyUSB0
Aug  2 10:51:43 victor kernel: option 2-1:1.3: device disconnected
Aug  2 10:51:43 victor kernel: general protection fault: 0000 [#1] SMP 
Aug  2 10:51:43 victor kernel: last sysfs file: /sys/devices/pci0000:00/0000:00:1d.7/usb2/idVendor
Aug  2 10:51:43 victor kernel: CPU 0 
Aug  2 10:51:43 victor kernel: Modules linked in: option usbserial usb_storage bridge stp llc bnep sco l2cap bluetooth sunrpc autofs4 tun ipv6 cpufreq_ondemand acpi_cpufreq freq_table dm_multipath uinput snd_hda_codec_realtek snd_hda_intel arc4 ecb snd_hda_codec rtl8187 8139too snd_hwdep snd_pcm snd_timer mac80211 snd 8139cp eeprom_93cx6 serio_raw asus_laptop mii joydev iTCO_wdt cfg80211 iTCO_vendor_support soundcore rfkill snd_page_alloc i915 drm i2c_algo_bit i2c_core video output [last unloaded: microcode]
Aug  2 10:51:43 victor kernel: Pid: 9, comm: events/0 Not tainted 2.6.31-0.112.rc4.git3.fc12.x86_64 #1 Satellite L40
Aug  2 10:51:43 victor kernel: RIP: 0010:[<ffffffffa023579c>]  [<ffffffffa023579c>] serial_do_down+0x2e/0x7d [usbserial]
Aug  2 10:51:43 victor kernel: RSP: 0018:ffff88007c8f1cf0  EFLAGS: 00010202
Aug  2 10:51:43 victor kernel: RAX: 6b6b6b6b6b6b6b6b RBX: ffff8800661eeba8 RCX: 0000000000000106
Aug  2 10:51:43 victor kernel: RDX: 0000000000000000 RSI: ffff880050468000 RDI: ffff8800661eeba8
Aug  2 10:51:43 victor kernel: RBP: ffff88007c8f1d20 R08: ffff880050468170 R09: 000000006a18f030
Aug  2 10:51:43 victor kernel: R10: ffffffff81e00340 R11: 0000000000000000 R12: ffff8800504683f8
Aug  2 10:51:43 victor kernel: R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000246
Aug  2 10:51:43 victor kernel: FS:  0000000000000000(0000) GS:ffff88000267b000(0000) knlGS:0000000000000000
Aug  2 10:51:43 victor kernel: CS:  0010 DS: 0018 ES: 0018 CR0: 000000008005003b
Aug  2 10:51:43 victor kernel: CR2: 00007fbf0c6b1000 CR3: 000000006954c000 CR4: 00000000000006f0
Aug  2 10:51:43 victor kernel: DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Aug  2 10:51:43 victor kernel: DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Aug  2 10:51:43 victor kernel: Process events/0 (pid: 9, threadinfo ffff88007c8f0000, task ffff88007c8e8000)
Aug  2 10:51:43 victor kernel: Stack:
Aug  2 10:51:43 victor kernel: 0000000000000246 000000006a18f030 ffff88007c8f1d20 ffff8800661eeba8
Aug  2 10:51:43 victor kernel: <0> ffff8800504683f8 0000000000000000 ffff88007c8f1d50 ffffffffa0235817
Aug  2 10:51:43 victor kernel: <0> ffff880050468000 000000006a18f030 ffff880050468000 ffff880050468000
Aug  2 10:51:43 victor kernel: Call Trace:
Aug  2 10:51:43 victor kernel: [<ffffffffa0235817>] serial_hangup+0x2c/0x50 [usbserial]
Aug  2 10:51:43 victor kernel: [<ffffffff81313736>] do_tty_hangup+0x300/0x345
Aug  2 10:51:43 victor kernel: [<ffffffff81313436>] ? do_tty_hangup+0x0/0x345
Aug  2 10:51:43 victor kernel: [<ffffffff8107bb17>] worker_thread+0x222/0x33e
Aug  2 10:51:43 victor kernel: [<ffffffff8107bac2>] ? worker_thread+0x1cd/0x33e
Aug  2 10:51:43 victor kernel: [<ffffffff814f9947>] ? thread_return+0x4e/0xd3
Aug  2 10:51:43 victor kernel: [<ffffffff81081b0b>] ? autoremove_wake_function+0x0/0x5f
Aug  2 10:51:43 victor kernel: [<ffffffff8107b8f5>] ? worker_thread+0x0/0x33e
Aug  2 10:51:43 victor kernel: [<ffffffff810816bd>] kthread+0xa5/0xad
Aug  2 10:51:43 victor kernel: [<ffffffff8101412a>] child_rip+0xa/0x20
Aug  2 10:51:43 victor kernel: [<ffffffff81013a90>] ? restore_args+0x0/0x30
Aug  2 10:51:43 victor kernel: [<ffffffff81081618>] ? kthread+0x0/0xad
Aug  2 10:51:43 victor kernel: [<ffffffff81014120>] ? child_rip+0x0/0x20
Aug  2 10:51:43 victor kernel: Code: e5 41 55 41 54 53 48 83 ec 18 0f 1f 44 00 00 65 48 8b 04 25 28 00 00 00 48 89 45 d8 31 c0 80 bf b2 03 00 00 00 48 8b 07 48 89 fb <4c> 8b 68 08 75 2a 4c 8d a7 f8 01 00 00 31 f6 4c 89 e7 e8 78 52 
Aug  2 10:51:43 victor kernel: RIP  [<ffffffffa023579c>] serial_do_down+0x2e/0x7d [usbserial]
Aug  2 10:51:43 victor kernel: RSP <ffff88007c8f1cf0>
Aug  2 10:51:43 victor kernel: ---[ end trace f3a304ca6ac4cc6d ]---
Aug  2 10:51:43 victor kernel: usb 2-1: reset high speed USB device using ehci_hcd and address 3
Aug  2 10:51:44 victor kernel: option 2-1:1.3: GSM modem (1-port) converter detected
Aug  2 10:51:44 victor kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB0
Aug  2 10:51:44 victor kernel: option 2-1:1.1: GSM modem (1-port) converter detected
Aug  2 10:51:44 victor kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB3
Aug  2 10:51:44 victor kernel: option 2-1:1.0: GSM modem (1-port) converter detected
Aug  2 10:51:44 victor kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB4
Aug  2 10:51:46 victor NetworkManager: <WARN>  libudev_get_modem_capabilities(): couldn't inspect device '/sys/devices/pci0000:00/0000:00:1d.7/usb2/2-1/2-1:1.1/ttyUSB4/tty/ttyUSB4' with libudev
Aug  2 10:51:46 victor NetworkManager: <WARN>  modem_device_creator(): (ttyUSB4): udev probing failed; using only HAL modem capabilities.
Aug  2 10:51:46 victor NetworkManager: <info>  (ttyUSB4): ignoring due to lack of mobile broadband capabilties
Aug  2 10:51:51 victor kernel: option1 ttyUSB4: GSM modem (1-port) converter now disconnected from ttyUSB4
Aug  2 10:51:51 victor kernel: option 2-1:1.0: device disconnected
Aug  2 10:51:51 victor kernel: option1 ttyUSB3: GSM modem (1-port) converter now disconnected from ttyUSB3
Aug  2 10:51:51 victor kernel: option 2-1:1.1: device disconnected
Aug  2 10:51:51 victor kernel: option: option_instat_callback: error -108
Aug  2 10:51:51 victor kernel: option1 ttyUSB0: GSM modem (1-port) converter now disconnected from ttyUSB0
Aug  2 10:51:51 victor kernel: option 2-1:1.3: device disconnected
Aug  2 10:51:51 victor kernel: usb 2-1: reset high speed USB device using ehci_hcd and address 3
Aug  2 10:51:51 victor kernel: option 2-1:1.3: GSM modem (1-port) converter detected
Aug  2 10:51:51 victor kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB0
Aug  2 10:51:51 victor kernel: option 2-1:1.1: GSM modem (1-port) converter detected
Aug  2 10:51:51 victor kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB1
Aug  2 10:51:51 victor kernel: option 2-1:1.0: GSM modem (1-port) converter detected
Aug  2 10:51:51 victor kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB2
Aug  2 10:52:05 victor kernel: option1 ttyUSB2: GSM modem (1-port) converter now disconnected from ttyUSB2
Aug  2 10:52:05 victor kernel: option 2-1:1.0: device disconnected
Aug  2 10:52:05 victor kernel: option1 ttyUSB1: GSM modem (1-port) converter now disconnected from ttyUSB1
Aug  2 10:52:05 victor kernel: option 2-1:1.1: device disconnected
Aug  2 10:52:05 victor kernel: option: option_instat_callback: error -108
Aug  2 10:52:05 victor kernel: option1 ttyUSB0: GSM modem (1-port) converter now disconnected from ttyUSB0
Aug  2 10:52:05 victor kernel: option 2-1:1.3: device disconnected
Aug  2 10:52:05 victor kernel: usb 2-1: reset high speed USB device using ehci_hcd and address 3
Aug  2 10:52:05 victor kernel: option 2-1:1.3: GSM modem (1-port) converter detected
Aug  2 10:52:05 victor kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB0
Aug  2 10:52:05 victor kernel: option 2-1:1.1: GSM modem (1-port) converter detected
Aug  2 10:52:05 victor kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB1
Aug  2 10:52:05 victor kernel: option 2-1:1.0: GSM modem (1-port) converter detected
Aug  2 10:52:05 victor kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB2

Comment 4 Axel Thimm 2009-08-02 17:34:34 UTC
Analyzing the logs I think the only ever time the connection worked from kernel and NM side was when the SIM was still w/o a PIN. I was able to give the PIN through NM and there was a connection. Ever since the connection has been Oopsed in various ways.

I did use NM with the PIN-on-SIM fix (0.7.1-8.git20090708.fc11) from the very beginning.

I'm attaching the logs from the one and only working connection (using kernel-2.6.29.6-213.fc11.x86_64 and NetworkManager-0.7.1-8.git20090708.fc11.x86_64). The other remarkable difference is that in this session the reconnect to the modem only pulled an "MMC Storage" while all other (failing) sessions had a second "USB SCSI CD-ROM" pulled in as well. Not sure how this is connected, though.

Jul 31 16:10:20 victor kernel: usb 2-1: new high speed USB device using ehci_hcd and address 3
Jul 31 16:10:20 victor kernel: usb 2-1: New USB device found, idVendor=19d2, idProduct=2000
Jul 31 16:10:20 victor kernel: usb 2-1: New USB device strings: Mfr=3, Product=2, SerialNumber=4
Jul 31 16:10:20 victor kernel: usb 2-1: Product: ZTE CDMA Technologies MSM
Jul 31 16:10:20 victor kernel: usb 2-1: Manufacturer: ZTE,Incorporated
Jul 31 16:10:20 victor kernel: usb 2-1: SerialNumber: 1234567890ABCDEF
Jul 31 16:10:20 victor kernel: usb 2-1: configuration #1 chosen from 1 choice
Jul 31 16:10:21 victor kernel: Initializing USB Mass Storage driver...
Jul 31 16:10:21 victor kernel: scsi5 : SCSI emulation for USB Mass Storage devices
Jul 31 16:10:21 victor kernel: usbcore: registered new interface driver usb-storage
Jul 31 16:10:21 victor kernel: USB Mass Storage support registered.
Jul 31 16:10:21 victor kernel: usbcore: registered new interface driver usbserial
Jul 31 16:10:21 victor kernel: USB Serial support registered for generic
Jul 31 16:10:21 victor kernel: usbcore: registered new interface driver usbserial_generic
Jul 31 16:10:21 victor kernel: usbserial: USB Serial Driver core
Jul 31 16:10:21 victor kernel: USB Serial support registered for GSM modem (1-port)
Jul 31 16:10:21 victor kernel: usbcore: registered new interface driver option
Jul 31 16:10:21 victor kernel: option: v0.7.2:USB Driver for GSM modems
Jul 31 16:10:32 victor kernel: usb 2-1: reset high speed USB device using ehci_hcd and address 3
Jul 31 16:10:32 victor kernel: scsi 5:0:0:0: CD-ROM            ZTE      USB SCSI CD-ROM  2.31 PQ: 0 ANSI: 2
Jul 31 16:10:32 victor kernel: sr1: scsi-1 drive
Jul 31 16:10:32 victor kernel: sr 5:0:0:0: Attached scsi generic sg2 type 5
Jul 31 16:12:17 victor kernel: usbcore: deregistering interface driver option
Jul 31 16:12:17 victor kernel: USB Serial deregistering driver GSM modem (1-port)
Jul 31 16:12:18 victor kernel: usbcore: deregistering interface driver usbserial_generic
Jul 31 16:12:18 victor kernel: USB Serial deregistering driver generic
Jul 31 16:12:18 victor kernel: usbcore: deregistering interface driver usbserial
Jul 31 16:12:26 victor kernel: usbcore: registered new interface driver usbserial
Jul 31 16:12:26 victor kernel: USB Serial support registered for generic
Jul 31 16:12:26 victor kernel: usbcore: registered new interface driver usbserial_generic
Jul 31 16:12:26 victor kernel: usbserial: USB Serial Driver core
Jul 31 16:12:26 victor kernel: USB Serial support registered for GSM modem (1-port)
Jul 31 16:12:26 victor kernel: usbcore: registered new interface driver option
Jul 31 16:12:26 victor kernel: option: v0.7.2:USB Driver for GSM modems
Jul 31 16:13:21 victor gnome-keyring-daemon[2595]: adding removable location: volume_label_ZTEMODEM at /mnt
Jul 31 16:14:14 victor gnome-keyring-daemon[2595]: removing removable location: volume_label_ZTEMODEM
Jul 31 16:14:14 victor kernel: usb 2-1: USB disconnect, address 3
Jul 31 16:14:19 victor kernel: usb 2-1: new high speed USB device using ehci_hcd and address 4
Jul 31 16:14:19 victor kernel: usb 2-1: New USB device found, idVendor=19d2, idProduct=0031
Jul 31 16:14:19 victor kernel: usb 2-1: New USB device strings: Mfr=3, Product=2, SerialNumber=4
Jul 31 16:14:19 victor kernel: usb 2-1: Product: ZTE CDMA Technologies MSM
Jul 31 16:14:19 victor kernel: usb 2-1: Manufacturer: ZTE,Incorporated
Jul 31 16:14:19 victor kernel: usb 2-1: SerialNumber: 1234567890ABCDEF
Jul 31 16:14:19 victor kernel: usb 2-1: configuration #1 chosen from 1 choice
Jul 31 16:14:19 victor kernel: option 2-1:1.0: GSM modem (1-port) converter detected
Jul 31 16:14:19 victor kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB0
Jul 31 16:14:19 victor kernel: option 2-1:1.1: GSM modem (1-port) converter detected
Jul 31 16:14:19 victor kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB1
Jul 31 16:14:19 victor kernel: scsi6 : SCSI emulation for USB Mass Storage devices
Jul 31 16:14:19 victor kernel: option 2-1:1.3: GSM modem (1-port) converter detected
Jul 31 16:14:19 victor kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB2
Jul 31 16:14:25 victor kernel: scsi 6:0:0:0: Direct-Access     ZTE      MMC Storage      2.31 PQ: 0 ANSI: 2
Jul 31 16:14:25 victor kernel: sd 6:0:0:0: [sdb] Attached SCSI removable disk
Jul 31 16:14:25 victor kernel: sd 6:0:0:0: Attached scsi generic sg2 type 0
Jul 31 16:14:40 victor NetworkManager: <info>  (ttyUSB2): found serial port (udev:GSM  hal:)
Jul 31 16:14:40 victor NetworkManager: <info>  (ttyUSB2): deferring until all ports found
Jul 31 16:14:45 victor NetworkManager: <info>  Re-checking deferred serial ports
Jul 31 16:14:45 victor NetworkManager: <info>  (ttyUSB2): new Modem device (driver: 'option')
Jul 31 16:14:45 victor NetworkManager: <info>  (ttyUSB2): exported as /org/freedesktop/Hal/devices/usb_device_19d2_31_1234567890ABCDEF_if3_serial_usb_0
Jul 31 16:14:49 victor NetworkManager: <info>  (ttyUSB2): device state change: 1 -> 2 (reason 2)
Jul 31 16:14:49 victor NetworkManager: <info>  (ttyUSB2): deactivating device (reason: 2).
Jul 31 16:14:49 victor NetworkManager: <info>  (ttyUSB2): device state change: 2 -> 3 (reason 0)
Jul 31 16:15:36 victor NetworkManager: <info>  Activation (ttyUSB2) starting connection 'Cosmote Default'
Jul 31 16:15:36 victor NetworkManager: <info>  (ttyUSB2): device state change: 3 -> 4 (reason 0)
Jul 31 16:15:36 victor NetworkManager: <info>  Activation (ttyUSB2) Stage 1 of 5 (Device Prepare) scheduled...
Jul 31 16:15:36 victor NetworkManager: <info>  Activation (ttyUSB2) Stage 1 of 5 (Device Prepare) started...
Jul 31 16:15:36 victor NetworkManager: <info>  Activation (ttyUSB2) Stage 1 of 5 (Device Prepare) complete.
Jul 31 16:15:36 victor NetworkManager: <WARN>  init_done(): Trying alternate modem initialization (1)
Jul 31 16:15:38 victor NetworkManager: <WARN>  init_done(): Trying alternate modem initialization (2)
Jul 31 16:15:39 victor NetworkManager: <WARN>  init_done(): Trying alternate modem initialization (3)
Jul 31 16:15:40 victor NetworkManager: <WARN>  init_done(): Trying alternate modem initialization (4)
Jul 31 16:15:41 victor NetworkManager: <info>  (ttyUSB2): GSM pin secret required
Jul 31 16:15:41 victor NetworkManager: <info>  (ttyUSB2): device state change: 4 -> 6 (reason 0)
Jul 31 16:16:07 victor NetworkManager: <info>  Activation (ttyUSB2) Stage 1 of 5 (Device Prepare) scheduled...
Jul 31 16:16:07 victor NetworkManager: <info>  Activation (ttyUSB2) Stage 1 of 5 (Device Prepare) started...
Jul 31 16:16:07 victor NetworkManager: <info>  (ttyUSB2): device state change: 6 -> 4 (reason 0)
Jul 31 16:16:07 victor NetworkManager: <info>  Activation (ttyUSB2) Stage 1 of 5 (Device Prepare) complete.
Jul 31 16:16:07 victor gnome-keyring-daemon[2595]: couldn't allocate secure memory to keep passwords and or keys from being written to the disk
Jul 31 16:16:07 victor NetworkManager: <WARN>  init_done(): Trying alternate modem initialization (1)
Jul 31 16:16:09 victor NetworkManager: <WARN>  init_done(): Trying alternate modem initialization (2)
Jul 31 16:16:10 victor NetworkManager: <WARN>  init_done(): Trying alternate modem initialization (3)
Jul 31 16:16:11 victor NetworkManager: <WARN>  init_done(): Trying alternate modem initialization (4)
Jul 31 16:16:12 victor NetworkManager: <info>  (ttyUSB2): powering up...
Jul 31 16:16:12 victor NetworkManager: <info>  Searching for a network...
Jul 31 16:16:14 victor NetworkManager: <info>  Searching for a network...
Jul 31 16:16:15 victor NetworkManager: <info>  Searching for a network...
Jul 31 16:16:16 victor NetworkManager: <info>  Searching for a network...
Jul 31 16:16:17 victor NetworkManager: <info>  Searching for a network...
Jul 31 16:16:18 victor NetworkManager: <info>  Searching for a network...
Jul 31 16:16:19 victor NetworkManager: <info>  Searching for a network...
Jul 31 16:16:20 victor NetworkManager: <info>  Searching for a network...
Jul 31 16:16:21 victor NetworkManager: <info>  Registered on Home network
Jul 31 16:16:21 victor NetworkManager: <info>  Associated with network: +COPS: 0,1,"C-OTE",2
Jul 31 16:16:21 victor NetworkManager: <info>  Connected, Woo!
Jul 31 16:16:21 victor NetworkManager: <info>  Activation (ttyUSB2) Stage 2 of 5 (Device Configure) scheduled...
Jul 31 16:16:21 victor NetworkManager: <info>  Activation (ttyUSB2) Stage 2 of 5 (Device Configure) starting...
Jul 31 16:16:21 victor NetworkManager: <info>  (ttyUSB2): device state change: 4 -> 5 (reason 0)
Jul 31 16:16:21 victor NetworkManager: <info>  Starting pppd connection
Jul 31 16:16:21 victor NetworkManager: <info>  Activation (ttyUSB2) Stage 2 of 5 (Device Configure) complete.

Comment 5 Dan Williams 2009-11-07 05:27:15 UTC
Ouch, that's all pretty evil.  Before I punt to the kernel, could you try:

NetworkManager-0.7.1.998-1.fc11 has been pushed to the Fedora
11 testing repository.  If problems still persist, please make note of it in
this bug report.
 If you want to test the update, you can install it with 
 su -c 'yum --enablerepo=updates-testing update NetworkManager'.  You can provide feedback for this update
here: http://admin.fedoraproject.org/updates/F11/FEDORA-2009-10696  

Thanks!

Comment 6 Bug Zapper 2010-04-28 09:29:23 UTC
This message is a reminder that Fedora 11 is nearing its end of life.
Approximately 30 (thirty) days from now Fedora will stop maintaining
and issuing updates for Fedora 11.  It is Fedora's policy to close all
bug reports from releases that are no longer maintained.  At that time
this bug will be closed as WONTFIX if it remains open with a Fedora 
'version' of '11'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version prior to Fedora 11's end of life.

Bug Reporter: Thank you for reporting this issue and we are sorry that 
we may not be able to fix it before Fedora 11 is end of life.  If you 
would still like to see this bug fixed and are able to reproduce it 
against a later version of Fedora please change the 'version' of this 
bug to the applicable version.  If you are unable to change the version, 
please add a comment here and someone will do it for you.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events.  Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

The process we are following is described here: 
http://fedoraproject.org/wiki/BugZappers/HouseKeeping

Comment 7 Dan Williams 2010-06-10 04:57:08 UTC
Closing due to lack of a response... if you try updated kernels and still have the problem, please re-open this bug and we'll punt to the kernel.  There are some known issues in the 'option' kernel driver even in F13+ though...


Note You need to log in before you can comment on or make changes to this bug.