Bug 473166

Summary: Slow to detect Novatel USB EVDO modem
Product: [Fedora] Fedora Reporter: Frank Cox <theatre>
Component: kernelAssignee: Pete Zaitcev <zaitcev>
Status: CLOSED WONTFIX QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: medium Docs Contact:
Priority: medium    
Version: 10CC: kernel-maint
Target Milestone: ---Keywords: Triaged
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2009-12-18 06:57:50 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Frank Cox 2008-11-26 21:12:03 UTC
Description of problem:
It takes five minutes from plugging a Novatel Wireless modem into the USB slot (or from booting up the computer with the modem already attached) before the machine realizes that it has a modem.

Here is the /var/log/messages output:

> Nov 26 12:20:09 mutt kernel: usb 7-2: new full speed USB device using uhci_hcd and address 2
> Nov 26 12:20:09 mutt kernel: usb 7-2: configuration #1 chosen from 1 choice
> Nov 26 12:20:09 mutt kernel: usb 7-2: New USB device found, idVendor=1410, idProduct=5010
> Nov 26 12:20:09 mutt kernel: usb 7-2: New USB device strings: Mfr=1, Product=2, SerialNumber=4
> Nov 26 12:20:09 mutt kernel: usb 7-2: Product: Novatel Wireless CDMA
> Nov 26 12:20:09 mutt kernel: usb 7-2: Manufacturer: Novatel Wireless Inc.
> Nov 26 12:20:09 mutt kernel: usb 7-2: SerialNumber: 091087439150000
> Nov 26 12:20:10 mutt kernel: Initializing USB Mass Storage driver...
> Nov 26 12:20:10 mutt kernel: scsi6 : SCSI emulation for USB Mass Storage devices
> Nov 26 12:20:10 mutt kernel: usbcore: registered new interface driver usb-storage
> Nov 26 12:20:10 mutt kernel: USB Mass Storage support registered.
> Nov 26 12:20:15 mutt kernel: scsi 6:0:0:0: CD-ROM            Novatel  Mass Storage     1.00 PQ: 0 ANSI: 2
> Nov 26 12:20:15 mutt kernel: sr1: scsi-1 drive
> Nov 26 12:20:15 mutt kernel: sr 6:0:0:0: Attached scsi generic sg2 type 5
> Nov 26 12:20:16 mutt kernel: sr1: CDROM (ioctl) error, command: Get configuration 46 00 00 00 00 00 00 00 20 00
> Nov 26 12:20:16 mutt kernel: sr: Sense Key : No Sense [current] 
> Nov 26 12:20:16 mutt kernel: sr: Add. Sense: No additional sense information
> Nov 26 12:20:17 mutt kernel: sr1: CDROM (ioctl) error, command: Get configuration 46 00 00 00 00 00 00 00 20 00
> Nov 26 12:20:17 mutt kernel: sr: Sense Key : No Sense [current] 
> Nov 26 12:20:17 mutt kernel: sr: Add. Sense: No additional sense information
> Nov 26 12:20:17 mutt kernel: sr1: CDROM (ioctl) error, command: Get configuration 46 00 00 28 00 00 00 00 10 00
> Nov 26 12:20:17 mutt kernel: sr: Sense Key : No Sense [current] 
> Nov 26 12:20:17 mutt kernel: sr: Add. Sense: No additional sense information
> Nov 26 12:20:17 mutt kernel: sr1: CDROM (ioctl) error, command: Get configuration 46 00 00 20 00 00 00 00 18 00
> Nov 26 12:20:17 mutt kernel: sr: Sense Key : No Sense [current] 
> Nov 26 12:20:17 mutt kernel: sr: Add. Sense: No additional sense information
> Nov 26 12:20:17 mutt kernel: sr1: CDROM (ioctl) error, command: Get configuration 46 00 00 00 00 00 00 00 20 00
> Nov 26 12:20:17 mutt kernel: sr: Sense Key : No Sense [current] 
> Nov 26 12:20:17 mutt kernel: sr: Add. Sense: No additional sense information
> Nov 26 12:20:17 mutt gnome-keyring-daemon[2986]: adding removable location: volume_label_Novatel_Mobilink at /media/Novatel Mobilink
> Nov 26 12:20:17 mutt hald: mounted /dev/sr1 on behalf of uid 500
> Nov 26 12:23:23 mutt ntpd[2242]: kernel time sync status change 4001
> Nov 26 12:26:53 mutt kernel: usb 7-2: USB disconnect, address 2
> Nov 26 12:26:53 mutt hald[2073]: forcibly attempting to lazy unmount /dev/sr1 as enclosing drive was disconnected
> Nov 26 12:26:53 mutt kernel: scsi 6:0:0:0: rejecting I/O to dead device
> Nov 26 12:26:53 mutt gnome-keyring-daemon[2986]: removing removable location: volume_label_Novatel_Mobilink
> Nov 26 12:26:53 mutt hald: unmounted /dev/sr1 from '/media/Novatel Mobilink' on behalf of uid 0
> Nov 26 12:26:54 mutt kernel: usb 7-2: new full speed USB device using uhci_hcd and address 3
> Nov 26 12:26:55 mutt kernel: usb 7-2: configuration #1 chosen from 1 choice
> Nov 26 12:26:55 mutt kernel: scsi7 : SCSI emulation for USB Mass Storage devices
> Nov 26 12:26:55 mutt kernel: usb 7-2: New USB device found, idVendor=1410, idProduct=4100
> Nov 26 12:26:55 mutt kernel: usb 7-2: New USB device strings: Mfr=1, Product=2, SerialNumber=4
> Nov 26 12:26:55 mutt kernel: usb 7-2: Product: Novatel Wireless CDMA
> Nov 26 12:26:55 mutt kernel: usb 7-2: Manufacturer: Novatel Wireless Inc.
> Nov 26 12:26:55 mutt kernel: usb 7-2: SerialNumber: 091087439151000
> Nov 26 12:26:55 mutt kernel: usbcore: registered new interface driver usbserial
> Nov 26 12:26:55 mutt kernel: usbserial: USB Serial support registered for generic
> Nov 26 12:26:55 mutt kernel: usbcore: registered new interface driver usbserial_generic
> Nov 26 12:26:55 mutt kernel: usbserial: USB Serial Driver core
> Nov 26 12:26:55 mutt kernel: usbserial: USB Serial support registered for GSM modem (1-port)
> Nov 26 12:26:55 mutt kernel: option 7-2:1.0: GSM modem (1-port) converter detected
> Nov 26 12:26:55 mutt kernel: usb 7-2: GSM modem (1-port) converter now attached to ttyUSB0
> Nov 26 12:26:55 mutt kernel: option 7-2:1.1: GSM modem (1-port) converter detected
> Nov 26 12:26:55 mutt kernel: usb 7-2: GSM modem (1-port) converter now attached to ttyUSB1
> Nov 26 12:26:55 mutt kernel: option 7-2:1.2: GSM modem (1-port) converter detected
> Nov 26 12:26:55 mutt kernel: usb 7-2: GSM modem (1-port) converter now attached to ttyUSB2
> Nov 26 12:26:55 mutt kernel: option 7-2:1.3: GSM modem (1-port) converter detected
> Nov 26 12:26:55 mutt kernel: usb 7-2: GSM modem (1-port) converter now attached to ttyUSB3
> Nov 26 12:26:55 mutt kernel: usbcore: registered new interface driver option
> Nov 26 12:26:55 mutt kernel: option: USB Driver for GSM modems: v0.7.2
> Nov 26 12:27:00 mutt kernel: scsi 7:0:0:0: Direct-Access     Novatel  MMC Storage      2.31 PQ: 0 ANSI: 2
> Nov 26 12:27:00 mutt kernel: sd 7:0:0:0: [sdb] Attached SCSI removable disk
> Nov 26 12:27:00 mutt kernel: sd 7:0:0:0: Attached scsi generic sg2 type 0
> Nov 26 12:29:54 mutt kernel: usb 7-2: USB disconnect, address 3
> Nov 26 12:29:54 mutt kernel: option1 ttyUSB0: GSM modem (1-port) converter now disconnected from ttyUSB0
> Nov 26 12:29:54 mutt kernel: option 7-2:1.0: device disconnected
> Nov 26 12:29:54 mutt kernel: option1 ttyUSB1: GSM modem (1-port) converter now disconnected from ttyUSB1
> Nov 26 12:29:54 mutt kernel: option 7-2:1.1: device disconnected
> Nov 26 12:29:54 mutt kernel: option1 ttyUSB2: GSM modem (1-port) converter now disconnected from ttyUSB2
> Nov 26 12:29:54 mutt kernel: option 7-2:1.2: device disconnected
> Nov 26 12:29:54 mutt kernel: option1 ttyUSB3: GSM modem (1-port) converter now disconnected from ttyUSB3
> Nov 26 12:29:54 mutt kernel: option 7-2:1.3: device disconnected


