[Openswan Users] Missing incoming packets

Wed Nov 25 00:16:37 EST 2009

Hi,

I'm having an issue with Openswan not receiving "some" of the packets
a counterparty (Cisco concentrator) sends via an ipsec site-to-site
VPN tunnel (I'm using Vyatta which uses Openswan).
The tunnel itself comes up without problems:

Local           Peer            State     Encrypt   Hash     NAT-T A-Time L-Time
--------        -------         -----     -------   ----     -----
------ ------
local           remote          up        3des      sha1     No    2443   86400

Peer            Tunnel# Dir SPI      Encrypt    Hash       NAT-T A-Time L-Time
-------         ------- --- ---      -------    ----       ----- ------ ------
remote          1       in  a9923bfb 3des       sha1       No    31     120
remote          1       out 37b5f5cc 3des       sha1       No    31     120

Everything works fine initially but I start losing packets from the
counterparty whenever they send a batch of messages. Here's some of my
tcpdump output:

22:27:19.736658 IP local.500 > remote.500: isakmp: phase 2/others ? inf[E]
22:27:20.579032 IP local > remote: ESP(spi=0xf94d7e2e,seq=0x4), length 84
22:27:20.584966 IP remote > local: ESP(spi=0x94309eaf,seq=0x4), length 84
22:27:20.585359 IP local > remote: ESP(spi=0xf94d7e2e,seq=0x5), length 76
22:27:20.585717 IP local > remote: ESP(spi=0xf94d7e2e,seq=0x6), length 164
22:27:20.590835 IP remote > local: ESP(spi=0x94309eaf,seq=0x5), length 76
22:27:23.147735 IP remote > local: ESP(spi=0x94309eaf,seq=0x6), length 164
22:27:23.148919 IP local > remote: ESP(spi=0xf94d7e2e,seq=0x7), length 164
22:27:23.153882 IP remote > local: ESP(spi=0x94309eaf,seq=0x7), length 76
22:27:23.734375 IP remote > local: ESP(spi=0x94309eaf,seq=0x8), length 404
22:27:23.734437 IP remote > local: ESP(spi=0x94309eaf,seq=0x9), length 404
22:27:23.734840 IP local > remote: ESP(spi=0xf94d7e2e,seq=0x8), length 76

// At this point I should see a ton of packets coming in which the
counterparty is sending out but they're simply not showing up

22:27:39.368559 IP remote.500 > local.500: isakmp: phase 2/others ? inf[E]
22:27:39.368747 IP local.500 > remote.500: isakmp: phase 2/others ? inf[E]
22:27:43.149498 IP local > remote: ESP(spi=0xf94d7e2e,seq=0x9), length 156
22:27:43.154401 IP remote > local: ESP(spi=0x94309eaf,seq=0xa), length 76
22:27:47.377153 IP local.500 > remote.500: isakmp: phase 2/others ?
oakley-quick[E]
22:27:47.386487 IP remote.500 > local.500: isakmp: phase 2/others ?
oakley-quick[E]
22:27:47.386760 IP local.500 > remote.500: isakmp: phase 2/others ?
oakley-quick[E]
22:27:47.736956 IP local > remote: ESP(spi=0x4a5775d4,seq=0x1), length 172
22:27:47.741843 IP remote > local: ESP(spi=0xfc91db00,seq=0x1), length 76
22:27:58.636868 IP remote.500 > local.500: isakmp: phase 2/others ? inf[E]
22:27:58.637031 IP local.500 > remote.500: isakmp: phase 2/others ? inf[E]
22:28:07.738019 IP local > remote: ESP(spi=0x4a5775d4,seq=0x2), length 156
22:28:07.743079 IP remote > local: ESP(spi=0xfc91db00,seq=0x2), length 76
22:28:08.647424 IP local.500 > remote.500: isakmp: phase 2/others ?
oakley-quick[E]
22:28:08.656723 IP remote.500 > local.500: isakmp: phase 2/others ?
oakley-quick[E]
22:28:08.656987 IP local.500 > remote.500: isakmp: phase 2/others ?
oakley-quick[E]
22:28:11.738723 IP local > remote: ESP(spi=0x6fac9798,seq=0x1), length 76
22:28:11.744558 IP remote > local: ESP(spi=0x0734a937,seq=0x1), length 76
22:28:11.744946 IP local > remote: ESP(spi=0x6fac9798,seq=0x2), length 76
22:28:11.750005 IP remote > local: ESP(spi=0x0734a937,seq=0x2), length 76
22:28:17.389258 IP remote.500 > local.500: isakmp: phase 2/others ? inf[E]
22:28:17.389452 IP local.500 > remote.500: isakmp: phase 2/others ? inf[E]
22:28:26.752039 IP local > remote: ESP(spi=0x6fac9798,seq=0x3), length 84

Here a more verbose version:

 tcpdump -i eth0 -v -n -p ip host remote and not port 22
tcpdump: listening on eth0, link-type EN10MB (Ethernet), capture size 96 bytes
22:33:59.170641 IP (tos 0x0, ttl 242, id 10656, offset 0, flags
[none], proto UDP (17), length 120) remote.500 > local.500: isakmp 1.0
msgid : phase 2/others ? inf[E]: [encrypted hash]
22:33:59.170781 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto
UDP (17), length 112) local.500 > remote.500: isakmp 1.0 msgid : phase
2/others ? inf[E]: [encrypted hash]
22:34:02.382568 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto
ESP (50), length 104) local > remote: ESP(spi=0xe3ce1654,seq=0x4),
length 84
22:34:02.393746 IP (tos 0x0, ttl 241, id 11040, offset 0, flags [DF],
proto ESP (50), length 104) remote > local:
ESP(spi=0xccfbe698,seq=0x4), length 84
22:34:02.394146 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto
ESP (50), length 96) local > remote: ESP(spi=0xe3ce1654,seq=0x5),
length 76
22:34:02.394628 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto
ESP (50), length 184) local > remote: ESP(spi=0xe3ce1654,seq=0x6),
length 164
22:34:02.399133 IP (tos 0x0, ttl 241, id 11041, offset 0, flags [DF],
proto ESP (50), length 96) remote > local:
ESP(spi=0xccfbe698,seq=0x5), length 76
22:34:04.771729 IP (tos 0x0, ttl 241, id 11308, offset 0, flags [DF],
proto ESP (50), length 184) remote > local:
ESP(spi=0xccfbe698,seq=0x6), length 164
22:34:04.772851 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto
ESP (50), length 184) local > remote: ESP(spi=0xe3ce1654,seq=0x7),
length 164
22:34:04.777713 IP (tos 0x0, ttl 241, id 11309, offset 0, flags [DF],
proto ESP (50), length 96) remote > local:
ESP(spi=0xccfbe698,seq=0x7), length 76
22:34:05.402074 IP (tos 0x0, ttl 241, id 11409, offset 0, flags [DF],
proto ESP (50), length 424) remote > local:
ESP(spi=0xccfbe698,seq=0x8), length 404
22:34:05.402128 IP (tos 0x0, ttl 241, id 11410, offset 0, flags [DF],
proto ESP (50), length 424) remote > local:
ESP(spi=0xccfbe698,seq=0x9), length 404

