Re: Regression regarding 0af0:7211 from NM-0.7.0 to NM-0.7.1-rc1

[Kenneth Mokkelbost <kmokk yahoo no>]

> From: Dan Williams

> 
> On Sun, 2009-02-22 at 18:46 +0000, Kenneth Mokkelbost wrote:
> > > From: Dan Williams 
> > > 
> > > On Sun, 2009-02-22 at 15:07 +0000, Kenneth Mokkelbost wrote: 
> > > > Hi,
> > > > 
> > > > The in-built Option 3G card in Acer Aspire One is not working in 
> NM-0.7.1rc1. 
> > > In NM-0.7..0 i did. The card uses the hso driver.
> > > > 
> > > > I've tested this with both the NM-build in the latest daily Ubuntu 
> live-cd, 
> > > and with a locally compiled 0.7.1-rc1 with the same result.
> > > > 
> > > > I've attached some logs I think is relevant from both the latest live-cd 
> > > (containing  0.7.1-rc1) and the latest live-cd that contained 0.7.0. lsusb 
> and 
> > > lshal is identical between versions with regards to the device.
> > > 
> > > The logs indicate that NM found the Option card.  But there are a few
> > > issues here:
> > > 
> > > 1) It's being detected from HAL capabilities, not the built-in prober,
> > > which is what I'd expect.  What's the output of:
> > > 
> > > udevinfo --query=env --path=/sys/class/tty/ttyHS0
> > > udevinfo --query=env --path=/sys/class/tty/ttyHS1
> > > udevinfo --query=env --path=/sys/class/tty/ttyHS2
> > > udevinfo --query=env --path=/sys/class/tty/ttyHS3
> > > 
> > See attached files
> > 
> > > 2) Looks like it's using the wrong serial port, which is a problem in
> > > the HAL .fdi configuration, but shouldn't be a problem with 0.7.1rc1.
> > > Can you supply the output of the following commands?
> > > 
> > > cat /sys/class/tty/ttyHS0/hsotype
> > > cat /sys/class/tty/ttyHS1/hsotype
> > > cat /sys/class/tty/ttyHS2/hsotype
> > > cat /sys/class/tty/ttyHS3/hsotype
> > > 
> > HS0: Control
> 
> So this is the problem; HAL is reporting that HS3 is the correct one to
> use, but that's clearly not correct.  It should always be the "Control"
> one.
> 
> > HS1: Application
> > HS2: Diagnostic
> > HS3: Modem
> > 
> > 
> > > 3) What version of udev is the latest livecd running?
> > > 
> > Version 138
> > 
> > > 4) Which of these do you have?
> > > 
> > > /etc/udev/rules.d/77-nm-probe-modem-capabilities.rules
> > > /lib/udev/rules.d/77-nm-probe-modem-capabilities.rules
> > > 
> > None of them, actually
> 
> Ok, that's an Ubuntu packaging bug that you should get the Ubuntu
> developers to fix.  That's what actually makes the autodetection logic
> work :)
> 
> It occurs to me that they may not have pulled a recent enough snapshot;
> the code that's best is from Thursday or Friday this past week.  Not
> sure when Alexander Sack built the Ubuntu test packages.
> 
> Dan
> 
> > > and what do they contain?
> > > 
> > > 5) Also, is the problem that the modem doesn't *show up*, or that it
> > > cannot actually connect?  The logs you provided for NM 0.7.1rc1 don't
> > > show a connection attempt, while the logs from 0..7.0 do.  Next, the
> > > 0.7.0 logs show the is being used, which is exceptionally odd for 'hso'
> > > devices, because the driver is written specifically to avoid PPP but
> > > instead use a network device for better throughput..  So NM in 0.7.0
> > > shouldn't even be using PPP at all.
> > > 
> > > Let me know!
> > > Dan
> > 
> > Yes, the problem is that it doesn't show up. If I change the fdi to
> >    
> > it shows up, but can't connect. With 0.7.0 I can connect if the fdi is
> >    
> > which is what I wanted :)
> > 
> > Kenneth

