Re: system-connection for WWAN not working

[van Schelve <public van-schelve de>]

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.

-- 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