Help with debugging a routed IPSec connection between pfSense 2.5.1 (physical) and pfSense 2.5.1 (Azure VM)
-
Hi,
I'm attempting to setup a routed IPSec connection between my home network and MS Azure test lab following the Netgate guidance.The home device is a Qotom 6-port i5 running pfSense CE 2.5.1, and the remote device is an Azure VM, also running pfSense CE2.5.1. Both devices have been operating stably for 2-3 months and I've recently upgraded to 2.5.1.
From what I can see in the logs, I don't think the P1 connection is being established, so looking for some pointers on what to try next.
Here's a high-level network diagram:
I have previously successfully tested S2S WireGuard connections with pfSense CE 2.5. I know that WireGuard and IPSec aren't exactly apples-to-apples but I'm at least confident that the Azure configuration is passing traffic between VNICs/Subnets and that NAT from the WAN VNIC to the public IP is being handled.
Here's the IPSec connection configuration. Anything not included below has been left at its default setting and is identical on both sides:
Each side has an auto-created gateway, and I've created static routes and firewall rules on the IPSec interface:
Here's an extract of what I think is the relevant section of the IPSec log file. This is from the Azure side attempting to connect. The log entries from the home side are functionally identical, but I don't think I can see anything to indicate that it's a two-way conversation at any point!
I can add more detail or upload log files if needed:
Apr 23 15:32:16 charon 6675 08[CFG] proposals = ESP:AES_GCM_16_128/MODP_2048/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ Apr 23 15:32:16 charon 6675 08[CFG] local_ts = 10.100.100.1/32|/0 0.0.0.0/0|/0 Apr 23 15:32:16 charon 6675 08[CFG] remote_ts = 10.100.100.2/32|/0 0.0.0.0/0|/0 Apr 23 15:32:16 charon 6675 08[CFG] hw_offload = no Apr 23 15:32:16 charon 6675 08[CFG] sha256_96 = 0 Apr 23 15:32:16 charon 6675 08[CFG] copy_df = 1 Apr 23 15:32:16 charon 6675 08[CFG] copy_ecn = 1 Apr 23 15:32:16 charon 6675 08[CFG] copy_dscp = out Apr 23 15:32:16 charon 6675 08[CFG] version = 2 Apr 23 15:32:16 charon 6675 08[CFG] local_addrs = 10.20.23.10 Apr 23 15:32:16 charon 6675 08[CFG] remote_addrs = X.X.34.157 Apr 23 15:32:16 charon 6675 08[CFG] local_port = 500 Apr 23 15:32:16 charon 6675 08[CFG] remote_port = 500 Apr 23 15:32:16 charon 6675 08[CFG] send_certreq = 1 Apr 23 15:32:16 charon 6675 08[CFG] send_cert = CERT_SEND_IF_ASKED Apr 23 15:32:16 charon 6675 08[CFG] ppk_id = (null) Apr 23 15:32:16 charon 6675 08[CFG] ppk_required = 0 Apr 23 15:32:16 charon 6675 08[CFG] mobike = 0 Apr 23 15:32:16 charon 6675 08[CFG] aggressive = 0 Apr 23 15:32:16 charon 6675 08[CFG] dscp = 0x00 Apr 23 15:32:16 charon 6675 08[CFG] encap = 0 Apr 23 15:32:16 charon 6675 08[CFG] dpd_delay = 10 Apr 23 15:32:16 charon 6675 08[CFG] dpd_timeout = 60 Apr 23 15:32:16 charon 6675 08[CFG] fragmentation = 2 Apr 23 15:32:16 charon 6675 08[CFG] childless = 0 Apr 23 15:32:16 charon 6675 08[CFG] unique = UNIQUE_REPLACE Apr 23 15:32:16 charon 6675 08[CFG] keyingtries = 1 Apr 23 15:32:16 charon 6675 08[CFG] reauth_time = 0 Apr 23 15:32:16 charon 6675 08[CFG] rekey_time = 25920 Apr 23 15:32:16 charon 6675 08[CFG] over_time = 2880 Apr 23 15:32:16 charon 6675 08[CFG] rand_time = 2880 Apr 23 15:32:16 charon 6675 08[CFG] proposals = IKE:AES_GCM_16_128/PRF_AES128_XCBC/MODP_2048 Apr 23 15:32:16 charon 6675 08[CFG] if_id_in = 0 Apr 23 15:32:16 charon 6675 08[CFG] if_id_out = 0 Apr 23 15:32:16 charon 6675 08[CFG] local: Apr 23 15:32:16 charon 6675 08[CFG] class = pre-shared key Apr 23 15:32:16 charon 6675 08[CFG] id = fwlab-ipsec-001 Apr 23 15:32:16 charon 6675 08[CFG] remote: Apr 23 15:32:16 charon 6675 08[CFG] class = pre-shared key Apr 23 15:32:16 charon 6675 08[CFG] id = home-ipsec-001 Apr 23 15:32:16 charon 6675 08[CFG] added vici connection: con1000 Apr 23 15:32:16 charon 6675 08[CFG] initiating 'con1000' Apr 23 15:32:16 charon 6675 08[IKE] <con1000|1> queueing IKE_VENDOR task Apr 23 15:32:16 charon 6675 08[IKE] <con1000|1> queueing IKE_INIT task Apr 23 15:32:16 charon 6675 08[IKE] <con1000|1> queueing IKE_NATD task Apr 23 15:32:16 charon 6675 08[IKE] <con1000|1> queueing IKE_CERT_PRE task Apr 23 15:32:16 charon 6675 08[IKE] <con1000|1> queueing IKE_AUTH task Apr 23 15:32:16 charon 6675 08[IKE] <con1000|1> queueing IKE_CERT_POST task Apr 23 15:32:16 charon 6675 08[IKE] <con1000|1> queueing IKE_CONFIG task Apr 23 15:32:16 charon 6675 08[IKE] <con1000|1> queueing IKE_AUTH_LIFETIME task Apr 23 15:32:16 charon 6675 08[IKE] <con1000|1> queueing CHILD_CREATE task Apr 23 15:32:16 charon 6675 08[IKE] <con1000|1> activating new tasks Apr 23 15:32:16 charon 6675 08[IKE] <con1000|1> activating IKE_VENDOR task Apr 23 15:32:16 charon 6675 08[IKE] <con1000|1> activating IKE_INIT task Apr 23 15:32:16 charon 6675 08[IKE] <con1000|1> activating IKE_NATD task Apr 23 15:32:16 charon 6675 08[IKE] <con1000|1> activating IKE_CERT_PRE task Apr 23 15:32:16 charon 6675 08[IKE] <con1000|1> activating IKE_AUTH task Apr 23 15:32:16 charon 6675 08[IKE] <con1000|1> activating IKE_CERT_POST task Apr 23 15:32:16 charon 6675 08[IKE] <con1000|1> activating IKE_CONFIG task Apr 23 15:32:16 charon 6675 08[IKE] <con1000|1> activating CHILD_CREATE task Apr 23 15:32:16 charon 6675 08[IKE] <con1000|1> activating IKE_AUTH_LIFETIME task Apr 23 15:32:16 charon 6675 08[IKE] <con1000|1> initiating IKE_SA con1000[1] to X.X.34.157 Apr 23 15:32:16 charon 6675 08[IKE] <con1000|1> IKE_SA con1000[1] state change: CREATED => CONNECTING Apr 23 15:32:16 charon 6675 08[CFG] <con1000|1> configured proposals: IKE:AES_GCM_16_128/PRF_AES128_XCBC/MODP_2048 Apr 23 15:32:16 charon 6675 08[CFG] <con1000|1> sending supported signature hash algorithms: sha256 sha384 sha512 identity Apr 23 15:32:16 charon 6675 08[ENC] <con1000|1> generating IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(FRAG_SUP) N(HASH_ALG) N(REDIR_SUP) ] Apr 23 15:32:16 charon 6675 08[NET] <con1000|1> sending packet: from 10.20.23.10[500] to X.X.34.157[500] (456 bytes) Apr 23 15:32:16 charon 6675 09[CFG] vici client 1 disconnected Apr 23 15:32:20 charon 6675 09[IKE] <con1000|1> retransmit 1 of request with message ID 0 Apr 23 15:32:20 charon 6675 09[NET] <con1000|1> sending packet: from 10.20.23.10[500] to X.X.34.157[500] (456 bytes) Apr 23 15:32:20 charon 6675 09[KNL] creating acquire job for policy 10.20.23.10/32|/0 === X.X.34.157/32|/0 with reqid {1000} Apr 23 15:32:20 charon 6675 09[CFG] trap not found, unable to acquire reqid 1000 Apr 23 15:32:26 charon 6675 08[KNL] creating acquire job for policy 10.20.23.10/32|/0 === X.X.34.157/32|/0 with reqid {1000} Apr 23 15:32:26 charon 6675 08[CFG] trap not found, unable to acquire reqid 1000 Apr 23 15:32:27 charon 6675 09[IKE] <con1000|1> retransmit 2 of request with message ID 0 Apr 23 15:32:27 charon 6675 09[NET] <con1000|1> sending packet: from 10.20.23.10[500] to X.X.34.157[500] (456 bytes) Apr 23 15:32:30 charon 6675 08[CFG] vici client 2 connected Apr 23 15:32:30 charon 6675 08[CFG] vici client 2 registered for: list-sa Apr 23 15:32:30 charon 6675 05[CFG] vici client 2 requests: list-sas Apr 23 15:32:30 charon 6675 05[CFG] vici client 2 disconnected Apr 23 15:32:33 charon 6675 05[KNL] creating acquire job for policy 10.20.23.10/32|/0 === X.X.34.157/32|/0 with reqid {1000} Apr 23 15:32:33 charon 6675 08[CFG] trap not found, unable to acquire reqid 1000 Apr 23 15:32:35 charon 6675 05[CFG] vici client 3 connected Apr 23 15:32:35 charon 6675 08[CFG] vici client 3 registered for: list-sa Apr 23 15:32:35 charon 6675 05[CFG] vici client 3 requests: list-sas Apr 23 15:32:35 charon 6675 08[CFG] vici client 3 disconnected Apr 23 15:32:39 charon 6675 08[KNL] creating acquire job for policy 10.20.23.10/32|/0 === X.X.34.157/32|/0 with reqid {1000} Apr 23 15:32:39 charon 6675 05[CFG] trap not found, unable to acquire reqid 1000
Then follows another 3 retransmit attempts before the connection attempt fails
I'm not sure what to try next, but any suggestions are appreciated.Cheers
-
@captaincathode I do not have experience of your configuration, but I do have experience of pfSense/IPSec <-> Azure VPN gateway. In that configuration, the P2 remote network is specified as a subnet, not a single host. At the Azure end, the remote network subnet is also specified. So I wonder if this might be your issue, as you appear to be specifying single host IP addresses? (although this might be how a pfSense<->pfSense tunnel needs to be configured).
I also do not need to add any static routing to make my pfSense<->Azure tunnel work.
-
Thanks @rolytheflycatcher
I've now got this working - the culprit was a misconfiguration in an Azure routing table for one of the subnets within the Azure vnet.To your routing point, I've setup an Azure VPN gateway in the past (although not connected to pfSense), but the recipe is a little different.
For this connection I've been following Netgate's guidance on routed (VTI) IPSec connections, where a routing entry is needed. In my case
a simple static route at each pfSense instance connects both my networks, but you can also use OSPF or BGP. -
Now resolved - a misconfigured Azure routing table was blocking the connection.