[Swan] negotiation hangs for connections with many SAs
Paul Wouters
paul at nohats.ca
Thu Dec 29 15:29:41 UTC 2016
This has been fixed, please try 3.19rc2 or wait a day or so for 3.19 to be released.
Sent from my iPhone
> On Dec 29, 2016, at 09:55, Noam Singer <noam at fortycloud.com> wrote:
>
> Hello team,
>
> I suspect there is a race condition related to negotiation (and there may be a simple workaround).
>
> I am using LibreSwan 3.16, and I've created a simple IPSec tunnel between two nano machines in AWS, one in Ireland, and the other is in Frankfurt. The only complexity is that these connections use lots of left and right subnets, causing the creation of many SAs.
>
> What happen is that pluto gets stuck completely. Executing anything like ipsec auto --status, would just hang.
>
> The workaround:
> ===============
> Add to /etc/ipsec.conf
> nhelpers=0
> Although I am not 100% sure this resolves the problem in all cases.
>
>
> Here is an example of the configuration files with the problem:
> ---------------------------------------------------------------
> root at ip-172-31-16-203:/home/ubuntu# cat /etc/ipsec.conf
> config setup
> plutodebug=all
> include /etc/ipsec.d/*.conf
>
> root at ip-172-31-16-203:/home/ubuntu# cat /etc/ipsec.d/connST1439.conf
> conn connST1439
> authby=rsasig
> auto=start
> dpdaction=restart
> dpddelay=30
> dpdtimeout=120
> forceencaps=yes
> ike=aes128-sha1
> ikelifetime=86400s
> keyingtries=3
> left=%defaultroute
> leftid=@54.93.130.169
> leftrsasigkey=0sAQPJ1YxE+mxELI/qyHuIqkoFEUrwgSp2sq5ylvAOwxJtyPt0EBLtXdAPBjBw+ZCA8xl28XDssu+oZ6mKZ6aRVKksBAf69VNyNp8d8PYBs2fACkedXYHhLwvPVeyW3HsT26DqfY0oyesoj4ykaH91HUAjMHyS40dEj9+c+y3HJp7LQKgbp3beBNCKnx9ZKbzg1YXXHGe0REqrQnRIcDvXZ3eohjZtHjsHXuKQaWCukSWwgSlOI2Zer5Ag7c44imxlmNPDozm1IegtHC39qxGbxT5cVrWVF332YmxP6Q+Y8uJOpspxOASUNfxCpiOHqLGZBjHg21UylkFf7SsGSdFvxizDK7EEhcIM2Fa6OGDcplY6bCdD
> leftsubnets=10.254.129.0/24,172.31.16.0/20,172.31.42.0/28,172.31.42.112/28,172.31.42.128/28,172.31.42.144/28,172.31.42.16/28,172.31.42.160/28,172.31.42.176/28,172.31.42.192/28,172.31.42.208/28,172.31.42.224/28,172.31.42.240/28,172.31.42.32/28,172.31.42.48/28,172.31.42.64/28,172.31.42.80/28,172.31.42.96/28
> leftupdown=/usr/fortycloud/libreSwanUpDown.sh
> pfs=no
> phase2alg=aes128-sha1
> right=54.171.1.11
> rightid=@54.171.1.11
> rightrsasigkey=0sAQPCXrYVHB4PX47nOXvfiRlHiXZQFqBj6TLEyVH5WzOrJN8xeKiy3/X8Q3Y6hX8aH2MASCsDqvbGXEvA/HfHvFjIaPuzxd7i8cNrsMbCUVAYe7wAl9Duwzq/dPdp6G3WkAFEi0wo8ocAwKanef7Xd7DmldUFjKe96S6Z01TNRQsX3H8+mKQQOcBgNJoj6CniHD5GGSbtibJWEQU4pmeuYSp4YZc5kGnpYWt5sU0F0wVcFRaY71Y9wqe4BiNJi05lnvwq6Z+MN527C18tUbGyfaJuqk2IE4dM8yTp/p6FC8MhNjwZmFZwk4TOVYPX16X6JYQm+ieoKl3Gpc74kpnujJax2lhLdEkVUFRZIJ9plytV9Ow1
> rightsubnets=10.10.10.0/24,10.10.42.0/28,10.10.42.112/28,10.10.42.128/28,10.10.42.144/28,10.10.42.16/28,10.10.42.160/28,10.10.42.176/28,10.10.42.192/28,10.10.42.208/28,10.10.42.224/28,10.10.42.240/28,10.10.42.32/28,10.10.42.48/28,10.10.42.64/28,10.10.42.80/28,10.10.42.96/28,10.254.128.0/24
> salifetime=28800s
> type=tunnel
>
>
> Here are the last log lines in /var/log/auth.log:
> -------------------------------------------------
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | #198 send_crypto_helper_request:613 st->st_calculating = TRUE;
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | state: #198 requesting EVENT_SO_DISCARD to be deleted
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | event_schedule called for 60 seconds
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | event_schedule_tv called for about 60 seconds and change
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | inserting event EVENT_CRYPTO_FAILED, timeout in 60.000000 seconds for #198
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | removing pending policy for "none" {0x7f585a9705e0}
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | unqueuing pending Quick Mode with 54.171.1.11 "connST1439/11x18" import:admin initiate
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | creating state object #199 at 0x7f585a9ee1e0
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | parent state #199: new > STATE_UNDEFINED(ignore)
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | duplicating state object #1 as #199
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | #199 quick_outI1:921 st->st_calculating == FALSE;
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | processing connection "connST1439/11x18"
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | child state #199: STATE_UNDEFINED(ignore) > STATE_QUICK_I1(authenticated-ipsec)
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | ignore states: 0
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | half-open-ike states: 0
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | open-ike states: 0
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | established-anonymous-ike states: 0
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | established-authenticated-ike states: 1
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | anonymous-ipsec states: 0
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | authenticated-ipsec states: 198
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | informational states: 0
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | unknown states: 0
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | category states: 199 count states: 199
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | inserting state object #199
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | finding hash chain in state hash table
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | ICOOKIE: 0e e5 16 96 4e c3 51 d4
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | RCOOKIE: 67 1c 39 6d eb bb 26 d0
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | found hash chain 2
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | list 0x7f5859f49318 first entry 0x7f585a9edf18
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | inserted state 0x7f585a9ee1e0 entry 0x7f585a9ee848 next 0x7f585a9edf18 prev-next 0x7f5859f49318 into list
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | updated next state 0x7f585a9ed8b0 entry 0x7f585a9edf18 next 0x7f585a9ed5e8 prev-next 0x7f585a9ee848
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | finding hash chain in icookie hash table
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | ICOOKIE: 0e e5 16 96 4e c3 51 d4
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | RCOOKIE: 00 00 00 00 00 00 00 00
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | found hash chain 23
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | list 0x7f5859f49500 first entry 0x7f585a9edf30
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | inserted state 0x7f585a9ee1e0 entry 0x7f585a9ee860 next 0x7f585a9edf30 prev-next 0x7f5859f49500 into list
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | updated next state 0x7f585a9ed8b0 entry 0x7f585a9edf30 next 0x7f585a9ed600 prev-next 0x7f585a9ee860
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | event_schedule called for 0 seconds
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | event_schedule_tv called for about 0 seconds and change
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | inserting event EVENT_SO_DISCARD, timeout in 0.000000 seconds for #199
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | check_kernel_encrypt_alg(12,0): OK
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: "connST1439/11x18" #199: initiating Quick Mode RSASIG+ENCRYPT+TUNNEL+UP+IKEV1_ALLOW+IKEV2_ALLOW+SAREF_TRACK+IKE_FRAG_ALLOW {using isakmp#1 msgid:d7e131fe proposal=AES(12)_128-SHA1(2)_000 pfsgroup=no-pfs}
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | crypto helper 0: pcw_work: 197
> Dec 29 14:28:15 ip-172-31-16-203 pluto[2294]: | asking crypto helper 0 to do build nonce; request ID 200 (len=2776, pcw_work=197)
>
>
> I would appreciate your thoughts on this issue
>
> Thanks in advance
>
>
> Noam Singer
>
> _______________________________________________
> Swan mailing list
> Swan at lists.libreswan.org
> https://lists.libreswan.org/mailman/listinfo/swan
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.libreswan.org/pipermail/swan/attachments/20161229/663e653b/attachment-0001.html>
More information about the Swan
mailing list