[Swan] Frequent Crashing with libreswan 3.10/pluto

Reuben Farrelly reuben-libreswan at reub.net
Tue Oct 7 02:39:31 EEST 2014 

I've recently set up an IPSec VPN between a VPS I run and a Cisco IOS 
router.  This seems to function just fine (initiates and passes traffic 
as designed) however I'm seeing frequent crashes on the libreswan end, 
which is causing disruptions in connectivity.  The frequency of the 
crashing is usually 1-2 times per day.

The Cisco end is an 800 series router running 15.4(3)M which acts as a 
spoke, initiating connections.  The VPS end is acting as a hub and is a 
Gentoo x86_64 VM running on Linode, who use Xen.  I am using the kernel 
they supply as part of the VPS, which is currently 3.15.4.  I am running 
with libreswan-3.10 and nss-3.17.1 from Gentoo portage.

The IPSec connection uses IKEv2 and runs in tunnel mode, and I have 
separate /32s on each end of the link and only encrypt data between the 
two endpoints.

The libreswan config I have is:

conn reub.net
         type=tunnel
         left=106.187.48.126
         leftid=@lightning.reub.net
         leftsubnet=192.168.6.1/32
         leftsourceip=192.168.6.1
         right=%any
         rightid=@router-2.reub.net
         rightsubnet=192.168.6.2/32
         authby=secret
         ikev2=insist
         ike=aes256-sha1;modp1536
         esp=aes128-sha1;modp1536
         mtu=1438
         dpddelay=15
         dpdtimeout=45
         dpdaction=restart
         auto=add

Frequently the libreswan end seems to just die.  Pluto crashes out 
entirely and the VPN goes down.

At the time of this the following is logged in the kernel log:

Oct  6 14:52:06 lightning kernel: pluto[23223]: segfault at 58 ip 
00007f8f85f0c8d0 sp 00007fffb30275b8 error 4 in 
libnss3.so[7f8f85ebc000+11f000]

And in the auth.log the lines preceding this are:

