Discussion:
[Swan] Multiple Child IPsec SA Connections Established
Benjamin Doerr
2017-08-30 19:47:38 UTC
Permalink
Hello,

I'm working on updating from 3.18 to 3.21 on Centos6 and have a
situation when restarting ipsec across the cluster there almost always
ends up with one or two servers that are unable to connect to each
other. I've been working all day to try to understand what is going on
since there appears to be connections. It seems like there is a race
possibly with both sides set to "auto=start".

In our logs we see:

Aug 30 15:17:25 10.32.39.68 pluto[24416]: packet from 10.32.39.90:500:
discarding invalid packet: 8 octet payload length is not a multiple of
encryption block-size (16)

And here is the output of "ipsec auto --status" on 10.32.39.68 for
10.32.39.90 which I noticed has two SA connections. Our working
transport connections do not have two.

000 "10.32.39.90":
10.32.39.68<10.32.39.68>...10.32.39.90<10.32.39.90>; erouted; eroute
owner: #34
000 "10.32.39.90": oriented; my_ip=unset; their_ip=unset;
mycert=10.32.39.68 - Test
000 "10.32.39.90": xauth us:none, xauth them:none,
my_username=[any]; their_username=[any]
000 "10.32.39.90": our auth:rsasig, their auth:rsasig
000 "10.32.39.90": modecfg info: us:none, them:none, modecfg
policy:push, dns1:unset, dns2:unset, domain:unset, banner:unset,
cat:unset;
000 "10.32.39.90": labeled_ipsec:no;
000 "10.32.39.90": policy_label:unset;
000 "10.32.39.90": CAs: 'C=US, ST=North Carolina, L=Charlotte,
O=Testing, OU=SLA, OU=Devi Environment, CN=SLA Devi CA'...'%any'
000 "10.32.39.90": ike_life: 3600s; ipsec_life: 28800s;
replay_window: 32; rekey_margin: 540s; rekey_fuzz: 100%; keyingtries:
0;
000 "10.32.39.90": retransmit-interval: 500ms; retransmit-timeout: 60s;
000 "10.32.39.90": sha2-truncbug:no; initial-contact:no;
cisco-unity:no; fake-strongswan:no; send-vendorid:no;
send-no-esp-tfc:no;
000 "10.32.39.90": policy:
RSASIG+ENCRYPT+PFS+UP+IKEV2_ALLOW+IKEV2_PROPOSE+SAREF_TRACK+IKE_FRAG_ALLOW+ESN_NO;
000 "10.32.39.90": conn_prio: 32,32; interface: eth0; metric: 0;
mtu: 1500; sa_prio:auto; sa_tfc:none;
000 "10.32.39.90": nflog-group: unset; mark: unset;
vti-iface:unset; vti-routing:no; vti-shared:no; nic-offload:auto;
000 "10.32.39.90": our idtype: ID_IPV4_ADDR; our id=10.32.39.68;
their idtype: ID_IPV4_ADDR; their id:10.32.39.90
000 "10.32.39.90": dpd: action:restart; delay:30; timeout:30;
nat-t: encaps:auto; nat_keepalive:yes; ikev1_natt:both
000 "10.32.39.90": newest ISAKMP SA: #32; newest IPsec SA: #34;
000 "10.32.39.90": IKE algorithms wanted:
AES_CBC(7)_256-SHA2_256(4)-MODP2048(14)
000 "10.32.39.90": IKE algorithms found:
AES_CBC(7)_256-SHA2_256(4)-MODP2048(14)
000 "10.32.39.90": IKEv2 algorithm newest:
AES_CBC_256-AUTH_HMAC_SHA2_256_128-PRF_HMAC_SHA2_256-MODP2048
000 "10.32.39.90": ESP algorithms wanted: AES_GCM_C(20)_128-NONE(0)
000 "10.32.39.90": ESP algorithms loaded: AES_GCM_C(20)_128-NONE(0)
000 "10.32.39.90": ESP algorithm newest: AES_GCM_C_128-NONE;
pfsgroup=<Phase1>
000 #34: "10.32.39.90":500 STATE_V2_IPSEC_R (IPsec SA
established); EVENT_SA_REPLACE in 27124s; newest IPSEC; eroute owner;
isakmp#32; idle; import:admin initiate
000 #34: "10.32.39.90" ***@10.32.39.90
***@10.32.39.68 ref=0 refhim=0 Traffic: ESPin=0B ESPout=1KB!
ESPmax=0B
000 #33: "10.32.39.90":500 STATE_V2_IPSEC_I (IPsec SA
established); EVENT_SA_REPLACE in 26774s; isakmp#32; idle;
import:admin initiate
000 #33: "10.32.39.90" ***@10.32.39.90
***@10.32.39.68 ref=0 refhim=0 Traffic: ESPin=0B ESPout=0B!
ESPmax=0B
000 #32: "10.32.39.90":500 STATE_PARENT_I3 (PARENT SA
established); EVENT_SA_REPLACE in 1934s; newest ISAKMP; isakmp#0;
idle; import:admin initiate
000 #32: "10.32.39.90" ref=0 refhim=0 Traffic:

Output of "ipsec auto --status" on 10.32.39.90 for 10.32.39.68 shows
the same two SA connections.

000 "10.32.39.68":
10.32.39.90<10.32.39.90>...10.32.39.68<10.32.39.68>; erouted; eroute
owner: #24
000 "10.32.39.68": oriented; my_ip=unset; their_ip=unset;
mycert=10.32.39.90 - Test
000 "10.32.39.68": xauth us:none, xauth them:none,
my_username=[any]; their_username=[any]
000 "10.32.39.68": our auth:rsasig, their auth:rsasig
000 "10.32.39.68": modecfg info: us:none, them:none, modecfg
policy:push, dns1:unset, dns2:unset, domain:unset, banner:unset,
cat:unset;
000 "10.32.39.68": labeled_ipsec:no;
000 "10.32.39.68": policy_label:unset;
000 "10.32.39.68": CAs: 'C=US, ST=North Carolina, L=Charlotte,
O=Testing, OU=SLA, OU=Devi Environment, CN=SLA Devi CA'...'%any'
000 "10.32.39.68": ike_life: 3600s; ipsec_life: 28800s;
replay_window: 32; rekey_margin: 540s; rekey_fuzz: 100%; keyingtries:
0;
000 "10.32.39.68": retransmit-interval: 500ms; retransmit-timeout: 60s;
000 "10.32.39.68": sha2-truncbug:no; initial-contact:no;
cisco-unity:no; fake-strongswan:no; send-vendorid:no;
send-no-esp-tfc:no;
000 "10.32.39.68": policy:
RSASIG+ENCRYPT+PFS+UP+IKEV2_ALLOW+IKEV2_PROPOSE+SAREF_TRACK+IKE_FRAG_ALLOW+ESN_NO;
000 "10.32.39.68": conn_prio: 32,32; interface: eth0; metric: 0;
mtu: 1500; sa_prio:auto; sa_tfc:none;
000 "10.32.39.68": nflog-group: unset; mark: unset;
vti-iface:unset; vti-routing:no; vti-shared:no; nic-offload:auto;
000 "10.32.39.68": our idtype: ID_IPV4_ADDR; our id=10.32.39.90;
their idtype: ID_IPV4_ADDR; their id:10.32.39.68
000 "10.32.39.68": dpd: action:restart; delay:30; timeout:30;
nat-t: encaps:auto; nat_keepalive:yes; ikev1_natt:both
000 "10.32.39.68": newest ISAKMP SA: #4; newest IPsec SA: #24;
000 "10.32.39.68": IKE algorithms wanted:
AES_CBC(7)_256-SHA2_256(4)-MODP2048(14)
000 "10.32.39.68": IKE algorithms found:
AES_CBC(7)_256-SHA2_256(4)-MODP2048(14)
000 "10.32.39.68": IKEv2 algorithm newest:
AES_CBC_256-AUTH_HMAC_SHA2_256_128-PRF_HMAC_SHA2_256-MODP2048
000 "10.32.39.68": ESP algorithms wanted: AES_GCM_C(20)_128-NONE(0)
000 "10.32.39.68": ESP algorithms loaded: AES_GCM_C(20)_128-NONE(0)
000 "10.32.39.68": ESP algorithm newest: AES_GCM_C_128-NONE;
pfsgroup=<Phase1>
000 #24: "10.32.39.68":500 STATE_V2_IPSEC_I (IPsec SA
established); EVENT_SA_REPLACE in 26575s; newest IPSEC; eroute owner;
isakmp#4; idle; import:admin initiate
000 #24: "10.32.39.68" ***@10.32.39.68
***@10.32.39.90 ***@10.32.39.68 ***@10.32.39.90 ref=0
refhim=0 Traffic: ESPin=0B ESPout=468B! ESPmax=0B
000 #12: "10.32.39.68":500 STATE_V2_IPSEC_R (IPsec SA
established); EVENT_SA_REPLACE in 26575s; isakmp#4; idle;
import:respond to stranger
000 #12: "10.32.39.68" ***@10.32.39.68
***@10.32.39.90 ref=0 refhim=0 Traffic: ESPin=0B ESPout=0B!
ESPmax=0B
000 #4: "10.32.39.68":500 STATE_PARENT_R2 (received v2I2, PARENT
SA established); EVENT_SA_REPLACE in 1375s; newest ISAKMP; isakmp#0;
idle; import:admin initiate
000 #4: "10.32.39.68" ref=0 refhim=0 Traffic:

And corresponding ipsec.conf connections.

On 10.32.39.68

conn 10.32.39.90
type=transport
authby=rsasig
left=10.32.39.68
leftrsasigkey=%cert
leftcert="10.32.39.68 - Test"
right=10.32.39.90
rightrsasigkey=%cert
ike=aes256-sha2_256;modp2048
ikev2=insist
pfs=yes
phase2=esp
phase2alg=aes_gcm_c-128-null
mtu=1500
auto=start

And on nn 10.32.39.90

conn 10.32.39.86
type=transport
authby=rsasig
left=10.32.39.90
leftrsasigkey=%cert
leftcert="10.32.39.90 - Test"
right=10.32.39.86
rightrsasigkey=%cert
ike=aes256-sha2_256;modp2048
ikev2=insist
pfs=yes
phase2=esp
phase2alg=aes_gcm_c-128-null
mtu=1500
auto=start

If I go on one of those servers say 10.32.39.68, and run "ipsec auto
--down 10.32.39.90". Now the connection works, I assume when the other
side reconnects.

002 "10.32.39.90": terminating SAs using this connection
002 "10.32.39.90" #34: deleting state (STATE_V2_IPSEC_R) and
sending notification
005 "10.32.39.90" #34: ESP traffic information: in=1KB out=0B
002 "10.32.39.90" #33: deleting state (STATE_V2_IPSEC_I) and
sending notification
005 "10.32.39.90" #33: ESP traffic information: in=0B out=0B
002 "10.32.39.90" #32: deleting state (STATE_PARENT_I3) and
sending notification

What is going on here and is there any way that I can fix it?

Best Regards,
Benjamin Doerr
Benjamin Doerr
2017-09-05 17:27:28 UTC
Permalink
Hello,

Not sure if my first email was rejected by the list, sent it pretty soon
after subscribing. If this is a dup sorry.

I'm working on updating from 3.18 to 3.21 on Centos6 and have a situation
when restarting ipsec across the cluster there almost always ends up with
one or two servers that are unable to connect to each other. I've been
working all day to try to understand what is going on since there appears
to be connections. It seems like there is a race possibly with both sides
set to "auto=start".

In our logs we see:

Aug 30 15:17:25 10.32.39.68 pluto[24416]: packet from 10.32.39.90:500:
discarding invalid packet: 8 octet payload length is not a multiple of
encryption block-size (16)

And here is the output of "ipsec auto --status" on 10.32.39.68 for
10.32.39.90 which I noticed has two SA connections. Our working
transport connections do not have two.

