IPsec phase 1 and 2 negotiation in an infinite loop.

Tue Sep 6 00:19:05 UTC 2011

Hi,

Can anyone please comment/shed some light/give hints on the following?:

I've got a VPN cranking between 8.2-RELEASE-p2 (my end) and an unknown
appliance (the other party doesn't want to disclose specs). Everything
works just fine and I had a stable and fully established connection for 4
months without a problem. However, today the tunnel went down.

I'm using FreeBSD's IPsec and ipsec-tools-0.8.0_2 (racoon). Everything's
up to date. The thing is, according to tcpdump, it seems that both
machines are trying to get beyond phases 1 and 2 in an infinite loop:

00:00:04.024146 00:11:22:33:44:55 > 55:44:33:22:11:00, ethertype IPv4
(0x0800), length 378: 1.2.3.4.5.500 > 5.4.3.2.1.500: isakmp: phase 1
I ident
00:00:01.800582 55:44:33:22:11:00 > 00:11:22:33:44:55, ethertype IPv4
(0x0800), length 126: 5.4.3.2.1.500 > 1.2.3.4.5.500: isakmp: phase 1
R ident
00:00:02.220315 00:11:22:33:44:55 > 55:44:33:22:11:00, ethertype IPv4
(0x0800), length 378: 1.2.3.4.5.500 > 5.4.3.2.1.500: isakmp: phase 1
I ident
00:00:04.067302 00:11:22:33:44:55 > 55:44:33:22:11:00, ethertype IPv4
(0x0800), length 662: 1.2.3.4.5.500 > 5.4.3.2.1.500: isakmp: phase
2/others ? oakley-quick[E]
00:00:00.000069 55:44:33:22:11:00 > 00:11:22:33:44:55, ethertype IPv4
(0x0800), length 82: 5.4.3.2.1.500 > 1.2.3.4.5.500: isakmp: phase
2/others ? inf
00:00:02.393116 00:11:22:33:44:55 > 55:44:33:22:11:00, ethertype IPv4
(0x0800), length 662: 1.2.3.4.5.500 > 5.4.3.2.1.500: isakmp: phase
2/others ? oakley-quick[E]
00:00:00.000092 55:44:33:22:11:00 > 00:11:22:33:44:55, ethertype IPv4
(0x0800), length 82: 5.4.3.2.1.500 > 1.2.3.4.5.500: isakmp: phase
2/others ? inf
00:00:01.320660 55:44:33:22:11:00 > 00:11:22:33:44:55, ethertype IPv4
(0x0800), length 126: 5.4.3.2.1.500 > 1.2.3.4.5.500: isakmp: phase 1
R ident
00:00:00.689822 00:11:22:33:44:55 > 55:44:33:22:11:00, ethertype IPv4
(0x0800), length 662: 1.2.3.4.5.500 > 5.4.3.2.1.500: isakmp: phase
2/others ? oakley-quick[E]
00:00:00.000093 55:44:33:22:11:00 > 00:11:22:33:44:55, ethertype IPv4
(0x0800), length 82: 5.4.3.2.1.500 > 1.2.3.4.5.500: isakmp: phase
2/others ? inf
00:00:02.009365 00:11:22:33:44:55 > 55:44:33:22:11:00, ethertype IPv4
(0x0800), length 662: 1.2.3.4.5.500 > 5.4.3.2.1.500: isakmp: phase
2/others ? oakley-quick[E]
00:00:00.000099 55:44:33:22:11:00 > 00:11:22:33:44:55, ethertype IPv4
(0x0800), length 82: 5.4.3.2.1.500 > 1.2.3.4.5.500: isakmp: phase
2/others ? inf
00:00:02.010914 00:11:22:33:44:55 > 55:44:33:22:11:00, ethertype IPv4
(0x0800), length 662: 1.2.3.4.5.500 > 5.4.3.2.1.500: isakmp: phase
2/others ? oakley-quick[E]
00:00:00.000106 55:44:33:22:11:00 > 00:11:22:33:44:55, ethertype IPv4
(0x0800), length 82: 5.4.3.2.1.500 > 1.2.3.4.5.500: isakmp: phase
2/others ? inf
00:00:02.008823 00:11:22:33:44:55 > 55:44:33:22:11:00, ethertype IPv4
(0x0800), length 662: 1.2.3.4.5.500 > 5.4.3.2.1.500: isakmp: phase
2/others ? oakley-quick[E]
00:00:00.000062 55:44:33:22:11:00 > 00:11:22:33:44:55, ethertype IPv4
(0x0800), length 82: 5.4.3.2.1.500 > 1.2.3.4.5.500: isakmp: phase
2/others ? inf
00:00:02.015381 00:11:22:33:44:55 > 55:44:33:22:11:00, ethertype IPv4
(0x0800), length 662: 1.2.3.4.5.500 > 5.4.3.2.1.500: isakmp: phase
2/others ? oakley-quick[E]
00:00:00.000089 55:44:33:22:11:00 > 00:11:22:33:44:55, ethertype IPv4
(0x0800), length 82: 5.4.3.2.1.500 > 1.2.3.4.5.500: isakmp: phase
2/others ? inf
00:00:04.005956 00:11:22:33:44:55 > 55:44:33:22:11:00, ethertype IPv4
(0x0800), length 662: 1.2.3.4.5.500 > 5.4.3.2.1.500: isakmp: phase
2/others ? oakley-quick[E]
00:00:00.000109 55:44:33:22:11:00 > 00:11:22:33:44:55, ethertype IPv4
(0x0800), length 82: 5.4.3.2.1.500 > 1.2.3.4.5.500: isakmp: phase
2/others ? inf
00:00:04.030017 00:11:22:33:44:55 > 55:44:33:22:11:00, ethertype IPv4
(0x0800), length 662: 1.2.3.4.5.500 > 5.4.3.2.1.500: isakmp: phase
2/others ? oakley-quick[E]
00:00:00.000083 55:44:33:22:11:00 > 00:11:22:33:44:55, ethertype IPv4
(0x0800), length 82: 5.4.3.2.1.500 > 1.2.3.4.5.500: isakmp: phase
2/others ? inf
00:00:04.012759 00:11:22:33:44:55 > 55:44:33:22:11:00, ethertype IPv4
(0x0800), length 662: 1.2.3.4.5.500 > 5.4.3.2.1.500: isakmp: phase
2/others ? oakley-quick[E]
00:00:00.000100 55:44:33:22:11:00 > 00:11:22:33:44:55, ethertype IPv4
(0x0800), length 82: 5.4.3.2.1.500 > 1.2.3.4.5.500: isakmp: phase
2/others ? inf
00:00:04.007933 00:11:22:33:44:55 > 55:44:33:22:11:00, ethertype IPv4
(0x0800), length 662: 1.2.3.4.5.500 > 5.4.3.2.1.500: isakmp: phase
2/others ? oakley-quick[E]
00:00:00.000105 55:44:33:22:11:00 > 00:11:22:33:44:55, ethertype IPv4
(0x0800), length 82: 5.4.3.2.1.500 > 1.2.3.4.5.500: isakmp: phase
2/others ? inf
00:00:04.019993 00:11:22:33:44:55 > 55:44:33:22:11:00, ethertype IPv4
(0x0800), length 662: 1.2.3.4.5.500 > 5.4.3.2.1.500: isakmp: phase
2/others ? oakley-quick[E]
00:00:00.000097 55:44:33:22:11:00 > 00:11:22:33:44:55, ethertype IPv4
(0x0800), length 82: 5.4.3.2.1.500 > 1.2.3.4.5.500: isakmp: phase
2/others ? inf
00:00:04.047917 00:11:22:33:44:55 > 55:44:33:22:11:00, ethertype IPv4
(0x0800), length 378: 1.2.3.4.5.500 > 5.4.3.2.1.500: isakmp: phase 1
I ident
00:00:00.000108 55:44:33:22:11:00 > 00:11:22:33:44:55, ethertype IPv4
(0x0800), length 126: 5.4.3.2.1.500 > 1.2.3.4.5.500: isakmp: phase 1
R ident
00:00:02.022728 00:11:22:33:44:55 > 55:44:33:22:11:00, ethertype IPv4
(0x0800), length 378: 1.2.3.4.5.500 > 5.4.3.2.1.500: isakmp: phase 1
I ident

I've restarted both racoon and ipsec several times. Set racoon's log to
debug/debug2 but couldn't find any lines relevant to the problem in the
logs apart from:

[1.2.3.4] DEBUG: malformed cookie received. it has to be as the initiator.

Out of desperation and pressure in reestablishing the tunnel I restarted
the machine. That did the trick. She's up and running without a problem.

Now I'm trying to understand what went wrong and how to prevent this thing
from occurring in the future. After doing my homework I suspect that the
culprit might've been PF. I completely forgot about it when I was
restarting ipsec and racoon. Let me add that the machine was running for
months and no settings were changed at all. Could that be the MTU, packet
reassembly or anything related to PF? What are the thoughts of people
working with VPNs?

Configuration files and logs are available on request.

Cheers,
Mikhail.

-- 
Mikhail Goriachev
Webanoide

Mobile: +56 9 78772741
Web: www.webanoide.org