[Swan] libreswan version 3.20: IPv4 transport mode behind NAT cannot work

Hao Chen earthlovepython at outlook.com
Wed Oct 18 06:03:32 UTC 2017


Hi All:

Good evening!

I am trying to set up IPSec between 2 local machines which are all behind NAT. But no luck.
"Responder" stuck in "STATE_V2_IPSEC_R". It complain "packet from 10.0.161.34:4500: sending unencrypted notification v2N_INVALID_IKE_SPI to 10.0.161.34:4500"
"Initiator" stuck in "STATE_V2_IPSEC_R". It complain "packet from 10.0.146.196:4500: missing payload(s) (ISAKMP_NEXT_v2SK). Message dropped."

Can you please give me a hand?  Following is detailed information




The network topology :
====================================
172.16.0.195(private IP on eth1) ----- [172.16.0.196(private IP on eth1),10.0.146.196(public IP on eth0)] <=========> [10.0.161.34(public IP on eth1),192.168.0.34(private IP on eth1)] ----- 192.168.0.35(private ip on eth1)




configuration on 172.16.0.195 is:
====================================
conn ipv4tran35_195
  ike=aes256-md5;modp1536
  authby=secret
  aggrmode=no
  ikelifetime=14409s
  ikev2=yes
  phase2=esp
  type=transport
  pfs=yes
  rekey=yes
  rekeymargin=540s
  phase2alg=3des,aes256-md5;modp1536
  salifetime=3600s
  #local
  left=172.16.0.195
  leftsubnet=172.16.0.0/12
  #right
  right=10.0.161.34
  rightsubnet=192.168.0.0/24
  rightsourceip=192.168.0.35
  auto=start


configuration on 192.168.0.35 is:
====================================
conn ipv4tran35_195
  ike=aes256-md5;modp1536
  authby=secret
  aggrmode=no
  ikelifetime=14409s
  ikev2=yes
  phase2=esp
  type=transport
  pfs=yes
  rekey=yes
  rekeymargin=540s
  phase2alg=3des,aes256-md5;modp1536
  salifetime=3600s
  ## local
  left=192.168.0.35
  leftsubnet=192.168.0.0/24
  # remote
  right=10.0.146.196
  rightsubnet=172.16.0.0/12
  rightsourceip=172.16.0.195
  auto=start


/etc/ipsec.conf on boths sides is:
==================================
[root at qa161-35 ~]# more /etc/ipsec.conf
config setup
        protostack=netkey
        plutodebug="controlmore"
        plutostderrlog=/var/log/pluto.log
        dumpdir=/var/run/pluto/
        nat_traversal=yes
        virtual_private=%v4:10.0.0.0/8,%v4:192.168.0.0/24,%v4:172.16.0.0/12,%v4:25.0.0.0/8,%v4:100.64.0.0/10,%v6:fd00::/8,%v6:fe80::/10
