[strongSwan] Asymmetric configuration after IKE SA rekey
Alan Ford
alan.ford at gmail.com
Thu May 30 11:43:03 CEST 2013
Hi all,
Nobody's replied to this issue or my other, similar asymmetry issue (
https://lists.strongswan.org/pipermail/users/2013-May/009245.html).
Really hoping someone could give me some pointers here on how this could be
further debugged... Is there anything else I can look at here, or should be
doing?
Many thanks,
Alan
On 20 May 2013 13:57, Alan Ford <alan.ford at gmail.com> wrote:
> 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] <http://10.1.1.1/32%5Budp/8005%5D> ===
> 10.1.1.2/32[udp/8005] <http://10.1.1.2/32%5Budp/8005%5D> 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] <http://10.1.1.2/32%5Budp/8005%5D> ===
> 10.1.1.1/32[udp/8005] <http://10.1.1.1/32%5Budp/8005%5D> 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/20130530/a4b37b8b/attachment.html>
More information about the Users
mailing list