[strongSwan] TS_UNACCEPTABLE some CHILD_SA rekeys
Alan Ford
alan.ford at gmail.com
Fri Jul 19 17:14:05 CEST 2013
Hello,
I am wondering why I am seeing so many TS_UNACCEPTABLE responses to
CHILD_SA rekey requests.
It seems that I am only seeing these in one direction. I was under the
impression either side could initiate a rekey, but my logs are full of
issues like this.
Setup on Host 1:
2013-07-19T11:57:44.648+00:00 host1 charon: 01[NET] sending packet: from
10.0.0.1[500] to 10.0.0.2[500]
2013-07-19T11:57:44.745+00:00 host1 charon: 14[NET] received packet: from
10.0.0.2[500] to 10.0.0.1[500]
2013-07-19T11:57:44.745+00:00 host1 charon: 14[ENC] parsed IKE_SA_INIT
response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) CERTREQ N(MULT_AUTH) ]
2013-07-19T11:57:44.795+00:00 host1 charon: 14[IKE] received cert request
for
2013-07-19T11:57:44.795+00:00 host1 charon: 14[IKE] sending cert request
for
2013-07-19T11:57:44.810+00:00 host1 charon: 14[IKE] authentication of
'10.0.0.1' (myself) with RSA signature successful
2013-07-19T11:57:44.810+00:00 host1 charon: 14[IKE] sending end entity cert
2013-07-19T11:57:44.810+00:00 host1 charon: 14[IKE] establishing CHILD_SA
node2-10.0.0.2
2013-07-19T11:57:44.810+00:00 host1 charon: 14[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-07-19T11:57:44.811+00:00 host1 charon: 14[NET] sending packet: from
10.0.0.1[500] to 10.0.0.2[500]
2013-07-19T11:57:44.860+00:00 host1 charon: 03[NET] received packet: from
10.0.0.2[500] to 10.0.0.1[500]
2013-07-19T11:57:44.860+00:00 host1 charon: 03[ENC] parsed IKE_AUTH
response 1 [ IDr CERT AUTH N(USE_TRANSP) SA TSi TSr N(AUTH_LFT) ]
2013-07-19T11:57:44.860+00:00 host1 charon: 03[IKE] received end entity cert
2013-07-19T11:57:44.860+00:00 host1 charon: 03[CFG] using certificate
2013-07-19T11:57:44.861+00:00 host1 charon: 03[CFG] using trusted ca
certificate
2013-07-19T11:57:44.861+00:00 host1 charon: 03[CFG] checking certificate
status
2013-07-19T11:57:44.861+00:00 host1 charon: 03[CFG] certificate status is
not available
2013-07-19T11:57:44.861+00:00 host1 charon: 03[CFG] reached self-signed
root ca with a path length of 0
2013-07-19T11:57:44.861+00:00 host1 charon: 03[IKE] authentication of
'10.0.0.2' with RSA signature successful
2013-07-19T11:57:44.861+00:00 host1 charon: 03[IKE] IKE_SA
node2-10.0.0.2[1] established between
10.0.0.1[10.0.0.1]...10.0.0.2[10.0.0.2]
2013-07-19T11:57:44.861+00:00 host1 charon: 03[IKE] scheduling rekeying in
10259s
2013-07-19T11:57:44.861+00:00 host1 charon: 03[IKE] maximum IKE_SA lifetime
10799s
2013-07-19T11:57:45.045+00:00 host1 charon: 03[IKE] CHILD_SA
node2-10.0.0.2{2} established with SPIs c1b6a7e6_i c784536f_o and TS
10.0.0.1/32 === 10.0.0.2/32
Setup on Host 2:
2013-07-19T11:57:44.000+00:00 host2 charon: 15[NET] received packet: from
10.0.0.1[500] to 10.0.0.2[500]
2013-07-19T11:57:44.000+00:00 host2 charon: 15[ENC] parsed IKE_SA_INIT
request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) ]
2013-07-19T11:57:44.000+00:00 host2 charon: 15[IKE] 10.0.0.1 is initiating
an IKE_SA
2013-07-19T11:57:44.000+00:00 host2 charon: 15[IKE] sending cert request
2013-07-19T11:57:44.000+00:00 host2 charon: 15[ENC] generating IKE_SA_INIT
response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) CERTREQ N(MULT_AUTH) ]
2013-07-19T11:57:44.000+00:00 host2 charon: 15[NET] sending packet: from
10.0.0.2[500] to 10.0.0.1[500]
2013-07-19T11:57:44.000+00:00 host2 charon: 16[NET] received packet: from
10.0.0.1[500] to 10.0.0.2[500]
2013-07-19T11:57:44.000+00:00 host2 charon: 16[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-07-19T11:57:44.000+00:00 host2 charon: 16[IKE] received cert request
2013-07-19T11:57:44.000+00:00 host2 charon: 16[IKE] received end entity
cert
2013-07-19T11:57:44.000+00:00 host2 charon: 16[CFG] looking for peer
configs matching 10.0.0.2[10.0.0.2]...10.0.0.1[10.0.0.1]
2013-07-19T11:57:44.000+00:00 host2 charon: 16[CFG] selected peer config
'node1-10.0.0.1'
2013-07-19T11:57:44.000+00:00 host2 charon: 16[CFG] using certificate
2013-07-19T11:57:44.000+00:00 host2 charon: 16[CFG] using trusted ca
certificate
2013-07-19T11:57:44.000+00:00 host2 charon: 16[CFG] checking certificate
status
2013-07-19T11:57:44.000+00:00 host2 charon: 16[CFG] certificate status is
not available
2013-07-19T11:57:44.000+00:00 host2 charon: 16[CFG] reached self-signed
root ca with a path length of 0
2013-07-19T11:57:44.000+00:00 host2 charon: 16[IKE] authentication of
'10.0.0.1' with RSA signature successful
2013-07-19T11:57:44.000+00:00 host2 charon: 16[IKE] authentication of
'10.0.0.2' (myself) with RSA signature successful
2013-07-19T11:57:44.000+00:00 host2 charon: 16[IKE] IKE_SA
node1-10.0.0.1[1] established between
10.0.0.2[10.0.0.2]...10.0.0.1[10.0.0.1]
2013-07-19T11:57:44.000+00:00 host2 charon: 16[IKE] scheduling
reauthentication in 10102s
2013-07-19T11:57:44.000+00:00 host2 charon: 16[IKE] maximum IKE_SA lifetime
10642s
2013-07-19T11:57:44.000+00:00 host2 charon: 16[IKE] sending end entity cert
2013-07-19T11:57:44.000+00:00 host2 charon: 16[IKE] CHILD_SA
node1-10.0.0.1{2} established with SPIs c784536f_i c1b6a7e6_o and TS
10.0.0.2/32 === 10.0.0.1/32
2013-07-19T11:57:44.000+00:00 host2 charon: 16[ENC] generating IKE_AUTH
response 1 [ IDr CERT AUTH N(USE_TRANSP) SA TSi TSr N(AUTH_LFT) ]
2013-07-19T11:57:44.000+00:00 host2 charon: 16[NET] sending packet: from
10.0.0.2[500] to 10.0.0.1[500]
We happen to rewrite some config under charon here so have to run ipsec
update; hopefully this doesn't affect anything:
2013-07-19T11:57:57.803+00:00 host2 charon: 15[CFG] received stroke: delete
connection 'node1-10.0.0.1'
2013-07-19T11:57:57.803+00:00 host2 charon: 15[CFG] deleted connection
'node1-10.0.0.1'
2013-07-19T11:57:57.804+00:00 host2 charon: 11[CFG] received stroke: add
connection 'node1-10.0.0.1'
2013-07-19T11:57:57.804+00:00 host2 charon: 11[CFG] loaded certificate
2013-07-19T11:57:57.804+00:00 host2 charon: 11[CFG] added configuration
'node1-10.0.0.1'
2013-07-19T11:57:57.804+00:00 host2 charon: 12[CFG] received stroke: route
'node1-10.0.0.1'
2013-07-19T11:57:57.804+00:00 host2 charon: 12[CFG] CHILD_SA named
'node1-10.0.0.1' already routed
Rekey attempt from Host 1:
2013-07-19T12:40:22.045+00:00 host1 charon: 05[KNL] creating rekey job for
ESP CHILD_SA with SPI c1b6a7e6 and reqid {2}
2013-07-19T12:40:22.045+00:00 host1 charon: 01[IKE] establishing CHILD_SA
node2-10.0.0.2{2}
2013-07-19T12:40:22.093+00:00 host1 charon: 01[ENC] generating
CREATE_CHILD_SA request 2 [ N(REKEY_SA) N(USE_TRANSP) SA No KE TSi TSr ]
2013-07-19T12:40:22.094+00:00 host1 charon: 01[NET] sending packet: from
10.0.0.1[500] to 10.0.0.2[500]
2013-07-19T12:40:22.190+00:00 host1 charon: 11[NET] received packet: from
10.0.0.2[500] to 10.0.0.1[500]
2013-07-19T12:40:22.190+00:00 host1 charon: 11[ENC] parsed CREATE_CHILD_SA
response 2 [ N(TS_UNACCEPT) ]
2013-07-19T12:40:22.190+00:00 host1 charon: 11[IKE] received
TS_UNACCEPTABLE notify, no CHILD_SA built
2013-07-19T12:40:22.190+00:00 host1 charon: 11[IKE] failed to establish
CHILD_SA, keeping IKE_SA
2013-07-19T12:40:22.190+00:00 host1 charon: 11[IKE] CHILD_SA rekeying
failed, trying again in 30 seconds
Associated logs on Host 2:
2013-07-19T12:40:22.100+00:00 host2 charon: 12[NET] received packet: from
10.0.0.1[500] to 10.0.0.2[500]
2013-07-19T12:40:22.100+00:00 host2 charon: 12[ENC] parsed CREATE_CHILD_SA
request 2 [ N(REKEY_SA) N(USE_TRANSP) SA No KE TSi TSr ]
2013-07-19T12:40:22.196+00:00 host2 charon: 12[IKE] traffic selectors
10.0.0.2/32 === 10.0.0.1/32 inacceptable
2013-07-19T12:40:22.196+00:00 host2 charon: 12[IKE] failed to establish
CHILD_SA, keeping IKE_SA
2013-07-19T12:40:22.196+00:00 host2 charon: 12[ENC] generating
CREATE_CHILD_SA response 2 [ N(TS_UNACCEPT) ]
2013-07-19T12:40:22.196+00:00 host2 charon: 12[NET] sending packet: from
10.0.0.2[500] to 10.0.0.1[500]
These rekey attempts go on for four minutes until Host 2 decides it wants
to do a rekey, which works.
Rekey attempt from Host 2:
2013-07-19T12:44:46.997+00:00 host2 charon: 02[KNL] creating rekey job for
ESP CHILD_SA with SPI c784536f and reqid {2}
2013-07-19T12:44:46.997+00:00 host2 charon: 14[IKE] establishing CHILD_SA
node1-10.0.0.1{2}
2013-07-19T12:44:47.045+00:00 host2 charon: 14[ENC] generating
CREATE_CHILD_SA request 0 [ N(REKEY_SA) N(USE_TRANSP) SA No KE TSi TSr ]
2013-07-19T12:44:47.046+00:00 host2 charon: 14[NET] sending packet: from
10.0.0.2[500] to 10.0.0.1[500]
2013-07-19T12:44:47.143+00:00 host2 charon: 15[NET] received packet: from
10.0.0.1[500] to 10.0.0.2[500]
2013-07-19T12:44:47.143+00:00 host2 charon: 15[ENC] parsed CREATE_CHILD_SA
response 0 [ N(USE_TRANSP) SA No KE TSi TSr ]
2013-07-19T12:44:47.191+00:00 host2 charon: 15[IKE] CHILD_SA
node1-10.0.0.1{2} established with SPIs c7ccbd36_i c779deca_o and TS
10.0.0.2/32 === 10.0.0.1/32
2013-07-19T12:44:47.191+00:00 host2 charon: 15[IKE] closing CHILD_SA
node1-10.0.0.1{2} with SPIs c784536f_i (5854890 bytes) c1b6a7e6_o (4991601
bytes) and TS 10.0.0.2/3
2013-07-19T12:44:47.191+00:00 host2 charon: 15[IKE] sending DELETE for ESP
CHILD_SA with SPI c784536f
2013-07-19T12:44:47.191+00:00 host2 charon: 15[ENC] generating
INFORMATIONAL request 1 [ D ]
2013-07-19T12:44:47.191+00:00 host2 charon: 15[NET] sending packet: from
10.0.0.2[500] to 10.0.0.1[500]
2013-07-19T12:44:47.192+00:00 host2 charon: 16[NET] received packet: from
10.0.0.1[500] to 10.0.0.2[500]
2013-07-19T12:44:47.192+00:00 host2 charon: 16[ENC] parsed INFORMATIONAL
response 1 [ D ]
2013-07-19T12:44:47.192+00:00 host2 charon: 16[IKE] received DELETE for ESP
CHILD_SA with SPI c1b6a7e6
2013-07-19T12:44:47.192+00:00 host2 charon: 16[IKE] CHILD_SA closed
2013-07-19T12:44:47.800+00:00 host2 charon: 13[NET] received packet: from
10.0.0.1[500] to 10.0.0.2[500]
2013-07-19T12:44:47.800+00:00 host2 charon: 13[ENC] parsed INFORMATIONAL
request 23 [ ]
2013-07-19T12:44:47.800+00:00 host2 charon: 13[ENC] generating
INFORMATIONAL response 23 [ ]
2013-07-19T12:44:47.801+00:00 host2 charon: 13[NET] sending packet: from
10.0.0.2[500] to 10.0.0.1[500]
Associated logs from Host 1:
2013-07-19T12:44:47.042+00:00 host1 charon: 15[NET] received packet: from
10.0.0.2[500] to 10.0.0.1[500]
2013-07-19T12:44:47.042+00:00 host1 charon: 15[ENC] parsed CREATE_CHILD_SA
request 0 [ N(REKEY_SA) N(USE_TRANSP) SA No KE TSi TSr ]
2013-07-19T12:44:47.139+00:00 host1 charon: 15[IKE] CHILD_SA
node2-10.0.0.2{2} established with SPIs c779deca_i c7ccbd36_o and TS
10.0.0.1/32 === 10.0.0.2/32
2013-07-19T12:44:47.139+00:00 host1 charon: 15[ENC] generating
CREATE_CHILD_SA response 0 [ N(USE_TRANSP) SA No KE TSi TSr ]
2013-07-19T12:44:47.139+00:00 host1 charon: 15[NET] sending packet: from
10.0.0.1[500] to 10.0.0.2[500]
2013-07-19T12:44:47.187+00:00 host1 charon: 14[NET] received packet: from
10.0.0.2[500] to 10.0.0.1[500]
2013-07-19T12:44:47.187+00:00 host1 charon: 14[ENC] parsed INFORMATIONAL
request 1 [ D ]
2013-07-19T12:44:47.188+00:00 host1 charon: 14[IKE] received DELETE for ESP
CHILD_SA with SPI c784536f
2013-07-19T12:44:47.188+00:00 host1 charon: 14[IKE] closing CHILD_SA
node2-10.0.0.2{2} with SPIs c1b6a7e6_i (4991601 bytes) c784536f_o (5854890
bytes) and TS 10.0.0.1/32 ===
2013-07-19T12:44:47.188+00:00 host1 charon: 14[IKE] sending DELETE for ESP
CHILD_SA with SPI c1b6a7e6
2013-07-19T12:44:47.188+00:00 host1 charon: 14[IKE] CHILD_SA closed
Why does Host 1's rekey attempt fail and Host 2's work?
This is my ipsec.conf on Host 1:
config setup
plutostart=no
conn %default
left=10.0.0.1
leftcert=cert.pem
rightca=%same
auto=route
reauth=no
type=transport
mobike=no
ike=aes256-sha512-modp4096!
esp=aes256-sha512-modp4096!
keyingtries=%forever
conn node2-10.0.0.2
right=10.0.0.2
And on Host 2:
config setup
plutostart=no
conn %default
left=10.0.0.2
leftcert=cert.pem
rightca=%same
auto=route
reauth=no
type=transport
mobike=no
ike=aes256-sha512-modp4096!
esp=aes256-sha512-modp4096!
keyingtries=%forever
conn node1-10.0.0.1
right=10.0.0.1
Any insights gratefully received; although this is not affecting operation,
it is very disconcerting to have all these errors in the logs. I am running
strongSwan 4.6.4, from Ubuntu 12.04.
Many thanks,
Alan
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.strongswan.org/pipermail/users/attachments/20130719/f251c984/attachment.html>
More information about the Users
mailing list