Re: Sierra Wireless dongle enable failed

[John E Connolly <john buglabs net>]

-John


On Sep 25, 2010, at 12:48 AM, Dan Williams <dcbw redhat com> wrote:

> On Mon, 2010-09-20 at 12:28 -0400, John Connolly wrote:
>> Questions inline
>> 
>> On Wed, 2010-05-26 at 10:25 +0200, Maxime Boure wrote:
>>> Thanks for your answer !
>>> 
>>> 
>>> Indeed it is a timing problem. The 6 ttyUSB created make the enabling
>>> longer. I got lucky once and the first ttyUSB enabled was the right
>>> one and I got connected. 
>>> What are my options ? modify this timeout value and recompile NM ?
>>> 
>>> Actually I'd encourage you to use the latest MM 0.4 beta release, which
>>> has the following improvements that will be relevant to you: 
>>> 1) doesn't expose modem on D-Bus until *all* ports have finished
>>> probing; your traces show that NM starts to enable the device before MM
>>> has really finished initializing it
>>> 
>>> 2) prints a timestamp for debug output allowing me to easily see delays
>>> without having to ask you
>>> 
>>> then lets do the same thing and see if we still get the problem, and if
>>> so, what we can do about it.
>> 
>> Was there a resolution for this?  I'm using modem-manager 3 on my embedded device but I see the identical problem.  
>> 
>> Some background though: I'm dropping in a config file into /etc/NetworkManager/system-connections/ resetting NM and I get the same error.
>> 
>> 
>> 
>> My config:
>> /etc/NetworkManager/system-connections/AT\&T\ Data\ Connect\ 1 
>> 
>> 
>> [connection]
>> id=AT&T Data Connect 1
>> uuid=5f817c66-9373-4a52-8819-bd5f5a21947e
>> type=gsm
>> autoconnect=false
>> 
>> 
>> timestamp=0
>> 
>> [ppp]
>> noauth=true
>> refuse-eap=false
>> refuse-pap=false
>> refuse-chap=false
>> refuse-mschap=false
>> refuse-mschapv2=false
>> nobsdcomp=false
>> nodeflate=false
>> no-vj-comp=false
>> require-mppe=false
>> 
>> 
>> require-mppe-128=false
>> mppe-stateful=false
>> crtscts=false
>> baud=0
>> mru=0
>> mtu=0
>> lcp-echo-failure=0
>> lcp-echo-interval=0
>> 
>> [ipv4]
>> method=auto
>> ignore-auto-routes=false
>> ignore-auto-dns=false
>> 
>> 
>> dhcp-send-hostname=false
>> never-default=false
>> 
>> [gsm]
>> number=*99#
>> username=ISP CINGULARGPRS COM
>> password=CINGULAR1
>> apn=ISP.CINGULAR
>> network-type=-1
>> band=-1
>> 
>> 
>> allowed-bands=1
>> 
>> [serial]
>> baud=115200
>> bits=8
>> parity=110
>> stopbits=1
>> send-delay=0
>> 
>> 
>> My error:
>> 
>> Sep 20 17:18:28 bug20 NetworkManager: <info>  Re-checking deferred serial ports
>> Sep 20 17:18:28 bug20 NetworkManager: <info>  (ttyUSB3): new Modem device (driver: 'sierra')
>> 
>> 
>> Sep 20 17:18:28 bug20 NetworkManager: <info>  (ttyUSB3): exported as /org/freedesktop/Hal/devices/usb_device_1199_6890_noserial_if3_serial_usb_0
>> Sep 20 17:18:28 bug20 NetworkManager: <info>  (wlan0): device state change: 2 -> 3 (reason 0)
>> 
>> 
>> Sep 20 17:18:28 bug20 NetworkManager: <info>  (wlan0): supplicant interface state:  starting -> ready
>> Sep 20 17:18:33 bug20 NetworkManager: <info>  (ttyUSB3): device state change: 1 -> 2 (reason 2)
>> 
>> 
>> Sep 20 17:18:33 bug20 NetworkManager: <info>  (ttyUSB3): deactivating device (reason: 2).
>> Sep 20 17:18:33 bug20 NetworkManager: nm_system_device_flush_ip4_routes_with_iface: assertion `iface_idx >= 0' failed
>> 
>> 
>> Sep 20 17:18:33 bug20 NetworkManager: nm_system_device_flush_ip4_addresses_with_iface: assertion `iface_idx >= 0' failed
>> Sep 20 17:18:33 bug20 NetworkManager: <info>  (ttyUSB3): device state change: 2 -> 3 (reason 0)
>> 
>> 
>> Sep 20 17:18:33 bug20 NetworkManager: <info>  Activation (ttyUSB3) starting connection 'AT&T Data Connect 1'
>> Sep 20 17:18:33 bug20 NetworkManager: <info>  (ttyUSB3): device state change: 3 -> 4 (reason 0)
>> 
>> 
>> Sep 20 17:18:33 bug20 NetworkManager: <info>  Activation (ttyUSB3) Stage 1 of 5 (Device Prepare) scheduled...
>> Sep 20 17:18:33 bug20 NetworkManager: <info>  Activation (ttyUSB3) Stage 1 of 5 (Device Prepare) started...
>> 
>> 
>> Sep 20 17:18:33 bug20 NetworkManager: <debug> [1284999513.177490] nm_serial_device_open(): (ttyUSB3) opening device...
>> Sep 20 17:18:38 bug20 usb 1-2.3: NetworkManager timed out on ep0out len=0/0
>> Sep 20 17:18:38 bug20 ehci-omap ehci-omap.0: reused qh ffc00780 schedule
>> 
>> 
>> Sep 20 17:18:38 bug20 usb 1-2.3: link qh2-0001/ffc00780 start 1 [2/0 us]
>> Sep 20 17:18:43 bug20 usb 1-2.3: NetworkManager timed out on ep0out len=0/0
>> Sep 20 17:18:48 bug20 usb 1-2.3: NetworkManager timed out on ep0out len=0/0
>> 
>> 
>> Sep 20 17:18:53 bug20 usb 1-2.3: NetworkManager timed out on ep0out len=0/0
>> Sep 20 17:18:53 bug20 NetworkManager: <info>  Activation (ttyUSB3) Stage 1 of 5 (Device Prepare) complete.
>> Sep 20 17:18:58 bug20 usb 1-2.3: NetworkManager timed out on ep0out len=0/0
>> 
>> 
>> Sep 20 17:19:09 bug20 NetworkManager: <info>  Retrying modem initialization (0)
>> Sep 20 17:19:09 bug20 NetworkManager: <WARN>  nm_serial_device_add_timeout(): Trying to add a new time out while the old one still exists
>> 
>> 
>> Sep 20 17:19:19 bug20 NetworkManager: <WARN>  init_done(): Modem initialization timed out
>> Sep 20 17:19:19 bug20 NetworkManager: <info>  (ttyUSB3): device state change: 4 -> 9 (reason 28)
>> Sep 20 17:19:19 bug20 NetworkManager: <debug> [1284999559.003539] nm_serial_device_close(): Closing device 'ttyUSB3'
>> 
>> 
>> Sep 20 17:19:24 bug20 usb 1-2.3: NetworkManager timed out on ep0out len=0/0
>> Sep 20 17:19:29 bug20 usb 1-2.3: NetworkManager timed out on ep0out len=0/0
>> Sep 20 17:19:29 bug20 usb 1-2.3: unlink qh2-0001/ffc00780 start 1 [2/0 us]
>> 
>> 
>> Sep 20 17:19:35 bug20 usb 1-2.3: NetworkManager timed out on ep0out len=0/0
>> Sep 20 17:19:35 bug20 NetworkManager: <info>  Marking connection 'AT&T Data Connect 1' invalid.
>> Sep 20 17:19:35 bug20 NetworkManager: <info>  Activation (ttyUSB3) failed.
>> 
>> 
>> Sep 20 17:19:35 bug20 NetworkManager: <info>  (ttyUSB3): device state change: 9 -> 3 (reason 0)
>> Sep 20 17:19:35 bug20 NetworkManager: <info>  (ttyUSB3): deactivating device (reason: 0).
>> Sep 20 17:19:35 bug20 NetworkManager: nm_system_device_flush_ip4_routes_with_iface: assertion `iface_idx >= 0' failed
>> 
>> 
>> Sep 20 17:19:35 bug20 NetworkManager: nm_system_device_flush_ip4_addresses_with_iface: assertion `iface_idx >= 0' failed
>> 
>> And my version information:
>> NetworkManager: 0.7.1.997
>> modemmanager: v3 (from http://ftp.gnome.org/pub/GNOME/sources/ModemManager/0.3/ModemManager-0.3.tar.bz2)
> 
> Ah, so here's the key though.  If you're using NetworkManager 0.7 then
> you're not actually using NetworkManager unless you've patched NM with
> the SUSE patches to add ModemManager support.  I haven't tried those
> patches out for a long time though, and they're not really supported.
> 
> Only NetworkManager 0.8 and later are built to work with ModemManager,
> otherwise if you run NM and MM at the same time, they'll fight over the
> ports.  NM 0.7 had it's own mobile broadband support, but it was pretty
> limited and we built ModemManager specifically to extend that and
> provide support for a lot more devices.  It was not possible to extend
> the integrated NM support for as many devices as ModemManager now
> supports.

Ah yes, this makes sense.  I'll give a shot at porting NM 0.8 to OpenEmbedded and see where that leads me.  Thanks for the tip.

> 
> Dan
> 
> 
>> 
>> I thought it might be the uuid, but it appears that if I drop this into my other x86 machine the uuid isn't an issue.
>> 
>>> 
>> h>ttp://ftp.gnome.org/pub/gnome/sources/ModemManager/0.3/ModemManager-0.3.997.tar.bz2 >Dan
>> Shall I try 0.3.997 ?
>> 
>> -- 
>> 
>> ______________________
>> John Connolly
>> Software Developer
>> Bug Labs
>> 598 Broadway, 4th Floor
>> New York, NY 10012-3206
>> 646.723.9258
>> jconnolly @ irc.freenode.net/#buglabs
>> _______________________________________________
>> networkmanager-list mailing list
>> networkmanager-list gnome org
>> http://mail.gnome.org/mailman/listinfo/networkmanager-list
> 
>