Test Information

TitleRe-keying of IPsec SA
CommandLine./ENODE/I_RFC2407_4_5.seq -pkt ./ENODE/I_RFC2407_4_5.def test_phase=2 test_type=BASIC -log 109.html -ti Re-keying of IPsec SA
TestVersionundefined
ToolVersionREL_3_0_8
Start2006/03/16 15:06:57
Tn/usr/local/v6eval//etc//tn.def
Nu/usr/local/v6eval//etc//nut.def
Pkt./ENODE/I_RFC2407_4_5.def
Systemfreebsd-i386
TargetNamefreebsd5.4
HostNameracoon
Typehost

Test Sequence Execution Log

15:06:57Start

*** Target IKE initialization phase ***
Target: Reset IKE SA entries: saddump
15:06:57 vRemote(ikeResetSA.rmt) ``/usr/local/v6eval//bin/freebsd-i386//ikeResetSA.rmt -t freebsd-i386 -u root -p v6eval -d ucom0 -o 1 saddump ''
Connected

dell# 
dell# /usr/local/sbin/setkey -c <<EOD
dump;
flush;
EOD

? dump;
? flush;
? EOD
No SAD entries.
dell# 
dell# sendMessagesSync: never got /usr/local/sbin/setkey -c <<EODdump;flush;EOD
echo $status
0
dell# kill -TERM `head -1 /var/run/racoon.pid`
head: /var/run/racoon.pid: No such file or directory

dell# 
echo $status
dell# echo $status
1
dell# /bin/rm -f /var/run/racoon.pid

dell# 
dell# echo $status
0
~
[EOT]

Target: Clear SPD entries: spddump
15:07:06 vRemote(ipsecResetSPD.rmt) ``/usr/local/v6eval//bin/freebsd-i386//ipsecResetSPD.rmt -t freebsd-i386 -u root -p v6eval -d ucom0 -o 1 spddump ''
Connected

dell# 
dell# /usr/local/sbin/setkey -c <<EOD
spddump;
spdflush;? spddump;

EOD

? spdflush;
EOD

? EOD
No SPD entries.
dell# 
dell# sendMessagesSync: never got /usr/local/sbin/setkey -c <<EODspddump;spdflush;EOD
echo $status
0~
[EOT]

Target: Set SPD entries: src=3ffe:501:ffff:100:290:99ff:fe7e:3e52 dst=3ffe:501:ffff:101::11 upperspec=any direction=out protocol=PROTO_IPSEC_ESP mode=Transport
15:07:13 vRemote(ipsecSetSPD.rmt) ``/usr/local/v6eval//bin/freebsd-i386//ipsecSetSPD.rmt -t freebsd-i386 -u root -p v6eval -d ucom0 -o 1 src=3ffe:501:ffff:100:290:99ff:fe7e:3e52 dst=3ffe:501:ffff:101::11 upperspec=any direction=out protocol=PROTO_IPSEC_ESP mode=Transport ''
Connected

dell# 
dell# /usr/local/sbin/setkey -c <<EOD
spdadd 3ffe:501:ffff:100:290:99ff:fe7e:3e52 3ffe:501:ffff:101::11
       any
       -P out ipsec
       esp/transport/3ffe:501:ffff:100:290:99ff:fe7e:3e52-3ffe:501:ffff:101::11/require
;
spddump;
EOD

? spdadd 3ffe:501:ffff:100:290:99ff:fe7e:3e52 3ffe:501:ffff:101::11
       any
       -P out ipsec
       esp/transport/3ffe:501:ffff:100:290:99ff:fe7e:3e52-3ffe:501:ffff:101::11/require
;
spddump;
EOD

?        any
?        -P out ipsec
?        esp/transport/3ffe:501:ffff:100:290:99ff:fe7e:3e52-3ffe:501:ffff:101::1 1/require
? ;
? spddump;
? EOD
3ffe:501:ffff:100:290:99ff:fe7e:3e52[any] 3ffe:501:ffff:101::11[any] any
        out ipsec
        esp/transport/3ffe:501:ffff:100:290:99ff:fe7e:3e52-3ffe:501:ffff:101::11/require
        created: Mar 16 06:14:28 2006  lastused: Mar 16 06:14:28 2006
        lifetime: 0(s) validtime: 0(s)
        spid=17765 seq=0 pid=1552
        refcnt=1
dell# 
dell# sendMessagesSync: never got /usr/local/sbin/setkey -c <<EODspdadd 3ffe:501:ffff:100:290:99ff:fe7e:3e52 3ffe:501:ffff:101::11       any       -P out ipsec       esp/transport/3ffe:501:ffff:100:290:99ff:fe7e:3e52-3ffe:501:ffff:101::11/require;spddump;EOD
echo $status
0~
[EOT]

