OPNsense Forum

Archive => 16.7 Legacy Series => Topic started by: abel408 on September 29, 2016, 08:53:14 pm

Title: L2TP/IPsec issues with PSK
Post by: abel408 on September 29, 2016, 08:53:14 pm

Hey Everyone,

I'm trying to set up a L2TP/IPsec VPN. I believe my settings are correct, but when I try to connect to the VPN I get the following error on OSX:

Code: [Select]

The L2TP-VPN server did not respond. Try reconnecting. If the problem continues, verify your settings and contact your Administrator.
My IPsec logs look like this:

Code: [Select]

Sep 29 14:43:31 charon: 07[NET] sending packet: from yy.yy.yy.yy[500] to xx.xx.xx.xx[500] (56 bytes)
Sep 29 14:43:31 charon: 07[ENC] generating INFORMATIONAL_V1 request 3734048287 [ N(INVAL_KE) ]
Sep 29 14:43:31 charon: 07[IKE] no shared key found for yy.yy.yy.yy - xx.xx.xx.xx
Sep 29 14:43:31 charon: 07[IKE] <3> no shared key found for yy.yy.yy.yy - xx.xx.xx.xx
Sep 29 14:43:31 charon: 07[IKE] no shared key found for 'yy.yy.yy.yy'[yy.yy.yy.yy] - '(null)'[xx.xx.xx.xx]
Sep 29 14:43:31 charon: 07[IKE] <3> no shared key found for 'yy.yy.yy.yy'[yy.yy.yy.yy] - '(null)'[xx.xx.xx.xx]
Sep 29 14:43:31 charon: 07[IKE] remote host is behind NAT
Sep 29 14:43:31 charon: 07[IKE] <3> remote host is behind NAT
Sep 29 14:43:31 charon: 07[ENC] parsed ID_PROT request 0 [ KE No NAT-D NAT-D ]
Sep 29 14:43:31 charon: 07[NET] received packet: from xx.xx.xx.xx[500] to yy.yy.yy.yy[500] (228 bytes)
Sep 29 14:43:31 charon: 07[NET] sending packet: from yy.yy.yy.yy[500] to xx.xx.xx.xx[500] (160 bytes)
Sep 29 14:43:31 charon: 07[ENC] generating ID_PROT response 0 [ SA V V V V ]
Sep 29 14:43:31 charon: 07[IKE] xx.xx.xx.xx is initiating a Main Mode IKE_SA
Sep 29 14:43:31 charon: 07[IKE] <3> xx.xx.xx.xx is initiating a Main Mode IKE_SA
Sep 29 14:43:31 charon: 07[IKE] received DPD vendor ID
Sep 29 14:43:31 charon: 07[IKE] <3> received DPD vendor ID
Sep 29 14:43:31 charon: 07[IKE] received FRAGMENTATION vendor ID
Sep 29 14:43:31 charon: 07[IKE] <3> received FRAGMENTATION vendor ID
Sep 29 14:43:31 charon: 07[IKE] received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Sep 29 14:43:31 charon: 07[IKE] <3> received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Sep 29 14:43:31 charon: 07[IKE] received draft-ietf-ipsec-nat-t-ike-02 vendor ID
Sep 29 14:43:31 charon: 07[IKE] <3> received draft-ietf-ipsec-nat-t-ike-02 vendor ID
Sep 29 14:43:31 charon: 07[IKE] received draft-ietf-ipsec-nat-t-ike-03 vendor ID
Sep 29 14:43:31 charon: 07[IKE] <3> received draft-ietf-ipsec-nat-t-ike-03 vendor ID
Sep 29 14:43:31 charon: 07[IKE] received draft-ietf-ipsec-nat-t-ike-04 vendor ID
Sep 29 14:43:31 charon: 07[IKE] <3> received draft-ietf-ipsec-nat-t-ike-04 vendor ID
Sep 29 14:43:31 charon: 07[IKE] received draft-ietf-ipsec-nat-t-ike-05 vendor ID
Sep 29 14:43:31 charon: 07[IKE] <3> received draft-ietf-ipsec-nat-t-ike-05 vendor ID
Sep 29 14:43:31 charon: 07[IKE] received draft-ietf-ipsec-nat-t-ike-06 vendor ID
Sep 29 14:43:31 charon: 07[IKE] <3> received draft-ietf-ipsec-nat-t-ike-06 vendor ID
Sep 29 14:43:31 charon: 07[IKE] received draft-ietf-ipsec-nat-t-ike-07 vendor ID
Sep 29 14:43:31 charon: 07[IKE] <3> received draft-ietf-ipsec-nat-t-ike-07 vendor ID
Sep 29 14:43:31 charon: 07[IKE] received draft-ietf-ipsec-nat-t-ike-08 vendor ID
Sep 29 14:43:31 charon: 07[IKE] <3> received draft-ietf-ipsec-nat-t-ike-08 vendor ID
Sep 29 14:43:31 charon: 07[IKE] received draft-ietf-ipsec-nat-t-ike vendor ID
Sep 29 14:43:31 charon: 07[IKE] <3> received draft-ietf-ipsec-nat-t-ike vendor ID
Sep 29 14:43:31 charon: 07[IKE] received NAT-T (RFC 3947) vendor ID
Sep 29 14:43:31 charon: 07[IKE] <3> received NAT-T (RFC 3947) vendor ID
Sep 29 14:43:31 charon: 07[ENC] parsed ID_PROT request 0 [ SA V V V V V V V V V V V V ]
Sep 29 14:43:31 charon: 07[NET] received packet: from xx.xx.xx.xx[500] to yy.yy.yy.yy[500] (788 bytes)
The "no shared key" log doesn't seem right. I do have a shared key set in my settings. Here is what my ipsec.conf file looks like:

