Re: issue with pptp plugin

[Trey Nolen <support internetpro net>]

On Mon, 2009-06-15 at 10:36 +0200, Axel wrote:
> Le 13/06/2009 21:15, Trey Nolen a écrit :
> > I'm running Ubuntu Jaunty using the network manager package that comes
> > with the distro.  It is version 0.7.1~rc.4.1-0ubuntu2. The
> > network-manager-pptp package is version 0.7.1~rc.4.20090316
> > +bzr23-0ubuntu3.
> >    
> 
> Would you post the log messages that seems to be related to your VPN 
> connection attempts ? (on fedora 11, you can find it in the 
> /var/log/messages file, it may be the same on ubuntu)


Here you go:

Jun 15 07:09:54 stuggots NetworkManager: <info>  VPN plugin state
changed: 3 
Jun 15 07:09:54 stuggots NetworkManager: <info>  VPN connection 'Test
VPN' (Connect) reply received. 
Jun 15 07:09:54 stuggots pppd[4731]:
Plugin /usr/lib/pppd/2.4.5//nm-pptp-pppd-plugin.so loaded.
Jun 15 07:09:54 stuggots pppd[4731]: pppd 2.4.5 started by root, uid 0
Jun 15 07:09:54 stuggots pppd[4731]: Using interface ppp0
Jun 15 07:09:54 stuggots pppd[4731]: Connect: ppp0 <--> /dev/pts/2
Jun 15 07:09:54 stuggots pptp[4735]: nm-pptp-service-4482
log[main:pptp.c:314]: The synchronous pptp option is NOT activated 
Jun 15 07:09:54 stuggots pptp[4743]: nm-pptp-service-4482
log[ctrlp_rep:pptp_ctrl.c:251]: Sent control packet type is 1
'Start-Control-Connection-Request' 
Jun 15 07:09:54 stuggots pptp[4743]: nm-pptp-service-4482
log[ctrlp_disp:pptp_ctrl.c:739]: Received Start Control Connection Reply
Jun 15 07:09:54 stuggots pptp[4743]: nm-pptp-service-4482
log[ctrlp_disp:pptp_ctrl.c:773]: Client connection established.
Jun 15 07:09:55 stuggots pptp[4743]: nm-pptp-service-4482
log[ctrlp_rep:pptp_ctrl.c:251]: Sent control packet type is 7
'Outgoing-Call-Request' 
Jun 15 07:09:55 stuggots pptp[4743]: nm-pptp-service-4482
log[ctrlp_disp:pptp_ctrl.c:858]: Received Outgoing Call Reply.
Jun 15 07:09:55 stuggots pptp[4743]: nm-pptp-service-4482
log[ctrlp_disp:pptp_ctrl.c:897]: Outgoing call established (call ID 0,
peer's call ID 5058). 
Jun 15 07:09:55 stuggots pptp[4743]: nm-pptp-service-4482
log[ctrlp_disp:pptp_ctrl.c:950]: PPTP_SET_LINK_INFO received from
peer_callid 1
Jun 15 07:09:55 stuggots pptp[4743]: nm-pptp-service-4482
log[ctrlp_disp:pptp_ctrl.c:953]:   send_accm is 00000000, recv_accm is
FFFFFFFF
Jun 15 07:09:55 stuggots pptp[4743]: nm-pptp-service-4482
warn[ctrlp_disp:pptp_ctrl.c:956]: Non-zero Async Control Character Maps
are not supported!
Jun 15 07:09:55 stuggots pppd[4731]: CHAP authentication succeeded
Jun 15 07:09:55 stuggots pppd[4731]: MPPE 128-bit stateless compression
enabled
Jun 15 07:09:57 stuggots pppd[4731]: Cannot determine ethernet address
for proxy ARP
Jun 15 07:09:57 stuggots pppd[4731]: local  IP address 192.168.4.109
Jun 15 07:09:57 stuggots pppd[4731]: remote IP address 192.168.4.115
Jun 15 07:09:57 stuggots pppd[4731]: primary   DNS address 192.168.4.14
Jun 15 07:09:57 stuggots pppd[4731]: secondary DNS address 192.168.4.249
Jun 15 07:09:57 stuggots NetworkManager: <info>  VPN connection
'RealtyBid' (IP Config Get) reply received. 
Jun 15 07:09:57 stuggots NetworkManager: <info>  VPN Gateway: 0.0.0.0 
Jun 15 07:09:57 stuggots NetworkManager: <info>  Tunnel Device: ppp0 
Jun 15 07:09:57 stuggots NetworkManager: <info>  Internal IP4 Address:
192.168.4.109 
Jun 15 07:09:57 stuggots NetworkManager: <info>  Internal IP4 Prefix:
32 
Jun 15 07:09:57 stuggots NetworkManager: <info>  Internal IP4
Point-to-Point Address: 192.168.4.115 
Jun 15 07:09:57 stuggots NetworkManager: <info>  Maximum Segment Size
(MSS): 0 
Jun 15 07:09:57 stuggots NetworkManager: <info>  Internal IP4 DNS:
192.168.4.14 
Jun 15 07:09:57 stuggots NetworkManager: <info>  Internal IP4 DNS:
192.168.4.249 
Jun 15 07:09:57 stuggots NetworkManager: <info>  DNS Domain: '(none)' 
Jun 15 07:09:57 stuggots NetworkManager: <info>  Login Banner: 
Jun 15 07:09:57 stuggots NetworkManager: <info>
----------------------------------------- 
Jun 15 07:09:57 stuggots NetworkManager: <info>  (null) 
Jun 15 07:09:57 stuggots NetworkManager: <info>
----------------------------------------- 
Jun 15 07:09:58 stuggots NetworkManager: <info>  (ppp0): writing
resolv.conf to /sbin/resolvconf 
Jun 15 07:09:58 stuggots NetworkManager: <info>  VPN connection
'RealtyBid' (IP Config Get) complete. 
Jun 15 07:09:58 stuggots NetworkManager: <info>  (eth0): writing
resolv.conf to /sbin/resolvconf 
Jun 15 07:09:58 stuggots NetworkManager: <info>  Policy set 'Auto
eth0' (eth0) as default for routing and DNS. 
Jun 15 07:09:58 stuggots NetworkManager: <info>  VPN plugin state
changed: 4 
Jun 15 07:09:58 stuggots nm-dispatcher.action: Script
'/etc/NetworkManager/dispatcher.d/01ifupdown' exited with error status
1.

--This is where it stops while the connection is connected.  Then, after
some traffic passes, you get:


Jun 15 07:10:20 stuggots pptp[4735]: nm-pptp-service-4482
warn[decaps_gre:pptp_gre.c:331]: short read (-1): Message too long
Jun 15 07:10:20 stuggots pptp[4743]: nm-pptp-service-4482
log[callmgr_main:pptp_callmgr.c:234]: Closing connection (unhandled)
Jun 15 07:10:20 stuggots pptp[4743]: nm-pptp-service-4482
log[ctrlp_rep:pptp_ctrl.c:251]: Sent control packet type is 12
'Call-Clear-Request' 
Jun 15 07:10:20 stuggots pptp[4743]: nm-pptp-service-4482
log[call_callback:pptp_callmgr.c:79]: Closing connection (call state)
Jun 15 07:10:20 stuggots pppd[4731]: Modem hangup
Jun 15 07:10:20 stuggots pppd[4731]: Connect time 0.4 minutes.
Jun 15 07:10:20 stuggots pppd[4731]: Sent 8896 bytes, received 74857
bytes.
Jun 15 07:10:20 stuggots dnsmasq[3075]: reading /etc/resolv.conf
Jun 15 07:10:20 stuggots dnsmasq[3075]: using nameserver
208.67.222.222#53
Jun 15 07:10:20 stuggots dnsmasq[3075]: using nameserver
192.168.4.249#53
Jun 15 07:10:20 stuggots dnsmasq[3075]: using nameserver 192.168.4.14#53
Jun 15 07:10:20 stuggots pppd[4731]: MPPE disabled
Jun 15 07:10:20 stuggots pppd[4731]: Connection terminated.
Jun 15 07:10:20 stuggots NetworkManager: <info>  VPN plugin state
changed: 5 
Jun 15 07:10:20 stuggots NetworkManager: <info>  VPN plugin state
changed: 6 
Jun 15 07:10:20 stuggots NetworkManager: <info>  VPN plugin state change
reason: 0 
Jun 15 07:10:20 stuggots NetworkManager: <WARN>
connection_state_changed(): Could not process the request because no VPN
connection was active. 
Jun 15 07:10:20 stuggots pppd[4731]: Exit.
Jun 15 07:10:20 stuggots NetworkManager:
nm_system_device_flush_ip4_routes_with_iface: assertion `iface_idx >= 0'
failed
Jun 15 07:10:20 stuggots NetworkManager:
nm_system_device_flush_ip4_addresses_with_iface: assertion `iface_idx >=
0' failed
Jun 15 07:10:20 stuggots NetworkManager: <info>  (ppp0): writing
resolv.conf to /sbin/resolvconf 
Jun 15 07:10:20 stuggots avahi-daemon[3401]: Withdrawing address record
for 192.168.1.167 on eth0.
Jun 15 07:10:20 stuggots avahi-daemon[3401]: Leaving mDNS multicast
group on interface eth0.IPv4 with address 192.168.1.167.
Jun 15 07:10:20 stuggots avahi-daemon[3401]: Interface eth0.IPv4 no
longer relevant for mDNS.
Jun 15 07:10:20 stuggots avahi-daemon[3401]: Joining mDNS multicast
group on interface eth0.IPv4 with address 192.168.1.167.
Jun 15 07:10:20 stuggots dnsmasq[3075]: reading /etc/resolv.conf
Jun 15 07:10:20 stuggots dnsmasq[3075]: using nameserver
208.67.220.220#53
Jun 15 07:10:20 stuggots dnsmasq[3075]: using nameserver
208.67.222.222#53
Jun 15 07:10:20 stuggots avahi-daemon[3401]: New relevant interface
eth0.IPv4 for mDNS.
Jun 15 07:10:20 stuggots avahi-daemon[3401]: Registering new address
record for 192.168.1.167 on eth0.IPv4.
Jun 15 07:10:21 stuggots NetworkManager: <info>  (eth0): writing
resolv.conf to /sbin/resolvconf 
Jun 15 07:10:21 stuggots NetworkManager: <info>  Policy set 'Auto
eth0' (eth0) as default for routing and DNS. 
Jun 15 07:10:21 stuggots nm-dispatcher.action: Script
'/etc/NetworkManager/dispatcher.d/01ifupdown' exited with error status
1.


--End Log


I had noticed the erros generated by the 01ifupdown script before, but
the VPN seems to work fine for a short time, so I'm not sure if that is
what is causing the issue.  I found some references to a bug in that
script online, but the issue did not seem to be the same as what I'm
seeing.


Trey Nolen