Re: system-connection for WWAN not working

[Dan Williams <dcbw redhat com>]

On Wed, 2009-11-18 at 13:46 +0100, van Schelve wrote:
> Hi!
> 
> I have received the logs from our radius server during my unsuccessful
> dial up:
> 
> Wed Nov 18 08:48:18 2009 : Auth: Login incorrect (rlm_chap: Wrong user
> password): [49160--------/<CHAP-Password>] (from client tmobwanip port 0
> cli 49160--------)
> Wed Nov 18 08:56:36 2009 : Auth: Login incorrect (rlm_chap: Wrong user
> password): [49160--------/<CHAP-Password>] (from client tmobwanip port 0
> cli 49160--------)
> 
> So it looks like to me that if the connection is system-wide pppd doesn't
> get chap credentials. This suspiction suggests itself because the t-mobile
> connection works. But this connection does not need a chap / pap password.
> 
> I tested to put username / password in /etc/ppp/{pap,chap}-secrets but
> this does not help.

I may have just fixed this the other day:

1151ac24782a4fd1a70a18849bc20a0e9bf970e1
0bbdc6b0fc3ca7425bb4e289571b014561b609d1
b135fa3265d1d684a93cb554a4c3f4690962f773

I'll re-test with a system WWAN connection and make sure.

Dan

