[Swan] libreswan 3.17 NAT-T fails in phase2

Tue Jun 14 23:03:27 UTC 2016

Paul,

First of all, thanks for your reply and suggestion.

I cannot find anything related about IPSec SA in syslog even though I set
klipsdebug=all and plutodebug=all in ipsec.conf.

After restart ipsec, I found that in the remote peer, it seems succeeds
according to the ipsec status as bellow.

000 vpn-0: "vpn-0-ipsectunnel-0":   newest ISAKMP SA: #8; newest IPsec SA:
#18;
000 vpn-0: "vpn-0-ipsectunnel-0":   IKE algorithms wanted:
3DES_CBC(5)_000-SHA1(2)_000-MODP1024(2)
000 vpn-0: "vpn-0-ipsectunnel-0":   IKE algorithms found:
 3DES_CBC(5)_192-SHA1(2)_160-MODP1024(2)
000 vpn-0: "vpn-0-ipsectunnel-0":   IKE algorithm newest:
3DES_CBC_192-SHA1-MODP1024
000 vpn-0: "vpn-0-ipsectunnel-0":   ESP algorithms wanted:
3DES(3)_000-SHA1(2)_000; pfsgroup=MODP1024(2)
000 vpn-0: "vpn-0-ipsectunnel-0":   ESP algorithms loaded:
3DES(3)_000-SHA1(2)_000
000 vpn-0: "vpn-0-ipsectunnel-0":   ESP algorithm newest:
3DES_000-HMAC_SHA1; pfsgroup=MODP1024
000 vpn-0:
000 vpn-0: Total IPsec connections: loaded 1, active 1
000 vpn-0:
000 vpn-0: State Information: DDoS cookies not required, Accepting new IKE
connections
000 vpn-0: IKE SAs: total(1), half-open(0), open(0), authenticated(1),
anonymous(0)
000 vpn-0: IPsec SAs: total(1), authenticated(1), anonymous(0)
000 vpn-0:
000 vpn-0: #18: "vpn-0-ipsectunnel-0":4500 STATE_QUICK_I2 (sent QI2, IPsec
SA established); EVENT_SA_REPLACE in 38s; newest IPSEC; eroute owner;
isakmp#8; idle; import:local rekey
000 vpn-0: #18: "vpn-0-ipsectunnel-0" used 26s ago;
esp.57df2ed4 at 10.2.128.241 esp.e688baf6 at 10.2.128.240 tun.1018 at 10.2.128.241
tun.1019 at 10.2.128.240 ref=0 refhim=4294901761 Traffic:! ESPmax=4194303B
000 vpn-0: #8: "vpn-0-ipsectunnel-0":4500 STATE_MAIN_I4 (ISAKMP SA
established); EVENT_SA_REPLACE in 26635s; newest ISAKMP; lastdpd=11s(seq
in:5909 out:0); idle; import:local rekey
000 vpn-0:
000 vpn-0: Bare Shunt list:
000 vpn-0:

But on the local peer behind NAT gateway, it looks weird. The message shows
IPsec SA installed but no established. IPsec connections active 0, and my
end to end traffic still cannot go through.

000 "vpn-0": 0.0.0.0/0===10.0.0.1
<10.0.0.1>[10.2.128.241]...10.2.128.240<10.2.128.240>===0.0.0.0/0;
unrouted; eroute owner: #0
000 "vpn-0":     oriented; my_ip=unset; their_ip=unset;
myup=/var/run/updown.klips
000 "vpn-0":   xauth us:none, xauth them:none,  my_username=[any];
their_username=[any]
000 "vpn-0":   modecfg info: us:none, them:none, modecfg policy:push,
dns1:unset, dns2:unset, domain:unset, banner:unset;
000 "vpn-0":   labeled_ipsec:no;
000 "vpn-0":   policy_label:unset;
000 "vpn-0":   ike_life: 28800s; ipsec_life: 3600s; replay_window: 32;
rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 0;
000 "vpn-0":   retransmit-interval: 500ms; retransmit-timeout: 60s;
000 "vpn-0":   sha2_truncbug:no; initial_contact:no; cisco_unity:no;
fake_strongswan:no; send_vendorid:no;
000 "vpn-0":   policy:
PSK+ENCRYPT+TUNNEL+PFS+IKEV1_ALLOW+IKEV2_ALLOW+SAREF_TRACK+IKE_FRAG_ALLOW+ESN_NO;
000 "vpn-0":   conn_prio: 0,0; interface: eth0; metric: 0; mtu: unset;
sa_prio:auto; nflog-group: unset; mark: unset;
000 "vpn-0":   dpd: action:hold; delay:15; timeout:75; nat-t:
force_encaps:no; nat_keepalive:yes; ikev1_natt:both
000 "vpn-0":   newest ISAKMP SA: #5; newest IPsec SA: #0;
000 "vpn-0":   IKE algorithms wanted:
3DES_CBC(5)_000-SHA1(2)_000-MODP1024(2)
000 "vpn-0":   IKE algorithms found:
 3DES_CBC(5)_192-SHA1(2)_160-MODP1024(2)
