Hi Paul, Do you have any idea about what is wrong with the phase2 according to the logs?
The machines at both sides have the same kernel I don't understand why the status on one side is active, but on the NAT side is not. Thanks, Toby On Tue, Jun 14, 2016 at 8:51 PM, Ge Xu <[email protected]> wrote: > Attached are the log files on both peers. I took a look, and found > following lines, but not sure. > > Jun 15 03:34:13: | pfkey_lib_debug:pfkey_extensions_free:Free extension 24 > (24) > Jun 15 03:34:13: | raw_eroute result=success > Jun 15 03:34:13: | command executing up-client > Jun 15 03:34:13: | executing up-client: 2>&1 PLUTO_VERB='up-client' > PLUTO_VERSION='2.0' PLUTO_CONNECTION='vpn-0' PLUTO_INTERFACE='ipsec0' > PLUTO_NEXT_HOP='10.2.128.240' PLUTO_ME='10.0.0.1' > PLUTO_MY_ID='10.2.128.241' PLUTO_MY_CLIENT='0.0.0.0/0' > PLUTO_MY_CLIENT_NET='0.0.0.0' PLUTO_MY_CLIENT_MASK='0.0.0.0' > PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_SA_REQID='16388' > PLUTO_SA_TYPE='ESP' PLUTO_PEER='10.2.128.240' PLUTO_PEER_ID='10.2.128.240' > PLUTO_PEER_CLIENT='0.0.0.0/0' PLUTO_PEER_CLIENT_NET='0.0.0.0' > PLUTO_PEER_CLIENT_MASK='0.0.0.0' PLUTO_PEER_PORT='0' > PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_STACK='klips' > PLUTO_ADDTIME='0' > PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+PFS+UP+IKEV1_ALLOW+IKEV2_ALLOW+SAREF_TRACK+IKE_FRAG_ALLOW+ESN_NO' > PLUTO_CONN_ADDRFAMILY='ipv4' XAUTH_FAILED=0 PLUTO_IS_PEER_CISCO='0' > PLUTO_PEER_DNS_INFO='' PLUTO_PEER_DOMAIN_INFO='' PLUTO_PEER_BANNER='' > PLUTO_NM_CONFIGURED='0' /var/run/updown.klips > Jun 15 03:34:13: | popen cmd is 883 chars long > Jun 15 03:34:13: | cmd( 0):2>&1 PLUTO_VERB='up-client' > PLUTO_VERSION='2.0' PLUTO_CONNECTION='vpn-0' PLUTO_I: > Jun 15 03:34:13: | cmd( 80):NTERFACE='ipsec0' > PLUTO_NEXT_HOP='10.2.128.240' PLUTO_ME='10.0.0.1' PLUTO_MY_ID=: > Jun 15 03:34:13: | cmd( 160):'10.2.128.241' PLUTO_MY_CLIENT='0.0.0.0/0' > PLUTO_MY_CLIENT_NET='0.0.0.0' PLUTO_M: > Jun 15 03:34:13: | cmd( 240):Y_CLIENT_MASK='0.0.0.0' PLUTO_MY_PORT='0' > PLUTO_MY_PROTOCOL='0' PLUTO_SA_REQID=': > Jun 15 03:34:13: | cmd( 320):16388' PLUTO_SA_TYPE='ESP' > PLUTO_PEER='10.2.128.240' PLUTO_PEER_ID='10.2.128.240: > Jun 15 03:34:13: | cmd( 400):' PLUTO_PEER_CLIENT='0.0.0.0/0' > PLUTO_PEER_CLIENT_NET='0.0.0.0' PLUTO_PEER_CLIEN: > Jun 15 03:34:13: | cmd( 480):T_MASK='0.0.0.0' PLUTO_PEER_PORT='0' > PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PL: > Jun 15 03:34:13: | cmd( 560):UTO_STACK='klips' PLUTO_ADDTIME='0' > PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+PFS+UP: > Jun 15 03:34:13: | cmd( > 640):+IKEV1_ALLOW+IKEV2_ALLOW+SAREF_TRACK+IKE_FRAG_ALLOW+ESN_NO' > PLUTO_CONN_ADDRFAMIL: > Jun 15 03:34:13: | cmd( 720):Y='ipv4' XAUTH_FAILED=0 > PLUTO_IS_PEER_CISCO='0' PLUTO_PEER_DNS_INFO='' PLUTO_PEE: > Jun 15 03:34:13: | cmd( 800):R_DOMAIN_INFO='' PLUTO_PEER_BANNER='' > PLUTO_NM_CONFIGURED='0' /var/run/updown.kl: > Jun 15 03:34:13: | cmd( 880):ips: > Jun 15 03:34:13: "vpn-0" #2: up-client output: /var/run/updown.klips: 12: > exec: /usr/local/libexec/ipsec/_updown.klips: not found > Jun 15 03:34:13: "vpn-0" #2: up-client command exited with status 127 > Jun 15 03:34:13: | route_and_eroute: firewall_notified: false > Jun 15 03:34:13: "vpn-0" #2: ASSERTION FAILED at > /home/htsai/src/libreswan/programs/pluto/kernel.c:3038: esr != NULL > Jun 15 03:34:13: "vpn-0" #2: ABORT at > /home/htsai/src/libreswan/programs/pluto/kernel.c:3038 > "vpn-0" #2: ABORT at /home/htsai/src/libreswan/programs/pluto/kernel.c:3038 > Jun 15 03:34:13: NSS DB directory: sql:/etc/ipsec.d > Jun 15 03:34:14: NSS initialized > Jun 15 03:34:14: libcap-ng support [disabled] > > > Thanks, > Toby > > On Tue, Jun 14, 2016 at 4:24 PM, Paul Wouters <[email protected]> wrote: > >> On Tue, 14 Jun 2016, Ge Xu wrote: >> >> Sorry but you will have to find the real logs. If you do not know where >> those are, you can always enable logging to a file in ipsec.conf by >> adding: >> >> logfile=/tmp/pluto.log >> >> to the "config setup" section in /etc/ipsec.conf >> >> It looks to me perhaps one kernel does not support whatever ESP >> algorithm you picked, but I can only tell for sure with the logs. >> >> Paul >> >> Date: Tue, 14 Jun 2016 19:03:27 >>> From: Ge Xu <[email protected]> >>> Cc: [email protected] >>> To: Paul Wouters <[email protected]> >>> Subject: Re: [Swan] libreswan 3.17 NAT-T fails in phase2 >>> >>> >>> 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; >>> [email protected] [email protected] >>> [email protected] [email protected] 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" [email protected] [email protected] >>> [email protected] [email protected] 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 <[email protected]> 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 >>> >>> >>> > > > -- > Ge (Toby) Xu > -- Ge (Toby) Xu
_______________________________________________ Swan mailing list [email protected] https://lists.libreswan.org/mailman/listinfo/swan