Oct  6 14:50:12 lightning pluto[23223]: | V2 microcode entry (R2: 
process INFORMATIONAL) has unspecified timeout_event
Oct  6 14:50:19 lightning pluto[23223]: "reub.net"[1] 59.167.163.35 #3: 
initiating v2 parent SA to replace #1
Oct  6 14:50:19 lightning pluto[23223]: | natd_hash: Warning, rcookie is 
zero !!
Oct  6 14:50:19 lightning pluto[23223]: | natd_hash: Warning, rcookie is 
zero !!
Oct  6 14:50:19 lightning pluto[23223]: "reub.net"[1] 59.167.163.35 #3: 
transition from state STATE_IKEv2_START to state STATE_PARENT_I1
Oct  6 14:50:19 lightning pluto[23223]: "reub.net"[1] 59.167.163.35 #3: 
STATE_PARENT_I1: sent v2I1, expected v2R1
Oct  6 14:50:19 lightning pluto[23223]: | V2 microcode entry (initiate 
IKE_SA_INIT) has unspecified timeout_event
Oct  6 14:50:20 lightning pluto[23223]: | no pending CHILD SAs found for 
reub.net: Reauthentication so use the original policy
Oct  6 14:50:20 lightning pluto[23223]: "reub.net"[1] 59.167.163.35 #4: 
transition from state STATE_PARENT_I1 to state STATE_PARENT_I2
Oct  6 14:50:20 lightning pluto[23223]: "reub.net"[1] 59.167.163.35 #4: 
STATE_PARENT_I2: sent v2I2, expected v2R2 {auth=IKEv2 cipher=aes_256 
integ=sha1_96 prf=sha group=MODP1536}
Oct  6 14:50:20 lightning pluto[23223]: | V2 microcode entry (Initiator: 
process IKE_SA_INIT reply, initiate IKE_AUTH) has unspecified timeout_event
Oct  6 14:50:20 lightning pluto[23223]: "reub.net"[1] 59.167.163.35 #4: 
missing payload(s) 
(ISAKMP_NEXT_v2SA+ISAKMP_NEXT_v2TSi+ISAKMP_NEXT_v2TSr). Message dropped.
Oct  6 14:50:36 lightning pluto[23223]: | V2 microcode entry (I2: 
process INFORMATIONAL) has unspecified timeout_event
Oct  6 14:50:41 lightning pluto[23223]: | V2 microcode entry (I2: 
process INFORMATIONAL) has unspecified timeout_event
Oct  6 14:50:46 lightning pluto[23223]: | V2 microcode entry (I2: 
process INFORMATIONAL) has unspecified timeout_event
Oct  6 14:50:51 lightning pluto[23223]: | V2 microcode entry (I2: 
process INFORMATIONAL) has unspecified timeout_event
Oct  6 14:50:56 lightning pluto[23223]: | V2 microcode entry (I2: 
process INFORMATIONAL) has unspecified timeout_event
Oct  6 14:51:01 lightning pluto[23223]: | V2 microcode entry (I2: 
process INFORMATIONAL) has unspecified timeout_event
Oct  6 14:51:50 lightning pluto[23223]: | found connection: reub.net
Oct  6 14:51:50 lightning pluto[23223]: | natd_hash: Warning, rcookie is 
zero !!
Oct  6 14:51:50 lightning pluto[23223]: | natd_hash: Warning, rcookie is 
zero !!
Oct  6 14:51:50 lightning pluto[23223]: "reub.net"[1] 59.167.163.35 #5: 
transition from state STATE_IKEv2_START to state STATE_PARENT_R1
Oct  6 14:51:50 lightning pluto[23223]: "reub.net"[1] 59.167.163.35 #5: 
STATE_PARENT_R1: received v2I1, sent v2R1 {auth=IKEv2 cipher=aes_256 
integ=sha1_96 prf=sha group=MODP1536}
Oct  6 14:51:50 lightning pluto[23223]: | found connection: reub.net
Oct  6 14:51:50 lightning pluto[23223]: | natd_hash: Warning, rcookie is 
zero !!
Oct  6 14:51:50 lightning pluto[23223]: | natd_hash: Warning, rcookie is 
zero !!
Oct  6 14:51:50 lightning pluto[23223]: "reub.net"[1] 59.167.163.35 #6: 
transition from state STATE_IKEv2_START to state STATE_PARENT_R1
Oct  6 14:51:50 lightning pluto[23223]: "reub.net"[1] 59.167.163.35 #6: 
STATE_PARENT_R1: received v2I1, sent v2R1 {auth=IKEv2 cipher=aes_256 
integ=sha1_96 prf=sha group=MODP1536}
Oct  6 14:51:50 lightning pluto[23223]: "reub.net"[1] 59.167.163.35 #5: 
IKEv2 mode peer ID is ID_FQDN: '@router-2.reub.net'
Oct  6 14:51:50 lightning pluto[23223]: | CHILD SA proposals received
Oct  6 14:51:50 lightning pluto[23223]: | printing contents struct 
traffic_selector
Oct  6 14:51:50 lightning pluto[23223]: |   ts_type: 
IKEv2_TS_IPV4_ADDR_RANGE
Oct  6 14:51:50 lightning pluto[23223]: |   ipprotoid: 0
Oct  6 14:51:50 lightning pluto[23223]: |   startport: 0
Oct  6 14:51:50 lightning pluto[23223]: |   endport: 65535
Oct  6 14:51:50 lightning pluto[23223]: |   ip low: 192.168.6.1
Oct  6 14:51:50 lightning pluto[23223]: |   ip high: 192.168.6.1
Oct  6 14:51:50 lightning pluto[23223]: | printing contents struct 
traffic_selector
Oct  6 14:51:50 lightning pluto[23223]: |   ts_type: 
IKEv2_TS_IPV4_ADDR_RANGE
Oct  6 14:51:50 lightning pluto[23223]: |   ipprotoid: 0
Oct  6 14:51:50 lightning pluto[23223]: |   startport: 0
Oct  6 14:51:50 lightning pluto[23223]: |   endport: 65535
Oct  6 14:51:50 lightning pluto[23223]: |   ip low: 192.168.6.2
Oct  6 14:51:50 lightning pluto[23223]: |   ip high: 192.168.6.2
Oct  6 14:51:50 lightning pluto[23223]: "reub.net"[1] 59.167.163.35 #7: 
transition from state STATE_PARENT_R1 to state STATE_PARENT_R2
Oct  6 14:51:50 lightning pluto[23223]: "reub.net"[1] 59.167.163.35 #7: 
negotiated tunnel [192.168.6.1,192.168.6.1:0-65535 0] -> 
[192.168.6.2,192.168.6.2:0-65535 0]
Oct  6 14:51:50 lightning pluto[23223]: "reub.net"[1] 59.167.163.35 #7: 
STATE_PARENT_R2: received v2I2, PARENT SA established tunnel mode 
{ESP=>0xe6ded03c <0xe746ba5e xfrm=AES_128-HMAC_SHA1 NATOA=none NATD=none 
DPD=active}
Oct  6 14:51:50 lightning pluto[23223]: | releasing whack for #7 (sock=-1)
Oct  6 14:51:50 lightning pluto[23223]: | releasing whack and unpending 
for parent #5

How do I go about debugging this and determining why the crash is occurring?

[Note: this internet connection is going to be changing in the next few 
days and the public IP address on the spoke side will be replaced by a 
NATted private IP, but I'm not expecting to make any config changes to 
the endpoints].

Thanks,
Reuben

More information about the Swan mailing list