[strongSwan] Asymmetric configuration after IKE SA rekey
Alan Ford
alan.ford at gmail.com
Mon May 20 14:57:07 CEST 2013
Hello,
I am having some strange issues with IPSec tunnels failing after an IKE SA
rekey. charon rekeys an IKE SA and then ends up with different policy and
multiple Child SAs on each host, thus leading to no traffic possible
between them. This resolves itself after another IKE SA rekey. This issue
happens about once a week or so. I am wondering if this is a known bug, an
unknown bug, or user error. I am using the most recent Debian unstable
strongSwan (4.6.4). Details below…
My ipsec.conf is trivial on box2 (and mirror left/right on box1)
conn %default
left=10.1.1.2
leftcert=cert.pem
right=10.1.1.1
rightca=%same
auto=route
type=transport
mobike=no
ike=aes256-sha512-modp4096!
esp=aes256-sha512-modp4096!
keyingtries=%forever
To work through an example. Prior to the rekey, we had this configuration:
Box 1:
box2[17]: ESTABLISHED 2 hours ago, 10.1.1.1[10.1.1.1]...10.1.1.2[10.1.1.1.2]
box2[17]: IKE SPIs: 24606edaf5e07323_i* edb04d3909a6a051_r, public key
reauthentication in 11 minutes
box2[17]: IKE proposal:
AES_CBC_256/HMAC_SHA2_512_256/PRF_HMAC_SHA2_512/MODP_4096
box2{18}: INSTALLED, TRANSPORT, ESP SPIs: ca5076a9_i ce4154d9_o
box2{18}: AES_CBC_256/HMAC_SHA2_512_256, 314243 bytes_i (0s ago), 117352
bytes_o (1s ago), rekeying in 34 minutes
box2{18}: 10.1.1.1/32 === 10.1.1.2/32
(ip xfrm policy)
src 10.1.1.2/32 dst 10.1.1.1/32
dir in priority 1795
tmpl src 0.0.0.0 dst 0.0.0.0
proto esp reqid 18 mode transport
src 10.1.1.1/32 dst 10.1.1.2/32
dir out priority 1795
tmpl src 0.0.0.0 dst 0.0.0.0
proto esp reqid 18 mode transport
Box 2:
(ipsec statusall)
box1[17]: ESTABLISHED 2 hours ago, 10.1.1.2[10.1.1.2]...10.1.1.1[10.1.1.1]
box1[17]: IKE SPIs: 24606edaf5e07323_i edb04d3909a6a051_r*, public key
reauthentication in 20 minutes
box1[17]: IKE proposal:
AES_CBC_256/HMAC_SHA2_512_256/PRF_HMAC_SHA2_512/MODP_4096
box1{15}: INSTALLED, TRANSPORT, ESP SPIs: ce4154d9_i ca5076a9_o
box1{15}: AES_CBC_256/HMAC_SHA2_512_256, 116893 bytes_i (0s ago), 333125
bytes_o (1s ago), rekeying in 30 minutes
box1{15}: 10.1.1.2/32 === 10.1.1.1/32
(ip xfrm policy)
src 10.1.1.2/32 dst 10.1.1.1/32
dir in priority 1795
tmpl src 0.0.0.0 dst 0.0.0.0
proto esp reqid 15 mode transport
src 10.1.1.1/32 dst 10.1.1.2/32
dir out priority 1795
tmpl src 0.0.0.0 dst 0.0.0.0
proto esp reqid 15 mode transport
Then an IKE rekey happened, and we ended up with:
Box 1:
(ipsec statusall)
box2[21]: ESTABLISHED 8 minutes ago,
10.1.1.1[10.1.1.1]...10.1.1.2[10.1.1.1.2]
box2[21]: IKE SPIs: 0bb3104f1e3a8c8f_i* c0d5c74941b82678_r, public key
reauthentication in 2 hours
box2[21]: IKE proposal:
AES_CBC_256/HMAC_SHA2_512_256/PRF_HMAC_SHA2_512/MODP_4096
box2{25}: INSTALLED, TRANSPORT, ESP SPIs: c9744ff1_i c1dc0653_o
box2{25}: AES_CBC_256/HMAC_SHA2_512_256, 130 bytes_i (1s ago), 66 bytes_o
(1s ago), rekeying in 33 minutes
box2{25}: 10.1.1.1/32 === 10.1.1.2/32
box2{26}: INSTALLED, TRANSPORT, ESP SPIs: c325ac33_i c58ecbc2_o
box2{26}: AES_CBC_256/HMAC_SHA2_512_256, 207339 bytes_i (1s ago), 0
bytes_o, rekeying in 37 minutes
box2{26}: 10.1.1.1/32 === 10.1.1.2/32
box2{6}: INSTALLED, TRANSPORT, ESP SPIs: ce41cacc_i c24af98a_o
box2{6}: AES_CBC_256/HMAC_SHA2_512_256, 0 bytes_i, 59138 bytes_o (1s ago),
rekeying in 35 minutes
box2{6}: 10.1.1.1/32 === 10.1.1.2/32
(ip xfrm policy)
src 10.1.1.2/32 dst 10.1.1.1/32
dir in priority 1795
tmpl src 0.0.0.0 dst 0.0.0.0
proto esp reqid 6 mode transport
src 10.1.1.1/32 dst 10.1.1.2/32
dir out priority 1795
tmpl src 0.0.0.0 dst 0.0.0.0
proto esp reqid 6 mode transport
Box 2:
(ipsec statusall)
box1[20]: ESTABLISHED 8 minutes ago, 10.1.1.2[10.1.1.2]...10.1.1.1[10.1.1.1]
box1[20]: IKE SPIs: 0bb3104f1e3a8c8f_i c0d5c74941b82678_r*, public key
reauthentication in 2 hours
box1[20]: IKE proposal:
AES_CBC_256/HMAC_SHA2_512_256/PRF_HMAC_SHA2_512/MODP_4096
box1{20}: INSTALLED, TRANSPORT, ESP SPIs: c1dc0653_i c9744ff1_o
box1{20}: AES_CBC_256/HMAC_SHA2_512_256, 66 bytes_i (1s ago), 130 bytes_o
(1s ago), rekeying in 40 minutes
box1{20}: 10.1.1.2/32 === 10.1.1.1/32
box1{21}: INSTALLED, TRANSPORT, ESP SPIs: c24af98a_i ce41cacc_o
box1{21}: AES_CBC_256/HMAC_SHA2_512_256, 59138 bytes_i (1s ago), 0
bytes_o, rekeying in 34 minutes
box1{21}: 10.1.1.2/32 === 10.1.1.1/32
box1{3}: INSTALLED, TRANSPORT, ESP SPIs: c58ecbc2_i c325ac33_o
box1{3}: AES_CBC_256/HMAC_SHA2_512_256, 0 bytes_i, 207570 bytes_o (1s
ago), rekeying in 40 minutes
box1{3}: 10.1.1.2/32 === 10.1.1.1/32
(ip xfrm policy)
src 10.44.99.2/32 dst 10.47.2.43/32
dir in priority 1795
tmpl src 0.0.0.0 dst 0.0.0.0
proto esp reqid 3 mode transport
src 10.47.2.43/32 dst 10.44.99.2/32
dir out priority 1795
tmpl src 0.0.0.0 dst 0.0.0.0
proto esp reqid 3 mode transport
So as can be seen, Box 1 thinks it should be using the SPIs child SA {6},
whereas Box 2 thinks it should be using those of {3} - the packet counters
show how one is receiving only and the other is sending only. So no traffic
is possible between the boxes.
The syslogs on each box read:
Box 1:
2013-05-20T10:31:35.896+00:00 box1 charon: 05[IKE] reauthenticating IKE_SA
box2[17]
2013-05-20T10:31:35.896+00:00 box1 charon: 05[IKE] deleting IKE_SA box2[17]
between 10.1.1.1[10.1.1.1]...10.1.1.2[10.1.1.2]
2013-05-20T10:31:35.896+00:00 box1 charon: 05[IKE] sending DELETE for
IKE_SA box2[17]
2013-05-20T10:31:35.896+00:00 box1 charon: 05[ENC] generating INFORMATIONAL
request 8 [ D ]
2013-05-20T10:31:35.896+00:00 box1 charon: 05[NET] sending packet: from
10.1.1.1[500] to 10.1.1.2[500]
2013-05-20T10:31:35.971+00:00 box1 charon: 15[NET] received packet: from
10.1.1.2[500] to 10.1.1.1[500]
2013-05-20T10:31:35.971+00:00 box1 charon: 15[ENC] parsed INFORMATIONAL
response 8 [ ]
2013-05-20T10:31:35.971+00:00 box1 charon: 15[IKE] IKE_SA deleted
2013-05-20T10:31:35.971+00:00 box1 charon: 15[IKE] restarting CHILD_SA box2
2013-05-20T10:31:35.971+00:00 box1 charon: 15[IKE] initiating IKE_SA
box2[21] to 10.1.1.2
2013-05-20T10:31:36.019+00:00 box1 charon: 15[ENC] generating IKE_SA_INIT
request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) ]
2013-05-20T10:31:36.019+00:00 box1 charon: 15[NET] sending packet: from
10.1.1.1[500] to 10.1.1.2[500]
2013-05-20T10:31:36.145+00:00 box1 charon: 02[KNL] creating acquire job for
policy 10.1.1.1/32[udp/8005] === 10.1.1.2/32[udp/8005] with reqid {6}
2013-05-20T10:31:36.196+00:00 box1 charon: 16[NET] received packet: from
10.1.1.2[500] to 10.1.1.1[500]
2013-05-20T10:31:36.196+00:00 box1 charon: 16[ENC] parsed IKE_SA_INIT
response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) CERTREQ N(MULT_AUTH) ]
2013-05-20T10:31:36.244+00:00 box1 charon: 16[IKE] received cert request
for "..."
2013-05-20T10:31:36.244+00:00 box1 charon: 16[IKE] sending cert request for
"..."
2013-05-20T10:31:36.257+00:00 box1 charon: 16[IKE] authentication of
'10.1.1.1' (myself) with RSA signature successful
2013-05-20T10:31:36.257+00:00 box1 charon: 16[IKE] sending end entity cert
"..."
2013-05-20T10:31:36.257+00:00 box1 charon: 16[IKE] establishing CHILD_SA
box2
2013-05-20T10:31:36.257+00:00 box1 charon: 16[ENC] generating IKE_AUTH
request 1 [ IDi CERT N(INIT_CONTACT) CERTREQ IDr AUTH N(USE_TRANSP) SA TSi
TSr N(MULT_AUTH) N(EAP_ONLY) ]
2013-05-20T10:31:36.257+00:00 box1 charon: 16[NET] sending packet: from
10.1.1.1[500] to 10.1.1.2[500]
2013-05-20T10:31:36.334+00:00 box1 charon: 13[NET] received packet: from
10.1.1.2[500] to 10.1.1.1[500]
2013-05-20T10:31:36.334+00:00 box1 charon: 13[ENC] parsed IKE_AUTH response
1 [ IDr CERT AUTH N(USE_TRANSP) SA TSi TSr N(AUTH_LFT) ]
2013-05-20T10:31:36.335+00:00 box1 charon: 13[IKE] received end entity cert
"..."
2013-05-20T10:31:36.335+00:00 box1 charon: 13[CFG] using certificate "..."
2013-05-20T10:31:36.335+00:00 box1 charon: 13[CFG] using trusted ca
certificate "..."
2013-05-20T10:31:36.335+00:00 box1 charon: 13[CFG] checking certificate
status of "..."
2013-05-20T10:31:36.335+00:00 box1 charon: 13[CFG] certificate status is
not available
2013-05-20T10:31:36.335+00:00 box1 charon: 13[CFG] reached self-signed
root ca with a path length of 0
2013-05-20T10:31:36.335+00:00 box1 charon: 13[IKE] authentication of
'10.1.1.2' with RSA signature successful
2013-05-20T10:31:36.335+00:00 box1 charon: 13[IKE] IKE_SA box2[21]
established between 10.1.1.1[10.1.1.1]...10.1.1.2[10.1.1.2]
2013-05-20T10:31:36.335+00:00 box1 charon: 13[IKE] scheduling
reauthentication in 9742s
2013-05-20T10:31:36.335+00:00 box1 charon: 13[IKE] maximum IKE_SA lifetime
10282s
2013-05-20T10:31:36.335+00:00 box1 charon: 13[IKE] CHILD_SA box2{25}
established with SPIs c9744ff1_i c1dc0653_o and TS 10.1.1.1/32 ===
10.1.1.2/32
2013-05-20T10:31:36.335+00:00 box1 charon: 13[IKE] received AUTH_LIFETIME
of 10047s, scheduling reauthentication in 9507s
2013-05-20T10:31:36.335+00:00 box1 charon: 13[IKE] establishing CHILD_SA
box2{6}
2013-05-20T10:31:36.383+00:00 box1 charon: 13[ENC] generating
CREATE_CHILD_SA request 2 [ N(USE_TRANSP) SA No KE TSi TSr ]
2013-05-20T10:31:36.383+00:00 box1 charon: 13[NET] sending packet: from
10.1.1.1[500] to 10.1.1.2[500]
2013-05-20T10:31:36.396+00:00 box1 charon: 10[NET] received packet: from
10.1.1.2[500] to 10.1.1.1[500]
2013-05-20T10:31:36.396+00:00 box1 charon: 10[ENC] parsed CREATE_CHILD_SA
request 0 [ N(USE_TRANSP) SA No KE TSi TSr ]
2013-05-20T10:31:36.493+00:00 box1 charon: 10[IKE] CHILD_SA box2{26}
established with SPIs c325ac33_i c58ecbc2_o and TS 10.1.1.1/32 ===
10.1.1.2/32
2013-05-20T10:31:36.493+00:00 box1 charon: 10[ENC] generating
CREATE_CHILD_SA response 0 [ N(USE_TRANSP) SA No KE TSi TSr ]
2013-05-20T10:31:36.493+00:00 box1 charon: 10[NET] sending packet: from
10.1.1.1[500] to 10.1.1.2[500]
2013-05-20T10:31:36.563+00:00 box1 charon: 14[NET] received packet: from
10.1.1.2[500] to 10.1.1.1[500]
2013-05-20T10:31:36.563+00:00 box1 charon: 14[ENC] parsed CREATE_CHILD_SA
response 2 [ N(USE_TRANSP) SA No KE TSi TSr ]
2013-05-20T10:31:36.611+00:00 box1 charon: 14[IKE] CHILD_SA box2{6}
established with SPIs ce41cacc_i c24af98a_o and TS 10.1.1.1/32 ===
10.1.1.2/32
Box 2:
2013-05-20T10:31:35.924+00:00 box2 charon: 15[NET] received packet: from
10.1.1.1[500] to 10.1.1.2[500]
2013-05-20T10:31:35.924+00:00 box2 charon: 15[ENC] parsed INFORMATIONAL
request 8 [ D ]
2013-05-20T10:31:35.924+00:00 box2 charon: 15[IKE] received DELETE for
IKE_SA box1[17]
2013-05-20T10:31:35.924+00:00 box2 charon: 15[IKE] deleting IKE_SA box1[17]
between 10.1.1.2[10.1.1.2]...10.1.1.1[10.1.1.1]
2013-05-20T10:31:35.924+00:00 box2 charon: 15[IKE] IKE_SA deleted
2013-05-20T10:31:35.924+00:00 box2 charon: 15[ENC] generating INFORMATIONAL
response 8 [ ]
2013-05-20T10:31:35.924+00:00 box2 charon: 15[NET] sending packet: from
10.1.1.2[500] to 10.1.1.1[500]
2013-05-20T10:31:36.048+00:00 box2 charon: 14[NET] received packet: from
10.1.1.1[500] to 10.1.1.2[500]
2013-05-20T10:31:36.048+00:00 box2 charon: 14[ENC] parsed IKE_SA_INIT
request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) ]
2013-05-20T10:31:36.048+00:00 box2 charon: 14[IKE] 10.1.1.1 is initiating
an IKE_SA
2013-05-20T10:31:36.169+00:00 box2 charon: 14[IKE] sending cert request for
"..."
2013-05-20T10:31:36.169+00:00 box2 charon: 14[ENC] generating IKE_SA_INIT
response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) CERTREQ N(MULT_AUTH) ]
2013-05-20T10:31:36.169+00:00 box2 charon: 14[NET] sending packet: from
10.1.1.2[500] to 10.1.1.1[500]
2013-05-20T10:31:36.288+00:00 box2 charon: 13[NET] received packet: from
10.1.1.1[500] to 10.1.1.2[500]
2013-05-20T10:31:36.288+00:00 box2 charon: 13[ENC] parsed IKE_AUTH request
1 [ IDi CERT N(INIT_CONTACT) CERTREQ IDr AUTH N(USE_TRANSP) SA TSi TSr
N(MULT_AUTH) N(EAP_ONLY) ]
2013-05-20T10:31:36.288+00:00 box2 charon: 13[IKE] received cert request
for "..."
2013-05-20T10:31:36.288+00:00 box2 charon: 13[IKE] received end entity cert
"..."
2013-05-20T10:31:36.288+00:00 box2 charon: 13[CFG] looking for peer configs
matching 10.1.1.2[10.1.1.2]...10.1.1.1[10.1.1.1]
2013-05-20T10:31:36.288+00:00 box2 charon: 13[CFG] selected peer config
'box1'
2013-05-20T10:31:36.288+00:00 box2 charon: 13[CFG] using certificate "..."
2013-05-20T10:31:36.288+00:00 box2 charon: 13[CFG] using trusted ca
certificate "..."
2013-05-20T10:31:36.288+00:00 box2 charon: 13[CFG] checking certificate
status of "..."
2013-05-20T10:31:36.288+00:00 box2 charon: 13[CFG] certificate status is
not available
2013-05-20T10:31:36.289+00:00 box2 charon: 13[CFG] reached self-signed
root ca with a path length of 0
2013-05-20T10:31:36.289+00:00 box2 charon: 13[IKE] authentication of
'10.1.1.1' with RSA signature successful
2013-05-20T10:31:36.298+00:00 box2 charon: 02[KNL] creating acquire job for
policy 10.1.1.2/32[udp/8005] === 10.1.1.1/32[udp/8005] with reqid {3}
2013-05-20T10:31:36.306+00:00 box2 charon: 13[IKE] authentication of
'10.1.1.2' (myself) with RSA signature successful
2013-05-20T10:31:36.306+00:00 box2 charon: 13[IKE] IKE_SA box1[20]
established between 10.1.1.2[10.1.1.2]...10.1.1.1[10.1.1.1]
2013-05-20T10:31:36.306+00:00 box2 charon: 13[IKE] scheduling
reauthentication in 10047s
2013-05-20T10:31:36.306+00:00 box2 charon: 13[IKE] maximum IKE_SA lifetime
10587s
2013-05-20T10:31:36.306+00:00 box2 charon: 13[IKE] sending end entity cert
"..."
2013-05-20T10:31:36.306+00:00 box2 charon: 13[IKE] CHILD_SA box1{20}
established with SPIs c1dc0653_i c9744ff1_o and TS 10.1.1.2/32 ===
10.1.1.1/32
2013-05-20T10:31:36.306+00:00 box2 charon: 13[ENC] generating IKE_AUTH
response 1 [ IDr CERT AUTH N(USE_TRANSP) SA TSi TSr N(AUTH_LFT) ]
2013-05-20T10:31:36.306+00:00 box2 charon: 13[NET] sending packet: from
10.1.1.2[500] to 10.1.1.1[500]
2013-05-20T10:31:36.306+00:00 box2 charon: 10[IKE] establishing CHILD_SA
box1{3}
2013-05-20T10:31:36.368+00:00 box2 charon: 10[ENC] generating
CREATE_CHILD_SA request 0 [ N(USE_TRANSP) SA No KE TSi TSr ]
2013-05-20T10:31:36.368+00:00 box2 charon: 10[NET] sending packet: from
10.1.1.2[500] to 10.1.1.1[500]
2013-05-20T10:31:36.414+00:00 box2 charon: 05[NET] received packet: from
10.1.1.1[500] to 10.1.1.2[500]
2013-05-20T10:31:36.414+00:00 box2 charon: 05[ENC] parsed CREATE_CHILD_SA
request 2 [ N(USE_TRANSP) SA No KE TSi TSr ]
2013-05-20T10:31:36.536+00:00 box2 charon: 05[IKE] CHILD_SA box1{21}
established with SPIs c24af98a_i ce41cacc_o and TS 10.1.1.2/32 ===
10.1.1.1/32
2013-05-20T10:31:36.536+00:00 box2 charon: 05[ENC] generating
CREATE_CHILD_SA response 2 [ N(USE_TRANSP) SA No KE TSi TSr ]
2013-05-20T10:31:36.536+00:00 box2 charon: 05[NET] sending packet: from
10.1.1.2[500] to 10.1.1.1[500]
2013-05-20T10:31:36.547+00:00 box2 charon: 11[NET] received packet: from
10.1.1.1[500] to 10.1.1.2[500]
2013-05-20T10:31:36.548+00:00 box2 charon: 11[ENC] parsed CREATE_CHILD_SA
response 0 [ N(USE_TRANSP) SA No KE TSi TSr ]
2013-05-20T10:31:36.610+00:00 box2 charon: 11[IKE] CHILD_SA box1{3}
established with SPIs c58ecbc2_i c325ac33_o and TS 10.1.1.2/32 ===
10.1.1.1/32
Does anybody have any idea what is going on here? This feels like a bug,
but I have been unable to find anything in the mailing list archives
discussing it.
Many thanks,
Alan
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.strongswan.org/pipermail/users/attachments/20130520/9a137aa3/attachment.html>
More information about the Users
mailing list