Target: Set IKE SA entries: dst=3ffe:501:ffff:101::11 dst_port=500 exchange_mode=main doi=ipsec_doi situation=identity_only isakmp_src_id_type=address isakmp_src_id=3ffe:501:ffff:100:290:99ff:fe7e:3e52 dh_group=2 lifetime=28800 lifetime_unit=seconds encryption_algorithm=3des hash_algorithm=sha1 authentication_method=pre_shared_key key_id=3ffe:501:ffff:101::11 key_value=0x494b452d54455354 ph2_id_type=address ph2_src_id=3ffe:501:ffff:100:290:99ff:fe7e:3e52 ph2_dst_id=3ffe:501:ffff:101::11 ph2_src_upper=any ph2_dst_upper=any ipsec_p_num=1 ipsec_p1_t_num=1 ph2_p1_t1_lt=60 ph2_p1_t1_lt_unit=seconds ph2_p1_t1_enc_alg=ESP_3DES ph2_p1_t1_auth_mtd=HMAC_SHA
15:07:20 vRemote(ikeSetSA.rmt) ``/usr/local/v6eval//bin/freebsd-i386//ikeSetSA.rmt -t freebsd-i386 -u root -p v6eval -d ucom0 -o 1 dst=3ffe:501:ffff:101::11 dst_port=500 exchange_mode=main doi=ipsec_doi situation=identity_only isakmp_src_id_type=address isakmp_src_id=3ffe:501:ffff:100:290:99ff:fe7e:3e52 dh_group=2 lifetime=28800 lifetime_unit=seconds encryption_algorithm=3des hash_algorithm=sha1 authentication_method=pre_shared_key key_id=3ffe:501:ffff:101::11 key_value=0x494b452d54455354 ph2_id_type=address ph2_src_id=3ffe:501:ffff:100:290:99ff:fe7e:3e52 ph2_dst_id=3ffe:501:ffff:101::11 ph2_src_upper=any ph2_dst_upper=any ipsec_p_num=1 ipsec_p1_t_num=1 ph2_p1_t1_lt=60 ph2_p1_t1_lt_unit=seconds ph2_p1_t1_enc_alg=ESP_3DES ph2_p1_t1_auth_mtd=HMAC_SHA ''
Connected

dell# 
dell# ~[set] echocheck

dell# 
dell# ~[put] freebsd-i386.psk.txt /tmp/psk.txt
Ddell# 
dell# 
dell# /bin/chmod 600 /tmp/psk.txt
dell# echo $status
0
dell# ~[set] echocheck

dell# 
dell# ~[put] freebsd-i386.ike.conf /tmp/ike.conf
Ddell# 
dell# 
dell# test -f /var/run/racoon.pid &&kill -TERM `head -1 /var/run/racoon.pid`

dell# 
dell# echo $status
1
dell# /usr/local/sbin/racoon -f /tmp/ike.conf

dell# 
dell# echo $status
0~
[EOT]
15:07:34 vRemote(ikeEnable.rmt) ``/usr/local/v6eval//bin/freebsd-i386//ikeEnable.rmt -t freebsd-i386 -u root -p v6eval -d ucom0 -o 1 ''


*** Target initialization phase ***
15:07:34Start Capturing Packets (Link0)
15:07:34 vRecv(Link0,rs_from_nut rs_from_nut_wsll) timeout:15 cntLimit:0 seektime:0
vRecv() return status=1

*** Target pre-test seaquence ***
15:07:49Clear Captured Packets (Link0)

*** Phase-1 1st message recv ***
HOST1(NUT) send ICMP to HOST2(TN)
15:07:49 vRemoteAsync(ping6.rmt) ``/usr/local/v6eval//bin/freebsd-i386//ping6.rmt -t freebsd-i386 -u root -p v6eval -d ucom0 -o 1 count=12 interval=6 if=rl0 addr=3ffe:501:ffff:101::11''

Link to remote control log
15:07:49 vRecv(Link0,isakmp_phase1_recv ns_uni rs_from_nut rs_from_nut_wsll ns_uni_tll_sll ns_uni_sll ns_multi_llt ns_multi) timeout:10 cntLimit:0 seektime:0
Receive Neighbor Solicitation from HOST-1(NUT)
15:07:53 vSend(Link0,na_llt)
Send Neighbor Advertisement(TN)
15:07:53 vRecv(Link0,isakmp_phase1_recv ns_uni rs_from_nut rs_from_nut_wsll ns_uni_tll_sll ns_uni_sll ns_multi_llt ns_multi) timeout:10 cntLimit:0 seektime:0
Recv 1st message from HOST1(NUT)