Code: [Select]

# This file is automatically generated. Do not edit
config setup
  uniqueids = yes
  charondebug=""

conn con1
  aggressive = yes
  fragmentation = yes
  keyexchange = ikev1
  reauth = yes
  rekey = yes
  forceencaps = yes
  installpolicy = yes
  type = tunnel
  dpdaction = clear
  dpddelay = 90s
  dpdtimeout = 540s
  left = 67.248.71.80
  right = %any
  leftid = 67.248.71.80
  ikelifetime = 28800s
  lifetime = 3600s
  rightsourceip = 10.133.27.0/24
  ike = aes256-sha1-modp1024!
  leftauth = psk
  rightauth = psk
  rightauth2 = xauth-generic
  rightsubnet = 10.133.27.0/24
  leftsubnet = 0.0.0.0/0
  esp = aes128-sha1!
  auto = add

And here is what my ipsec.secrets file looks like:

Code: [Select]

any : PSK "MySh@r3dS3cr3t"
Any where else I should be looking? Any help is appreciated. I've been trying to troubleshoot this for wayyy to long.

Thanks,
Chris

Title: Re: L2TP/IPsec issues with PSK
Post by: abel408 on September 29, 2016, 09:34:36 pm

I'm pretty sure this is a bug. I think my ipsec.secrets file should look like this:

Code: [Select]

%any : PSK "MySh@r3dS3cr3t"
But when I try to input "%any" into the OPNsense GUI, it gives an error about an invalid character.

There is currently a message that says "PSK for any user can be set by using an identifier of any/ANY" which to me is unclear. Are we supposed to use the identifier any, ANY, or any/ANY? None of these choices work anyway.

To get around this, I used the identifier 0.0.0.0

Title: Re: L2TP/IPsec issues with PSK
Post by: AdSchellevis on September 30, 2016, 09:31:27 am

Hi abel408,

I just checked, there seem to be two problems in there, as a workaround 0.0.0.0 is the probably the best option for now. The changes are already in development, they probably will be in our release version soon.

These are the related patches:
https://github.com/opnsense/core/commit/57ab36d3f0ad3b8e8a6ccf70d9f62a74b3a3867f (https://github.com/opnsense/core/commit/57ab36d3f0ad3b8e8a6ccf70d9f62a74b3a3867f)
https://github.com/opnsense/core/commit/76c66b2e0c2f651f68285b2ed7485f7cc427833a (https://github.com/opnsense/core/commit/76c66b2e0c2f651f68285b2ed7485f7cc427833a)
https://github.com/opnsense/core/commit/6e5f2354873080352464e30fce31bc99b324669b (https://github.com/opnsense/core/commit/6e5f2354873080352464e30fce31bc99b324669b)

Best regards,

Ad

