Hi,
I'm having a problem where the kernel policies and charons trap list are
getting out of
sync (strongswan 4.5.1). It's occuring on a host-host transport connection when
the
connection does an IKE_REAUTH task with an existing child SA. The kernel
policy's reqid
is getting incremented, but the trap list entry is unchanged. Thus when a later
XFRM
acquire comes in with the new reqid, it doesn't find a match on the trap list.
I don't know whether the charon reqid should be getting incremented for a
reauth or
whether the policies need to be deleted and readded with the updated reqid.
It's easy
for me to recreate, so I can test any fixes or gather more debug if needed.
Thanks for any help.
-mike
The scenario is:
HOST 1 HOST 2
<establish ike connection>
<establish SA (reqid=1)>
.
.
.
.
<ike lifetime expires -
IKE_REAUTH>
<new ike connection>
<new SA (reqid=2)>
.
.
.
<reboot host 1>
<SA deleted>
<host 1 up>
<ping6 host1>
XFRM acquire reqid=2
-> no match
This is HOST-2's ipsec.conf. HOST-1 is the same (with left/right flipped).
config setup
dumpdir=
strictcrlpolicy=no
uniqueids=yes
plutostart=no
charonstart=yes
conn %default
auth=esp
auto=route
dpdaction=hold
keyexchange=ikev2
leftfirewall=no
mobike=no
conn Policy_S0P0ipsec0sa0
esp=3des-sha1!
ike=3des-sha1-modp1024!
ikelifetime=3600s
keylife=1800s
rekey=yes
type=transport
left=fd70:c154:c2df:83:2c0:ddff:fe12:cdd4
right=fd70:c154:c2df:83:2c0:ddff:fe0d:53e6
leftauth=psk
rightauth=psk
Here's some data from HOST-2 after the problem has occurred:
[root@hsb3800-2 conf]# ip x m
acquire proto esp
sel src fd70:c154:c2df:83:2c0:ddff:fe12:cdd4/128 dst
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6/128 proto ipv6-icmp type 128 code 0
policy src fd70:c154:c2df:83:2c0:ddff:fe12:cdd4/128 dst
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6/128
dir out priority 1027 ptype main
tmpl src :: dst ::
proto esp reqid 2 mode transport
[root@hsb3800-2 TRAP2]# ipsec statusall
Status of IKEv2 charon daemon (strongSwan 4.5.1):
uptime: 104 minutes, since Mar 02 23:05:35 2011
malloc: sbrk 151552, mmap 0, used 83064, free 68488
worker threads: 1 idle of 8, job queue load: 0, scheduled events: 0
loaded plugins: aes des sha1 sha2 md5 random x509 revocation constraints
pubkey pkcs1 pgp pem fips-prf gmp xcbc hmac ctr kernel-netlink socket-default
stroke
Listening IP addresses:
10.20.83.97
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4
Connections:
Policy_S0P0ipsec0sa0:
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4...fd70:c154:c2df:83:2c0:ddff:fe0d:53e6,
dpddelay=30s
Policy_S0P0ipsec0sa0: local: [fd70:c154:c2df:83:2c0:ddff:fe12:cdd4] uses
pre-shared key authentication
Policy_S0P0ipsec0sa0: remote: [fd70:c154:c2df:83:2c0:ddff:fe0d:53e6] uses
pre-shared key authentication
Policy_S0P0ipsec0sa0: child: dynamic === dynamic , dpdaction=hold
Routed Connections:
Policy_S0P0ipsec0sa0{1}: ROUTED, TRANSPORT
Policy_S0P0ipsec0sa0{1}: fd70:c154:c2df:83:2c0:ddff:fe12:cdd4/128 ===
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6/128
Security Associations:
none
[root@hsb3800-2 TRAP2]# ip x p
src fd70:c154:c2df:83:2c0:ddff:fe0d:53e6/128 dst
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4/128
dir in priority 1027 ptype main
tmpl src :: dst ::
proto esp reqid 2 mode transport
src fd70:c154:c2df:83:2c0:ddff:fe12:cdd4/128 dst
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6/128
dir out priority 1027 ptype main
tmpl src :: dst ::
proto esp reqid 2 mode transport
logfile (w/ a few extra DBG's added)
-------
Mar 2 23:48:50 switch charon: 08[JOB] got event, queuing job for execution
Mar 2 23:48:50 switch charon: 08[JOB] next event in 14s 512ms, waiting
Mar 2 23:48:50 switch charon: 07[MGR] checkout IKE_SA
Mar 2 23:48:50 switch charon: 07[MGR] IKE_SA Policy_S0P0ipsec0sa0[1]
successfully checked out
Mar 2 23:48:50 switch charon: 07[IKE] <Policy_S0P0ipsec0sa0|1> reauth.1490:
Mar 2 23:48:50 switch charon: 07[IKE] <Policy_S0P0ipsec0sa0|1> queueing
IKE_REAUTH task
Mar 2 23:48:50 switch charon: 07[IKE] <Policy_S0P0ipsec0sa0|1> activating new
tasks
Mar 2 23:48:50 switch charon: 07[IKE] <Policy_S0P0ipsec0sa0|1> activating
IKE_REAUTH task
Mar 2 23:48:50 switch charon: 07[IKE] <Policy_S0P0ipsec0sa0|1> deleting IKE_SA
Policy_S0P0ipsec0sa0[1] between
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4[fd70:c154:c2df:83:2c0:ddff:fe12:cdd4]...fd70:c154:c2df:83:2c0:ddff:fe0d:53e6[fd70:c154:c2df:83:2c0:ddff:fe0d:53e6]
Mar 2 23:48:50 switch charon: 07[IKE] <Policy_S0P0ipsec0sa0|1> IKE_SA
Policy_S0P0ipsec0sa0[1] state change: ESTABLISHED => DELETING
Mar 2 23:48:50 switch charon: 08[JOB] next event in 14s 473ms, waiting
Mar 2 23:48:50 switch charon: 07[IKE] <Policy_S0P0ipsec0sa0|1> sending DELETE
for IKE_SA Policy_S0P0ipsec0sa0[1]
Mar 2 23:48:50 switch charon: 07[ENC] <Policy_S0P0ipsec0sa0|1> generating
INFORMATIONAL request 12 [ D ]
Mar 2 23:48:50 switch charon: 07[NET] <Policy_S0P0ipsec0sa0|1> sending packet:
from fd70:c154:c2df:83:2c0:ddff:fe12:cdd4[500] to
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6[500]
Mar 2 23:48:50 switch charon: 08[JOB] next event in 3s 999ms, waiting
Mar 2 23:48:50 switch charon: 07[MGR] <Policy_S0P0ipsec0sa0|1> checkin IKE_SA
Policy_S0P0ipsec0sa0[1]
Mar 2 23:48:50 switch charon: 07[MGR] <Policy_S0P0ipsec0sa0|1> check-in of
IKE_SA successful.
Mar 2 23:48:50 switch charon: 04[NET] sending packet: from
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4[500] to
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6[500]
Mar 2 23:48:50 switch charon: 05[NET] received packet: from
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6[500] to
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4[500]
Mar 2 23:48:50 switch charon: 05[NET] waiting for data on sockets
Mar 2 23:48:50 switch charon: 06[MGR] checkout IKE_SA by message
Mar 2 23:48:50 switch charon: 06[MGR] IKE_SA Policy_S0P0ipsec0sa0[1]
successfully checked out
Mar 2 23:48:50 switch charon: 06[NET] <Policy_S0P0ipsec0sa0|1> received
packet: from fd70:c154:c2df:83:2c0:ddff:fe0d:53e6[500] to
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4[500]
Mar 2 23:48:50 switch charon: 06[ENC] <Policy_S0P0ipsec0sa0|1> parsed
INFORMATIONAL response 12 [ ]
Mar 2 23:48:50 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|1>
update_hosts.833:
Mar 2 23:48:50 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|1> IKE_SA deleted
Mar 2 23:48:50 switch charon: 06[MGR] <Policy_S0P0ipsec0sa0|1> created IKE_SA
(unnamed)[2]
Mar 2 23:48:50 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|1> initiate.1097:
Mar 2 23:48:50 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|1> queueing
IKE_VENDOR task
Mar 2 23:48:50 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|1> queueing
IKE_INIT task
Mar 2 23:48:50 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|1> queueing
IKE_NATD task
Mar 2 23:48:50 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|1> queueing
IKE_CERT_PRE task
Mar 2 23:48:50 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|1> queueing
IKE_AUTHENTICATE task
Mar 2 23:48:50 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|1> queueing
IKE_CERT_POST task
Mar 2 23:48:50 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|1> queueing
IKE_CONFIG task
Mar 2 23:48:50 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|1> queueing
IKE_AUTH_LIFETIME task
Mar 2 23:48:50 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|1> queueing
CHILD_CREATE task
Mar 2 23:48:50 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|1> activating new
tasks
Mar 2 23:48:50 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|1> activating
IKE_VENDOR task
Mar 2 23:48:50 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|1> activating
IKE_INIT task
Mar 2 23:48:50 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|1> activating
IKE_NATD task
Mar 2 23:48:50 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|1> activating
IKE_CERT_PRE task
Mar 2 23:48:50 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|1> activating
IKE_AUTHENTICATE task
Mar 2 23:48:50 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|1> activating
IKE_CERT_POST task
Mar 2 23:48:50 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|1> activating
IKE_CONFIG task
Mar 2 23:48:50 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|1> activating
CHILD_CREATE task
Mar 2 23:48:50 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|1> activating
IKE_AUTH_LIFETIME task
Mar 2 23:48:51 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|1> initiating
IKE_SA Policy_S0P0ipsec0sa0[2] to fd70:c154:c2df:83:2c0:ddff:fe0d:53e6
Mar 2 23:48:51 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|1> IKE_SA
Policy_S0P0ipsec0sa0[2] state change: CREATED => CONNECTING
Mar 2 23:48:51 switch charon: 06[LIB] <Policy_S0P0ipsec0sa0|1> size of DH
secret exponent: 1022 bits
Mar 2 23:48:51 switch charon: 06[ENC] <Policy_S0P0ipsec0sa0|1> generating
IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) ]
Mar 2 23:48:51 switch charon: 06[NET] <Policy_S0P0ipsec0sa0|1> sending packet:
from fd70:c154:c2df:83:2c0:ddff:fe12:cdd4[500] to
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6[500]
Mar 2 23:48:51 switch charon: 04[NET] sending packet: from
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4[500] to
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6[500]
Mar 2 23:48:51 switch charon: 08[JOB] next event in 3s 710ms, waiting
Mar 2 23:48:51 switch charon: 06[MGR] <Policy_S0P0ipsec0sa0|1> checkin IKE_SA
Policy_S0P0ipsec0sa0[2]
Mar 2 23:48:51 switch charon: 06[MGR] <Policy_S0P0ipsec0sa0|1> checkin and
destroy IKE_SA Policy_S0P0ipsec0sa0[1]
Mar 2 23:48:51 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|1> destroy.1996:
Mar 2 23:48:51 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|1> IKE_SA
Policy_S0P0ipsec0sa0[1] state change: DELETING => DESTROYING
Mar 2 23:48:51 switch charon: 06[CHD] <Policy_S0P0ipsec0sa0|1> destroy.915:
Mar 2 23:48:51 switch charon: 06[KNL] <Policy_S0P0ipsec0sa0|1> deleting SAD
entry with SPI c698b6c8
Mar 2 23:48:51 switch charon: 06[KNL] <Policy_S0P0ipsec0sa0|1> deleted SAD
entry with SPI c698b6c8
Mar 2 23:48:51 switch charon: 06[KNL] <Policy_S0P0ipsec0sa0|1> deleting SAD
entry with SPI c0daf98b
Mar 2 23:48:51 switch charon: 06[KNL] <Policy_S0P0ipsec0sa0|1> deleted SAD
entry with SPI c0daf98b
Mar 2 23:48:51 switch charon: 06[KNL] <Policy_S0P0ipsec0sa0|1> deleting policy
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4/128 ===
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6/128 out
Mar 2 23:48:51 switch charon: 06[KNL] <Policy_S0P0ipsec0sa0|1> policy still
used by another CHILD_SA, not removed
Mar 2 23:48:51 switch charon: 06[KNL] <Policy_S0P0ipsec0sa0|1> deleting policy
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6/128 ===
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4/128 in
Mar 2 23:48:51 switch charon: 06[KNL] <Policy_S0P0ipsec0sa0|1> policy still
used by another CHILD_SA, not removed
Mar 2 23:48:51 switch charon: 06[MGR] check-in and destroy of IKE_SA successful
Mar 2 23:48:51 switch charon: 05[NET] received packet: from
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6[500] to
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4[500]
Mar 2 23:48:51 switch charon: 05[NET] waiting for data on sockets
Mar 2 23:48:51 switch charon: 07[MGR] checkout IKE_SA by message
Mar 2 23:48:51 switch charon: 07[MGR] IKE_SA Policy_S0P0ipsec0sa0[2]
successfully checked out
Mar 2 23:48:51 switch charon: 07[NET] <Policy_S0P0ipsec0sa0|2> received
packet: from fd70:c154:c2df:83:2c0:ddff:fe0d:53e6[500] to
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4[500]
Mar 2 23:48:51 switch charon: 07[ENC] <Policy_S0P0ipsec0sa0|2> parsed
IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(MULT_AUTH) ]
Mar 2 23:48:51 switch charon: 07[IKE] <Policy_S0P0ipsec0sa0|2>
update_hosts.833:
Mar 2 23:48:51 switch charon: 07[CFG] <Policy_S0P0ipsec0sa0|2> selecting
proposal:
Mar 2 23:48:51 switch charon: 07[CFG] <Policy_S0P0ipsec0sa0|2> proposal
matches
Mar 2 23:48:51 switch charon: 07[CFG] <Policy_S0P0ipsec0sa0|2> received
proposals: IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024
Mar 2 23:48:51 switch charon: 07[CFG] <Policy_S0P0ipsec0sa0|2> configured
proposals: IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024
Mar 2 23:48:51 switch charon: 07[CFG] <Policy_S0P0ipsec0sa0|2> selected
proposal: IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024
Mar 2 23:48:51 switch charon: 07[IKE] <Policy_S0P0ipsec0sa0|2> reinitiating
already active tasks
Mar 2 23:48:51 switch charon: 07[IKE] <Policy_S0P0ipsec0sa0|2> IKE_CERT_PRE
task
Mar 2 23:48:51 switch charon: 07[IKE] <Policy_S0P0ipsec0sa0|2>
IKE_AUTHENTICATE task
Mar 2 23:48:51 switch charon: 07[IKE] <Policy_S0P0ipsec0sa0|2> authentication
of 'fd70:c154:c2df:83:2c0:ddff:fe12:cdd4' (myself) with pre-shared key
Mar 2 23:48:51 switch charon: 07[IKE] <Policy_S0P0ipsec0sa0|2> successfully
created shared key MAC
Mar 2 23:48:51 switch charon: 07[IKE] <Policy_S0P0ipsec0sa0|2> establishing
CHILD_SA Policy_S0P0ipsec0sa0
Mar 2 23:48:51 switch charon: 07[CFG] <Policy_S0P0ipsec0sa0|2> proposing
traffic selectors for us:
Mar 2 23:48:51 switch charon: 07[CFG] <Policy_S0P0ipsec0sa0|2>
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4/128 (derived from dynamic)
Mar 2 23:48:51 switch charon: 07[CFG] <Policy_S0P0ipsec0sa0|2> proposing
traffic selectors for other:
Mar 2 23:48:51 switch charon: 07[CFG] <Policy_S0P0ipsec0sa0|2>
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6/128 (derived from dynamic)
Mar 2 23:48:51 switch charon: 07[CHD] <Policy_S0P0ipsec0sa0|2>
child_sa_create.1029: reqid=0 rekey=0 reqid=1
Mar 2 23:48:51 switch charon: 07[KNL] <Policy_S0P0ipsec0sa0|2> getting SPI for
reqid {2}
Mar 2 23:48:51 switch charon: 07[KNL] <Policy_S0P0ipsec0sa0|2> got SPI
cb48d316 for reqid {2}
Mar 2 23:48:51 switch charon: 07[ENC] <Policy_S0P0ipsec0sa0|2> generating
IKE_AUTH request 1 [ IDi CERTREQ IDr AUTH N(USE_TRANSP) SA TSi TSr N(MULT_AUTH)
N(EAP_ONLY) ]
Mar 2 23:48:51 switch charon: 07[NET] <Policy_S0P0ipsec0sa0|2> sending packet:
from fd70:c154:c2df:83:2c0:ddff:fe12:cdd4[500] to
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6[500]
Mar 2 23:48:51 switch charon: 04[NET] sending packet: from
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4[500] to
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6[500]
Mar 2 23:48:51 switch charon: 08[JOB] next event in 3s 394ms, waiting
Mar 2 23:48:51 switch charon: 07[MGR] <Policy_S0P0ipsec0sa0|2> checkin IKE_SA
Policy_S0P0ipsec0sa0[2]
Mar 2 23:48:51 switch charon: 07[MGR] <Policy_S0P0ipsec0sa0|2> check-in of
IKE_SA successful.
Mar 2 23:48:51 switch charon: 05[NET] received packet: from
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6[500] to
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4[500]
Mar 2 23:48:51 switch charon: 05[NET] waiting for data on sockets
Mar 2 23:48:51 switch charon: 06[MGR] checkout IKE_SA by message
Mar 2 23:48:51 switch charon: 06[MGR] IKE_SA Policy_S0P0ipsec0sa0[2]
successfully checked out
Mar 2 23:48:51 switch charon: 06[NET] <Policy_S0P0ipsec0sa0|2> received
packet: from fd70:c154:c2df:83:2c0:ddff:fe0d:53e6[500] to
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4[500]
Mar 2 23:48:51 switch charon: 06[ENC] <Policy_S0P0ipsec0sa0|2> parsed IKE_AUTH
response 1 [ IDr AUTH N(USE_TRANSP) SA TSi TSr N(AUTH_LFT) ]
Mar 2 23:48:51 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|2>
update_hosts.833:
Mar 2 23:48:51 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|2> received
USE_TRANSPORT_MODE notify
Mar 2 23:48:51 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|2> authentication
of 'fd70:c154:c2df:83:2c0:ddff:fe0d:53e6' with pre-shared key successful
Mar 2 23:48:51 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|2> IKE_SA
Policy_S0P0ipsec0sa0[2] established between
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4[fd70:c154:c2df:83:2c0:ddff:fe12:cdd4]...fd70:c154:c2df:83:2c0:ddff:fe0d:53e6[fd70:c154:c2df:83:2c0:ddff:fe0d:53e6]
Mar 2 23:48:51 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|2> IKE_SA
Policy_S0P0ipsec0sa0[2] state change: CONNECTING => ESTABLISHED
Mar 2 23:48:51 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|2> scheduling
reauthentication in 2912s
Mar 2 23:48:51 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|2> maximum IKE_SA
lifetime 3452s
Mar 2 23:48:51 switch charon: 06[CFG] <Policy_S0P0ipsec0sa0|2> selecting
proposal:
Mar 2 23:48:51 switch charon: 06[CFG] <Policy_S0P0ipsec0sa0|2> proposal
matches
Mar 2 23:48:51 switch charon: 06[CFG] <Policy_S0P0ipsec0sa0|2> received
proposals: ESP:3DES_CBC/HMAC_SHA1_96/NO_EXT_SEQ
Mar 2 23:48:51 switch charon: 06[CFG] <Policy_S0P0ipsec0sa0|2> configured
proposals: ESP:3DES_CBC/HMAC_SHA1_96/NO_EXT_SEQ
Mar 2 23:48:51 switch charon: 06[CFG] <Policy_S0P0ipsec0sa0|2> selected
proposal: ESP:3DES_CBC/HMAC_SHA1_96/NO_EXT_SEQ
Mar 2 23:48:51 switch charon: 06[CFG] <Policy_S0P0ipsec0sa0|2> selecting
traffic selectors for us:
Mar 2 23:48:51 switch charon: 06[CFG] <Policy_S0P0ipsec0sa0|2> config:
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4/128, received:
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4/128 => match:
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4/128
Mar 2 23:48:51 switch charon: 06[CFG] <Policy_S0P0ipsec0sa0|2> selecting
traffic selectors for other:
Mar 2 23:48:51 switch charon: 06[CFG] <Policy_S0P0ipsec0sa0|2> config:
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6/128, received:
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6/128 => match:
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6/128
Mar 2 23:48:51 switch charon: 06[CHD] <Policy_S0P0ipsec0sa0|2> using
3DES_CBC for encryption
Mar 2 23:48:51 switch charon: 06[CHD] <Policy_S0P0ipsec0sa0|2> using
HMAC_SHA1_96 for integrity
Mar 2 23:48:51 switch charon: 06[CHD] <Policy_S0P0ipsec0sa0|2> adding inbound
ESP SA
Mar 2 23:48:51 switch charon: 06[CHD] <Policy_S0P0ipsec0sa0|2> SPI
0xcb48d316, src fd70:c154:c2df:83:2c0:ddff:fe0d:53e6 dst
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4
Mar 2 23:48:51 switch charon: 06[KNL] <Policy_S0P0ipsec0sa0|2> adding SAD
entry with SPI cb48d316 and reqid {2}
Mar 2 23:48:51 switch charon: 06[KNL] <Policy_S0P0ipsec0sa0|2> using
encryption algorithm 3DES_CBC with key size 192
Mar 2 23:48:51 switch charon: 06[KNL] <Policy_S0P0ipsec0sa0|2> using
integrity algorithm HMAC_SHA1_96 with key size 160
Mar 2 23:48:51 switch charon: 06[CHD] <Policy_S0P0ipsec0sa0|2> adding outbound
ESP SA
Mar 2 23:48:51 switch charon: 06[CHD] <Policy_S0P0ipsec0sa0|2> SPI
0xcedd9e58, src fd70:c154:c2df:83:2c0:ddff:fe12:cdd4 dst
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6
Mar 2 23:48:51 switch charon: 06[KNL] <Policy_S0P0ipsec0sa0|2> adding SAD
entry with SPI cedd9e58 and reqid {2}
Mar 2 23:48:51 switch charon: 06[KNL] <Policy_S0P0ipsec0sa0|2> using
encryption algorithm 3DES_CBC with key size 192
Mar 2 23:48:51 switch charon: 06[KNL] <Policy_S0P0ipsec0sa0|2> using
integrity algorithm HMAC_SHA1_96 with key size 160
Mar 2 23:48:51 switch charon: 06[CHD] <Policy_S0P0ipsec0sa0|2>
add_policies.666:
Mar 2 23:48:51 switch charon: 06[KNL] <Policy_S0P0ipsec0sa0|2> policy
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4/128 ===
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6/128 out already exists, increasing refcount
Mar 2 23:48:51 switch charon: 06[KNL] <Policy_S0P0ipsec0sa0|2> adding policy
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4/128 ===
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6/128 out
Mar 2 23:48:51 switch charon: 06[KNL] <Policy_S0P0ipsec0sa0|2> policy
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6/128 ===
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4/128 in already exists, increasing refcount
Mar 2 23:48:51 switch charon: 06[KNL] <Policy_S0P0ipsec0sa0|2> adding policy
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6/128 ===
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4/128 in
Mar 2 23:48:51 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|2> CHILD_SA
Policy_S0P0ipsec0sa0{2} established with SPIs cb48d316_i cedd9e58_o and TS
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4/128 ===
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6/128
Mar 2 23:48:51 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|2> received
AUTH_LIFETIME of 2660s, scheduling reauthentication in 2120s
Mar 2 23:48:51 switch charon: 08[JOB] next event in 3s 96ms, waiting
Mar 2 23:48:51 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|2> activating new
tasks
Mar 2 23:48:51 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|2> nothing to
initiate
Mar 2 23:48:51 switch charon: 06[MGR] <Policy_S0P0ipsec0sa0|2> checkin IKE_SA
Policy_S0P0ipsec0sa0[2]
Mar 2 23:48:51 switch charon: 06[MGR] <Policy_S0P0ipsec0sa0|2> check-in of
IKE_SA successful.
<HOST-1 is rebooted here>
Mar 2 23:56:37 switch charon: 05[NET] received packet: from
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6[500] to
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4[500]
Mar 2 23:56:37 switch charon: 06[MGR] checkout IKE_SA by message
Mar 2 23:56:37 switch charon: 06[MGR] IKE_SA Policy_S0P0ipsec0sa0[2]
successfully checked out
Mar 2 23:56:37 switch charon: 06[NET] <Policy_S0P0ipsec0sa0|2> received
packet: from fd70:c154:c2df:83:2c0:ddff:fe0d:53e6[500] to
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4[500]
Mar 2 23:56:37 switch charon: 06[ENC] <Policy_S0P0ipsec0sa0|2> parsed
INFORMATIONAL request 15 [ D ]
Mar 2 23:56:37 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|2>
update_hosts.833:
Mar 2 23:56:37 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|2> received DELETE
for IKE_SA Policy_S0P0ipsec0sa0[2]
Mar 2 23:56:37 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|2> deleting IKE_SA
Policy_S0P0ipsec0sa0[2] between
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4[fd70:c154:c2df:83:2c0:ddff:fe12:cdd4]...fd70:c154:c2df:83:2c0:ddff:fe0d:53e6[fd70:c154:c2df:83:2c0:ddff:fe0d:53e6]
Mar 2 23:56:37 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|2> IKE_SA
Policy_S0P0ipsec0sa0[2] state change: ESTABLISHED => DELETING
Mar 2 23:56:37 switch charon: 08[JOB] next event in 13s 727ms, waiting
Mar 2 23:56:37 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|2>
reestablish.1534:
Mar 2 23:56:37 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|2>
reestablish.1547: state=5 action=1
Mar 2 23:56:37 switch charon: 06[CFG] <Policy_S0P0ipsec0sa0|2> CHILD_SA named
'Policy_S0P0ipsec0sa0' already routed
Mar 2 23:56:37 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|2> IKE_SA deleted
Mar 2 23:56:37 switch charon: 06[ENC] <Policy_S0P0ipsec0sa0|2> generating
INFORMATIONAL response 15 [ ]
Mar 2 23:56:37 switch charon: 06[NET] <Policy_S0P0ipsec0sa0|2> sending packet:
from fd70:c154:c2df:83:2c0:ddff:fe12:cdd4[500] to
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6[500]
Mar 2 23:56:37 switch charon: 06[MGR] <Policy_S0P0ipsec0sa0|2> checkin and
destroy IKE_SA Policy_S0P0ipsec0sa0[2]
Mar 2 23:56:37 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|2> destroy.1996:
Mar 2 23:56:37 switch charon: 06[IKE] <Policy_S0P0ipsec0sa0|2> IKE_SA
Policy_S0P0ipsec0sa0[2] state change: DELETING => DESTROYING
Mar 2 23:56:37 switch charon: 06[CHD] <Policy_S0P0ipsec0sa0|2> destroy.915:
Mar 2 23:56:37 switch charon: 06[KNL] <Policy_S0P0ipsec0sa0|2> deleting SAD
entry with SPI cb48d316
Mar 2 23:56:37 switch charon: 06[KNL] <Policy_S0P0ipsec0sa0|2> deleted SAD
entry with SPI cb48d316
Mar 2 23:56:37 switch charon: 06[KNL] <Policy_S0P0ipsec0sa0|2> deleting SAD
entry with SPI cedd9e58
Mar 2 23:56:37 switch charon: 06[KNL] <Policy_S0P0ipsec0sa0|2> deleted SAD
entry with SPI cedd9e58
Mar 2 23:56:37 switch charon: 06[KNL] <Policy_S0P0ipsec0sa0|2> deleting policy
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4/128 ===
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6/128 out
Mar 2 23:56:37 switch charon: 06[KNL] <Policy_S0P0ipsec0sa0|2> policy still
used by another CHILD_SA, not removed
Mar 2 23:56:37 switch charon: 06[KNL] <Policy_S0P0ipsec0sa0|2> deleting policy
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6/128 ===
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4/128 in
Mar 2 23:56:37 switch charon: 06[KNL] <Policy_S0P0ipsec0sa0|2> policy still
used by another CHILD_SA, not removed
Mar 2 23:56:37 switch charon: 06[MGR] check-in and destroy of IKE_SA successful
Mar 2 23:56:37 switch charon: 04[NET] sending packet: from
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4[500] to
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6[500]
Mar 2 23:56:37 switch charon: 05[NET] waiting for data on sockets
Mar 2 23:56:50 switch charon: 08[JOB] got event, queuing job for execution
Mar 2 23:56:50 switch charon: 08[JOB] next event in 16s 271ms, waiting
Mar 2 23:56:50 switch charon: 07[MGR] checkout IKE_SA
Mar 2 23:56:57 switch charon: 06[CFG] proposing traffic selectors for us:
Mar 2 23:56:57 switch charon: 06[CFG] dynamic (derived from dynamic)
Mar 2 23:56:57 switch charon: 06[CFG] proposing traffic selectors for other:
Mar 2 23:56:57 switch charon: 06[CFG] dynamic (derived from dynamic)
Mar 2 23:57:07 switch charon: 08[JOB] got event, queuing job for execution
Mar 2 23:57:07 switch charon: 06[MGR] checkout IKE_SA
Mar 2 23:57:07 switch charon: 08[JOB] next event in 188s 339ms, waiting
Mar 2 23:59:09 switch charon: 06[CFG] proposing traffic selectors for us:
Mar 2 23:59:09 switch charon: 06[CFG] dynamic (derived from dynamic)
Mar 2 23:59:09 switch charon: 06[CFG] proposing traffic selectors for other:
Mar 2 23:59:09 switch charon: 06[CFG] dynamic (derived from dynamic)
<ping6 from HOST-2 to HOST-1>
Mar 2 23:59:23 switch charon: 01[KNL] received a XFRM_MSG_ACQUIRE
Mar 2 23:59:23 switch charon: 01[KNL] XFRMA_TMPL
Mar 2 23:59:23 switch charon: 01[KNL] creating acquire job for policy
fd70:c154:c2df:83:2c0:ddff:fe12:cdd4/128[ipv6-icmp/128] ===
fd70:c154:c2df:83:2c0:ddff:fe0d:53e6/128[ipv6-icmp] with reqid {2}
Mar 2 23:59:23 switch charon: 03[CFG] acquiring trap: request reqid=2; entry:
name=Policy_S0P0ipsec0sa0 reqid=1
Mar 2 23:59:23 switch charon: 03[CFG] trap not found, unable to acquire reqid 2
Mar 3 00:00:15 switch charon: 08[JOB] got event, queuing job for execution
Mar 3 00:00:15 switch charon: 08[JOB] next event in 539s 991ms, waiting
Mar 3 00:00:15 switch charon: 07[MGR] checkout IKE_SA
Mar 3 00:00:15 switch charon: 07[JOB] IKE_SA to rekey not found
_______________________________________________
Users mailing list
[email protected]
https://lists.strongswan.org/mailman/listinfo/users