include /etc/ipsec.d/*.conf
include /etc/ipsec.d/configs/*.conf

The /var/log/pluto.log on "responder" shows:
====================================
Oct 17 15:10:04: packet from 10.0.161.34:500: proposal 1:IKE:ENCR=AES_CBC_256;PRF=HMAC_MD5;INTEG=HMAC_MD5_96;DH=MODP1536 chosen from: 1:IKE:ENCR=AES_CBC_256;PRF=HMAC_MD5;INTEG=HMAC_MD5_96;DH=MODP1536[first-match]
Oct 17 15:10:04: | parent state #15: new => STATE_UNDEFINED(ignore)
Oct 17 15:10:04: | processing connection "ipv4tran35_195"
Oct 17 15:10:04: | processing connection "ipv4tran35_195"
Oct 17 15:10:04: | parent state #15: STATE_UNDEFINED(ignore) => STATE_PARENT_R1(half-open-ike)
Oct 17 15:10:04: | ignore states: 0
Oct 17 15:10:04: | half-open-ike states: 1
Oct 17 15:10:04: | open-ike states: 0
Oct 17 15:10:04: | established-anonymous-ike states: 0
Oct 17 15:10:04: | established-authenticated-ike states: 0
Oct 17 15:10:04: | anonymous-ipsec states: 0
Oct 17 15:10:04: | authenticated-ipsec states: 0
Oct 17 15:10:04: | informational states: 0
Oct 17 15:10:04: | unknown states: 0
Oct 17 15:10:04: | category states: 1 count states: 1
Oct 17 15:10:04: | #15 send_crypto_helper_request:642 st->st_calculating = TRUE;
Oct 17 15:10:04: | state #15 requesting EVENT_SO_DISCARD to be deleted
Oct 17 15:10:04: | processing connection "ipv4tran35_195"
Oct 17 15:10:04: | #15 ikev2_parent_inI1outR1_continue:1307 st->st_calculating = FALSE;
Oct 17 15:10:04: | Adding a v2N Payload
Oct 17 15:10:04: | Adding a v2N Payload
Oct 17 15:10:04: | Adding a v2N Payload
Oct 17 15:10:04: | no IKE message padding required for IKEv2
Oct 17 15:10:04: | parent state #15: STATE_PARENT_R1(half-open-ike) => STATE_PARENT_R1(half-open-ike)
Oct 17 15:10:04: | ignore states: 0
Oct 17 15:10:04: | half-open-ike states: 1
Oct 17 15:10:04: | open-ike states: 0
Oct 17 15:10:04: | established-anonymous-ike states: 0
Oct 17 15:10:04: | established-authenticated-ike states: 0
Oct 17 15:10:04: | anonymous-ipsec states: 0
Oct 17 15:10:04: | authenticated-ipsec states: 0
Oct 17 15:10:04: | informational states: 0
Oct 17 15:10:04: | unknown states: 0
Oct 17 15:10:04: | category states: 1 count states: 1
Oct 17 15:10:04: | message ID #15 STATE_PARENT_R1 ipv4tran35_195 pst #15 st_msgid_nextuse(before=0) 0 st_msgid_lastack 4294967295 st_msgid_lastrecv 0
Oct 17 15:10:04: "ipv4tran35_195" #15: STATE_PARENT_R1: received v2I1, sent v2R1 {auth=IKEv2 cipher=aes_256 integ=md5_96 prf=md5 group=MODP1536}
Oct 17 15:10:04: | state #15 requesting EVENT_CRYPTO_FAILED to be deleted
Oct 17 15:10:04: | processing connection "ipv4tran35_195"
Oct 17 15:10:04: | processing connection "ipv4tran35_195"
Oct 17 15:10:04: | #15 state_busy:2531 st != NULL && st->st_calculating == FALSE;
Oct 17 15:10:04: | processing connection "ipv4tran35_195"
Oct 17 15:10:04: "ipv4tran35_195" #15: new NAT mapping for #15, was 10.0.161.34:500, now 10.0.161.34:4500
Oct 17 15:10:04: | ikev2 parent inI2outR2: calculating g^{xy} in order to decrypt I2
Oct 17 15:10:04: | calculating skeyseed using prf=PRF_HMAC_MD5 integ=AUTH_HMAC_MD5_96 cipherkey=AES_CBC
Oct 17 15:10:04: | #15 send_crypto_helper_request:642 st->st_calculating = TRUE;
Oct 17 15:10:04: | state #15 requesting EVENT_v2_RESPONDER_TIMEOUT to be deleted
Oct 17 15:10:04: | calculating skeyseed using prf=md5 integ=md5 cipherkey-size=32 salt-size=0
Oct 17 15:10:04: | processing connection "ipv4tran35_195"
Oct 17 15:10:04: | #15 ikev2_parent_inI2outR2_continue:3371 st->st_calculating = FALSE;
Oct 17 15:10:04: | #15 ikev2 ISAKMP_v2_AUTH decrypt sucess
Oct 17 15:10:04: | #15 match encrypted payloads to svm respond to IKE_AUTH
Oct 17 15:10:04: | refine_host_connection for IKEv2: starting with "ipv4tran35_195"
Oct 17 15:10:04: |    match_id a=192.168.0.35
Oct 17 15:10:04: |             b=10.0.161.34
Oct 17 15:10:04: |    results  fail
Oct 17 15:10:04: | trusted_ca_nss: trustee A = '(empty)'
Oct 17 15:10:04: | trusted_ca_nss: trustor B = '(empty)'
Oct 17 15:10:04: | refine_host_connection: checking "ipv4tran35_195" against "ipv4tran35_195", best=(none) with match=0(id=0/ca=1/reqca=1)
Oct 17 15:10:04: | find_host_pair: comparing 172.16.0.195:500 to 10.0.161.34:500
Oct 17 15:10:04: | find_host_pair: comparing ::1:500 to :::500
Oct 17 15:10:04: "ipv4tran35_195" #15: EXPECTATION FAILED: r != NULL (in ikev2_decode_peer_id_and_certs at ikev2.c:1390)
Oct 17 15:10:04: "ipv4tran35_195" #15: IKEv2 mode peer ID is ID_IPV4_ADDR: '192.168.0.35'
Oct 17 15:10:04: | line 1: key type PPK_PSK(172.16.0.195) to type PPK_PSK
Oct 17 15:10:04: | parent state #15: STATE_PARENT_R1(half-open-ike) => STATE_PARENT_R2(established-authenticated-ike)
Oct 17 15:10:04: | ignore states: 0
Oct 17 15:10:04: | half-open-ike states: 0
Oct 17 15:10:04: | open-ike states: 0
Oct 17 15:10:04: | established-anonymous-ike states: 0
Oct 17 15:10:04: | established-authenticated-ike states: 1
Oct 17 15:10:04: | anonymous-ipsec states: 0
Oct 17 15:10:04: | authenticated-ipsec states: 0
Oct 17 15:10:04: | informational states: 0
Oct 17 15:10:04: | unknown states: 0
Oct 17 15:10:04: | category states: 1 count states: 1
Oct 17 15:10:04: | state #15 requesting EVENT_CRYPTO_FAILED to be deleted
Oct 17 15:10:04: | assembled IDr payload
Oct 17 15:10:04: | CHILD SA proposals received
Oct 17 15:10:04: | going to assemble AUTH payload
Oct 17 15:10:04: | line 1: key type PPK_PSK(172.16.0.195) to type PPK_PSK
Oct 17 15:10:04: |   ikev2_evaluate_connection_fit evaluating our conn="ipv4tran35_195" I=192.168.0.0/24:0/0 R=172.16.0.0/12:0/0  to their:
Oct 17 15:10:04: |     tsi[0]=192.168.0.0/192.168.0.255 proto=0 portrange 0-65535, tsr[0]=172.16.0.0/172.31.255.255 proto=0 portrange 0-65535
Oct 17 15:10:04: |       has ts_range1=8 maskbits1=24 ts_range2=20 maskbits2=12 fitbits=8224 <> -1
Oct 17 15:10:04: | prefix fitness found a better match c ipv4tran35_195
Oct 17 15:10:04: | port fitness found better match c ipv4tran35_195, tsi[0],tsr[0]
Oct 17 15:10:04: | protocol fitness found better match c ipv4tran35_195, tsi[0],tsr[0]
Oct 17 15:10:04: | find_host_pair: comparing 172.16.0.195:500 to 10.0.161.34:500
Oct 17 15:10:04: |   checking hostpair 172.16.0.0/12 -> 192.168.0.0/24 is found
Oct 17 15:10:04: |    match_id a=10.0.161.34
Oct 17 15:10:04: |             b=10.0.161.34
Oct 17 15:10:04: |    results  matched
Oct 17 15:10:04: | trusted_ca_nss: trustee A = '(empty)'
Oct 17 15:10:04: | trusted_ca_nss: trustor B = '(empty)'
Oct 17 15:10:04: |   ikev2_evaluate_connection_fit evaluating our conn="ipv4tran35_195" I=192.168.0.0/24:0/0 R=172.16.0.0/12:0/0  to their:
Oct 17 15:10:04: |     tsi[0]=192.168.0.0/192.168.0.255 proto=0 portrange 0-65535, tsr[0]=172.16.0.0/172.31.255.255 proto=0 portrange 0-65535
Oct 17 15:10:04: |       has ts_range1=8 maskbits1=24 ts_range2=20 maskbits2=12 fitbits=8224 <> -1
Oct 17 15:10:04: | prefix fitness rejected d ipv4tran35_195
Oct 17 15:10:04: | parent state #16: new => STATE_UNDEFINED(ignore)
Oct 17 15:10:04: | printing contents struct traffic_selector
Oct 17 15:10:04: |   ts_type: IKEv2_TS_IPV4_ADDR_RANGE
Oct 17 15:10:04: |   ipprotoid: 0
Oct 17 15:10:04: |   startport: 0
Oct 17 15:10:04: |   endport: 65535
Oct 17 15:10:04: |   ip low: 172.16.0.0
Oct 17 15:10:04: |   ip high: 172.31.255.255
Oct 17 15:10:04: | printing contents struct traffic_selector
Oct 17 15:10:04: |   ts_type: IKEv2_TS_IPV4_ADDR_RANGE
Oct 17 15:10:04: |   ipprotoid: 0
Oct 17 15:10:04: |   startport: 0
Oct 17 15:10:04: |   endport: 65535
Oct 17 15:10:04: |   ip low: 192.168.0.0
Oct 17 15:10:04: |   ip high: 192.168.0.255
Oct 17 15:10:04: | local proposal 1 type ENCR has 1 transforms
Oct 17 15:10:04: | local proposal 1 type PRF has 0 transforms
Oct 17 15:10:04: | local proposal 1 type INTEG has 1 transforms
Oct 17 15:10:04: | local proposal 1 type DH has 0 transforms
Oct 17 15:10:04: | local proposal 1 type ESN has 1 transforms
Oct 17 15:10:04: | local proposal 1 transforms: required: ENCR+INTEG+ESN; optional: none
Oct 17 15:10:04: | local proposal 2 type ENCR has 1 transforms
Oct 17 15:10:04: | local proposal 2 type PRF has 0 transforms
Oct 17 15:10:04: | local proposal 2 type INTEG has 1 transforms
Oct 17 15:10:04: | local proposal 2 type DH has 0 transforms
Oct 17 15:10:04: | local proposal 2 type ESN has 1 transforms
Oct 17 15:10:04: | local proposal 2 transforms: required: ENCR+INTEG+ESN; optional: none
Oct 17 15:10:04: | local proposal 3 type ENCR has 1 transforms
Oct 17 15:10:04: | local proposal 3 type PRF has 0 transforms
Oct 17 15:10:04: | local proposal 3 type INTEG has 1 transforms
Oct 17 15:10:04: | local proposal 3 type DH has 0 transforms
Oct 17 15:10:04: | local proposal 3 type ESN has 1 transforms
Oct 17 15:10:04: | local proposal 3 transforms: required: ENCR+INTEG+ESN; optional: none
Oct 17 15:10:04: | remote proposal 1 transform 0 (ENCR=3DES) matches local proposal 1 type 1 (ENCR) transform 0
Oct 17 15:10:04: | remote proposal 1 transform 0 (ENCR=3DES) matches local proposal 2 type 1 (ENCR) transform 0
Oct 17 15:10:04: | remote proposal 1 transform 1 (INTEG=HMAC_MD5_96) matches local proposal 1 type 3 (INTEG) transform 0
Oct 17 15:10:04: | remote proposal 1 transform 1 (INTEG=HMAC_MD5_96) matches local proposal 3 type 3 (INTEG) transform 0
Oct 17 15:10:04: | remote proposal 1 transform 2 (ESN=DISABLED) matches local proposal 1 type 5 (ESN) transform 0
Oct 17 15:10:04: | remote proposal 1 transform 2 (ESN=DISABLED) matches local proposal 2 type 5 (ESN) transform 0
Oct 17 15:10:04: | remote proposal 1 transform 2 (ESN=DISABLED) matches local proposal 3 type 5 (ESN) transform 0
Oct 17 15:10:04: | remote proposal 1 proposed transforms: ENCR+INTEG+ESN; matched: ENCR+INTEG+ESN; unmatched: none
Oct 17 15:10:04: | comparing remote proposal 1 and local proposal 1 transforms: required: ENCR+INTEG+ESN; optional: none; proposed: ENCR+INTEG+ESN; matched: ENCR+INTEG+ESN
Oct 17 15:10:04: | remote proposal 2 proposed transforms: ENCR+INTEG+ESN; matched: none; unmatched: ENCR+INTEG+ESN
Oct 17 15:10:04: | remote proposal 3 proposed transforms: ENCR+INTEG+ESN; matched: none; unmatched: ENCR+INTEG+ESN
Oct 17 15:10:04: "ipv4tran35_195" #15: proposal 1:ESP:SPI=77f0deb4;ENCR=3DES;INTEG=HMAC_MD5_96;ESN=DISABLED chosen from: 1:ESP:ENCR=3DES;INTEG=HMAC_MD5_96;ESN=DISABLED[first-match] 2:ESP:ENCR=3DES;INTEG=HMAC_SHA1_96;ESN=DISABLED 3:ESP:ENCR=AES_CBC_256;INTEG=HMAC_MD5_96;ESN=DISABLED
Oct 17 15:10:04: | Adding a v2N Payload
Oct 17 15:10:04: | route_and_eroute with c: ipv4tran35_195 (next: none) ero:ipv4tran35_195 esr:{(nil)} ro:ipv4tran35_195 rosr:{(nil)} and state: #16
Oct 17 15:10:04: | ISAKMP_v2_AUTH: instance ipv4tran35_195[0], setting IKEv2 newest_ipsec_sa to #16 (was #0) (spd.eroute=#16) cloned from #15
Oct 17 15:10:04: | child state #16: STATE_UNDEFINED(ignore) => STATE_V2_IPSEC_R(authenticated-ipsec)
Oct 17 15:10:04: | ignore states: 0
Oct 17 15:10:04: | half-open-ike states: 0
Oct 17 15:10:04: | open-ike states: 0
Oct 17 15:10:04: | established-anonymous-ike states: 0
Oct 17 15:10:04: | established-authenticated-ike states: 1
Oct 17 15:10:04: | anonymous-ipsec states: 0
Oct 17 15:10:04: | authenticated-ipsec states: 1
Oct 17 15:10:04: | informational states: 0
Oct 17 15:10:04: | unknown states: 0
Oct 17 15:10:04: | category states: 2 count states: 2
Oct 17 15:10:04: | message ID #16 STATE_V2_IPSEC_R ipv4tran35_195 pst #15 st_msgid_nextuse(before=0) 0 st_msgid_lastack 4294967295 st_msgid_lastrecv 1
Oct 17 15:10:04: "ipv4tran35_195" #16: negotiated connection [172.16.0.0,172.31.255.255:0-65535 0] -> [192.168.0.0,192.168.0.255:0-65535 0]
Oct 17 15:10:04: "ipv4tran35_195" #16: STATE_V2_IPSEC_R: IPsec SA established transport mode {ESP/NAT=>0x77f0deb4 <0x2a7159dd xfrm=3DES_192-HMAC_MD5 NATOA=none NATD=10.0.161.34:4500 DPD=passive}
Oct 17 15:10:04: | state #16 requesting EVENT_SO_DISCARD to be deleted
Oct 17 15:10:05: | processing connection "ipv4tran35_195"
Oct 17 15:10:05: | processing connection "ipv4tran35_195"
Oct 17 15:10:06: | processing connection "ipv4tran35_195"
Oct 17 15:10:08: | processing connection "ipv4tran35_195"
Oct 17 15:10:12: | processing connection "ipv4tran35_195"
Oct 17 15:10:20: | processing connection "ipv4tran35_195"
Oct 17 15:10:36: | processing connection "ipv4tran35_195"
Oct 17 15:14:34: packet from 10.0.161.34:4500: sending unencrypted notification v2N_INVALID_IKE_SPI to 10.0.161.34:4500
Oct 17 15:14:34: | Adding a v2N Payload
Oct 17 15:14:34: | no IKEv1 message padding required
Oct 17 15:14:34: packet from 10.0.161.34:4500: sending unencrypted notification v2N_INVALID_IKE_SPI to 10.0.161.34:4500
Oct 17 15:14:34: | Adding a v2N Payload
Oct 17 15:14:34: | no IKEv1 message padding required


The /var/log/pluto.log on "initiator" shows:
====================================
Oct 17 22:31:21: | parent state #5: STATE_UNDEFINED(ignore) => STATE_PARENT_I1(half-open-ike)
Oct 17 22:31:21: | ignore states: 0
Oct 17 22:31:21: | half-open-ike states: 1
Oct 17 22:31:21: | open-ike states: 0
Oct 17 22:31:21: | established-anonymous-ike states: 0
Oct 17 22:31:21: | established-authenticated-ike states: 1
Oct 17 22:31:21: | anonymous-ipsec states: 0
Oct 17 22:31:21: | authenticated-ipsec states: 1
Oct 17 22:31:21: | informational states: 0
Oct 17 22:31:21: | unknown states: 0
Oct 17 22:31:21: | category states: 3 count states: 3
Oct 17 22:31:21: "ipv4tran35_195" #5: initiating v2 parent SA to replace #4
Oct 17 22:31:21: | #5 send_crypto_helper_request:642 st->st_calculating = TRUE;
Oct 17 22:31:21: | state #5 requesting EVENT_SO_DISCARD to be deleted
Oct 17 22:31:21: | delete_pluto_event cannot delete NULL event
Oct 17 22:31:21: | delete_pluto_event cannot delete NULL event
Oct 17 22:31:21: | processing connection "ipv4tran35_195"
Oct 17 22:31:21: | #5 ikev2_crypto_continue:254 st->st_calculating = FALSE;
Oct 17 22:31:21: | Adding a v2N Payload
Oct 17 22:31:21: | Adding a v2N Payload
Oct 17 22:31:21: | Adding a v2N Payload
Oct 17 22:31:21: | no IKE message padding required for IKEv2
Oct 17 22:31:21: | parent state #5: STATE_PARENT_I1(half-open-ike) => STATE_PARENT_I1(half-open-ike)
Oct 17 22:31:21: | ignore states: 0
Oct 17 22:31:21: | half-open-ike states: 1
Oct 17 22:31:21: | open-ike states: 0
Oct 17 22:31:21: | established-anonymous-ike states: 0
Oct 17 22:31:21: | established-authenticated-ike states: 1
Oct 17 22:31:21: | anonymous-ipsec states: 0
Oct 17 22:31:21: | authenticated-ipsec states: 1
Oct 17 22:31:21: | informational states: 0
Oct 17 22:31:21: | unknown states: 0
Oct 17 22:31:21: | category states: 3 count states: 3
Oct 17 22:31:21: | message ID #5 STATE_PARENT_I1 ipv4tran35_195 pst #5 st_msgid_nextuse(before=0) 1 st_msgid_lastack 4294967295 st_msgid_lastrecv 4294967295
Oct 17 22:31:21: "ipv4tran35_195" #5: STATE_PARENT_I1: sent v2I1, expected v2R1
Oct 17 22:31:21: | state #5 requesting EVENT_CRYPTO_FAILED to be deleted
Oct 17 22:31:21: | processing connection "ipv4tran35_195"
Oct 17 22:31:21: | processing connection "ipv4tran35_195"
Oct 17 22:31:21: | #5 state_busy:2531 st != NULL && st->st_calculating == FALSE;
Oct 17 22:31:21: | ikev2 parent inR1: calculating g^{xy} in order to send I2
Oct 17 22:31:21: | local proposal 1 type ENCR has 1 transforms
Oct 17 22:31:21: | local proposal 1 type PRF has 1 transforms
Oct 17 22:31:21: | local proposal 1 type INTEG has 1 transforms
Oct 17 22:31:21: | local proposal 1 type DH has 1 transforms
Oct 17 22:31:21: | local proposal 1 type ESN has 0 transforms
Oct 17 22:31:21: | local proposal 1 transforms: required: ENCR+PRF+INTEG+DH; optional: none
Oct 17 22:31:21: | remote proposal 1 transform 0 (ENCR=AES_CBC_256) matches local proposal 1 type 1 (ENCR) transform 0
Oct 17 22:31:21: | remote proposal 1 transform 1 (PRF=HMAC_MD5) matches local proposal 1 type 2 (PRF) transform 0
Oct 17 22:31:21: | remote proposal 1 transform 2 (INTEG=HMAC_MD5_96) matches local proposal 1 type 3 (INTEG) transform 0
Oct 17 22:31:21: | remote proposal 1 transform 3 (DH=MODP1536) matches local proposal 1 type 4 (DH) transform 0
Oct 17 22:31:21: | remote proposal 1 proposed transforms: ENCR+PRF+INTEG+DH; matched: ENCR+PRF+INTEG+DH; unmatched: none
Oct 17 22:31:21: | comparing remote proposal 1 and local proposal 1 transforms: required: ENCR+PRF+INTEG+DH; optional: none; proposed: ENCR+PRF+INTEG+DH; matched: ENCR+PRF+INTEG+DH
Oct 17 22:31:21: | message ID #5 STATE_PARENT_I1 ipv4tran35_195 pst #5 st_msgid_nextuse(before=1) 1 st_msgid_lastack 0 st_msgid_lastrecv 4294967295
Oct 17 22:31:21: | calculating skeyseed using prf=PRF_HMAC_MD5 integ=AUTH_HMAC_MD5_96 cipherkey=AES_CBC
Oct 17 22:31:21: | #5 send_crypto_helper_request:642 st->st_calculating = TRUE;
Oct 17 22:31:21: | state #5 requesting EVENT_v2_RETRANSMIT to be deleted
Oct 17 22:31:21: | calculating skeyseed using prf=md5 integ=md5 cipherkey-size=32 salt-size=0
Oct 17 22:31:21: | processing connection "ipv4tran35_195"
Oct 17 22:31:21: | #5 ikev2_parent_inR1outI2_continue:1867 st->st_calculating = FALSE;
Oct 17 22:31:21: | parent state #6: new => STATE_UNDEFINED(ignore)
Oct 17 22:31:21: | state #5 requesting EVENT_CRYPTO_FAILED to be deleted
Oct 17 22:31:21: | parent state #5: STATE_PARENT_I1(half-open-ike) => STATE_PARENT_I2(open-ike)
Oct 17 22:31:21: | ignore states: 0
Oct 17 22:31:21: | half-open-ike states: 0
Oct 17 22:31:21: | open-ike states: 1
Oct 17 22:31:21: | established-anonymous-ike states: 0
Oct 17 22:31:21: | established-authenticated-ike states: 1
Oct 17 22:31:21: | anonymous-ipsec states: 0
Oct 17 22:31:21: | authenticated-ipsec states: 1
Oct 17 22:31:21: | informational states: 0
Oct 17 22:31:21: | unknown states: 0
Oct 17 22:31:21: | category states: 3 count states: 3
Oct 17 22:31:21: | line 1: key type PPK_PSK(192.168.0.35) to type PPK_PSK
Oct 17 22:31:21: | Adding a v2N Payload
Oct 17 22:31:21: | child state #6: STATE_UNDEFINED(ignore) => STATE_PARENT_I2(open-ike)
Oct 17 22:31:21: | ignore states: 0
Oct 17 22:31:21: | half-open-ike states: 0
Oct 17 22:31:21: | open-ike states: 2
Oct 17 22:31:21: | established-anonymous-ike states: 0
Oct 17 22:31:21: | established-authenticated-ike states: 1
Oct 17 22:31:21: | anonymous-ipsec states: 0
Oct 17 22:31:21: | authenticated-ipsec states: 1
Oct 17 22:31:21: | informational states: 0
Oct 17 22:31:21: | unknown states: 0
Oct 17 22:31:21: | category states: 4 count states: 4
Oct 17 22:31:21: | message ID #6 STATE_PARENT_I2 ipv4tran35_195 pst #5 st_msgid_nextuse(before=1) 2 st_msgid_lastack 0 st_msgid_lastrecv 4294967295
Oct 17 22:31:21: "ipv4tran35_195" #6: STATE_PARENT_I2: sent v2I2, expected v2R2 {auth=IKEv2 cipher=aes_256 integ=md5_96 prf=md5 group=MODP1536}
Oct 17 22:31:21: | state #6 requesting EVENT_SO_DISCARD to be deleted
Oct 17 22:31:21: | processing connection "ipv4tran35_195"
Oct 17 22:31:21: | processing connection "ipv4tran35_195"
Oct 17 22:31:21: | #6 state_busy:2531 st != NULL && st->st_calculating == FALSE;
Oct 17 22:31:21: | ikev2 parent inR2: calculating g^{xy} in order to decrypt I2
Oct 17 22:31:21: | #6 ikev2 ISAKMP_v2_AUTH decrypt sucess
Oct 17 22:31:21: | #6 match encrypted payloads to svm Initiator: process IKE_AUTH response
Oct 17 22:31:21: "ipv4tran35_195" #6: we require IKEv2 peer to have ID '10.0.146.196', but peer declares '172.16.0.195'
Oct 17 22:31:22: | processing connection "ipv4tran35_195"
Oct 17 22:31:22: | processing connection "ipv4tran35_195"
Oct 17 22:31:23: | processing connection "ipv4tran35_195"
Oct 17 22:31:25: | processing connection "ipv4tran35_195"
Oct 17 22:31:29: | processing connection "ipv4tran35_195"
Oct 17 22:31:37: | processing connection "ipv4tran35_195"
Oct 17 22:31:53: | processing connection "ipv4tran35_195"
Oct 17 22:32:21: | processing connection "ipv4tran35_195"
Oct 17 22:32:21: "ipv4tran35_195" #5: deleting other state #6 (STATE_PARENT_I2) "ipv4tran35_195"
Oct 17 22:32:21: | child state #6: STATE_PARENT_I2(open-ike) => delete
Oct 17 22:32:21: | delete_pluto_event cannot delete NULL event
Oct 17 22:32:21: | delete_pluto_event cannot delete NULL event
Oct 17 22:32:21: | delete_pluto_event cannot delete NULL event
Oct 17 22:32:21: | state #6 requesting EVENT_v2_RETRANSMIT to be deleted
Oct 17 22:32:21: | child state #6: STATE_PARENT_I2(open-ike) => STATE_UNDEFINED(ignore)
Oct 17 22:32:21: | ignore states: 0
Oct 17 22:32:21: | half-open-ike states: 0
Oct 17 22:32:21: | open-ike states: 1
Oct 17 22:32:21: | established-anonymous-ike states: 0
Oct 17 22:32:21: | established-authenticated-ike states: 1
Oct 17 22:32:21: | anonymous-ipsec states: 0
Oct 17 22:32:21: | authenticated-ipsec states: 1
Oct 17 22:32:21: | informational states: 0
Oct 17 22:32:21: | unknown states: 0
Oct 17 22:32:21: | category states: 3 count states: 3
Oct 17 22:32:21: "ipv4tran35_195" #5: deleting state (STATE_PARENT_I2)
Oct 17 22:32:21: | parent state #5: STATE_PARENT_I2(open-ike) => delete
Oct 17 22:32:21: | delete_pluto_event cannot delete NULL event
Oct 17 22:32:21: | delete_pluto_event cannot delete NULL event
Oct 17 22:32:21: | delete_pluto_event cannot delete NULL event
Oct 17 22:32:21: | state #5 requesting to delete non existing event
Oct 17 22:32:21: | parent state #5: STATE_PARENT_I2(open-ike) => STATE_UNDEFINED(ignore)
Oct 17 22:32:21: | ignore states: 0
Oct 17 22:32:21: | half-open-ike states: 0
Oct 17 22:32:21: | open-ike states: 0
Oct 17 22:32:21: | established-anonymous-ike states: 0
Oct 17 22:32:21: | established-authenticated-ike states: 1
Oct 17 22:32:21: | anonymous-ipsec states: 0
Oct 17 22:32:21: | authenticated-ipsec states: 1
Oct 17 22:32:21: | informational states: 0
Oct 17 22:32:21: | unknown states: 0
Oct 17 22:32:21: | category states: 2 count states: 2
Oct 17 22:35:51: | processing connection "ipv4tran35_195"
Oct 17 22:35:51: "ipv4tran35_195" #4: deleting state (STATE_V2_IPSEC_R)
Oct 17 22:35:51: | child state #4: STATE_V2_IPSEC_R(authenticated-ipsec) => delete
Oct 17 22:35:51: "ipv4tran35_195" #4: ESP traffic information: in=0B out=0B
Oct 17 22:35:51: | delete_pluto_event cannot delete NULL event
Oct 17 22:35:51: | delete_pluto_event cannot delete NULL event
Oct 17 22:35:51: | delete_pluto_event cannot delete NULL event
Oct 17 22:35:51: | state #4 requesting to delete non existing event
Oct 17 22:35:51: | child state #4: STATE_V2_IPSEC_R(authenticated-ipsec) => STATE_UNDEFINED(ignore)
Oct 17 22:35:51: | ignore states: 0
Oct 17 22:35:51: | half-open-ike states: 0
Oct 17 22:35:51: | open-ike states: 0
Oct 17 22:35:51: | established-anonymous-ike states: 0
Oct 17 22:35:51: | established-authenticated-ike states: 1
Oct 17 22:35:51: | anonymous-ipsec states: 0
Oct 17 22:35:51: | authenticated-ipsec states: 0
Oct 17 22:35:51: | informational states: 0
Oct 17 22:35:51: | unknown states: 0
Oct 17 22:35:51: | category states: 1 count states: 1
Oct 17 22:35:51: expire unused parent SA #3 "ipv4tran35_195"
Oct 17 22:35:51: | state #3 requesting EVENT_SA_REPLACE to be deleted
Oct 17 22:35:51: packet from 10.0.146.196:4500: missing payload(s) (ISAKMP_NEXT_v2SK). Message dropped.
Oct 17 22:35:51: packet from 10.0.146.196:4500: Received v2N_INVALID_IKE_SPI notify
Oct 17 22:35:51: | processing connection "ipv4tran35_195"
Oct 17 22:35:51: "ipv4tran35_195" #3: ISAKMP SA expired (LATEST!)
Oct 17 22:35:51: "ipv4tran35_195" #3: deleting state (STATE_PARENT_R2)
Oct 17 22:35:51: | parent state #3: STATE_PARENT_R2(established-authenticated-ike) => delete
Oct 17 22:35:51: | delete_pluto_event cannot delete NULL event
Oct 17 22:35:51: | delete_pluto_event cannot delete NULL event
Oct 17 22:35:51: | delete_pluto_event cannot delete NULL event
Oct 17 22:35:51: | state #3 requesting to delete non existing event
Oct 17 22:35:51: | parent state #3: STATE_PARENT_R2(established-authenticated-ike) => STATE_UNDEFINED(ignore)
Oct 17 22:35:51: | ignore states: 0
Oct 17 22:35:51: | half-open-ike states: 0
Oct 17 22:35:51: | open-ike states: 0
Oct 17 22:35:51: | established-anonymous-ike states: 0
Oct 17 22:35:51: | established-authenticated-ike states: 0
Oct 17 22:35:51: | anonymous-ipsec states: 0
Oct 17 22:35:51: | authenticated-ipsec states: 0
Oct 17 22:35:51: | informational states: 0
Oct 17 22:35:51: | unknown states: 0
Oct 17 22:35:51: | category states: 0 count states: 0


-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.libreswan.org/pipermail/swan/attachments/20171018/108d3cbe/attachment-0001.html>


More information about the Swan mailing list