000 "10.32.39.90": 10.32.39.68<10.32.39.68>...10.32.39.90<10.32.39.90>;
erouted; eroute owner: #34
000 "10.32.39.90": oriented; my_ip=unset; their_ip=unset;
mycert=10.32.39.68 - Test
000 "10.32.39.90": xauth us:none, xauth them:none, my_username=[any];
their_username=[any]
000 "10.32.39.90": our auth:rsasig, their auth:rsasig
000 "10.32.39.90": modecfg info: us:none, them:none, modecfg
policy:push, dns1:unset, dns2:unset, domain:unset, banner:unset, cat:unset;
000 "10.32.39.90": labeled_ipsec:no;
000 "10.32.39.90": policy_label:unset;
000 "10.32.39.90": CAs: 'C=US, ST=North Carolina, L=Charlotte,
O=Testing, OU=SLA, OU=Devi Environment, CN=SLA Devi CA'...'%any'
000 "10.32.39.90": ike_life: 3600s; ipsec_life: 28800s;
replay_window: 32; rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 0;
000 "10.32.39.90": retransmit-interval: 500ms; retransmit-timeout:
60s;
000 "10.32.39.90": sha2-truncbug:no; initial-contact:no;
cisco-unity:no; fake-strongswan:no; send-vendorid:no; send-no-esp-tfc:no;
000 "10.32.39.90": policy:
RSASIG+ENCRYPT+PFS+UP+IKEV2_ALLOW+IKEV2_PROPOSE+SAREF_TRACK+IKE_FRAG_ALLOW+ESN_NO;
000 "10.32.39.90": conn_prio: 32,32; interface: eth0; metric: 0; mtu:
1500; sa_prio:auto; sa_tfc:none;
000 "10.32.39.90": nflog-group: unset; mark: unset; vti-iface:unset;
vti-routing:no; vti-shared:no; nic-offload:auto;
000 "10.32.39.90": our idtype: ID_IPV4_ADDR; our id=10.32.39.68;
their idtype: ID_IPV4_ADDR; their id:10.32.39.90
000 "10.32.39.90": dpd: action:restart; delay:30; timeout:30; nat-t:
encaps:auto; nat_keepalive:yes; ikev1_natt:both
000 "10.32.39.90": newest ISAKMP SA: #32; newest IPsec SA: #34;
000 "10.32.39.90": IKE algorithms wanted:
AES_CBC(7)_256-SHA2_256(4)-MODP2048(14)
000 "10.32.39.90": IKE algorithms found:
AES_CBC(7)_256-SHA2_256(4)-MODP2048(14)
000 "10.32.39.90": IKEv2 algorithm newest:
AES_CBC_256-AUTH_HMAC_SHA2_256_128-PRF_HMAC_SHA2_256-MODP2048
000 "10.32.39.90": ESP algorithms wanted: AES_GCM_C(20)_128-NONE(0)
000 "10.32.39.90": ESP algorithms loaded: AES_GCM_C(20)_128-NONE(0)
000 "10.32.39.90": ESP algorithm newest: AES_GCM_C_128-NONE;
pfsgroup=<Phase1>
000 #34: "10.32.39.90":500 STATE_V2_IPSEC_R (IPsec SA established);
EVENT_SA_REPLACE in 27124s; newest IPSEC; eroute owner; isakmp#32; idle;
import:admin initiate
000 #34: "10.32.39.90" ***@10.32.39.90 ***@10.32.39.68
ref=0 refhim=0 Traffic: ESPin=0B ESPout=1KB! ESPmax=0B
000 #33: "10.32.39.90":500 STATE_V2_IPSEC_I (IPsec SA established);
EVENT_SA_REPLACE in 26774s; isakmp#32; idle; import:admin initiate
000 #33: "10.32.39.90" ***@10.32.39.90 ***@10.32.39.68
ref=0 refhim=0 Traffic: ESPin=0B ESPout=0B! ESPmax=0B
000 #32: "10.32.39.90":500 STATE_PARENT_I3 (PARENT SA established);
EVENT_SA_REPLACE in 1934s; newest ISAKMP; isakmp#0; idle; import:admin
initiate
000 #32: "10.32.39.90" ref=0 refhim=0 Traffic:

Output of "ipsec auto --status" on 10.32.39.90 for 10.32.39.68 shows
the same two SA connections.