Ok, so I've installed udev-extras and changed the fdi to HS0, but still no luck getting
the connection to succeed.

I've attached the new debug log, and as you can see the AT$QCPDPP=1,1,"","" command fails.
Might that be the culprit?

Kenneth



NetworkManager: <info>  starting...
NetworkManager: <info>  (eth0): new Ethernet device (driver: 'r8169')
NetworkManager: <info>  (eth0): exported as /org/freedesktop/Hal/devices/net_00_23_8b_14_61_d0
NetworkManager: <info>  (wlan0): driver supports SSID scans (scan_capa 0x01).
NetworkManager: <info>  (wlan0): new 802.11 WiFi device (driver: 'ath5k_pci')
NetworkManager: <info>  (wlan0): exported as /org/freedesktop/Hal/devices/net_00_23_4e_0d_7e_0a
NetworkManager: <info>  (ttyHS1): detected GSM modem via HAL capabilities
NetworkManager: <info>  (ttyHS0): detected GSM modem via HAL capabilities
NetworkManager: <info>  (ttyHS0): new Modem device (driver: 'hso')
NetworkManager: <info>  (ttyHS0): exported as /org/freedesktop/Hal/devices/usb_device_af0_7211_Serial_Number_if0_serial_unknown_0
NetworkManager: <info>  (eth0): device state change: 1 -> 2
NetworkManager: <info>  (eth0): bringing up device.
NetworkManager: <info>  (eth0): preparing device.
NetworkManager: <info>  (eth0): deactivating device (reason: 2).
NetworkManager: <info>  Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889)
NetworkManager: <info>  Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889)
NetworkManager: <info>  (wlan0): device state change: 1 -> 2
NetworkManager: <info>  (wlan0): bringing up device.
NetworkManager: <info>  (wlan0): preparing device.
NetworkManager: <info>  (wlan0): deactivating device (reason: 2).
NetworkManager: <info>  Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889)
NetworkManager: <info>  (ttyHS0): device state change: 1 -> 2
NetworkManager: <info>  (ttyHS0): deactivating device (reason: 2).
NetworkManager: nm_system_device_flush_ip4_routes_with_iface: assertion `iface_idx >= 0' failed
NetworkManager: nm_system_device_flush_ip4_addresses_with_iface: assertion `iface_idx >= 0' failed
NetworkManager: <info>  (ttyHS0): device state change: 2 -> 3
NetworkManager: <info>  Activation (ttyHS0) starting connection 'Telenor'
NetworkManager: <info>  (ttyHS0): device state change: 3 -> 4
NetworkManager: <info>  Activation (ttyHS0) Stage 1 of 5 (Device Prepare) scheduled...
NetworkManager: <info>  Activation (ttyHS0) Stage 1 of 5 (Device Prepare) started...
NetworkManager: <debug> [1235599854.327123] nm_serial_device_open(): (ttyHS0) opening device...
NetworkManager: <info>  Activation (ttyHS0) Stage 1 of 5 (Device Prepare) complete.
NetworkManager: <debug> [1235599854.427915] nm_serial_debug(): Sending: 'ATZ E0 V1 X4 &C1 +FCLASS=0
'
NetworkManager: <debug> [1235599854.564616] nm_serial_debug(): Got: '

OK

'
NetworkManager: <debug> [1235599854.564973] nm_serial_debug(): Sending: 'AT+CPIN?
'
NetworkManager: <debug> [1235599854.692571] nm_serial_debug(): Got: '

+CPIN: READY



OK

'
NetworkManager: <debug> [1235599854.692888] nm_serial_debug(): Sending: 'ATZ E0 V1 X4 &C1 +FCLASS=0
'
NetworkManager: <debug> [1235599854.820566] nm_serial_debug(): Got: '

OK

