On Tue, 2009-04-28 at 18:42 +0200, Alessandro Bono wrote: > On Tue, 2009-04-28 at 11:46 -0400, Dan Williams wrote: > > On Mon, 2009-04-27 at 14:14 +0200, Alessandro Bono wrote: > > > Hi > > > > > > I'm testing my new umts connection but seems there are problem with NM > > > on my system > > > I tried with two different modem (onda et505up and onda mt503hsa) with > > > the same result > > > warning "pppd_timed_out(): Looks like pppd didn't initialize our dbus > > > module" not seems influence the result, it's possible to remove this > > > warning changing a dbus acl but without any difference > > > below full log of a connection with pppd debug enabled and some info of > > > my system > > > > > > any idea how to debug or workaround this problem? > > > > Stop NM, then as root: > > > > NM_PPP_DEBUG=1 /usr/sbin/NetworkManager --no-daemon > > Hi Dan > > I tried as you suggest but not found nothing interesting > just to be sure I tried with wvdial with this configuration
What dbus version? Dan > [Dialer Defaults] > Modem = /dev/ttyUSB2 > Baud = 460800 > Init1 = ATZ > Init2 = AT+CGDCONT=1,"IP","ibox.tim.it",,0,0 > ISDN = 0 > Modem Type = Analog Modem > Carrier Check = no > Phone = *99# > Username = '' > Password = '' > > and connection works without problem > > below a full log with NM_PPP_DEBUG (I tried with and without username > and password) > > > NetworkManager: <info> Activation (ttyUSB2) starting connection 'TIM' > NetworkManager: <info> (ttyUSB2): device state change: 3 -> 4 > NetworkManager: <info> Activation (ttyUSB2) Stage 1 of 5 (Device > Prepare) scheduled... > NetworkManager: <info> Activation (ttyUSB2) Stage 1 of 5 (Device > Prepare) started... > NetworkManager: <debug> [1240936873.552324] nm_serial_device_open(): > (ttyUSB2) opening device... > NetworkManager: <info> Activation (ttyUSB2) Stage 1 of 5 (Device > Prepare) complete. > NetworkManager: <info> (ttyUSB2): powering > up... > NetworkManager: <info> Registered on Home > network > NetworkManager: <info> Associated with network: +COPS: 0,0,"Telecom > Italia Mobile",2 > NetworkManager: <info> Connected, > Woo! > 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 > NetworkManager: <info> Starting pppd > connection > NetworkManager: <debug> [1240936875.322454] nm_ppp_manager_start(): > Command line: /usr/sbin/pppd nodetach lock nodefaultroute debug ttyUSB2 > noipdefault noauth usepeerdns lcp-echo-failure 0 lcp-echo-interval 0 > ipparam /org/freedesktop/NetworkManager/PPP/1 > plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so > > > Plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so > loaded. > > > NetworkManager: <debug> [1240936875.342187] nm_ppp_manager_start(): ppp > started with pid > 7319 > > NetworkManager: <info> Activation (ttyUSB2) Stage 2 of 5 (Device > Configure) > complete. > > > using channel > 2 > > > Using interface > ppp0 > > > Connect: ppp0 > <--> /dev/ttyUSB2 > > > sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x2874a5b2> <pcomp> > <accomp>] > > > rcvd [LCP ConfReq id=0x3 <asyncmap 0x0> <auth chap MD5> <magic > 0x117ef87> <pcomp> <accomp>] > sent [LCP ConfAck id=0x3 <asyncmap 0x0> <auth chap MD5> <magic > 0x117ef87> <pcomp> <accomp>] > rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0x2874a5b2> <pcomp> > <accomp>] > rcvd [LCP DiscReq id=0x4 magic=0x117ef87] > rcvd [CHAP Challenge id=0x1 <3824bee55e4e3c26ee103d41b89a2210>, name = > "UMTS_CHAP_SRVR"] > > ** (process:7319): WARNING **: Could not get secrets: Rejected send > message, 7 matched rules; type="method_call", sender=":1.72" (uid=0 > pid=7319 comm="/usr/sbin/pppd nodetach lock nodefaultroute debug ") > interface="org.freedesktop.NetworkManager.PPP" member="NeedSecrets" > error name="(unset)" requested_reply=0 > destination="org.freedesktop.NetworkManager" (uid=0 pid=5936 > comm="/usr/sbin/NetworkManager --no-daemon ")) > Unable to obtain CHAP password for champagne on UMTS_CHAP_SRVR from > plugin > No CHAP secret found for authenticating us to UMTS_CHAP_SRVR > sent [CHAP Response id=0x1 <ca8c2baa0c5a38f79113f9736cbdc716>, name = > "champagne"] > rcvd [CHAP Success id=0x1 ""] > CHAP authentication succeeded > CHAP authentication succeeded > sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>] > sent [IPCP ConfReq id=0x1 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 > 0.0.0.0> <ms-dns2 0.0.0.0>] > rcvd [LCP ProtRej id=0x5 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> > <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>] > sent [IPCP ConfReq id=0x2 <compress VJ 0f 01> <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> > <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>] > sent [IPCP ConfReq id=0x3 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 > 10.11.12.13> <ms-dns2 10.11.12.14>] > rcvd [IPCP ConfReq id=0x2] > sent [IPCP ConfNak id=0x2 <addr 0.0.0.0>] > rcvd [IPCP ConfRej id=0x3 <compress VJ 0f 01>] > sent [IPCP ConfReq id=0x4 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 > 10.11.12.14>] > rcvd [IPCP ConfReq id=0x3] > sent [IPCP ConfAck id=0x3] > rcvd [IPCP ConfNak id=0x4 <addr 217.202.217.135> <ms-dns1 > 213.230.128.222> <ms-dns2 213.230.129.94>] > sent [IPCP ConfReq id=0x5 <addr 217.202.217.135> <ms-dns1 > 213.230.128.222> <ms-dns2 213.230.129.94>] > rcvd [IPCP ConfAck id=0x5 <addr 217.202.217.135> <ms-dns1 > 213.230.128.222> <ms-dns2 213.230.129.94>] > Could not determine remote IP address: defaulting to 10.64.64.64 > Cannot determine ethernet address for proxy ARP > local IP address 217.202.217.135 > remote IP address 10.64.64.64 > primary DNS address 213.230.128.222 > secondary DNS address 213.230.129.94 > Script /etc/ppp/ip-up started (pid 7324) > Script /etc/ppp/ip-up finished (pid 7324), status = 0x0 > NetworkManager: <WARN> pppd_timed_out(): Looks like pppd didn't > initialize our dbus module > NetworkManager: <info> (ttyUSB2): device state change: 5 -> 9 > Terminating on signal 15 > NetworkManager: <debug> [1240936891.003005] nm_serial_device_close(): > Closing device 'ttyUSB2' > Connect time 0.3 minutes. > Sent 0 bytes, received 144 bytes. > NetworkManager: <info> Marking connection 'TIM' invalid. > NetworkManager: <info> Activation (ttyUSB2) failed. > NetworkManager: <info> (ttyUSB2): device state change: 9 -> 3 > NetworkManager: <info> (ttyUSB2): 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 > Script /etc/ppp/ip-down started (pid 7400) > sent [LCP TermReq id=0x2 "User request"] > rcvd [LCP TermAck id=0x2] > Connection terminated. > Script /etc/ppp/ip-down finished (pid 7400), status = 0x0 > NetworkManager: <debug> [1240936893.001609] ensure_killed(): waiting for > ppp pid 7319 to exit > NetworkManager: <debug> [1240936893.001772] ensure_killed(): ppp pid > 7319 cleaned up > > > > > > and lets see what PPP thinks. You probably also want to try setting a > > username and password explicitly, which some devices seem to really > > want. > > > > Dan > > > > > thanks > > > > > > ps please cc to me, I'm not subscribed to ml > > > > > > distribution ubuntu jaunty 64bit > > > > > > dpkg -l | grep network-manager > > > ii network-manager > > > 0.7.1~rc4.1.cf199a964-0ubuntu2 network > > > management framework daemon > > > ii network-manager-gnome 0.7.1~rc4.1-0ubuntu2 > > > network management framework (GNOME frontend > > > ii network-manager-openvpn 0.7.1~rc4.1.20090323 > > > +bzr27-0ubuntu2 network management framework > > > (OpenVPN plugin > > > ii network-manager-pptp 0.7.1~rc4.20090316 > > > +bzr23-0ubuntu3 network management framework > > > (PPTP plugin) > > > ii network-manager-vpnc 0.7.1~rc4.20090316 > > > +bzr21-0ubuntu2 network management framework > > > (VPNC plugin) > > > > > > dpkg -l | grep ppp > > > ii ppp > > > 2.4.5~git20081126t100229-0ubuntu2 > > > Point-to-Point Protocol (PPP) - daemon > > > > > > > > > Apr 27 14:05:08 champagne NetworkManager: <info> Activation (ttyUSB2) > > > starting connection > > > 'TIM' > > > > > > Apr 27 14:05:08 champagne NetworkManager: <info> (ttyUSB2): device > > > state change: 3 -> > > > 4 > > > > > > Apr 27 14:05:08 champagne NetworkManager: <info> Activation (ttyUSB2) > > > Stage 1 of 5 (Device Prepare) > > > scheduled... > > > > > > Apr 27 14:05:08 champagne NetworkManager: <info> Activation (ttyUSB2) > > > Stage 1 of 5 (Device Prepare) > > > started... > > > > > > Apr 27 14:05:08 champagne NetworkManager: <debug> [1240833908.133093] > > > nm_serial_device_open(): (ttyUSB2) opening > > > device... > > > > > > Apr 27 14:05:08 champagne NetworkManager: <info> Activation (ttyUSB2) > > > Stage 1 of 5 (Device Prepare) > > > complete. > > > > > > Apr 27 14:05:08 champagne NetworkManager: <info> (ttyUSB2): powering > > > up... > > > > > > Apr 27 14:05:08 champagne NetworkManager: <info> Registered on Home > > > network > > > > > > Apr 27 14:05:08 champagne NetworkManager: <info> Associated with > > > network: +COPS: 0,0,"Telecom Italia > > > Mobile",0 > > > > > > Apr 27 14:05:08 champagne NetworkManager: <info> Connected, > > > Woo! > > > > > > Apr 27 14:05:08 champagne NetworkManager: <info> Activation (ttyUSB2) > > > Stage 2 of 5 (Device Configure) > > > scheduled... > > > > > > Apr 27 14:05:08 champagne NetworkManager: <info> Activation (ttyUSB2) > > > Stage 2 of 5 (Device Configure) > > > starting... > > > > > > Apr 27 14:05:08 champagne NetworkManager: <info> (ttyUSB2): device > > > state change: 4 -> > > > 5 > > > > > > Apr 27 14:05:08 champagne NetworkManager: <info> Starting pppd > > > connection > > > > > > Apr 27 14:05:08 champagne NetworkManager: <debug> [1240833908.566302] > > > nm_ppp_manager_start(): Command line: /usr/sbin/pppd nodetach lock > > > nodefaultroute 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 > > > > > > Apr 27 14:05:08 champagne NetworkManager: <debug> [1240833908.577009] > > > nm_ppp_manager_start(): ppp started with pid > > > 17545 > > > > > > Apr 27 14:05:08 champagne NetworkManager: <info> Activation (ttyUSB2) > > > Stage 2 of 5 (Device Configure) > > > complete. > > > > > > Apr 27 14:05:08 champagne pppd[17545]: > > > Plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so > > > loaded. > > > > > > Apr 27 14:05:08 champagne pppd[17545]: pppd 2.4.5 started by root, uid > > > 0 > > > > > > Apr 27 14:05:08 champagne pppd[17545]: using channel > > > 6 > > > > > > > > > Apr 27 14:05:08 champagne pppd[17545]: Using interface > > > ppp0 > > > > > > > > > Apr 27 14:05:08 champagne pppd[17545]: Connect: ppp0 > > > <--> /dev/ttyUSB2 > > > > > > > > > Apr 27 14:05:08 champagne pppd[17545]: sent [LCP ConfReq id=0x1 > > > <asyncmap 0x0> <magic 0x69f9c20a> <pcomp> > > > <accomp>] > > > > > > Apr 27 14:05:08 champagne pppd[17545]: rcvd [LCP ConfReq id=0x3 > > > <asyncmap 0x0> <auth chap MD5> <magic 0x143273a> <pcomp> > > > <accomp>] > > > > > > Apr 27 14:05:08 champagne pppd[17545]: sent [LCP ConfAck id=0x3 > > > <asyncmap 0x0> <auth chap MD5> <magic 0x143273a> <pcomp> > > > <accomp>] > > > > > > Apr 27 14:05:08 champagne pppd[17545]: rcvd [LCP ConfAck id=0x1 > > > <asyncmap 0x0> <magic 0x69f9c20a> <pcomp> > > > <accomp>] > > > > > > Apr 27 14:05:08 champagne pppd[17545]: rcvd [LCP DiscReq id=0x4 > > > magic=0x143273a] > > > > > > Apr 27 14:05:08 champagne pppd[17545]: rcvd [CHAP Challenge id=0x1 > > > <185744973e36b20764240745a244e6d7>, name = > > > "UMTS_CHAP_SRVR"] > > > > > > Apr 27 14:05:08 champagne pppd[17545]: Unable to obtain CHAP password > > > for champagne on UMTS_CHAP_SRVR from > > > plugin > > > > > > Apr 27 14:05:08 champagne pppd[17545]: No CHAP secret found for > > > authenticating us to > > > UMTS_CHAP_SRVR > > > > > > Apr 27 14:05:08 champagne pppd[17545]: sent [CHAP Response id=0x1 > > > <1c5af77c60e557b78d5037f01e6b393e>, name = > > > "champagne"] > > > > > > Apr 27 14:05:08 champagne pppd[17545]: rcvd [CHAP Success id=0x1 > > > ""] > > > > > > Apr 27 14:05:08 champagne pppd[17545]: CHAP authentication > > > succeeded > > > > > > Apr 27 14:05:08 champagne pppd[17545]: CHAP authentication > > > succeeded > > > > > > Apr 27 14:05:08 champagne pppd[17545]: sent [CCP ConfReq id=0x1 <deflate > > > 15> <deflate(old#) 15> <bsd v1 15>] > > > Apr 27 14:05:08 champagne pppd[17545]: sent [IPCP ConfReq id=0x1 > > > <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>] > > > Apr 27 14:05:08 champagne pppd[17545]: rcvd [LCP ProtRej id=0x5 80 fd 01 > > > 01 00 0f 1a 04 78 00 18 04 78 00 15 03 2f] > > > Apr 27 14:05:08 champagne pppd[17545]: Protocol-Reject for 'Compression > > > Control Protocol' (0x80fd) received > > > Apr 27 14:05:09 champagne pppd[17545]: rcvd [IPCP ConfReq id=0x2] > > > Apr 27 14:05:09 champagne pppd[17545]: sent [IPCP ConfNak id=0x2 <addr > > > 0.0.0.0>] > > > Apr 27 14:05:09 champagne pppd[17545]: rcvd [IPCP ConfRej id=0x1 > > > <compress VJ 0f 01>] > > > Apr 27 14:05:09 champagne pppd[17545]: sent [IPCP ConfReq id=0x2 <addr > > > 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>] > > > Apr 27 14:05:09 champagne pppd[17545]: rcvd [IPCP ConfReq id=0x3] > > > Apr 27 14:05:09 champagne pppd[17545]: sent [IPCP ConfAck id=0x3] > > > Apr 27 14:05:09 champagne pppd[17545]: rcvd [IPCP ConfNak id=0x2 <addr > > > 217.202.5.135> <ms-dns1 213.230.129.94> <ms-dns2 213.230.128.222>] > > > Apr 27 14:05:09 champagne pppd[17545]: sent [IPCP ConfReq id=0x3 <addr > > > 217.202.5.135> <ms-dns1 213.230.129.94> <ms-dns2 213.230.128.222>] > > > Apr 27 14:05:09 champagne pppd[17545]: rcvd [IPCP ConfAck id=0x3 <addr > > > 217.202.5.135> <ms-dns1 213.230.129.94> <ms-dns2 213.230.128.222>] > > > Apr 27 14:05:09 champagne pppd[17545]: Could not determine remote IP > > > address: defaulting to 10.64.64.64 > > > Apr 27 14:05:09 champagne pppd[17545]: Cannot determine ethernet address > > > for proxy ARP > > > Apr 27 14:05:09 champagne pppd[17545]: local IP address 217.202.5.135 > > > Apr 27 14:05:09 champagne pppd[17545]: remote IP address 10.64.64.64 > > > Apr 27 14:05:09 champagne pppd[17545]: primary DNS address > > > 213.230.129.94 > > > Apr 27 14:05:09 champagne pppd[17545]: secondary DNS address > > > 213.230.128.222 > > > Apr 27 14:05:09 champagne pppd[17545]: Script /etc/ppp/ip-up started > > > (pid 17550) > > > Apr 27 14:05:13 champagne postfix/master[3803]: reload > > > configuration /etc/postfix > > > Apr 27 14:05:13 champagne pppd[17545]: Script /etc/ppp/ip-up finished > > > (pid 17550), status = 0x0 > > > Apr 27 14:05:24 champagne NetworkManager: <WARN> pppd_timed_out(): > > > Looks like pppd didn't initialize our dbus module > > > Apr 27 14:05:24 champagne NetworkManager: <info> (ttyUSB2): device > > > state change: 5 -> 9 > > > Apr 27 14:05:24 champagne NetworkManager: <debug> [1240833924.005739] > > > nm_serial_device_close(): Closing device 'ttyUSB2' > > > Apr 27 14:05:24 champagne pppd[17545]: Terminating on signal 15 > > > Apr 27 14:05:24 champagne pppd[17545]: Connect time 0.3 minutes. > > > Apr 27 14:05:24 champagne pppd[17545]: Sent 0 bytes, received 721 bytes. > > > Apr 27 14:05:24 champagne NetworkManager: <info> Marking connection > > > 'TIM' invalid. > > > Apr 27 14:05:24 champagne NetworkManager: <info> Activation (ttyUSB2) > > > failed. > > > Apr 27 14:05:24 champagne NetworkManager: <info> (ttyUSB2): device > > > state change: 9 -> 3 > > > Apr 27 14:05:24 champagne NetworkManager: <info> (ttyUSB2): > > > deactivating device (reason: 0). > > > Apr 27 14:05:24 champagne dnsmasq[3777]: reading /etc/resolv.conf > > > Apr 27 14:05:24 champagne dnsmasq[3777]: using nameserver > > > 192.168.0.11#53 > > > Apr 27 14:05:24 champagne dnsmasq[3777]: using nameserver > > > 213.230.128.222#53 > > > Apr 27 14:05:24 champagne dnsmasq[3777]: using nameserver > > > 213.230.129.94#53 > > > Apr 27 14:05:24 champagne NetworkManager: <info> (eth0): writing > > > resolv.conf to /sbin/resolvconf > > > Apr 27 14:05:24 champagne pppd[17545]: Script /etc/ppp/ip-down started > > > (pid 17626) > > > Apr 27 14:05:24 champagne pppd[17545]: sent [LCP TermReq id=0x2 "User > > > request"] > > > Apr 27 14:05:24 champagne pppd[17545]: rcvd [LCP TermAck id=0x2] > > > Apr 27 14:05:24 champagne NetworkManager: <info> Policy set 'Auto > > > eth0' (eth0) as default for routing and DNS. > > > Apr 27 14:05:24 champagne NetworkManager: > > > nm_system_device_flush_ip4_routes_with_iface: assertion `iface_idx >= 0' > > > failed > > > Apr 27 14:05:24 champagne NetworkManager: > > > nm_system_device_flush_ip4_addresses_with_iface: assertion `iface_idx >= > > > 0' failed > > > Apr 27 14:05:24 champagne pppd[17545]: Connection terminated. > > > Apr 27 14:05:24 champagne postfix/master[3803]: reload > > > configuration /etc/postfix > > > Apr 27 14:05:24 champagne pppd[17545]: Script /etc/ppp/ip-down finished > > > (pid 17626), status = 0x0 > > > Apr 27 14:05:24 champagne pppd[17545]: Exit. > > > Apr 27 14:05:26 champagne NetworkManager: <debug> [1240833926.002163] > > > ensure_killed(): waiting for ppp pid 17545 to exit > > > Apr 27 14:05:26 champagne NetworkManager: <debug> [1240833926.002312] > > > ensure_killed(): ppp pid 17545 cleaned up > > > > > > > > _______________________________________________ NetworkManager-list mailing list NetworkManager-list@gnome.org http://mail.gnome.org/mailman/listinfo/networkmanager-list