// A lot more data should be coming in at this point...

22:34:05.402524 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto
ESP (50), length 96) local > remote: ESP(spi=0xe3ce1654,seq=0x8),
length 76
22:34:10.550726 IP (tos 0x0, ttl 242, id 11952, offset 0, flags
[none], proto UDP (17), length 104) remote.500 > local.500: isakmp 1.0
msgid : phase 2/others ? inf[E]: [encrypted hash]
22:34:10.550896 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto
UDP (17), length 96) local.500 > remote.500: isakmp 1.0 msgid : phase
2/others ? inf[E]: [encrypted hash]
^C
28 packets captured
28 packets received by filter
0 packets dropped by kernel

After reading some more on the Openswan site, I realized this might be
an MTU problem but I'm honestly not quite sure how I can make sure of
that or what I could do about it.
When I ping the counterparty I get the following results:

Pinging remote with 32 bytes of data:
Reply from remote: bytes=32 time=7ms TTL=247
Reply from remote: bytes=32 time=4ms TTL=247
Reply from remote: bytes=32 time=4ms TTL=247
Reply from remote: bytes=32 time=4ms TTL=247

C:\Users\Administrator>ping -l 2000 remote

Pinging remote with 2000 bytes of data:
Reply from remote: bytes=1472 (sent 2000) time=6ms TTL=246
Reply from remote: bytes=1472 (sent 2000) time=8ms TTL=246
Reply from remote: bytes=1472 (sent 2000) time=22ms TTL=246
Reply from remote: bytes=1472 (sent 2000) time=14ms TTL=246

C:\Users\Administrator>ping -l 1415 -f remote (when I set -l > 1415
and < 1420, pings will time out)

Pinging remote with 1415 bytes of data:
Reply from remote: bytes=1415 time=6ms TTL=247
Reply from remote: bytes=1415 time=10ms TTL=247
Reply from remote: bytes=1415 time=6ms TTL=247
Reply from remote: bytes=1415 time=20ms TTL=247

At this point I don't really know what to do to fix this issue, so any
help is greatly appreciated!

Thanks

Tom