OK payload_check
*** Phase-1 2nd message send ***
15:07:53Clear Captured Packets (Link0)
15:07:53 vSend(Link0,isakmp_phase1_send_2nd)
Send 2nd message from HOST2(TN)

*** Phase-1 3rd message recv ***
15:07:53 vRecv(Link0,isakmp_phase1_recv_3rd ns_uni rs_from_nut rs_from_nut_wsll ns_uni_tll_sll ns_uni_sll ns_multi_llt ns_multi) timeout:5 cntLimit:0 seektime:0
Recv 3rd message from HOST1(NUT)

OK payload_check
*** Phase-1 4th message send ***
15:07:53Clear Captured Packets (Link0)
15:07:53 vSend(Link0,isakmp_phase1_send_4th)
Send 4th message from HOST2(TN)

*** Phase-1 5th message recv ***
15:07:54 vRecv(Link0,isakmp_phase1_recv_5th ns_uni rs_from_nut rs_from_nut_wsll ns_uni_tll_sll ns_uni_sll ns_multi_llt ns_multi) timeout:5 cntLimit:0 seektime:0
Recv 5th message from HOST1(NUT)

OK payload_check
*** Phase-1 6th message send ***
15:07:54Clear Captured Packets (Link0)
15:07:54 vSend(Link0,isakmp_phase1_send_6th)
Send 6th message from HOST2(TN)

*** Target testing phase start ***
*** Phase-2 1st message recv ***
15:07:54 vRecv(Link0,isakmp_phase2_recv ns_uni rs_from_nut rs_from_nut_wsll ns_uni_tll_sll ns_uni_sll ns_multi_llt ns_multi) timeout:5 cntLimit:0 seektime:0
recv unexpect packet at 15:07:54
Recv Phase-2 1st message (HDR*, HASH(1), SA, Ni, *, *) from HOST1(NUT)

OK payload_check
*** Phase-2 2nd message send ***
15:07:55Clear Captured Packets (Link0)
15:07:55 vSend(Link0,isakmp_phase2_send_2nd)
Send Phase-2 2nd message (HDR*, HASH(2), SA, Nr) from HOST2(TN)

*** Phase-2 3rd message recv ***
15:07:55 vRecv(Link0,isakmp_phase2_recv_3rd ns_uni rs_from_nut rs_from_nut_wsll ns_uni_tll_sll ns_uni_sll ns_multi_llt ns_multi) timeout:5 cntLimit:0 seektime:0
Recv Phase-2 3rd message HDR*, HASH(3) from HOST1(NUT)

OK payload_check
*** IPsec SA is esatblished ***
*** The first IPsec transmission ***
## 1st SA elapsed time: 0 ##
15:07:55 vRecv(Link0,echo_request_recv_esp_trans_net0host1_net1host2 ns_uni rs_from_nut rs_from_nut_wsll ns_uni_tll_sll ns_uni_sll ns_multi_llt ns_multi) timeout:6 cntLimit:0 seektime:0
Receive Encrypted Echo Request from HOST-1(NUT)

*** Encrypted Echo Reply message recv 1 ***
*** Re-key testing phase start ***
## 1st SA elapsed time: 4 ##
15:07:59 vRecv(Link0,echo_request_recv_esp_trans_net0host1_net1host2 isakmp_phase2_recv ns_uni rs_from_nut rs_from_nut_wsll ns_uni_tll_sll ns_uni_sll ns_multi_llt ns_multi) timeout:6 cntLimit:1 seektime:0
Receive Encrypted Echo Request from HOST-1(NUT)

*** Encrypted Echo Reply message recv 2 ***
## 1st SA elapsed time: 10 ##
15:08:05 vRecv(Link0,echo_request_recv_esp_trans_net0host1_net1host2 isakmp_phase2_recv ns_uni rs_from_nut rs_from_nut_wsll ns_uni_tll_sll ns_uni_sll ns_multi_llt ns_multi) timeout:6 cntLimit:1 seektime:0
Receive Encrypted Echo Request from HOST-1(NUT)

*** Encrypted Echo Reply message recv 3 ***
## 1st SA elapsed time: 16 ##
15:08:11 vRecv(Link0,echo_request_recv_esp_trans_net0host1_net1host2 isakmp_phase2_recv ns_uni rs_from_nut rs_from_nut_wsll ns_uni_tll_sll ns_uni_sll ns_multi_llt ns_multi) timeout:6 cntLimit:1 seektime:0
Receive Encrypted Echo Request from HOST-1(NUT)

