Bug 14499
| Summary: | USB serial regression after 2.6.31.1 with Huawei E220 GSM modem | ||
|---|---|---|---|
| Product: | Drivers | Reporter: | Iiro Rinta-Jouppi (irj) |
| Component: | USB | Assignee: | Alan Stern (stern) |
| Status: | CLOSED INVALID | ||
| Severity: | normal | CC: | arto.jarvinen, benh, damjan.jov, davidf, frederic, jejb, mmokrejs, pcirne.foruns, stern |
| Priority: | P1 | ||
| Hardware: | All | ||
| OS: | Linux | ||
| Kernel Version: | 2.6.31.2 ... 2.6.31-5 | Subsystem: | |
| Regression: | Yes | Bisected commit-id: | |
| Attachments: |
last known working kernel with E220
2.6.31.5 E220 going on/off/on/off got 2.6.31.5 working with rmmod usb_storage usbmon log file dmesg from 2.6.39.2 with Huawei E1823 Huawei1823-2.6.39.2.usbmon.log once it got briefly enough power - Huawei E1823 on 2.6.39.2 |
||
|
Description
Iiro Rinta-Jouppi
2009-10-28 14:32:49 UTC
Created attachment 23559 [details]
2.6.31.5 E220 going on/off/on/off
Created attachment 23560 [details]
got 2.6.31.5 working with rmmod usb_storage
This is fixed in 2.6.31.6. Hi Greg ! Do you have a pointer to the patch ? I couldn't find it ... my patch in .5 that fixes E169 doesn't seem to fix E220/E620 according to some ubuntu user reports. Same issue with E220: [ 4060.068051] usb 3-1: new full speed USB device using uhci_hcd and address 22 [ 4060.230258] usb 3-1: configuration #1 chosen from 1 choice [ 4060.237777] scsi134 : SCSI emulation for USB Mass Storage devices [ 4060.238017] usb-storage: device found at 22 [ 4060.238022] usb-storage: waiting for device to settle before scanning [ 4060.424127] usb 3-1: USB disconnect, address 22 [ 4061.160061] usb 3-1: new full speed USB device using uhci_hcd and address 23 [ 4061.323258] usb 3-1: configuration #1 chosen from 1 choice [ 4061.330765] option 3-1:1.0: GSM modem (1-port) converter detected [ 4061.330850] usb 3-1: GSM modem (1-port) converter now attached to ttyUSB0 [ 4061.333206] option 3-1:1.1: GSM modem (1-port) converter detected [ 4061.333274] usb 3-1: GSM modem (1-port) converter now attached to ttyUSB1 [ 4061.339421] scsi137 : SCSI emulation for USB Mass Storage devices [ 4061.351221] usb-storage: device found at 23 [ 4061.351225] usb-storage: waiting for device to settle before scanning [ 4066.350149] usb-storage: device scan complete [ 4066.354135] scsi 137:0:0:0: CD-ROM HUAWEI Mass Storage 2.31 PQ: 0 ANSI: 2 [ 4066.383094] sr1: scsi-1 drive [ 4066.383346] sr 137:0:0:0: Attached scsi CD-ROM sr1 [ 4066.383494] sr 137:0:0:0: Attached scsi generic sg2 type 5 [ 4077.753095] sr1: CDROM (ioctl) error, command: Get configuration 46 00 00 00 00 00 00 00 20 00 [ 4077.753122] sr: Sense Key : No Sense [current] [ 4077.753131] sr: Add. Sense: No additional sense information [ 4078.016109] sr1: CDROM (ioctl) error, command: Get configuration 46 00 00 00 00 00 00 00 20 00 [ 4078.016137] sr: Sense Key : No Sense [current] [ 4078.016146] sr: Add. Sense: No additional sense information [ 4078.155063] option: option_instat_callback: error -108 [ 4078.156301] option1 ttyUSB0: GSM modem (1-port) converter now disconnected from ttyUSB0 [ 4078.156324] option 3-1:1.0: device disconnected [ 4078.156388] option1 ttyUSB1: GSM modem (1-port) converter now disconnected from ttyUSB1 [ 4078.156405] option 3-1:1.1: device disconnected [ 4078.324045] usb 3-1: reset full speed USB device using uhci_hcd and address 23 [ 4078.471254] option 3-1:1.1: GSM modem (1-port) converter detected [ 4078.471417] usb 3-1: GSM modem (1-port) converter now attached to ttyUSB0 [ 4078.479115] option 3-1:1.0: GSM modem (1-port) converter detected [ 4078.479276] usb 3-1: GSM modem (1-port) converter now attached to ttyUSB1 [ 4078.876079] option: option_instat_callback: error -108 [ 4078.877639] option1 ttyUSB1: GSM modem (1-port) converter now disconnected from ttyUSB1 [ 4078.877683] option 3-1:1.0: device disconnected [ 4078.877796] option1 ttyUSB0: GSM modem (1-port) converter now disconnected from ttyUSB0 [ 4078.877827] option 3-1:1.1: device disconnected [ 4079.000069] usb 3-1: reset full speed USB device using uhci_hcd and address 23 [ 4079.124035] usb 3-1: device descriptor read/64, error -71 [ 4079.296744] usb 3-1: USB disconnect, address 23 cirne@cirne-laptop:/var/log$ lsusb Bus 002 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub Bus 003 Device 026: ID 12d1:1003 Huawei Technologies Co., Ltd. E220 HSDPA Modem / E270 HSDPA/HSUPA Modem Bus 003 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub Bus 004 Device 002: ID 044e:300c Alps Electric Co., Ltd Bluetooth Controller (ALPS/UGPZ6) Bus 004 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub Bus 005 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub cirne@cirne-laptop:/var/log$ uname -a Linux cirne-laptop 2.6.31-14-generic #48-Ubuntu SMP Fri Oct 16 14:04:26 UTC 2009 i686 GNU/Linux Where can we find a patch/fix for this? :) I can just confirm what Benjamin wrote in #4. The fix that got into 2.6.31.5 did not fix the E220 issue. As you can see from the logs I attached, the 2.6.31.1 was the last known working kernel for E220. The USB patch that got in 2.6.31.2 broke things and they still are not fixed in 2.6.31.5. I have tested it with other kernels in between, and they do not work either. I'll wait for 2.6.31.6... /Iiro None of the usbmon traces in the three attachments show anything useful because they monitored the wrong bus: They looked at bus 1 whereas the E220 device was on bus 3. Can we get another set of traces? Iiro, please do a log using the "0u" file which will capture everything, that's the easiest way to avoid that sort of confusion :-) Damn, I'm really sorry for the confusion. It seems that I was not careful enough. At the moment I am in another country than my E220, so unfortunately I can not test it further in couple of weeks. Ok so the launchpad bug https://bugs.launchpad.net/bugs/446146 has some more logs now. Specifically: http://launchpadlibrarian.net/35317354/dmesg-apw5.bz2 http://launchpadlibrarian.net/35317459/usbmon-apw5.bz2 should be logs done with ubuntu variant of 2.6.31.5 which shows the problem with the E220. This log shows a very different problem from before. To begin with, the E220's mass-storage interface declares itself as a cdrom instead of a disk drive. The host sends a command code 0x46, which the device doesn't understand. (I'm not too familiar with SCSI cdrom commands; according to the dmesg log 0x46 is GET CONFIGURATION.) Instead of telling the host it doesn't understand the command, which would be the right thing to do, the device replies with a failure indication and no sense data. That's what causes those ioctl error messages in the log. Then the host sends a MODE SENSE(10) command (0x5a) which the device apparently thinks it understands, but in fact it doesn't. Its reply is too long, leading the host to reset the device. This reset confuses the device and causes it to disconnect itself from the bus. That's the reason for all those disconnections. I don't know what is the source of these two commands. I suspect it is a user program rather than the kernel's CD driver, but this is just a guess. It might udev, hal, or even usb_modeswitch. Whichever it is, if the program can be prevented from sending these commands to the device then the problem should go away. Alternatively, maybe Huawei can provide a firmware update to fix these two issues, if somebody informs them about the problem. I have some doubts as to relying on a FW update from Huawei... I wonder what's the best approach to work around those. We could add more tweaks to the driver to make it more robust for things like mode sense(10) but I'm hesitant to put too many hacks that could potentially make it miss real errors. Or we could just blacklist the E220 from usb storage... we still want the magic quirk in initializers.c to run but it could be made to return an error. Now, of course, an additional problem is that I suspect a lot of those Huawei devices have the nasty habit of having the same vendorID/deviceID... we we may end up also black listing good ones which means losing the usage of the SD-card reader on them, but that's secondary to having the modem functionality I believe. I have some doubts as to relying on a FW update from Huawei... I wonder what's the best approach to work around those. We could add more tweaks to the driver to make it more robust for things like mode sense(10) but I'm hesitant to put too many hacks that could potentially make it miss real errors. Or we could just blacklist the E220 from usb storage... we still want the magic quirk in initializers.c to run but it could be made to return an error. Now, of course, an additional problem is that I suspect a lot of those Huawei devices have the nasty habit of having the same vendorID/deviceID... we we may end up also black listing good ones which means losing the usage of the SD-card reader on them, but that's secondary to having the modem functionality I believe. James, I added you on CC as SCSI maintainer. The problem we have here is that those SCSI protocol "bugs" in the modem are causing the SCSI stack to send host resets which we then turn into USB resets, which have the effect of disrupting the modem side of the device as well, essentially preventing it from working. It looks like a lot of those Huawei things have differently broken mass storage firmware (see the E169 with its incorrect sense length), but this one seems to be a bit more nasty. Should we ignore incorrect length (or add a quirk for that specific value of incorrect length ?) on mode sense (10) as a workaround ? Or something else ? I like avoiding device specific quirks (ie, I prefer making the code generally more robust to deal with that sort of issues which is how we fixed the other sense issues of the E169 models) but this looks a bit "edgy". Actually, James, I wonder ... should we create a new error policy for that sort of device (maybe triggered by usb-storage in general or by usb-storage when faced with a multi-function device, or even via a quirk list) that simply avoids resets on such errors ? IE, just error out the command, but don't reset the device... What do you think ? The resets in question aren't initiated by the SCSI core. They come directly from usb-storage; it always resets a device when certain types of protocol violation occur. Oliver Neukum has suggested adding a USB quirks flag to mark devices which should not be reset during error recovery. In theory this would help. It would leave the modem's mass-storage interface unusable, but that's no worse than it is right now. Alternatively, instead of blacklisting all the Huawei modems from usb-storage, we could reject just the devices which present as cdrom drives. In the end, it really would be best to update the firmware. I don't know why Huawei has so much trouble obeying the restrictions of the USB mass-storage protocol. Why not doing the reset in this case would make usb-storage unuseable ? In the above case, can't we just return some kind of transport error to the initiator in user space and move on ? IE. The kernel CD-ROM driver would probably still work. We can (and do) return a transport error to the initiator. But without the reset we can't move on -- the protocol violation means that we have lost proper framing and so we can't communicate with the device. Thus it is unusable. In theory, we could restore proper framing by polling the device repeatedly and waiting until it stops sending data. This would be clumsy and time consuming, but it might sometimes work. Maybe. Hrm... that sucks... We can also try a quirk to blacklist those two commands (especially the MODE_SENSE(10) I suppose...) And then what about the next device, which will mess up on a different set of commands? And the device after that? This way madness lies... I still think there's a good chance the Huawei people can fix their firmware. They've done it before. Yeah, possibly. But in the meantime, we still have a regression on our hands and quite a lot of users who cannot use their modems anymore. My attempts at contacting Huawei have not yet been successful. So what do we do ? We could hack back the initializer for these in USB storage to make probing of storage fail, which would bring us back to the 2.6.31.1 situation I suppose, which means no storage but at least a working modem. Some people would complain that it reverts the support for the micro-SD reader that worked for the E169 and E620 models (the one we fixed with the sense retry patch) but I don't see that as being a big deal. What do you reckon ? At the moment I don't see much of an alternative. If Fangxiao Zhi gets annoyed then maybe he'll be motivated to get the firmware fixed. I suppose the initializer could send an INQUIRY command to determine whether the device claims to be a hard drive or a cdrom, and make probing succeed for one but not the other. But that's a brittle sort of heuristic. So I got in touch with Franko Fang from Huawei. Unfortunately, he cannot post to this bugzilla entry, but he asked that we provide the FW version of the problematic E220 modems. - Boot with a kernel where the modem works (ie, you -do- get a /dev/ttyUSB0 created) - open it with minicom - type the AT command "ati" <return> - tell us the modem response For example, my E169 says: ati Manufacturer: huawei Model: E169 Revision: 11.314.17.00.261 IMEI: 358109021939159 +GCAP: +CGSM,+DS,+ES My affected Huawei E220 says this: Manufacturer: huawei Model: E220 Revision: 11.110.05.00.00 IMEI: 358191017694576 +GCAP: +CGSM,+DS,+ES The question is: how does Windows probe it so it never breaks? Manufacturer: huawei Model: E220 Revision: 11.117.09.01.56 IMEI: 358954001901277 +GCAP: +CGSM,+DS,+ES The network manager always tells me that I get connected but most of the time I don't get a nameserver, like so: arto@Sectra:~$ cat /etc/resolv.conf # Generated by NetworkManager When I unplug and plug in the modem again, I sometimes actually get a nameserver, like this: arto@Sectra:~$ cat /etc/resolv.conf # Generated by NetworkManager nameserver 130.244.127.161 nameserver 130.244.127.169 This is still present on Ubuntu 10.04 with its 2.6.32 kernel.
The crashes/resets seem to come from user-space interaction with the device, not from something the kernel does automatically. In particular, killing devkit-power daemon and devkit-disks-daemon on Ubuntu 9.10, and killing udisks-daemon on Ubuntu 10.04, stops the crashes.
Blacklisting the E220 from udisks-daemon by adding ENV{UDISKS_DISABLE_POLLING}="1", ENV{UDISKS_PRESENTATION_NOPOLICY}="1" to the udev rule for the E220 (then reboot before testing) seems to work as well.
See https://bugs.launchpad.net/ubuntu/+source/linux/+bug/446146/comments/260 and https://bugs.launchpad.net/ubuntu/+source/linux/+bug/449394/comments/68 for more details.
Can someone else test these workarounds? If they work, maybe this bug should be worked around in user-space.
On Mon, 3 May 2010 bugzilla-daemon@bugzilla.kernel.org wrote: > The crashes/resets seem to come from user-space interaction with the device, > not from something the kernel does automatically. In particular, killing > devkit-power daemon and devkit-disks-daemon on Ubuntu 9.10, and killing > udisks-daemon on Ubuntu 10.04, stops the crashes. It would help to know exactly what causes the device to fail. You wrote that running "udisks --enumerate" is enough to do it. Can you capture a usbmon trace showing this, and attach it to this bug report? If this allows us to identify a flaw in the Huawei firmware, the manufacturer may be able to fix it with a firmware update. Alan Stern Hi, I have the same connection problem, since some months I can not connect to the Internet with Gnome and NetworkManager, I use LXDE and NetworkManager. I opened several bug report in Debian, Linux and Gnome: http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=563551 https://bugzilla.kernel.org/show_bug.cgi?id=15650 https://bugzilla.gnome.org/show_bug.cgi?id=617454 Others are the same problem: http://www.draisberghof.de/usb_modeswitch/bb/viewtopic.php?p=2036#2036 I tested the method of Damjan Jovanovic by killing devkit-disks-daemon (Debian package devicekit-disks 009-3). Below the logs before killing devkit-disks-daemon, the connection fails: May 9 16:48:18 cthulhu kernel: usb 5-2: new full speed USB device using uhci_hcd and address 5 May 9 16:48:19 cthulhu kernel: usb 5-2: New USB device found, idVendor=12d1, idProduct=1003 May 9 16:48:19 cthulhu kernel: usb 5-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0 May 9 16:48:19 cthulhu kernel: usb 5-2: Product: HUAWEI Mobile May 9 16:48:19 cthulhu kernel: usb 5-2: Manufacturer: HUAWEI Technologies May 9 16:48:19 cthulhu kernel: scsi12 : usb-storage 5-2:1.0 May 9 16:48:19 cthulhu kernel: usb 5-2: USB disconnect, address 5 May 9 16:48:19 cthulhu kernel: usb 5-2: new full speed USB device using uhci_hcd and address 6 May 9 16:48:19 cthulhu kernel: usb 5-2: New USB device found, idVendor=12d1, idProduct=1003 May 9 16:48:19 cthulhu kernel: usb 5-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0 May 9 16:48:19 cthulhu kernel: usb 5-2: Product: HUAWEI Mobile May 9 16:48:19 cthulhu kernel: usb 5-2: Manufacturer: HUAWEI Technologies May 9 16:48:19 cthulhu kernel: option 5-2:1.0: GSM modem (1-port) converter detected May 9 16:48:19 cthulhu kernel: usb 5-2: GSM modem (1-port) converter now attached to ttyUSB0 May 9 16:48:19 cthulhu kernel: option 5-2:1.1: GSM modem (1-port) converter detected May 9 16:48:19 cthulhu kernel: usb 5-2: GSM modem (1-port) converter now attached to ttyUSB1 May 9 16:48:19 cthulhu kernel: scsi15 : usb-storage 5-2:1.2 May 9 16:48:20 cthulhu modem-manager: (Huawei): (ttyUSB1) deferring support check May 9 16:48:20 cthulhu modem-manager: (ttyUSB0) opening serial device... May 9 16:48:20 cthulhu modem-manager: (ttyUSB0): probe requested by plugin 'Huawei' May 9 16:48:23 cthulhu modem-manager: (ttyUSB1): re-checking support... May 9 16:48:23 cthulhu modem-manager: (Huawei): (ttyUSB1) deferring support check May 9 16:48:24 cthulhu kernel: scsi 15:0:0:0: CD-ROM HUAWEI Mass Storage 2.31 PQ: 0 ANSI: 2 May 9 16:48:24 cthulhu kernel: sr2: scsi-1 drive May 9 16:48:24 cthulhu kernel: sr 15:0:0:0: Attached scsi CD-ROM sr2 May 9 16:48:24 cthulhu kernel: sr 15:0:0:0: Attached scsi generic sg3 type 5 May 9 16:48:26 cthulhu modem-manager: (ttyUSB1): re-checking support... May 9 16:48:26 cthulhu modem-manager: (Huawei): (ttyUSB1) deferring support check May 9 16:48:29 cthulhu modem-manager: (ttyUSB1): re-checking support... May 9 16:48:29 cthulhu modem-manager: (Huawei): (ttyUSB1) deferring support check May 9 16:48:32 cthulhu modem-manager: (ttyUSB1): re-checking support... May 9 16:48:32 cthulhu modem-manager: (Huawei): (ttyUSB1) deferring support check May 9 16:48:32 cthulhu modem-manager: (ttyUSB0) closing serial device... May 9 16:48:32 cthulhu modem-manager: (Huawei): GSM modem /sys/devices/pci0000:00/0000:00:1d.0/usb5/5-2 claimed port ttyUSB0 May 9 16:48:32 cthulhu modem-manager: Added modem /sys/devices/pci0000:00/0000:00:1d.0/usb5/5-2 May 9 16:48:32 cthulhu modem-manager: Exported modem /sys/devices/pci0000:00/0000:00:1d.0/usb5/5-2 as /org/freedesktop/ModemManager/Modems/1 May 9 16:48:32 cthulhu NetworkManager: <info> (ttyUSB0): new GSM device (driver: 'option1') May 9 16:48:32 cthulhu NetworkManager: <info> (ttyUSB0): exported as /org/freedesktop/NetworkManager/Devices/3 May 9 16:48:32 cthulhu NetworkManager: <info> (ttyUSB0): now managed May 9 16:48:32 cthulhu NetworkManager: <info> (ttyUSB0): device state change: 1 -> 2 (reason 2) May 9 16:48:32 cthulhu NetworkManager: <info> (ttyUSB0): deactivating device (reason: 2). May 9 16:48:32 cthulhu NetworkManager: <info> (ttyUSB0): device state change: 2 -> 3 (reason 0) May 9 16:48:32 cthulhu NetworkManager: <info> Activation (ttyUSB0) starting connection 'Connexion GSM SFR' May 9 16:48:32 cthulhu NetworkManager: <info> (ttyUSB0): device state change: 3 -> 4 (reason 0) May 9 16:48:32 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled... May 9 16:48:32 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started... May 9 16:48:32 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete. May 9 16:48:32 cthulhu modem-manager: (ttyUSB0) opening serial device... May 9 16:48:32 cthulhu modem-manager: Modem /org/freedesktop/ModemManager/Modems/1: state changed (disabled -> enabling) May 9 16:48:32 cthulhu modem-manager: Got failure code 11: SIM PIN required May 9 16:48:32 cthulhu modem-manager: Modem /org/freedesktop/ModemManager/Modems/1: state changed (enabling -> enabled) May 9 16:48:32 cthulhu modem-manager: Registration state changed: 2 May 9 16:48:32 cthulhu modem-manager: Modem /org/freedesktop/ModemManager/Modems/1: state changed (enabled -> searching) May 9 16:48:34 cthulhu kernel: sr2: CDROM (ioctl) error, command: cdb[0]=0x51 51 00 00 00 00 00 00 00 02 00 May 9 16:48:34 cthulhu kernel: sr: Sense Key : 0x4 [current] May 9 16:48:34 cthulhu kernel: sr: ASC=0x0 ASCQ=0x0 May 9 16:48:34 cthulhu kernel: sr2: CDROM (ioctl) error, command: cdb[0]=0x46 46 00 00 00 00 00 00 00 20 00 May 9 16:48:34 cthulhu kernel: sr: Sense Key : 0x4 [current] May 9 16:48:34 cthulhu kernel: sr: ASC=0x0 ASCQ=0x0 May 9 16:48:34 cthulhu kernel: sr2: CDROM (ioctl) error, command: cdb[0]=0x46 46 00 00 00 00 00 00 00 20 00 May 9 16:48:34 cthulhu kernel: sr: Sense Key : 0x4 [current] May 9 16:48:34 cthulhu kernel: sr: ASC=0x0 ASCQ=0x0 May 9 16:48:34 cthulhu kernel: sr2: CDROM (ioctl) error, command: cdb[0]=0x46 46 00 00 00 00 00 00 00 20 00 May 9 16:48:34 cthulhu kernel: sr: Sense Key : 0x4 [current] May 9 16:48:34 cthulhu kernel: sr: ASC=0x0 ASCQ=0x0 May 9 16:48:34 cthulhu kernel: option: option_instat_callback: error -108 May 9 16:48:34 cthulhu modem-manager: (ttyUSB0) closing serial device... May 9 16:48:34 cthulhu kernel: option1 ttyUSB0: GSM modem (1-port) converter now disconnected from ttyUSB0 May 9 16:48:34 cthulhu kernel: option 5-2:1.0: device disconnected May 9 16:48:34 cthulhu kernel: option1 ttyUSB1: GSM modem (1-port) converter now disconnected from ttyUSB1 May 9 16:48:34 cthulhu kernel: option 5-2:1.1: device disconnected May 9 16:48:34 cthulhu modem-manager: Modem /org/freedesktop/ModemManager/Modems/1: state changed (searching -> disabled) May 9 16:48:34 cthulhu modem-manager: Removed modem /sys/devices/pci0000:00/0000:00:1d.0/usb5/5-2 May 9 16:48:34 cthulhu modem-manager: mm_callback_info_schedule: assertion `info->pending_id == 0' failed May 9 16:48:34 cthulhu NetworkManager: <info> (ttyUSB0): now unmanaged May 9 16:48:34 cthulhu NetworkManager: <info> (ttyUSB0): device state change: 4 -> 1 (reason 36) May 9 16:48:34 cthulhu NetworkManager: <info> (ttyUSB0): deactivating device (reason: 36). May 9 16:48:34 cthulhu modem-manager: mm_callback_info_schedule: assertion `info->called == FALSE' failed May 9 16:48:34 cthulhu NetworkManager: <info> (ttyUSB0): cleaning up... May 9 16:48:34 cthulhu NetworkManager: <info> (ttyUSB0): taking down device. May 9 16:48:34 cthulhu kernel: usb 5-2: reset full speed USB device using uhci_hcd and address 6 May 9 16:48:35 cthulhu kernel: usb 5-2: reset full speed USB device using uhci_hcd and address 6 May 9 16:48:35 cthulhu kernel: usb 5-2: device descriptor read/64, error -71 May 9 16:48:35 cthulhu kernel: usb 5-2: USB disconnect, address 6 May 9 16:48:35 cthulhu kernel: scsi 15:0:0:0: rejecting I/O to dead device May 9 16:48:35 cthulhu kernel: scsi 15:0:0:0: rejecting I/O to dead device Below the logs after killing devkit-disks-daemon, the connection succeeded: May 9 16:49:53 cthulhu kernel: usb 5-2: new full speed USB device using uhci_hcd and address 7 May 9 16:49:53 cthulhu kernel: usb 5-2: New USB device found, idVendor=12d1, idProduct=1003 May 9 16:49:53 cthulhu kernel: usb 5-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0 May 9 16:49:53 cthulhu kernel: usb 5-2: Product: HUAWEI Mobile May 9 16:49:53 cthulhu kernel: usb 5-2: Manufacturer: HUAWEI Technologies May 9 16:49:53 cthulhu kernel: scsi16 : usb-storage 5-2:1.0 May 9 16:49:53 cthulhu kernel: usb 5-2: USB disconnect, address 7 May 9 16:49:54 cthulhu kernel: usb 5-2: new full speed USB device using uhci_hcd and address 8 May 9 16:49:54 cthulhu kernel: usb 5-2: New USB device found, idVendor=12d1, idProduct=1003 May 9 16:49:54 cthulhu kernel: usb 5-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0 May 9 16:49:54 cthulhu kernel: usb 5-2: Product: HUAWEI Mobile May 9 16:49:54 cthulhu kernel: usb 5-2: Manufacturer: HUAWEI Technologies May 9 16:49:54 cthulhu kernel: option 5-2:1.0: GSM modem (1-port) converter detected May 9 16:49:54 cthulhu kernel: usb 5-2: GSM modem (1-port) converter now attached to ttyUSB0 May 9 16:49:54 cthulhu kernel: option 5-2:1.1: GSM modem (1-port) converter detected May 9 16:49:54 cthulhu kernel: usb 5-2: GSM modem (1-port) converter now attached to ttyUSB1 May 9 16:49:54 cthulhu kernel: scsi19 : usb-storage 5-2:1.2 May 9 16:49:54 cthulhu modem-manager: (Huawei): (ttyUSB1) deferring support check May 9 16:49:54 cthulhu modem-manager: (ttyUSB0) opening serial device... May 9 16:49:54 cthulhu modem-manager: (ttyUSB0): probe requested by plugin 'Huawei' May 9 16:49:57 cthulhu modem-manager: (ttyUSB1): re-checking support... May 9 16:49:57 cthulhu modem-manager: (Huawei): (ttyUSB1) deferring support check May 9 16:49:59 cthulhu kernel: scsi 19:0:0:0: CD-ROM HUAWEI Mass Storage 2.31 PQ: 0 ANSI: 2 May 9 16:49:59 cthulhu kernel: sr2: scsi-1 drive May 9 16:49:59 cthulhu kernel: sr 19:0:0:0: Attached scsi CD-ROM sr2 May 9 16:49:59 cthulhu kernel: sr 19:0:0:0: Attached scsi generic sg3 type 5 May 9 16:50:00 cthulhu modem-manager: (ttyUSB1): re-checking support... May 9 16:50:00 cthulhu modem-manager: (Huawei): (ttyUSB1) deferring support check May 9 16:50:03 cthulhu modem-manager: (ttyUSB1): re-checking support... May 9 16:50:03 cthulhu modem-manager: (Huawei): (ttyUSB1) deferring support check May 9 16:50:06 cthulhu modem-manager: (ttyUSB1): re-checking support... May 9 16:50:06 cthulhu modem-manager: (Huawei): (ttyUSB1) deferring support check May 9 16:50:07 cthulhu modem-manager: (ttyUSB0) closing serial device... May 9 16:50:07 cthulhu modem-manager: (Huawei): GSM modem /sys/devices/pci0000:00/0000:00:1d.0/usb5/5-2 claimed port ttyUSB0 May 9 16:50:07 cthulhu modem-manager: Added modem /sys/devices/pci0000:00/0000:00:1d.0/usb5/5-2 May 9 16:50:07 cthulhu modem-manager: Exported modem /sys/devices/pci0000:00/0000:00:1d.0/usb5/5-2 as /org/freedesktop/ModemManager/Modems/2 May 9 16:50:07 cthulhu NetworkManager: <info> (ttyUSB0): new GSM device (driver: 'option1') May 9 16:50:07 cthulhu NetworkManager: <info> (ttyUSB0): exported as /org/freedesktop/NetworkManager/Devices/4 May 9 16:50:07 cthulhu NetworkManager: <info> (ttyUSB0): now managed May 9 16:50:07 cthulhu NetworkManager: <info> (ttyUSB0): device state change: 1 -> 2 (reason 2) May 9 16:50:07 cthulhu NetworkManager: <info> (ttyUSB0): deactivating device (reason: 2). May 9 16:50:07 cthulhu NetworkManager: <info> (ttyUSB0): device state change: 2 -> 3 (reason 0) May 9 16:50:07 cthulhu NetworkManager: <info> Activation (ttyUSB0) starting connection 'Connexion GSM SFR' May 9 16:50:07 cthulhu NetworkManager: <info> (ttyUSB0): device state change: 3 -> 4 (reason 0) May 9 16:50:07 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled... May 9 16:50:07 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started... May 9 16:50:07 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete. May 9 16:50:07 cthulhu modem-manager: (ttyUSB0) opening serial device... May 9 16:50:07 cthulhu modem-manager: Modem /org/freedesktop/ModemManager/Modems/2: state changed (disabled -> enabling) May 9 16:50:07 cthulhu modem-manager: Got failure code 11: SIM PIN required May 9 16:50:07 cthulhu modem-manager: Modem /org/freedesktop/ModemManager/Modems/2: state changed (enabling -> enabled) May 9 16:50:07 cthulhu modem-manager: Registration state changed: 2 May 9 16:50:07 cthulhu modem-manager: Modem /org/freedesktop/ModemManager/Modems/2: state changed (enabled -> searching) May 9 16:50:09 cthulhu modem-manager: (ttyUSB1): re-checking support... May 9 16:50:09 cthulhu modem-manager: (ttyUSB1) opening serial device... May 9 16:50:09 cthulhu modem-manager: (ttyUSB1) closing serial device... May 9 16:50:09 cthulhu modem-manager: (Huawei): GSM modem /sys/devices/pci0000:00/0000:00:1d.0/usb5/5-2 claimed port ttyUSB1 May 9 16:50:11 cthulhu modem-manager: Registration state changed: 1 May 9 16:50:11 cthulhu modem-manager: Modem /org/freedesktop/ModemManager/Modems/2: state changed (searching -> registered) May 9 16:50:11 cthulhu modem-manager: Modem /org/freedesktop/ModemManager/Modems/2: state changed (registered -> connecting) May 9 16:50:11 cthulhu modem-manager: Modem /org/freedesktop/ModemManager/Modems/2: state changed (connecting -> connected) May 9 16:50:11 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) scheduled... May 9 16:50:11 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) starting... May 9 16:50:11 cthulhu NetworkManager: <info> (ttyUSB0): device state change: 4 -> 5 (reason 0) May 9 16:50:11 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) successful. May 9 16:50:11 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) scheduled. May 9 16:50:11 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) complete. May 9 16:50:11 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) started... May 9 16:50:11 cthulhu NetworkManager: <info> (ttyUSB0): device state change: 5 -> 7 (reason 0) May 9 16:50:11 cthulhu NetworkManager: <info> Starting pppd connection May 9 16:50:11 cthulhu NetworkManager: <debug> [1273416611.180686] nm_ppp_manager_start(): Command line: /usr/sbin/pppd nodetach lock nodefaultroute user slsfr ttyUSB0 noipdefault noauth refuse-eap refuse-mschap refuse-mschap-v2 usepeerdns lcp-echo-failure 0 lcp-echo-interval 0 ipparam /org/freedesktop/NetworkManager/PPP/2 plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so May 9 16:50:11 cthulhu NetworkManager: <debug> [1273416611.188326] nm_ppp_manager_start(): ppp started with pid 16339 May 9 16:50:11 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 4 of 5 (IP6 Configure Get) scheduled... May 9 16:50:11 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) complete. May 9 16:50:11 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 4 of 5 (IP6 Configure Get) started... May 9 16:50:11 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 4 of 5 (IP6 Configure Get) complete. May 9 16:50:11 cthulhu pppd[16339]: Plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so loaded. May 9 16:50:11 cthulhu pppd[16339]: pppd 2.4.4 started by root, uid 0 May 9 16:50:11 cthulhu pppd[16339]: Using interface ppp0 May 9 16:50:11 cthulhu pppd[16339]: Connect: ppp0 <--> /dev/ttyUSB0 May 9 16:50:11 cthulhu NetworkManager: SCPlugin-Ifupdown: devices added (path: /sys/devices/virtual/net/ppp0, iface: ppp0) May 9 16:50:11 cthulhu NetworkManager: SCPlugin-Ifupdown: device added (path: /sys/devices/virtual/net/ppp0, iface: ppp0): no ifupdown configuration found. May 9 16:50:11 cthulhu pppd[16339]: CHAP authentication succeeded May 9 16:50:11 cthulhu pppd[16339]: CHAP authentication succeeded May 9 16:50:31 cthulhu NetworkManager: <WARN> pppd_timed_out(): Looks like pppd didn't initialize our dbus module May 9 16:50:31 cthulhu NetworkManager: <info> (ttyUSB0): device state change: 7 -> 9 (reason 14) May 9 16:50:31 cthulhu NetworkManager: <info> Marking connection 'Connexion GSM SFR' invalid. May 9 16:50:31 cthulhu NetworkManager: <info> Activation (ttyUSB0) failed. May 9 16:50:31 cthulhu NetworkManager: <info> (ttyUSB0): device state change: 9 -> 3 (reason 0) May 9 16:50:31 cthulhu NetworkManager: <info> (ttyUSB0): deactivating device (reason: 0). May 9 16:50:31 cthulhu pppd[16339]: Terminating on signal 15 May 9 16:50:31 cthulhu modem-manager: Modem /org/freedesktop/ModemManager/Modems/2: state changed (connected -> disconnecting) May 9 16:50:31 cthulhu pppd[16339]: Connection terminated. May 9 16:50:31 cthulhu NetworkManager: SCPlugin-Ifupdown: devices removed (path: /sys/devices/virtual/net/ppp0, iface: ppp0) May 9 16:50:31 cthulhu modem-manager: Got failure code 3: No carrier May 9 16:50:32 cthulhu modem-manager: Modem /org/freedesktop/ModemManager/Modems/2: state changed (disconnecting -> registered) May 9 16:50:32 cthulhu pppd[16339]: Exit. May 9 16:50:33 cthulhu NetworkManager: <debug> [1273416633.001757] ensure_killed(): waiting for ppp pid 16339 to exit May 9 16:50:33 cthulhu NetworkManager: <debug> [1273416633.001871] ensure_killed(): ppp pid 16339 cleaned up May 9 16:50:42 cthulhu NetworkManager: <info> Activation (ttyUSB0) starting connection 'Connexion GSM SFR' May 9 16:50:42 cthulhu NetworkManager: <info> (ttyUSB0): device state change: 3 -> 4 (reason 0) May 9 16:50:42 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled... May 9 16:50:42 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started... May 9 16:50:42 cthulhu NetworkManager: <info> (ttyUSB0): device state change: 4 -> 6 (reason 0) May 9 16:50:42 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete. May 9 16:50:42 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled... May 9 16:50:42 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started... May 9 16:50:42 cthulhu NetworkManager: <info> (ttyUSB0): device state change: 6 -> 4 (reason 0) May 9 16:50:42 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete. May 9 16:50:42 cthulhu modem-manager: Modem /org/freedesktop/ModemManager/Modems/2: state changed (registered -> connecting) May 9 16:50:42 cthulhu modem-manager: Modem /org/freedesktop/ModemManager/Modems/2: state changed (connecting -> connected) May 9 16:50:42 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) scheduled... May 9 16:50:42 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) starting... May 9 16:50:42 cthulhu NetworkManager: <info> (ttyUSB0): device state change: 4 -> 5 (reason 0) May 9 16:50:42 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) successful. May 9 16:50:42 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) scheduled. May 9 16:50:42 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) complete. May 9 16:50:42 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) started... May 9 16:50:42 cthulhu NetworkManager: <info> (ttyUSB0): device state change: 5 -> 7 (reason 0) May 9 16:50:42 cthulhu NetworkManager: <info> Starting pppd connection May 9 16:50:42 cthulhu NetworkManager: <debug> [1273416642.833057] nm_ppp_manager_start(): Command line: /usr/sbin/pppd nodetach lock nodefaultroute user slsfr ttyUSB0 noipdefault noauth refuse-eap refuse-mschap refuse-mschap-v2 usepeerdns lcp-echo-failure 0 lcp-echo-interval 0 ipparam /org/freedesktop/NetworkManager/PPP/3 plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so May 9 16:50:42 cthulhu NetworkManager: <debug> [1273416642.835066] nm_ppp_manager_start(): ppp started with pid 16530 May 9 16:50:42 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 4 of 5 (IP6 Configure Get) scheduled... May 9 16:50:42 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) complete. May 9 16:50:42 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 4 of 5 (IP6 Configure Get) started... May 9 16:50:42 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 4 of 5 (IP6 Configure Get) complete. May 9 16:50:42 cthulhu pppd[16530]: Plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so loaded. May 9 16:50:42 cthulhu pppd[16530]: pppd 2.4.4 started by root, uid 0 May 9 16:50:42 cthulhu pppd[16530]: Using interface ppp0 May 9 16:50:42 cthulhu pppd[16530]: Connect: ppp0 <--> /dev/ttyUSB0 May 9 16:50:42 cthulhu pppd[16530]: CHAP authentication succeeded May 9 16:50:42 cthulhu pppd[16530]: CHAP authentication succeeded May 9 16:50:42 cthulhu NetworkManager: SCPlugin-Ifupdown: devices added (path: /sys/devices/virtual/net/ppp0, iface: ppp0) May 9 16:50:42 cthulhu NetworkManager: SCPlugin-Ifupdown: device added (path: /sys/devices/virtual/net/ppp0, iface: ppp0): no ifupdown configuration found. May 9 16:50:51 cthulhu pppd[16530]: Could not determine remote IP address: defaulting to 10.64.64.64 May 9 16:50:51 cthulhu pppd[16530]: Cannot determine ethernet address for proxy ARP May 9 16:50:51 cthulhu pppd[16530]: local IP address 10.50.219.213 May 9 16:50:51 cthulhu pppd[16530]: remote IP address 10.64.64.64 May 9 16:50:51 cthulhu pppd[16530]: primary DNS address 172.20.2.39 May 9 16:50:51 cthulhu pppd[16530]: secondary DNS address 172.20.2.10 May 9 16:50:51 cthulhu NetworkManager: <info> PPP manager(IP Config Get) reply received. May 9 16:50:51 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 4 of 5 (IP4 Configure Get) scheduled... May 9 16:50:51 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 4 of 5 (IP4 Configure Get) started... May 9 16:50:51 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 5 of 5 (IP Configure Commit) scheduled... May 9 16:50:51 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 4 of 5 (IP4 Configure Get) complete. May 9 16:50:51 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 5 of 5 (IP Configure Commit) started... May 9 16:50:51 cthulhu postfix/master[2268]: reload -- version 2.6.5, configuration /etc/postfix May 9 16:50:52 cthulhu NetworkManager: <info> (ttyUSB0): device state change: 7 -> 8 (reason 0) May 9 16:50:52 cthulhu NetworkManager: <info> Policy set 'Connexion GSM SFR' (ppp0) as default for routing and DNS. May 9 16:50:52 cthulhu NetworkManager: <info> Activation (ttyUSB0) successful, device activated. May 9 16:50:52 cthulhu NetworkManager: <info> Activation (ttyUSB0) Stage 5 of 5 (IP Configure Commit) complete. I can test usbmon if you guide me. I will test the changes on the file /etc/udev/rules.d/70-persistent-cd.rules (https://bugs.launchpad.net/ubuntu/+source/linux/+bug/449394/comments/68). Regards. On Sun, 9 May 2010 bugzilla-daemon@bugzilla.kernel.org wrote: > I tested the method of Damjan Jovanovic by killing devkit-disks-daemon > (Debian > package devicekit-disks 009-3). > > Below the logs before killing devkit-disks-daemon, the connection fails: > > May 9 16:48:18 cthulhu kernel: usb 5-2: new full speed USB device using > uhci_hcd and address 5 > May 9 16:48:19 cthulhu kernel: usb 5-2: New USB device found, idVendor=12d1, > idProduct=1003 > May 9 16:48:19 cthulhu kernel: usb 5-2: New USB device strings: Mfr=1, > Product=2, SerialNumber=0 > May 9 16:48:19 cthulhu kernel: usb 5-2: Product: HUAWEI Mobile ... > Below the logs after killing devkit-disks-daemon, the connection succeeded: ... > I can test usbmon if you guide me. Please do. Using usbmon is easy: mount -t debugfs none /sys/kernel/debug cat /sys/kernel/debug/usb/usbmon/5u >usbmon.log Here the "5u" refers to the "usb 5-2" in the log above; if the bus number changes from 5 to something else then you would use the new value instead. While this is running, plug in the modem. After the failure occurs, kill the "cat" program with ^C. The usbmon.log file will contain the recorded information. Attach it to the bug report. Make sure that devkit-disks-daemon is running when you do the test, so we can see what command it sends that the modem doesn't like. Also, it will help if you unplug as many of your other USB devices as possible before starting the test. Alan Stern Hi, I tested the changes on the file "/etc/udev/rules.d/70-persistent-cd.rules" (https://bugs.launchpad.net/ubuntu/+source/linux/+bug/449394/comments/68), but it does not work. But my version of Gnome is not yet using udisks, I use devicekit-disks add the name (UDISKS_DISABLE_POLLING, UDISKS_PRESENTATION_NOPOLICY) to be different. Regards. Hi, I used usbmon to record information. I attached the log file. Regards. Created attachment 26372 [details]
usbmon log file
Hi, With Gnome, after killing devicekit-disks, I connect to the Internet. I run the commands : # devkit-disks --enumerate /org/freedesktop/DeviceKit/Disks/devices/sr1 /org/freedesktop/DeviceKit/Disks/devices/sda1 /org/freedesktop/DeviceKit/Disks/devices/sda2 /org/freedesktop/DeviceKit/Disks/devices/sda /org/freedesktop/DeviceKit/Disks/devices/sr2 /org/freedesktop/DeviceKit/Disks/devices/sr0 /org/freedesktop/DeviceKit/Disks/devices/fd0 It will not reset the E220, the connection remains active. sr2 is associated to the E220. In the logs I have this: May 14 03:52:21 cthulhu kernel: sr2: CDROM (ioctl) error, command: cdb[0]=0x51 51 00 00 00 00 00 00 00 02 00 May 14 03:52:21 cthulhu kernel: sr: Sense Key : 0x4 [current] May 14 03:52:21 cthulhu kernel: sr: ASC=0x0 ASCQ=0x0 May 14 03:52:23 cthulhu kernel: sr2: CDROM (ioctl) error, command: cdb[0]=0x46 46 00 00 00 00 00 00 00 20 00 May 14 03:52:23 cthulhu kernel: sr: Sense Key : 0x4 [current] May 14 03:52:23 cthulhu kernel: sr: ASC=0x0 ASCQ=0x0 May 14 03:52:23 cthulhu kernel: sr2: CDROM (ioctl) error, command: cdb[0]=0x46 46 00 00 00 00 00 00 00 20 00 May 14 03:52:23 cthulhu kernel: sr: Sense Key : 0x4 [current] May 14 03:52:23 cthulhu kernel: sr: ASC=0x0 ASCQ=0x0 May 14 03:52:23 cthulhu kernel: sr2: CDROM (ioctl) error, command: cdb[0]=0x46 46 00 00 00 00 00 00 00 20 00 May 14 03:52:23 cthulhu kernel: sr: Sense Key : 0x4 [current] May 14 03:52:23 cthulhu kernel: sr: ASC=0x0 ASCQ=0x0 Regards. On Fri, 14 May 2010 bugzilla-daemon@bugzilla.kernel.org wrote: > In the logs I have this: > > May 14 03:52:21 cthulhu kernel: sr2: CDROM (ioctl) error, command: > cdb[0]=0x51 > 51 00 00 00 00 00 00 00 02 00 > May 14 03:52:21 cthulhu kernel: sr: Sense Key : 0x4 [current] > May 14 03:52:21 cthulhu kernel: sr: ASC=0x0 ASCQ=0x0 > May 14 03:52:23 cthulhu kernel: sr2: CDROM (ioctl) error, command: > cdb[0]=0x46 > 46 00 00 00 00 00 00 00 20 00 > May 14 03:52:23 cthulhu kernel: sr: Sense Key : 0x4 [current] > May 14 03:52:23 cthulhu kernel: sr: ASC=0x0 ASCQ=0x0 > May 14 03:52:23 cthulhu kernel: sr2: CDROM (ioctl) error, command: > cdb[0]=0x46 > 46 00 00 00 00 00 00 00 20 00 > May 14 03:52:23 cthulhu kernel: sr: Sense Key : 0x4 [current] > May 14 03:52:23 cthulhu kernel: sr: ASC=0x0 ASCQ=0x0 > May 14 03:52:23 cthulhu kernel: sr2: CDROM (ioctl) error, command: > cdb[0]=0x46 > 46 00 00 00 00 00 00 00 20 00 > May 14 03:52:23 cthulhu kernel: sr: Sense Key : 0x4 [current] > May 14 03:52:23 cthulhu kernel: sr: ASC=0x0 ASCQ=0x0 I think those errors are harmless, although they do indicate a bug in the firmware. More important is an error that occurs later: f5518300 240909067 S Bo:5:004:4 -115 31 = 55534243 d5000000 0a000000 80000a5a 082a0000 0000000a 00000000 000000 f5518300 240909911 C Bo:5:004:4 0 31 > f50c1800 240909979 S Bi:5:004:3 -115 10 < f50c1800 240939906 C Bi:5:004:3 -75 10 = 0e000000 00000800 0000 f5518300 240939984 S Bi:5:004:3 -115 13 < f5518300 240940908 C Bi:5:004:3 -75 13 = 0e000000 00000800 0000ffff 00 This is also due to a firmware bug, and it _does_ cause the device to be reset. Have you checked the version of the firmware in your E220? Is there an update available for you to install? Alan Stern The NetworkManager mobile broadband page (http://live.gnome.org/NetworkManager/MobileBroadband) documents that the minimum working firmware version for the Huawei E220 is 11.117.09.04.00 You can check the firmware version by typing this in one terminal: sudo cat /dev/ttyUSB0 and this in another: echo "ATI" > /dev/ttyUSB0 Without the new firmware, I've heard the E220 doesn't work on newer versions of Windows either. Unfortunately the firmware upgrade must be done on Windows. Hi, I updated the firmware of the Huawei E220 with version 11.117.09.04.00, and the problems have been resolved. I can use Gnome and I connect to the Internet, I can browse the contents of the Huawei E220, and I am no longer obliged to throw twice Network-Manager to activate the network. Fucking bug !!! :o) I downloaded the firmware here : http://www.vodafone.de/hilfe-support/technischer-support/129464.html Regards. On Wed, 26 May 2010 bugzilla-daemon@bugzilla.kernel.org wrote: > --- Comment #36 from Frederic MASSOT <frederic@juliana-multimedia.com> > 2010-05-26 14:05:06 --- > Hi, > > I updated the firmware of the Huawei E220 with version 11.117.09.04.00, and > the > problems have been resolved. Damjan (or anyone else): Under these circumstances, is there any reason to keep this bug report open? Alan Stern In the absence of any response, I'm closing out this bug report. Hi Alan, it still does happen even with newer devices and kernels. I have same problem with 2.6.38.8 and 2.6.39.2 with Huawei E1823: Manufacturer: huawei Model: E1823 Revision: 11.825.03.10.55 IMEI: xxxx +GCAP: +CGSM,+FCLASS,+DS As others am getting the: option: option_instat_callback: error -84 or option: option_instat_callback: error -108 I made the usbmon log (Huawei1823-2.6.39.2.usbmon.log) and attach the dmesg (Huawei1823-2.6.39.2.txt). It was weird to me yesterday it worked for me while today not. And I tried external USB hub via USB1 port, via PCMCIA to USB2.0 to the hub, also plugged the USB stick directly into my old laptop. And I think at least for today I can conclude what was the cause - I forgot to run on power from the wall socket. ;) I got fooled because the LED lights on the USB hub were on, and the only hint was probably the fact that once pppd managed to dial in, negotiate but then it broke quickly (will attach Huawei1823-2.6.39.2.txt2). I am not saying it could NOT happen for other reasons but at least I have incidentally some explanation. For completeness, my working setup (at least time to time): ;) # pppd ttyUSB0 460800 connect '/usr/sbin/chat -v -f /etc/ppp/chat-tmobile' dump debug pppd options in effect: debug debug # (from /etc/ppp/options.ttyUSB0) nodetach # (from /etc/ppp/options.ttyUSB0) persist # (from /etc/ppp/options.ttyUSB0) maxfail 0 # (from /etc/ppp/options.ttyUSB0) unit 9 # (from /etc/ppp/options.ttyUSB0) dump # (from command line) noauth # (from /etc/ppp/options.ttyUSB0) user gprs # (from /etc/ppp/options.ttyUSB0) password ?????? # (from /etc/ppp/options.ttyUSB0) /dev/ttyUSB0 # (from command line) 460800 # (from command line) lock # (from /etc/ppp/options.ttyUSB0) connect /usr/sbin/chat -v -f /etc/ppp/chat-tmobile # (from command line) crtscts # (from /etc/ppp/options.ttyUSB0) mtu 1492 # (from /etc/ppp/options.ttyUSB0) ipcp-accept-local # (from /etc/ppp/options.ttyUSB0) ipcp-accept-remote # (from /etc/ppp/options.ttyUSB0) noipdefault # (from /etc/ppp/options.ttyUSB0) defaultroute # (from /etc/ppp/options.ttyUSB0) usepeerdns # (from /etc/ppp/options.ttyUSB0) Waiting for CONNECT string chat: Jul 10 16:08:51 CONNECT 236800 Script /usr/sbin/chat -v -f /etc/ppp/chat-tmobile finished (pid 9630), status = 0x0 Serial connection established. using channel 4 Using interface ppp9 Connect: ppp9 <--> /dev/ttyUSB0 sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x44bb728d> <pcomp> <accomp>] rcvd [LCP ConfReq id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0x2d88ca6> <pcomp> <accomp>] sent [LCP ConfAck id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0x2d88ca6> <pcomp> <accomp>] rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0x44bb728d> <pcomp> <accomp>] rcvd [LCP DiscReq id=0x1 magic=0x2d88ca6] rcvd [CHAP Challenge id=0x1 <a4c7fb0100e1ef3834e49c0c64184a10>, name = "UMTS_CHAP_SRVR"] sent [CHAP Response id=0x1 <991c62c942c5e614fe543c4d2cb2093b>, name = "gprs"] rcvd [CHAP Success id=0x1 ""] CHAP authentication succeeded CHAP authentication succeeded sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>] sent [IPCP ConfReq id=0x1 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>] rcvd [LCP ProtRej id=0x2 80 fd 01 01 00 0f 1a 04 78 00 18 04 78 00 15 03 2f] Protocol-Reject for 'Compression Control Protocol' (0x80fd) received rcvd [IPCP ConfNak id=0x1 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>] sent [IPCP ConfReq id=0x2 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>] rcvd [IPCP ConfNak id=0x2 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>] sent [IPCP ConfReq id=0x3 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>] rcvd [IPCP ConfNak id=0x3 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>] sent [IPCP ConfReq id=0x4 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>] rcvd [IPCP ConfReq id=0x0] sent [IPCP ConfNak id=0x0 <addr 0.0.0.0>] rcvd [IPCP ConfRej id=0x4 <compress VJ 0f 01>] sent [IPCP ConfReq id=0x5 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>] rcvd [IPCP ConfReq id=0x1] sent [IPCP ConfAck id=0x1] rcvd [IPCP ConfNak id=0x5 <addr 93.153.87.160> <ms-dns1 93.153.117.1> <ms-dns2 62.141.0.2>] sent [IPCP ConfReq id=0x6 <addr 93.153.87.160> <ms-dns1 93.153.117.1> <ms-dns2 62.141.0.2>] rcvd [IPCP ConfAck id=0x6 <addr 93.153.87.160> <ms-dns1 93.153.117.1> <ms-dns2 62.141.0.2>] Could not determine remote IP address: defaulting to 10.64.64.73 local IP address 93.153.87.160 remote IP address 10.64.64.73 primary DNS address 93.153.117.1 secondary DNS address 62.141.0.2 Script /etc/ppp/ip-up started (pid 9632) Script /etc/ppp/ip-up finished (pid 9632), status = 0x0 Created attachment 65152 [details]
dmesg from 2.6.39.2 with Huawei E1823
battery-powered laptop, USB hub powered from the laptop
Created attachment 65162 [details]
Huawei1823-2.6.39.2.usbmon.log
when on the battery power and failing
Created attachment 65172 [details]
once it got briefly enough power - Huawei E1823 on 2.6.39.2
|