IPsec VPN tunnel to a Fritzbox after update to 2.4.4-p1
-
Hi,
For years my VPN connection between my pfSense router and a Fritzbox worked without a problem. After the upgrade to version 2.4.4-p1, pfSense shows the tunnel as inactive after some time, even though the Fritzbox on the other side still shows the connection as active but no routing between the two netwoks is possible.
Anyone else experiencing the same issue?
Martin
-
Hi,
I just had the same problem on multiple Fritzboxes in ike1 main mode after upgrading to 2.4.4-p1. Enabling "Disables renegotiation when a connection is about to expire." in ipsec phase1 settings on pfsense side solved the problem for now (tunnel Uptime >60 minutes), but more observation in the next days is needed...
Christoph
-
Hi,
This change did little to me. Tunnel went down after after some minutes again but I after unchecking "Dead Peer Detection" in phase1, the connection is holding.
I agree, more observation in the next days is needed...
Martin
-
Hi,
Update: So far, any additional tinkering with the settings on both ends (pfsense and Fritzbox) have not shown any improvements yet and resulted always to the same status that the Fritzbox shows the tunnel as alive but no traffic passes thru and the pfsense box shows the tunnel as inactive.
Anyone else with the same problem? Any other suggestions?
Martin
-
Same here (pfSense 2.4.4-p1 with 6490 cable) and no answer!
@kuschi: could you add "after update to 2.4.4-p1" to the thread title, please? IMHO all Fritzbox-Users should have the same problem right now...
-
Have to see the FULL IPsec logs from pfSense from the time the tunnel disconnects to be able to have any hope of making a determination.
That will show who is requesting the tunnel be destroyed, and what the result was.
Disabling re-key should never be required.
-
I hope I got the right passage:
Dec 17 09:13:35 charon 04[IKE] <con1000|475> activating new tasks
Dec 17 09:13:34 charon 04[IKE] <con1000|475> IKE_SA con1000[475] state change: CONNECTING => CREATED
Dec 17 09:13:34 charon 04[IKE] <con1000|475> peer not responding, trying again (3/3)
Dec 17 09:13:34 charon 04[IKE] <con1000|475> giving up after 5 retransmits
Dec 17 09:12:29 charon 04[CFG] ignoring acquire, connection attempt pending
Dec 17 09:12:29 charon 11[KNL] creating acquire job for policy 192.10.10.2/32|/0 === 86.118.66.38/32|/0 with reqid {5}
Dec 17 09:12:19 charon 11[NET] <con1000|475> sending packet: from 192.10.10.2[500] to 86.118.66.38[500] (176 bytes)
Dec 17 09:12:19 charon 11[IKE] <con1000|475> sending retransmit 5 of request message ID 0, seq 1
Dec 17 09:11:37 charon 11[NET] <con1000|475> sending packet: from 192.10.10.2[500] to 86.118.66.38[500] (176 bytes)
Dec 17 09:11:37 charon 11[IKE] <con1000|475> sending retransmit 4 of request message ID 0, seq 1
Dec 17 09:11:14 charon 11[NET] <con1000|475> sending packet: from 192.10.10.22[500] to 86.118.66.388[500] (176 bytes)
Dec 17 09:11:14 charon 11[IKE] <con1000|475> sending retransmit 3 of request message ID 0, seq 1
Dec 17 09:11:01 charon 11[NET] <con1000|475> sending packet: from 192.10.10.2[500] to 886.118.66.38[500] (176 bytes)
Dec 17 09:11:01 charon 11[IKE] <con1000|475> sending retransmit 2 of request message ID 0, seq 1
Dec 17 09:10:53 charon 11[NET] <con1000|475> sending packet: from 192.10.10.2[500] to 86.118.66.38[500] (176 bytes)
Dec 17 09:10:53 charon 11[IKE] <con1000|475> sending retransmit 1 of request message ID 0, seq 1
Dec 17 09:10:49 charon 11[NET] <con1000|475> sending packet: from 192.10.10.2[500] to 86.118.66.388[500] (176 bytes)
Dec 17 09:10:49 charon 11[ENC] <con1000|475> generating ID_PROT request 0 [ SA V V V V V ]
Dec 17 09:10:49 charon 11[CFG] <con1000|475> configured proposals: IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_768
Dec 17 09:10:49 charon 11[IKE] <con1000|475> IKE_SA con1000[475] state change: CREATED => CONNECTING
Dec 17 09:10:49 charon 11[IKE] <con1000|475> initiating Main Mode IKE_SA con1000[475] to 86.118.66.38
Dec 17 09:10:49 charon 11[IKE] <con1000|475> sending draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Dec 17 09:10:49 charon 11[IKE] <con1000|475> sending NAT-T (RFC 3947) vendor ID
Dec 17 09:10:49 charon 11[IKE] <con1000|475> sending FRAGMENTATION vendor ID -
@commwest Done. I hope it worked :-)
-
OK so that is pfSense trying to reconnect and the other side is not responding.
We'll need to see the point the tunnel is taken down. You can probably find the approximate time by searching for DESTROYED.
-
Dec 17 18:06:25 charon 07[NET] <con1000|549> sending packet: from 10.14.113.1[500] to 82.117.73.44[500] (176 bytes)
Dec 17 18:06:25 charon 07[IKE] <con1000|549> sending retransmit 2 of request message ID 0, seq 1
Dec 17 18:06:18 charon 07[NET] <con1000|549> sending packet: from 10.14.113.1[500] to 82.117.73.44[500] (176 bytes)
Dec 17 18:06:18 charon 07[IKE] <con1000|549> sending retransmit 1 of request message ID 0, seq 1
Dec 17 18:06:14 charon 07[NET] <con1000|549> sending packet: from 10.14.113.1[500] to 82.117.73.44[500] (176 bytes)
Dec 17 18:06:14 charon 07[ENC] <con1000|549> generating ID_PROT request 0 [ SA V V V V V ]
Dec 17 18:06:14 charon 07[CFG] <con1000|549> configured proposals: IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_768
Dec 17 18:06:14 charon 07[IKE] <con1000|549> IKE_SA con1000[549] state change: CREATED => CONNECTING
Dec 17 18:06:14 charon 07[IKE] <con1000|549> initiating Main Mode IKE_SA con1000[549] to 82.117.73.44
Dec 17 18:06:14 charon 07[IKE] <con1000|549> sending draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Dec 17 18:06:14 charon 07[IKE] <con1000|549> sending NAT-T (RFC 3947) vendor ID
Dec 17 18:06:14 charon 07[IKE] <con1000|549> sending FRAGMENTATION vendor ID
Dec 17 18:06:14 charon 07[IKE] <con1000|549> sending DPD vendor ID
Dec 17 18:06:14 charon 07[IKE] <con1000|549> sending XAuth vendor ID
Dec 17 18:06:14 charon 07[IKE] <con1000|549> activating ISAKMP_NATD task
Dec 17 18:06:14 charon 07[IKE] <con1000|549> activating ISAKMP_CERT_POST task
Dec 17 18:06:14 charon 07[IKE] <con1000|549> activating MAIN_MODE task
Dec 17 18:06:14 charon 07[IKE] <con1000|549> activating ISAKMP_CERT_PRE task
Dec 17 18:06:14 charon 07[IKE] <con1000|549> activating ISAKMP_VENDOR task
Dec 17 18:06:14 charon 07[IKE] <con1000|549> activating new tasks
Dec 17 18:06:14 charon 07[IKE] <con1000|549> queueing QUICK_MODE task
Dec 17 18:06:14 charon 07[IKE] <con1000|549> queueing ISAKMP_NATD task
Dec 17 18:06:14 charon 07[IKE] <con1000|549> queueing ISAKMP_CERT_POST task
Dec 17 18:06:14 charon 07[IKE] <con1000|549> queueing MAIN_MODE task
Dec 17 18:06:14 charon 07[IKE] <con1000|549> queueing ISAKMP_CERT_PRE task
Dec 17 18:06:14 charon 07[IKE] <con1000|549> queueing ISAKMP_VENDOR task
Dec 17 18:06:14 charon 10[KNL] creating acquire job for policy 10.14.113.1/32|/0 === 82.117.73.44/32|/0 with reqid {5}
Dec 17 18:05:39 charon 10[IKE] <con1000|548> IKE_SA con1000[548] state change: CONNECTING => DESTROYING
Dec 17 18:05:39 charon 10[IKE] <con1000|548> establishing IKE_SA failed, peer not responding
Dec 17 18:05:39 charon 10[IKE] <con1000|548> giving up after 5 retransmits
Dec 17 18:04:24 charon 10[NET] <con1000|548> sending packet: from 10.14.113.1[500] to 82.117.73.44[500] (176 bytes)
Dec 17 18:04:24 charon 10[IKE] <con1000|548> sending retransmit 5 of request message ID 0, seq 1
Dec 17 18:03:42 charon 10[NET] <con1000|548> sending packet: from 10.14.113.1[500] to 82.117.73.44[500] (176 bytes)
Dec 17 18:03:42 charon 10[IKE] <con1000|548> sending retransmit 4 of request message ID 0, seq 1
Dec 17 18:03:18 charon 10[NET] <con1000|548> sending packet: from 10.14.113.1[500] to 82.117.73.44[500] (176 bytes)
Dec 17 18:03:18 charon 10[IKE] <con1000|548> sending retransmit 3 of request message ID 0, seq 1
Dec 17 18:03:05 charon 10[NET] <con1000|548> sending packet: from 10.14.113.1[500] to 82.117.73.44[500] (176 bytes)
Dec 17 18:03:05 charon 10[IKE] <con1000|548> sending retransmit 2 of request message ID 0, seq 1
Dec 17 18:02:58 charon 10[NET] <con1000|548> sending packet: from 10.14.113.1[500] to 82.117.73.44[500] (176 bytes)
Dec 17 18:02:58 charon 10[IKE] <con1000|548> sending retransmit 1 of request message ID 0, seq 1
Dec 17 18:02:54 charon 12[NET] <con1000|548> sending packet: from 10.14.113.1[500] to 82.117.73.44[500] (176 bytes)
Dec 17 18:02:54 charon 12[ENC] <con1000|548> generating ID_PROT request 0 [ SA V V V V V ]
Dec 17 18:02:54 charon 12[CFG] <con1000|548> configured proposals: IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_768
Dec 17 18:02:54 charon 12[IKE] <con1000|548> IKE_SA con1000[548] state change: CREATED => CONNECTING
Dec 17 18:02:54 charon 12[IKE] <con1000|548> initiating Main Mode IKE_SA con1000[548] to 82.117.73.44
Dec 17 18:02:54 charon 12[IKE] <con1000|548> sending draft-ietf-ipsec-nat-t-ike-02\n vendor ID -
OK that catches the same thing so no good.
See if searching for IKE_DELETE finds something more interesting.
-
If 'nothing found' is interesting... :(
Any other guesses? -
Increase the logging retention for IPsec logs and/or search closer to when a disconnect happened.
The logs will tell you who requested the delete and what happened. Without that it's a "who knows".
-
Sorry, but I'm at a loss here... changed log to raw and got some stuff, saying no acceptable encryption algorithm found.
(ignore the obviously wrong ip addresses - they are only placeholders)
Here we go:
Dec 17 23:36:53 charon: 11[CFG] <con1000|594> no acceptable ENCRYPTION_ALGORITHM found
Dec 17 23:36:53 charon: 11[CFG] <con1000|594> selecting proposal:
Dec 17 23:36:53 charon: 11[CFG] <con1000|594> no acceptable ENCRYPTION_ALGORITHM found
Dec 17 23:36:53 charon: 11[CFG] <con1000|594> selecting proposal:
Dec 17 23:36:53 charon: 11[CFG] <con1000|594> no acceptable ENCRYPTION_ALGORITHM found
Dec 17 23:36:53 charon: 11[CFG] <con1000|594> selecting proposal:
Dec 17 23:36:53 charon: 11[CFG] <con1000|594> config: 192.12.13.1/0, received: 192.12.13.1/0 => match: 192.12.13.1/0
Dec 17 23:36:53 charon: 11[CFG] <con1000|594> selecting traffic selectors for us:
Dec 17 23:36:53 charon: 11[CFG] <con1000|594> config: 192.12.13.1/0, received: 192.12.13.1/0 => match: 192.12.13.1/0
Dec 17 23:36:53 charon: 11[CFG] <con1000|594> selecting traffic selectors for other:
Dec 17 23:36:53 charon: 11[CFG] <con1000|594> found matching child config "con1000" with prio 10
Dec 17 23:36:53 charon: 11[CFG] <con1000|594> candidate "con1000" with prio 5+5
Dec 17 23:36:53 charon: 11[CFG] <con1000|594> 192.12.13.1/0
Dec 17 23:36:53 charon: 11[CFG] <con1000|594> proposing traffic selectors for other:
Dec 17 23:36:53 charon: 11[CFG] <con1000|594> 192.12.13.1/0
Dec 17 23:36:53 charon: 11[CFG] <con1000|594> proposing traffic selectors for us:
Dec 17 23:36:53 charon: 11[CFG] <con1000|594> looking for a child config for 192.12.13.1/0 === 192.12.13.1/0
Dec 17 23:36:53 charon: 11[ENC] <con1000|594> parsed QUICK_MODE request 673042099 [ HASH SA No KE ID ID ]
Dec 17 23:36:53 charon: 11[NET] <con1000|594> received packet: from 82.110.36.24[4500] to 192.12.13.1[4500] (260 bytes)
Dec 17 23:36:53 charon: 09[NET] <con1000|594> sending packet: from 192.12.13.1[4500] to 82.110.36.24[4500] (68 bytes)
Dec 17 23:36:53 charon: 09[ENC] <con1000|594> generating ID_PROT response 0 [ ID HASH ]
Dec 17 23:36:53 charon: 09[IKE] <con1000|594> IKE_SA con1000[594] state change: CONNECTING => ESTABLISHED
Dec 17 23:36:53 charon: 09[IKE] <con1000|594> IKE_SA con1000[594] established between 192.12.13.1[192.12.13.1]...82.110.36.24[xyz.rubber.com]
Dec 17 23:36:53 charon: 09[CFG] <594> selected peer config "con1000"
Dec 17 23:36:53 charon: 09[CFG] <594> candidate "con1000", match: 1/20/3100 (me/other/ike)
Dec 17 23:36:53 charon: 09[CFG] <594> candidate "bypasslan", match: 1/1/24 (me/other/ike)
Dec 17 23:36:53 charon: 09[CFG] <594> looking for pre-shared key peer configs matching 192.12.13.1...82.110.36.24[xyz.rubber.com]
Dec 17 23:36:53 charon: 09[ENC] <594> parsed ID_PROT request 0 [ ID HASH ]
Dec 17 23:36:53 charon: 09[NET] <594> received packet: from 82.110.36.24[4500] to 192.12.13.1[4500] (84 bytes)
Dec 17 23:36:53 charon: 09[NET] <594> sending packet: from 192.12.13.1[4500] to 82.110.36.24[4500] (212 bytes)
Dec 17 23:36:53 charon: 09[ENC] <594> generating ID_PROT response 0 [ KE No NAT-D NAT-D ]
Dec 17 23:36:53 charon: 09[CFG] <594> candidate "con1000", match: 1/1/3100 (me/other/ike)
Dec 17 23:36:53 charon: 09[CFG] <594> candidate "bypasslan", match: 1/1/24 (me/other/ike)
Dec 17 23:36:53 charon: 09[IKE] <594> remote host is behind NAT
Dec 17 23:36:53 charon: 09[IKE] <594> local host is behind NAT, sending keep alives
Dec 17 23:36:53 charon: 09[ENC] <594> parsed ID_PROT request 0 [ KE No NAT-D NAT-D ]
Dec 17 23:36:53 charon: 09[NET] <594> received packet: from 82.110.36.24[4500] to 192.12.13.1[4500] (196 bytes)
Dec 17 23:36:53 charon: 09[NET] <594> sending packet: from 192.12.13.1[4500] to 82.110.36.24[4500] (132 bytes)
Dec 17 23:36:53 charon: 09[ENC] <594> generating ID_PROT response 0 [ SA V V V ]
Dec 17 23:36:53 charon: 09[IKE] <594> sending NAT-T (RFC 3947) vendor ID
Dec 17 23:36:53 charon: 09[IKE] <594> sending DPD vendor ID
Dec 17 23:36:53 charon: 09[IKE] <594> sending XAuth vendor ID
Dec 17 23:36:53 charon: 09[CFG] <594> selected proposal: IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_768
Dec 17 23:36:53 charon: 09[CFG] <594> configured proposals: IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_768
Dec 17 23:36:53 charon: 09[CFG] <594> received proposals: IKE:AES_CBC_256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_768, IKE:AES_CBC_192/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_768, IKE:AES_CBC_128/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_768, IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_768, IKE:DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_768, IKE:AES_CBC_256/HMAC_MD5_96/PRF_HMAC_MD5/MODP_768, IKE:AES_CBC_192/HMAC_MD5_96/PRF_HMAC_MD5/MODP_768, IKE:AES_CBC_128/HMAC_MD5_96/PRF_HMAC_MD5/MODP_768, IKE:3DES_CBC/HMAC_MD5_96/PRF_HMAC_MD5/MODP_768, IKE:DES_CBC/HMAC_MD5_96/PRF_HMAC_MD5/MODP_768
Dec 17 23:36:53 charon: 09[CFG] <594> proposal matches
Dec 17 23:36:53 charon: 09[CFG] <594> selecting proposal:
Dec 17 23:36:53 charon: 09[CFG] <594> no acceptable ENCRYPTION_ALGORITHM found
Dec 17 23:36:53 charon: 09[CFG] <594> selecting proposal:
Dec 17 23:36:53 charon: 09[CFG] <594> no acceptable ENCRYPTION_ALGORITHM found
Dec 17 23:36:53 charon: 09[CFG] <594> selecting proposal:
Dec 17 23:36:53 charon: 09[CFG] <594> no acceptable ENCRYPTION_ALGORITHM found
Dec 17 23:36:53 charon: 09[CFG] <594> selecting proposal:
Dec 17 23:36:53 charon: 09[IKE] <594> IKE_SA (unnamed)[594] state change: CREATED => CONNECTING
Dec 17 23:36:53 charon: 09[IKE] <594> 82.110.36.24 is initiating a Main Mode IKE_SA
Dec 17 23:36:53 charon: 09[ENC] <594> received unknown vendor ID: a2:22:6f:c3:64:50:0f:56:34:ff:77:db:3b:74:f4:1b
Dec 17 23:36:53 charon: 09[IKE] <594> received draft-ietf-ipsec-nat-t-ike-03 vendor ID
Dec 17 23:36:53 charon: 09[IKE] <594> received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Dec 17 23:36:53 charon: 09[IKE] <594> received NAT-T (RFC 3947) vendor ID
Dec 17 23:36:53 charon: 09[IKE] <594> received DPD vendor ID
Dec 17 23:36:53 charon: 09[IKE] <594> received XAuth vendor ID
Dec 17 23:36:53 charon: 09[CFG] <594> found matching ike config: 192.12.13.1...xyz.rubber.com with prio 3100
Dec 17 23:36:53 charon: 09[CFG] <594> candidate: 192.12.13.1...xyz.rubber.com, prio 3100
Dec 17 23:36:53 charon: 09[CFG] <594> candidate: %any...%any, prio 24
Dec 17 23:36:53 charon: 09[CFG] <594> looking for an IKEv1 config for 192.12.13.1...82.110.36.24
Dec 17 23:36:53 charon: 09[ENC] <594> parsed ID_PROT request 0 [ SA V V V V V V ]
Dec 17 23:36:53 charon: 09[NET] <594> received packet: from 82.110.36.24[4500] to 192.12.13.1[4500] (496 bytes)
Dec 17 23:36:47 charon: 09[NET] <con1000|593> sending packet: from 192.12.13.1[500] to 82.110.36.24[500] (176 bytes)
Dec 17 23:36:47 charon: 09[IKE] <con1000|593> sending retransmit 5 of request message ID 0, seq 1
Dec 17 23:36:05 charon: 10[NET] <con1000|593> sending packet: from 192.12.13.1[500] to 82.110.36.24[500] (176 bytes)
Dec 17 23:36:05 charon: 10[IKE] <con1000|593> sending retransmit 4 of request message ID 0, seq 1
Dec 17 23:35:42 charon: 10[NET] <con1000|593> sending packet: from 192.12.13.1[500] to 82.110.36.24[500] (176 bytes)
Dec 17 23:35:42 charon: 10[IKE] <con1000|593> sending retransmit 3 of request message ID 0, seq 1Bought an apu-board for the "fritz-side" of the vpn connection. Better to take one variable (with poor encryption) out of the equitation and have the backups running...
-
That looks like the fritzbox side is not allowing initiations from you to it, but it is working when that side initiates from them to you.
The no acceptable encryption found is the other side working through its configured PFS groups. It matched at GROUP 1 (MODP_768) which is almost too weak to be useful any more:
Dec 17 23:36:53 charon: 09[CFG] <594> selected proposal: IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_768 Dec 17 23:36:53 charon: 09[CFG] <594> configured proposals: IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_768 Dec 17 23:36:53 charon: 09[CFG] <594> received proposals: IKE:AES_CBC_256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_768, IKE:AES_CBC_192/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_768, IKE:AES_CBC_128/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_768, IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_768, IKE:DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_768, IKE:AES_CBC_256/HMAC_MD5_96/PRF_HMAC_MD5/MODP_768, IKE:AES_CBC_192/HMAC_MD5_96/PRF_HMAC_MD5/MODP_768, IKE:AES_CBC_128/HMAC_MD5_96/PRF_HMAC_MD5/MODP_768, IKE:3DES_CBC/HMAC_MD5_96/PRF_HMAC_MD5/MODP_768, IKE:DES_CBC/HMAC_MD5_96/PRF_HMAC_MD5/MODP_768
Note that those logs are newest entries at the top, oldest at the bottom.
So the logs at the bottom are your side trying to initiate and being ignored. Then you receive an initiation from them and it completes. Then it starts negotiating the Phase 2 and the logs cut off before getting to the establishment.
-
(MODP_768) which is almost too weak to be useful
Entirely my opinion. That's why pfsense on both ends should be the best way and that is what I will do now.
Thanks a lot anyway! -
Here is also my log file. The disconnect happened about one minute after midnight.
Dec 18 00:02:34 charon 12[CFG] vici client 2634 disconnected Dec 18 00:02:34 charon 05[CFG] vici client 2634 requests: list-sas Dec 18 00:02:34 charon 12[CFG] vici client 2634 registered for: list-sa Dec 18 00:02:34 charon 05[CFG] vici client 2634 connected Dec 18 00:02:21 charon 06[CFG] vici client 2633 disconnected Dec 18 00:02:21 charon 13[CFG] vici client 2633 requests: list-sas Dec 18 00:02:21 charon 13[CFG] vici client 2633 registered for: list-sa Dec 18 00:02:21 charon 06[CFG] vici client 2633 connected Dec 18 00:02:06 charon 16[CFG] vici client 2632 disconnected Dec 18 00:02:06 charon 06[CFG] vici client 2632 requests: list-sas Dec 18 00:02:06 charon 06[CFG] vici client 2632 registered for: list-sa Dec 18 00:02:06 charon 16[CFG] vici client 2632 connected Dec 18 00:01:51 charon 07[CFG] vici client 2631 disconnected Dec 18 00:01:51 charon 06[CFG] vici client 2631 requests: list-sas Dec 18 00:01:51 charon 07[CFG] vici client 2631 registered for: list-sa Dec 18 00:01:51 charon 06[CFG] vici client 2631 connected Dec 18 00:01:48 charon 09[CHD] <con3000|445> CHILD_SA con3000{418} state change: INSTALLED => DESTROYING Dec 18 00:01:48 charon 09[IKE] <con3000|445> IKE_SA con3000[445] state change: ESTABLISHED => DESTROYING Dec 18 00:01:48 charon 09[JOB] <con3000|445> DPD check timed out, enforcing DPD action Dec 18 00:01:38 charon 09[IKE] <con3000|445> nothing to initiate Dec 18 00:01:38 charon 09[IKE] <con3000|445> activating new tasks Dec 18 00:01:38 charon 09[NET] <con3000|445> sending packet: from xxx.xxx.xxx.xxx (IP pfsense)[500] to xxx.xxx.xxx.xxx (IP Fritzbox)[500] (92 bytes) Dec 18 00:01:38 charon 09[ENC] <con3000|445> generating INFORMATIONAL_V1 request 1223470614 [ HASH N(DPD) ] Dec 18 00:01:38 charon 09[IKE] <con3000|445> activating ISAKMP_DPD task Dec 18 00:01:38 charon 09[IKE] <con3000|445> activating new tasks Dec 18 00:01:38 charon 09[IKE] <con3000|445> queueing ISAKMP_DPD task Dec 18 00:01:38 charon 09[IKE] <con3000|445> sending DPD request Dec 18 00:01:36 charon 09[CFG] vici client 2630 disconnected Dec 18 00:01:36 charon 09[CFG] vici client 2630 requests: list-sas Dec 18 00:01:36 charon 09[CFG] vici client 2630 registered for: list-sa Dec 18 00:01:36 charon 08[CFG] vici client 2630 connected Dec 18 00:01:28 charon 08[IKE] <con3000|445> nothing to initiate Dec 18 00:01:28 charon 08[IKE] <con3000|445> activating new tasks Dec 18 00:01:28 charon 08[NET] <con3000|445> sending packet: from xxx.xxx.xxx.xxx (IP pfsense)[500] to xxx.xxx.xxx.xxx (IP Fritzbox)[500] (92 bytes) Dec 18 00:01:28 charon 08[ENC] <con3000|445> generating INFORMATIONAL_V1 request 320752580 [ HASH N(DPD) ] Dec 18 00:01:28 charon 08[IKE] <con3000|445> activating ISAKMP_DPD task Dec 18 00:01:28 charon 08[IKE] <con3000|445> activating new tasks Dec 18 00:01:28 charon 08[IKE] <con3000|445> queueing ISAKMP_DPD task Dec 18 00:01:28 charon 08[IKE] <con3000|445> sending DPD request Dec 18 00:01:23 charon 11[CFG] vici client 2629 disconnected Dec 18 00:01:23 charon 11[CFG] vici client 2629 requests: list-sas Dec 18 00:01:23 charon 08[CFG] vici client 2629 registered for: list-sa Dec 18 00:01:23 charon 14[CFG] vici client 2629 connected Dec 18 00:01:18 charon 14[IKE] <con3000|445> nothing to initiate Dec 18 00:01:18 charon 14[IKE] <con3000|445> activating new tasks Dec 18 00:01:18 charon 14[NET] <con3000|445> sending packet: from xxx.xxx.xxx.xxx (IP pfsense)[500] to xxx.xxx.xxx.xxx (IP Fritzbox)[500] (92 bytes) Dec 18 00:01:18 charon 14[ENC] <con3000|445> generating INFORMATIONAL_V1 request 2927126343 [ HASH N(DPD) ] Dec 18 00:01:18 charon 14[IKE] <con3000|445> activating ISAKMP_DPD task Dec 18 00:01:18 charon 14[IKE] <con3000|445> activating new tasks Dec 18 00:01:18 charon 14[IKE] <con3000|445> queueing ISAKMP_DPD task Dec 18 00:01:18 charon 14[IKE] <con3000|445> sending DPD request Dec 18 00:01:08 charon 05[IKE] <con3000|445> nothing to initiate Dec 18 00:01:08 charon 05[IKE] <con3000|445> activating new tasks Dec 18 00:01:08 charon 05[NET] <con3000|445> sending packet: from xxx.xxx.xxx.xxx (IP pfsense)[500] to xxx.xxx.xxx.xxx (IP Fritzbox)[500] (92 bytes) Dec 18 00:01:08 charon 05[ENC] <con3000|445> generating INFORMATIONAL_V1 request 2708381718 [ HASH N(DPD) ] Dec 18 00:01:08 charon 05[IKE] <con3000|445> activating ISAKMP_DPD task Dec 18 00:01:08 charon 05[IKE] <con3000|445> activating new tasks Dec 18 00:01:08 charon 05[IKE] <con3000|445> queueing ISAKMP_DPD task Dec 18 00:01:08 charon 05[IKE] <con3000|445> sending DPD request Dec 18 00:00:58 charon 05[IKE] <con3000|445> nothing to initiate Dec 18 00:00:58 charon 05[IKE] <con3000|445> activating new tasks Dec 18 00:00:58 charon 05[NET] <con3000|445> sending packet: from xxx.xxx.xxx.xxx (IP pfsense)[500] to xxx.xxx.xxx.xxx (IP Fritzbox)[500] (92 bytes) Dec 18 00:00:58 charon 05[ENC] <con3000|445> generating INFORMATIONAL_V1 request 180128396 [ HASH N(DPD) ] Dec 18 00:00:58 charon 05[IKE] <con3000|445> activating ISAKMP_DPD task Dec 18 00:00:58 charon 05[IKE] <con3000|445> activating new tasks Dec 18 00:00:58 charon 05[IKE] <con3000|445> queueing ISAKMP_DPD task Dec 18 00:00:58 charon 05[IKE] <con3000|445> sending DPD request Dec 18 00:00:42 charon 05[KNL] 10.10.10.1 appeared on em1 Dec 18 00:00:42 charon 05[KNL] 10.10.10.1 disappeared from em1 Dec 18 00:00:10 charon 16[CFG] vici client 2628 disconnected Dec 18 00:00:10 charon 15[CFG] vici client 2628 requests: list-sas Dec 18 00:00:10 charon 16[CFG] vici client 2628 registered for: list-sa Dec 18 00:00:10 charon 16[CFG] vici client 2628 connected Dec 18 00:00:00 charon 07[CFG] vici client 2627 disconnected Dec 18 00:00:00 charon 07[CFG] vici client 2627 requests: list-sas Dec 18 00:00:00 charon 09[CFG] vici client 2627 registered for: list-sa Dec 18 00:00:00 charon 09[CFG] vici client 2627 connected Dec 17 23:59:50 charon 06[CFG] vici client 2626 disconnected Dec 17 23:59:50 charon 09[CFG] vici client 2626 requests: list-sas Dec 17 23:59:50 charon 09[CFG] vici client 2626 registered for: list-sa Dec 17 23:59:50 charon 06[CFG] vici client 2626 connected Dec 17 23:59:44 charon 08[IKE] <con3000|445> nothing to initiate Dec 17 23:59:44 charon 08[IKE] <con3000|445> activating new tasks Dec 17 23:59:44 charon 08[NET] <con3000|445> sending packet: from xxx.xxx.xxx.xxx (IP pfsense)[500] to xxx.xxx.xxx.xxx (IP Fritzbox)[500] (92 bytes) Dec 17 23:59:44 charon 08[ENC] <con3000|445> generating INFORMATIONAL_V1 request 3418999340 [ HASH N(DPD) ] Dec 17 23:59:44 charon 08[IKE] <con3000|445> activating ISAKMP_DPD task Dec 17 23:59:44 charon 08[IKE] <con3000|445> activating new tasks Dec 17 23:59:44 charon 08[IKE] <con3000|445> queueing ISAKMP_DPD task Dec 17 23:59:44 charon 08[IKE] <con3000|445> sending DPD request Dec 17 23:59:40 charon 08[CFG] vici client 2625 disconnected Dec 17 23:59:40 charon 08[CFG] vici client 2625 requests: list-sas Dec 17 23:59:40 charon 11[CFG] vici client 2625 registered for: list-sa Dec 17 23:59:40 charon 08[CFG] vici client 2625 connected Dec 17 23:59:34 charon 12[IKE] <con3000|445> nothing to initiate Dec 17 23:59:34 charon 12[IKE] <con3000|445> activating new tasks Dec 17 23:59:34 charon 12[NET] <con3000|445> sending packet: from xxx.xxx.xxx.xxx (IP pfsense)[500] to xxx.xxx.xxx.xxx (IP Fritzbox)[500] (92 bytes) Dec 17 23:59:34 charon 12[ENC] <con3000|445> generating INFORMATIONAL_V1 request 1748552581 [ HASH N(DPD) ] Dec 17 23:59:34 charon 12[IKE] <con3000|445> activating ISAKMP_DPD task Dec 17 23:59:34 charon 12[IKE] <con3000|445> activating new tasks Dec 17 23:59:34 charon 12[IKE] <con3000|445> queueing ISAKMP_DPD task Dec 17 23:59:34 charon 12[IKE] <con3000|445> sending DPD request Dec 17 23:59:30 charon 12[CFG] vici client 2624 disconnected Dec 17 23:59:30 charon 12[CFG] vici client 2624 requests: list-sas Dec 17 23:59:30 charon 08[CFG] vici client 2624 registered for: list-sa Dec 17 23:59:30 charon 12[CFG] vici client 2624 connected Dec 17 23:59:24 charon 12[IKE] <con3000|445> nothing to initiate Dec 17 23:59:24 charon 12[IKE] <con3000|445> activating new tasks Dec 17 23:59:24 charon 12[ENC] <con3000|445> parsed INFORMATIONAL_V1 response 1660130927 [ HASH N(DPD_ACK) ] Dec 17 23:59:24 charon 12[NET] <con3000|445> received packet: from xxx.xxx.xxx.xxx (IP Fritzbox)[500] to xxx.xxx.xxx.xxx (IP pfsense)[500] (92 bytes) Dec 17 23:59:24 charon 12[IKE] <con3000|445> nothing to initiate Dec 17 23:59:24 charon 12[IKE] <con3000|445> activating new tasks Dec 17 23:59:24 charon 12[NET] <con3000|445> sending packet: from xxx.xxx.xxx.xxx (IP pfsense)[500] to xxx.xxx.xxx.xxx (IP Fritzbox)[500] (92 bytes) Dec 17 23:59:24 charon 12[ENC] <con3000|445> generating INFORMATIONAL_V1 request 1660130927 [ HASH N(DPD) ] Dec 17 23:59:24 charon 12[IKE] <con3000|445> activating ISAKMP_DPD task Dec 17 23:59:24 charon 12[IKE] <con3000|445> activating new tasks Dec 17 23:59:24 charon 12[IKE] <con3000|445> queueing ISAKMP_DPD task Dec 17 23:59:24 charon 12[IKE] <con3000|445> sending DPD request Dec 17 23:59:20 charon 12[CFG] vici client 2623 disconnected Dec 17 23:59:20 charon 10[CFG] vici client 2623 requests: list-sas Dec 17 23:59:20 charon 12[CFG] vici client 2623 registered for: list-sa Dec 17 23:59:20 charon 10[CFG] vici client 2623 connected Dec 17 23:59:02 charon 05[CHD] <con3000|445> CHILD_SA con3000{418} state change: INSTALLING => INSTALLED Dec 17 23:59:02 charon 05[IKE] <con3000|445> CHILD_SA con3000{418} established with SPIs c3c51713_i 5077683c_o and TS 192.168.2.0/24|/0 === 192.168.178.0/24|/0 Dec 17 23:59:02 charon 05[CHD] <con3000|445> SPI 0x5077683c, src xxx.xxx.xxx.xxx (IP pfsense) dst xxx.xxx.xxx.xxx (IP Fritzbox) Dec 17 23:59:02 charon 05[CHD] <con3000|445> adding outbound ESP SA Dec 17 23:59:02 charon 05[CHD] <con3000|445> SPI 0xc3c51713, src xxx.xxx.xxx.xxx (IP Fritzbox) dst xxx.xxx.xxx.xxx (IP pfsense) Dec 17 23:59:02 charon 05[CHD] <con3000|445> adding inbound ESP SA Dec 17 23:59:02 charon 05[CHD] <con3000|445> using HMAC_SHA1_96 for integrity Dec 17 23:59:02 charon 05[CHD] <con3000|445> using AES_CBC for encryption Dec 17 23:59:02 charon 05[CHD] <con3000|445> CHILD_SA con3000{418} state change: CREATED => INSTALLING Dec 17 23:59:02 charon 05[ENC] <con3000|445> parsed QUICK_MODE request 134785801 [ HASH ] Dec 17 23:59:02 charon 05[NET] <con3000|445> received packet: from xxx.xxx.xxx.xxx (IP Fritzbox)[500] to xxx.xxx.xxx.xxx (IP pfsense)[500] (60 bytes) Dec 17 23:59:01 charon 15[NET] <con3000|445> sending packet: from xxx.xxx.xxx.xxx (IP pfsense)[500] to xxx.xxx.xxx.xxx (IP Fritzbox)[500] (444 bytes) Dec 17 23:59:01 charon 15[ENC] <con3000|445> generating QUICK_MODE response 134785801 [ HASH SA No KE ID ID ] Dec 17 23:59:01 charon 15[IKE] <con3000|445> received 3600s lifetime, configured 0s Dec 17 23:59:01 charon 15[CFG] <con3000|445> selected proposal: ESP:AES_CBC_256/HMAC_SHA1_96/MODP_2048/NO_EXT_SEQ Dec 17 23:59:01 charon 15[CFG] <con3000|445> configured proposals: ESP:AES_CBC_256/HMAC_SHA1_96/MODP_2048/NO_EXT_SEQ, ESP:3DES_CBC/HMAC_SHA1_96/MODP_2048/NO_EXT_SEQ Dec 17 23:59:01 charon 15[CFG] <con3000|445> received proposals: ESP:AES_CBC_256/HMAC_SHA2_512_256/MODP_2048/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA1_96/MODP_2048/NO_EXT_SEQ, ESP:3DES_CBC/HMAC_SHA1_96/MODP_2048/NO_EXT_SEQ Dec 17 23:59:01 charon 15[CFG] <con3000|445> proposal matches Dec 17 23:59:01 charon 15[CFG] <con3000|445> selecting proposal: Dec 17 23:59:01 charon 15[CFG] <con3000|445> no acceptable INTEGRITY_ALGORITHM found Dec 17 23:59:01 charon 15[CFG] <con3000|445> selecting proposal: Dec 17 23:59:01 charon 15[CFG] <con3000|445> config: 192.168.2.0/24|/0, received: 192.168.2.0/24|/0 => match: 192.168.2.0/24|/0 Dec 17 23:59:01 charon 15[CFG] <con3000|445> selecting traffic selectors for us: Dec 17 23:59:01 charon 15[CFG] <con3000|445> config: 192.168.178.0/24|/0, received: 192.168.178.0/24|/0 => match: 192.168.178.0/24|/0 Dec 17 23:59:01 charon 15[CFG] <con3000|445> selecting traffic selectors for other: Dec 17 23:59:01 charon 15[CFG] <con3000|445> found matching child config "con3000" with prio 10 Dec 17 23:59:01 charon 15[CFG] <con3000|445> candidate "con3000" with prio 5+5 Dec 17 23:59:01 charon 15[CFG] <con3000|445> 192.168.178.0/24|/0 Dec 17 23:59:01 charon 15[CFG] <con3000|445> proposing traffic selectors for other: Dec 17 23:59:01 charon 15[CFG] <con3000|445> 192.168.2.0/24|/0 Dec 17 23:59:01 charon 15[CFG] <con3000|445> proposing traffic selectors for us: Dec 17 23:59:01 charon 15[CFG] <con3000|445> looking for a child config for 192.168.2.0/24|/0 === 192.168.178.0/24|/0 Dec 17 23:59:01 charon 15[ENC] <con3000|445> parsed QUICK_MODE request 134785801 [ HASH SA No KE ID ID ] Dec 17 23:59:01 charon 15[NET] <con3000|445> received packet: from xxx.xxx.xxx.xxx (IP Fritzbox)[500] to xxx.xxx.xxx.xxx (IP pfsense)[500] (508 bytes) Dec 17 23:59:01 charon 15[ENC] <con3000|445> parsed INFORMATIONAL_V1 request 3490275435 [ HASH N(INITIAL_CONTACT) ] Dec 17 23:59:01 charon 15[NET] <con3000|445> received packet: from xxx.xxx.xxx.xxx (IP Fritzbox)[500] to xxx.xxx.xxx.xxx (IP pfsense)[500] (92 bytes) Dec 17 23:59:01 charon 05[NET] <con3000|445> sending packet: from xxx.xxx.xxx.xxx (IP pfsense)[500] to xxx.xxx.xxx.xxx (IP Fritzbox)[500] (76 bytes) Dec 17 23:59:01 charon 05[ENC] <con3000|445> generating ID_PROT response 0 [ ID HASH ] Dec 17 23:59:01 charon 05[IKE] <con3000|445> IKE_SA con3000[445] state change: CONNECTING => ESTABLISHED Dec 17 23:59:01 charon 05[IKE] <con3000|445> IKE_SA con3000[445] established between xxx.xxx.xxx.xxx (IP pfsense)[xxx.xxx.xxx.xxx (IP pfsense)]...xxx.xxx.xxx.xxx (IP Fritzbox)[opaundoma.no-ip.biz] Dec 17 23:59:01 charon 05[CFG] <445> selected peer config "con3000" Dec 17 23:59:01 charon 05[CFG] <445> candidate "con3000", match: 1/20/3096 (me/other/ike) Dec 17 23:59:01 charon 05[CFG] <445> candidate "bypasslan", match: 1/1/24 (me/other/ike) Dec 17 23:59:01 charon 05[CFG] <445> looking for pre-shared key peer configs matching xxx.xxx.xxx.xxx (IP pfsense)...xxx.xxx.xxx.xxx (IP Fritzbox)[opaundoma.no-ip.biz] Dec 17 23:59:01 charon 05[ENC] <445> parsed ID_PROT request 0 [ ID HASH N(INITIAL_CONTACT) ] Dec 17 23:59:01 charon 05[NET] <445> received packet: from xxx.xxx.xxx.xxx (IP Fritzbox)[500] to xxx.xxx.xxx.xxx (IP pfsense)[500] (108 bytes) Dec 17 23:59:01 charon 05[NET] <445> sending packet: from xxx.xxx.xxx.xxx (IP pfsense)[500] to xxx.xxx.xxx.xxx (IP Fritzbox)[500] (324 bytes) Dec 17 23:59:01 charon 05[ENC] <445> generating ID_PROT response 0 [ KE No ] Dec 17 23:59:01 charon 05[CFG] <445> candidate "con3000", match: 1/1/3096 (me/other/ike) Dec 17 23:59:01 charon 05[CFG] <445> candidate "bypasslan", match: 1/1/24 (me/other/ike) Dec 17 23:59:01 charon 05[ENC] <445> parsed ID_PROT request 0 [ KE No ] Dec 17 23:59:01 charon 05[NET] <445> received packet: from xxx.xxx.xxx.xxx (IP Fritzbox)[500] to xxx.xxx.xxx.xxx (IP pfsense)[500] (308 bytes) Dec 17 23:59:00 charon 05[NET] <445> sending packet: from xxx.xxx.xxx.xxx (IP pfsense)[500] to xxx.xxx.xxx.xxx (IP Fritzbox)[500] (116 bytes) Dec 17 23:59:00 charon 05[ENC] <445> generating ID_PROT response 0 [ SA V V ] Dec 17 23:59:00 charon 05[IKE] <445> sending DPD vendor ID Dec 17 23:59:00 charon 05[IKE] <445> sending XAuth vendor ID Dec 17 23:59:00 charon 05[CFG] <445> selected proposal: IKE:AES_CBC_256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_2048 Dec 17 23:59:00 charon 05[CFG] <445> configured proposals: IKE:AES_CBC_256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_2048 Dec 17 23:59:00 charon 05[CFG] <445> received proposals: IKE:AES_CBC_256/HMAC_SHA2_512_256/PRF_HMAC_SHA2_512/MODP_2048, IKE:AES_CBC_256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_2048, IKE:AES_CBC_192/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_2048, IKE:AES_CBC_128/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_2048 Dec 17 23:59:00 charon 05[CFG] <445> proposal matches Dec 17 23:59:00 charon 05[CFG] <445> selecting proposal: Dec 17 23:59:00 charon 05[CFG] <445> no acceptable INTEGRITY_ALGORITHM found Dec 17 23:59:00 charon 05[CFG] <445> selecting proposal: Dec 17 23:59:00 charon 05[IKE] <445> IKE_SA (unnamed)[445] state change: CREATED => CONNECTING Dec 17 23:59:00 charon 05[IKE] <445> xxx.xxx.xxx.xxx (IP Fritzbox) is initiating a Main Mode IKE_SA Dec 17 23:59:00 charon 05[IKE] <445> received DPD vendor ID Dec 17 23:59:00 charon 05[IKE] <445> received XAuth vendor ID Dec 17 23:59:00 charon 05[CFG] <445> found matching ike config: xxx.xxx.xxx.xxx (IP pfsense)...opaundoma.no-ip.biz with prio 3096 Dec 17 23:59:00 charon 05[CFG] <445> candidate: xxx.xxx.xxx.xxx (IP pfsense)...opaundoma.no-ip.biz, prio 3096 Dec 17 23:59:00 charon 05[CFG] <445> candidate: %any...%any, prio 24 Dec 17 23:59:00 charon 05[CFG] <445> looking for an IKEv1 config for xxx.xxx.xxx.xxx (IP pfsense)...xxx.xxx.xxx.xxx (IP Fritzbox) Dec 17 23:59:00 charon 05[ENC] <445> parsed ID_PROT request 0 [ SA V V ] Dec 17 23:59:00 charon 05[NET] <445> received packet: from xxx.xxx.xxx.xxx (IP Fritzbox)[500] to xxx.xxx.xxx.xxx (IP pfsense)[500] (220 bytes)
(Enclosed in text markdown to eliminate links - Derelict)
-
@kuschi: nice link you inserted instead of your ip-addresses...
(Firefox-User)
-
@commwest Oops, wasn't me intention.... :-O
-
@commwest said in IPsec VPN tunnel to a Fritzbox after update to 2.4.4-p1:
(MODP_768) which is almost too weak to be useful
Entirely my opinion. That's why pfsense on both ends should be the best way and that is what I will do now.
Thanks a lot anyway!It looks like it is trying three other (presumably stronger) PFS groups before reverting to group 1. It would not surprise me if those were 14, 5, 2.