Title: Re: L2TP/IPsec issues with PSK
Post by: abel408 on September 30, 2016, 05:45:19 pm

Thanks AdSchellevis for the fix.

I now have IPsec working, but my end goal is to get L2TP working. I followed the following guide o the T, but am unable to access the L2TP tunnel. https://doc.pfsense.org/index.php/L2TP/IPsec

Here is my IPsec log:

Code: [Select]

Sep 30 11:37:17 charon: 14[IKE] deleting IKE_SA con1[29] between yy.yy.yy.yy[yy.yy.yy.yy]...xx.xx.xx.xx[10.131.10.151]
Sep 30 11:37:17 charon: 14[IKE] <con1|29> deleting IKE_SA con1[29] between yy.yy.yy.yy[yy.yy.yy.yy]...xx.xx.xx.xx[10.131.10.151]
Sep 30 11:37:17 charon: 14[IKE] received DELETE for IKE_SA con1[29]
Sep 30 11:37:17 charon: 14[IKE] <con1|29> received DELETE for IKE_SA con1[29]
Sep 30 11:37:17 charon: 14[ENC] parsed INFORMATIONAL_V1 request 3647522843 [ HASH D ]
Sep 30 11:37:17 charon: 14[NET] received packet: from xx.xx.xx.xx[4500] to yy.yy.yy.yy[4500] (92 bytes)
Sep 30 11:37:16 charon: 14[IKE] received retransmit of request with ID 3624973947, but no response to retransmit
Sep 30 11:37:16 charon: 14[IKE] <con1|29> received retransmit of request with ID 3624973947, but no response to retransmit
Sep 30 11:37:16 charon: 14[NET] received packet: from xx.xx.xx.xx[4500] to yy.yy.yy.yy[4500] (316 bytes)
Sep 30 11:37:13 charon: 14[IKE] received retransmit of request with ID 3624973947, but no response to retransmit
Sep 30 11:37:13 charon: 14[IKE] <con1|29> received retransmit of request with ID 3624973947, but no response to retransmit
Sep 30 11:37:13 charon: 14[NET] received packet: from xx.xx.xx.xx[4500] to yy.yy.yy.yy[4500] (316 bytes)
Sep 30 11:37:10 charon: 14[IKE] received retransmit of request with ID 3624973947, but no response to retransmit
Sep 30 11:37:10 charon: 14[IKE] <con1|29> received retransmit of request with ID 3624973947, but no response to retransmit
Sep 30 11:37:10 charon: 14[NET] received packet: from xx.xx.xx.xx[4500] to yy.yy.yy.yy[4500] (316 bytes)
Sep 30 11:37:06 charon: 14[IKE] received retransmit of request with ID 3624973947, but no response to retransmit
Sep 30 11:37:06 charon: 14[IKE] <con1|29> received retransmit of request with ID 3624973947, but no response to retransmit
Sep 30 11:37:06 charon: 14[NET] received packet: from xx.xx.xx.xx[4500] to yy.yy.yy.yy[4500] (316 bytes)
Sep 30 11:37:03 charon: 14[IKE] received retransmit of request with ID 3624973947, but no response to retransmit
Sep 30 11:37:03 charon: 14[IKE] <con1|29> received retransmit of request with ID 3624973947, but no response to retransmit
Sep 30 11:37:03 charon: 14[NET] received packet: from xx.xx.xx.xx[4500] to yy.yy.yy.yy[4500] (316 bytes)
Sep 30 11:37:00 charon: 14[IKE] received retransmit of request with ID 3624973947, but no response to retransmit
Sep 30 11:37:00 charon: 14[IKE] <con1|29> received retransmit of request with ID 3624973947, but no response to retransmit
Sep 30 11:37:00 charon: 14[NET] received packet: from xx.xx.xx.xx[4500] to yy.yy.yy.yy[4500] (316 bytes)
Sep 30 11:36:56 charon: 14[IKE] received retransmit of request with ID 3624973947, but no response to retransmit
Sep 30 11:36:56 charon: 14[IKE] <con1|29> received retransmit of request with ID 3624973947, but no response to retransmit
Sep 30 11:36:56 charon: 14[NET] received packet: from xx.xx.xx.xx[4500] to yy.yy.yy.yy[4500] (316 bytes)
Sep 30 11:36:53 charon: 14[IKE] received retransmit of request with ID 3624973947, but no response to retransmit
Sep 30 11:36:53 charon: 14[IKE] <con1|29> received retransmit of request with ID 3624973947, but no response to retransmit
Sep 30 11:36:53 charon: 14[NET] received packet: from xx.xx.xx.xx[4500] to yy.yy.yy.yy[4500] (316 bytes)
Sep 30 11:36:50 charon: 14[IKE] received retransmit of request with ID 3624973947, but no response to retransmit
Sep 30 11:36:50 charon: 14[IKE] <con1|29> received retransmit of request with ID 3624973947, but no response to retransmit
Sep 30 11:36:50 charon: 14[NET] received packet: from xx.xx.xx.xx[4500] to yy.yy.yy.yy[4500] (316 bytes)
Sep 30 11:36:47 charon: 14[NET] sending packet: from yy.yy.yy.yy[4500] to xx.xx.xx.xx[4500] (76 bytes)
Sep 30 11:36:47 charon: 14[ENC] generating INFORMATIONAL_V1 request 3832143175 [ HASH N(INVAL_ID) ]
Sep 30 11:36:47 charon: 14[IKE] no matching CHILD_SA config found
Sep 30 11:36:47 charon: 14[IKE] <con1|29> no matching CHILD_SA config found
Sep 30 11:36:47 charon: 14[ENC] parsed QUICK_MODE request 3624973947 [ HASH SA No ID ID NAT-OA NAT-OA ]
Sep 30 11:36:47 charon: 14[NET] received packet: from xx.xx.xx.xx[4500] to yy.yy.yy.yy[4500] (316 bytes)
Sep 30 11:36:46 charon: 08[NET] sending packet: from yy.yy.yy.yy[4500] to xx.xx.xx.xx[4500] (76 bytes)
Sep 30 11:36:46 charon: 08[ENC] generating ID_PROT response 0 [ ID HASH ]
Sep 30 11:36:46 charon: 08[IKE] maximum IKE_SA lifetime 28487s
Sep 30 11:36:46 charon: 08[IKE] <con1|29> maximum IKE_SA lifetime 28487s
Sep 30 11:36:46 charon: 08[IKE] scheduling reauthentication in 27947s
Sep 30 11:36:46 charon: 08[IKE] <con1|29> scheduling reauthentication in 27947s
Sep 30 11:36:46 charon: 08[IKE] IKE_SA con1[29] established between yy.yy.yy.yy[yy.yy.yy.yy]...xx.xx.xx.xx[10.131.10.151]
Sep 30 11:36:46 charon: 08[IKE] <con1|29> IKE_SA con1[29] established between yy.yy.yy.yy[yy.yy.yy.yy]...xx.xx.xx.xx[10.131.10.151]
Sep 30 11:36:46 charon: 08[CFG] selected peer config "con1"
Sep 30 11:36:46 charon: 08[CFG] looking for pre-shared key peer configs matching yy.yy.yy.yy...xx.xx.xx.xx[10.131.10.151]
Sep 30 11:36:46 charon: 08[ENC] parsed ID_PROT request 0 [ ID HASH N(INITIAL_CONTACT) ]

