[Openswan Users] openSWAN to Cisco IOS
Glenn Henshaw
thraxisp at logicaloutcome.ca
Tue Aug 22 17:02:30 EDT 2006
On 22-Aug-06, at 12:22 PM, Andy Gay wrote:
> On Tue, 2006-08-22 at 11:53 -0400, Glenn Henshaw wrote:
>> 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?
>>
> The 2 ends can't agree on phase2 parameters. Everything has to match -
> left/right subnets, encryption/authentication algorithms, PFS,
> probably
> more...
I walked through this with the Cisco tech at the other end, There
aren't any explicit failure logs pointing to a mismatch. There were
some before the encryption was matched up.
The status on the Cisco does tentatively show the link as up for a
while.
cisco#sh cryp isa sa
dst src state conn-id slot status
xxx.xxx.xxx.xxx yyy.yyy.yyy.yyy QM_IDLE 231 0 ACTIVE
>
> I don't think you're showing us enough of the cisco config. Shouldn't
> there be a crypto map that references the dynamic map? That's how it
> works on a PIX, maybe IOS is different.
>
> I'm guessing you probably need an ACL in the cisco which matches your
> left/rightsubnets, that needs to be referenced in the crypto map
> (something like "crypto map xx match address <acl>").
This is a roadwarrior setup so the PSK is set up to match any host
like:
crypto keyring QP_Spokes
pre-shared-key address 0.0.0.0 0.0.0.0 key shared_secret
The Cisco also allows access to 10.0.0.0/8 (but I can't find that
in the section of the config I have).
>
> Debug logs from the cisco will help. And your openswan logs will be
> much
> easier to read if you set plutodebug="none"....
I can't get these as it's a commercial provider managing someone
elses network. I can ask questions though.
... Glenn
>
>>
>> ... 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
>>
>>
>>
>> _______________________________________________
>> Users at openswan.org
>> http://lists.openswan.org/mailman/listinfo/users
>> Building and Integrating Virtual Private Networks with Openswan:
>> http://www.amazon.com/gp/product/1904811256/104-3099591-2946327?
>> n=283155
>>
>
--
Glenn Henshaw Logical Outcome Ltd.
t: (613) 853-6702 e: thraxisp at logicaloutcome.ca
f: (613) 839-2286 w: www.logicaloutcome.ca
This message is for the designated recipient only and may contain
privileged, proprietary, or otherwise private information. If you have
received it in error, please notify the sender immediately and delete
the original. Any other use of the email by you is prohibited.
More information about the Users
mailing list