'
NetworkManager: <info>  (ttyHS0): powering up...
NetworkManager: <debug> [1235599854.820984] nm_serial_debug(): Sending: 'AT+CFUN=1
'
NetworkManager: <debug> [1235599854.948615] nm_serial_debug(): Got: '

OK

'
NetworkManager: <debug> [1235599854.948965] nm_serial_debug(): Sending: 'AT+CGMM
'
NetworkManager: <debug> [1235599855.076564] nm_serial_debug(): Got: '

GTM380



OK

'
NetworkManager: <debug> [1235599855.076896] nm_serial_debug(): Sending: 'AT+CREG?
'
NetworkManager: <debug> [1235599855.204572] nm_serial_debug(): Got: '

+CREG: 0,1



OK

'
NetworkManager: <info>  Registered on Home network
NetworkManager: <debug> [1235599855.204979] nm_serial_debug(): Sending: 'AT+COPS?
'
NetworkManager: <debug> [1235599855.332609] nm_serial_debug(): Got: '

+COPS: 0,0,"N Telenor",2



OK

'
NetworkManager: <info>  Associated with network: +COPS: 0,0,"N Telenor",2
NetworkManager: <debug> [1235599855.333114] nm_serial_debug(): Sending: 'AT+CGDCONT=1,"IP","internet"
'
NetworkManager: <debug> [1235599855.460567] nm_serial_debug(): Got: '

OK

'
NetworkManager: <info>  Activation (ttyHS0) Stage 2 of 5 (Device Configure) scheduled...
NetworkManager: <info>  Activation (ttyHS0) Stage 2 of 5 (Device Configure) starting...
NetworkManager: <info>  (ttyHS0): device state change: 4 -> 5
NetworkManager: <debug> [1235599855.621974] nm_serial_debug(): Sending: 'AT$QCPDPP=1,1,"",""
'
NetworkManager: <info>  Activation (ttyHS0) Stage 2 of 5 (Device Configure) complete.
NetworkManager: <debug> [1235599855.716571] nm_serial_debug(): Got: '

ERROR

'
NetworkManager: <WARN>  hso_auth_done(): Authentication failed
NetworkManager: <info>  (ttyHS0): device state change: 5 -> 9
NetworkManager: <debug> [1235599855.717031] nm_serial_device_close(): Closing device 'ttyHS0'
NetworkManager: <info>  Marking connection 'Telenor' invalid.
NetworkManager: <info>  Activation (ttyHS0) failed.
NetworkManager: <info>  (ttyHS0): device state change: 9 -> 3
NetworkManager: <info>  (ttyHS0): deactivating device (reason: 0).
NetworkManager: nm_system_device_flush_ip4_routes_with_iface: assertion `iface_idx >= 0' failed
NetworkManager: nm_system_device_flush_ip4_addresses_with_iface: assertion `iface_idx >= 0' failed
NetworkManager: <WARN>  nm_signal_handler(): Caught signal 2, shutting down normally.
NetworkManager: <info>  (eth0): now unmanaged
NetworkManager: <info>  (eth0): device state change: 2 -> 1
NetworkManager: <info>  (eth0): cleaning up...
NetworkManager: <info>  (eth0): taking down device.
NetworkManager: <info>  Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889)
NetworkManager: <info>  Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889)
NetworkManager: <info>  (wlan0): now unmanaged
NetworkManager: <info>  (wlan0): device state change: 2 -> 1
NetworkManager: <info>  (wlan0): cleaning up...
NetworkManager: <info>  (wlan0): taking down device.
NetworkManager: <info>  Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889)
NetworkManager: <info>  (ttyHS0): now unmanaged
NetworkManager: <info>  (ttyHS0): device state change: 3 -> 1
NetworkManager: <info>  (ttyHS0): cleaning up...
NetworkManager: <info>  (ttyHS0): taking down device.
NetworkManager: <info>  Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889)
NetworkManager: <info>  exiting (success)