[Openswan Users] openSWAN to Cisco IOS

Glenn Henshaw thraxisp at logicaloutcome.ca
Tue Aug 22 11:53:54 EDT 2006


   Having resolved some of the protocol incompatibilities, I can now  
get the connection to progress past the key exchange. It stops before  
bringing up the tunnel declaring "NO_PROPOSAL_CHOSEN". The Cisco end  
thinks that the tunnel is up until the keep-alive expires.

   What can cause the "NO_PROPOSAL_CHOSEN" message from the Cisco?


    ... Glenn


openSWAN config:
version 2.0
config setup
         interfaces=%defaultroute
         klipsdebug="none"
         plutodebug="control"
         nat_traversal=yes

conn host
         # host specific configuration
         esp=3des-sha1-1024
         ike=3des-sha1-1024
         pfs=no
         keyexchange=ike
         # basic configuration
         type=tunnel
         left=%defaultroute
         leftnexthop=%defaultroute
         leftid=@xxxxxxxxx
         right=xxx.xxx.xxx.xxx
         rightsubnet=10.0.0.0/8
         authby=secret
         auto=start

#disable opportunistic encryption
include /etc/config/ipsec.d/examples/no_oe.conf

Cisco Config: (abbreviated)
crypto isakmp policy 10
encr 3des
authentication pre-share
group 2
crypto isakmp nat keepalive 30
crypto isakmp client configuration address-pool local xxxxxxxxxxxx
!
crypto isakmp profile L2L
    keyring QP_Spokes
    match identity address 0.0.0.0
!
crypto ipsec transform-set QP_Set esp-3des esp-sha-hmac
!
crypto dynamic-map xxxxxxxxxxx 40
set transform-set QP_Set
set isakmp-profile L2L
!



openSWAN startup:
# ipsec auto --up host
104 "host" #3: STATE_MAIN_I1: initiate
003 "host" #3: received Vendor ID payload [draft-ietf-ipsec-nat-t- 
ike-03] method set to=108
106 "host" #3: STATE_MAIN_I2: sent MI2, expecting MR2
003 "host" #3: received Vendor ID payload [Cisco-Unity]
003 "host" #3: received Vendor ID payload [Dead Peer Detection]
003 "host" #3: ignoring unknown Vendor ID payload  
[0c447920daaa628dce64a39fb745f11d]
003 "host" #3: received Vendor ID payload [XAUTH]
003 "host" #3: NAT-Traversal: Result using draft-ietf-ipsec-nat-t- 
ike-02/03: i am NATed
108 "host" #3: STATE_MAIN_I3: sent MI3, expecting MR3
004 "host" #3: STATE_MAIN_I4: ISAKMP SA established  
{auth=OAKLEY_PRESHARED_KEY cipher=oakley_3des_cbc_192 prf=oakley_sha  
group=modp1024}
117 "host" #4: STATE_QUICK_I1: initiate
010 "host" #4: STATE_QUICK_I1: retransmission; will wait 20s for  
response
010 "host" #4: STATE_QUICK_I1: retransmission; will wait 40s for  
response
031 "host" #4: max number of retransmissions (2) reached  
STATE_QUICK_I1.  No acceptable response to our first Quick Mode  
message: perhaps peer likes no proposal000 "host" #4: starting keying  
attempt 2 of an unlimited number, but releasing whack


