Hi list.
I've been running libreswan 3.29 on the two ends on Fedora for about a
week with no problems. Yesterday, however, the tunnel got down and only
got up after a forced restart on both sites. Today it happened again and
after searching the logs, they were like this:
<PART 1>
Oct 3 01:17:49.027022: added connection description "foobar/1x0"
Oct 3 01:17:49.027099: added connection description "foobar/2x0"
Oct 3 01:17:49.028710: loading secrets from "/etc/ipsec.d/foobar.secrets"
Oct 3 01:17:49.029648: initiating all conns with alias='foobar'
Oct 3 01:17:49.029695: "foobar/2x0" #3: initiating v2 parent SA
Oct 3 01:17:49.029722: "foobar/2x0": constructed local IKE proposals
for foobar/2x0 (IKE SA initiator selecting KE):
1:IKE:ENCR=AES_GCM_C_256,AES_GCM_C_128;PRF=HMAC_SHA2_512;INTEG=NONE;DH=MODP2048
Oct 3 01:17:49.036593: "foobar/2x0" #3: STATE_PARENT_I1: sent v2I1,
expected v2R1
Oct 3 01:17:49.055340: | Switching Child connection for #6 to
"foobar/1x0" from "foobar/2x0"
Oct 3 01:17:49.055380: "foobar/1x0": constructed local ESP/AH proposals
for foobar/1x0 (IKE SA initiator emitting ESP/AH proposals):
1:ESP:ENCR=AES_GCM_C_128,AES_GCM_C_256;INTEG=NONE;DH=NONE;ESN=DISABLED
Oct 3 01:17:49.055409: "foobar/1x0" #6: STATE_PARENT_I2: sent v2I2,
expected v2R2 {auth=IKEv2 cipher=AES_GCM_16_256 integ=n/a
prf=HMAC_SHA2_512 group=MODP2048}
Oct 3 01:17:49.088039: "foobar/1x0" #6: IKEv2 mode peer ID is
ID_IPV4_ADDR: '<right_ip>'
Oct 3 01:17:49.088134: "foobar/1x0" #6: Authenticated using authby=secret
Oct 3 01:17:49.141648: "foobar/1x0" #6: negotiated connection
[172.16.0.0-172.16.3.255:0-65535 0] ->
[192.168.120.0-192.168.120.255:0-65535 0]
Oct 3 01:17:49.141681: "foobar/1x0" #6: STATE_V2_IPSEC_I: IPsec SA
established tunnel mode {ESP/NAT=>0x3c33205c <0x5a6d3e16
xfrm=AES_GCM_16_128-NONE NATOA=none NATD=<right_ip>:4500 DPD=passive}
Oct 3 01:17:49.141720: "foobar/2x0": constructed local ESP/AH proposals
for foobar/2x0 (ESP/AH initiator emitting proposals):
1:ESP:ENCR=AES_GCM_C_128,AES_GCM_C_256;INTEG=NONE;DH=MODP2048;ESN=DISABLED
Oct 3 01:17:49.143342: "foobar/2x0" #7: STATE_V2_CREATE_I: sent IPsec
Child req wait response
Oct 3 01:17:49.197757: "foobar/2x0" #7: negotiated connection
[10.17.1.0-10.17.1.255:0-65535 0] ->
[192.168.120.0-192.168.120.255:0-65535 0]
Oct 3 01:17:49.197784: "foobar/2x0" #7: STATE_V2_IPSEC_I: IPsec SA
established tunnel mode {ESP/NAT=>0x36de525f <0x9a3b0da8
xfrm=AES_GCM_16_128-NONE-MODP2048 NATOA=none NATD=<right_ip>:4500
DPD=passive}
Oct 3 01:42:18.050187: "foobar/2x0" #7: deleting state
(STATE_V2_IPSEC_I) aged 1468.908s and sending notification
Oct 3 01:42:18.050224: "foobar/2x0" #7: ESP traffic information: in=0B
out=943B
Oct 3 01:42:18.068007: "foobar/1x0" #6: deleting state
(STATE_V2_IPSEC_I) aged 1469.012s and sending notification
Oct 3 01:42:18.068047: "foobar/1x0" #6: ESP traffic information:
in=123KB out=122KB
Oct 3 01:42:18.081285: "foobar/2x0" #3: deleting state
(STATE_PARENT_I3) aged 1469.051s and sending notification
Oct 3 01:42:18.081392: "foobar/2x0" #3: deleting IKE SA for connection
'foobar/2x0' but connection is supposed to remain up; schedule
EVENT_REVIVE_CONNS
Oct 3 01:42:18.098134: "foobar/1x0": unroute-client output: Error:
ipv4: Invalid values in header for route get request.
Oct 3 01:42:18.105102: "foobar/1x0": unroute-client output:
/usr/libexec/ipsec/_updown.netkey: line 449: [: too many arguments
</PART 1>
<PART 2>
Oct 3 01:42:18.809574: added connection description "foobar/1x0"
Oct 3 01:42:18.809675: added connection description "foobar/2x0"
Oct 3 01:42:18.811288: loading secrets from "/etc/ipsec.d/foobar.secrets"
Oct 3 01:42:18.811967: initiating all conns with alias='foobar'
Oct 3 01:42:18.812014: "foobar/2x0" #3: initiating v2 parent SA
Oct 3 01:42:18.812040: "foobar/2x0": constructed local IKE proposals
for foobar/2x0 (IKE SA initiator selecting KE):
1:IKE:ENCR=AES_GCM_C_256,AES_GCM_C_128;PRF=HMAC_SHA2_512;INTEG=NONE;DH=MODP2048
Oct 3 01:42:18.818694: "foobar/2x0" #3: STATE_PARENT_I1: sent v2I1,
expected v2R1
Oct 3 01:42:19.318591: "foobar/2x0" #3: STATE_PARENT_I1:
retransmission; will wait 0.5 seconds for response
Oct 3 01:42:19.818551: "foobar/2x0" #3: STATE_PARENT_I1:
retransmission; will wait 1 seconds for response
Oct 3 01:42:20.819064: "foobar/2x0" #3: STATE_PARENT_I1:
retransmission; will wait 2 seconds for response
Oct 3 01:42:22.820584: "foobar/2x0" #3: STATE_PARENT_I1:
retransmission; will wait 4 seconds for response
Oct 3 01:42:26.823015: "foobar/2x0" #3: STATE_PARENT_I1:
retransmission; will wait 8 seconds for response
Oct 3 01:42:34.828368: "foobar/2x0" #3: STATE_PARENT_I1:
retransmission; will wait 16 seconds for response
Oct 3 01:42:50.829629: "foobar/2x0" #3: STATE_PARENT_I1:
retransmission; will wait 32 seconds for response
Oct 3 01:42:58.899240: "foobar/2x0" #3: deleting state
(STATE_PARENT_I1) aged 40.087s and NOT sending notification
Oct 3 01:42:58.899271: "foobar/2x0" #3: deleting IKE SA for connection
'foobar/2x0' but connection is supposed to remain up; schedule
EVENT_REVIVE_CONNS
</PART 2>
The obvious error on the end of PART 1 happened about once a hour until
it failed permanently. That was the moment the tunnel got down. Then
PART 2 kept repeating.
I went to the script and edited it from
if [ -z $(ip -o route list src ${PLUTO_MY_SOURCEIP}) ]; then
to
if [ -z "$(ip -o route list src ${PLUTO_MY_SOURCEIP})" ]; then
The error message seem to have stopped so far, but I don't know if it is
really the cause of the problem (of if this is the correct fix).
My configs are like this on both sites:
conn foobar
authby=secret
left=<left_ip>
leftid=<left_ip>
leftsubnets={172.16.0.0/22,10.17.1.0/24}
leftsourceip=172.16.0.1
right=<right_ip>
rightid=<right_ip>
rightsubnet=192.168.120.0/24
ike=aes_gcm-sha2_512;modp2048
ikelifetime=43200
salifetime=21600
esp=aes_gcm-null;modp2048
pfs=yes
ikev2=insist
auto=start
Maybe someone out there knows if it is really a bug on the script?
Thanks!
_______________________________________________
Swan mailing list
[email protected]
https://lists.libreswan.org/mailman/listinfo/swan
