[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