And here is the client log:

Code: [Select]

Sep 30 12:15:17 abel pppd[37251]: IPSec connection started
Sep 30 12:15:17 abel racoon[37252]: accepted connection on vpn control socket.
Sep 30 12:15:17 --- last message repeated 1 time ---
Sep 30 12:15:17 abel racoon[37252]: Connecting.
Sep 30 12:15:17 abel racoon[37252]: IPSec Phase 1 started (Initiated by me).
Sep 30 12:15:17 --- last message repeated 1 time ---
Sep 30 12:15:17 abel racoon[37252]: IKE Packet: transmit success. (Initiator, Main-Mode message 1).
Sep 30 12:15:17 abel racoon[37252]: >>>>> phase change status = Phase 1 started by us
Sep 30 12:15:18 --- last message repeated 1 time ---
Sep 30 12:15:18 abel racoon[37252]: >>>>> phase change status = Phase 1 started by peer
Sep 30 12:15:18 --- last message repeated 1 time ---
Sep 30 12:15:18 abel racoon[37252]: IKE Packet: receive success. (Initiator, Main-Mode message 2).
Sep 30 12:15:18 abel racoon[37252]: IKE Packet: transmit success. (Initiator, Main-Mode message 3).
Sep 30 12:15:18 abel racoon[37252]: IKE Packet: receive success. (Initiator, Main-Mode message 4).
Sep 30 12:15:18 abel racoon[37252]: IKE Packet: transmit success. (Initiator, Main-Mode message 5).
Sep 30 12:15:18 abel racoon[37252]: IKEv1 Phase 1 AUTH: success. (Initiator, Main-Mode Message 6).
Sep 30 12:15:18 abel racoon[37252]: IKE Packet: receive success. (Initiator, Main-Mode message 6).
Sep 30 12:15:18 abel racoon[37252]: IKEv1 Phase 1 Initiator: success. (Initiator, Main-Mode).
Sep 30 12:15:18 abel racoon[37252]: IPSec Phase 1 established (Initiated by me).
Sep 30 12:15:18 --- last message repeated 1 time ---
Sep 30 12:15:18 abel racoon[37252]: IPSec Phase 2 started (Initiated by me).
Sep 30 12:15:18 --- last message repeated 1 time ---
Sep 30 12:15:18 abel racoon[37252]: >>>>> phase change status = Phase 2 started
Sep 30 12:15:18 --- last message repeated 1 time ---
Sep 30 12:15:18 abel racoon[37252]: IKE Packet: transmit success. (Initiator, Quick-Mode message 1).
Sep 30 12:15:19 abel racoon[37252]: Fatal INVALID-ID-INFORMATION notify messsage, Phase 1 should be deleted.
From what I've been reading, these errors would indicate that my identifiers don't match. I have my_identifier set to "My IP Address" and I think that is correct. Any where else I should be looking?