> -- Hans-Gerd
> 
> On Wed, 18 Nov 2009 09:13:08 +0100, van Schelve <public van-schelve de>
> wrote:
> > Dan, Eugene.
> > 
> > I have captured the debug from this connection while not available as
> > system-connection. It works in this case as you can see:
> > 
> > NetworkManager: Tried to set deprecated property gsm/band
> > NetworkManager: Tried to set deprecated property gsm/band
> > NetworkManager: Tried to set deprecated property gsm/band
> > NetworkManager: Tried to set deprecated property gsm/band
> > NetworkManager: <info>  (ttyUSB2): new GSM device (driver: 'sierra')
> > NetworkManager: <info>  (ttyUSB2): exported as
> > /org/freedesktop/NetworkManager/Devices/3
> > NetworkManager: <info>  (ttyUSB2): now managed
> > NetworkManager: <info>  (ttyUSB2): device state change: 1 -> 2 (reason
> 2)
> > NetworkManager: <info>  (ttyUSB2): deactivating device (reason: 2).
> > NetworkManager: flush_routes: assertion `iface_idx >= 0' failed
> > NetworkManager: flush_addresses: assertion `iface_idx >= 0' failed
> > NetworkManager: <info>  (ttyUSB2): device state change: 2 -> 3 (reason
> 0)
> > NetworkManager: <info>  Activation (ttyUSB2) starting connection
> 'MyWWAN'
> > NetworkManager: <info>  (ttyUSB2): device state change: 3 -> 4 (reason
> 0)
> > NetworkManager: <info>  Activation (ttyUSB2) Stage 1 of 5 (Device
> Prepare)
> > scheduled...
> > NetworkManager: <info>  Activation (ttyUSB2) Stage 1 of 5 (Device
> Prepare)
> > started...
> > NetworkManager: <info>  (ttyUSB2): device state change: 4 -> 6 (reason
> 0)
> > NetworkManager: <info>  Activation (ttyUSB2) Stage 1 of 5 (Device
> Prepare)
> > complete.
> > NetworkManager: <info>  Activation (ttyUSB2) Stage 1 of 5 (Device
> Prepare)
> > scheduled...
> > NetworkManager: <info>  Activation (ttyUSB2) Stage 1 of 5 (Device
> Prepare)
> > started...
> > NetworkManager: <info>  (ttyUSB2): device state change: 6 -> 4 (reason
> 0)
> > NetworkManager: <info>  Activation (ttyUSB2) Stage 1 of 5 (Device
> Prepare)
> > complete.
> > NetworkManager: <info>  Activation (ttyUSB2) Stage 2 of 5 (Device
> > Configure) scheduled...
> > NetworkManager: <info>  Activation (ttyUSB2) Stage 2 of 5 (Device
> > Configure) starting...
> > NetworkManager: <info>  (ttyUSB2): device state change: 4 -> 5 (reason
> 0)
> > NetworkManager: <info>  Activation (ttyUSB2) Stage 2 of 5 (Device
> > Configure) successful.
> > NetworkManager: <info>  Activation (ttyUSB2) Stage 3 of 5 (IP Configure
> > Start) scheduled.
> > NetworkManager: <info>  Activation (ttyUSB2) Stage 2 of 5 (Device
> > Configure) complete.
> > NetworkManager: <info>  Activation (ttyUSB2) Stage 3 of 5 (IP Configure
> > Start) started...
> > NetworkManager: <info>  (ttyUSB2): device state change: 5 -> 7 (reason
> 0)
> > NetworkManager: <info>  Starting pppd connection
> > NetworkManager: <debug> [1258531195.240804] nm_ppp_manager_start():
> > Command line: /usr/sbin/pppd nodetach lock nodefaultroute debug user
> > username ttyUSB2 noipdefault noauth usepeerdns lcp-echo-failure 0
> > lcp-echo-interval 0 ipparam /org/freedesktop/NetworkManager/PPP/0 plugin
> > /usr/lib/pppd/2.4.4/nm-pppd-plugin.so
> > Plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so loaded.
> > ** Message: nm-ppp-plugin: (plugin_init): initializing
> > NetworkManager: <debug> [1258531195.258102] nm_ppp_manager_start(): ppp
> > started with pid 9331
> > NetworkManager: <info>  Activation (ttyUSB2) Stage 4 of 5 (IP6 Configure
> > Get) scheduled...
> > NetworkManager: <info>  Activation (ttyUSB2) Stage 3 of 5 (IP Configure
> > Start) complete.
> > NetworkManager: <info>  Activation (ttyUSB2) Stage 4 of 5 (IP6 Configure
> > Get) started...
> > NetworkManager: <info>  Activation (ttyUSB2) Stage 4 of 5 (IP6 Configure
> > Get) complete.
> > ** Message: nm-ppp-plugin: (nm_phasechange): status 3 / phase 'serial
> > connection'
> > Removed stale lock on ttyUSB2 (pid 9216)
> > using channel 7
> > Using interface ppp0
> > Connect: ppp0 <--> /dev/ttyUSB2
> > ** Message: nm-ppp-plugin: (nm_phasechange): status 5 / phase
> 'establish'
> > sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xd8437790> <pcomp>
> > <accomp>]
> > NetworkManager:    SCPlugin-Ifupdown: devices added (path:
> > /sys/devices/virtual/net/ppp0, iface: ppp0)
> > NetworkManager:    SCPlugin-Ifupdown: device added (path:
> > /sys/devices/virtual/net/ppp0, iface: ppp0): no ifupdown configuration
> > found.
> > rcvd [LCP ConfReq id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0xc4897c>
> > <pcomp> <accomp>]
> > sent [LCP ConfAck id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0xc4897c>
> > <pcomp> <accomp>]
> > rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0xd8437790> <pcomp>
> > <accomp>]
> > ** Message: nm-ppp-plugin: (nm_phasechange): status 6 / phase
> > 'authenticate'
> > rcvd [LCP DiscReq id=0x1 magic=0xc4897c]
> > rcvd [CHAP Challenge id=0x1 <7e969b37b646b5c728bd354e34b515aa>, name =
> > "UMTS_CHAP_SRVR"]
> > ** Message: nm-ppp-plugin: (get_credentials): passwd-hook, requesting
> > credentials...
> > ** Message: nm-ppp-plugin: (get_credentials): got credentials from
> > NetworkManager
> > sent [CHAP Response id=0x1 <332d24b44f6834bd0ecc62af3b7fd0d6>, name =
> > "username"]
> > rcvd [CHAP Success id=0x1 ""]
> > CHAP authentication succeeded
> > CHAP authentication succeeded
> > ** Message: nm-ppp-plugin: (nm_phasechange): status 8 / phase 'network'
> > sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
> > sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2
> > 0.0.0.0>]
> > rcvd [LCP ProtRej id=0x2 80 fd 01 01 00 0f 1a 04 78 00 18 04 78 00 15 03
> > 2f]
> > Protocol-Reject for 'Compression Control Protocol' (0x80fd) received
> > rcvd [IPCP ConfNak id=0x1 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
> > sent [IPCP ConfReq id=0x2 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2
> > 10.11.12.14>]
> > rcvd [IPCP ConfNak id=0x2 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
> > sent [IPCP ConfReq id=0x3 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2
> > 10.11.12.14>]
> > rcvd [IPCP ConfNak id=0x3 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
> > sent [IPCP ConfReq id=0x4 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2
> > 10.11.12.14>]
> > rcvd [IPCP ConfNak id=0x4 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
> > sent [IPCP ConfReq id=0x5 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2
> > 10.11.12.14>]
> > rcvd [IPCP ConfNak id=0x5 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
> > sent [IPCP ConfReq id=0x6 <addr 0.0.0.0>]
> > rcvd [IPCP ConfNak id=0x6 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
> > sent [IPCP ConfReq id=0x7 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2
> > 10.11.12.14>]
> > rcvd [IPCP ConfNak id=0x7 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
> > sent [IPCP ConfReq id=0x8 <addr 0.0.0.0>]
> > rcvd [IPCP ConfReq id=0x0]
> > sent [IPCP ConfNak id=0x0 <addr 0.0.0.0>]
> > rcvd [IPCP ConfNak id=0x8 <addr 10.33.145.106>]
> > sent [IPCP ConfReq id=0x9]
> > rcvd [IPCP ConfNak id=0x9 <addr 10.33.145.106>]
> > sent [IPCP ConfReq id=0xa <addr 10.33.145.106>]
> > rcvd [IPCP ConfAck id=0xa <addr 10.33.145.106>]
> > rcvd [IPCP ConfReq id=0x1]
> > sent [IPCP ConfAck id=0x1]
> > Could not determine remote IP address: defaulting to 10.64.64.64
> > Cannot determine ethernet address for proxy ARP
> > local  IP address 10.33.145.106
> > remote IP address 10.64.64.64
> > ** Message: nm-ppp-plugin: (nm_phasechange): status 9 / phase 'running'
> > ** Message: nm-ppp-plugin: (nm_ip_up): ip-up event
> > ** Message: nm-ppp-plugin: (nm_ip_up): sending Ip4Config to
> > NetworkManager...
> > Script /etc/ppp/ip-up started (pid 9334)
> > NetworkManager: <info>  PPP manager(IP Config Get) reply received.
> > NetworkManager: <info>  Activation (ttyUSB2) Stage 4 of 5 (IP4 Configure
> > Get) scheduled...
> > NetworkManager: <info>  Activation (ttyUSB2) Stage 4 of 5 (IP4 Configure
> > Get) started...
> > NetworkManager: <info>  Activation (ttyUSB2) Stage 5 of 5 (IP Configure
> > Commit) scheduled...
> > NetworkManager: <info>  Activation (ttyUSB2) Stage 4 of 5 (IP4 Configure
> > Get) complete.
> > NetworkManager: <info>  Activation (ttyUSB2) Stage 5 of 5 (IP Configure
> > Commit) started...
> > Script /etc/ppp/ip-up finished (pid 9334), status = 0x0
> > NetworkManager: <info>  Policy set 'Auto eth0' (eth0) as default for
> > routing and DNS.
> > NetworkManager: <info>  (ttyUSB2): device state change: 7 -> 8 (reason
> 0)
> > NetworkManager: <info>  Activation (ttyUSB2) successful, device
> activated.
> > NetworkManager: <info>  Activation (ttyUSB2) Stage 5 of 5 (IP Configure
> > Commit) complete.
> > NetworkManager: Tried to set deprecated property gsm/band
> > NetworkManager: Tried to set deprecated property gsm/band
> > NetworkManager: Tried to set deprecated property gsm/band
> > NetworkManager: Tried to set deprecated property gsm/band
> > NetworkManager: <WARN>  nm_signal_handler(): Caught signal 2, shutting
> > down normally.
> > NetworkManager: <info>  (wlan0): taking down device.
> > NetworkManager: <info>  (ttyUSB2): now unmanaged
> > NetworkManager: <info>  (ttyUSB2): device state change: 8 -> 1 (reason
> 36)
> > NetworkManager: <info>  (ttyUSB2): deactivating device (reason: 36).
> > NetworkManager: <info>  (ttyUSB2): cleaning up...
> > NetworkManager: <info>  (ttyUSB2): taking down device.
> > Terminating on signal 15
> > ** Message: nm-ppp-plugin: (nm_phasechange): status 10 / phase
> 'terminate'
> > ** Message: nm-ppp-plugin: (nm_phasechange): status 8 / phase 'network'
> > Connect time 0.6 minutes.
> > Sent 0 bytes, received 0 bytes.
> > 
> > (NetworkManager:9221): GLib-GObject-CRITICAL **: g_object_unref:
> assertion
> > `G_IS_OBJECT (object)' failed
> > NetworkManager: <info>  exiting (success)
> > Script /etc/ppp/ip-down started (pid 9405)
> > ** Message: nm-ppp-plugin: (nm_phasechange): status 5 / phase
> 'establish'
> > sent [LCP TermReq id=0x2 "User request"]
> > rcvd [LCP TermAck id=0x2]
> > ** Message: nm-ppp-plugin: (nm_phasechange): status 11 / phase
> > 'disconnect'
> > Connection terminated.
> > ** Message: nm-ppp-plugin: (nm_phasechange): status 1 / phase 'dead'
> > Script /etc/ppp/ip-down finished (pid 9405), status = 0x0
> > ** Message: nm-ppp-plugin: (nm_exit_notify): cleaning up
> > 
> > 
> > I tried again the system-connection with -vj option in /etc/ppp/options
> > but it's still not working.
> > 
> > -- Hans-Gerd
> > _______________________________________________
> > NetworkManager-list mailing list
> > NetworkManager-list gnome org
> > http://mail.gnome.org/mailman/listinfo/networkmanager-list
> _______________________________________________
> NetworkManager-list mailing list
> NetworkManager-list gnome org
> http://mail.gnome.org/mailman/listinfo/networkmanager-list