*** Encrypted Echo Reply message recv 4 ***
## 1st SA elapsed time: 22 ##
15:08:17 vRecv(Link0,echo_request_recv_esp_trans_net0host1_net1host2 isakmp_phase2_recv ns_uni rs_from_nut rs_from_nut_wsll ns_uni_tll_sll ns_uni_sll ns_multi_llt ns_multi) timeout:6 cntLimit:1 seektime:0
Receive Encrypted Echo Request from HOST-1(NUT)

*** Encrypted Echo Reply message recv 5 ***
## 1st SA elapsed time: 28 ##
15:08:23 vRecv(Link0,echo_request_recv_esp_trans_net0host1_net1host2 isakmp_phase2_recv ns_uni rs_from_nut rs_from_nut_wsll ns_uni_tll_sll ns_uni_sll ns_multi_llt ns_multi) timeout:6 cntLimit:1 seektime:0
Receive Neighbor Solicitation from HOST-1(NUT)
15:08:28 vSend(Link0,na_ll_llt)
Send Neighbor Advertisement(TN)
15:08:28 vRecv(Link0,echo_request_recv_esp_trans_net0host1_net1host2 isakmp_phase2_recv ns_uni rs_from_nut rs_from_nut_wsll ns_uni_tll_sll ns_uni_sll ns_multi_llt ns_multi) timeout:6 cntLimit:1 seektime:0
Receive Encrypted Echo Request from HOST-1(NUT)

*** Encrypted Echo Reply message recv 6 ***
## 1st SA elapsed time: 34 ##
15:08:29 vRecv(Link0,echo_request_recv_esp_trans_net0host1_net1host2 isakmp_phase2_recv ns_uni rs_from_nut rs_from_nut_wsll ns_uni_tll_sll ns_uni_sll ns_multi_llt ns_multi) timeout:6 cntLimit:1 seektime:0
Receive Encrypted Echo Request from HOST-1(NUT)

*** Encrypted Echo Reply message recv 7 ***
## 1st SA elapsed time: 40 ##
15:08:35 vRecv(Link0,echo_request_recv_esp_trans_net0host1_net1host2 isakmp_phase2_recv ns_uni rs_from_nut rs_from_nut_wsll ns_uni_tll_sll ns_uni_sll ns_multi_llt ns_multi) timeout:6 cntLimit:1 seektime:0
Receive Encrypted Echo Request from HOST-1(NUT)

*** Encrypted Echo Reply message recv 8 ***
## 1st SA elapsed time: 46 ##
15:08:41 vRecv(Link0,echo_request_recv_esp_trans_net0host1_net1host2 isakmp_phase2_recv ns_uni rs_from_nut rs_from_nut_wsll ns_uni_tll_sll ns_uni_sll ns_multi_llt ns_multi) timeout:6 cntLimit:1 seektime:0
!!! ISAKMP PayloadLength decode(15472) over remain size(88)
Recv Phase-2 1st message (HDR*, HASH(1), SA, Ni, *, *) from HOST1(NUT)

OK payload_check
*** Re-Key 1st message recv ***
*** Re-Key 2nd message send ***
15:08:44Clear Captured Packets (Link0)
15:08:44 vSend(Link0,isakmp_phase2_send_2nd)
Send Phase-2 2nd message (HDR*, HASH(2), SA, Nr) from HOST2(TN)

*** Re-Key 3rd message recv ***
15:08:44 vRecv(Link0,isakmp_phase2_recv_3rd ns_uni rs_from_nut rs_from_nut_wsll ns_uni_tll_sll ns_uni_sll ns_multi_llt ns_multi) timeout:5 cntLimit:0 seektime:0
Recv Phase-2 3rd message HDR*, HASH(3) from HOST1(NUT)

OK payload_check
*** 2nd IPsec SA is esatblished ***
*** Encrypted Echo Request message recv using 2nd IPsec SA ***
15:08:44 vRecv(Link0,echo_request_recv_esp_trans_net0host1_net1host2_2 echo_request_recv_esp_trans_net0host1_net1host2 ns_uni rs_from_nut rs_from_nut_wsll ns_uni_tll_sll ns_uni_sll ns_multi_llt ns_multi) timeout:6 cntLimit:1 seektime:0
!!! ESP Padding size(15) over remain size(14)
Receive Encrypted Echo Request from HOST-1(NUT)

## 1st SA elapsed time: 52 ##
## 2nd SA elapsed time: 3 ##
Re-keying of IPsec SA is correct
*** Target test finish ***
15:08:47Stop Capturing Packets (Link0)
15:08:47 vRemoteAsyncWait()

