IPsec phase 1 and 2 negotiation in an infinite loop.

Mikhail Goriachev mikhailg at webanoide.org
Tue Sep 6 03:57:50 UTC 2011


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 <external int>  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



More information about the freebsd-questions mailing list