[strongSwan] problems with charon in 4.5.2 (was: 4.4.1)

Andreas Schuldei schuldei+strongswan at spotify.com
Wed Jun 1 09:56:52 CEST 2011 

Hi!

now i ran strongswan 4.5.2 for two days and it looks more stable then
4.4.1 on our testbed.

however, even 4.5.2 died tonight. the connection between alvina and
sarah went down and attempts to reinitiate it failed.

i attache the output of grep alvina /var/log/daemon (on sarah) and vice versa.

it seems alvina gives up on sarah when it does not respond. sarah in
turn has some issues where it becomes unresponsive for several seconds
and freezes. it could be that the rekeying interval fell into such a
freeze. i didnt go to the bottom of those freezes yet, but i would
think that this could happen in real life situations, too. Of course i
would like the two hosts to try harder to re-establish their
connection again. did something go wrong at that point? how can i
increase the number of reconnection attempts in case of loss of SA?
%forever sounds long to me, but hey. should i just put a really big
number here?

for the record: this is how my config file for 4.5.2 looks like. is
there anything else i can do for resilience?

config setup
	plutostart=no # pluto is used for IKEv1

conn %default
	ikelifetime=3h           # strongSwan default
	lifetime=1h              # strongSwan default
	margintime=9m            # strongSwan default
	keyingtries=%forever     # strongSwan default
	mobike=no                # mobike is used for NAT traversal
	keyexchange=ikev2
	ike=aes128-sha1-modp2048
	esp=aes128-sha1-modp2048
	left=%defaultroute
	leftcert=host_server.crt
	type=transport           # should work just as good as tunnel, but
less overhead
	reauth=no                # recommended so that SAs are rekeyed, not
reauthenticaed

# Begin connection section

# For all connections, the peer with the host name
# that is first in a lexicographical sorting
# is selected as the initiator of the connection.
#for $peer in $peers

conn $host-$peer.name
	right=$peer.ip
	rightid="C=SE, O=Spotify, CN=$peer.name"
	auto=start
#end for