Title: Re: L2TP/IPsec issues with PSK
Post by: AdSchellevis on September 30, 2016, 06:49:23 pm

Hi abel408,

"no matching CHILD_SA config found" would suggest a mismatch in the phase 2 networks on both ends, could be a typo.

Best regards,

Ad

Title: Re: L2TP/IPsec issues with PSK
Post by: franco on October 01, 2016, 02:02:02 pm

I've seen that strongswan sometimes ignores the config settings in IKEv1, the support has been added not too long ago after IKEv2 was already working so there could be bugs that I don't know how to work around other than fixing up the other side's proposal.

Title: Re: L2TP/IPsec issues with PSK
Post by: abel408 on October 03, 2016, 06:19:52 pm

Quote from: franco on October 01, 2016, 02:02:02 pm

I've seen that strongswan sometimes ignores the config settings in IKEv1, the support has been added not too long ago after IKEv2 was already working so there could be bugs that I don't know how to work around other than fixing up the other side's proposal.

I was able to fix the "no matching CHILD_SA config found" error by removing the "Virtual Address Pool" in Mobile Client settings. I am now getting the following logs on my client:

Code: [Select]

Oct  3 12:01:20 abel pppd[43317]: l2tp_get_router_address
Oct  3 12:01:20 abel pppd[43317]: l2tp_get_router_address 192.168.43.1 from dict 1
Oct  3 12:01:20 abel pppd[43317]: L2TP connecting to server 'xx.xx.xx.xx' (xx.xx.xx.xx)...
Oct  3 12:01:20 abel pppd[43317]: IPSec connection started
Oct  3 12:01:20 abel racoon[43318]: accepted connection on vpn control socket.
Oct  3 12:01:20 --- last message repeated 1 time ---
Oct  3 12:01:20 abel racoon[43318]: Connecting.
Oct  3 12:01:20 abel racoon[43318]: IPSec Phase 1 started (Initiated by me).
Oct  3 12:01:20 --- last message repeated 1 time ---
Oct  3 12:01:20 abel racoon[43318]: IKE Packet: transmit success. (Initiator, Main-Mode message 1).
Oct  3 12:01:20 abel racoon[43318]: >>>>> phase change status = Phase 1 started by us
Oct  3 12:01:20 --- last message repeated 1 time ---
Oct  3 12:01:20 abel racoon[43318]: >>>>> phase change status = Phase 1 started by peer
Oct  3 12:01:20 --- last message repeated 1 time ---
Oct  3 12:01:20 abel racoon[43318]: IKE Packet: receive success. (Initiator, Main-Mode message 2).
Oct  3 12:01:20 abel racoon[43318]: IKE Packet: transmit success. (Initiator, Main-Mode message 3).
Oct  3 12:01:20 abel racoon[43318]: IKE Packet: receive success. (Initiator, Main-Mode message 4).
Oct  3 12:01:20 abel racoon[43318]: IKE Packet: transmit success. (Initiator, Main-Mode message 5).
Oct  3 12:01:21 abel racoon[43318]: IKEv1 Phase 1 AUTH: success. (Initiator, Main-Mode Message 6).
Oct  3 12:01:21 abel racoon[43318]: IKE Packet: receive success. (Initiator, Main-Mode message 6).
Oct  3 12:01:21 abel racoon[43318]: IKEv1 Phase 1 Initiator: success. (Initiator, Main-Mode).
Oct  3 12:01:21 abel racoon[43318]: IPSec Phase 1 established (Initiated by me).
Oct  3 12:01:21 --- last message repeated 1 time ---
Oct  3 12:01:21 abel racoon[43318]: IPSec Phase 2 started (Initiated by me).
Oct  3 12:01:21 --- last message repeated 1 time ---
Oct  3 12:01:21 abel racoon[43318]: >>>>> phase change status = Phase 2 started
Oct  3 12:01:21 --- last message repeated 1 time ---
Oct  3 12:01:21 abel racoon[43318]: IKE Packet: transmit success. (Initiator, Quick-Mode message 1).
Oct  3 12:01:21 abel racoon[43318]: mismatched ID was returned - ignored because nat traversal is being used.
Oct  3 12:01:21 --- last message repeated 1 time ---
Oct  3 12:01:21 abel racoon[43318]: attribute has been modified.
Oct  3 12:01:21 --- last message repeated 1 time ---
Oct  3 12:01:21 abel racoon[43318]: IKE Packet: receive success. (Initiator, Quick-Mode message 2).
Oct  3 12:01:21 abel racoon[43318]: IKE Packet: transmit success. (Initiator, Quick-Mode message 3).
Oct  3 12:01:21 abel racoon[43318]: IKEv1 Phase 2 Initiator: success. (Initiator, Quick-Mode).
Oct  3 12:01:21 abel racoon[43318]: IPSec Phase 2 established (Initiated by me).
Oct  3 12:01:21 --- last message repeated 1 time ---
Oct  3 12:01:21 abel racoon[43318]: >>>>> phase change status = Phase 2 established
Oct  3 12:01:21 --- last message repeated 1 time ---
Oct  3 12:01:21 abel pppd[43317]: IPSec connection established
Oct  3 12:01:41 abel pppd[43317]: L2TP cannot connect to the server
Oct  3 12:01:41 abel racoon[43318]: IPSec disconnecting from server xx.xx.xx.xx
Oct  3 12:01:41 abel racoon[43318]: IPSec disconnecting from server xx.xx.xx.xx
Oct  3 12:01:41 abel racoon[43318]: IKE Packet: transmit success. (Information message).
Oct  3 12:01:41 abel racoon[43318]: IKEv1 Information-Notice: transmit success. (Delete IPSEC-SA).
Oct  3 12:01:41 abel racoon[43318]: IKE Packet: transmit success. (Information message).
Oct  3 12:01:41 abel racoon[43318]: IKEv1 Information-Notice: transmit success. (Delete ISAKMP-SA).
Oct  3 12:01:41 abel racoon[43318]: glob found no matches for path "/var/run/racoon/*.conf"
Oct  3 12:01:41 abel racoon[43318]: pfkey DELETE failed: No such file or directory