000 "vpn-0":   IKE algorithm newest: 3DES_CBC_192-SHA1-MODP1024
000 "vpn-0":   ESP algorithms wanted: 3DES(3)_000-SHA1(2)_000;
pfsgroup=MODP1024(2)
000 "vpn-0":   ESP algorithms loaded: 3DES(3)_000-SHA1(2)_000
000
000 Total IPsec connections: loaded 1, active 0
000
000 State Information: DDoS cookies not required, Accepting new IKE
connections
000 IKE SAs: total(1), half-open(0), open(0), authenticated(1), anonymous(0)
000 IPsec SAs: total(1), authenticated(1), anonymous(0)
000
000 #15: "vpn-0":4500 STATE_QUICK_R1 (sent QR1, inbound IPsec SA installed,
expecting QI2); EVENT_v1_RETRANSMIT in 2s; isakmp#5; idle; import:not set
000 #15: "vpn-0" esp.e688baf6 at 10.2.128.240 esp.57df2ed4 at 10.0.0.1
tun.1016 at 10.2.128.240 tun.1017 at 10.0.0.1 ref=0 refhim=4294901761 Traffic:!
ESPmax=4194303B
000 #5: "vpn-0":4500 STATE_MAIN_R3 (sent MR3, ISAKMP SA established);
EVENT_SA_REPLACE in 27399s; newest ISAKMP; lastdpd=18s(seq in:1072 out:0);
idle; import:not set
000
000 Bare Shunt list:

Looks like in phase 2, something wrong in the 2nd/3rd packet.

I tcpdump the packets on local side and see

23:00:08.195272 IP 10.2.128.240.4500 > 10.0.0.1.4500: NONESP-encap: isakmp:
phase 1 ? ident[E]
23:00:08.215129 IP 10.0.0.1.4500 > 10.2.128.240.4500: NONESP-encap: isakmp:
phase 1 ? ident[E]
23:00:08.238236 IP 10.2.128.240.4500 > 10.0.0.1.4500: NONESP-encap: isakmp:
phase 2/others ? oakley-quick[E]
23:00:08.339546 IP 10.0.0.1.4500 > 10.2.128.240.4500: NONESP-encap: isakmp:
phase 2/others ? oakley-quick[E]
23:00:08.477468 IP 10.2.128.240.4500 > 10.0.0.1.4500: NONESP-encap: isakmp:
phase 2/others ? oakley-quick[E]
23:00:08.791668 IP 10.0.0.1.4500 > 10.2.128.240.4500: NONESP-encap: isakmp:
phase 2/others ? oakley-quick[E]
23:00:08.819497 IP 10.2.128.240.4500 > 10.0.0.1.4500: NONESP-encap: isakmp:
phase 2/others ? oakley-quick[E]
23:00:09.292133 IP 10.0.0.1.4500 > 10.2.128.240.4500: NONESP-encap: isakmp:
phase 2/others ? oakley-quick[E]
23:00:09.304959 IP 10.2.128.240.4500 > 10.0.0.1.4500: NONESP-encap: isakmp:
phase 2/others ? oakley-quick[E]
23:00:10.294561 IP 10.0.0.1.4500 > 10.2.128.240.4500: NONESP-encap: isakmp:
phase 2/others ? oakley-quick[E]
23:00:12.294304 IP 10.0.0.1.4500 > 10.2.128.240.4500: NONESP-encap: isakmp:
phase 2/others ? oakley-quick[E]
23:00:16.296868 IP 10.0.0.1.4500 > 10.2.128.240.4500: NONESP-encap: isakmp:
phase 2/others ? oakley-quick[E]
23:00:23.201352 IP 10.0.0.1.4500 > 10.2.128.240.4500: NONESP-encap: isakmp:
phase 2/others ? inf[E]
23:00:23.212712 IP 10.2.128.240.4500 > 10.0.0.1.4500: NONESP-encap: isakmp:
phase 2/others ? inf[E]
23:00:24.297207 IP 10.0.0.1.4500 > 10.2.128.240.4500: NONESP-encap: isakmp:
phase 2/others ? oakley-quick[E]
23:00:28.135880 IP 10.0.0.1.4500 > 10.2.128.240.4500: isakmp-nat-keep-alive
23:00:38.370317 IP 10.2.128.240.4500 > 10.0.0.1.4500: NONESP-encap: isakmp:
phase 2/others ? inf[E]
23:00:38.378497 IP 10.0.0.1.4500 > 10.2.128.240.4500: NONESP-encap: isakmp:
phase 2/others ? inf[E]
23:00:40.298093 IP 10.0.0.1.4500 > 10.2.128.240.4500: NONESP-encap: isakmp:
phase 2/others ? oakley-quick[E]

Just from this dump, it is difficult to find anything useful.  Is there a
way to see more detailed things about what happened in phase 2?

Thanks,
Toby

Thanks,
Toby

On Tue, Jun 14, 2016 at 10:45 AM, Paul Wouters <paul at nohats.ca> wrote:

> On Mon, 13 Jun 2016, Ge Xu wrote:
>
> I am testing a VPN behind of a NAT gateway. I tried libreswan 3.15 and
>> 3.17 with same configuration. 3.15 succeeds, but 3.17
>> fails.
>>
>
> I am not aware of anything specific causing that.
>
> 000 #2: "vpn-0":4500 STATE_QUICK_I1 (sent QI1, expecting QR1);
>> EVENT_CRYPTO_FAILED in 54s; lastdpd=-1s(seq in:0 out:0); idle;
>> import:admin initiate
>> 000 #1: "vpn-0":4500 STATE_MAIN_I4 (ISAKMP SA established);
>> EVENT_SA_REPLACE in 27801s; newest ISAKMP; lastdpd=-1s(seq in:0
>> out:0); idle; import:admin initiate
>>
>
> It looks like the IPsec SA did not fully establish. Either your logs or
> the remote endpoint's log should have an entry saying what went wrong.
>
> Paul
>

-- 
Ge (Toby) Xu
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.libreswan.org/pipermail/swan/attachments/20160614/fd76ea23/attachment-0001.html>