Version-Release number of selected component (if applicable):
I have tried this on three differnent computers with exactly the same result:  One Fedora 9/x86_64, one Fedora 10/i386 and one Fedora 10/x86_64.

How reproducible:


Steps to Reproduce:
1.Plug in Novatel EVDO USB modem
2.The modem is immediately mounted as a "storage device" but that's it.  No /tty/USB? devices are set up.
3. Wait five minutes.
4. The modem suddenly mounts itself as a modem and sets up the /tty/USB? devices and starts to work.
5.  No other action is required to get the modem to activate.  All it takes is waiting five minutes.
  
Actual results:
Five minute wait before modem is found and activated

Expected results:
The modem should be found immediately.  The device is detected immediately as a storage device but doesn't follow through with the rest of the job and set itself up as a modem until five minutes later.

Additional info:
Affects at least Fedora 9 and Fedora 10 on both x86_64 and i386 architectures.

Comment 1 Frank Cox 2008-12-03 06:01:10 UTC
I have now discovered what changes when the five minute delay is up.  As mentioned before, the modem takes 5 minutes before it creates the /tty/USB? devices.

Somehow, the modem changes its identity after being plugged in for 5 minutes.

When the modem is first plugged in, this is what is created in /proc/bus/usb/devices:

T:  Bus=04 Lev=01 Prnt=01 Port=00 Cnt=01 Dev#=  3 Spd=12  MxCh= 0
D:  Ver= 1.10 Cls=00(>ifc ) Sub=00 Prot=00 MxPS=64 #Cfgs=  1
P:  Vendor=1410 ProdID=5010 Rev= 0.00
S:  Manufacturer=Novatel Wireless Inc.
S:  Product=Novatel Wireless CDMA
S:  SerialNumber=091087439150000
C:* #Ifs= 1 Cfg#= 1 Atr=a0 MxPwr=500mA
I:* If#= 0 Alt= 0 #EPs= 2 Cls=08(stor.) Sub=06 Prot=50 Driver=usb-storage
E:  Ad=87(I) Atr=02(Bulk) MxPS=  64 Ivl=0ms
E:  Ad=08(O) Atr=02(Bulk) MxPS=  64 Ivl=0ms

