[prev in list] [next in list] [prev in thread] [next in thread]
List: strongswan-announce
Subject: [strongSwan-dev] TS_UNACCEPTABLE on Child SA setup after IKE reauth with virtual IP from DHCP
From: Thomas Klute <thomas2.klute () uni-dortmund ! de>
Date: 2014-02-21 14:13:40
Message-ID: 53075F14.2050505 () uni-dortmund ! de
[Download RAW message or body]
Hi everyone,
I have a problem with a roadwarrior configuration where the responder
assigns virtual IP addresses from DHCP to initiators. My test setup uses
Strongswan 5.1.1 (5.1.1-1~bpo70+1 from Debian wheezy-backports, to be
precise) on both initiator and responder. I have configured short
rekeying intervals on the initiator for testing purposes. Logs and
ipsec.conf files are attached.
Connection setup works without problems. The DHCP plugin on the
responder requests an address from the DHCP server and assigns it to
the initiator. However, when the initiator attempts IKE SA
reauthentication, the negotiation of traffic selectors fails at the
following Child SA creation. If my interpretation of the logs is
correct, the following happens:
1. Initiator closes the IKE SA
2. Responder releases the virtual IP address to the DHCP server
3. Initiator creates a new IKE SA
4. Initiator requests a new Child SA with the old virtual IP address
as TS on its side
5. Responder requests an IP address from the DHCP server
6. Responder receives an address which is different from the previous
one
7. Responder sends new IP address, but also TS_UNACCEPTABLE because of
the old address
8. Initiator receives TS_UNACCEPTABLE, Child SA setup fails
I'm not entirely sure which side is at fault here, but since the IKE
SA is deleted, I think it might be the initiator which does not accept
the new IP address, although ideally, the responder should be able to
preserve the DHCP lease during IKE reauthentication. If I configure
the responder in a way that ensures that it will always assign the
same IP to the initiator (e.g., by setting
charon.plugins.dhcp.identity_lease=yes), the connection continues to
work after rekeying, but the specification for our use case explicitly
requests a random address assignment at connection setup (which the DHCP
plugin does perfectly well by default).
The issue might be similar to one described and solved in two mails I
found in the archives:
https://lists.strongswan.org/pipermail/users/2012-December/008648.html
https://lists.strongswan.org/pipermail/users/2012-December/008649.html
Any help would be appreciated.
Kind regards,
Thomas Klute
["ike-rekey-initiator.log" (text/x-log)]
Feb 21 11:18:33 initiator charon: 10[CFG] received stroke: initiate 'testconn'
Feb 21 11:18:33 initiator charon: 13[IKE] queueing IKE_VENDOR task
Feb 21 11:18:33 initiator charon: 13[IKE] queueing IKE_INIT task
Feb 21 11:18:33 initiator charon: 13[IKE] queueing IKE_NATD task
Feb 21 11:18:33 initiator charon: 13[IKE] queueing IKE_CERT_PRE task
Feb 21 11:18:33 initiator charon: 13[IKE] queueing IKE_AUTH task
Feb 21 11:18:33 initiator charon: 13[IKE] queueing IKE_CERT_POST task
Feb 21 11:18:33 initiator charon: 13[IKE] queueing IKE_CONFIG task
Feb 21 11:18:33 initiator charon: 13[IKE] queueing IKE_AUTH_LIFETIME task
Feb 21 11:18:33 initiator charon: 13[IKE] queueing IKE_MOBIKE task
Feb 21 11:18:33 initiator charon: 13[IKE] queueing IKE_ME task
Feb 21 11:18:33 initiator charon: 13[IKE] queueing CHILD_CREATE task
Feb 21 11:18:33 initiator charon: 13[IKE] activating new tasks
Feb 21 11:18:33 initiator charon: 13[IKE] activating IKE_VENDOR task
Feb 21 11:18:33 initiator charon: 13[IKE] activating IKE_INIT task
Feb 21 11:18:33 initiator charon: 13[IKE] activating IKE_NATD task
Feb 21 11:18:33 initiator charon: 13[IKE] activating IKE_CERT_PRE task
Feb 21 11:18:33 initiator charon: 13[IKE] activating IKE_ME task
Feb 21 11:18:33 initiator charon: 13[IKE] activating IKE_AUTH task
Feb 21 11:18:33 initiator charon: 13[IKE] activating IKE_CERT_POST task
Feb 21 11:18:33 initiator charon: 13[IKE] activating IKE_CONFIG task
Feb 21 11:18:33 initiator charon: 13[IKE] activating CHILD_CREATE task
Feb 21 11:18:33 initiator charon: 13[IKE] activating IKE_AUTH_LIFETIME task
Feb 21 11:18:33 initiator charon: 13[IKE] activating IKE_MOBIKE task
Feb 21 11:18:33 initiator charon: 13[IKE] initiating IKE_SA testconn[10] to 10.50.0.2
Feb 21 11:18:33 initiator charon: 13[IKE] IKE_SA testconn[10] state change: CREATED \
=> CONNECTING
Feb 21 11:18:33 initiator charon: 13[ENC] generating IKE_SA_INIT request 0 [ SA KE No \
N(NATD_S_IP) N(NATD_D_IP) ]
Feb 21 11:18:33 initiator charon: 13[NET] sending packet: from 192.168.1.55[500] to \
10.50.0.2[500] (564 bytes)
Feb 21 11:18:33 initiator charon: 09[NET] sending packet: from 192.168.1.55[500] to \
10.50.0.2[500]
Feb 21 11:18:37 initiator charon: 02[IKE] retransmit 1 of request with message ID 0
Feb 21 11:18:37 initiator charon: 02[NET] sending packet: from 192.168.1.55[500] to \
10.50.0.2[500] (564 bytes)
Feb 21 11:18:37 initiator charon: 09[NET] sending packet: from 192.168.1.55[500] to \
10.50.0.2[500]
Feb 21 11:18:44 initiator charon: 14[IKE] retransmit 2 of request with message ID 0
Feb 21 11:18:44 initiator charon: 14[NET] sending packet: from 192.168.1.55[500] to \
10.50.0.2[500] (564 bytes)
Feb 21 11:18:44 initiator charon: 09[NET] sending packet: from 192.168.1.55[500] to \
10.50.0.2[500]
Feb 21 11:18:57 initiator charon: 11[IKE] retransmit 3 of request with message ID 0
Feb 21 11:18:57 initiator charon: 11[NET] sending packet: from 192.168.1.55[500] to \
10.50.0.2[500] (564 bytes)
Feb 21 11:18:57 initiator charon: 09[NET] sending packet: from 192.168.1.55[500] to \
10.50.0.2[500]
Feb 21 11:18:57 initiator charon: 08[NET] received packet: from 10.50.0.2[500] to \
192.168.1.55[500]
Feb 21 11:18:57 initiator charon: 08[NET] waiting for data on sockets
Feb 21 11:18:57 initiator charon: 12[NET] received packet: from 10.50.0.2[500] to \
192.168.1.55[500] (465 bytes)
Feb 21 11:18:57 initiator charon: 12[ENC] parsed IKE_SA_INIT response 0 [ SA KE No \
N(NATD_S_IP) N(NATD_D_IP) CERTREQ N(MULT_AUTH) ]
Feb 21 11:18:57 initiator charon: 12[IKE] local host is behind NAT, sending keep \
alives
Feb 21 11:18:57 initiator charon: 12[IKE] received cert request for "C=DE, O=company, \
CN=Test CA"
Feb 21 11:18:57 initiator charon: 12[IKE] reinitiating already active tasks
Feb 21 11:18:57 initiator charon: 12[IKE] IKE_CERT_PRE task
Feb 21 11:18:57 initiator charon: 12[IKE] IKE_AUTH task
Feb 21 11:18:57 initiator charon: 12[IKE] sending cert request for "C=DE, O=company, \
CN=Test CA"
Feb 21 11:18:57 initiator charon: 12[IKE] authentication of 'C=DE, O=company, \
CN=initiator.test' (myself) with RSA signature successful
Feb 21 11:18:57 initiator charon: 12[IKE] sending end entity cert "C=DE, O=company, \
CN=initiator.test"
Feb 21 11:18:57 initiator charon: 12[IKE] building INTERNAL_IP4_DNS attribute
Feb 21 11:18:57 initiator charon: 12[IKE] establishing CHILD_SA testconn
Feb 21 11:18:57 initiator charon: 12[ENC] generating IKE_AUTH request 1 [ IDi CERT \
N(INIT_CONTACT) CERTREQ IDr AUTH CPRQ(ADDR DNS) N(IPCOMP_SUP) SA TSi TSr \
N(MOBIKE_SUP) N(NO_ADD_ADDR) N(MULT_AUTH) N(EAP_ONLY) ]
Feb 21 11:18:57 initiator charon: 12[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500] (1564 bytes)
Feb 21 11:18:57 initiator charon: 09[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500]
Feb 21 11:18:59 initiator charon: 08[NET] received packet: from 10.50.0.2[4500] to \
192.168.1.55[4500]
Feb 21 11:18:59 initiator charon: 08[NET] waiting for data on sockets
Feb 21 11:18:59 initiator charon: 15[NET] received packet: from 10.50.0.2[4500] to \
192.168.1.55[4500] (1356 bytes)
Feb 21 11:18:59 initiator charon: 15[ENC] parsed IKE_AUTH response 1 [ IDr CERT AUTH \
CPRP(ADDR DNS) N(IPCOMP_SUP) SA TSi TSr N(AUTH_LFT) N(MOBIKE_SUP) \
N(ADD_4_ADDR) ]
Feb 21 11:18:59 initiator charon: 15[IKE] received end entity cert "C=DE, O=company, \
CN=responder.test"
Feb 21 11:18:59 initiator charon: 15[IKE] received IPCOMP_SUPPORTED notify
Feb 21 11:18:59 initiator charon: 15[CFG] using certificate "C=DE, O=company, \
CN=responder.test"
Feb 21 11:18:59 initiator charon: 15[CFG] using trusted ca certificate "C=DE, \
O=company, CN=Test CA"
Feb 21 11:18:59 initiator charon: 15[CFG] checking certificate status of "C=DE, \
O=company, CN=responder.test"
Feb 21 11:18:59 initiator charon: 15[CFG] certificate status is not available
Feb 21 11:18:59 initiator charon: 15[CFG] reached self-signed root ca with a path \
length of 0
Feb 21 11:18:59 initiator charon: 15[IKE] authentication of 'C=DE, O=company, \
CN=responder.test' with RSA signature successful
Feb 21 11:18:59 initiator charon: 15[IKE] IKE_SA testconn[10] established between \
192.168.1.55[C=DE, O=company, CN=initiator.test]...10.50.0.2[C=DE, O=company, \
CN=responder.test]
Feb 21 11:18:59 initiator charon: 15[IKE] IKE_SA testconn[10] state change: \
CONNECTING => ESTABLISHED
Feb 21 11:18:59 initiator charon: 15[IKE] scheduling reauthentication in 77s
Feb 21 11:18:59 initiator charon: 15[IKE] maximum IKE_SA lifetime 197s
Feb 21 11:18:59 initiator charon: 15[IKE] processing INTERNAL_IP4_ADDRESS attribute
Feb 21 11:18:59 initiator charon: 15[IKE] processing INTERNAL_IP4_DNS attribute
Feb 21 11:18:59 initiator charon: 15[IKE] installing DNS server 10.50.1.4 to \
/etc/resolv.conf
Feb 21 11:18:59 initiator charon: 15[IKE] installing new virtual IP 10.50.1.242
Feb 21 11:18:59 initiator charon: 15[IKE] CHILD_SA testconn{5} established with SPIs \
cda23df7_i cc73ac72_o and TS 10.50.1.242/32 === 10.50.1.0/24
Feb 21 11:18:59 initiator charon: 15[IKE] received AUTH_LIFETIME of 10143s, \
reauthentication already scheduled in 77s
Feb 21 11:18:59 initiator charon: 15[IKE] peer supports MOBIKE
Feb 21 11:18:59 initiator charon: 15[IKE] got additional MOBIKE peer address: \
10.50.1.4
Feb 21 11:18:59 initiator charon: 15[IKE] activating new tasks
Feb 21 11:18:59 initiator charon: 15[IKE] nothing to initiate
Feb 21 11:19:31 initiator charon: 01[IKE] sending DPD request
Feb 21 11:19:31 initiator charon: 01[IKE] queueing IKE_MOBIKE task
Feb 21 11:19:31 initiator charon: 01[IKE] activating new tasks
Feb 21 11:19:31 initiator charon: 01[IKE] activating IKE_MOBIKE task
Feb 21 11:19:31 initiator charon: 01[ENC] generating INFORMATIONAL request 2 [ \
N(NATD_S_IP) N(NATD_D_IP) ]
Feb 21 11:19:31 initiator charon: 01[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500] (124 bytes)
Feb 21 11:19:31 initiator charon: 09[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500]
Feb 21 11:19:31 initiator charon: 08[NET] received packet: from 10.50.0.2[4500] to \
192.168.1.55[4500]
Feb 21 11:19:31 initiator charon: 08[NET] waiting for data on sockets
Feb 21 11:19:31 initiator charon: 05[NET] received packet: from 10.50.0.2[4500] to \
192.168.1.55[4500] (124 bytes)
Feb 21 11:19:31 initiator charon: 05[ENC] parsed INFORMATIONAL response 2 [ \
N(NATD_S_IP) N(NATD_D_IP) ]
Feb 21 11:19:31 initiator charon: 05[IKE] activating new tasks
Feb 21 11:19:31 initiator charon: 05[IKE] nothing to initiate
Feb 21 11:19:35 initiator charon: 10[KNL] creating rekey job for ESP CHILD_SA with \
SPI cda23df7 and reqid {5}
Feb 21 11:19:35 initiator charon: 10[IKE] queueing CHILD_REKEY task
Feb 21 11:19:35 initiator charon: 10[IKE] activating new tasks
Feb 21 11:19:35 initiator charon: 10[IKE] activating CHILD_REKEY task
Feb 21 11:19:35 initiator charon: 10[IKE] establishing CHILD_SA testconn{5}
Feb 21 11:19:35 initiator charon: 10[ENC] generating CREATE_CHILD_SA request 3 [ \
N(REKEY_SA) N(IPCOMP_SUP) SA No KE TSi TSr ]
Feb 21 11:19:35 initiator charon: 10[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500] (636 bytes)
Feb 21 11:19:35 initiator charon: 09[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500]
Feb 21 11:19:35 initiator charon: 08[NET] received packet: from 10.50.0.2[4500] to \
192.168.1.55[4500]
Feb 21 11:19:35 initiator charon: 08[NET] waiting for data on sockets
Feb 21 11:19:35 initiator charon: 16[NET] received packet: from 10.50.0.2[4500] to \
192.168.1.55[4500] (476 bytes)
Feb 21 11:19:35 initiator charon: 16[ENC] parsed CREATE_CHILD_SA response 3 [ \
N(IPCOMP_SUP) SA No KE TSi TSr ]
Feb 21 11:19:35 initiator charon: 16[IKE] received IPCOMP_SUPPORTED notify
Feb 21 11:19:35 initiator charon: 16[IKE] CHILD_SA testconn{5} established with SPIs \
c18336b6_i c60a4fee_o and TS 10.50.1.242/32 === 10.50.1.0/24
Feb 21 11:19:35 initiator charon: 16[IKE] reinitiating already active tasks
Feb 21 11:19:35 initiator charon: 16[IKE] CHILD_REKEY task
Feb 21 11:19:35 initiator charon: 16[IKE] closing CHILD_SA testconn{5} with SPIs \
cda23df7_i (76 bytes) cc73ac72_o (76 bytes) and TS 10.50.1.242/32 === \
10.50.1.0/24
Feb 21 11:19:35 initiator charon: 16[IKE] sending DELETE for ESP CHILD_SA with SPI \
cda23df7
Feb 21 11:19:35 initiator charon: 16[ENC] generating INFORMATIONAL request 4 [ D ]
Feb 21 11:19:35 initiator charon: 16[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500] (76 bytes)
Feb 21 11:19:35 initiator charon: 09[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500]
Feb 21 11:19:35 initiator charon: 08[NET] received packet: from 10.50.0.2[4500] to \
192.168.1.55[4500]
Feb 21 11:19:35 initiator charon: 08[NET] waiting for data on sockets
Feb 21 11:19:35 initiator charon: 04[NET] received packet: from 10.50.0.2[4500] to \
192.168.1.55[4500] (76 bytes)
Feb 21 11:19:35 initiator charon: 04[ENC] parsed INFORMATIONAL response 4 [ D ]
Feb 21 11:19:35 initiator charon: 04[IKE] received DELETE for ESP CHILD_SA with SPI \
cc73ac72
Feb 21 11:19:35 initiator charon: 04[IKE] CHILD_SA closed
Feb 21 11:19:35 initiator charon: 04[IKE] activating new tasks
Feb 21 11:19:35 initiator charon: 04[IKE] nothing to initiate
Feb 21 11:19:59 initiator charon: 12[IKE] sending keep alive to 10.50.0.2[4500]
Feb 21 11:19:59 initiator charon: 09[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500]
Feb 21 11:20:05 initiator charon: 05[IKE] sending DPD request
Feb 21 11:20:05 initiator charon: 05[IKE] queueing IKE_MOBIKE task
Feb 21 11:20:05 initiator charon: 05[IKE] activating new tasks
Feb 21 11:20:05 initiator charon: 05[IKE] activating IKE_MOBIKE task
Feb 21 11:20:05 initiator charon: 05[ENC] generating INFORMATIONAL request 5 [ \
N(NATD_S_IP) N(NATD_D_IP) ]
Feb 21 11:20:05 initiator charon: 05[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500] (124 bytes)
Feb 21 11:20:05 initiator charon: 09[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500]
Feb 21 11:20:05 initiator charon: 08[NET] received packet: from 10.50.0.2[4500] to \
192.168.1.55[4500]
Feb 21 11:20:05 initiator charon: 08[NET] waiting for data on sockets
Feb 21 11:20:05 initiator charon: 03[NET] received packet: from 10.50.0.2[4500] to \
192.168.1.55[4500] (124 bytes)
Feb 21 11:20:05 initiator charon: 03[ENC] parsed INFORMATIONAL response 5 [ \
N(NATD_S_IP) N(NATD_D_IP) ]
Feb 21 11:20:05 initiator charon: 03[IKE] activating new tasks
Feb 21 11:20:05 initiator charon: 03[IKE] nothing to initiate
Feb 21 11:20:06 initiator charon: 15[KNL] creating rekey job for ESP CHILD_SA with \
SPI c60a4fee and reqid {5}
Feb 21 11:20:06 initiator charon: 15[IKE] queueing CHILD_REKEY task
Feb 21 11:20:06 initiator charon: 15[IKE] activating new tasks
Feb 21 11:20:06 initiator charon: 15[IKE] activating CHILD_REKEY task
Feb 21 11:20:06 initiator charon: 15[IKE] establishing CHILD_SA testconn{5}
Feb 21 11:20:06 initiator charon: 15[ENC] generating CREATE_CHILD_SA request 6 [ \
N(REKEY_SA) N(IPCOMP_SUP) SA No KE TSi TSr ]
Feb 21 11:20:06 initiator charon: 15[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500] (636 bytes)
Feb 21 11:20:06 initiator charon: 09[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500]
Feb 21 11:20:06 initiator charon: 08[NET] received packet: from 10.50.0.2[4500] to \
192.168.1.55[4500]
Feb 21 11:20:06 initiator charon: 08[NET] waiting for data on sockets
Feb 21 11:20:06 initiator charon: 16[NET] received packet: from 10.50.0.2[4500] to \
192.168.1.55[4500] (476 bytes)
Feb 21 11:20:06 initiator charon: 16[ENC] parsed CREATE_CHILD_SA response 6 [ \
N(IPCOMP_SUP) SA No KE TSi TSr ]
Feb 21 11:20:06 initiator charon: 16[IKE] received IPCOMP_SUPPORTED notify
Feb 21 11:20:06 initiator charon: 16[IKE] CHILD_SA testconn{5} established with SPIs \
cb0a3c6b_i c4844bbd_o and TS 10.50.1.242/32 === 10.50.1.0/24
Feb 21 11:20:06 initiator charon: 16[IKE] reinitiating already active tasks
Feb 21 11:20:06 initiator charon: 16[IKE] CHILD_REKEY task
Feb 21 11:20:06 initiator charon: 16[IKE] closing CHILD_SA testconn{5} with SPIs \
c18336b6_i (0 bytes) c60a4fee_o (0 bytes) and TS 10.50.1.242/32 === \
10.50.1.0/24
Feb 21 11:20:06 initiator charon: 16[IKE] sending DELETE for ESP CHILD_SA with SPI \
c18336b6
Feb 21 11:20:06 initiator charon: 16[ENC] generating INFORMATIONAL request 7 [ D ]
Feb 21 11:20:06 initiator charon: 16[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500] (76 bytes)
Feb 21 11:20:06 initiator charon: 09[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500]
Feb 21 11:20:06 initiator charon: 08[NET] received packet: from 10.50.0.2[4500] to \
192.168.1.55[4500]
Feb 21 11:20:06 initiator charon: 08[NET] waiting for data on sockets
Feb 21 11:20:06 initiator charon: 04[NET] received packet: from 10.50.0.2[4500] to \
192.168.1.55[4500] (76 bytes)
Feb 21 11:20:06 initiator charon: 04[ENC] parsed INFORMATIONAL response 7 [ D ]
Feb 21 11:20:06 initiator charon: 04[IKE] received DELETE for ESP CHILD_SA with SPI \
c60a4fee
Feb 21 11:20:06 initiator charon: 04[IKE] CHILD_SA closed
Feb 21 11:20:06 initiator charon: 04[IKE] activating new tasks
Feb 21 11:20:06 initiator charon: 04[IKE] nothing to initiate
Feb 21 11:20:13 initiator charon: 12[KNL] creating rekey job for ESP CHILD_SA with \
SPI c4844bbd and reqid {5}
Feb 21 11:20:13 initiator charon: 12[IKE] queueing CHILD_REKEY task
Feb 21 11:20:13 initiator charon: 12[IKE] activating new tasks
Feb 21 11:20:13 initiator charon: 12[IKE] activating CHILD_REKEY task
Feb 21 11:20:13 initiator charon: 12[IKE] establishing CHILD_SA testconn{5}
Feb 21 11:20:13 initiator charon: 12[ENC] generating CREATE_CHILD_SA request 8 [ \
N(REKEY_SA) N(IPCOMP_SUP) SA No KE TSi TSr ]
Feb 21 11:20:13 initiator charon: 12[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500] (636 bytes)
Feb 21 11:20:13 initiator charon: 09[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500]
Feb 21 11:20:13 initiator charon: 08[NET] received packet: from 10.50.0.2[4500] to \
192.168.1.55[4500]
Feb 21 11:20:13 initiator charon: 08[NET] waiting for data on sockets
Feb 21 11:20:13 initiator charon: 05[NET] received packet: from 10.50.0.2[4500] to \
192.168.1.55[4500] (476 bytes)
Feb 21 11:20:13 initiator charon: 05[ENC] parsed CREATE_CHILD_SA response 8 [ \
N(IPCOMP_SUP) SA No KE TSi TSr ]
Feb 21 11:20:13 initiator charon: 05[IKE] received IPCOMP_SUPPORTED notify
Feb 21 11:20:13 initiator charon: 05[IKE] CHILD_SA testconn{5} established with SPIs \
c74fe159_i cda46c1b_o and TS 10.50.1.242/32 === 10.50.1.0/24
Feb 21 11:20:13 initiator charon: 05[IKE] reinitiating already active tasks
Feb 21 11:20:13 initiator charon: 05[IKE] CHILD_REKEY task
Feb 21 11:20:13 initiator charon: 05[IKE] closing CHILD_SA testconn{5} with SPIs \
cb0a3c6b_i (0 bytes) c4844bbd_o (0 bytes) and TS 10.50.1.242/32 === \
10.50.1.0/24
Feb 21 11:20:13 initiator charon: 05[IKE] sending DELETE for ESP CHILD_SA with SPI \
cb0a3c6b
Feb 21 11:20:13 initiator charon: 05[ENC] generating INFORMATIONAL request 9 [ D ]
Feb 21 11:20:13 initiator charon: 05[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500] (76 bytes)
Feb 21 11:20:13 initiator charon: 09[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500]
Feb 21 11:20:13 initiator charon: 08[NET] received packet: from 10.50.0.2[4500] to \
192.168.1.55[4500]
Feb 21 11:20:13 initiator charon: 08[NET] waiting for data on sockets
Feb 21 11:20:13 initiator charon: 03[NET] received packet: from 10.50.0.2[4500] to \
192.168.1.55[4500] (76 bytes)
Feb 21 11:20:13 initiator charon: 03[ENC] parsed INFORMATIONAL response 9 [ D ]
Feb 21 11:20:13 initiator charon: 03[IKE] received DELETE for ESP CHILD_SA with SPI \
c4844bbd
Feb 21 11:20:13 initiator charon: 03[IKE] CHILD_SA closed
Feb 21 11:20:13 initiator charon: 03[IKE] activating new tasks
Feb 21 11:20:13 initiator charon: 03[IKE] nothing to initiate
Feb 21 11:20:16 initiator charon: 10[IKE] reauthenticating IKE_SA testconn[10]
Feb 21 11:20:16 initiator charon: 10[IKE] queueing IKE_REAUTH task
Feb 21 11:20:16 initiator charon: 10[IKE] activating new tasks
Feb 21 11:20:16 initiator charon: 10[IKE] activating IKE_REAUTH task
Feb 21 11:20:16 initiator charon: 10[IKE] deleting IKE_SA testconn[10] between \
192.168.1.55[C=DE, O=company, CN=initiator.test]...10.50.0.2[C=DE, O=company, \
CN=responder.test]
Feb 21 11:20:16 initiator charon: 10[IKE] IKE_SA testconn[10] state change: \
ESTABLISHED => DELETING
Feb 21 11:20:16 initiator charon: 10[IKE] sending DELETE for IKE_SA testconn[10]
Feb 21 11:20:16 initiator charon: 10[ENC] generating INFORMATIONAL request 10 [ D ]
Feb 21 11:20:16 initiator charon: 10[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500] (76 bytes)
Feb 21 11:20:16 initiator charon: 09[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500]
Feb 21 11:20:16 initiator charon: 08[NET] received packet: from 10.50.0.2[4500] to \
192.168.1.55[4500]
Feb 21 11:20:16 initiator charon: 08[NET] waiting for data on sockets
Feb 21 11:20:16 initiator charon: 15[NET] received packet: from 10.50.0.2[4500] to \
192.168.1.55[4500] (76 bytes)
Feb 21 11:20:16 initiator charon: 15[ENC] parsed INFORMATIONAL response 10 [ ]
Feb 21 11:20:16 initiator charon: 15[IKE] IKE_SA deleted
Feb 21 11:20:21 initiator charon: 15[IKE] installing new virtual IP 10.50.1.242
Feb 21 11:20:21 initiator charon: 15[IKE] restarting CHILD_SA testconn
Feb 21 11:20:21 initiator charon: 15[IKE] queueing IKE_VENDOR task
Feb 21 11:20:21 initiator charon: 15[IKE] queueing IKE_INIT task
Feb 21 11:20:21 initiator charon: 15[IKE] queueing IKE_NATD task
Feb 21 11:20:21 initiator charon: 15[IKE] queueing IKE_CERT_PRE task
Feb 21 11:20:21 initiator charon: 15[IKE] queueing IKE_AUTH task
Feb 21 11:20:21 initiator charon: 15[IKE] queueing IKE_CERT_POST task
Feb 21 11:20:21 initiator charon: 15[IKE] queueing IKE_CONFIG task
Feb 21 11:20:21 initiator charon: 15[IKE] queueing IKE_AUTH_LIFETIME task
Feb 21 11:20:21 initiator charon: 15[IKE] queueing IKE_MOBIKE task
Feb 21 11:20:21 initiator charon: 15[IKE] queueing IKE_ME task
Feb 21 11:20:21 initiator charon: 15[IKE] queueing CHILD_CREATE task
Feb 21 11:20:21 initiator charon: 15[IKE] activating new tasks
Feb 21 11:20:21 initiator charon: 15[IKE] activating IKE_VENDOR task
Feb 21 11:20:21 initiator charon: 15[IKE] activating IKE_INIT task
Feb 21 11:20:21 initiator charon: 15[IKE] activating IKE_NATD task
Feb 21 11:20:21 initiator charon: 15[IKE] activating IKE_CERT_PRE task
Feb 21 11:20:21 initiator charon: 15[IKE] activating IKE_ME task
Feb 21 11:20:21 initiator charon: 15[IKE] activating IKE_AUTH task
Feb 21 11:20:21 initiator charon: 15[IKE] activating IKE_CERT_POST task
Feb 21 11:20:21 initiator charon: 15[IKE] activating IKE_CONFIG task
Feb 21 11:20:21 initiator charon: 15[IKE] activating CHILD_CREATE task
Feb 21 11:20:21 initiator charon: 15[IKE] activating IKE_AUTH_LIFETIME task
Feb 21 11:20:21 initiator charon: 15[IKE] activating IKE_MOBIKE task
Feb 21 11:20:21 initiator charon: 15[IKE] initiating IKE_SA testconn[11] to 10.50.0.2
Feb 21 11:20:21 initiator charon: 15[IKE] IKE_SA testconn[11] state change: CREATED \
=> CONNECTING
Feb 21 11:20:21 initiator charon: 15[ENC] generating IKE_SA_INIT request 0 [ SA KE No \
N(NATD_S_IP) N(NATD_D_IP) ]
Feb 21 11:20:21 initiator charon: 15[NET] sending packet: from 192.168.1.55[500] to \
10.50.0.2[500] (564 bytes)
Feb 21 11:20:21 initiator charon: 09[NET] sending packet: from 192.168.1.55[500] to \
10.50.0.2[500]
Feb 21 11:20:21 initiator charon: 15[IKE] IKE_SA testconn[10] state change: DELETING \
=> DESTROYING
Feb 21 11:20:21 initiator charon: 15[IKE] removing DNS server 10.50.1.4 from \
/etc/resolv.conf
Feb 21 11:20:21 initiator charon: 08[NET] received packet: from 10.50.0.2[500] to \
192.168.1.55[500]
Feb 21 11:20:21 initiator charon: 08[NET] waiting for data on sockets
Feb 21 11:20:21 initiator charon: 11[NET] received packet: from 10.50.0.2[500] to \
192.168.1.55[500] (465 bytes)
Feb 21 11:20:21 initiator charon: 11[ENC] parsed IKE_SA_INIT response 0 [ SA KE No \
N(NATD_S_IP) N(NATD_D_IP) CERTREQ N(MULT_AUTH) ]
Feb 21 11:20:21 initiator charon: 11[IKE] local host is behind NAT, sending keep \
alives
Feb 21 11:20:21 initiator charon: 11[IKE] received cert request for "C=DE, O=company, \
CN=Test CA"
Feb 21 11:20:21 initiator charon: 11[IKE] reinitiating already active tasks
Feb 21 11:20:21 initiator charon: 11[IKE] IKE_CERT_PRE task
Feb 21 11:20:21 initiator charon: 11[IKE] IKE_AUTH task
Feb 21 11:20:21 initiator charon: 11[IKE] sending cert request for "C=DE, O=company, \
CN=Test CA"
Feb 21 11:20:21 initiator charon: 11[IKE] authentication of 'C=DE, O=company, \
CN=initiator.test' (myself) with RSA signature successful
Feb 21 11:20:21 initiator charon: 11[IKE] sending end entity cert "C=DE, O=company, \
CN=initiator.test"
Feb 21 11:20:21 initiator charon: 11[IKE] building INTERNAL_IP4_DNS attribute
Feb 21 11:20:21 initiator charon: 11[IKE] establishing CHILD_SA testconn{5}
Feb 21 11:20:21 initiator charon: 11[ENC] generating IKE_AUTH request 1 [ IDi CERT \
N(INIT_CONTACT) CERTREQ IDr AUTH CPRQ(ADDR DNS) N(IPCOMP_SUP) SA TSi TSr \
N(MOBIKE_SUP) N(NO_ADD_ADDR) N(MULT_AUTH) N(EAP_ONLY) ]
Feb 21 11:20:21 initiator charon: 11[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500] (1564 bytes)
Feb 21 11:20:21 initiator charon: 09[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500]
Feb 21 11:20:23 initiator charon: 08[NET] received packet: from 10.50.0.2[4500] to \
192.168.1.55[4500]
Feb 21 11:20:23 initiator charon: 08[NET] waiting for data on sockets
Feb 21 11:20:23 initiator charon: 01[NET] received packet: from 10.50.0.2[4500] to \
192.168.1.55[4500] (1260 bytes)
Feb 21 11:20:23 initiator charon: 01[ENC] parsed IKE_AUTH response 1 [ IDr CERT AUTH \
CPRP(ADDR DNS) N(AUTH_LFT) N(MOBIKE_SUP) N(ADD_4_ADDR) N(TS_UNACCEPT) \
]
Feb 21 11:20:23 initiator charon: 01[IKE] received end entity cert "C=DE, O=company, \
CN=responder.test"
Feb 21 11:20:23 initiator charon: 01[CFG] using certificate "C=DE, O=company, \
CN=responder.test"
Feb 21 11:20:23 initiator charon: 01[CFG] using trusted ca certificate "C=DE, \
O=company, CN=Test CA"
Feb 21 11:20:23 initiator charon: 01[CFG] checking certificate status of "C=DE, \
O=company, CN=responder.test"
Feb 21 11:20:23 initiator charon: 01[CFG] certificate status is not available
Feb 21 11:20:23 initiator charon: 01[CFG] reached self-signed root ca with a path \
length of 0
Feb 21 11:20:23 initiator charon: 01[IKE] authentication of 'C=DE, O=company, \
CN=responder.test' with RSA signature successful
Feb 21 11:20:23 initiator charon: 01[IKE] IKE_SA testconn[11] established between \
192.168.1.55[C=DE, O=company, CN=initiator.test]...10.50.0.2[C=DE, O=company, \
CN=responder.test]
Feb 21 11:20:23 initiator charon: 01[IKE] IKE_SA testconn[11] state change: \
CONNECTING => ESTABLISHED
Feb 21 11:20:23 initiator charon: 01[IKE] scheduling reauthentication in 75s
Feb 21 11:20:23 initiator charon: 01[IKE] maximum IKE_SA lifetime 195s
Feb 21 11:20:23 initiator charon: 01[IKE] processing INTERNAL_IP4_ADDRESS attribute
Feb 21 11:20:23 initiator charon: 01[IKE] processing INTERNAL_IP4_DNS attribute
Feb 21 11:20:23 initiator charon: 01[IKE] installing DNS server 10.50.1.4 to \
/etc/resolv.conf
Feb 21 11:20:23 initiator charon: 01[IKE] installing new virtual IP 10.50.1.208
Feb 21 11:20:23 initiator charon: 01[IKE] received TS_UNACCEPTABLE notify, no \
CHILD_SA built
Feb 21 11:20:23 initiator charon: 01[IKE] failed to establish CHILD_SA, keeping \
IKE_SA
Feb 21 11:20:23 initiator charon: 01[IKE] received AUTH_LIFETIME of 9903s, \
reauthentication already scheduled in 75s
Feb 21 11:20:23 initiator charon: 01[IKE] peer supports MOBIKE
Feb 21 11:20:23 initiator charon: 01[IKE] got additional MOBIKE peer address: \
10.50.1.4
Feb 21 11:20:23 initiator charon: 01[IKE] activating new tasks
Feb 21 11:20:23 initiator charon: 01[IKE] nothing to initiate
Feb 21 11:20:45 initiator charon: 15[IKE] sending keep alive to 10.50.0.2[4500]
Feb 21 11:20:45 initiator charon: 09[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500]
Feb 21 11:20:53 initiator charon: 11[IKE] sending DPD request
Feb 21 11:20:53 initiator charon: 11[IKE] queueing IKE_MOBIKE task
Feb 21 11:20:53 initiator charon: 11[IKE] activating new tasks
Feb 21 11:20:53 initiator charon: 11[IKE] activating IKE_MOBIKE task
Feb 21 11:20:53 initiator charon: 11[ENC] generating INFORMATIONAL request 2 [ \
N(NATD_S_IP) N(NATD_D_IP) ]
Feb 21 11:20:53 initiator charon: 11[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500] (124 bytes)
Feb 21 11:20:53 initiator charon: 09[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500]
Feb 21 11:20:53 initiator charon: 08[NET] received packet: from 10.50.0.2[4500] to \
192.168.1.55[4500]
Feb 21 11:20:53 initiator charon: 08[NET] waiting for data on sockets
Feb 21 11:20:53 initiator charon: 12[NET] received packet: from 10.50.0.2[4500] to \
192.168.1.55[4500] (124 bytes)
Feb 21 11:20:53 initiator charon: 12[ENC] parsed INFORMATIONAL response 2 [ \
N(NATD_S_IP) N(NATD_D_IP) ]
Feb 21 11:20:53 initiator charon: 12[IKE] activating new tasks
Feb 21 11:20:53 initiator charon: 12[IKE] nothing to initiate
Feb 21 11:21:17 initiator charon: 01[IKE] sending keep alive to 10.50.0.2[4500]
Feb 21 11:21:17 initiator charon: 09[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500]
Feb 21 11:21:23 initiator charon: 04[IKE] sending DPD request
Feb 21 11:21:23 initiator charon: 04[IKE] queueing IKE_MOBIKE task
Feb 21 11:21:23 initiator charon: 04[IKE] activating new tasks
Feb 21 11:21:23 initiator charon: 04[IKE] activating IKE_MOBIKE task
Feb 21 11:21:23 initiator charon: 04[ENC] generating INFORMATIONAL request 3 [ \
N(NATD_S_IP) N(NATD_D_IP) ]
Feb 21 11:21:23 initiator charon: 04[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500] (124 bytes)
Feb 21 11:21:23 initiator charon: 09[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500]
Feb 21 11:21:23 initiator charon: 08[NET] received packet: from 10.50.0.2[4500] to \
192.168.1.55[4500]
Feb 21 11:21:23 initiator charon: 08[NET] waiting for data on sockets
Feb 21 11:21:23 initiator charon: 13[NET] received packet: from 10.50.0.2[4500] to \
192.168.1.55[4500] (124 bytes)
Feb 21 11:21:23 initiator charon: 13[ENC] parsed INFORMATIONAL response 3 [ \
N(NATD_S_IP) N(NATD_D_IP) ]
Feb 21 11:21:23 initiator charon: 13[IKE] activating new tasks
Feb 21 11:21:23 initiator charon: 13[IKE] nothing to initiate
Feb 21 11:21:38 initiator charon: 14[IKE] reauthenticating IKE_SA testconn[11]
Feb 21 11:21:38 initiator charon: 14[IKE] queueing IKE_REAUTH task
Feb 21 11:21:38 initiator charon: 14[IKE] activating new tasks
Feb 21 11:21:38 initiator charon: 14[IKE] activating IKE_REAUTH task
Feb 21 11:21:38 initiator charon: 14[IKE] deleting IKE_SA testconn[11] between \
192.168.1.55[C=DE, O=company, CN=initiator.test]...10.50.0.2[C=DE, O=company, \
CN=responder.test]
Feb 21 11:21:38 initiator charon: 14[IKE] IKE_SA testconn[11] state change: \
ESTABLISHED => DELETING
Feb 21 11:21:38 initiator charon: 14[IKE] sending DELETE for IKE_SA testconn[11]
Feb 21 11:21:38 initiator charon: 14[ENC] generating INFORMATIONAL request 4 [ D ]
Feb 21 11:21:38 initiator charon: 14[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500] (76 bytes)
Feb 21 11:21:38 initiator charon: 09[NET] sending packet: from 192.168.1.55[4500] to \
10.50.0.2[4500]
Feb 21 11:21:38 initiator charon: 08[NET] received packet: from 10.50.0.2[4500] to \
192.168.1.55[4500]
Feb 21 11:21:38 initiator charon: 08[NET] waiting for data on sockets
Feb 21 11:21:38 initiator charon: 15[NET] received packet: from 10.50.0.2[4500] to \
192.168.1.55[4500] (76 bytes)
Feb 21 11:21:38 initiator charon: 15[ENC] parsed INFORMATIONAL response 4 [ ]
Feb 21 11:21:38 initiator charon: 15[IKE] IKE_SA deleted
Feb 21 11:21:38 initiator charon: 15[IKE] unable to reauthenticate IKE_SA, no \
CHILD_SA to recreate
Feb 21 11:21:38 initiator charon: 15[IKE] reauthenticating IKE_SA failed
Feb 21 11:21:38 initiator charon: 15[IKE] IKE_SA testconn[11] state change: DELETING \
=> DESTROYING
Feb 21 11:21:38 initiator charon: 15[IKE] removing DNS server 10.50.1.4 from \
/etc/resolv.conf
["ike-rekey-responder.log" (text/x-log)]
Feb 21 11:19:58 responder charon: 16[NET] received packet: from 10.50.2.7[500] to \
10.50.0.2[500] (564 bytes)
Feb 21 11:19:58 responder charon: 16[ENC] parsed IKE_SA_INIT request 0 [ SA KE No \
N(NATD_S_IP) N(NATD_D_IP) ]
Feb 21 11:19:58 responder charon: 16[IKE] 10.50.2.7 is initiating an IKE_SA
Feb 21 11:19:58 responder charon: 16[IKE] remote host is behind NAT
Feb 21 11:19:58 responder charon: 16[IKE] sending cert request for "C=DE, O=company, \
CN=Test CA"
Feb 21 11:19:58 responder charon: 16[ENC] generating IKE_SA_INIT response 0 [ SA KE \
No N(NATD_S_IP) N(NATD_D_IP) CERTREQ N(MULT_AUTH) ]
Feb 21 11:19:58 responder charon: 16[NET] sending packet: from 10.50.0.2[500] to \
10.50.2.7[500] (465 bytes)
Feb 21 11:19:58 responder charon: 01[NET] received packet: from 10.50.2.7[4500] to \
10.50.0.2[4500] (1564 bytes)
Feb 21 11:19:58 responder charon: 01[ENC] parsed IKE_AUTH request 1 [ IDi CERT \
N(INIT_CONTACT) CERTREQ IDr AUTH CPRQ(ADDR DNS) N(IPCOMP_SUP) SA TSi TSr \
N(MOBIKE_SUP) N(NO_ADD_ADDR) N(MULT_AUTH) N(EAP_ONLY) ]
Feb 21 11:19:58 responder charon: 01[IKE] received cert request for "C=DE, O=company, \
CN=Test CA"
Feb 21 11:19:58 responder charon: 01[IKE] received end entity cert "C=DE, O=company, \
CN=initiator.test"
Feb 21 11:19:58 responder charon: 01[CFG] looking for peer configs matching \
10.50.0.2[C=DE, O=company, CN=responder.test]...10.50.2.7[C=DE, O=company, \
CN=initiator.test]
Feb 21 11:19:58 responder charon: 01[CFG] selected peer config 'testconn'
Feb 21 11:19:58 responder charon: 01[CFG] using certificate "C=DE, O=company, \
CN=initiator.test"
Feb 21 11:19:58 responder charon: 01[CFG] using trusted ca certificate "C=DE, \
O=company, CN=Test CA"
Feb 21 11:19:58 responder charon: 01[CFG] checking certificate status of "C=DE, \
O=company, CN=initiator.test"
Feb 21 11:19:58 responder charon: 01[CFG] certificate status is not available
Feb 21 11:19:58 responder charon: 01[CFG] reached self-signed root ca with a path \
length of 0
Feb 21 11:19:58 responder charon: 01[IKE] authentication of 'C=DE, O=company, \
CN=initiator.test' with RSA signature successful
Feb 21 11:19:58 responder charon: 01[IKE] peer supports MOBIKE
Feb 21 11:19:58 responder charon: 01[IKE] authentication of 'C=DE, O=company, \
CN=responder.test' (myself) with RSA signature successful
Feb 21 11:19:58 responder charon: 01[IKE] IKE_SA testconn[10] established between \
10.50.0.2[C=DE, O=company, CN=responder.test]...10.50.2.7[C=DE, O=company, \
CN=initiator.test]
Feb 21 11:19:58 responder charon: 01[IKE] scheduling reauthentication in 10145s
Feb 21 11:19:58 responder charon: 01[IKE] maximum IKE_SA lifetime 10685s
Feb 21 11:19:58 responder charon: 01[IKE] sending end entity cert "C=DE, O=company, \
CN=responder.test"
Feb 21 11:19:58 responder charon: 01[IKE] peer requested virtual IP %any
Feb 21 11:19:58 responder charon: 01[CFG] sending DHCP DISCOVER to 10.50.1.255
Feb 21 11:19:59 responder charon: 01[CFG] sending DHCP DISCOVER to 10.50.1.255
Feb 21 11:20:00 responder charon: 06[CFG] received DHCP OFFER 10.50.1.242 from \
10.50.1.4
Feb 21 11:20:00 responder charon: 01[CFG] sending DHCP REQUEST for 10.50.1.242 to \
10.50.1.4
Feb 21 11:20:00 responder charon: 01[CFG] sending DHCP REQUEST for 10.50.1.242 to \
10.50.1.4
Feb 21 11:20:00 responder charon: 05[CFG] received DHCP ACK for 10.50.1.242
Feb 21 11:20:00 responder charon: 01[IKE] assigning virtual IP 10.50.1.242 to peer \
'C=DE, O=company, CN=initiator.test'
Feb 21 11:20:00 responder charon: 01[IKE] CHILD_SA testconn{10} established with SPIs \
cc73ac72_i cda23df7_o and TS 10.50.1.0/24 === 10.50.1.242/32
Feb 21 11:20:00 responder charon: 01[ENC] generating IKE_AUTH response 1 [ IDr CERT \
AUTH CPRP(ADDR DNS) N(IPCOMP_SUP) SA TSi TSr N(AUTH_LFT) N(MOBIKE_SUP) N(ADD_4_ADDR) \
]
Feb 21 11:20:00 responder charon: 01[NET] sending packet: from 10.50.0.2[4500] to \
10.50.2.7[4500] (1356 bytes)
Feb 21 11:20:33 responder charon: 11[NET] received packet: from 10.50.2.7[4500] to \
10.50.0.2[4500] (124 bytes)
Feb 21 11:20:33 responder charon: 11[ENC] parsed INFORMATIONAL request 2 [ \
N(NATD_S_IP) N(NATD_D_IP) ]
Feb 21 11:20:33 responder charon: 11[ENC] generating INFORMATIONAL response 2 [ \
N(NATD_S_IP) N(NATD_D_IP) ]
Feb 21 11:20:33 responder charon: 11[NET] sending packet: from 10.50.0.2[4500] to \
10.50.2.7[4500] (124 bytes)
Feb 21 11:20:37 responder charon: 02[NET] received packet: from 10.50.2.7[4500] to \
10.50.0.2[4500] (636 bytes)
Feb 21 11:20:37 responder charon: 02[ENC] parsed CREATE_CHILD_SA request 3 [ \
N(REKEY_SA) N(IPCOMP_SUP) SA No KE TSi TSr ]
Feb 21 11:20:37 responder charon: 02[IKE] CHILD_SA testconn{10} established with SPIs \
c60a4fee_i c18336b6_o and TS 10.50.1.0/24 === 10.50.1.242/32
Feb 21 11:20:37 responder charon: 02[ENC] generating CREATE_CHILD_SA response 3 [ \
N(IPCOMP_SUP) SA No KE TSi TSr ]
Feb 21 11:20:37 responder charon: 02[NET] sending packet: from 10.50.0.2[4500] to \
10.50.2.7[4500] (476 bytes)
Feb 21 11:20:37 responder charon: 13[NET] received packet: from 10.50.2.7[4500] to \
10.50.0.2[4500] (76 bytes)
Feb 21 11:20:37 responder charon: 13[ENC] parsed INFORMATIONAL request 4 [ D ]
Feb 21 11:20:37 responder charon: 13[IKE] received DELETE for ESP CHILD_SA with SPI \
cda23df7
Feb 21 11:20:37 responder charon: 13[IKE] closing CHILD_SA testconn{10} with SPIs \
cc73ac72_i (76 bytes) cda23df7_o (76 bytes) and TS 10.50.1.0/24 === \
10.50.1.242/32
Feb 21 11:20:37 responder charon: 13[IKE] sending DELETE for ESP CHILD_SA with SPI \
cc73ac72
Feb 21 11:20:37 responder charon: 13[IKE] CHILD_SA closed
Feb 21 11:20:37 responder charon: 13[ENC] generating INFORMATIONAL response 4 [ D ]
Feb 21 11:20:37 responder charon: 13[NET] sending packet: from 10.50.0.2[4500] to \
10.50.2.7[4500] (76 bytes)
Feb 21 11:21:08 responder charon: 06[NET] received packet: from 10.50.2.7[4500] to \
10.50.0.2[4500] (124 bytes)
Feb 21 11:21:08 responder charon: 06[ENC] parsed INFORMATIONAL request 5 [ \
N(NATD_S_IP) N(NATD_D_IP) ]
Feb 21 11:21:08 responder charon: 06[ENC] generating INFORMATIONAL response 5 [ \
N(NATD_S_IP) N(NATD_D_IP) ]
Feb 21 11:21:08 responder charon: 06[NET] sending packet: from 10.50.0.2[4500] to \
10.50.2.7[4500] (124 bytes)
Feb 21 11:21:09 responder charon: 12[NET] received packet: from 10.50.2.7[4500] to \
10.50.0.2[4500] (636 bytes)
Feb 21 11:21:09 responder charon: 12[ENC] parsed CREATE_CHILD_SA request 6 [ \
N(REKEY_SA) N(IPCOMP_SUP) SA No KE TSi TSr ]
Feb 21 11:21:09 responder charon: 12[IKE] CHILD_SA testconn{10} established with SPIs \
c4844bbd_i cb0a3c6b_o and TS 10.50.1.0/24 === 10.50.1.242/32
Feb 21 11:21:09 responder charon: 12[ENC] generating CREATE_CHILD_SA response 6 [ \
N(IPCOMP_SUP) SA No KE TSi TSr ]
Feb 21 11:21:09 responder charon: 12[NET] sending packet: from 10.50.0.2[4500] to \
10.50.2.7[4500] (476 bytes)
Feb 21 11:21:09 responder charon: 05[NET] received packet: from 10.50.2.7[4500] to \
10.50.0.2[4500] (76 bytes)
Feb 21 11:21:09 responder charon: 05[ENC] parsed INFORMATIONAL request 7 [ D ]
Feb 21 11:21:09 responder charon: 05[IKE] received DELETE for ESP CHILD_SA with SPI \
c18336b6
Feb 21 11:21:09 responder charon: 05[IKE] closing CHILD_SA testconn{10} with SPIs \
c60a4fee_i (0 bytes) c18336b6_o (0 bytes) and TS 10.50.1.0/24 === \
10.50.1.242/32
Feb 21 11:21:09 responder charon: 05[IKE] sending DELETE for ESP CHILD_SA with SPI \
c60a4fee
Feb 21 11:21:09 responder charon: 05[IKE] CHILD_SA closed
Feb 21 11:21:09 responder charon: 05[ENC] generating INFORMATIONAL response 7 [ D ]
Feb 21 11:21:09 responder charon: 05[NET] sending packet: from 10.50.0.2[4500] to \
10.50.2.7[4500] (76 bytes)
Feb 21 11:21:16 responder charon: 15[NET] received packet: from 10.50.2.7[4500] to \
10.50.0.2[4500] (636 bytes)
Feb 21 11:21:16 responder charon: 15[ENC] parsed CREATE_CHILD_SA request 8 [ \
N(REKEY_SA) N(IPCOMP_SUP) SA No KE TSi TSr ]
Feb 21 11:21:16 responder charon: 15[IKE] CHILD_SA testconn{10} established with SPIs \
cda46c1b_i c74fe159_o and TS 10.50.1.0/24 === 10.50.1.242/32
Feb 21 11:21:16 responder charon: 15[ENC] generating CREATE_CHILD_SA response 8 [ \
N(IPCOMP_SUP) SA No KE TSi TSr ]
Feb 21 11:21:16 responder charon: 15[NET] sending packet: from 10.50.0.2[4500] to \
10.50.2.7[4500] (476 bytes)
Feb 21 11:21:16 responder charon: 03[NET] received packet: from 10.50.2.7[4500] to \
10.50.0.2[4500] (76 bytes)
Feb 21 11:21:16 responder charon: 03[ENC] parsed INFORMATIONAL request 9 [ D ]
Feb 21 11:21:16 responder charon: 03[IKE] received DELETE for ESP CHILD_SA with SPI \
cb0a3c6b
Feb 21 11:21:16 responder charon: 03[IKE] closing CHILD_SA testconn{10} with SPIs \
c4844bbd_i (0 bytes) cb0a3c6b_o (0 bytes) and TS 10.50.1.0/24 === \
10.50.1.242/32
Feb 21 11:21:16 responder charon: 03[IKE] sending DELETE for ESP CHILD_SA with SPI \
c4844bbd
Feb 21 11:21:16 responder charon: 03[IKE] CHILD_SA closed
Feb 21 11:21:16 responder charon: 03[ENC] generating INFORMATIONAL response 9 [ D ]
Feb 21 11:21:16 responder charon: 03[NET] sending packet: from 10.50.0.2[4500] to \
10.50.2.7[4500] (76 bytes)
Feb 21 11:21:19 responder charon: 01[NET] received packet: from 10.50.2.7[4500] to \
10.50.0.2[4500] (76 bytes)
Feb 21 11:21:19 responder charon: 01[ENC] parsed INFORMATIONAL request 10 [ D ]
Feb 21 11:21:19 responder charon: 01[IKE] received DELETE for IKE_SA testconn[10]
Feb 21 11:21:19 responder charon: 01[IKE] deleting IKE_SA testconn[10] between \
10.50.0.2[C=DE, O=company, CN=responder.test]...10.50.2.7[C=DE, O=company, \
CN=initiator.test]
Feb 21 11:21:19 responder charon: 01[IKE] IKE_SA deleted
Feb 21 11:21:19 responder charon: 01[ENC] generating INFORMATIONAL response 10 [ ]
Feb 21 11:21:19 responder charon: 01[NET] sending packet: from 10.50.0.2[4500] to \
10.50.2.7[4500] (76 bytes)
Feb 21 11:21:19 responder charon: 01[CFG] sending DHCP RELEASE for 10.50.1.242 to \
10.50.1.4
Feb 21 11:21:24 responder charon: 11[NET] received packet: from 10.50.2.7[500] to \
10.50.0.2[500] (564 bytes)
Feb 21 11:21:24 responder charon: 11[ENC] parsed IKE_SA_INIT request 0 [ SA KE No \
N(NATD_S_IP) N(NATD_D_IP) ]
Feb 21 11:21:24 responder charon: 11[IKE] 10.50.2.7 is initiating an IKE_SA
Feb 21 11:21:24 responder charon: 11[IKE] remote host is behind NAT
Feb 21 11:21:24 responder charon: 11[IKE] sending cert request for "C=DE, O=company, \
CN=Test CA"
Feb 21 11:21:24 responder charon: 11[ENC] generating IKE_SA_INIT response 0 [ SA KE \
No N(NATD_S_IP) N(NATD_D_IP) CERTREQ N(MULT_AUTH) ]
Feb 21 11:21:24 responder charon: 11[NET] sending packet: from 10.50.0.2[500] to \
10.50.2.7[500] (465 bytes)
Feb 21 11:21:24 responder charon: 02[NET] received packet: from 10.50.2.7[4500] to \
10.50.0.2[4500] (1564 bytes)
Feb 21 11:21:24 responder charon: 02[ENC] parsed IKE_AUTH request 1 [ IDi CERT \
N(INIT_CONTACT) CERTREQ IDr AUTH CPRQ(ADDR DNS) N(IPCOMP_SUP) SA TSi TSr \
N(MOBIKE_SUP) N(NO_ADD_ADDR) N(MULT_AUTH) N(EAP_ONLY) ]
Feb 21 11:21:24 responder charon: 02[IKE] received cert request for "C=DE, O=company, \
CN=Test CA"
Feb 21 11:21:24 responder charon: 02[IKE] received end entity cert "C=DE, O=company, \
CN=initiator.test"
Feb 21 11:21:24 responder charon: 02[CFG] looking for peer configs matching \
10.50.0.2[C=DE, O=company, CN=responder.test]...10.50.2.7[C=DE, O=company, \
CN=initiator.test]
Feb 21 11:21:24 responder charon: 02[CFG] selected peer config 'testconn'
Feb 21 11:21:24 responder charon: 02[CFG] using certificate "C=DE, O=company, \
CN=initiator.test"
Feb 21 11:21:24 responder charon: 02[CFG] using trusted ca certificate "C=DE, \
O=company, CN=Test CA"
Feb 21 11:21:24 responder charon: 02[CFG] checking certificate status of "C=DE, \
O=company, CN=initiator.test"
Feb 21 11:21:24 responder charon: 02[CFG] certificate status is not available
Feb 21 11:21:24 responder charon: 02[CFG] reached self-signed root ca with a path \
length of 0
Feb 21 11:21:24 responder charon: 02[IKE] authentication of 'C=DE, O=company, \
CN=initiator.test' with RSA signature successful
Feb 21 11:21:24 responder charon: 02[IKE] peer supports MOBIKE
Feb 21 11:21:24 responder charon: 02[IKE] authentication of 'C=DE, O=company, \
CN=responder.test' (myself) with RSA signature successful
Feb 21 11:21:24 responder charon: 02[IKE] IKE_SA testconn[11] established between \
10.50.0.2[C=DE, O=company, CN=responder.test]...10.50.2.7[C=DE, O=company, \
CN=initiator.test]
Feb 21 11:21:24 responder charon: 02[IKE] scheduling reauthentication in 9905s
Feb 21 11:21:24 responder charon: 02[IKE] maximum IKE_SA lifetime 10445s
Feb 21 11:21:24 responder charon: 02[IKE] sending end entity cert "C=DE, O=company, \
CN=responder.test"
Feb 21 11:21:24 responder charon: 02[IKE] peer requested virtual IP 10.50.1.242
Feb 21 11:21:24 responder charon: 02[CFG] sending DHCP DISCOVER to 10.50.1.255
Feb 21 11:21:25 responder charon: 02[CFG] sending DHCP DISCOVER to 10.50.1.255
Feb 21 11:21:26 responder charon: 13[CFG] received DHCP OFFER 10.50.1.208 from \
10.50.1.4
Feb 21 11:21:26 responder charon: 02[CFG] sending DHCP REQUEST for 10.50.1.208 to \
10.50.1.4
Feb 21 11:21:26 responder charon: 02[CFG] sending DHCP REQUEST for 10.50.1.208 to \
10.50.1.4
Feb 21 11:21:26 responder charon: 16[CFG] received DHCP ACK for 10.50.1.208
Feb 21 11:21:26 responder charon: 02[IKE] assigning virtual IP 10.50.1.208 to peer \
'C=DE, O=company, CN=initiator.test'
Feb 21 11:21:26 responder charon: 02[IKE] traffic selectors 0.0.0.0/0 === \
10.50.1.242/32 inacceptable
Feb 21 11:21:26 responder charon: 02[IKE] failed to establish CHILD_SA, keeping \
IKE_SA
Feb 21 11:21:26 responder charon: 02[ENC] generating IKE_AUTH response 1 [ IDr CERT \
AUTH CPRP(ADDR DNS) N(AUTH_LFT) N(MOBIKE_SUP) N(ADD_4_ADDR) \
N(TS_UNACCEPT) ]
Feb 21 11:21:26 responder charon: 02[NET] sending packet: from 10.50.0.2[4500] to \
10.50.2.7[4500] (1260 bytes)
Feb 21 11:21:57 responder charon: 03[NET] received packet: from 10.50.2.7[4500] to \
10.50.0.2[4500] (124 bytes)
Feb 21 11:21:57 responder charon: 03[ENC] parsed INFORMATIONAL request 2 [ \
N(NATD_S_IP) N(NATD_D_IP) ]
Feb 21 11:21:57 responder charon: 03[ENC] generating INFORMATIONAL response 2 [ \
N(NATD_S_IP) N(NATD_D_IP) ]
Feb 21 11:21:57 responder charon: 03[NET] sending packet: from 10.50.0.2[4500] to \
10.50.2.7[4500] (124 bytes)
Feb 21 11:22:27 responder charon: 04[NET] received packet: from 10.50.2.7[4500] to \
10.50.0.2[4500] (124 bytes)
Feb 21 11:22:27 responder charon: 04[ENC] parsed INFORMATIONAL request 3 [ \
N(NATD_S_IP) N(NATD_D_IP) ]
Feb 21 11:22:27 responder charon: 04[ENC] generating INFORMATIONAL response 3 [ \
N(NATD_S_IP) N(NATD_D_IP) ]
Feb 21 11:22:27 responder charon: 04[NET] sending packet: from 10.50.0.2[4500] to \
10.50.2.7[4500] (124 bytes)
Feb 21 11:22:43 responder charon: 11[NET] received packet: from 10.50.2.7[4500] to \
10.50.0.2[4500] (76 bytes)
Feb 21 11:22:43 responder charon: 11[ENC] parsed INFORMATIONAL request 4 [ D ]
Feb 21 11:22:43 responder charon: 11[IKE] received DELETE for IKE_SA testconn[11]
Feb 21 11:22:43 responder charon: 11[IKE] deleting IKE_SA testconn[11] between \
10.50.0.2[C=DE, O=company, CN=responder.test]...10.50.2.7[C=DE, O=company, \
CN=initiator.test]
Feb 21 11:22:43 responder charon: 11[IKE] IKE_SA deleted
Feb 21 11:22:43 responder charon: 11[ENC] generating INFORMATIONAL response 4 [ ]
Feb 21 11:22:43 responder charon: 11[NET] sending packet: from 10.50.0.2[4500] to \
10.50.2.7[4500] (76 bytes)
Feb 21 11:22:43 responder charon: 11[CFG] sending DHCP RELEASE for 10.50.1.208 to \
10.50.1.4
["initiator-ipsec.conf" (text/plain)]
config setup
charondebug="ike 1, net 1"
conn %default
authby=pubkey
keyexchange=ikev2
left=%defaultroute
conn testconn
auto=add
type=tunnel
leftid="C=DE, O=company, CN=initiator.test"
leftca="C=DE, O=company, CN=Test CA"
leftcert=initiatorCert.der
leftsendcert=always
leftsourceip=%config
rightca=%same
right=responder.test
rightid="C=DE, O=company, CN=responder.test"
rightsubnet=0.0.0.0/0
ike=aes256-sha1-modp2048,aes256-sha256-modp2048,aes256-sha384-modp2048,aes256-sha512-modp2048!
esp=aes256-sha1-modp2048,aes256-sha256-modp2048,aes256-sha384-modp2048,aes256-sha512-modp2048!
compress = yes
dpdaction = restart
ikelifetime = 5m
lifetime = 4m
margintime = 2m
["responder-ipsec.conf" (text/plain)]
config setup
conn %default
authby=pubkey
keyexchange=ikev2
left=%defaultroute
conn testconn
auto=add
type=tunnel
right=%any
leftca="C=DE, O=company, CN=Test CA"
leftcert=responderCert.der
leftsubnet=10.50.1.0/24
rightca=%same
rightsourceip=%dhcp
ike=aes256-sha1-modp2048,aes256-sha256-modp2048,aes256-sha384-modp2048,aes256-sha512-modp2048!
esp=aes256-sha1-modp2048,aes256-sha256-modp2048,aes256-sha384-modp2048,aes256-sha512-modp2048!
ikelifetime = 3h
lifetime = 1h
compress = yes
_______________________________________________
Dev mailing list
Dev@lists.strongswan.org
https://lists.strongswan.org/mailman/listinfo/dev
[prev in list] [next in list] [prev in thread] [next in thread]
Configure |
About |
News |
Add a list |
Sponsored by KoreLogic