Skip site navigation (1)Skip section navigation (2)
Date:      Wed, 03 Apr 2002 11:20:03 -0700
From:      Ryan Larsen <rlarsen@zserve.com>
To:        freebsd-questions@freebsd.org
Subject:   Question about IPsec and Racoon
Message-ID:  <3CAB47D3.2020302@zserve.com>

next in thread | raw e-mail | index | archive | help
Hi! Hoping for a little help. I'm trying to set up a VPN tunnel between 
a Cisco PIX and a BSD box. Here are my BSD configs for rc.conf and 
racoon.conf:

rc.conf
# -- sysinstall generated deltas -- # Fri Mar 29 14:27:35 2002
# Created: Fri Mar 29 14:27:35 2002
# Enable network daemons for user convenience.
# Please make all changes to this file, not to /etc/defaults/rc.conf.
# This file now contains just the overrides from /etc/defaults/rc.conf.
kern_securelevel_enable="NO"
nfs_reserved_port_only="YES"
#sendmail_enable="YES"
#sshd_enable="YES"
usbd_enable="YES"

# -- sysinstall generated deltas -- # Fri Mar 29 07:50:35 2002
ifconfig_xl0="inet 208.186.182.111  netmask 255.255.255.224"
ifconfig_dc0="inet 192.168.2.253  netmask 255.255.255.0"
kern_securelevel_enable="NO"
sendmail_enable="NO"
defaultrouter="208.186.182.97"
sshd_enable="YES"
hostname="fw_pr.zserve.com"

# -- sysinstall generated deltas -- # Fri Mar 29 08:02:15 2002
ifconfig_dc0="inet 192.168.2.253  netmask 255.255.255.0"
defaultrouter="208.186.182.97"
hostname="fw_pr.zserve.com"

# -- gif interfaces for IPSEC tunnel
gif_interface="YES"
gif_interfaces="gif0"
gifconfig_gif0="208.186.182.111 166.70.161.130"
ifconfig_gif0="inet 192.168.2.253 192.168.1.254 netmask 255.255.255.0"

racoon.conf
remote anonymous
{
        #exchange_mode main,aggressive;
        exchange_mode aggressive,main;
        doi ipsec_doi;
        situation identity_only;

        #my_identifier address "208.186.182.111";
        #my_identifier user_fqdn "sakane@kame.net";
        #peers_identifier user_fqdn "sakane@kame.net";
        #certificate_type x509 "mycert" "mypriv";

        nonce_size 16;
        lifetime time 86400 sec;        # sec,min,hour
        initial_contact on;
        support_mip6 on;
        proposal_check obey;    # obey, strict or claim

        proposal {
                encryption_algorithm des;
                hash_algorithm sha1;
                authentication_method pre_shared_key ;
                dh_group 2 ;
        }
}
sainfo anonymous
{
        pfs_group 1;
        lifetime time 3600 sec;
        encryption_algorithm des ;
        authentication_algorithm hmac_md5;
        compression_algorithm deflate ;
}

The SPD's are set up correctly. Racoon startup generates an error about 
not being able to bind an address that's already in use:

2002-04-03 10:59:36: ERROR: isakmp.c:1349:isakmp_open(): failed to bind 
(Address already in use).

I'm seeing the attempted exchange of keys when trying to ping 
192.168.1.2 from 192.168.2.253. Debugging shows:

#####################
2002-04-03 11:09:58: DEBUG: pfkey.c:192:pfkey_handler(): get pfkey 
ACQUIRE message
2002-04-03 11:09:58: DEBUG: pfkey.c:1519:pk_recvacquire(): suitable 
outbound SP found: 192.168.2.0/24[0] 192.168.1.2/24[0] proto=any dir=out.
2002-04-03 11:09:58: DEBUG: policy.c:184:cmpspidxstrict(): 
sub:0xbfbff93c: 192.168.1.2/24[0] 192.168.2.0/24[0] proto=any dir=in
2002-04-03 11:09:58: DEBUG: policy.c:185:cmpspidxstrict(): db 
:0x80a3c08: 192.168.1.2/24[0] 192.168.2.0/24[0] proto=any dir=in
2002-04-03 11:09:58: DEBUG: pfkey.c:1535:pk_recvacquire(): suitable 
inbound SP found: 192.168.1.2/24[0] 192.168.2.0/24[0] proto=any dir=in.
2002-04-03 11:09:58: DEBUG: pfkey.c:1574:pk_recvacquire(): new acquire 
192.168.2.0/24[0] 192.168.1.2/24[0] proto=any dir=out
2002-04-03 11:09:58: DEBUG: sainfo.c:100:getsainfo(): anonymous sainfo 
selected.
2002-04-03 11:09:58: DEBUG: proposal.c:825:printsaproto():  
(proto_id=ESP spisize=4 spi=00000000 spi_p=00000000 encmode=Tunnel 
reqid=0:0)
2002-04-03 11:09:58: DEBUG: proposal.c:859:printsatrns():   (trns_id=DES 
encklen=0 authtype=1)
2002-04-03 11:09:58: DEBUG: remoteconf.c:129:getrmconf(): anonymous 
configuration selected for 166.70.161.130.
2002-04-03 11:09:58: DEBUG: isakmp.c:1711:isakmp_post_acquire(): begin 
QUICK mode.
2002-04-03 11:09:58: DEBUG: isakmp.c:934:isakmp_ph2begin_i(): ===
2002-04-03 11:09:58: DEBUG: isakmp.c:935:isakmp_ph2begin_i(): begin 
QUICK mode.
2002-04-03 11:09:58: INFO: isakmp.c:939:isakmp_ph2begin_i(): initiate 
new phase 2 negotiation: 208.186.182.111[0]<=>166.70.161.130[0] 
2002-04-03 11:09:58: DEBUG: oakley.c:2540:oakley_newiv2(): compute IV 
for phase2
2002-04-03 11:09:58: DEBUG: oakley.c:2541:oakley_newiv2(): phase1 last IV:
2002-04-03 11:09:58: DEBUG: plog.c:193:plogdump():
699ebf71 8345291a 741e5d42
2002-04-03 11:09:58: DEBUG: algorithm.c:252:alg_oakley_hashdef(): hash(sha1)
2002-04-03 11:09:58: DEBUG: algorithm.c:382:alg_oakley_encdef(): 
encription(des)
2002-04-03 11:09:58: DEBUG: oakley.c:2573:oakley_newiv2(): phase2 IV 
computed:
2002-04-03 11:09:58: DEBUG: plog.c:193:plogdump():
42680b26 aef6a0e8
2002-04-03 11:09:58: DEBUG: pfkey.c:789:pk_sendgetspi(): call 
pfkey_send_getspi
2002-04-03 11:09:58: DEBUG: pfkey.c:802:pk_sendgetspi(): pfkey GETSPI 
sent: ESP/Tunnel 166.70.161.130->208.186.182.111
2002-04-03 11:09:58: DEBUG: isakmp_quick.c:129:quick_i1prep(): pfkey 
getspi sent.
2002-04-03 11:09:58: DEBUG: pfkey.c:192:pfkey_handler(): get pfkey 
GETSPI message
2002-04-03 11:09:58: DEBUG: pfkey.c:873:pk_recvgetspi(): pfkey GETSPI 
succeeded: ESP/Tunnel 166.70.161.130->208.186.182.111 
spi=192386530(0xb7795e2)
2002-04-03 11:09:58: DEBUG: algorithm.c:610:alg_oakley_dhdef(): 
hmac(modp768)
2002-04-03 11:09:58: DEBUG: algorithm.c:610:alg_oakley_dhdef(): 
hmac(modp768)
2002-04-03 11:09:58: DEBUG: algorithm.c:610:alg_oakley_dhdef(): 
hmac(modp768)
2002-04-03 11:09:58: DEBUG: oakley.c:253:oakley_dh_generate(): compute 
DH's private.
2002-04-03 11:09:58: DEBUG: plog.c:193:plogdump():
6545ae44 8a512f4b bbbce773 9942998b 80885f56 b73784b7 cdfeab99 09832420
d02287be 2a768c90 ed60d1e4 d3a20075 d2de2aba c4896113 b0ba5821 9c077703
3e14119c f0a91d0a a235e447 888180e4 90562adb 5ed79eec 02be3b37 b14d3a6b
2002-04-03 11:09:58: DEBUG: oakley.c:255:oakley_dh_generate(): compute 
DH's public.
2002-04-03 11:09:58: DEBUG: plog.c:193:plogdump():
d1686ea7 a370c3a1 187830c4 dc25dba6 1f20993d d8b11e55 2588c562 dd4a4bc5
ff3b6a86 1f0b5e56 e1e90b84 17de6fb7 838ba3bd ab9aa1c2 886d9ff0 b7a4698a
5259cec4 75a8d708 516da5b5 b17191df 65da499e 79e2d2d3 c4d3ebd7 f01409c7
2002-04-03 11:09:58: DEBUG: ipsec_doi.c:3324:ipsecdoi_setid2(): use 
local ID type IPv4_subnet
2002-04-03 11:09:58: DEBUG: ipsec_doi.c:3364:ipsecdoi_setid2(): use 
remote ID type IPv4_subnet
2002-04-03 11:09:58: DEBUG: isakmp_quick.c:206:quick_i1send(): 
IDci:2002-04-03 11:09:58: DEBUG: plog.c:193:plogdump():
04000000 c0a80200 ffffff00
2002-04-03 11:09:58: DEBUG: isakmp_quick.c:208:quick_i1send(): 
IDcr:2002-04-03 11:09:58: DEBUG: plog.c:193:plogdump():
04000000 c0a80102 ffffff00
2002-04-03 11:09:58: DEBUG: isakmp.c:2110:set_isakmp_payload(): add 
payload of len 48, next type 10
2002-04-03 11:09:58: DEBUG: isakmp.c:2110:set_isakmp_payload(): add 
payload of len 16, next type 4
2002-04-03 11:09:58: DEBUG: isakmp.c:2110:set_isakmp_payload(): add 
payload of len 96, next type 5
2002-04-03 11:09:58: DEBUG: isakmp.c:2110:set_isakmp_payload(): add 
payload of len 12, next type 5
2002-04-03 11:09:58: DEBUG: isakmp.c:2110:set_isakmp_payload(): add 
payload of len 12, next type 0
2002-04-03 11:09:58: DEBUG: oakley.c:745:oakley_compute_hash1(): HASH with:
2002-04-03 11:09:58: DEBUG: plog.c:193:plogdump():
741e5d42 0a000034 00000001 00000001 00000028 01030401 0b7795e2 0000001c
01020000 80010001 80020e10 80040001 80050001 80030001 04000014 b659f19d
0c7c873c 385a1984 a6128d34 05000064 d1686ea7 a370c3a1 187830c4 dc25dba6
1f20993d d8b11e55 2588c562 dd4a4bc5 ff3b6a86 1f0b5e56 e1e90b84 17de6fb7
838ba3bd ab9aa1c2 886d9ff0 b7a4698a 5259cec4 75a8d708 516da5b5 b17191df
65da499e 79e2d2d3 c4d3ebd7 f01409c7 05000010 04000000 c0a80200 ffffff00
00000010 04000000 c0a80102 ffffff00
2002-04-03 11:09:58: DEBUG: algorithm.c:322:alg_oakley_hmacdef(): 
hmac(hmac_sha1)
2002-04-03 11:09:58: DEBUG: oakley.c:755:oakley_compute_hash1(): HASH 
computed:
2002-04-03 11:09:58: DEBUG: plog.c:193:plogdump():
8cc47faf 3e21c166 8b14b441 ac3003fa 1ac44d5d
2002-04-03 11:09:58: DEBUG: isakmp.c:2110:set_isakmp_payload(): add 
payload of len 20, next type 1
2002-04-03 11:09:58: DEBUG: isakmp.c:2245:isakmp_printpacket(): begin.
09:58.129761 208.186.182.111:500 -> 166.70.161.130:500: isakmp 1.0 msgid 
741e5d42 cookie 15015d2d542d9348->78d1bcf042eb7a2e: phase 2/others ? 
oakley-quick:
    (hash: len=20)
    (sa: doi=ipsec situation=identity
        (p: #1 protoid=ipsec-esp transform=1 spi=0b7795e2
            (t: #1 id=1des (type=lifetype value=sec)(type=life 
value=0e10)(type=enc mode value=tunnel)(type=auth 
value=hmac-md5)(type=group desc value=modp768))))
    (nonce: n len=16)
    (ke: key len=96)
    (id: idtype=IPv4net protoid=0 port=0 len=8 192.168.2.0/255.255.255.0)
    (id: idtype=IPv4net protoid=0 port=0 len=8 192.168.1.2/255.255.255.0)