After five minutes, this is what I find in /proc/bus/usb/devices:

T:  Bus=04 Lev=01 Prnt=01 Port=00 Cnt=01 Dev#=  4 Spd=12  MxCh= 0
D:  Ver= 1.10 Cls=00(>ifc ) Sub=00 Prot=00 MxPS=64 #Cfgs=  1
P:  Vendor=1410 ProdID=4100 Rev= 0.00
S:  Manufacturer=Novatel Wireless Inc.
S:  Product=Novatel Wireless CDMA
S:  SerialNumber=091087439151000
C:* #Ifs= 5 Cfg#= 1 Atr=a0 MxPwr=500mA
I:* If#= 0 Alt= 0 #EPs= 3 Cls=ff(vend.) Sub=ff Prot=ff Driver=option
E:  Ad=81(I) Atr=03(Int.) MxPS=  16 Ivl=128ms
E:  Ad=82(I) Atr=02(Bulk) MxPS=  64 Ivl=0ms
E:  Ad=02(O) Atr=02(Bulk) MxPS=  64 Ivl=0ms
I:* If#= 1 Alt= 0 #EPs= 2 Cls=ff(vend.) Sub=ff Prot=ff Driver=option
E:  Ad=84(I) Atr=02(Bulk) MxPS=  64 Ivl=0ms
E:  Ad=04(O) Atr=02(Bulk) MxPS=  64 Ivl=0ms
I:* If#= 2 Alt= 0 #EPs= 2 Cls=ff(vend.) Sub=ff Prot=ff Driver=option
E:  Ad=89(I) Atr=02(Bulk) MxPS=  64 Ivl=0ms
E:  Ad=09(O) Atr=02(Bulk) MxPS=  64 Ivl=0ms
I:* If#= 3 Alt= 0 #EPs= 2 Cls=ff(vend.) Sub=ff Prot=ff Driver=option
E:  Ad=8a(I) Atr=02(Bulk) MxPS=  64 Ivl=0ms
E:  Ad=0a(O) Atr=02(Bulk) MxPS=  64 Ivl=0ms
I:* If#= 4 Alt= 0 #EPs= 2 Cls=08(stor.) Sub=06 Prot=50 Driver=usb-storage
E:  Ad=85(I) Atr=02(Bulk) MxPS=  64 Ivl=0ms
E:  Ad=06(O) Atr=02(Bulk) MxPS=  64 Ivl=0ms

