UDP source port changes, breaking VPN connections

[Jeff Mitchell]

I am having a problem very similar to the one described in #6667, except that it's on OSX using official packages version 4.3.26.

After discussion of a disconnect problem I was having with the OpenVPN developers, they believed the issue could lie with the VM NAT stack. They suggested capturing traffic on the OpenVPN server and indeed, when I did so I could see that in the middle of a connection (running rsync between two VMs via the server) the UDP source port for the VPN connection suddenly changed:

...
20:46:59.274161 IP 172.19.45.154.50349 > 172.27.102.152.443: UDP, length 1445
20:46:59.274547 IP 172.19.45.154.50349 > 172.27.102.152.443: UDP, length 1445
20:46:59.274555 IP 172.19.45.154.50349 > 172.27.102.152.443: UDP, length 1445
20:46:59.276917 IP 172.19.45.154.50349 > 172.27.102.152.443: UDP, length 1445
20:46:59.277719 IP 172.19.45.154.59878 > 172.27.102.152.443: UDP, length 1445
20:46:59.277993 IP 172.19.45.154.59878 > 172.27.102.152.443: UDP, length 1445
...

When this happens, of course, the VPN software thinks the old connection has died, and eventually times out and disconnects.

At this point I can trigger the problem extremely reliably by rsyncing files over the VPN connection -- it will happen within a minute. This suggests to me that what's triggering this problem is either the total data rate back and forth through the NAT stack or some total number of packets or bytes through the NAT stack. That, or for some reason at some point the NAT stack stops correctly tracking the connection, decides that it's a new connection, and gives it a new outbound port. Just my guesses.

[Jeff Mitchell]

(Deleted as the formatted log was moved to the issue description, thanks!)

[Jeff Mitchell]

Log file

[Jeff Mitchell]

I attached a log file. This is the log from startup until a few minutes after this UDP source port switch occurred -- note that there was *no* logging of anything at that time, so the end of the log is a minute or so before that happened.

The guest is running guest utilities from upstream Ubuntu repositories (I didn't find an updated version in your swupdate repositories): virtualbox-guest-dkms, virtualbox-guest-utils, virtualbox-guest-x11, all version 4.3.10-dfsg-1ubuntu3. If desired I can try installing updated definitions (I may try this anyways while waiting for a response).

[Jeff Mitchell]

I removed the old guest additions and installed the 4.3.26 additions the recommended way (via the ISO). It did not make a difference.

[Valery Ushakov]

I don't think guest additions has anything to do with this.

At this point I can trigger the problem extremely reliably by rsyncing files over the VPN connection -- it will happen within a minute.

Hmm, so, you have an active transfer and the source port changes suddenly in the middle of it? Interesting.

Can you provide a packet capture from the guest side, please? Just to make sure that the source port is not changed on the guest side.

[Jeff Mitchell]

I captured the entire VPN session on the client side during the rsync, using -i any (so you'll see the outbound IP/port on the VM instead of the VPN's internal IP/port).

Following is the head and tail of the file, you'll see that the port remains constant.

~  ᐅ head rsynccap.txt
15:58:05.740150 IP 10.0.2.15.36948 > 172.27.102.193.443: UDP, length 133
15:58:05.761457 IP 172.27.102.193.443 > 10.0.2.15.36948: UDP, length 109
15:58:05.889454 IP 172.27.102.193.443 > 10.0.2.15.36948: UDP, length 125
15:58:05.890649 IP 10.0.2.15.36948 > 172.27.102.193.443: UDP, length 125
15:58:05.896495 IP 10.0.2.15.36948 > 172.27.102.193.443: UDP, length 93
15:58:05.912088 IP 172.27.102.193.443 > 10.0.2.15.36948: UDP, length 93
15:58:05.912383 IP 10.0.2.15.36948 > 172.27.102.193.443: UDP, length 85
15:58:05.912625 IP 10.0.2.15.36948 > 172.27.102.193.443: UDP, length 85
15:58:05.912705 IP 10.0.2.15.36948 > 172.27.102.193.443: UDP, length 101
15:58:05.912978 IP 10.0.2.15.36948 > 172.27.102.193.443: UDP, length 101
~  ᐅ tail rsynccap.txt
15:58:50.865005 IP 10.0.2.15.36948 > 172.27.102.193.443: UDP, length 1445
15:58:51.749534 IP 10.0.2.15.36948 > 172.27.102.193.443: UDP, length 277
15:58:52.750228 IP 10.0.2.15.36948 > 172.27.102.193.443: UDP, length 277
15:58:53.751151 IP 10.0.2.15.36948 > 172.27.102.193.443: UDP, length 277
15:58:54.751855 IP 10.0.2.15.36948 > 172.27.102.193.443: UDP, length 237
15:58:58.304297 IP 10.0.2.15.36948 > 172.27.102.193.443: UDP, length 1445
15:59:00.740492 IP 10.0.2.15.36948 > 172.27.102.193.443: UDP, length 93
15:59:01.742825 IP 10.0.2.15.36948 > 172.27.102.193.443: UDP, length 93
15:59:03.744134 IP 10.0.2.15.36948 > 172.27.102.193.443: UDP, length 93
15:59:07.752130 IP 10.0.2.15.36948 > 172.27.102.193.443: UDP, length 93

At the end there the packets simply stop being sent mid-stream, presumably because it has not received a reply from the VPN server in whatever window or time limit it requires (due to the server trying to send to the original port).

[Valery Ushakov]

I think this is a duplicate of #13475 which I now managed to reproduce. It's probably killed by unreachable/fragmentation needed from some router upstream.