local logs:
<83>Aug 21 16:53:18.406 2006 ipsec__plutorun: Starting Pluto  
subsystem...
<84>Aug 21 16:53:18.597 2006 pluto[5458]: Starting Pluto (Openswan  
Version 2.4.5rc6 X.509-1.5.4 PLUTO_SENDS_VENDORID PLUTO_USES_KEYRR;  
Vendor ID OESTg[~pX at __)
<84>Aug 21 16:53:18.599 2006 pluto[5458]: Setting NAT-Traversal  
port-4500 floating to on
<84>Aug 21 16:53:18.600 2006 pluto[5458]:    port floating activation  
criteria nat_t=1/port_fload=1
<84>Aug 21 16:53:18.602 2006 pluto[5458]:   including NAT-Traversal  
patch (Version 0.6c)
<87>Aug 21 16:53:18.603 2006 pluto[5458]: | opening /dev/urandom
<87>Aug 21 16:53:18.613 2006 pluto[5458]: | inserting event  
EVENT_REINIT_SECRET, timeout in 3600 seconds
<87>Aug 21 16:53:18.633 2006 pluto[5458]: | inserting event  
EVENT_PENDING_PHASE2, timeout in 120 seconds
<84>Aug 21 16:53:18.639 2006 pluto[5458]: ike_alg_register_enc():  
Activating OAKLEY_AES_CBC: Ok (ret=0)
<84>Aug 21 16:53:18.641 2006 pluto[5458]: starting up 1 cryptographic  
helpers
<87>Aug 21 16:53:18.655 2006 pluto[5461]: | opening /dev/urandom
<84>Aug 21 16:53:18.657 2006 pluto[5458]: started helper pid=5461 (fd:5)
<84>Aug 21 16:53:18.660 2006 pluto[5458]: Using KLIPS IPsec interface  
code on 2.4.27-uc1
<87>Aug 21 16:53:18.664 2006 pluto[5458]: | inserting event  
EVENT_SHUNT_SCAN, timeout in 120 seconds
<87>Aug 21 16:53:18.673 2006 pluto[5461]: ! helper 0 waiting on fd: 7
<84>Aug 21 16:53:18.701 2006 pluto[5458]: Changing to directory '/etc/ 
config/ipsec.d/cacerts'
<84>Aug 21 16:53:18.749 2006 pluto[5458]: Changing to directory '/etc/ 
config/ipsec.d/aacerts'
<84>Aug 21 16:53:18.751 2006 pluto[5458]: Changing to directory '/etc/ 
config/ipsec.d/ocspcerts'
<84>Aug 21 16:53:18.753 2006 pluto[5458]: Changing to directory '/etc/ 
config/ipsec.d/crls'
<84>Aug 21 16:53:18.755 2006 pluto[5458]:   Warning: empty directory
<87>Aug 21 16:53:18.757 2006 pluto[5458]: | inserting event  
EVENT_LOG_DAILY, timeout in 25602 seconds
<87>Aug 21 16:53:18.758 2006 pluto[5458]: | next event  
EVENT_SHUNT_SCAN in 120 seconds
<87>Aug 21 16:53:20.571 2006 pluto[5458]: |
<87>Aug 21 16:53:20.572 2006 pluto[5458]: | *received whack message
<87>Aug 21 16:53:20.572 2006 pluto[5458]: | Added new connection host  
with policy PSK+ENCRYPT+TUNNEL
<87>Aug 21 16:53:20.573 2006 pluto[5458]: | from whack: got -- 
esp=3des-sha1
<87>Aug 21 16:53:20.574 2006 pluto[5458]: | esp string values:  
3_000-2, flags=strict
<87>Aug 21 16:53:20.574 2006 pluto[5458]: | from whack: got --ike=3des
<87>Aug 21 16:53:20.575 2006 pluto[5458]: | ike string values:  
5_000-1-5, 5_000-2-5, 5_000-1-2, 5_000-2-2, flags=strict
<87>Aug 21 16:53:20.576 2006 pluto[5458]: | counting wild cards for  
@xxxxxxx is 0
<87>Aug 21 16:53:20.576 2006 pluto[5458]: | counting wild cards for  
(none) is 15
<87>Aug 21 16:53:20.577 2006 pluto[5458]: | alg_info_addref()  
alg_info->ref_cnt=1
<87>Aug 21 16:53:20.583 2006 pluto[5458]: | alg_info_addref()  
alg_info->ref_cnt=2
<84>Aug 21 16:53:20.584 2006 pluto[5458]: added connection  
description "host"
<87>Aug 21 16:53:20.585 2006 pluto[5458]: | 192.168.1.234 
[@Pxxxxxxx]---192.168.1.2...xxx.xxx.xxx.xxx===10.0.0.0/8
<87>Aug 21 16:53:20.586 2006 pluto[5458]: | ike_life: 3600s;  
ipsec_life: 28800s; rekey_margin: 540s; rekey_fuzz: 100%;  
keyingtries: 0; policy: PSK+ENCRYPT+TUNNEL
<87>Aug 21 16:53:20.586 2006 pluto[5458]: | next event  
EVENT_SHUNT_SCAN in 118 seconds
<87>Aug 21 16:53:20.807 2006 pluto[5458]: |
<87>Aug 21 16:53:20.808 2006 pluto[5458]: | *received whack message
<84>Aug 21 16:53:20.817 2006 pluto[5458]: listening for IKE messages
<87>Aug 21 16:53:20.818 2006 pluto[5458]: | found lo with address  
127.0.0.1
<87>Aug 21 16:53:20.819 2006 pluto[5458]: | found ipsec0 with address  
192.168.1.234
<87>Aug 21 16:53:20.819 2006 pluto[5458]: | found eth0 with address  
192.168.4.1
<87>Aug 21 16:53:20.820 2006 pluto[5458]: | found eth1 with address  
192.168.1.234
<84>Aug 21 16:53:20.821 2006 pluto[5458]: adding interface ipsec0/ 
eth1 192.168.1.234:500
<84>Aug 21 16:53:20.821 2006 pluto[5458]: adding interface ipsec0/ 
eth1 192.168.1.234:4500
<87>Aug 21 16:53:20.822 2006 pluto[5458]: | IP interface eth0  
192.168.4.1 has no matching ipsec* interface -- ignored
<87>Aug 21 16:53:20.823 2006 pluto[5458]: | IP interface lo 127.0.0.1  
has no matching ipsec* interface -- ignored
<87>Aug 21 16:53:20.823 2006 pluto[5458]: | could not open /proc/net/ 
if_inet6
<84>Aug 21 16:53:20.824 2006 pluto[5458]: loading secrets from "/etc/ 
config/ipsec.secrets"
<87>Aug 21 16:53:20.825 2006 pluto[5458]: | next event  
EVENT_SHUNT_SCAN in 118 seconds
<87>Aug 21 16:53:21.058 2006 pluto[5458]: |
<87>Aug 21 16:53:21.059 2006 pluto[5458]: | *received whack message
<87>Aug 21 16:53:21.068 2006 pluto[5458]: | processing connection host
<87>Aug 21 16:53:21.069 2006 pluto[5458]: | route owner of "host"  
unrouted: NULL; eroute owner: NULL
<87>Aug 21 16:53:21.070 2006 pluto[5458]: | could_route called for  
host (kind=CK_PERMANENT)
<87>Aug 21 16:53:21.070 2006 pluto[5458]: | route owner of "host"  
unrouted: NULL; eroute owner: NULL
<87>Aug 21 16:53:21.071 2006 pluto[5458]: | eroute_connection add  
eroute 192.168.1.234/32:0 --0-> 10.0.0.0/8:0 => %trap (raw_eroute)
<87>Aug 21 16:53:21.072 2006 pluto[5458]: | route_and_eroute:  
firewall_notified: true
<87>Aug 21 16:53:21.072 2006 pluto[5458]: | command executing prepare- 
host
<87>Aug 21 16:53:21.073 2006 pluto[5458]: | executing prepare-host:  
2>&1 PLUTO_VERSION='1.1' PLUTO_VERB='prepare-host'  
PLUTO_CONNECTION='host' PLUTO_NEXT_HOP='192.168.1.2'  
PLUTO_INTERFACE='ipsec0' PLUTO_ME='192.168.1.234'  
PLUTO_MY_ID='@xxxxxxx' PLUTO_MY_CLIENT='192.168.1.234/32'  
PLUTO_MY_CLIENT_NET='192.168.1.234'  
PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='0'  
PLUTO_MY_PROTOCOL='0' PLUTO_PEER='xxx.xxx.xxx.xxx'  
PLUTO_PEER_ID='xxx.xxx.xxx.xxx' PLUTO_PEER_CLIENT='10.0.0.0/8'  
PLUTO_PEER_CLIENT_NET='10.0.0.0' PLUTO_PEER_CLIENT_MASK='255.0.0.0'  
PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA=''  
PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL'   ipsec _updown
<87>Aug 21 16:53:21.229 2006 pluto[5458]: | command executing route-host
<87>Aug 21 16:53:21.230 2006 pluto[5458]: | executing route-host:  
2>&1 PLUTO_VERSION='1.1' PLUTO_VERB='route-host'  
PLUTO_CONNECTION='host' PLUTO_NEXT_HOP='192.168.1.2'  
PLUTO_INTERFACE='ipsec0' PLUTO_ME='192.168.1.234'  
PLUTO_MY_ID='@xxxxxxx' PLUTO_MY_CLIENT='192.168.1.234/32'  
PLUTO_MY_CLIENT_NET='192.168.1.234'  
PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='0'  
PLUTO_MY_PROTOCOL='0' PLUTO_PEER='xxx.xxx.xxx.xxx'  
PLUTO_PEER_ID='xxx.xxx.xxx.xxx' PLUTO_PEER_CLIENT='10.0.0.0/8'  
PLUTO_PEER_CLIENT_NET='10.0.0.0' PLUTO_PEER_CLIENT_MASK='255.0.0.0'  
PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA=''  
PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL'   ipsec _updown
<87>Aug 21 16:53:21.433 2006 pluto[5458]: | next event  
EVENT_SHUNT_SCAN in 117 seconds
<87>Aug 21 16:53:21.664 2006 pluto[5458]: |
<87>Aug 21 16:53:21.665 2006 pluto[5458]: | *received whack message
<87>Aug 21 16:53:21.673 2006 pluto[5458]: | processing connection host
<87>Aug 21 16:53:21.673 2006 pluto[5458]: | kernel_alg_db_new() will  
return p_new->protoid=3, p_new->trans_cnt=1
<87>Aug 21 16:53:21.674 2006 pluto[5458]: | kernel_alg_db_new() trans 
[0]: transid=3, attr_cnt=1, attrs[0].type=5, attrs[0].val=2
<87>Aug 21 16:53:21.675 2006 pluto[5458]: | returning new proposal  
from esp_info
<87>Aug 21 16:53:21.676 2006 pluto[5458]: | creating state object #1  
at 0xc19c8
<87>Aug 21 16:53:21.676 2006 pluto[5458]: | processing connection host
<87>Aug 21 16:53:21.677 2006 pluto[5458]: | ICOOKIE:  ea 05 fa e0  30  
4b 19 01
<87>Aug 21 16:53:21.678 2006 pluto[5458]: | RCOOKIE:  00 00 00 00  00  
00 00 00
<87>Aug 21 16:53:21.678 2006 pluto[5458]: | peer:  d0 fa 32 c1
<87>Aug 21 16:53:21.679 2006 pluto[5458]: | state hash entry 17
<87>Aug 21 16:53:21.680 2006 pluto[5458]: | inserting event  
EVENT_SO_DISCARD, timeout in 0 seconds for #1
<87>Aug 21 16:53:21.685 2006 pluto[5458]: | Queuing pending Quick  
Mode with 208.250.50.193 "host"
<84>Aug 21 16:53:21.686 2006 pluto[5458]: "host" #1: initiating Main  
Mode
<87>Aug 21 16:53:21.687 2006 pluto[5458]: | sending 312 bytes for  
main_outI1 through eth1:500 to 208.250.50.193:500:
<87>Aug 21 16:53:21.687 2006 pluto[5458]: | inserting event  
EVENT_RETRANSMIT, timeout in 10 seconds for #1
<87>Aug 21 16:53:21.688 2006 pluto[5458]: | next event  
EVENT_RETRANSMIT in 10 seconds for #1
<27>Aug 21 16:53:21.691 2006 ipsec__plutorun: 104 "host" #1:  
STATE_MAIN_I1: initiate
<27>Aug 21 16:53:21.718 2006 ipsec__plutorun: ...could not start conn  
"host"
<87>Aug 21 16:53:21.767 2006 pluto[5458]: |
<87>Aug 21 16:53:21.768 2006 pluto[5458]: | *received 100 bytes from  
208.250.50.193:500 on eth1 (port=500)
<87>Aug 21 16:53:21.769 2006 pluto[5458]: |  processing packet with  
exchange type=ISAKMP_XCHG_IDPROT (2)
<87>Aug 21 16:53:21.769 2006 pluto[5458]: | ICOOKIE:  ea 05 fa e0  30  
4b 19 01
<87>Aug 21 16:53:21.770 2006 pluto[5458]: | RCOOKIE:  f9 83 de 3d  12  
9a 6e e3
<87>Aug 21 16:53:21.771 2006 pluto[5458]: | peer:  d0 fa 32 c1
<87>Aug 21 16:53:21.772 2006 pluto[5458]: | state hash entry 31
<87>Aug 21 16:53:21.772 2006 pluto[5458]: | state object not found
<87>Aug 21 16:53:21.773 2006 pluto[5458]: | ICOOKIE:  ea 05 fa e0  30  
4b 19 01
<87>Aug 21 16:53:21.774 2006 pluto[5458]: | RCOOKIE:  00 00 00 00  00  
00 00 00
<87>Aug 21 16:53:21.774 2006 pluto[5458]: | peer:  d0 fa 32 c1
<87>Aug 21 16:53:21.780 2006 pluto[5458]: | state hash entry 17
<87>Aug 21 16:53:21.781 2006 pluto[5458]: | peer and cookies match on  
#1, provided msgid 00000000 vs 00000000
<87>Aug 21 16:53:21.782 2006 pluto[5458]: | state object #1 found, in  
STATE_MAIN_I1
<87>Aug 21 16:53:21.782 2006 pluto[5458]: | processing connection host
<84>Aug 21 16:53:21.783 2006 pluto[5458]: "host" #1: received Vendor  
ID payload [draft-ietf-ipsec-nat-t-ike-03] method set to=108
<87>Aug 21 16:53:21.784 2006 pluto[5458]: | started looking for  
secret for @xxxxxx->xxx.xxx.xxx.xxx of kind PPK_PSK
<87>Aug 21 16:53:21.784 2006 pluto[5458]: | actually looking for  
secret for @xxxxxxx->xxx.xxx.xxx.xxx of kind PPK_PSK
<87>Aug 21 16:53:21.785 2006 pluto[5458]: | 1: compared PSK  
xxx.xxx.xxx.xxx to @xxxxxx / xxx.xxx.xxx.xxx -> 2
<87>Aug 21 16:53:21.786 2006 pluto[5458]: | 2: compared PSK @xxxxxxx  
to @xxxxxxx / xxx.xxx.xxx.xxx -> 6
<87>Aug 21 16:53:21.786 2006 pluto[5458]: | best_match 0>6  
best=0xc16b0 (line=1)
<87>Aug 21 16:53:21.787 2006 pluto[5458]: | concluding with  
best_match=6 best=0xc16b0 (lineno=1)
<84>Aug 21 16:53:21.791 2006 pluto[5458]: "host" #1: enabling  
possible NAT-traversal with method RFC 3947 (NAT-Traversal)
<87>Aug 21 16:53:21.791 2006 pluto[5458]: | 0: w->pcw_dead: 0 w- 
 >pcw_work: 0 cnt: 1
<87>Aug 21 16:53:21.792 2006 pluto[5458]: | asking helper 0 to do  
build_kenonce op on seq: 1
<87>Aug 21 16:53:21.793 2006 pluto[5458]: | inserting event  
EVENT_CRYPTO_FAILED, timeout in 300 seconds for #1
<87>Aug 21 16:53:21.794 2006 pluto[5458]: | complete state transition  
with STF_SUSPEND
<87>Aug 21 16:53:21.794 2006 pluto[5458]: | next event  
EVENT_SHUNT_SCAN in 117 seconds
<87>Aug 21 16:53:21.796 2006 pluto[5461]: ! helper -1 doing  
build_kenonce op id: 1
<87>Aug 21 16:53:21.855 2006 pluto[5458]: | processing connection host
<87>Aug 21 16:53:21.856 2006 pluto[5458]: | ICOOKIE:  ea 05 fa e0  30  
4b 19 01
<87>Aug 21 16:53:21.856 2006 pluto[5458]: | RCOOKIE:  00 00 00 00  00  
00 00 00
<87>Aug 21 16:53:21.857 2006 pluto[5458]: | peer:  d0 fa 32 c1
<87>Aug 21 16:53:21.858 2006 pluto[5458]: | state hash entry 17
<87>Aug 21 16:53:21.858 2006 pluto[5458]: | ICOOKIE:  ea 05 fa e0  30  
4b 19 01
<87>Aug 21 16:53:21.859 2006 pluto[5458]: | RCOOKIE:  f9 83 de 3d  12  
9a 6e e3
<87>Aug 21 16:53:21.860 2006 pluto[5458]: | peer:  d0 fa 32 c1
<87>Aug 21 16:53:21.861 2006 pluto[5458]: | state hash entry 31
<87>Aug 21 16:53:21.861 2006 pluto[5458]: | complete state transition  
with STF_OK
<84>Aug 21 16:53:21.862 2006 pluto[5458]: "host" #1: transition from  
state STATE_MAIN_I1 to state STATE_MAIN_I2
<87>Aug 21 16:53:21.866 2006 pluto[5458]: | sending reply packet to  
xxx.xxx.xxx.xxx:500 (from port=500)
<87>Aug 21 16:53:21.867 2006 pluto[5458]: | sending 228 bytes for  
STATE_MAIN_I1 through eth1:500 to xxx.xxx.xxx.xxx:500:
<87>Aug 21 16:53:21.867 2006 pluto[5458]: | inserting event  
EVENT_RETRANSMIT, timeout in 10 seconds for #1
<84>Aug 21 16:53:21.868 2006 pluto[5458]: "host" #1: STATE_MAIN_I2:  
sent MI2, expecting MR2
<87>Aug 21 16:53:21.869 2006 pluto[5458]: | modecfg pull: noquirk  
policy:push not-client
<87>Aug 21 16:53:21.869 2006 pluto[5458]: | phase 1 is done, looking  
for phase 1 to unpend
<87>Aug 21 16:53:21.870 2006 pluto[5458]: | next event  
EVENT_RETRANSMIT in 10 seconds for #1
<87>Aug 21 16:53:21.933 2006 pluto[5458]: |
<87>Aug 21 16:53:21.934 2006 pluto[5458]: | *received 304 bytes from  
xxx.xxx.xxx.xxx:500 on eth1 (port=500)
<87>Aug 21 16:53:21.934 2006 pluto[5458]: |  processing packet with  
exchange type=ISAKMP_XCHG_IDPROT (2)
<87>Aug 21 16:53:21.935 2006 pluto[5458]: | ICOOKIE:  ea 05 fa e0  30  
4b 19 01
<87>Aug 21 16:53:21.936 2006 pluto[5458]: | RCOOKIE:  f9 83 de 3d  12  
9a 6e e3
<87>Aug 21 16:53:21.937 2006 pluto[5458]: | peer:  d0 fa 32 c1
<87>Aug 21 16:53:21.937 2006 pluto[5458]: | state hash entry 31
<87>Aug 21 16:53:21.938 2006 pluto[5458]: | peer and cookies match on  
#1, provided msgid 00000000 vs 00000000
<87>Aug 21 16:53:21.939 2006 pluto[5458]: | state object #1 found, in  
STATE_MAIN_I2
<87>Aug 21 16:53:21.939 2006 pluto[5458]: | processing connection host
<84>Aug 21 16:53:21.940 2006 pluto[5458]: "host" #1: received Vendor  
ID payload [Cisco-Unity]
<84>Aug 21 16:53:21.946 2006 pluto[5458]: "host" #1: received Vendor  
ID payload [Dead Peer Detection]
<84>Aug 21 16:53:21.946 2006 pluto[5458]: "host" #1: ignoring unknown  
Vendor ID payload [0c447920129b6ee321fb0b4497074d62]
<84>Aug 21 16:53:21.947 2006 pluto[5458]: "host" #1: received Vendor  
ID payload [XAUTH]
<87>Aug 21 16:53:21.948 2006 pluto[5458]: | thinking about whether to  
send my certificate:
<87>Aug 21 16:53:21.948 2006 pluto[5458]: |   I have RSA key:  
OAKLEY_PRESHARED_KEY cert.type: CERT_NONE
<87>Aug 21 16:53:21.949 2006 pluto[5458]: |   sendcert:  
CERT_ALWAYSSEND and I did not get a certificate request
<87>Aug 21 16:53:21.950 2006 pluto[5458]: |   so do not send cert.
<84>Aug 21 16:53:21.950 2006 pluto[5458]: "host" #1: I did not send a  
certificate because I do not have one.
<87>Aug 21 16:53:21.951 2006 pluto[5458]: |  I am not sending a  
certificate request
<87>Aug 21 16:53:21.952 2006 pluto[5458]: | started looking for  
secret for @xxxxxxx->xxx.xxx.xxx.xxx of kind PPK_PSK
<87>Aug 21 16:53:21.953 2006 pluto[5458]: | actually looking for  
secret for @xxxxxxx->xxx.xxx.xxx.xxx of kind PPK_PSK
<87>Aug 21 16:53:22.002 2006 pluto[5458]: | 1: compared PSK  
xxx.xxx.xxx.xxx to @xxxxxxx / xxx.xxx.xxx.xxx -> 2
<87>Aug 21 16:53:22.003 2006 pluto[5458]: | 2: compared PSK @xxxxxxx  
to @xxxxxxx / xxx.xxx.xxx.xxx -> 6
<87>Aug 21 16:53:22.003 2006 pluto[5458]: | best_match 0>6  
best=0xc16b0 (line=1)
<87>Aug 21 16:53:22.004 2006 pluto[5458]: | concluding with  
best_match=6 best=0xc16b0 (lineno=1)
<84>Aug 21 16:53:22.005 2006 pluto[5458]: "host" #1: NAT-Traversal:  
Result using draft-ietf-ipsec-nat-t-ike-02/03: i am NATed
<87>Aug 21 16:53:22.006 2006 pluto[5458]: | inserting event  
EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
<87>Aug 21 16:53:22.006 2006 pluto[5458]: | complete state transition  
with STF_OK
<84>Aug 21 16:53:22.007 2006 pluto[5458]: "host" #1: transition from  
state STATE_MAIN_I2 to state STATE_MAIN_I3
<87>Aug 21 16:53:22.009 2006 pluto[5458]: | sending reply packet to  
xxx.xxx.xxx.xxx:500 (from port=500)
<87>Aug 21 16:53:22.011 2006 pluto[5458]: | sending 68 bytes for  
STATE_MAIN_I2 through eth1:4500 to xxx.xxx.xxx.xxx:4500:
<87>Aug 21 16:53:22.012 2006 pluto[5458]: | inserting event  
EVENT_RETRANSMIT, timeout in 10 seconds for #1
<84>Aug 21 16:53:22.014 2006 pluto[5458]: "host" #1: STATE_MAIN_I3:  
sent MI3, expecting MR3
<87>Aug 21 16:53:22.015 2006 pluto[5458]: | modecfg pull: noquirk  
policy:push not-client
<87>Aug 21 16:53:22.017 2006 pluto[5458]: | phase 1 is done, looking  
for phase 1 to unpend
<87>Aug 21 16:53:22.018 2006 pluto[5458]: | next event  
EVENT_RETRANSMIT in 10 seconds for #1
<87>Aug 21 16:53:22.076 2006 pluto[5458]: |
<87>Aug 21 16:53:22.078 2006 pluto[5458]: | *received 68 bytes from  
xxx.xxx.xxx.xxx:4500 on eth1 (port=4500)
<87>Aug 21 16:53:22.079 2006 pluto[5458]: |  processing packet with  
exchange type=ISAKMP_XCHG_IDPROT (2)
<87>Aug 21 16:53:22.081 2006 pluto[5458]: | ICOOKIE:  ea 05 fa e0  30  
4b 19 01
<87>Aug 21 16:53:22.082 2006 pluto[5458]: | RCOOKIE:  f9 83 de 3d  12  
9a 6e e3
<87>Aug 21 16:53:22.084 2006 pluto[5458]: | peer:  d0 fa 32 c1
<87>Aug 21 16:53:22.085 2006 pluto[5458]: | state hash entry 31
<87>Aug 21 16:53:22.086 2006 pluto[5458]: | peer and cookies match on  
#1, provided msgid 00000000 vs 00000000
<87>Aug 21 16:53:22.088 2006 pluto[5458]: | state object #1 found, in  
STATE_MAIN_I3
<87>Aug 21 16:53:22.089 2006 pluto[5458]: | processing connection host
<87>Aug 21 16:53:22.091 2006 pluto[5458]: | protocol/port in Phase 1  
ID Payload is 17/0. accepted with port_floating NAT-T
<84>Aug 21 16:53:22.092 2006 pluto[5458]: "host" #1: Main mode peer  
ID is ID_IPV4_ADDR: 'xxx.xxx.xxx.xxx'
<87>Aug 21 16:53:22.094 2006 pluto[5458]: | complete state transition  
with STF_OK
<84>Aug 21 16:53:22.095 2006 pluto[5458]: "host" #1: transition from  
state STATE_MAIN_I3 to state STATE_MAIN_I4
<87>Aug 21 16:53:22.097 2006 pluto[5458]: | inserting event  
EVENT_SA_REPLACE, timeout in 2601 seconds for #1
<84>Aug 21 16:53:22.099 2006 pluto[5458]: "host" #1: STATE_MAIN_I4:  
ISAKMP SA established {auth=OAKLEY_PRESHARED_KEY  
cipher=oakley_3des_cbc_192 prf=oakley_sha group=modp1024}
<87>Aug 21 16:53:22.100 2006 pluto[5458]: | modecfg pull: noquirk  
policy:push not-client
<87>Aug 21 16:53:22.101 2006 pluto[5458]: | phase 1 is done, looking  
for phase 1 to unpend
<87>Aug 21 16:53:22.103 2006 pluto[5458]: | unqueuing pending Quick  
Mode with 208.250.50.193 "host"
<87>Aug 21 16:53:22.104 2006 pluto[5458]: | duplicating state object #1
<87>Aug 21 16:53:22.106 2006 pluto[5458]: | creating state object #2  
at 0xc3698
<87>Aug 21 16:53:22.107 2006 pluto[5458]: | processing connection host
<87>Aug 21 16:53:22.109 2006 pluto[5458]: | ICOOKIE:  ea 05 fa e0  30  
4b 19 01
<87>Aug 21 16:53:22.111 2006 pluto[5458]: | RCOOKIE:  f9 83 de 3d  12  
9a 6e e3
<87>Aug 21 16:53:22.112 2006 pluto[5458]: | peer:  d0 fa 32 c1
<87>Aug 21 16:53:22.114 2006 pluto[5458]: | state hash entry 31
<87>Aug 21 16:53:22.115 2006 pluto[5458]: | inserting event  
EVENT_SO_DISCARD, timeout in 0 seconds for #2
<84>Aug 21 16:53:22.117 2006 pluto[5458]: "host" #2: initiating Quick  
Mode PSK+ENCRYPT+TUNNEL+UP {using isakmp#1}
<87>Aug 21 16:53:22.118 2006 pluto[5458]: | 0: w->pcw_dead: 0 w- 
 >pcw_work: 0 cnt: 1
<87>Aug 21 16:53:22.120 2006 pluto[5458]: | asking helper 0 to do  
build_nonce op on seq: 2
<87>Aug 21 16:53:22.121 2006 pluto[5458]: | inserting event  
EVENT_CRYPTO_FAILED, timeout in 300 seconds for #2
<87>Aug 21 16:53:22.123 2006 pluto[5458]: | next event  
EVENT_NAT_T_KEEPALIVE in 20 seconds
<87>Aug 21 16:53:22.124 2006 pluto[5461]: ! helper -1 doing  
build_nonce op id: 2
<87>Aug 21 16:53:22.129 2006 pluto[5458]: | processing connection host
<87>Aug 21 16:53:22.131 2006 pluto[5458]: | kernel_alg_db_new() will  
return p_new->protoid=3, p_new->trans_cnt=1
<87>Aug 21 16:53:22.132 2006 pluto[5458]: | kernel_alg_db_new() trans 
[0]: transid=3, attr_cnt=1, attrs[0].type=5, attrs[0].val=2
<87>Aug 21 16:53:22.134 2006 pluto[5458]: | returning new proposal  
from esp_info
<87>Aug 21 16:53:22.136 2006 pluto[5458]: | generate SPI:  e4 1c fe 60
<87>Aug 21 16:53:22.138 2006 pluto[5458]: | sending 148 bytes for  
quick_outI1 through eth1:4500 to 208.250.50.193:4500:
<87>Aug 21 16:53:22.140 2006 pluto[5458]: | inserting event  
EVENT_RETRANSMIT, timeout in 10 seconds for #2
<87>Aug 21 16:53:22.141 2006 pluto[5458]: | next event  
EVENT_RETRANSMIT in 10 seconds for #2
<87>Aug 21 16:53:22.192 2006 pluto[5458]: |
<87>Aug 21 16:53:22.194 2006 pluto[5458]: | *received 124 bytes from  
xxx.xxx.xxx.xxx:4500 on eth1 (port=4500)
<87>Aug 21 16:53:22.195 2006 pluto[5458]: |  processing packet with  
exchange type=ISAKMP_XCHG_INFO (5)
<87>Aug 21 16:53:22.196 2006 pluto[5458]: | ICOOKIE:  ea 05 fa e0  30  
4b 19 01
<87>Aug 21 16:53:22.198 2006 pluto[5458]: | RCOOKIE:  f9 83 de 3d  12  
9a 6e e3
<87>Aug 21 16:53:22.199 2006 pluto[5458]: | peer:  d0 fa 32 c1
<87>Aug 21 16:53:22.201 2006 pluto[5458]: | state hash entry 31
<87>Aug 21 16:53:22.202 2006 pluto[5458]: | peer and cookies match on  
#2, provided msgid 00000000 vs 810d28c6/00000000
<87>Aug 21 16:53:22.204 2006 pluto[5458]: | peer and cookies match on  
#1, provided msgid 00000000 vs 00000000/00000000
<87>Aug 21 16:53:22.205 2006 pluto[5458]: | p15 state object #1  
found, in STATE_MAIN_I4
<87>Aug 21 16:53:22.206 2006 pluto[5458]: | processing connection host
<84>Aug 21 16:53:22.208 2006 pluto[5458]: "host" #1: ignoring  
informational payload, type NO_PROPOSAL_CHOSEN
<87>Aug 21 16:53:22.210 2006 pluto[5458]: | processing informational  
NO_PROPOSAL_CHOSEN (14)
<84>Aug 21 16:53:22.211 2006 pluto[5458]: "host" #1: received and  
ignored informational message
<87>Aug 21 16:53:22.213 2006 pluto[5458]: | complete state transition  
with STF_IGNORE
<87>Aug 21 16:53:22.214 2006 pluto[5458]: | next event  
EVENT_RETRANSMIT in 10 seconds for #2

-- 
Glenn Henshaw                     Logical Outcome Ltd.
e: thraxisp at logicaloutcome.ca     w: www.logicaloutcome.ca





More information about the Users mailing list