000 "10.32.39.68": 10.32.39.90<10.32.39.90>...10.32.39.68<10.32.39.68>;
erouted; eroute owner: #24
000 "10.32.39.68": oriented; my_ip=unset; their_ip=unset;
mycert=10.32.39.90 - Test
000 "10.32.39.68": xauth us:none, xauth them:none, my_username=[any];
their_username=[any]
000 "10.32.39.68": our auth:rsasig, their auth:rsasig
000 "10.32.39.68": modecfg info: us:none, them:none, modecfg
policy:push, dns1:unset, dns2:unset, domain:unset, banner:unset, cat:unset;
000 "10.32.39.68": labeled_ipsec:no;
000 "10.32.39.68": policy_label:unset;
000 "10.32.39.68": CAs: 'C=US, ST=North Carolina, L=Charlotte,
O=Testing, OU=SLA, OU=Devi Environment, CN=SLA Devi CA'...'%any'
000 "10.32.39.68": ike_life: 3600s; ipsec_life: 28800s;
replay_window: 32; rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 0;
000 "10.32.39.68": retransmit-interval: 500ms; retransmit-timeout:
60s;
000 "10.32.39.68": sha2-truncbug:no; initial-contact:no;
cisco-unity:no; fake-strongswan:no; send-vendorid:no; send-no-esp-tfc:no;
000 "10.32.39.68": policy:
RSASIG+ENCRYPT+PFS+UP+IKEV2_ALLOW+IKEV2_PROPOSE+SAREF_TRACK+IKE_FRAG_ALLOW+ESN_NO;
000 "10.32.39.68": conn_prio: 32,32; interface: eth0; metric: 0; mtu:
1500; sa_prio:auto; sa_tfc:none;
000 "10.32.39.68": nflog-group: unset; mark: unset; vti-iface:unset;
vti-routing:no; vti-shared:no; nic-offload:auto;
000 "10.32.39.68": our idtype: ID_IPV4_ADDR; our id=10.32.39.90;
their idtype: ID_IPV4_ADDR; their id:10.32.39.68
000 "10.32.39.68": dpd: action:restart; delay:30; timeout:30; nat-t:
encaps:auto; nat_keepalive:yes; ikev1_natt:both
000 "10.32.39.68": newest ISAKMP SA: #4; newest IPsec SA: #24;
000 "10.32.39.68": IKE algorithms wanted:
AES_CBC(7)_256-SHA2_256(4)-MODP2048(14)
000 "10.32.39.68": IKE algorithms found:
AES_CBC(7)_256-SHA2_256(4)-MODP2048(14)
000 "10.32.39.68": IKEv2 algorithm newest:
AES_CBC_256-AUTH_HMAC_SHA2_256_128-PRF_HMAC_SHA2_256-MODP2048
000 "10.32.39.68": ESP algorithms wanted: AES_GCM_C(20)_128-NONE(0)
000 "10.32.39.68": ESP algorithms loaded: AES_GCM_C(20)_128-NONE(0)
000 "10.32.39.68": ESP algorithm newest: AES_GCM_C_128-NONE;
pfsgroup=<Phase1>
000 #24: "10.32.39.68":500 STATE_V2_IPSEC_I (IPsec SA established);
EVENT_SA_REPLACE in 26575s; newest IPSEC; eroute owner; isakmp#4; idle;
import:admin initiate
000 #24: "10.32.39.68" ***@10.32.39.68 ***@10.32.39.90
***@10.32.39.68 ***@10.32.39.90 ref=0 refhim=0 Traffic: ESPin=0B
ESPout=468B! ESPmax=0B
000 #12: "10.32.39.68":500 STATE_V2_IPSEC_R (IPsec SA established);
EVENT_SA_REPLACE in 26575s; isakmp#4; idle; import:respond to stranger
000 #12: "10.32.39.68" ***@10.32.39.68 ***@10.32.39.90
ref=0 refhim=0 Traffic: ESPin=0B ESPout=0B! ESPmax=0B
000 #4: "10.32.39.68":500 STATE_PARENT_R2 (received v2I2, PARENT SA
established); EVENT_SA_REPLACE in 1375s; newest ISAKMP; isakmp#0; idle;
import:admin initiate
000 #4: "10.32.39.68" ref=0 refhim=0 Traffic:

And corresponding ipsec.conf connections.

On 10.32.39.68

conn 10.32.39.90
type=transport
authby=rsasig
left=10.32.39.68
leftrsasigkey=%cert
leftcert="10.32.39.68 - Test"
right=10.32.39.90
rightrsasigkey=%cert
ike=aes256-sha2_256;modp2048
ikev2=insist
pfs=yes
phase2=esp
phase2alg=aes_gcm_c-128-null
mtu=1500
auto=start

And on 10.32.39.90

conn 10.32.39.86
type=transport
authby=rsasig
left=10.32.39.90
leftrsasigkey=%cert
leftcert="10.32.39.90 - Test"
right=10.32.39.86
rightrsasigkey=%cert
ike=aes256-sha2_256;modp2048
ikev2=insist
pfs=yes
phase2=esp
phase2alg=aes_gcm_c-128-null
mtu=1500
auto=start

Here are the connections that I'm suspicious of.

002 "10.32.39.90": terminating SAs using this connection
002 "10.32.39.90" #34: deleting state (STATE_V2_IPSEC_R) and sending
notification
005 "10.32.39.90" #34: ESP traffic information: in=1KB out=0B
002 "10.32.39.90" #33: deleting state (STATE_V2_IPSEC_I) and sending
notification
005 "10.32.39.90" #33: ESP traffic information: in=0B out=0B
002 "10.32.39.90" #32: deleting state (STATE_PARENT_I3) and sending
notification

If I go on one of those servers say 10.32.39.68, and run "ipsec auto --down
10.32.39.90". Now the connection works, I assume when the other side
reconnects.

What is going on here and is there any way that I can fix it? Is there
other information I can provide?

Best Regards,
Benjamin Doerr

Loading...