2002-04-03 11:09:58: DEBUG: oakley.c:2739:oakley_do_encrypt(): begin 
encryption.
2002-04-03 11:09:58: DEBUG: algorithm.c:382:alg_oakley_encdef(): 
encription(des)
2002-04-03 11:09:58: DEBUG: oakley.c:2755:oakley_do_encrypt(): pad 
length = 4
2002-04-03 11:09:58: DEBUG: plog.c:193:plogdump():
01000018 8cc47faf 3e21c166 8b14b441 ac3003fa 1ac44d5d 0a000034 00000001
00000001 00000028 01030401 0b7795e2 0000001c 01020000 80010001 80020e10
80040001 80050001 80030001 04000014 b659f19d 0c7c873c 385a1984 a6128d34
05000064 d1686ea7 a370c3a1 187830c4 dc25dba6 1f20993d d8b11e55 2588c562
dd4a4bc5 ff3b6a86 1f0b5e56 e1e90b84 17de6fb7 838ba3bd ab9aa1c2 886d9ff0
b7a4698a 5259cec4 75a8d708 516da5b5 b17191df 65da499e 79e2d2d3 c4d3ebd7
f01409c7 05000010 04000000 c0a80200 ffffff00 00000010 04000000 c0a80102
ffffff00 00000004
2002-04-03 11:09:58: DEBUG: algorithm.c:382:alg_oakley_encdef(): 
encription(des)
2002-04-03 11:09:58: DEBUG: oakley.c:2790:oakley_do_encrypt(): with key:
2002-04-03 11:09:58: DEBUG: plog.c:193:plogdump():
2a3271bb 86af08b2
2002-04-03 11:09:58: DEBUG: oakley.c:2798:oakley_do_encrypt(): encrypted 
payload by IV:
2002-04-03 11:09:58: DEBUG: plog.c:193:plogdump():
42680b26 aef6a0e8
2002-04-03 11:09:58: DEBUG: oakley.c:2805:oakley_do_encrypt(): save IV 
for next:
2002-04-03 11:09:58: DEBUG: plog.c:193:plogdump():
23bd7b5c 86a2a508
2002-04-03 11:09:58: DEBUG: oakley.c:2822:oakley_do_encrypt(): encrypted.
2002-04-03 11:09:58: DEBUG: sockmisc.c:421:sendfromto(): sockname 
208.186.182.111[500]
2002-04-03 11:09:58: DEBUG: sockmisc.c:423:sendfromto(): send packet 
from 208.186.182.111[500]
2002-04-03 11:09:58: DEBUG: sockmisc.c:425:sendfromto(): send packet to 
166.70.161.130[500]
2002-04-03 11:09:58: DEBUG: sockmisc.c:563:sendfromto(): 1 times of 260 
bytes message will be sent to 208.186.182.111[500]
2002-04-03 11:09:58: DEBUG: plog.c:193:plogdump():
15015d2d 542d9348 78d1bcf0 42eb7a2e 08102001 741e5d42 00000104 c8cb1680
652b4d43 86ef4b0a f592e945 b3a66724 abe0bcc6 9f7cc280 e7a88415 ad6fa883
e2710815 75bbf392 490e7a5e af73151d 5348d45f c5a3bd42 ad2e79ca a7f893b1
92dae530 9d514c8c b808fa71 d60fc08d 35f988a2 7ea92012 3886d9f1 c813d7b5
cf2dac49 9bfc6473 dc8a4133 3ee3d928 d075b6b2 c400f273 5d388b9c 834db890
aecfe8e9 d0fbff46 9fd02ee7 ef8ede2d ed1e6df7 525d5412 752a9f42 a24f26cb
f87e0aca fb4c42f6 70ccd2dc f24be846 cc5a7094 d637cbb4 0954f482 3d90c8e4
c9500185 a48a9903 87622f39 e186b31a 05229f0a f519a9f6 42ce5489 23bd7b5c
86a2a508
2002-04-03 11:09:58: DEBUG: isakmp.c:1484:isakmp_ph2resend(): resend 
phase2 packet 15015d2d542d9348:78d1bcf042eb7a2e:0000741e
2002-04-03 11:09:58: DEBUG: isakmp.c:218:isakmp_handler(): ===
2002-04-03 11:09:58: DEBUG: isakmp.c:219:isakmp_handler(): 124 bytes 
message received from 166.70.161.130[500]
2002-04-03 11:09:58: DEBUG: plog.c:193:plogdump():
15015d2d 542d9348 78d1bcf0 42eb7a2e 08100501 dce0b8fe 0000007c 04b56c08
d17bd0d8 f5738df2 6034c432 32c5c89d c36b63cb 81a8ddcf e56b76b9 84c4b1e9
b791b300 6fa9ec81 6b5cf50d 737163de 1908b8de 19c64e6c e60d967d 920be094
af6f70a4 13919c41 a38e0581 6bc84a36 7f786c2e 555dcf62 9494dba6
2002-04-03 11:09:58: DEBUG: isakmp.c:2245:isakmp_printpacket(): begin.
09:58.218566 166.70.161.130:500 -> 208.186.182.111:500: isakmp 1.0 msgid 
dce0b8fe cookie 15015d2d542d9348->78d1bcf042eb7a2e: phase 2/others ? 
inf[E]: [|hash]
2002-04-03 11:09:58: DEBUG: isakmp_inf.c:115:isakmp_info_recv(): receive 
Information.
2002-04-03 11:09:58: DEBUG: oakley.c:2540:oakley_newiv2(): compute IV 
for phase2
2002-04-03 11:09:58: DEBUG: oakley.c:2541:oakley_newiv2(): phase1 last IV:
2002-04-03 11:09:58: DEBUG: plog.c:193:plogdump():
699ebf71 8345291a dce0b8fe
2002-04-03 11:09:58: DEBUG: algorithm.c:252:alg_oakley_hashdef(): hash(sha1)
2002-04-03 11:09:58: DEBUG: algorithm.c:382:alg_oakley_encdef(): 
encription(des)
2002-04-03 11:09:58: DEBUG: oakley.c:2573:oakley_newiv2(): phase2 IV 
computed:
2002-04-03 11:09:58: DEBUG: plog.c:193:plogdump():
3222f0d1 0c6c6056
2002-04-03 11:09:58: DEBUG: oakley.c:2616:oakley_do_decrypt(): begin 
decryption.
2002-04-03 11:09:58: DEBUG: algorithm.c:382:alg_oakley_encdef(): 
encription(des)
2002-04-03 11:09:58: DEBUG: oakley.c:2630:oakley_do_decrypt(): IV was 
saved for next processing:
2002-04-03 11:09:58: DEBUG: plog.c:193:plogdump():
555dcf62 9494dba6
2002-04-03 11:09:58: DEBUG: algorithm.c:382:alg_oakley_encdef(): 
encription(des)
2002-04-03 11:09:58: DEBUG: oakley.c:2655:oakley_do_decrypt(): with key:
2002-04-03 11:09:58: DEBUG: plog.c:193:plogdump():
2a3271bb 86af08b2
2002-04-03 11:09:58: DEBUG: oakley.c:2663:oakley_do_decrypt(): decrypted 
payload by IV:
2002-04-03 11:09:58: DEBUG: plog.c:193:plogdump():
3222f0d1 0c6c6056
2002-04-03 11:09:58: DEBUG: oakley.c:2666:oakley_do_decrypt(): decrypted 
payload, but not trimed.
2002-04-03 11:09:58: DEBUG: plog.c:193:plogdump():
0b000018 12cd3fe7 2f9fda89 078b488f 94372d53 99e09ade 00000044 00000001
0304000e 0b7795e2 0a000034 00000001 00000001 00000000 00000000 00000000
00000000 00000000 00000000 00000000 c435d180 b6be0980 f8d5db80 00000000
2002-04-03 11:09:58: DEBUG: oakley.c:2675:oakley_do_decrypt(): padding len=0
2002-04-03 11:09:58: DEBUG: oakley.c:2689:oakley_do_decrypt(): skip to 
trim padding.
2002-04-03 11:09:58: DEBUG: oakley.c:2704:oakley_do_decrypt(): decrypted.
2002-04-03 11:09:58: DEBUG: plog.c:193:plogdump():
15015d2d 542d9348 78d1bcf0 42eb7a2e 08100501 dce0b8fe 0000007c 0b000018
12cd3fe7 2f9fda89 078b488f 94372d53 99e09ade 00000044 00000001 0304000e
0b7795e2 0a000034 00000001 00000001 00000000 00000000 00000000 00000000
00000000 00000000 00000000 c435d180 b6be0980 f8d5db80 00000000
2002-04-03 11:09:58: DEBUG: isakmp.c:2245:isakmp_printpacket(): begin.
09:58.223912 166.70.161.130:500 -> 208.186.182.111:500: isakmp 1.0 msgid 
dce0b8fe cookie 15015d2d542d9348->78d1bcf042eb7a2e: phase 2/others ? inf:
    (hash: len=20)
    (n: doi=ipsec proto=ipsec-esp type=NO-PROPOSAL-CHOSEN spi=0b7795e2 
orig=(
        (sa: doi=ipsec situation=identity
            (p: #0 protoid=#0 transform=0
                (t: #0 id=0 )))
        (nonce: n len=-4)))
2002-04-03 11:09:58: DEBUG: isakmp.c:1109:isakmp_parsewoh(): begin.
2002-04-03 11:09:58: DEBUG: isakmp.c:1136:isakmp_parsewoh(): seen 
nptype=8(hash)
2002-04-03 11:09:58: DEBUG: isakmp.c:1136:isakmp_parsewoh(): seen 
nptype=11(notify)
2002-04-03 11:09:58: DEBUG: isakmp.c:1175:isakmp_parsewoh(): succeed.
2002-04-03 11:09:58: ERROR: isakmp_inf.c:776:isakmp_info_recv_n(): 
unknown notify message, no phase2 handle found.
2002-04-03 11:09:58: DEBUG: isakmp_inf.c:798:isakmp_info_recv_n(): 
notification message 14:NO-PROPOSAL-CHOSEN, doi=1 proto_id=3 
spi=0b7795e2(size=4).
2002-04-03 11:10:13: ERROR: pfkey.c:738:pfkey_timeover(): 166.70.161.130 
give up to get IPsec-SA due to time up to wait.
2002-04-03 11:10:13: DEBUG: schedule.c:210:sched_scrub_param(): an 
undead schedule has been deleted.
#######################

Is the error in racoon startup a problem? If so, what am I missing or 
overlooking? Thanks in advance for any assistance?

Ryan :)


To Unsubscribe: send mail to majordomo@FreeBSD.org
with "unsubscribe freebsd-questions" in the body of the message




Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?3CAB47D3.2020302>