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 110.html -ti Re-keying of IPsec SA
TestVersionundefined
ToolVersionREL_3_0_8
Start2006/03/17 23:44:24
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

23:44:24Start

*** Target IKE initialization phase ***
Target: Reset IKE SA entries: saddump
23:44:24 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
dell# echo $status
1
dell# /bin/rm -f /var/run/racoon.pid

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

Target: Clear SPD entries: spddump
23:44:33 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
23:44:40 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 17 14:51:58 2006  lastused: Mar 17 14:51:58 2006
        lifetime: 0(s) validtime: 0(s)
        spid=17681 seq=0 pid=1544
        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
23:44:47 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# 
echo $status
dell# echo $status
1
dell# /usr/local/sbin/racoon -f /tmp/ike.conf

dell# 
echo $status
dell# echo $status
0~
[EOT]
23:45:01 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 ***
23:45:01Start Capturing Packets (Link0)
23:45:01 vRecv(Link0,rs_from_nut rs_from_nut_wsll) timeout:15 cntLimit:0 seektime:0
vRecv() return status=1

*** Target pre-test seaquence ***
23:45:16Clear Captured Packets (Link0)

*** Phase-1 1st message recv ***
HOST1(NUT) send ICMP to HOST2(TN)
23:45:16 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
23:45:16 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)
23:45:20 vSend(Link0,na_llt)
Send Neighbor Advertisement(TN)
23:45:20 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 ***
23:45:20Clear Captured Packets (Link0)
23:45:20 vSend(Link0,isakmp_phase1_send_2nd)
Send 2nd message from HOST2(TN)

*** Phase-1 3rd message recv ***
23:45:21 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 ***
23:45:21Clear Captured Packets (Link0)
23:45:21 vSend(Link0,isakmp_phase1_send_4th)
Send 4th message from HOST2(TN)

*** Phase-1 5th message recv ***
23:45:21 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 ***
23:45:21Clear Captured Packets (Link0)
23:45:21 vSend(Link0,isakmp_phase1_send_6th)
Send 6th message from HOST2(TN)

*** Target testing phase start ***
*** Phase-2 1st message recv ***
23:45:21 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 23:45:21
Recv Phase-2 1st message (HDR*, HASH(1), SA, Ni, *, *) from HOST1(NUT)

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

*** Phase-2 3rd message recv ***
23:45:22 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 ##
23:45:22 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 ##
23:45:26 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 ##
23:45:32 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 ##
23:45:38 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 ##
23:45:44 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 ##
23:45:50 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 ##
23:45:56 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 ##
23:46:02 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 ##
23:46:08 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(21590) 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 ***
23:46:11Clear Captured Packets (Link0)
23:46:11 vSend(Link0,isakmp_phase2_send_2nd)
Send Phase-2 2nd message (HDR*, HASH(2), SA, Nr) from HOST2(TN)

*** Re-Key 3rd message recv ***
23:46:12 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 ***
23:46:12 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
Receive Neighbor Solicitation from HOST-1(NUT)
23:46:13 vSend(Link0,na_ll_llt)
Send Neighbor Advertisement(TN)
23:46:13 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(133) over remain size(14)
Receive Encrypted Echo Request from HOST-1(NUT)

## 1st SA elapsed time: 52 ##
## 2nd SA elapsed time: 2 ##
Re-keying of IPsec SA is correct
*** Target test finish ***
23:46:14Stop Capturing Packets (Link0)
23:46:14 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
23:46:14 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  c638bcd2 0a195faa a087a65c ef9804dd 4a118e89 7cd31a8f
        A: hmac-sha1  04971a9a 131c8fb6 734af8bb 1867670e 8d37a7f1
        seq=0x00000001 replay=4 flags=0x00000000 state=mature 
        created: Mar 17 14:53:29 2006   current: Mar 17 14:53:59 2006
        diff: 30(s)     hard: 60(s)     soft: 48(s)
        last: Mar 17 14:53:43 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=1552 refcnt=2
3ffe:501:ffff:101::11 3ffe:501:ffff:100:290:99ff:fe7e:3e52 
        esp mode=transport spi=219555231(0x0d16259f) reqid=0(0x00000000)
        E: 3des-cbc  cfb2c55d 3f34b147 aed084da 09516696 f3bd894e 7e68b16e
        A: hmac-sha1  045a28b8 3bf69573 2e83cea8 ac2af178 6efca0fa
        seq=0x00000000 replay=4 flags=0x00000000 state=mature 
        created: Mar 17 14:53:29 2006   current: Mar 17 14:53:59 2006
        diff: 30(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=1552 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
23:46:49 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;
? spdflush;
EOD

? 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 17 14:51:58 2006  lastused: Mar 17 14:53:43 2006
        lifetime: 0(s) validtime: 0(s)
        spid=17681 seq=0 pid=1555
        refcnt=1

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

OK
23:46:57End

Packet Reverse Log