Notice that the product id has magically changed from 5010 to 4100.  This is the point at which the modem begins working and the /tty/USB? devices are created.

I put this same modem on a machine running Centos 5 and found the exact same behaviour, though I have to use a modprobe command to make it recognize the modem on Centos 5 (modprobe usbserial vendor=0x1410 product=0x4100) and the modprobe is not required to make it recognize the modem on Fedora 10.  The product id changes in the same way in /proc/bus/usb/devices, after the same five minute wait.

Comment 2 Frank Cox 2008-12-19 23:44:09 UTC
HERE IS A WORK-AROUND FOR THIS BUG

Jamie Bernstein (jamie at bernstein.be) is also using a Novatel USB modem and he advised me that this command will cause the modem to immediately do its thing (reset?) and create the /dev/ttyUSB? devices.

eject /dev/cdrom

After entering this command at a terminal prompt (or putting it into /etc/rc.local if the modem is connected on boot-up) the modem immediately starts working.  No 5 minute wait required.

Therefore, if there is some way that the kernel driver for this modem can issue a similar "reset" command, the problem may go away.

Comment 3 Pete Zaitcev 2009-01-16 23:18:25 UTC
Instead of changing rc.local, t would be better to add a udev rule like this:

DRIVER=="sr", SYSFS{idVendor}=="1410", SYSFS{idProduct}=="5010", RUN+="/usr/bin/eject /dev/sr%n"

Not sure about %n, this might need some experimentation.

Comment 4 Bug Zapper 2009-11-18 08:59:10 UTC
This message is a reminder that Fedora 10 is nearing its end of life.
Approximately 30 (thirty) days from now Fedora will stop maintaining
and issuing updates for Fedora 10.  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 '10'.

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 10'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 10 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 5 Bug Zapper 2009-12-18 06:57:50 UTC
Fedora 10 changed to end-of-life (EOL) status on 2009-12-17. Fedora 10 is 
no longer maintained, which means that it will not receive any further 
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of 
Fedora please feel free to reopen this bug against that version.

Thank you for reporting this bug and we are sorry it could not be fixed.