Description of problem: I've been playing with Apple's new support for IKEv2. To start simple I used a PSK. Apple asks for Server Address, Remote ID and Local ID. For Remote ID I used the same value as the Server Address, the FQDN of my vpn server since that is a required field. I left Local ID empty since I have no idea what should be filled in there and I couldn't find any documentation. Now as soon as I connect I get: Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: FATAL ERROR: "myvpn"[2] 217.100.28.18 #1: unable to malloc 140723783091312 bytes for copy of id And pluto is restarted by systemd. On a hunch, I put "beep boop" into the Local ID field, and now I can connect successfully. Here are the full logs, please let me know if you need more debug logging. Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: packet from 217.100.28.18:500: myvpn IKE proposals for initial responder: 1:IKE:ENCR=AES_GCM_C_256;PRF=HMAC_SHA2-512,HMAC_SHA2-256,HMAC_SHA1;INTEG=NONE;DH=MODP2048,MODP3072,MODP4096,MODP8192 2:IKE:ENCR=AES_GCM_C_128;PRF=HMAC_SHA2-512,HMAC_SHA2-256,HMAC_SHA1;INTEG=NONE;DH=MODP2048,MODP3072,MODP4096,MODP8192 3:IKE:ENCR=AES_CBC_256;PRF=HMAC_SHA2-512,HMAC_SHA2-256,HMAC_SHA1;INTEG=HMAC_SHA2_512_256,HMAC_SHA2_256_128,HMAC_SHA1_96;DH=MODP2048,MODP3072,MODP1536 4:IKE:ENCR=AES_CBC_128;PRF=HMAC_SHA2-512,HMAC_SHA2-256,HMAC_SHA1;INTEG=HMAC_SHA2_512_256,HMAC_SHA2_256_128,HMAC_SHA1_96;DH=MODP2048,MODP3072,MODP1536 (default) Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: packet from 217.100.28.18:500: proposal 1:IKE:ENCR=AES_CBC_256;PRF=HMAC_SHA2-256;INTEG=HMAC_SHA2_256_128;DH=MODP2048 chosen from: 1:IKE:ENCR=AES_CBC_256;PRF=HMAC_SHA2-256;INTEG=HMAC_SHA2_256_128;DH=MODP2048[first-match] 2:IKE:ENCR=AES_CBC_256;PRF=HMAC_SHA2-256;INTEG=HMAC_SHA2_256_128;DH=ECP_256 3:IKE:ENCR=AES_CBC_256;PRF=HMAC_SHA2-256;INTEG=HMAC_SHA2_256_128;DH=MODP1536 4:IKE:ENCR=AES_CBC_128;PRF=HMAC_SHA1;INTEG=HMAC_SHA1_96;DH=MODP1024 5:IKE:ENCR=3DES;PRF=HMAC_SHA1;INTEG=HMAC_SHA1_96;DH=MODP1024 Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: "myvpn"[1] 217.100.28.18 #1: STATE_PARENT_R1: received v2I1, sent v2R1 {auth=IKEv2 cipher=aes_256 integ=sha256_128 prf=OAKLEY_SHA2_256 group=MODP2048} Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: "myvpn"[1] 217.100.28.18 #1: new NAT mapping for #1, was 217.100.28.18:500, now 217.100.28.18:4500 Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: "myvpn"[1] 217.100.28.18 #1: switched from "myvpn"[1] 217.100.28.18 to "myvpn" Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: "myvpn"[2] 217.100.28.18 #1: deleting connection "myvpn"[1] 217.100.28.18 instance with peer 217.100.28.18 {isakmp=#0/ipsec=#0} Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: "myvpn"[2] 217.100.28.18 #1: IKEv2 mode peer ID is ID_IPV4_ADDR: '192.168.1.20' Nov 05 21:41:43 vpn.cloud.tilaa.com audit[6585]: CRYPTO_IKE_SA pid=6585 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:ipsec_t:s0 msg='op=start direction=responder conn-name="myvpn" connstate=1 ike-version=2.0 auth=PRESHARED_KEY cipher=aes ksize=256 integ=sha256_128 prf=sha256 pfs=MODP2048 laddr=37.252.126.87 exe="/usr/libexec/ipsec/pluto" hostname=? addr=217.100.28.18 terminal=? res=success' Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: FATAL ERROR: "myvpn"[2] 217.100.28.18 #1: unable to malloc 140723783091312 bytes for copy of id Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: forgetting secrets Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: "myvpn"[2] 217.100.28.18: deleting connection "myvpn"[2] 217.100.28.18 instance with peer 217.100.28.18 {isakmp=#1/ipsec=#0} Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: "myvpn" #1: deleting state (STATE_PARENT_R2) Nov 05 21:41:43 vpn.cloud.tilaa.com audit[6585]: CRYPTO_IKE_SA pid=6585 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:ipsec_t:s0 msg='op=destroy direction=responder conn-name="myvpn" connstate=1 ike-version=2.0 auth=PRESHARED_KEY cipher=aes ksize=256 integ=sha256_128 prf=sha256 pfs=MODP2048 laddr=37.252.126.87 exe="/usr/libexec/ipsec/pluto" hostname=? addr=217.100.28.18 terminal=? res=success' Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: "myvpn": deleting connection Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: shutting down interface eth0/eth0 2a02:2770:7:0:21a:4aff:fe18:bff2:500 Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: shutting down interface lo/lo ::1:500 Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: shutting down interface lo/lo 127.0.0.1:4500 Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: shutting down interface lo/lo 127.0.0.1:500 Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: shutting down interface eth0/eth0 37.252.126.87:4500 Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: shutting down interface eth0/eth0 37.252.126.87:500 Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: leak: address lease entry, item size: 80 Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: leak: ikev2_inI2outR2 KE, item size: 144 Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: leak: message buffer in comm_handle(), item size: 544 Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: leak: msg_digest, item size: 4152 Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: leak: EVENT_SHUNT_SCAN, item size: 32 Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: leak: EVENT_PENDING_DDNS, item size: 32 Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: leak: EVENT_PENDING_PHASE2, item size: 32 Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: leak: EVENT_SD_WATCHDOG, item size: 32 Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: leak: addresspool entry, item size: 88 Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: leak: EVENT_LOG_DAILY, item size: 32 Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: leak: EVENT_REINIT_SECRET, item size: 32 Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: leak: nssdb, item size: 17 Nov 05 21:41:43 vpn.cloud.tilaa.com pluto[6585]: leak detective found 12 leaks, total size 5217 Nov 05 21:41:43 vpn.cloud.tilaa.com systemd[1]: ipsec.service: Main process exited, code=exited, status=1/FAILURE Version-Release number of selected component (if applicable): # rpm -q libreswan libreswan-3.18-1.fc24.x86_64 This happens with both OSX Sierra (10.12.1) and El Capitan (10.11.1)
can you rerun with plutodebug=all and attach the logs?
Its weird because the segment of code there checks for a null pointer and if not copy it. So the source id is already mangled. void duplicate_id(struct id *dst, const struct id *src) { passert(dst->name.ptr == NULL || dst->name.ptr != src->name.ptr); free_id_content(dst); dst->kind = src->kind; dst->ip_addr = src->ip_addr; clonetochunk(dst->name, src->name.ptr, src->name.len, "copy of id"); } The clonetochunk() is causing the malloc., so id *src is already corrupted?
I uploaded a core dump to https://ruben.fedorapeople.org/core.pluto.0.87ceb5ba134d4b8aa84d5463e4c732ac.18610.1478525826000000000000.lz4 and the log to https://ruben.fedorapeople.org/pluto.log Please note these are from another server on Rawhide, but it's the same Librewan version.
I double checked, src is indeed already garbled: (gdb) bt #0 0x00007f3f8d2cea37 in memcpy.5 () from /lib64/libc.so.6 #1 0x000055c409f4f3c5 in memcpy (__len=16, __src=0x20, __dest=<optimized out>) at /usr/include/bits/string3.h:53 #2 clone_bytes (orig=0x20, size=16, name=name@entry=0x55c409fa3371 "copy of id") at /usr/src/debug/libreswan-3.18/lib/libswan/alloc.c:211 #3 0x000055c409f5065e in duplicate_id (dst=dst@entry=0x55c40b930830, src=src@entry=0x55c40b935e30) at /usr/src/debug/libreswan-3.18/lib/libswan/id.c:544 #4 0x000055c409f3ff30 in lease_an_address (c=c@entry=0x55c40b935bb8, ipa=ipa@entry=0x7fffac9f9900) at /usr/src/debug/libreswan-3.18/programs/pluto/addresspool.c:351 #5 0x000055c409f19564 in ikev2_cp_reply_state (md=0x55c40b92f3d8, isa_xchg=ISAKMP_v2_AUTH, ret_cst=0x7fffac9f98b8) at /usr/src/debug/libreswan-3.18/programs/pluto/ikev2_child.c:931 #6 ikev2_child_sa_respond (md=md@entry=0x55c40b92f3d8, role=role@entry=ORIGINAL_RESPONDER, outpbs=outpbs@entry=0x7fffac9f9a40, isa_xchg=isa_xchg@entry=ISAKMP_v2_AUTH) at /usr/src/debug/libreswan-3.18/programs/pluto/ikev2_child.c:974 #7 0x000055c409f10b92 in ikev2_parent_inI2outR2_auth_tail (md=md@entry=0x55c40b92f3d8, pam_status=pam_status@entry=1) at /usr/src/debug/libreswan-3.18/programs/pluto/ikev2_parent.c:3364 #8 0x000055c409f1162f in ikev2_parent_inI2outR2_tail (dh=0x55c40b931498, r=<optimized out>) at /usr/src/debug/libreswan-3.18/programs/pluto/ikev2_parent.c:3155 #9 ikev2_parent_inI2outR2_continue (dh=0x55c40b931498, r=<optimized out>) at /usr/src/debug/libreswan-3.18/programs/pluto/ikev2_parent.c:3007 #10 0x000055c409f32b13 in handle_helper_answer (w=0x55c40b921288) at /usr/src/debug/libreswan-3.18/programs/pluto/pluto_crypt.c:884 #11 0x00007f3f8e3386b6 in event_base_loop () from /lib64/libevent-2.0.so.5 #12 0x000055c409ef5e04 in main_loop () at /usr/src/debug/libreswan-3.18/programs/pluto/server.c:628 #13 call_server () at /usr/src/debug/libreswan-3.18/programs/pluto/server.c:742 #14 0x000055c409edeba0 in main (argc=<optimized out>, argv=<optimized out>) at /usr/src/debug/libreswan-3.18/programs/pluto/plutomain.c:1642 (gdb) frame 2 #2 clone_bytes (orig=0x20, size=16, name=name@entry=0x55c409fa3371 "copy of id") at /usr/src/debug/libreswan-3.18/lib/libswan/alloc.c:211 211 memcpy(p, orig, size); (gdb) frame 3 #3 0x000055c409f5065e in duplicate_id (dst=dst@entry=0x55c40b930830, src=src@entry=0x55c40b935e30) at /usr/src/debug/libreswan-3.18/lib/libswan/id.c:544 544 clonetochunk(dst->name, src->name.ptr, src->name.len, "copy of id"); (gdb) set print pretty (gdb) p src $1 = (const struct id *) 0x55c40b935e30 (gdb) p *src $2 = { kind = 1, ip_addr = { u = { v4 = { sin_family = 2, sin_port = 0, sin_addr = { s_addr = 335653056 }, sin_zero = "\000\000\000\000\000\000\000" }, v6 = { sin6_family = 2, sin6_port = 0, sin6_flowinfo = 335653056, sin6_addr = { __in6_u = { __u6_addr8 = '\000' <repeats 12 times>, "\340\332_\215", __u6_addr16 = {0, 0, 0, 0, 0, 0, 56032, 36191}, __u6_addr32 = {0, 0, 0, 2371869408} } }, sin6_scope_id = 32575 } } }, name = { ptr = 0x20 <error: Cannot access memory at address 0x20>, len = 16 } }
Still an issue with libreswan-3.19-1.fc26.x86_64 on Rawhide.
If it helps, I can reproduce the issue with strongswan 5.5.1 as a client instead of OSX. This is my strongswan config: conn vpn leftsourceip=%config right=37.252.122.142 keyexchange=ikev2 ike = aes256-sha256-modp2048! esp = aes256-sha256-modp2048,aes256-sha256! leftauth=psk rightauth=psk auto=start #leftid=bliep If I uncomment leftid, all is fine.
thanks! that does help as I can now make a test case for this more easily!
leftid=bliep generates ip address for host name bliep. That is not same as @bliep.
Could you please add your libreswan config.
So I cannot reproduce this. The above strongswan config results in: no IDi configured, fall back on IP address So either it fails to AUTH because the ID on the libreswan end does not match. or if i use no ID on the libreswan end, it matches ID and there is no problem. Can you share your libreswan config so we have the configs of both ends?
Sure, here's my libreswan config: conn myvpn left = 37.252.122.142 leftsubnet = 0.0.0.0/0 narrowing = yes right = %any rightaddresspool = 10.224.1.97-10.224.1.128 authby = secret auto = add ikev2 = insist rekey = no ike = aes256-sha256;modp2048 esp = aes256-sha256;modp2048 modecfgdns1 = 37.252.122.8 modecfgdns2 = 37.252.122.9 dpddelay = 30 dpdtimeout = 120 dpdaction = clear
I'm not sure if this helps, but my client is behind NAT, my server isn't: Jan 29 18:23:32: | request lease from addresspool 10.224.1.97-10.224.1.128 reference count 5 thatid '192.168.1.62' that.client.addr 217.100.28.18 Jan 29 18:23:32: | in share_lease: no lingering addresspool lease for '192.168.1.62' FATAL ERROR: "myvpn"[2] 217.100.28.18 #1: unable to malloc 139951907828681 bytes for copy of id Here 192.168.1.62 is my private ip on my home lan, 217.100.28.18 is the public ip of home router.
Created attachment 1245616 [details] pluto log with strongswan client and no leftid set
This bug appears to have been reported against 'rawhide' during the Fedora 26 development cycle. Changing version to '26'.
Fixed in 3.21-1