Link to remote control start point
sleep 3 [sec] for escaping critical point of asynchronous remoteconf.

Connected

dell# 
dell# /sbin/ping6 -n -c 12 -i 6 -h 64 -s 2 -p 00 -I rl0 3ffe:501:ffff:101::11
PATTERN: 0x00
PING6(50=40+8+2 bytes) 3ffe:501:ffff:100:290:99ff:fe7e:3e52 --> 3ffe:501:ffff:101::11

~
[EOT]

Target: Reset IKE SA entries: saddump
15:08:47 vRemote(ikeResetSA.rmt) ``/usr/local/v6eval//bin/freebsd-i386//ikeResetSA.rmt -t freebsd-i386 -u root -p v6eval -d ucom0 -o 1 saddump ''
Connected




--- 3ffe:501:ffff:101::11 ping6 statistics ---
12 packets transmitted, 0 packets received, 100.0% packet loss

dell# 
dell# 
dell# 
dell# 
dell# 
/usr/local/sbin/setkey -c <<EOD
dump;
flush;
EOD

dell# /usr/local/sbin/setkey -c <<EOD
dump;
flush;
EOD

? dump;
? flush;
? EOD
3ffe:501:ffff:100:290:99ff:fe7e:3e52 3ffe:501:ffff:101::11 
        esp mode=transport spi=4097(0x00001001) reqid=0(0x00000000)
        E: 3des-cbc  7539c939 eeed9e16 119fc414 967c83ef 2df52db1 afc5978c
        A: hmac-sha1  b4f72d36 ee1d598b 7c4cda11 6a176851 41bbc02b
        seq=0x00000001 replay=4 flags=0x00000000 state=mature 
        created: Mar 16 06:15:59 2006   current: Mar 16 06:16:30 2006
        diff: 31(s)     hard: 60(s)     soft: 48(s)
        last: Mar 16 06:16:13 2006      hard: 0(s)      soft: 0(s)
        current: 84(bytes)      hard: 0(bytes)  soft: 0(bytes)
        allocated: 1    hard: 0 soft: 0
        sadb_seq=1 pid=1563 refcnt=2
3ffe:501:ffff:101::11 3ffe:501:ffff:100:290:99ff:fe7e:3e52 
        esp mode=transport spi=256683866(0x0f4caf5a) reqid=0(0x00000000)
        E: 3des-cbc  dc3ed32d eaa8eaa0 799d46db c5d0b6ff 1dbf16d5 03cb075f
        A: hmac-sha1  d7be8d06 75a6251e 005b62fc 7ddda4bd 5f894011
        seq=0x00000000 replay=4 flags=0x00000000 state=mature 
        created: Mar 16 06:15:59 2006   current: Mar 16 06:16:30 2006
        diff: 31(s)     hard: 60(s)     soft: 48(s)
        last:                           hard: 0(s)      soft: 0(s)
        current: 0(bytes)       hard: 0(bytes)  soft: 0(bytes)
        allocated: 0    hard: 0 soft: 0
        sadb_seq=0 pid=1563 refcnt=1
dell# 
dell# sendMessagesSync: never got /usr/local/sbin/setkey -c <<EODdump;flush;EOD
echo $status
0
dell# kill -TERM `head -1 /var/run/racoon.pid`

dell# 
echo $status
dell# echo $status
0
dell# /bin/rm -f /var/run/racoon.pid

dell# 
echo $status
dell# echo $status
0~
[EOT]

Target: Clear SPD entries: spddump
15:09:22 vRemote(ipsecResetSPD.rmt) ``/usr/local/v6eval//bin/freebsd-i386//ipsecResetSPD.rmt -t freebsd-i386 -u root -p v6eval -d ucom0 -o 1 spddump ''
Connected

dell# 
dell# /usr/local/sbin/setkey -c <<EOD
spddump;
spdflush;
EOD? spddump;
? spdflush;


? EOD
3ffe:501:ffff:100:290:99ff:fe7e:3e52[any] 3ffe:501:ffff:101::11[any] any
        out ipsec
        esp/transport/3ffe:501:ffff:100:290:99ff:fe7e:3e52-3ffe:501:ffff:101::11/require
        created: Mar 16 06:14:28 2006  lastused: Mar 16 06:16:13 2006
        lifetime: 0(s) validtime: 0(s)
        spid=17765 seq=0 pid=1566
        refcnt=1

dell# 
dell# sendMessagesSync: never got /usr/local/sbin/setkey -c <<EODspddump;spdflush;EOD
echo $status
0~
[EOT]

OK
15:09:30End

Packet Reverse Log