VPN - short read (-1): 'Message too long'
So I'm trying to use my VPN at a hotel wifi where I'm on a vacation, but for some reason I get this annoying problem. When I connect to my VPN in about a few seconds it breaks, and syslog shows:
Jun 14 20:51:14 botev-ThinkPad-T440 NetworkManager[845]: <info> Starting VPN service 'pptp'...
Jun 14 20:51:14 botev-ThinkPad-T440 NetworkManager[845]: <info> VPN service 'pptp' started (org.freedesktop.NetworkManager.pptp), PID 9778
Jun 14 20:51:14 botev-ThinkPad-T440 NetworkManager[845]: <info> VPN service 'pptp' appeared; activating connections
Jun 14 20:51:14 botev-ThinkPad-T440 NetworkManager[845]: <info> VPN plugin state changed: init (1)
Jun 14 20:51:14 botev-ThinkPad-T440 NetworkManager[845]: <info> VPN plugin state changed: starting (3)
Jun 14 20:51:14 botev-ThinkPad-T440 NetworkManager[845]: <info> VPN connection 'UCL CS VPN' (Connect) reply received.
Jun 14 20:51:14 botev-ThinkPad-T440 pppd[9783]: Plugin /usr/lib/pppd/2.4.5/nm-pptp-pppd-plugin.so loaded.
Jun 14 20:51:14 botev-ThinkPad-T440 pppd[9783]: pppd 2.4.5 started by root, uid 0
Jun 14 20:51:14 botev-ThinkPad-T440 pppd[9783]: Using interface ppp0
Jun 14 20:51:14 botev-ThinkPad-T440 pppd[9783]: Connect: ppp0 <--> /dev/pts/9
Jun 14 20:51:14 botev-ThinkPad-T440 pptp[9787]: nm-pptp-service-9778 log[main:pptp.c:314]: The synchronous pptp option is NOT activated
Jun 14 20:51:14 botev-ThinkPad-T440 NetworkManager[845]: SCPlugin-Ifupdown: devices added (path: /sys/devices/virtual/net/ppp0, iface: ppp0)
Jun 14 20:51:14 botev-ThinkPad-T440 NetworkManager[845]: SCPlugin-Ifupdown: device added (path: /sys/devices/virtual/net/ppp0, iface: ppp0): no ifupdown configuration found.
Jun 14 20:51:14 botev-ThinkPad-T440 NetworkManager[845]: <warn> /sys/devices/virtual/net/ppp0: couldn't determine device driver; ignoring...
Jun 14 20:51:14 botev-ThinkPad-T440 kernel: [ 5763.841477] init: network-interface (ppp0) pre-start process (9794) terminated with status 1
Jun 14 20:51:14 botev-ThinkPad-T440 kernel: [ 5763.846659] init: network-interface (ppp0) post-stop process (9802) terminated with status 1
Jun 14 20:51:14 botev-ThinkPad-T440 pptp[9807]: nm-pptp-service-9778 log[ctrlp_rep:pptp_ctrl.c:251]: Sent control packet type is 1 'Start-Control-Connection-Request'
Jun 14 20:51:14 botev-ThinkPad-T440 pptp[9807]: nm-pptp-service-9778 log[ctrlp_disp:pptp_ctrl.c:739]: Received Start Control Connection Reply
Jun 14 20:51:14 botev-ThinkPad-T440 pptp[9807]: nm-pptp-service-9778 log[ctrlp_disp:pptp_ctrl.c:773]: Client connection established.
Jun 14 20:51:15 botev-ThinkPad-T440 pptp[9807]: nm-pptp-service-9778 log[ctrlp_rep:pptp_ctrl.c:251]: Sent control packet type is 7 'Outgoing-Call-Request'
Jun 14 20:51:15 botev-ThinkPad-T440 pptp[9807]: nm-pptp-service-9778 log[ctrlp_disp:pptp_ctrl.c:858]: Received Outgoing Call Reply.
Jun 14 20:51:15 botev-ThinkPad-T440 pptp[9807]: nm-pptp-service-9778 log[ctrlp_disp:pptp_ctrl.c:897]: Outgoing call established (call ID 0, peer's call ID 1661).
Jun 14 20:51:15 botev-ThinkPad-T440 pptp[9807]: nm-pptp-service-9778 log[ctrlp_disp:pptp_ctrl.c:950]: PPTP_SET_LINK_INFO received from peer_callid 56205
Jun 14 20:51:15 botev-ThinkPad-T440 pptp[9807]: nm-pptp-service-9778 log[ctrlp_disp:pptp_ctrl.c:953]: send_accm is 00000000, recv_accm is FFFFFFFF
Jun 14 20:51:15 botev-ThinkPad-T440 pptp[9807]: nm-pptp-service-9778 warn[ctrlp_disp:pptp_ctrl.c:956]: Non-zero Async Control Character Maps are not supported!
Jun 14 20:51:15 botev-ThinkPad-T440 pppd[9783]: CHAP authentication succeeded
Jun 14 20:51:15 botev-ThinkPad-T440 pppd[9783]: MPPE 128-bit stateless compression enabled
Jun 14 20:51:17 botev-ThinkPad-T440 pppd[9783]: local IP address 128.16.114.3
Jun 14 20:51:17 botev-ThinkPad-T440 pppd[9783]: remote IP address 128.16.114.1
Jun 14 20:51:17 botev-ThinkPad-T440 pppd[9783]: primary DNS address 128.16.6.8
Jun 14 20:51:17 botev-ThinkPad-T440 pppd[9783]: secondary DNS address 128.16.5.31
Jun 14 20:51:17 botev-ThinkPad-T440 NetworkManager[845]: <info> VPN connection 'UCL CS VPN' (IP4 Config Get) reply received from old-style plugin.
Jun 14 20:51:17 botev-ThinkPad-T440 NetworkManager[845]: <info> VPN Gateway: 128.16.11.245
Jun 14 20:51:17 botev-ThinkPad-T440 NetworkManager[845]: <info> Tunnel Device: ppp0
Jun 14 20:51:17 botev-ThinkPad-T440 NetworkManager[845]: <info> IPv4 configuration:
Jun 14 20:51:17 botev-ThinkPad-T440 NetworkManager[845]: <info> Internal Address: 128.16.114.3
Jun 14 20:51:17 botev-ThinkPad-T440 NetworkManager[845]: <info> Internal Prefix: 32
Jun 14 20:51:17 botev-ThinkPad-T440 NetworkManager[845]: <info> Internal Point-to-Point Address: 128.16.114.1
Jun 14 20:51:17 botev-ThinkPad-T440 NetworkManager[845]: <info> Maximum Segment Size (MSS): 0
Jun 14 20:51:17 botev-ThinkPad-T440 NetworkManager[845]: <info> Forbid Default Route: no
Jun 14 20:51:17 botev-ThinkPad-T440 NetworkManager[845]: <info> Internal DNS: 128.16.6.8
Jun 14 20:51:17 botev-ThinkPad-T440 NetworkManager[845]: <info> Internal DNS: 128.16.5.31
Jun 14 20:51:17 botev-ThinkPad-T440 NetworkManager[845]: <info> DNS Domain: '(none)'
Jun 14 20:51:17 botev-ThinkPad-T440 NetworkManager[845]: <info> No IPv6 configuration
Jun 14 20:51:18 botev-ThinkPad-T440 NetworkManager[845]: <info> VPN connection 'UCL CS VPN' (IP Config Get) complete.
Jun 14 20:51:18 botev-ThinkPad-T440 NetworkManager[845]: <info> Policy set 'UCL CS VPN' (ppp0) as default for IPv4 routing and DNS.
Jun 14 20:51:18 botev-ThinkPad-T440 NetworkManager[845]: <info> Writing DNS information to /sbin/resolvconf
Jun 14 20:51:18 botev-ThinkPad-T440 dnsmasq[3602]: setting upstream servers from DBus
Jun 14 20:51:18 botev-ThinkPad-T440 dnsmasq[3602]: using nameserver 128.16.5.31#53
Jun 14 20:51:18 botev-ThinkPad-T440 dnsmasq[3602]: using nameserver 128.16.6.8#53
Jun 14 20:51:18 botev-ThinkPad-T440 dbus[525]: [system] Activating service name='org.freedesktop.nm_dispatcher' (using servicehelper)
Jun 14 20:51:18 botev-ThinkPad-T440 NetworkManager[845]: <info> VPN plugin state changed: started (4)
Jun 14 20:51:18 botev-ThinkPad-T440 dbus[525]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Jun 14 20:51:20 botev-ThinkPad-T440 pptp[9787]: nm-pptp-service-9778 warn[decaps_gre:pptp_gre.c:331]: short read (-1): Message too long
Jun 14 20:51:20 botev-ThinkPad-T440 pptp[9807]: nm-pptp-service-9778 log[callmgr_main:pptp_callmgr.c:234]: Closing connection (unhandled)
Jun 14 20:51:20 botev-ThinkPad-T440 pptp[9807]: nm-pptp-service-9778 log[ctrlp_rep:pptp_ctrl.c:251]: Sent control packet type is 12 'Call-Clear-Request'
Jun 14 20:51:20 botev-ThinkPad-T440 pptp[9807]: nm-pptp-service-9778 log[call_callback:pptp_callmgr.c:79]: Closing connection (call state)
Jun 14 20:51:20 botev-ThinkPad-T440 pppd[9783]: Modem hangup
Jun 14 20:51:20 botev-ThinkPad-T440 pppd[9783]: Connect time 0.1 minutes.
Jun 14 20:51:20 botev-ThinkPad-T440 pppd[9783]: Sent 7680 bytes, received 13570 bytes.
Jun 14 20:51:20 botev-ThinkPad-T440 pppd[9783]: MPPE disabled
Jun 14 20:51:20 botev-ThinkPad-T440 pppd[9783]: Connection terminated.
Jun 14 20:51:20 botev-ThinkPad-T440 NetworkManager[845]: <info> VPN plugin state changed: stopping (5)
Jun 14 20:51:20 botev-ThinkPad-T440 NetworkManager[845]: <info> VPN plugin state changed: stopped (6)
Jun 14 20:51:20 botev-ThinkPad-T440 NetworkManager[845]: <info> VPN plugin state change reason: 0
Jun 14 20:51:20 botev-ThinkPad-T440 avahi-daemon[581]: Withdrawing workstation service for ppp0.
Jun 14 20:51:20 botev-ThinkPad-T440 avahi-daemon[581]: Withdrawing address record for 172.17.31.180 on wlan0.
Jun 14 20:51:20 botev-ThinkPad-T440 avahi-daemon[581]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 172.17.31.180.
Jun 14 20:51:20 botev-ThinkPad-T440 avahi-daemon[581]: Interface wlan0.IPv4 no longer relevant for mDNS.
Jun 14 20:51:20 botev-ThinkPad-T440 avahi-daemon[581]: Joining mDNS multicast group on interface wlan0.IPv4 with address 172.17.31.180.
Jun 14 20:51:20 botev-ThinkPad-T440 avahi-daemon[581]: New relevant interface wlan0.IPv4 for mDNS.
Jun 14 20:51:20 botev-ThinkPad-T440 avahi-daemon[581]: Registering new address record for 172.17.31.180 on wlan0.IPv4.
Jun 14 20:51:19 botev-ThinkPad-T440 whoopsie[1103]: message repeated 6 times: [ online]
Jun 14 20:51:20 botev-ThinkPad-T440 whoopsie[1103]: offline
Jun 14 20:51:21 botev-ThinkPad-T440 pppd[9783]: Exit.
Jun 14 20:51:21 botev-ThinkPad-T440 NetworkManager[845]: <info> Policy set 'Hotel Broadband' (wlan0) as default for IPv4 routing and DNS.
Jun 14 20:51:21 botev-ThinkPad-T440 NetworkManager[845]: <info> Writing DNS information to /sbin/resolvconf
Jun 14 20:51:21 botev-ThinkPad-T440 dnsmasq[3602]: setting upstream servers from DBus
Jun 14 20:51:21 botev-ThinkPad-T440 dnsmasq[3602]: using nameserver 172.17.31.1#53
Jun 14 20:51:21 botev-ThinkPad-T440 NetworkManager[845]: <warn> error disconnecting VPN: Could not process the request because no VPN connection was active.
Jun 14 20:51:21 botev-ThinkPad-T440 NetworkManager[845]: <warn> (14) failed to find interface name for index
Jun 14 20:51:21 botev-ThinkPad-T440 NetworkManager[845]: nm_system_iface_flush_routes: assertion 'iface != NULL' failed
Jun 14 20:51:21 botev-ThinkPad-T440 NetworkManager[845]: <warn> (14) failed to find interface name for index
Jun 14 20:51:21 botev-ThinkPad-T440 NetworkManager[845]: SCPlugin-Ifupdown: devices removed (path: /sys/devices/virtual/net/ppp0, iface: ppp0)
Jun 14 20:51:20 botev-ThinkPad-T440 whoopsie[1103]: offline
Jun 14 20:51:22 botev-ThinkPad-T440 whoopsie[1103]: online
Jun 14 20:51:24 botev-ThinkPad-T440 ntpdate[9867]: adjust time server 91.189.89.199 offset -0.003853 sec
Jun 14 20:51:27 botev-ThinkPad-T440 NetworkManager[845]: <info> VPN service 'pptp' disappeared
Now following very similar problem here and here I've tried to change the MTU for my wlan0 and ppp0 as well. For some reason the wlan0 was capped at 2304, if I try sudo ifconfig wlan0 mtu X for anything higher I get the error message SIOCSIFMTU: Invalid argument. For the ppp0, however I managed to set almost anything (tried with 30000 and works). Nevertheless, this did not help resolve the issue. So here I am wondering if there is any change for me?
I'm using Ubuntu 14.04 with kernel 3.17.
Solution 1:
Okay so after some more digging and lot's of experimentation it turns out I have to in fact lower the MTU of wlan0, rather than increase it. The reason, as far as I understood and please correct if I'm wrong, is that probably one of routers or a switch on the way is having a lower MTU as well, thus although it sends the packets correctly, my guess is that the VPN server sees only the MTU from the VPN packets, and replies with that MTU. When they hit this router it just gives up, because the incoming packet is too big. Again that is my hypothesis on the issue. How much to lower it, I can not say exactly. I did first 1412, than 1400 and 1200 in the end it was most stable at 1000 so I stick with that. If it happens to you just experiment a bit with it.
Solution 2:
I had this issue few minutes ago and that`s how I have solved it:
sudo ifconfig ppp0 mtu 1300
This command has changed MTU size for ppp0 connection at this session only.
If you want to use permanently this settings for your connection, create a new file in /etc/network/if-up.d/ directory Example:
sudo vi /etc/network/if-up.d/ppp0-mtu
with the content:
#!/bin/sh
if [ "$IFACE" = "ppp0" ]; then
sudo ifconfig ppp0 mtu 1300
fi
make this file executable and check your VPN connection now
sudo chmod a+x /etc/network/if-up.d/ppp0-mtu