[Openswan Users] Openswan configuration problem
Mateusz Korab
korab.mateusz at gmail.com
Wed Jul 15 19:17:46 EDT 2009
Logs from /var/log/auth.log:
Jul 16 01:47:30 servantes pluto[19179]: "xxxxx" #1: initiating Main Mode
Jul 16 01:47:30 servantes pluto[19179]: | sending 116 bytes for
main_outI1 through eth0:500 to 83.238.137.33:500:
Jul 16 01:47:30 servantes pluto[19179]: | inserting event
EVENT_RETRANSMIT, timeout in 10 seconds for #1
Jul 16 01:47:30 servantes pluto[19179]: | next event EVENT_RETRANSMIT
in 10 seconds for #1
Jul 16 01:47:30 servantes pluto[19179]: |
Jul 16 01:47:30 servantes pluto[19179]: | *received 116 bytes from
IP_B:500 on eth0 (port=500)
Jul 16 01:47:30 servantes pluto[19179]: | processing packet with
exchange type=ISAKMP_XCHG_IDPROT (2)
Jul 16 01:47:30 servantes pluto[19179]: | ICOOKIE: 3d 65 c6 fe 18 53 ca 77
Jul 16 01:47:30 servantes pluto[19179]: | RCOOKIE: b9 bb e4 46 c9 12 ea 5b
Jul 16 01:47:30 servantes pluto[19179]: | peer: 53 ee 89 21
Jul 16 01:47:30 servantes pluto[19179]: | state hash entry 17
Jul 16 01:47:30 servantes pluto[19179]: | state object not found
Jul 16 01:47:30 servantes pluto[19179]: | ICOOKIE: 3d 65 c6 fe 18 53 ca 77
Jul 16 01:47:30 servantes pluto[19179]: | RCOOKIE: 00 00 00 00 00 00 00 00
Jul 16 01:47:30 servantes pluto[19179]: | peer: 53 ee 89 21
Jul 16 01:47:30 servantes pluto[19179]: | state hash entry 3
Jul 16 01:47:30 servantes pluto[19179]: | peer and cookies match on
#1, provided msgid 00000000 vs 00000000
Jul 16 01:47:30 servantes pluto[19179]: | state object #1 found, in
STATE_MAIN_I1
Jul 16 01:47:30 servantes pluto[19179]: | processing connection unima
Jul 16 01:47:30 servantes pluto[19179]: "xxxxx" #1: ignoring unknown
Vendor ID payload [4f455a565c774846787a4e56]
Jul 16 01:47:30 servantes pluto[19179]: "xxxxx" #1: received Vendor ID
payload [Dead Peer Detection]
Jul 16 01:47:30 servantes pluto[19179]: | started looking for secret
for IP_A->IP_B of kind PPK_PSK
Jul 16 01:47:30 servantes pluto[19179]: | actually looking for secret
for IP_A->IP_B of kind PPK_PSK
Jul 16 01:47:30 servantes pluto[19179]: | 1: compared PSK IP_B to IP_A
/ IP_B -> 2
Jul 16 01:47:30 servantes pluto[19179]: | 2: compared PSK IP_A to IP_A
/ IP_B -> 6
Jul 16 01:47:30 servantes pluto[19179]: | best_match 0>6
best=0x8bc3f98 (line=11)
Jul 16 01:47:30 servantes pluto[19179]: | concluding with best_match=6
best=0x8bc3f98 (lineno=11)
Jul 16 01:47:30 servantes pluto[19179]: | helper -1 doing build_kenonce op id: 0
Jul 16 01:47:30 servantes pluto[19179]: | processing connection unima
Jul 16 01:47:30 servantes pluto[19179]: | ICOOKIE: 3d 65 c6 fe 18 53 ca 77
Jul 16 01:47:30 servantes pluto[19179]: | RCOOKIE: 00 00 00 00 00 00 00 00
Jul 16 01:47:30 servantes pluto[19179]: | peer: 53 ee 89 21
Jul 16 01:47:30 servantes pluto[19179]: | state hash entry 3
Jul 16 01:47:30 servantes pluto[19179]: | ICOOKIE: 3d 65 c6 fe 18 53 ca 77
Jul 16 01:47:30 servantes pluto[19179]: | RCOOKIE: b9 bb e4 46 c9 12 ea 5b
Jul 16 01:47:30 servantes pluto[19179]: | peer: 53 ee 89 21
Jul 16 01:47:30 servantes pluto[19179]: | state hash entry 17
Jul 16 01:47:30 servantes pluto[19179]: | complete state transition with STF_OK
Jul 16 01:47:30 servantes pluto[19179]: "xxxxx" #1: transition from
state STATE_MAIN_I1 to state STATE_MAIN_I2
Jul 16 01:47:30 servantes pluto[19179]: | sending reply packet to
IP_B:500 (from port=500)
Jul 16 01:47:30 servantes pluto[19179]: | sending 180 bytes for
STATE_MAIN_I1 through eth0:500 to IP_B:500:
Jul 16 01:47:30 servantes pluto[19179]: | inserting event
EVENT_RETRANSMIT, timeout in 10 seconds for #1
Jul 16 01:47:30 servantes pluto[19179]: "xxxxx" #1: STATE_MAIN_I2:
sent MI2, expecting MR2
Jul 16 01:47:30 servantes pluto[19179]: | modecfg pull: noquirk
policy:push not-client
Jul 16 01:47:30 servantes pluto[19179]: | phase 1 is done, looking for
phase 1 to unpend
Jul 16 01:47:30 servantes pluto[19179]: | complete state transition
with STF_INLINE
Jul 16 01:47:30 servantes pluto[19179]: | next event EVENT_RETRANSMIT
in 10 seconds for #1
Jul 16 01:47:30 servantes pluto[19179]: |
Jul 16 01:47:30 servantes pluto[19179]: | *received 180 bytes from
IP_B:500 on eth0 (port=500)
Jul 16 01:47:30 servantes pluto[19179]: | processing packet with
exchange type=ISAKMP_XCHG_IDPROT (2)
Jul 16 01:47:30 servantes pluto[19179]: | ICOOKIE: 3d 65 c6 fe 18 53 ca 77
Jul 16 01:47:30 servantes pluto[19179]: | RCOOKIE: b9 bb e4 46 c9 12 ea 5b
Jul 16 01:47:30 servantes pluto[19179]: | peer: 53 ee 89 21
Jul 16 01:47:30 servantes pluto[19179]: | state hash entry 17
Jul 16 01:47:30 servantes pluto[19179]: | peer and cookies match on
#1, provided msgid 00000000 vs 00000000
Jul 16 01:47:30 servantes pluto[19179]: | state object #1 found, in
STATE_MAIN_I2
Jul 16 01:47:30 servantes pluto[19179]: | processing connection unima
Jul 16 01:47:30 servantes pluto[19179]: | thinking about whether to
send my certificate:
Jul 16 01:47:30 servantes pluto[19179]: | I have RSA key:
OAKLEY_PRESHARED_KEY cert.type: CERT_NONE
Jul 16 01:47:30 servantes pluto[19179]: | sendcert: CERT_ALWAYSSEND
and I did not get a certificate request
Jul 16 01:47:30 servantes pluto[19179]: | so do not send cert.
Jul 16 01:47:30 servantes pluto[19179]: "xxxxx" #1: I did not send a
certificate because I do not have one.
Jul 16 01:47:30 servantes pluto[19179]: | I am not sending a
certificate request
Jul 16 01:47:30 servantes pluto[19179]: | started looking for secret
for IP_A->IP_B of kind PPK_PSK
Jul 16 01:47:30 servantes pluto[19179]: | actually looking for secret
for IP_A->IP_B of kind PPK_PSK
Jul 16 01:47:30 servantes pluto[19179]: | 1: compared PSK IP_B to IP_B
/ IP_B -> 2
Jul 16 01:47:30 servantes pluto[19179]: | 2: compared PSK IP_A to IP_A
/ IP_B -> 6
Jul 16 01:47:30 servantes pluto[19179]: | best_match 0>6
best=0x8bc3f98 (line=11)
Jul 16 01:47:30 servantes pluto[19179]: | concluding with best_match=6
best=0x8bc3f98 (lineno=11)
Jul 16 01:47:30 servantes pluto[19179]: | complete state transition with STF_OK
Jul 16 01:47:30 servantes pluto[19179]: "xxxxx" #1: transition from
state STATE_MAIN_I2 to state STATE_MAIN_I3
Jul 16 01:47:30 servantes pluto[19179]: | sending reply packet to
IP_B:500 (from port=500)
Jul 16 01:47:30 servantes pluto[19179]: | sending 68 bytes for
STATE_MAIN_I2 through eth0:500 to IP_B:500:
Jul 16 01:47:30 servantes pluto[19179]: | inserting event
EVENT_RETRANSMIT, timeout in 10 seconds for #1
Jul 16 01:47:30 servantes pluto[19179]: "xxxxx" #1: STATE_MAIN_I3:
sent MI3, expecting MR3
Jul 16 01:47:30 servantes pluto[19179]: | modecfg pull: noquirk
policy:push not-client
Jul 16 01:47:30 servantes pluto[19179]: | phase 1 is done, looking for
phase 1 to unpend
Jul 16 01:47:30 servantes pluto[19179]: | next event EVENT_RETRANSMIT
in 10 seconds for #1
Jul 16 01:47:30 servantes pluto[19179]: |
Jul 16 01:47:30 servantes pluto[19179]: | *received 68 bytes from
IP_B:500 on eth0 (port=500)
Jul 16 01:47:30 servantes pluto[19179]: | processing packet with
exchange type=ISAKMP_XCHG_IDPROT (2)
Jul 16 01:47:30 servantes pluto[19179]: | ICOOKIE: 3d 65 c6 fe 18 53 ca 77
Jul 16 01:47:30 servantes pluto[19179]: | RCOOKIE: b9 bb e4 46 c9 12 ea 5b
Jul 16 01:47:30 servantes pluto[19179]: | peer: 53 ee 89 21
Jul 16 01:47:30 servantes pluto[19179]: | state hash entry 17
Jul 16 01:47:30 servantes pluto[19179]: | peer and cookies match on
#1, provided msgid 00000000 vs 00000000
Jul 16 01:47:30 servantes pluto[19179]: | state object #1 found, in
STATE_MAIN_I3
Jul 16 01:47:30 servantes pluto[19179]: | processing connection unima
Jul 16 01:47:30 servantes pluto[19179]: "xxxxx" #1: Main mode peer ID
is ID_IPV4_ADDR: 'IP_B
Jul 16 01:47:30 servantes pluto[19179]: | complete state transition with STF_OK
Jul 16 01:47:30 servantes pluto[19179]: "xxxxx" #1: transition from
state STATE_MAIN_I3 to state STATE_MAIN_I4
Jul 16 01:47:30 servantes pluto[19179]: | inserting event
EVENT_SA_REPLACE, timeout in 13817 seconds for #1
Jul 16 01:47:30 servantes pluto[19179]: "xxxxx" #1: STATE_MAIN_I4:
ISAKMP SA established {auth=OAKLEY_PRESHARED_KEY
cipher=oakley_3des_cbc_192 prf=oakley_sha group=modp1024}
Jul 16 01:47:30 servantes pluto[19179]: | modecfg pull: noquirk
policy:push not-client
Jul 16 01:47:30 servantes pluto[19179]: | phase 1 is done, looking for
phase 1 to unpend
Jul 16 01:47:30 servantes pluto[19179]: | unqueuing pending Quick Mode
with IP_B "xxxxx"
Jul 16 01:47:30 servantes pluto[19179]: | duplicating state object #1
Jul 16 01:47:30 servantes pluto[19179]: | creating state object #2 at 0x8bc64b0
Jul 16 01:47:30 servantes pluto[19179]: | processing connection xxxxx
Jul 16 01:47:30 servantes pluto[19179]: | ICOOKIE: 3d 65 c6 fe 18 53 ca 77
Jul 16 01:47:30 servantes pluto[19179]: | RCOOKIE: b9 bb e4 46 c9 12 ea 5b
Jul 16 01:47:30 servantes pluto[19179]: | peer: 53 ee 89 21
Jul 16 01:47:30 servantes pluto[19179]: | state hash entry 17
Jul 16 01:47:30 servantes pluto[19179]: | inserting event
EVENT_SO_DISCARD, timeout in 0 seconds for #2
Jul 16 01:47:30 servantes pluto[19179]: "unima" #2: initiating Quick
Mode PSK+ENCRYPT+TUNNEL+UP {using isakmp#1}
Jul 16 01:47:30 servantes pluto[19179]: | helper -1 doing build_nonce op id: 0
Jul 16 01:47:30 servantes pluto[19179]: | processing connection unima
Jul 16 01:47:30 servantes pluto[19179]: | kernel_alg_db_new() will
return p_new->protoid=3, p_new->trans_cnt=2
Jul 16 01:47:30 servantes pluto[19179]: | kernel_alg_db_new()
trans[0]: transid=3, attr_cnt=1, attrs[0].type=5, attrs[0].val=1
Jul 16 01:47:30 servantes pluto[19179]: | kernel_alg_db_new()
trans[1]: transid=3, attr_cnt=1, attrs[0].type=5, attrs[0].val=2
Jul 16 01:47:30 servantes pluto[19179]: | returning new proposal from esp_info
Jul 16 01:47:30 servantes pluto[19179]: | sending 180 bytes for
quick_outI1 through eth0:500 to IP_B:500:
Jul 16 01:47:30 servantes pluto[19179]: | inserting event
EVENT_RETRANSMIT, timeout in 10 seconds for #2
Jul 16 01:47:30 servantes pluto[19179]: | next event EVENT_RETRANSMIT
in 10 seconds for #2
Jul 16 01:47:30 servantes pluto[19179]: |
Jul 16 01:47:30 servantes pluto[19179]: | *received 156 bytes from
IP_B:500 on eth0 (port=500)
Jul 16 01:47:30 servantes pluto[19179]: | processing packet with
exchange type=ISAKMP_XCHG_QUICK (32)
Jul 16 01:47:30 servantes pluto[19179]: | ICOOKIE: 3d 65 c6 fe 18 53 ca 77
Jul 16 01:47:30 servantes pluto[19179]: | RCOOKIE: b9 bb e4 46 c9 12 ea 5b
Jul 16 01:47:30 servantes pluto[19179]: | peer: 53 ee 89 21
Jul 16 01:47:30 servantes pluto[19179]: | state hash entry 17
Jul 16 01:47:30 servantes pluto[19179]: | peer and cookies match on
#2, provided msgid 8a1a9581 vs 8a1a9581
Jul 16 01:47:30 servantes pluto[19179]: | state object #2 found, in
STATE_QUICK_I1
Jul 16 01:47:30 servantes pluto[19179]: | processing connection unima
Jul 16 01:47:30 servantes pluto[19179]: | our client is subnet 192.168.5.0/24
Jul 16 01:47:30 servantes pluto[19179]: | our client protocol/port is 0/0
Jul 16 01:47:30 servantes pluto[19179]: | peer client is subnet 192.168.2.0/24
Jul 16 01:47:30 servantes pluto[19179]: | peer client protocol/port is 0/0
Jul 16 01:47:30 servantes pluto[19179]: | install_ipsec_sa() for #2:
inbound and outbound
Jul 16 01:47:30 servantes pluto[19179]: | route owner of "xxxxx"
prospective erouted: self; eroute owner: self
Jul 16 01:47:30 servantes pluto[19179]: | could_route called for xxxxx
(kind=CK_PERMANENT)
Jul 16 01:47:30 servantes pluto[19179]: | add inbound eroute
192.168.2.0/24:0 --0-> 192.168.5.0/24:0 => tun.10000 at IP_A(raw_eroute)
Jul 16 01:47:30 servantes pluto[19179]: | sr for #2: prospective erouted
Jul 16 01:47:30 servantes pluto[19179]: | route owner of "xxxxx"
prospective erouted: self; eroute owner: self
Jul 16 01:47:30 servantes pluto[19179]: | eroute_connection replace
eroute 192.168.5.0/24:0 --0-> 192.168.2.0/24:0 =>
tun.0 at IP_B(raw_eroute)
Jul 16 01:47:30 servantes pluto[19179]: | command executing up-client
Jul 16 01:47:30 servantes pluto[19179]: | executing up-client: 2>&1
PLUTO_VERSION='1.1' PLUTO_VERB='up-client' PLUTO_CONNECTION='xxxxx'
PLUTO_NEXT_HOP='IP_B' PLUTO_INTERFACE='eth0' PLUTO_ME='IP_A'
PLUTO_MY_ID='IP_A' PLUTO_MY_CLIENT='192.168.5.0/24'
PLUTO_MY_CLIENT_NET='192.168.5.0' PLUTO_MY_CLIENT_MASK='255.255.255.0'
PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='IP_B'
PLUTO_PEER_ID='IP_B' PLUTO_PEER_CLIENT='192.168.2.0/24'
PLUTO_PEER_CLIENT_NET='192.168.2.0'
PLUTO_PEER_CLIENT_MASK='255.255.255.0' PLUTO_PEER_PORT='0'
PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA=''
PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+UP' ipsec _updown
Jul 16 01:47:30 servantes pluto[19179]: | route_and_eroute:
firewall_notified: true
Jul 16 01:47:30 servantes pluto[19179]: | route_and_eroute: instance
"xxxxx", setting eroute_owner {spd=0x8bc45dc,sr=0x8bc45dc} to #2 (was
#0) (newest_ipsec_sa=#0)
Jul 16 01:47:30 servantes pluto[19179]: | complete state transition with STF_OK
Jul 16 01:47:30 servantes pluto[19179]: "xxxxx" #2: transition from
state STATE_QUICK_I1 to state STATE_QUICK_I2
Jul 16 01:47:30 servantes pluto[19179]: | sending reply packet to
IP_B:500 (from port=500)
Jul 16 01:47:30 servantes pluto[19179]: | sending 52 bytes for
STATE_QUICK_I1 through eth0:500 to IP_B:500:
Jul 16 01:47:30 servantes pluto[19179]: | inserting event
EVENT_SA_REPLACE, timeout in 3019 seconds for #2
Jul 16 01:47:30 servantes pluto[19179]: "xxxxx" #2: STATE_QUICK_I2:
sent QI2, IPsec SA established {ESP=>0x096a744d <0x9e00c29e
xfrm=3DES_0-HMAC_MD5 NATD=none DPD=none}
Jul 16 01:47:30 servantes pluto[19179]: | modecfg pull: noquirk
policy:push not-client
Jul 16 01:47:30 servantes pluto[19179]: | phase 1 is done, looking for
phase 1 to unpend
Jul 16 01:47:30 servantes pluto[19179]: | next event
EVENT_PENDING_PHASE2 in 118 seconds
krabu
On Thu, Jul 16, 2009 at 12:38 AM, Paul Wouters<paul at xelerance.com> wrote:
> On Wed, 15 Jul 2009, Mateusz Korab wrote:
>
>> I'm trying to set a vpn connection between two linux Debian serwers
>> usign openswan but with no success:
>
>> host_A:~# tcpdump -i eth0 -n host IP_B
>> 23:40:07.646132 IP IP_A.500 > IP_B.500: isakmp: phase 2/others R inf[E]
>> 23:40:07.649403 IP IP_A> IP_B.500: isakmp: phase 2/others R inf[E]
>
> dont post tcpdumps. this is all crypted anyway and useles.
>
>> Jul 15 23:46:14 servantes ipsec_setup: NETKEY on eth0
>> IP_A/255.255.255.0 broadcast broadcast_IP_A
>> Jul 15 23:46:15 servantes ipsec_setup: ...Openswan IPsec started
>> Jul 15 23:46:15 servantes ipsec_setup: Starting Openswan IPsec 2.4.12...
>
> upgrade to 2.4.15.
>
> also, this are only the partial logs, the real logs are in /var/log/secure
> or /var/log/auth.log
>
> Paul
>
More information about the Users
mailing list