2011-05-31T22:39:26.000+00:00 alvina.ash.spotify.net charon: 04[NET]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> received packet:
from 78.31.14.56[500] to 193.182.12.31[500]
2011-05-31T22:39:26.000+00:00 alvina.ash.spotify.net charon: 04[ENC]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> parsed
CREATE_CHILD_SA response 0 [ N(USE_TRANSP) SA No KE TSi TSr ]
2011-05-31T22:39:26.000+00:00 alvina.ash.spotify.net charon: 04[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> received
USE_TRANSPORT_MODE notify
2011-05-31T22:39:26.000+00:00 alvina.ash.spotify.net charon: 04[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> CHILD_SA
alvina.ash.spotify.net-sarah.sto.spotify.net{19} established with SPIs
c68e90b3_i c1afe29b_o and TS 193.182.12.31/32 === 78.31.14.56/32
2011-05-31T22:39:26.000+00:00 alvina.ash.spotify.net charon: 04[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> reinitiating
already active tasks
2011-05-31T22:39:26.000+00:00 alvina.ash.spotify.net charon: 04[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322>   CHILD_REKEY task
2011-05-31T22:39:26.000+00:00 alvina.ash.spotify.net charon: 04[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> closing CHILD_SA
alvina.ash.spotify.net-sarah.sto.spotify.net{19} with SPIs cd8f72b1_i
(44485206 bytes) c20dc52a_o (25465004 bytes) and TS 193.182.12.31/32
=== 78.31.14.56/32
2011-05-31T22:39:26.000+00:00 alvina.ash.spotify.net charon: 04[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> sending DELETE for
ESP CHILD_SA with SPI cd8f72b1
2011-05-31T22:39:26.000+00:00 alvina.ash.spotify.net charon: 04[ENC]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> generating
INFORMATIONAL request 1 [ D ]
2011-05-31T22:39:26.000+00:00 alvina.ash.spotify.net charon: 04[NET]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> sending packet:
from 193.182.12.31[500] to 78.31.14.56[500]
2011-05-31T22:39:26.000+00:00 alvina.ash.spotify.net charon: 14[NET]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> received packet:
from 78.31.14.56[500] to 193.182.12.31[500]
2011-05-31T22:39:26.000+00:00 alvina.ash.spotify.net charon: 14[ENC]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> parsed
INFORMATIONAL response 1 [ D ]
2011-05-31T22:39:26.000+00:00 alvina.ash.spotify.net charon: 14[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> received DELETE for
ESP CHILD_SA with SPI c20dc52a
2011-05-31T22:39:26.000+00:00 alvina.ash.spotify.net charon: 14[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> CHILD_SA closed
2011-05-31T22:39:26.000+00:00 alvina.ash.spotify.net charon: 14[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> activating new
tasks
2011-05-31T22:39:26.000+00:00 alvina.ash.spotify.net charon: 14[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> nothing to initiate
2011-05-31T23:21:47.000+00:00 alvina.ash.spotify.net charon: 14[NET]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> received packet:
from 78.31.14.56[500] to 193.182.12.31[500]
2011-05-31T23:21:47.000+00:00 alvina.ash.spotify.net charon: 14[ENC]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> parsed
CREATE_CHILD_SA request 4 [ N(REKEY_SA) N(USE_TRANSP) SA No KE TSi TSr
]
2011-05-31T23:21:47.000+00:00 alvina.ash.spotify.net charon: 14[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> CHILD_SA
alvina.ash.spotify.net-sarah.sto.spotify.net{19} established with SPIs
c9bb0b05_i cb4e7022_o and TS 193.182.12.31/32 === 78.31.14.56/32
2011-05-31T23:21:47.000+00:00 alvina.ash.spotify.net charon: 14[ENC]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> generating
CREATE_CHILD_SA response 4 [ N(USE_TRANSP) SA No KE TSi TSr ]
2011-05-31T23:21:47.000+00:00 alvina.ash.spotify.net charon: 14[NET]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> sending packet:
from 193.182.12.31[500] to 78.31.14.56[500]
2011-05-31T23:21:47.000+00:00 alvina.ash.spotify.net charon: 10[NET]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> received packet:
from 78.31.14.56[500] to 193.182.12.31[500]
2011-05-31T23:21:47.000+00:00 alvina.ash.spotify.net charon: 10[ENC]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> parsed
INFORMATIONAL request 5 [ D ]
2011-05-31T23:21:47.000+00:00 alvina.ash.spotify.net charon: 10[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> received DELETE for
ESP CHILD_SA with SPI c1afe29b
2011-05-31T23:21:47.000+00:00 alvina.ash.spotify.net charon: 10[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> closing CHILD_SA
alvina.ash.spotify.net-sarah.sto.spotify.net{19} with SPIs c68e90b3_i
(28495440 bytes) c1afe29b_o (18123146 bytes) and TS 193.182.12.31/32
=== 78.31.14.56/32
2011-05-31T23:21:47.000+00:00 alvina.ash.spotify.net charon: 10[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> sending DELETE for
ESP CHILD_SA with SPI c68e90b3
2011-05-31T23:21:47.000+00:00 alvina.ash.spotify.net charon: 10[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> CHILD_SA closed
2011-05-31T23:21:47.000+00:00 alvina.ash.spotify.net charon: 10[ENC]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> generating
INFORMATIONAL response 5 [ D ]
2011-05-31T23:21:47.000+00:00 alvina.ash.spotify.net charon: 10[NET]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> sending packet:
from 193.182.12.31[500] to 78.31.14.56[500]
2011-05-31T23:30:15.000+00:00 alvina.ash.spotify.net charon: 09[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> queueing IKE_REKEY
task
2011-05-31T23:30:15.000+00:00 alvina.ash.spotify.net charon: 09[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> activating new
tasks
2011-05-31T23:30:15.000+00:00 alvina.ash.spotify.net charon: 09[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322>   activating
IKE_REKEY task
2011-05-31T23:30:15.000+00:00 alvina.ash.spotify.net charon: 09[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> IKE_SA
alvina.ash.spotify.net-sarah.sto.spotify.net[322] state change:
ESTABLISHED => REKEYING
2011-05-31T23:30:15.000+00:00 alvina.ash.spotify.net charon: 09[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> initiating IKE_SA
alvina.ash.spotify.net-sarah.sto.spotify.net[345] to 78.31.14.56
2011-05-31T23:30:15.000+00:00 alvina.ash.spotify.net charon: 09[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> IKE_SA
alvina.ash.spotify.net-sarah.sto.spotify.net[345] state change:
CREATED => CONNECTING
2011-05-31T23:30:15.000+00:00 alvina.ash.spotify.net charon: 09[ENC]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> generating
CREATE_CHILD_SA request 2 [ SA No KE ]
2011-05-31T23:30:15.000+00:00 alvina.ash.spotify.net charon: 09[NET]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> sending packet:
from 193.182.12.31[500] to 78.31.14.56[500]
2011-05-31T23:30:19.000+00:00 alvina.ash.spotify.net charon: 04[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> retransmit 1 of
request with message ID 2
2011-05-31T23:30:19.000+00:00 alvina.ash.spotify.net charon: 04[NET]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> sending packet:
from 193.182.12.31[500] to 78.31.14.56[500]
2011-05-31T23:30:26.000+00:00 alvina.ash.spotify.net charon: 10[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> retransmit 2 of
request with message ID 2
2011-05-31T23:30:26.000+00:00 alvina.ash.spotify.net charon: 10[NET]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> sending packet:
from 193.182.12.31[500] to 78.31.14.56[500]
2011-05-31T23:30:39.000+00:00 alvina.ash.spotify.net charon: 08[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> retransmit 3 of
request with message ID 2
2011-05-31T23:30:39.000+00:00 alvina.ash.spotify.net charon: 08[NET]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> sending packet:
from 193.182.12.31[500] to 78.31.14.56[500]
2011-05-31T23:31:03.000+00:00 alvina.ash.spotify.net charon: 07[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> retransmit 4 of
request with message ID 2
2011-05-31T23:31:03.000+00:00 alvina.ash.spotify.net charon: 07[NET]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> sending packet:
from 193.182.12.31[500] to 78.31.14.56[500]
2011-05-31T23:31:45.000+00:00 alvina.ash.spotify.net charon: 14[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> retransmit 5 of
request with message ID 2
2011-05-31T23:31:45.000+00:00 alvina.ash.spotify.net charon: 14[NET]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> sending packet:
from 193.182.12.31[500] to 78.31.14.56[500]
2011-05-31T23:33:00.000+00:00 alvina.ash.spotify.net charon: 10[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> giving up after 5
retransmits
2011-05-31T23:33:00.000+00:00 alvina.ash.spotify.net charon: 10[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> rekeying IKE_SA
failed, peer not responding
2011-05-31T23:33:00.000+00:00 alvina.ash.spotify.net charon: 10[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|322> IKE_SA
alvina.ash.spotify.net-sarah.sto.spotify.net[322] state change:
REKEYING => DESTROYING
2011-05-31T23:33:00.000+00:00 alvina.ash.spotify.net charon: 10[IKE]
<alvina.ash.spotify.net-sarah.sto.spotify.net|345> IKE_SA
alvina.ash.spotify.net-sarah.sto.spotify.net[345] state change:
CONNECTING => DESTROYING



2011-05-31T23:21:47.000+00:00 sarah.sto.spotify.net charon: 09[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> CHILD_SA
sarah.sto.spotify.net-alvina.ash.spotify.net{23} established with SPIs
cb4e7022_i c9bb0b05_o and TS 78.31.14.56/32 === 193.182.12.31/32
2011-05-31T23:21:47.000+00:00 sarah.sto.spotify.net charon: 09[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> reinitiating
already active tasks
2011-05-31T23:21:47.000+00:00 sarah.sto.spotify.net charon: 09[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323>   CHILD_REKEY task
2011-05-31T23:21:47.000+00:00 sarah.sto.spotify.net charon: 09[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> closing CHILD_SA
sarah.sto.spotify.net-alvina.ash.spotify.net{23} with SPIs c1afe29b_i
(18123146 bytes) c68e90b3_o (29933116 bytes) and TS 78.31.14.56/32 ===
193.182.12.31/32
2011-05-31T23:21:47.000+00:00 sarah.sto.spotify.net charon: 09[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> sending DELETE for
ESP CHILD_SA with SPI c1afe29b
2011-05-31T23:21:47.000+00:00 sarah.sto.spotify.net charon: 09[ENC]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> generating
INFORMATIONAL request 5 [ D ]
2011-05-31T23:21:47.000+00:00 sarah.sto.spotify.net charon: 09[NET]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> sending packet:
from 78.31.14.56[500] to 193.182.12.31[500]
2011-05-31T23:21:47.000+00:00 sarah.sto.spotify.net charon: 14[NET]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> received packet:
from 193.182.12.31[500] to 78.31.14.56[500]
2011-05-31T23:21:47.000+00:00 sarah.sto.spotify.net charon: 14[ENC]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> parsed
INFORMATIONAL response 5 [ D ]
2011-05-31T23:21:47.000+00:00 sarah.sto.spotify.net charon: 14[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> received DELETE for
ESP CHILD_SA with SPI c68e90b3
2011-05-31T23:21:47.000+00:00 sarah.sto.spotify.net charon: 14[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> CHILD_SA closed
2011-05-31T23:21:47.000+00:00 sarah.sto.spotify.net charon: 14[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> activating new
tasks
2011-05-31T23:21:47.000+00:00 sarah.sto.spotify.net charon: 14[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> nothing to initiate
2011-05-31T23:30:15.000+00:00 sarah.sto.spotify.net charon: 14[NET]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> received packet:
from 193.182.12.31[500] to 78.31.14.56[500]
2011-05-31T23:30:15.000+00:00 sarah.sto.spotify.net charon: 14[ENC]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> parsed
CREATE_CHILD_SA request 2 [ SA No KE ]
2011-05-31T23:30:15.000+00:00 sarah.sto.spotify.net charon: 14[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> 193.182.12.31 is
initiating an IKE_SA
2011-05-31T23:30:15.000+00:00 sarah.sto.spotify.net charon: 14[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> IKE_SA
sarah.sto.spotify.net-alvina.ash.spotify.net[347] state change:
CREATED => CONNECTING
2011-05-31T23:30:15.000+00:00 sarah.sto.spotify.net charon: 14[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> IKE_SA
sarah.sto.spotify.net-alvina.ash.spotify.net[323] state change:
ESTABLISHED => REKEYING
2011-05-31T23:30:15.000+00:00 sarah.sto.spotify.net charon: 14[ENC]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> generating
CREATE_CHILD_SA response 2 [ SA No KE ]
2011-05-31T23:30:15.000+00:00 sarah.sto.spotify.net charon: 14[NET]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> sending packet:
from 78.31.14.56[500] to 193.182.12.31[500]
2011-05-31T23:30:19.000+00:00 sarah.sto.spotify.net charon: 12[NET]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> received packet:
from 193.182.12.31[500] to 78.31.14.56[500]
2011-05-31T23:30:19.000+00:00 sarah.sto.spotify.net charon: 12[ENC]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> parsed
CREATE_CHILD_SA request 2 [ SA No KE ]
2011-05-31T23:30:19.000+00:00 sarah.sto.spotify.net charon: 12[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> received retransmit
of request with ID 2, retransmitting response
2011-05-31T23:30:19.000+00:00 sarah.sto.spotify.net charon: 12[NET]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> sending packet:
from 78.31.14.56[500] to 193.182.12.31[500]
2011-05-31T23:30:27.000+00:00 sarah.sto.spotify.net charon: 11[NET]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> received packet:
from 193.182.12.31[500] to 78.31.14.56[500]
2011-05-31T23:30:27.000+00:00 sarah.sto.spotify.net charon: 11[ENC]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> parsed
CREATE_CHILD_SA request 2 [ SA No KE ]
2011-05-31T23:30:27.000+00:00 sarah.sto.spotify.net charon: 11[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> received retransmit
of request with ID 2, retransmitting response
2011-05-31T23:30:27.000+00:00 sarah.sto.spotify.net charon: 11[NET]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> sending packet:
from 78.31.14.56[500] to 193.182.12.31[500]
2011-05-31T23:30:39.000+00:00 sarah.sto.spotify.net charon: 04[NET]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> received packet:
from 193.182.12.31[500] to 78.31.14.56[500]
2011-05-31T23:30:39.000+00:00 sarah.sto.spotify.net charon: 04[ENC]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> parsed
CREATE_CHILD_SA request 2 [ SA No KE ]
2011-05-31T23:30:39.000+00:00 sarah.sto.spotify.net charon: 04[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> received retransmit
of request with ID 2, retransmitting response
2011-05-31T23:30:39.000+00:00 sarah.sto.spotify.net charon: 04[NET]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> sending packet:
from 78.31.14.56[500] to 193.182.12.31[500]
2011-05-31T23:31:03.000+00:00 sarah.sto.spotify.net charon: 15[NET]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> received packet:
from 193.182.12.31[500] to 78.31.14.56[500]
2011-05-31T23:31:03.000+00:00 sarah.sto.spotify.net charon: 15[ENC]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> parsed
CREATE_CHILD_SA request 2 [ SA No KE ]
2011-05-31T23:31:03.000+00:00 sarah.sto.spotify.net charon: 15[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> received retransmit
of request with ID 2, retransmitting response
2011-05-31T23:31:03.000+00:00 sarah.sto.spotify.net charon: 15[NET]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> sending packet:
from 78.31.14.56[500] to 193.182.12.31[500]
2011-05-31T23:31:45.000+00:00 sarah.sto.spotify.net charon: 13[NET]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> received packet:
from 193.182.12.31[500] to 78.31.14.56[500]
2011-05-31T23:31:45.000+00:00 sarah.sto.spotify.net charon: 13[ENC]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> parsed
CREATE_CHILD_SA request 2 [ SA No KE ]
2011-05-31T23:31:45.000+00:00 sarah.sto.spotify.net charon: 13[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> received retransmit
of request with ID 2, retransmitting response
2011-05-31T23:31:45.000+00:00 sarah.sto.spotify.net charon: 13[NET]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> sending packet:
from 78.31.14.56[500] to 193.182.12.31[500]
2011-05-31T23:33:40.000+00:00 sarah.sto.spotify.net charon: 14[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> queueing IKE_REKEY
task
2011-05-31T23:33:40.000+00:00 sarah.sto.spotify.net charon: 14[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> activating new
tasks
2011-05-31T23:33:40.000+00:00 sarah.sto.spotify.net charon: 14[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> nothing to initiate
2011-05-31T23:42:40.000+00:00 sarah.sto.spotify.net charon: 11[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> queueing IKE_DELETE
task
2011-05-31T23:42:40.000+00:00 sarah.sto.spotify.net charon: 11[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> activating new
tasks
2011-05-31T23:42:40.000+00:00 sarah.sto.spotify.net charon: 11[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323>   activating
IKE_DELETE task
2011-05-31T23:42:40.000+00:00 sarah.sto.spotify.net charon: 11[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> deleting IKE_SA
sarah.sto.spotify.net-alvina.ash.spotify.net[323] between
78.31.14.56[C=SE, O=Spotify,
CN=sarah.sto.spotify.net]...193.182.12.31[C=SE, O=Spotify,
CN=alvina.ash.spotify.net]
2011-05-31T23:42:40.000+00:00 sarah.sto.spotify.net charon: 11[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> IKE_SA
sarah.sto.spotify.net-alvina.ash.spotify.net[323] state change:
REKEYING => DELETING
2011-05-31T23:42:40.000+00:00 sarah.sto.spotify.net charon: 11[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> sending DELETE for
IKE_SA sarah.sto.spotify.net-alvina.ash.spotify.net[323]
2011-05-31T23:42:40.000+00:00 sarah.sto.spotify.net charon: 11[ENC]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> generating
INFORMATIONAL request 6 [ D ]
2011-05-31T23:42:40.000+00:00 sarah.sto.spotify.net charon: 11[NET]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> sending packet:
from 78.31.14.56[500] to 193.182.12.31[500]
2011-05-31T23:42:44.000+00:00 sarah.sto.spotify.net charon: 04[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> retransmit 1 of
request with message ID 6
2011-05-31T23:42:44.000+00:00 sarah.sto.spotify.net charon: 04[NET]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> sending packet:
from 78.31.14.56[500] to 193.182.12.31[500]
2011-05-31T23:42:51.000+00:00 sarah.sto.spotify.net charon: 15[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> retransmit 2 of
request with message ID 6
2011-05-31T23:42:51.000+00:00 sarah.sto.spotify.net charon: 15[NET]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> sending packet:
from 78.31.14.56[500] to 193.182.12.31[500]
2011-05-31T23:43:04.000+00:00 sarah.sto.spotify.net charon: 08[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> retransmit 3 of
request with message ID 6
2011-05-31T23:43:04.000+00:00 sarah.sto.spotify.net charon: 08[NET]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> sending packet:
from 78.31.14.56[500] to 193.182.12.31[500]
2011-05-31T23:43:10.000+00:00 sarah.sto.spotify.net charon: 13[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> destroying IKE_SA
in state DELETING without notification
2011-05-31T23:43:10.000+00:00 sarah.sto.spotify.net charon: 13[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|323> IKE_SA
sarah.sto.spotify.net-alvina.ash.spotify.net[323] state change:
DELETING => DESTROYING
2011-05-31T23:43:10.000+00:00 sarah.sto.spotify.net charon: 13[IKE]
<sarah.sto.spotify.net-alvina.ash.spotify.net|347> IKE_SA
sarah.sto.spotify.net-alvina.ash.spotify.net[347] state change:
CONNECTING => DESTROYING

More information about the Users mailing list