And this is what the server IPsec logs show:

Code: [Select]

Oct 3 11:48:59 charon: 06[IKE] deleting IKE_SA con1[6] between xx.xx.xx.xx[xx.xx.xx.xx]...yy.yy.yy.yy[192.168.43.112]
Oct 3 11:48:59 charon: 06[IKE] <con1|6> deleting IKE_SA con1[6] between xx.xx.xx.xx[xx.xx.xx.xx]...yy.yy.yy.yy[192.168.43.112]
Oct 3 11:48:59 charon: 06[IKE] received DELETE for IKE_SA con1[6]
Oct 3 11:48:59 charon: 06[IKE] <con1|6> received DELETE for IKE_SA con1[6]
Oct 3 11:48:59 charon: 06[ENC] parsed INFORMATIONAL_V1 request 2309233223 [ HASH D ]
Oct 3 11:48:59 charon: 06[NET] received packet: from yy.yy.yy.yy[25227] to xx.xx.xx.xx[4500] (92 bytes)
Oct 3 11:48:59 charon: 13[IKE] closing CHILD_SA con1{3} with SPIs cb00628b_i (742 bytes) 0610a9df_o (0 bytes) and TS xx.xx.xx.xx/32[udp/l2f] === yy.yy.yy.yy/32[udp/56255]
Oct 3 11:48:59 charon: 13[IKE] <con1|6> closing CHILD_SA con1{3} with SPIs cb00628b_i (742 bytes) 0610a9df_o (0 bytes) and TS xx.xx.xx.xx/32[udp/l2f] === yy.yy.yy.yy/32[udp/56255]
Oct 3 11:48:59 charon: 13[IKE] received DELETE for ESP CHILD_SA with SPI 0610a9df
Oct 3 11:48:59 charon: 13[IKE] <con1|6> received DELETE for ESP CHILD_SA with SPI 0610a9df
Oct 3 11:48:59 charon: 13[ENC] parsed INFORMATIONAL_V1 request 3244411409 [ HASH D ]
Oct 3 11:48:59 charon: 13[NET] received packet: from yy.yy.yy.yy[25227] to xx.xx.xx.xx[4500] (76 bytes)
Oct 3 11:48:39 charon: 13[IKE] CHILD_SA con1{3} established with SPIs cb00628b_i 0610a9df_o and TS xx.xx.xx.xx/32[udp/l2f] === yy.yy.yy.yy/32[udp/56255]
Oct 3 11:48:39 charon: 13[IKE] <con1|6> CHILD_SA con1{3} established with SPIs cb00628b_i 0610a9df_o and TS xx.xx.xx.xx/32[udp/l2f] === yy.yy.yy.yy/32[udp/56255]
Oct 3 11:48:39 charon: 13[ENC] parsed QUICK_MODE request 2690594180 [ HASH ]
Oct 3 11:48:39 charon: 13[NET] received packet: from yy.yy.yy.yy[25227] to xx.xx.xx.xx[4500] (60 bytes)
Oct 3 11:48:39 charon: 13[NET] sending packet: from xx.xx.xx.xx[4500] to yy.yy.yy.yy[25227] (204 bytes)
Oct 3 11:48:39 charon: 13[ENC] generating QUICK_MODE response 2690594180 [ HASH SA No ID ID NAT-OA NAT-OA ]
Oct 3 11:48:39 charon: 13[ENC] parsed QUICK_MODE request 2690594180 [ HASH SA No ID ID NAT-OA NAT-OA ]
Oct 3 11:48:39 charon: 13[NET] received packet: from yy.yy.yy.yy[25227] to xx.xx.xx.xx[4500] (316 bytes)
Oct 3 11:48:38 charon: 09[NET] sending packet: from xx.xx.xx.xx[4500] to yy.yy.yy.yy[25227] (76 bytes)
Oct 3 11:48:38 charon: 09[ENC] generating ID_PROT response 0 [ ID HASH ]
Oct 3 11:48:38 charon: 09[IKE] maximum IKE_SA lifetime 28306s
Oct 3 11:48:38 charon: 09[IKE] <con1|6> maximum IKE_SA lifetime 28306s
Oct 3 11:48:38 charon: 09[IKE] scheduling reauthentication in 27766s
Oct 3 11:48:38 charon: 09[IKE] <con1|6> scheduling reauthentication in 27766s
Oct 3 11:48:38 charon: 09[IKE] IKE_SA con1[6] established between xx.xx.xx.xx[xx.xx.xx.xx]...yy.yy.yy.yy[192.168.43.112]
Oct 3 11:48:38 charon: 09[IKE] <con1|6> IKE_SA con1[6] established between xx.xx.xx.xx[xx.xx.xx.xx]...yy.yy.yy.yy[192.168.43.112]
Oct 3 11:48:38 charon: 09[CFG] selected peer config "con1"
Oct 3 11:48:38 charon: 09[CFG] looking for pre-shared key peer configs matching xx.xx.xx.xx...yy.yy.yy.yy[192.168.43.112]
Oct 3 11:48:38 charon: 09[ENC] parsed ID_PROT request 0 [ ID HASH N(INITIAL_CONTACT) ]
Oct 3 11:48:38 charon: 09[NET] received packet: from yy.yy.yy.yy[25227] to xx.xx.xx.xx[4500] (108 bytes)
Oct 3 11:48:38 charon: 09[NET] sending packet: from xx.xx.xx.xx[500] to yy.yy.yy.yy[59767] (244 bytes)
Oct 3 11:48:38 charon: 09[ENC] generating ID_PROT response 0 [ KE No NAT-D NAT-D ]
Oct 3 11:48:38 charon: 09[IKE] remote host is behind NAT
Oct 3 11:48:38 charon: 09[IKE] <6> remote host is behind NAT
Oct 3 11:48:38 charon: 09[ENC] parsed ID_PROT request 0 [ KE No NAT-D NAT-D ]
Oct 3 11:48:38 charon: 09[NET] received packet: from yy.yy.yy.yy[59767] to xx.xx.xx.xx[500] (228 bytes)
Oct 3 11:48:38 charon: 09[NET] sending packet: from xx.xx.xx.xx[500] to yy.yy.yy.yy[59767] (160 bytes)
Oct 3 11:48:38 charon: 09[ENC] generating ID_PROT response 0 [ SA V V V V ]
Oct 3 11:48:38 charon: 09[IKE] yy.yy.yy.yy is initiating a Main Mode IKE_SA
Oct 3 11:48:38 charon: 09[IKE] <6> yy.yy.yy.yy is initiating a Main Mode IKE_SA
Oct 3 11:48:38 charon: 09[IKE] received DPD vendor ID
Oct 3 11:48:38 charon: 09[IKE] <6> received DPD vendor ID
Oct 3 11:48:38 charon: 09[IKE] received FRAGMENTATION vendor ID
Oct 3 11:48:38 charon: 09[IKE] <6> received FRAGMENTATION vendor ID
Oct 3 11:48:38 charon: 09[IKE] received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Oct 3 11:48:38 charon: 09[IKE] <6> received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Oct 3 11:48:38 charon: 09[IKE] received draft-ietf-ipsec-nat-t-ike-02 vendor ID
Oct 3 11:48:38 charon: 09[IKE] <6> received draft-ietf-ipsec-nat-t-ike-02 vendor ID
My L2TP log file looks like this:

Code: [Select]

Oct 3 12:05:15 l2tps: L2TP: bind: Can't assign requested address
Oct 3 12:05:15 l2tps: process 15848 started, version 5.8 (root@sensey64 06:47 23-Mar-2016)
Oct 3 12:05:15 l2tps:
Oct 3 12:05:15 l2tps: Multi-link PPP daemon for FreeBSD

I think I'm pretty close. Does this seem like a NAT issue? Seems odd that the L2TP server sees the remote and local address of the client. Also, why am I getting the following log in L2tp? "L2TP: bind: Can't assign requested address".

Title: Re: L2TP/IPsec issues with PSK
Post by: franco on October 04, 2016, 07:20:02 pm

Hi there,

That's not good at all... L2TP doesn't listen to requests, so maybe that's what you're seeing now.

MPD4 was replaced by MPD5 in 16.7, which came with the restriction of your server IP needing to be a real IP on your OPNsense. You can either use the real interface address, or add a virtual address to the interface.

Hope this helps.


Cheers,
Franco

Title: Re: L2TP/IPsec issues with PSK
Post by: le-luetz on November 19, 2016, 10:32:51 pm

hi there.

struggling around with the same configuration (l2tp/ipsec) for the last three days now. didn't get it working al least with any other interface than the WAN. but want to use an ip of the lan respectively an virtual ip assigned to it. for my understanding this should make the internal communication easier.
the binding to the virtual configured interface seems to work, the l2tp log is:

Code: [Select]

l2tps: L2TP: waiting for connection on 10.128.10.240 1701

but the nativ osx-client ist saying:

Code: [Select]

...
L2TP sent SCCRQ
L2TP cannot connect to the server

there are no corresponding entries in the log of the firewall.

the virtual ip is assigned to the lan interface. however even if i take an existing ip of the lan interface this does not succeed.

opnsense is up to date, 16.7.8

any help is appreciated.

best regards,
lutz.