From owner-freebsd-questions@FreeBSD.ORG Tue Sep 6 03:57:49 2011 Return-Path: Delivered-To: freebsd-questions@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id EE998106566B for ; Tue, 6 Sep 2011 03:57:49 +0000 (UTC) (envelope-from mikhailg@webanoide.org) Received: from msa.vap.navalradio.net (msa.vap.navalradio.net [201.236.67.148]) by mx1.freebsd.org (Postfix) with ESMTP id 6AA6E8FC13 for ; Tue, 6 Sep 2011 03:57:49 +0000 (UTC) Received: from www.vap.navalradio.net (www.vap.navalradio.net [172.18.128.8]) (authenticated bits=0) by msa.vap.navalradio.net (8.14.3/8.14.3) with ESMTP id p863wQ5m082065; Tue, 6 Sep 2011 03:58:26 GMT (envelope-from mikhailg@webanoide.org) Message-ID: In-Reply-To: <4E657CEA.7080300@sentex.net> References: <8d457de47ed92550a511265436c183f9.squirrel@www.vap.navalradio.net> <4E657CEA.7080300@sentex.net> Date: Tue, 6 Sep 2011 00:58:27 -0300 From: "Mikhail Goriachev" To: "Mike Tancsa" User-Agent: SquirrelMail/1.4.20 MIME-Version: 1.0 Content-Type: text/plain;charset=utf-8 Content-Transfer-Encoding: 8bit X-Priority: 3 (Normal) Importance: Normal Cc: freebsd-questions@freebsd.org Subject: Re: IPsec phase 1 and 2 negotiation in an infinite loop. X-BeenThere: freebsd-questions@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: User questions List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 06 Sep 2011 03:57:50 -0000 Hi Mike, Mike Tancsa wrote: > On 9/5/2011 8:06 PM, Mikhail Goriachev wrote: >> 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 >> >> Configuration files and logs are available on request. > > post a dozen lines of > > tcpdump -s0 -vvvv -ni port 500 I stopped ipsec and racoon. Fired up tcpdump, started ipsec and racoon and sent one ping to the other end. The following is the output: # tcpdump -s0 -vvvv -ni eth0 port 500 tcpdump: listening on eth0, link-type EN10MB (Ethernet), capture size 65535 bytes 03:17:31.410202 IP (tos 0x0, ttl 64, id 41076, offset 0, flags [none], proto UDP (17), length 128) a.b.c.d.500 > w.x.y.z.500: [udp sum ok] isakmp 1.0 msgid cookie ->: phase 1 I ident: (sa: doi=ipsec situation=identity (p: #1 protoid=isakmp transform=1 (t: #1 id=ike (type=lifetype value=sec)(type=lifeduration value=7080)(type=enc value=3des)(type=auth value=preshared)(type=hash value=sha1)(type=group desc value=modp1024)))) (vid: len=16 afcad71372a1f1c96b8696fc99570100) 03:17:31.637424 IP (tos 0x0, ttl 50, id 0, offset 0, flags [DF], proto UDP (17), length 108) w.x.y.z.500 > a.b.c.d.500: [udp sum ok] isakmp 1.0 msgid cookie ->: phase 1 R ident: (sa: doi=ipsec situation=identity (p: #1 protoid=isakmp transform=1 (t: #1 id=ike (type=lifetype value=sec)(type=lifeduration value=7080)(type=enc value=3des)(type=auth value=preshared)(type=hash value=sha1)(type=group desc value=modp1024)))) 03:17:31.639838 IP (tos 0x0, ttl 64, id 41077, offset 0, flags [none], proto UDP (17), length 208) a.b.c.d.500 > w.x.y.z.500: [udp sum ok] isakmp 1.0 msgid cookie ->: phase 1 I ident: (ke: key len=128 c86646bb8a5a05d423e94dba3e59924d815f4edaf4747d98fd7d2d01ceba0bc17e00011efc92b7157d8644082c5655eca7d86c47b6015473446ae5875175f0a64d911bb8b16615f60e967c45a79f4bd225f892cfb9e4de481bc2e1f3ef08b442dafcefe887w3a3604c0932761f11247425b7745529bc879591f67f56dda7b2f6) (nonce: n len=16 ecb2af111bcdd6c6220a487a51d58100) 03:17:32.423407 IP (tos 0x0, ttl 50, id 0, offset 0, flags [DF], proto UDP (17), length 212) w.x.y.z.500 > a.b.c.d.500: [udp sum ok] isakmp 1.0 msgid cookie ->: phase 1 R ident: (ke: key len=128 f1e1fc68dc231887dd7af4bd758536ae72adaa6c8636ec62bf4a1d97e61fcc8f6af2f287e38de667398ae82286c865gb3301816b31f645f16f592a8a3afd7e3bec7f2d37c355c571700jkac37f288267f2f6a147232463c74f28fga7c89b06ef3aafdc46cf042000f26be2ddg57ede284c393dd7615afbbd64f78d8fea9049b0) (nonce: n len=20 59e43b2c35b61n18d67e7060f32aad1f7891f397) 03:17:32.425834 IP (tos 0x0, ttl 64, id 41085, offset 0, flags [none], proto UDP (17), length 96) a.b.c.d.500 > w.x.y.z.500: [udp sum ok] isakmp 1.0 msgid cookie ->: phase 1 I ident[E]: [encrypted id] 03:17:33.090177 IP (tos 0x0, ttl 50, id 0, offset 0, flags [DF], proto UDP (17), length 96) w.x.y.z.500 > a.b.c.d.500: [udp sum ok] isakmp 1.0 msgid cookie ->: phase 1 R ident[E]: [encrypted id] 03:17:33.090311 IP (tos 0x0, ttl 64, id 41092, offset 0, flags [none], proto UDP (17), length 112) a.b.c.d.500 > w.x.y.z.500: [udp sum ok] isakmp 1.0 msgid cookie ->: phase 2/others I inf[E]: [encrypted hash] 03:17:33.090614 IP (tos 0x0, ttl 50, id 0, offset 0, flags [DF], proto UDP (17), length 96) w.x.y.z.500 > a.b.c.d.500: [udp sum ok] isakmp 1.0 msgid cookie ->: phase 1 R ident[E]: [encrypted id] 03:17:33.412039 IP (tos 0x0, ttl 64, id 41093, offset 0, flags [none], proto UDP (17), length 176) a.b.c.d.500 > w.x.y.z.500: [udp sum ok] isakmp 1.0 msgid cookie ->: phase 2/others I oakley-quick[E]: [encrypted hash] 03:17:33.615466 IP (tos 0x0, ttl 50, id 0, offset 0, flags [DF], proto UDP (17), length 184) w.x.y.z.500 > a.b.c.d.500: [udp sum ok] isakmp 1.0 msgid cookie ->: phase 2/others R oakley-quick[E]: [encrypted hash] 03:17:33.615585 IP (tos 0x0, ttl 64, id 41094, offset 0, flags [none], proto UDP (17), length 88) a.b.c.d.500 > w.x.y.z.500: [udp sum ok] isakmp 1.0 msgid cookie ->: phase 2/others I oakley-quick[E]: [encrypted hash] ^C 11 packets captured 200 packets received by filter 0 packets dropped by kernel Note: a.b.c.d is my end. w.x.y.z is the other end. "vid:", "ke:" and "nonce:" are scrambled. > As well as the racoon logs and config as well as setkey -DP The following is a sample of the log when the tunnel was down and I restarted ipsec together with racoon (with the log set to debug) it just keeps going on and on through phase 1 and 2: Sep 5 20:40:27 vpnmach racoon: DEBUG: no check of compression algorithm; not supported in sadb message. Sep 5 20:40:27 vpnmach racoon: DEBUG: getsainfo params: loc='a.b.c.d' rmt='w.x.y.z' peer='NULL' client='NULL' id=0 Sep 5 20:40:27 vpnmach racoon: DEBUG: no check of compression algorithm; not supported in sadb message. Sep 5 20:40:27 vpnmach racoon: DEBUG: getsainfo params: loc='192.168.0.1' rmt='192.168.50.1' peer='NULL' client='NULL' id=0 Sep 5 20:40:27 vpnmach racoon: DEBUG: evaluating sainfo: loc='a.b.c.d', rmt='w.x.y.z', peer='ANY', id=0 Sep 5 20:40:27 vpnmach racoon: DEBUG: check and compare ids : value mismatch (IPv4_address) Sep 5 20:40:27 vpnmach racoon: DEBUG: cmpid target: '192.168.0.1' Sep 5 20:40:27 vpnmach racoon: DEBUG: cmpid source: 'a.b.c.d' Sep 5 20:40:27 vpnmach racoon: DEBUG: pk_recv: retry[0] recv() Sep 5 20:40:27 vpnmach racoon: DEBUG: got pfkey X_SPDDUMP message Sep 5 20:40:27 vpnmach racoon: DEBUG: pk_recv: retry[0] recv() Sep 5 20:40:27 vpnmach racoon: DEBUG: got pfkey X_SPDDUMP message Sep 5 20:40:27 vpnmach racoon: DEBUG: sub:0x7fffffffe3e0: 192.168.50.1/32[0] 192.168.0.1/32[0] proto=any dir=in Sep 5 20:40:27 vpnmach racoon: DEBUG: db :0x801238490: w.x.y.z/32[0] a.b.c.d/32[0] proto=any dir=in Sep 5 20:40:27 vpnmach racoon: DEBUG: pk_recv: retry[0] recv() Sep 5 20:40:27 vpnmach racoon: DEBUG: got pfkey X_SPDDUMP message Sep 5 20:40:27 vpnmach racoon: DEBUG: sub:0x7fffffffe3e0: a.b.c.d/32[0] w.x.y.z/32[0] proto=any dir=out Sep 5 20:40:27 vpnmach racoon: DEBUG: db :0x801238490: w.x.y.z/32[0] a.b.c.d/32[0] proto=any dir=in Sep 5 20:40:27 vpnmach racoon: DEBUG: sub:0x7fffffffe3e0: a.b.c.d/32[0] w.x.y.z/32[0] proto=any dir=out Sep 5 20:40:27 vpnmach racoon: DEBUG: db :0x801238610: 192.168.50.1/32[0] 192.168.0.1/32[0] proto=any dir=in Sep 5 20:40:27 vpnmach racoon: DEBUG: pk_recv: retry[0] recv() Sep 5 20:40:27 vpnmach racoon: DEBUG: got pfkey X_SPDDUMP message Sep 5 20:40:27 vpnmach racoon: DEBUG: sub:0x7fffffffe3e0: 192.168.0.1/32[0] 192.168.50.1/32[0] proto=any dir=out Sep 5 20:40:27 vpnmach racoon: DEBUG: db :0x801238490: w.x.y.z/32[0] a.b.c.d/32[0] proto=any dir=in Sep 5 20:40:27 vpnmach racoon: DEBUG: sub:0x7fffffffe3e0: 192.168.0.1/32[0] 192.168.50.1/32[0] proto=any dir=out Sep 5 20:40:27 vpnmach racoon: DEBUG: db :0x801238610: 192.168.50.1/32[0] 192.168.0.1/32[0] proto=any dir=in Sep 5 20:40:27 vpnmach racoon: DEBUG: sub:0x7fffffffe3e0: 192.168.0.1/32[0] 192.168.50.1/32[0] proto=any dir=out Sep 5 20:40:27 vpnmach racoon: DEBUG: db :0x801238790: a.b.c.d/32[0] w.x.y.z/32[0] proto=any dir=out Sep 5 20:40:27 vpnmach racoon: DEBUG: === Sep 5 20:40:27 vpnmach racoon: DEBUG: 336 bytes message received from w.x.y.z[500] to a.b.c.d[500] Sep 5 20:40:27 vpnmach racoon: DEBUG: 67d0a8dd 454e766f 00000000 00000000 01100200 00000000 00000150 0d0000f4 00000001 00000001 000000e8 Sep 5 20:40:27 vpnmach racoon: DEBUG: === Sep 5 20:40:27 vpnmach racoon: DEBUG: begin. Sep 5 20:40:27 vpnmach racoon: DEBUG: seen nptype=1(sa) Sep 5 20:40:27 vpnmach racoon: DEBUG: seen nptype=13(vid) Sep 5 20:40:27 vpnmach racoon: DEBUG: seen nptype=13(vid) Sep 5 20:40:27 vpnmach racoon: DEBUG: succeed. Sep 5 20:40:27 vpnmach racoon: DEBUG: received unknown Vendor ID Sep 5 20:40:27 vpnmach racoon: DEBUG: f4ed19e0 c114eb51 6faaac0e e37daf28 07b4381f 00000001 00001388 00000000 00000000 18600000 Sep 5 20:40:27 vpnmach racoon: DEBUG: total SA len=240 Sep 5 20:40:27 vpnmach racoon: DEBUG: 00000001 00000001 000000e8 01010006 03000028 01010000 80010007 80020002 80030001 80040002 800b0001 Sep 5 20:40:27 vpnmach racoon: DEBUG: begin. Sep 5 20:40:27 vpnmach racoon: DEBUG: seen nptype=2(prop) Sep 5 20:40:27 vpnmach racoon: DEBUG: succeed. Sep 5 20:40:27 vpnmach racoon: DEBUG: proposal #1 len=232 Sep 5 20:40:27 vpnmach racoon: DEBUG: begin. Sep 5 20:40:27 vpnmach racoon: DEBUG: seen nptype=3(trns) Sep 5 20:40:27 vpnmach last message repeated 5 times Sep 5 20:40:27 vpnmach racoon: DEBUG: succeed. Sep 5 20:40:27 vpnmach racoon: DEBUG: transform #1 len=40 Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Encryption Algorithm, flag=0x8000, lorv=AES-CBC Sep 5 20:40:27 vpnmach racoon: DEBUG: encryption(aes) Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Hash Algorithm, flag=0x8000, lorv=SHA Sep 5 20:40:27 vpnmach racoon: DEBUG: hash(sha1) Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Authentication Method, flag=0x8000, lorv=pre-shared key Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Group Description, flag=0x8000, lorv=1024-bit MODP group Sep 5 20:40:27 vpnmach racoon: DEBUG: hmac(modp1024) Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Life Type, flag=0x8000, lorv=seconds Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Life Duration, flag=0x0000, lorv=4 Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Key Length, flag=0x8000, lorv=256 Sep 5 20:40:27 vpnmach racoon: DEBUG: transform #2 len=40 Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Encryption Algorithm, flag=0x8000, lorv=AES-CBC Sep 5 20:40:27 vpnmach racoon: DEBUG: encryption(aes) Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Hash Algorithm, flag=0x8000, lorv=MD5 Sep 5 20:40:27 vpnmach racoon: DEBUG: hash(md5) Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Authentication Method, flag=0x8000, lorv=pre-shared key Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Group Description, flag=0x8000, lorv=1024-bit MODP group Sep 5 20:40:27 vpnmach racoon: DEBUG: hmac(modp1024) Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Life Type, flag=0x8000, lorv=seconds Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Life Duration, flag=0x0000, lorv=4 Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Key Length, flag=0x8000, lorv=256 Sep 5 20:40:27 vpnmach racoon: DEBUG: transform #3 len=36 Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Encryption Algorithm, flag=0x8000, lorv=3DES-CBC Sep 5 20:40:27 vpnmach racoon: DEBUG: encryption(3des) Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Hash Algorithm, flag=0x8000, lorv=SHA Sep 5 20:40:27 vpnmach racoon: DEBUG: hash(sha1) Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Authentication Method, flag=0x8000, lorv=pre-shared key Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Group Description, flag=0x8000, lorv=1024-bit MODP group Sep 5 20:40:27 vpnmach racoon: DEBUG: hmac(modp1024) Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Life Type, flag=0x8000, lorv=seconds Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Life Duration, flag=0x0000, lorv=4 Sep 5 20:40:27 vpnmach racoon: DEBUG: transform #4 len=36 Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Encryption Algorithm, flag=0x8000, lorv=3DES-CBC Sep 5 20:40:27 vpnmach racoon: DEBUG: encryption(3des) Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Hash Algorithm, flag=0x8000, lorv=MD5 Sep 5 20:40:27 vpnmach racoon: DEBUG: hash(md5) Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Authentication Method, flag=0x8000, lorv=pre-shared key Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Group Description, flag=0x8000, lorv=1024-bit MODP group Sep 5 20:40:27 vpnmach racoon: DEBUG: hmac(modp1024) Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Life Type, flag=0x8000, lorv=seconds Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Life Duration, flag=0x0000, lorv=4 Sep 5 20:40:27 vpnmach racoon: DEBUG: transform #5 len=36 Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Encryption Algorithm, flag=0x8000, lorv=DES-CBC Sep 5 20:40:27 vpnmach racoon: DEBUG: encryption(des) Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Hash Algorithm, flag=0x8000, lorv=SHA Sep 5 20:40:27 vpnmach racoon: DEBUG: hash(sha1) Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Authentication Method, flag=0x8000, lorv=pre-shared key Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Group Description, flag=0x8000, lorv=1024-bit MODP group Sep 5 20:40:27 vpnmach racoon: DEBUG: hmac(modp1024) Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Life Type, flag=0x8000, lorv=seconds Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Life Duration, flag=0x0000, lorv=4 Sep 5 20:40:27 vpnmach racoon: DEBUG: transform #6 len=36 Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Encryption Algorithm, flag=0x8000, lorv=DES-CBC Sep 5 20:40:27 vpnmach racoon: DEBUG: encryption(des) Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Hash Algorithm, flag=0x8000, lorv=MD5 Sep 5 20:40:27 vpnmach racoon: DEBUG: hash(md5) Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Authentication Method, flag=0x8000, lorv=pre-shared key Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Group Description, flag=0x8000, lorv=1024-bit MODP group Sep 5 20:40:27 vpnmach racoon: DEBUG: hmac(modp1024) Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Life Type, flag=0x8000, lorv=seconds Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Life Duration, flag=0x0000, lorv=4 Sep 5 20:40:27 vpnmach racoon: DEBUG: pair 1: Sep 5 20:40:27 vpnmach racoon: DEBUG: 0x8012275a0: next=0x0 tnext=0x8012275c0 Sep 5 20:40:27 vpnmach racoon: DEBUG: 0x8012275c0: next=0x0 tnext=0x8012275e0 Sep 5 20:40:27 vpnmach racoon: DEBUG: 0x8012275e0: next=0x0 tnext=0x801227600 Sep 5 20:40:27 vpnmach racoon: DEBUG: 0x801227600: next=0x0 tnext=0x801227620 Sep 5 20:40:27 vpnmach racoon: DEBUG: 0x801227620: next=0x0 tnext=0x801227640 Sep 5 20:40:27 vpnmach racoon: DEBUG: 0x801227640: next=0x0 tnext=0x0 Sep 5 20:40:27 vpnmach racoon: DEBUG: proposal #1: 6 transform Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Encryption Algorithm, flag=0x8000, lorv=AES-CBC Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Hash Algorithm, flag=0x8000, lorv=SHA Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Authentication Method, flag=0x8000, lorv=pre-shared key Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Group Description, flag=0x8000, lorv=1024-bit MODP group Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Life Type, flag=0x8000, lorv=seconds Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Life Duration, flag=0x0000, lorv=4 Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Key Length, flag=0x8000, lorv=256 Sep 5 20:40:27 vpnmach racoon: DEBUG: prop#=1, prot-id=ISAKMP, spi-size=0, #trns=6 Sep 5 20:40:27 vpnmach racoon: DEBUG: trns#=1, trns-id=IKE Sep 5 20:40:27 vpnmach racoon: DEBUG: lifetime = 86400 Sep 5 20:40:27 vpnmach racoon: DEBUG: lifebyte = 0 Sep 5 20:40:27 vpnmach racoon: DEBUG: enctype = AES-CBC Sep 5 20:40:27 vpnmach racoon: DEBUG: encklen = 256 Sep 5 20:40:27 vpnmach racoon: DEBUG: hashtype = SHA Sep 5 20:40:27 vpnmach racoon: DEBUG: authmethod = pre-shared key Sep 5 20:40:27 vpnmach racoon: DEBUG: dh_group = 1024-bit MODP group Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Encryption Algorithm, flag=0x8000, lorv=AES-CBC Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Hash Algorithm, flag=0x8000, lorv=MD5 Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Authentication Method, flag=0x8000, lorv=pre-shared key Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Group Description, flag=0x8000, lorv=1024-bit MODP group Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Life Type, flag=0x8000, lorv=seconds Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Life Duration, flag=0x0000, lorv=4 Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Key Length, flag=0x8000, lorv=256 Sep 5 20:40:27 vpnmach racoon: DEBUG: prop#=1, prot-id=ISAKMP, spi-size=0, #trns=6 Sep 5 20:40:27 vpnmach racoon: DEBUG: trns#=2, trns-id=IKE Sep 5 20:40:27 vpnmach racoon: DEBUG: lifetime = 86400 Sep 5 20:40:27 vpnmach racoon: DEBUG: lifebyte = 0 Sep 5 20:40:27 vpnmach racoon: DEBUG: enctype = AES-CBC Sep 5 20:40:27 vpnmach racoon: DEBUG: encklen = 256 Sep 5 20:40:27 vpnmach racoon: DEBUG: hashtype = MD5 Sep 5 20:40:27 vpnmach racoon: DEBUG: authmethod = pre-shared key Sep 5 20:40:27 vpnmach racoon: DEBUG: dh_group = 1024-bit MODP group Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Encryption Algorithm, flag=0x8000, lorv=3DES-CBC Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Hash Algorithm, flag=0x8000, lorv=SHA Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Authentication Method, flag=0x8000, lorv=pre-shared key Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Group Description, flag=0x8000, lorv=1024-bit MODP group Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Life Type, flag=0x8000, lorv=seconds Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Life Type, flag=0x8000, lorv=seconds Sep 5 20:40:27 vpnmach racoon: DEBUG: type=Life Duration, flag=0x0000, lorv=4 Sep 5 20:40:27 vpnmach racoon: DEBUG: prop#=1, prot-id=ISAKMP, spi-size=0, #trns=6 Sep 5 20:40:27 vpnmach racoon: DEBUG: trns#=3, trns-id=IKE Sep 5 20:40:27 vpnmach racoon: DEBUG: lifetime = 86400 Sep 5 20:40:27 vpnmach racoon: DEBUG: lifebyte = 0 Sep 5 20:40:27 vpnmach racoon: DEBUG: enctype = 3DES-CBC Sep 5 20:40:27 vpnmach racoon: DEBUG: encklen = 0 Sep 5 20:40:27 vpnmach racoon: DEBUG: hashtype = SHA Sep 5 20:40:27 vpnmach racoon: DEBUG: authmethod = pre-shared key Sep 5 20:40:27 vpnmach racoon: DEBUG: dh_group = 1024-bit MODP group Sep 5 20:40:27 vpnmach racoon: DEBUG: an acceptable proposal found. Sep 5 20:40:27 vpnmach racoon: DEBUG: hmac(modp1024) Sep 5 20:40:27 vpnmach racoon: DEBUG: agreed on pre-shared key auth. Sep 5 20:40:27 vpnmach racoon: DEBUG: === Sep 5 20:40:27 vpnmach racoon: DEBUG: new cookie: 2d88244be68bad7a Sep 5 20:40:27 vpnmach racoon: DEBUG: add payload of len 52, next type 0 Sep 5 20:40:27 vpnmach racoon: DEBUG: 84 bytes from a.b.c.d[500] to w.x.y.z[500] Sep 5 20:40:27 vpnmach racoon: DEBUG: sockname a.b.c.d[500] Sep 5 20:40:27 vpnmach racoon: DEBUG: send packet from a.b.c.d[500] Sep 5 20:40:27 vpnmach racoon: DEBUG: send packet to w.x.y.z[500] Sep 5 20:40:27 vpnmach racoon: DEBUG: 1 times of 84 bytes message will be sent to w.x.y.z[500] Sep 5 20:40:27 vpnmach racoon: DEBUG: 67d0a8dd 454e766f 2d88344b e68aad8a 01100200 00000000 00000054 00000038 00000001 00000001 Sep 5 20:40:27 vpnmach racoon: DEBUG: resend phase1 packet 67d0a5ad431e746f:2d88244be68bad7a Sep 5 20:40:29 vpnmach racoon: DEBUG: === Sep 5 20:40:29 vpnmach racoon: DEBUG: 336 bytes message received from w.x.y.z[500] to a.b.c.d[500] Sep 5 20:40:29 vpnmach racoon: DEBUG: 67d0a8dd 454e766f 00000000 00000000 01100200 00000000 00000150 0d0000f4 00000001 00000001 Sep 5 20:40:29 vpnmach racoon: DEBUG: sockname a.b.c.d[500] Sep 5 20:40:29 vpnmach racoon: DEBUG: send packet from a.b.c.d[500] Sep 5 20:40:29 vpnmach racoon: DEBUG: send packet to w.x.y.z[500] Sep 5 20:40:29 vpnmach racoon: DEBUG: 1 times of 84 bytes message will be sent to w.x.y.z[500] Sep 5 20:40:29 vpnmach racoon: DEBUG: 67d0a8dd 454e766f 2d88344b e68aad8a 01100200 00000000 00000054 00000038 00000001 00000001 Sep 5 20:40:29 vpnmach racoon: DEBUG: pk_recv: retry[0] recv() Sep 5 20:40:29 vpnmach racoon: DEBUG: got pfkey FLUSH message Sep 5 20:40:29 vpnmach racoon: DEBUG: pk_recv: retry[0] recv() Sep 5 20:40:29 vpnmach racoon: DEBUG: got pfkey X_SPDFLUSH message Sep 5 20:40:29 vpnmach racoon: DEBUG: pk_recv: retry[0] recv() Sep 5 20:40:29 vpnmach racoon: DEBUG: got pfkey REGISTER message Sep 5 20:40:29 vpnmach racoon: DEBUG: pk_recv: retry[0] recv() Sep 5 20:40:29 vpnmach racoon: DEBUG: got pfkey X_SPDADD message Sep 5 20:40:29 vpnmach racoon: DEBUG: pk_recv: retry[0] recv() Sep 5 20:40:29 vpnmach racoon: DEBUG: got pfkey X_SPDADD message Sep 5 20:40:29 vpnmach racoon: DEBUG: sub:0x7fffffffe3e0: w.x.y.z/32[0] a.b.c.d/32[0] proto=any dir=in Sep 5 20:40:29 vpnmach racoon: DEBUG: db :0x801238490: a.b.c.d/32[0] w.x.y.z/32[0] proto=any dir=out Sep 5 20:40:29 vpnmach racoon: DEBUG: pk_recv: retry[0] recv() Sep 5 20:40:29 vpnmach racoon: DEBUG: got pfkey X_SPDADD message Sep 5 20:40:29 vpnmach racoon: DEBUG: sub:0x7fffffffe3e0: 192.168.0.1/32[0] 192.168.50.1/32[0] proto=any dir=out Sep 5 20:40:29 vpnmach racoon: DEBUG: db :0x801238490: a.b.c.d/32[0] w.x.y.z/32[0] proto=any dir=out Sep 5 20:40:29 vpnmach racoon: DEBUG: sub:0x7fffffffe3e0: 192.168.0.1/32[0] 192.168.50.1/32[0] proto=any dir=out Sep 5 20:40:29 vpnmach racoon: DEBUG: db :0x801238610: w.x.y.z/32[0] a.b.c.d/32[0] proto=any dir=in Sep 5 20:40:29 vpnmach racoon: DEBUG: pk_recv: retry[0] recv() Sep 5 20:40:29 vpnmach racoon: DEBUG: got pfkey X_SPDADD message Sep 5 20:40:29 vpnmach racoon: DEBUG: sub:0x7fffffffe3e0: 192.168.50.1/32[0] 192.168.0.1/32[0] proto=any dir=in Sep 5 20:40:29 vpnmach racoon: DEBUG: db :0x801238490: a.b.c.d/32[0] w.x.y.z/32[0] proto=any dir=out Sep 5 20:40:29 vpnmach racoon: DEBUG: sub:0x7fffffffe3e0: 192.168.50.1/32[0] 192.168.0.1/32[0] proto=any dir=in Sep 5 20:40:29 vpnmach racoon: DEBUG: db :0x801238610: w.x.y.z/32[0] a.b.c.d/32[0] proto=any dir=in Sep 5 20:40:29 vpnmach racoon: DEBUG: sub:0x7fffffffe3e0: 192.168.50.1/32[0] 192.168.0.1/32[0] proto=any dir=in Sep 5 20:40:29 vpnmach racoon: DEBUG: db :0x801238790: 192.168.0.1/32[0] 192.168.50.1/32[0] proto=any dir=out Sep 5 20:40:31 vpnmach racoon: DEBUG: === Sep 5 20:40:31 vpnmach racoon: DEBUG: 336 bytes message received from w.x.y.z[500] to a.b.c.d[500] Sep 5 20:40:31 vpnmach racoon: DEBUG: 67d0a8dd 454e766f 00000000 00000000 01100200 00000000 00000150 0d0000f4 00000001 00000001 Sep 5 20:40:31 vpnmach racoon: DEBUG: sockname a.b.c.d[500] Sep 5 20:40:31 vpnmach racoon: DEBUG: send packet from a.b.c.d[500] Sep 5 20:40:31 vpnmach racoon: DEBUG: send packet to w.x.y.z[500] Sep 5 20:40:31 vpnmach racoon: DEBUG: 1 times of 84 bytes message will be sent to w.x.y.z[500] Sep 5 20:40:31 vpnmach racoon: DEBUG: 67d0a8dd 454e766f 2d88344b e68aad8a 01100200 00000000 00000054 00000038 00000001 00000001 Sep 5 20:40:33 vpnmach racoon: DEBUG: === Sep 5 20:40:33 vpnmach racoon: DEBUG: 336 bytes message received from w.x.y.z[500] to a.b.c.d[500] Sep 5 20:40:33 vpnmach racoon: DEBUG: 67d0a8dd 454e766f 00000000 00000000 01100200 00000000 00000150 0d0000f4 00000001 00000001 Sep 5 20:40:33 vpnmach racoon: DEBUG: sockname a.b.c.d[500] Sep 5 20:40:33 vpnmach racoon: DEBUG: send packet from a.b.c.d[500] Sep 5 20:40:33 vpnmach racoon: DEBUG: send packet to w.x.y.z[500] Sep 5 20:40:33 vpnmach racoon: DEBUG: 1 times of 84 bytes message will be sent to w.x.y.z[500] Sep 5 20:40:33 vpnmach racoon: DEBUG: 67d0a8dd 454e766f 2d88344b e68aad8a 01100200 00000000 00000054 00000038 00000001 00000001 Sep 5 20:40:36 vpnmach racoon: DEBUG: === Sep 5 20:40:36 vpnmach racoon: DEBUG: 336 bytes message received from w.x.y.z[500] to a.b.c.d[500] Sep 5 20:40:36 vpnmach racoon: DEBUG: 67d0a8dd 454e766f 00000000 00000000 01100200 00000000 00000150 0d0000f4 00000001 00000001 Sep 5 20:40:36 vpnmach racoon: DEBUG: sockname a.b.c.d[500] Sep 5 20:40:36 vpnmach racoon: DEBUG: send packet from a.b.c.d[500] Sep 5 20:40:36 vpnmach racoon: DEBUG: send packet to w.x.y.z[500] Sep 5 20:40:36 vpnmach racoon: DEBUG: 1 times of 84 bytes message will be sent to w.x.y.z[500] Sep 5 20:40:36 vpnmach racoon: DEBUG: 67d0a8dd 454e766f 2d88344b e68aad8a 01100200 00000000 00000054 00000038 00000001 00000001 Sep 5 20:40:37 vpnmach racoon: DEBUG: 84 bytes from a.b.c.d[500] to w.x.y.z[500] Sep 5 20:40:37 vpnmach racoon: DEBUG: sockname a.b.c.d[500] Sep 5 20:40:37 vpnmach racoon: DEBUG: send packet from a.b.c.d[500] Sep 5 20:40:37 vpnmach racoon: DEBUG: send packet to w.x.y.z[500] Sep 5 20:40:37 vpnmach racoon: DEBUG: 1 times of 84 bytes message will be sent to w.x.y.z[500] Sep 5 20:40:37 vpnmach racoon: DEBUG: 67d0a8dd 454e766f 2d88344b e68aad8a 01100200 00000000 00000054 00000038 00000001 00000001 Sep 5 20:40:37 vpnmach racoon: DEBUG: resend phase1 packet 67d0a5ad431e746f:2d88244be68bad7a Sep 5 20:40:38 vpnmach racoon: DEBUG: === Sep 5 20:40:38 vpnmach racoon: DEBUG: 336 bytes message received from w.x.y.z[500] to a.b.c.d[500] Sep 5 20:40:38 vpnmach racoon: DEBUG: 67d0a8dd 454e766f 00000000 00000000 01100200 00000000 00000150 0d0000f4 00000001 00000001 Sep 5 20:40:38 vpnmach racoon: DEBUG: sockname a.b.c.d[500] Sep 5 20:40:38 vpnmach racoon: DEBUG: send packet from a.b.c.d[500] Sep 5 20:40:38 vpnmach racoon: DEBUG: send packet to w.x.y.z[500] Sep 5 20:40:38 vpnmach racoon: DEBUG: 1 times of 84 bytes message will be sent to w.x.y.z[500] Sep 5 20:40:38 vpnmach racoon: DEBUG: 67d0a8dd 454e766f 2d88344b e68aad8a 01100200 00000000 00000054 00000038 00000001 00000001 Sep 5 20:40:38 vpnmach racoon: DEBUG: deleted the retransmission packet to w.x.y.z[500]. Sep 5 20:40:42 vpnmach racoon: DEBUG: === Sep 5 20:40:42 vpnmach racoon: DEBUG: 336 bytes message received from w.x.y.z[500] to a.b.c.d[500] Sep 5 20:40:42 vpnmach racoon: DEBUG: 67d0a8dd 454e766f 00000000 00000000 01100200 00000000 00000150 0d0000f4 00000001 00000001 Sep 5 20:40:42 vpnmach racoon: [w.x.y.z] DEBUG: malformed cookie received. it has to be as the initiator. 67d0a5ad431e746f:2d88244be68bad7a Sep 5 20:40:46 vpnmach racoon: DEBUG: === Sep 5 20:40:46 vpnmach racoon: DEBUG: 336 bytes message received from w.x.y.z[500] to a.b.c.d[500] Note: a.b.c.d my public end, w.x.y.z the other public end. 192.168.0.1 my private end and 192.168.50.1 is the other private end. Some field are scrumbled. Configuration files: ====== /etc/ipsec.conf spdadd a.b.c.d w.x.y.z any -P out ipsec esp/tunnel/a.b.c.d-w.x.y.z/unique; spdadd w.x.y.z a.b.c.d any -P in ipsec esp/tunnel/w.x.y.z-a.b.c.d/unique; spdadd 192.168.0.1 192.168.50.1 any -P out ipsec esp/tunnel/a.b.c.d-w.x.y.z/unique; spdadd 192.168.50.1 192.168.0.1 any -P in ipsec esp/tunnel/w.x.y.z-a.b.c.d/unique; ====== /usr/local/etc/racoon/racoon.conf path pre_shared_key "/usr/local/etc/racoon/psk.keys"; listen { isakmp a.b.c.d; } remote w.x.y.z { exchange_mode main; proposal_check obey; proposal { encryption_algorithm 3des; hash_algorithm sha1; authentication_method pre_shared_key; dh_group modp1024; } } sainfo address a.b.c.d any address w.x.y.z any { encryption_algorithm 3des; authentication_algorithm hmac_sha1; compression_algorithm deflate; } sainfo address 192.168.0.1 any address 192.168.50.1 any { encryption_algorithm 3des; authentication_algorithm hmac_sha1; compression_algorithm deflate; } ====== /etc/pf.conf ... scrub in all no-df random-id ... block log all ... pass in log on $EIF proto udp from w.x.y.z port isakmp to $EIF:0 port isakmp pass in log on $EIF proto esp from w.x.y.z to $EIF:0 ... # setkey -DP w.x.y.z[any] a.b.c.d[any] any in ipsec esp/tunnel/w.x.y.z-a.b.c.d/unique#16394 spid=10 seq=3 pid=14210 refcnt=1 192.168.50.1[any] 192.168.0.1[any] any in ipsec esp/tunnel/w.x.y.z-a.b.c.d/unique#16396 spid=12 seq=2 pid=14210 refcnt=1 a.b.c.d[any] w.x.y.z[any] any out ipsec esp/tunnel/a.b.c.d-w.x.y.z/unique#16393 spid=9 seq=1 pid=14210 refcnt=1 192.168.0.1[any] 192.168.50.1[any] any out ipsec esp/tunnel/a.b.c.d-w.x.y.z/unique#16395 spid=11 seq=0 pid=14210 refcnt=1 Note: a.b.c.d my public end, w.x.y.z the other public end. 192.168.0.1 my private end and 192.168.50.1 is the other private end. Thanks for looking into that. Cheers, Mikhail. -- Mikhail Goriachev Webanoide Mobile: +56 9 78772741 Web: www.webanoide.org