Re: problems with 3g based connections

[Dan Williams <dcbw redhat com>]

On Mon, 2010-07-05 at 08:42 +0200, van Schelve wrote:
> >> Hi,
> >> 
> >> some days ago I have reported a curious issue with modem-manager. 
> >> My main Problem is that I'm sometimes not able to dialup a modem based
> 3g
> >> connection. The connection is not listed in nm-applet in this case and
> in
> >> syslog I have entries like this one: 
> >> 
> >> ... 
> >> May 21 10:055:28 nc0631 modem-manager: (tty/ttyUSB0): outstanding
> support
> >> task prevents export of /sys/devices/pci0000:00/0000:00:1d.1/usb6/6-1
> >> ...
> > 
> > This means that some ports of the modem are still being detected and
> > probed.  The modem cannot be used until all ports have completed
> > detection.
> > 
> >> @Dan, you asked me to bring more debug but I'm not able to reproduce
> this
> >> issue while manually starting nm / mm in debug mode. 
> >> Therefore: is it possible to run network-manager / modem-manager per
> >> default in debug mode while starting over upstart?
> > 
> > Possibly, but the debug output doesn't go to syslog, so unless it gets
> > stored somewhere by upstart it'll get lost.
> 
> We were able to capture the debug output. Without debug we run 6 of 10
> times into
> this problem. Running mm in debug mode we were able to reproduce it 3 of
> 10 times.
> 
> http://pastebin.com/RS5vDxwJ
> http://pastebin.com/FmZbkJnc
> http://pastebin.com/97GPPbZW

This is good stuff; near the end of the log entries you'll see:

** (modem-manager:1054): DEBUG: <1278077341.1209> (ttyUSB1): --> 00 78 f0 7e
** (modem-manager:1054): DEBUG: <1278077342.610807> (ttyUSB1): <-- 7e 00 0a 6b 24 00 00 07 00 00 00 00 00 00 00 7e
** (modem-manager:1054): DEBUG: <1278077349.610774> (ttyUSB1): <-- 7e 00 0a 6b 25 00 00 07 00 00 00 00 00 00 00 7e
** (modem-manager:1054): DEBUG: <1278077356.610695> (ttyUSB1): <-- 7e 00 0a 6b 26 00 00 07 00 00 00 00 00 00 00 7e
** (modem-manager:1054): DEBUG: <1278077363.610729> (ttyUSB1): <-- 7e 00 0a 6b 27 00 00 07 00 00 00 00 00 00 00 7e
** (modem-manager:1054): DEBUG: <1278077370.610737> (ttyUSB1): <-- 7e 00 0a 6b 28 00 00 07 00 00 00 00 00 00 00 7e
** (modem-manager:1054): DEBUG: <1278077377.606758> (ttyUSB1): <-- 7e 00 0a 6b 29 00 00 07 00 00 00 00 00 00 00 7e

so ttyUSB1 is a Sierra CnS port (their "Control and Status" protocol)
and MM isn't correctly failing out the QCDM probe.  What modem is this
again?

Does the modem flood MM with this reply?  Or does it only do these few
responses?

Dan

> > 
> >> A second problem, reported by our testorganisation is that existing
> >> connections are sometimes terminated. I cannot see the reason for this
> >> behaviour.
> > 
> > Getting logs from modem-manager and from NetworkManager with
> > NM_PPP_DEBUG=1 are helpful here:
> > 
> > http://live.gnome.org/NetworkManager/Debugging
> > 
> > I'd guess that PPP is terminating for some reason, but we need to figure
> > out why that is, and the NM PPP debug logs might help us figure that
> > out.  There are a ton of reasons why the call might get terminated, and
> > many of them are network side or handoff-related.  Or the firmware
> > screws up.  This happens on other platforms too :)
> > 
> >> And maybe there is a third problem. It looks like that it takes a long
> >> time ~6 seconds from powering up the modem until it can be used with
> >> network-manager. In the logfiles I see that the different ports are
> >> getting
> >> probed with all the available plugins. Is there any way to optimize
> this
> >> behaviour?
> > 
> > What do you mean by "powering up"?  Just plugging the modem in?
> 
> The Lenovo Laptops have a switch to disable / enable the radio devices at
> all once.
> So it looks like it's like plugging the modem in.
> 
> > 
> > You might also be forgetting about modeswitching, which takes a few
> > seconds (perhaps up to 5 or 7) depending on the device.  Otherwise,
> > there might be a few things we can do to eliminate delays, but you'll
> > also find that on other platforms things take a while to initialize too.
> > That doesn't mean we can't do better than we do right now, but there
> > will always be some amount of delay as the device is modeswitched,
> > detected, and initialized.
> 
> Ok, I understand. I will do some measurings to determinate how long it
> took with our 
> old wvdial script and the new nm / mm implementation.
> 
> > 
> > Getting the ModemManager debug logs help here.
> 
> Here it is:
> 
> http://pastebin.com/jLGNrjNq
> 
> > 
> > Note that some devices (Airlink 3GU and other Longcheer-based modems)
> > have kernel driver problems that delay their detection by up to 30 or
> > more seconds.
> > 
> > Dan