Re: Sierra Wireless dongle enable failed

[Dan Williams <dcbw redhat com>]

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.

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