IPsec VPN tunnel to a Fritzbox after update to 2.4.4-p1

kuschi

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

cschwadorf

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

kuschi

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

kuschi

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

CommWest

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...

Derelict

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.

CommWest

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

kuschi

@commwest Done. I hope it worked :-)

Derelict

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.

CommWest

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

Derelict

OK that catches the same thing so no good.

See if searching for IKE_DELETE finds something more interesting.

CommWest

If 'nothing found' is interesting... :(
Any other guesses?

Derelict

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".

CommWest

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 1

Bought 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...

Derelict

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.

CommWest

(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!

kuschi

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)

CommWest

@kuschi: nice link you inserted instead of your ip-addresses... (Firefox-User)

kuschi

@commwest Oops, wasn't me intention.... :-O

Derelict

@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.

Derelict

@kuschi said in IPsec VPN tunnel to a Fritzbox after update to 2.4.4-p1:

Dec 18 00:01:48 charon 09[JOB] <con3000|445> DPD check timed out, enforcing DPD action

They stop responding to DPD checks for whatever reason. The logs on the other side would need to be checked to see why.

It could just be intermittent connectivity.

But, regardless, based on the other logs, it will be down until they initiate.

kuschi

Here is the log file from the other side: Fritzbox. Sorry part of it is in German.

17.12.18 23:59:02 VPN-Verbindung zu VPN MCKUSCH [(IP pfsense)] IKE SA: DH14/AES-256/SHA1 IPsec SA: ESP-AES-256/SHA1/LT-3600 wurde erfolgreich hergestellt.
17.12.18 23:58:50 VPN-Verbindung zu VPN MCKUSCH wurde getrennt. Ursache: 12 SA loss
17.12.18 23:01:46 VPN-Verbindung zu VPN MCKUSCH [(IP pfsense)] IKE SA: DH14/AES-256/SHA1 IPsec SA: ESP-AES-256/SHA1/LT-3600 wurde erfolgreich hergestellt.
17.12.18 23:01:44 VPN-Verbindung zu VPN MCKUSCH wurde getrennt. Ursache: 9 Dead Peer Detection
17.12.18 22:46:40 VPN-Verbindung zu VPN MCKUSCH [(IP pfsense)] IKE SA: DH14/AES-256/SHA1 IPsec SA: ESP-AES-256/SHA1/LT-3600 wurde erfolgreich hergestellt.
17.12.18 22:46:39 VPN-Verbindung zu VPN MCKUSCH wurde getrennt. Ursache: 9 Dead Peer Detection

Derelict

@kuschi said in IPsec VPN tunnel to a Fritzbox after update to 2.4.4-p1:

17.12.18 23:59:02 VPN-Verbindung zu VPN MCKUSCH [(IP pfsense)] IKE SA: DH14/AES-256/SHA1 IPsec SA: ESP-AES-256/SHA1/LT-3600 wurde erfolgreich hergestellt.
17.12.18 23:58:50 VPN-Verbindung zu VPN MCKUSCH wurde getrennt. Ursache: 12 SA loss
17.12.18 23:01:46 VPN-Verbindung zu VPN MCKUSCH [(IP pfsense)] IKE SA: DH14/AES-256/SHA1 IPsec SA: ESP-AES-256/SHA1/LT-3600 wurde erfolgreich hergestellt.
17.12.18 23:01:44 VPN-Verbindung zu VPN MCKUSCH wurde getrennt. Ursache: 9 Dead Peer Detection
17.12.18 22:46:40 VPN-Verbindung zu VPN MCKUSCH [(IP pfsense)] IKE SA: DH14/AES-256/SHA1 IPsec SA: ESP-AES-256/SHA1/LT-3600 wurde erfolgreich hergestellt.
17.12.18 22:46:39 VPN-Verbindung zu VPN MCKUSCH wurde getrennt. Ursache: 9 Dead Peer Detection

17.12.18 23:59:02 VPN connection to VPN MCKUSCH [(IP pfsense)] IKE SA: DH14 / AES-256 / SHA1 IPsec SA: ESP-AES-256 / SHA1 / LT-3600 was successfully established.
17.12.18 23:58:50 VPN connection to VPN MCKUSCH has been disconnected. Cause: 12 SA loss
17.12.18 23:01:46 VPN connection to VPN MCKUSCH [(IP pfsense)] IKE SA: DH14 / AES-256 / SHA1 IPsec SA: ESP-AES-256 / SHA1 / LT-3600 was successfully established.
17.12.18 23:01:44 VPN connection to VPN MCKUSCH has been disconnected. Cause: 9 dead peer detection
17.12.18 22:46:40 VPN connection to VPN MCKUSCH [(IP pfsense)] IKE SA: DH14 / AES-256 / SHA1 IPsec SA: ESP-AES-256 / SHA1 / LT-3600 was successfully established.
17.12.18 22:46:39 VPN connection to VPN MCKUSCH has been disconnected. Cause: 9 dead peer detection

Doesn't tell us much.

Need the logs from there saying why it is ignoring these:

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 1

kuschi

@derelict If someone could tell me where will I find more detailed logs from the Fritzbox....

kuschi

I had some time to dig into the Fritzbox and found some additional log files:

BEGIN SECTION vpn VPN

VPN avmike

-rw-r--r-- 1 root root 16551 Dec 27 07:32 /var/tmp/ike.log
-rw-r--r-- 1 root root 20579 Dec 27 06:22 /var/tmp/ike.old
2018-12-27 05:28:24 avmike:wolke_neighbour_renew_sa 1 SAs
2018-12-27 05:28:25 avmike:>>> identity protection mode [(IP pfsense)] VPN MCKUSCH: V1.0 220 IC c7b118c56587c471 RC 00000000 0000 SA flags=
2018-12-27 05:28:25 avmike:<<< identity protection mode[(IP pfsense)] VPN MCKUSCH: V1.0 116 IC c7b118c56587c471 RC d66c8871d64ba1bd 0000 SA flags=
2018-12-27 05:28:25 avmike:identity protection mode VPN MCKUSCH: selected lifetime: 3600 sec(no notify)
2018-12-27 05:28:25 avmike:VPN MCKUSCH receive VENDOR ID Payload: XAUTH
2018-12-27 05:28:25 avmike:VPN MCKUSCH receive VENDOR ID Payload: DPD
2018-12-27 05:28:25 avmike:>>> identity protection mode [(IP pfsense)] VPN MCKUSCH: V1.0 308 IC c7b118c56587c471 RC d66c8871d64ba1bd 0000 KEY flags=
2018-12-27 05:28:25 avmike:< create_sa(appl=dsld,cname=VPN MCKUSCH)
2018-12-27 05:28:25 avmike:VPN MCKUSCH: Phase 2 waiting
2018-12-27 05:28:25 avmike:<<< identity protection mode[(IP pfsense)] VPN MCKUSCH: V1.0 324 IC c7b118c56587c471 RC d66c8871d64ba1bd 0000 KEY flags=
2018-12-27 05:28:25 avmike:VPN MCKUSCH: add phase 1 SA: DH14/AES-256/SHA1/3600sec id:187
2018-12-27 05:28:25 avmike:>>> identity protection mode [(IP pfsense)] VPN MCKUSCH: V1.0 92 IC c7b118c56587c471 RC d66c8871d64ba1bd 0000 IDENTIFICATION flags=e
2018-12-27 05:28:25 avmike:<<< identity protection mode[(IP pfsense)] VPN MCKUSCH: V1.0 76 IC c7b118c56587c471 RC d66c8871d64ba1bd 0000 IDENTIFICATION flags=e
2018-12-27 05:28:25 avmike:VPN MCKUSCH: Phase 1 ready
2018-12-27 05:28:25 avmike:VPN MCKUSCH: current=(IP pfsense) new=(IP pfsense)
2018-12-27 05:28:25 avmike:VPN MCKUSCH: start waiting connections
2018-12-27 05:28:25 avmike:VPN MCKUSCH: Phase 2 starting (start waiting)
2018-12-27 05:28:26 avmike:>>> quickmode [(IP pfsense)] VPN MCKUSCH: V1.0 508 IC c7b118c56587c471 RC d66c8871d64ba1bd b79b46b HASH flags=e
2018-12-27 05:28:26 avmike:<<< quickmode[(IP pfsense)] VPN MCKUSCH: V1.0 444 IC c7b118c56587c471 RC d66c8871d64ba1bd b79b46b HASH flags=e
2018-12-27 05:28:26 avmike:>>> quickmode [(IP pfsense)] VPN MCKUSCH: V1.0 60 IC c7b118c56587c471 RC d66c8871d64ba1bd b79b46b HASH flags=e
2018-12-27 05:28:26 avmike:VPN MCKUSCH: Phase 2 ready
2018-12-27 05:28:26 avmike:NEW Phase 2 SA: ESP-AES-256/SHA1 SPI: 4750E80D LT: 3600 I/O: IN
2018-12-27 05:28:26 avmike:NEW Phase 2 SA: ESP-AES-256/SHA1 SPI: C8CD6F95 LT: 3600 I/O: OUT
2018-12-27 05:28:26 avmike:< cb_sa_created(name=VPN MCKUSCH,id=186,...,flags=0x00002101)
2018-12-27 05:28:26 avmike:VPN MCKUSCH: start waiting connections
2018-12-27 05:28:26 avmike:VPN MCKUSCH: NO waiting connections
2018-12-27 05:28:36 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC c7b118c56587c471 RC d66c8871d64ba1bd 1520852e HASH flags=e
2018-12-27 05:28:36 avmike:>r> infomode [(IP pfsense)] VPN MCKUSCH: V1.0 92 IC c7b118c56587c471 RC d66c8871d64ba1bd 1520852e HASH flags=e
2018-12-27 05:28:46 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC c7b118c56587c471 RC d66c8871d64ba1bd d8578e17 HASH flags=e
2018-12-27 05:28:56 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC c7b118c56587c471 RC d66c8871d64ba1bd 2310d460 HASH flags=e
2018-12-27 05:29:06 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC c7b118c56587c471 RC d66c8871d64ba1bd 1ca9e35a HASH flags=e
2018-12-27 05:29:16 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC c7b118c56587c471 RC d66c8871d64ba1bd 1fcb9fb2 HASH flags=e
2018-12-27 05:29:26 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC c7b118c56587c471 RC d66c8871d64ba1bd 4a845476 HASH flags=e
2018-12-27 05:34:24 avmike:VPN MCKUSCH: del phase 1 SA 186
2018-12-27 05:34:25 avmike:< delete_sa(appl=dsld,cname=VPN MCKUSCH,id=185,what=7,reason=Lifetime expired)
2018-12-27 05:34:25 avmike:FreeIPsecSA: spi=FB204F02 protocol=3 iotype=1
2018-12-27 05:34:25 avmike:FreeIPsecSA: spi=C9852197 protocol=3 iotype=2
2018-12-27 06:22:25 avmike:wolke_neighbour_renew_sa 1 SAs
2018-12-27 06:22:25 avmike:>>> identity protection mode [(IP pfsense)] VPN MCKUSCH: V1.0 220 IC 6872414bef8f5559 RC 00000000 0000 SA flags=
2018-12-27 06:22:25 avmike:<<< identity protection mode[(IP pfsense)] VPN MCKUSCH: V1.0 116 IC 6872414bef8f5559 RC 6511773149bee334 0000 SA flags=
2018-12-27 06:22:25 avmike:identity protection mode VPN MCKUSCH: selected lifetime: 3600 sec(no notify)
2018-12-27 06:22:25 avmike:VPN MCKUSCH receive VENDOR ID Payload: XAUTH
2018-12-27 06:22:25 avmike:VPN MCKUSCH receive VENDOR ID Payload: DPD
2018-12-27 06:22:26 avmike:>>> identity protection mode [(IP pfsense)] VPN MCKUSCH: V1.0 308 IC 6872414bef8f5559 RC 6511773149bee334 0000 KEY flags=
2018-12-27 06:22:26 avmike:<<< identity protection mode[(IP pfsense)] VPN MCKUSCH: V1.0 324 IC 6872414bef8f5559 RC 6511773149bee334 0000 KEY flags=
2018-12-27 06:22:26 avmike:VPN MCKUSCH: add phase 1 SA: DH14/AES-256/SHA1/3600sec id:188
2018-12-27 06:22:26 avmike:>>> identity protection mode [(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 6872414bef8f5559 RC 6511773149bee334 0000 IDENTIFICATION flags=e
2018-12-27 06:22:26 avmike:< create_sa(appl=dsld,cname=VPN MCKUSCH)
2018-12-27 06:22:26 avmike:VPN MCKUSCH: Phase 2 waiting
2018-12-27 06:22:26 avmike:<<< identity protection mode[(IP pfsense)] VPN MCKUSCH: V1.0 76 IC 6872414bef8f5559 RC 6511773149bee334 0000 IDENTIFICATION flags=e
2018-12-27 06:22:26 avmike:VPN MCKUSCH: Phase 1 ready
2018-12-27 06:22:26 avmike:VPN MCKUSCH: current=(IP pfsense) new=(IP pfsense)
2018-12-27 06:22:26 avmike:VPN MCKUSCH: start waiting connections
2018-12-27 06:22:26 avmike:VPN MCKUSCH: Phase 2 starting (start waiting)
2018-12-27 06:22:26 avmike:>>> quickmode [(IP pfsense)] VPN MCKUSCH: V1.0 508 IC 6872414bef8f5559 RC 6511773149bee334 9a91fdf1 HASH flags=e
2018-12-27 06:22:26 avmike:<<< quickmode[(IP pfsense)] VPN MCKUSCH: V1.0 444 IC 6872414bef8f5559 RC 6511773149bee334 9a91fdf1 HASH flags=e
2018-12-27 06:22:27 avmike:>>> quickmode [(IP pfsense)] VPN MCKUSCH: V1.0 60 IC 6872414bef8f5559 RC 6511773149bee334 9a91fdf1 HASH flags=e
2018-12-27 06:22:27 avmike:VPN MCKUSCH: Phase 2 ready
2018-12-27 06:22:27 avmike:NEW Phase 2 SA: ESP-AES-256/SHA1 SPI: 86D44AE1 LT: 3600 I/O: IN
2018-12-27 06:22:27 avmike:NEW Phase 2 SA: ESP-AES-256/SHA1 SPI: C2365320 LT: 3600 I/O: OUT
2018-12-27 06:22:27 avmike:< cb_sa_created(name=VPN MCKUSCH,id=187,...,flags=0x00002101)
2018-12-27 06:22:27 avmike:VPN MCKUSCH: start waiting connections
2018-12-27 06:22:27 avmike:VPN MCKUSCH: NO waiting connections
2018-12-27 06:22:37 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 6872414bef8f5559 RC 6511773149bee334 a8fa1dd1 HASH flags=e
2018-12-27 06:22:37 avmike:>r> infomode [(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 6872414bef8f5559 RC 6511773149bee334 a8fa1dd1 HASH flags=e
2018-12-27 06:22:47 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 6872414bef8f5559 RC 6511773149bee334 2b5f8cc7 HASH flags=e
2018-12-27 06:22:57 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 6872414bef8f5559 RC 6511773149bee334 2549e835 HASH flags=e
2018-12-27 06:23:07 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 6872414bef8f5559 RC 6511773149bee334 751f7fab HASH flags=e
2018-12-27 06:23:17 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 6872414bef8f5559 RC 6511773149bee334 2c07e412 HASH flags=e
2018-12-27 06:23:27 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 6872414bef8f5559 RC 6511773149bee334 279a5e57 HASH flags=e
2018-12-27 06:28:25 avmike:VPN MCKUSCH: del phase 1 SA 187
2018-12-27 06:28:26 avmike:< delete_sa(appl=dsld,cname=VPN MCKUSCH,id=186,what=7,reason=Lifetime expired)
2018-12-27 06:28:26 avmike:FreeIPsecSA: spi=4750E80D protocol=3 iotype=1
2018-12-27 06:28:26 avmike:FreeIPsecSA: spi=C8CD6F95 protocol=3 iotype=2
2018-12-27 06:55:18 avmike:>r> infomode [(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 6872414bef8f5559 RC 6511773149bee334 2c1e5ef7 HASH flags=e
2018-12-27 07:16:26 avmike:wolke_neighbour_renew_sa 1 SAs
2018-12-27 07:16:26 avmike:>>> identity protection mode [(IP pfsense)] VPN MCKUSCH: V1.0 220 IC 928c71fe2ff76662 RC 00000000 0000 SA flags=
2018-12-27 07:16:26 avmike:<<< identity protection mode[(IP pfsense)] VPN MCKUSCH: V1.0 116 IC 928c71fe2ff76662 RC 8bac593a23c18ae1 0000 SA flags=
2018-12-27 07:16:26 avmike:identity protection mode VPN MCKUSCH: selected lifetime: 3600 sec(no notify)
2018-12-27 07:16:26 avmike:VPN MCKUSCH receive VENDOR ID Payload: XAUTH
2018-12-27 07:16:26 avmike:VPN MCKUSCH receive VENDOR ID Payload: DPD
2018-12-27 07:16:26 avmike:>>> identity protection mode [(IP pfsense)] VPN MCKUSCH: V1.0 308 IC 928c71fe2ff76662 RC 8bac593a23c18ae1 0000 KEY flags=
2018-12-27 07:16:27 avmike:< create_sa(appl=dsld,cname=VPN MCKUSCH)
2018-12-27 07:16:27 avmike:VPN MCKUSCH: Phase 2 waiting
2018-12-27 07:16:28 avmike:>r> identity protection mode [(IP pfsense)] VPN MCKUSCH: V1.0 308 IC 928c71fe2ff76662 RC 8bac593a23c18ae1 0000 KEY flags=
2018-12-27 07:16:28 avmike:<<< identity protection mode[(IP pfsense)] VPN MCKUSCH: V1.0 324 IC 928c71fe2ff76662 RC 8bac593a23c18ae1 0000 KEY flags=
2018-12-27 07:16:29 avmike:VPN MCKUSCH: add phase 1 SA: DH14/AES-256/SHA1/3600sec id:189
2018-12-27 07:16:29 avmike:>>> identity protection mode [(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 928c71fe2ff76662 RC 8bac593a23c18ae1 0000 IDENTIFICATION flags=e
2018-12-27 07:16:29 avmike:<<< identity protection mode[(IP pfsense)] VPN MCKUSCH: V1.0 76 IC 928c71fe2ff76662 RC 8bac593a23c18ae1 0000 IDENTIFICATION flags=e
2018-12-27 07:16:29 avmike:VPN MCKUSCH: Phase 1 ready
2018-12-27 07:16:29 avmike:VPN MCKUSCH: current=(IP pfsense) new=(IP pfsense)
2018-12-27 07:16:29 avmike:VPN MCKUSCH: start waiting connections
2018-12-27 07:16:29 avmike:VPN MCKUSCH: Phase 2 starting (start waiting)
2018-12-27 07:16:29 avmike:>>> quickmode [(IP pfsense)] VPN MCKUSCH: V1.0 508 IC 928c71fe2ff76662 RC 8bac593a23c18ae1 2bf7fa9 HASH flags=e
2018-12-27 07:16:29 avmike:<<< quickmode[(IP pfsense)] VPN MCKUSCH: V1.0 444 IC 928c71fe2ff76662 RC 8bac593a23c18ae1 2bf7fa9 HASH flags=e
2018-12-27 07:16:29 avmike:>>> quickmode [(IP pfsense)] VPN MCKUSCH: V1.0 60 IC 928c71fe2ff76662 RC 8bac593a23c18ae1 2bf7fa9 HASH flags=e
2018-12-27 07:16:29 avmike:VPN MCKUSCH: Phase 2 ready
2018-12-27 07:16:29 avmike:NEW Phase 2 SA: ESP-AES-256/SHA1 SPI: CBD62308 LT: 3600 I/O: IN
2018-12-27 07:16:29 avmike:NEW Phase 2 SA: ESP-AES-256/SHA1 SPI: C05403E4 LT: 3600 I/O: OUT
2018-12-27 07:16:29 avmike:< cb_sa_created(name=VPN MCKUSCH,id=188,...,flags=0x00002101)
2018-12-27 07:16:29 avmike:VPN MCKUSCH: start waiting connections
2018-12-27 07:16:29 avmike:VPN MCKUSCH: NO waiting connections
2018-12-27 07:16:40 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 928c71fe2ff76662 RC 8bac593a23c18ae1 2b4fccd5 HASH flags=e
2018-12-27 07:16:40 avmike:>r> infomode [(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 928c71fe2ff76662 RC 8bac593a23c18ae1 2b4fccd5 HASH flags=e
2018-12-27 07:16:50 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 928c71fe2ff76662 RC 8bac593a23c18ae1 f64d9069 HASH flags=e
2018-12-27 07:17:00 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 928c71fe2ff76662 RC 8bac593a23c18ae1 9a87db77 HASH flags=e
2018-12-27 07:17:10 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 928c71fe2ff76662 RC 8bac593a23c18ae1 69880609 HASH flags=e
2018-12-27 07:17:20 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 928c71fe2ff76662 RC 8bac593a23c18ae1 51824bd9 HASH flags=e
2018-12-27 07:17:30 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 928c71fe2ff76662 RC 8bac593a23c18ae1 bf9c6d0f HASH flags=e
2018-12-27 07:17:48 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 928c71fe2ff76662 RC 8bac593a23c18ae1 7a749f0 HASH flags=e
2018-12-27 07:17:58 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 928c71fe2ff76662 RC 8bac593a23c18ae1 65e2e2ed HASH flags=e
2018-12-27 07:18:08 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 928c71fe2ff76662 RC 8bac593a23c18ae1 bf211ecc HASH flags=e
2018-12-27 07:18:18 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 928c71fe2ff76662 RC 8bac593a23c18ae1 96681b4f HASH flags=e
2018-12-27 07:18:28 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 928c71fe2ff76662 RC 8bac593a23c18ae1 f62169fb HASH flags=e
2018-12-27 07:22:26 avmike:VPN MCKUSCH: del phase 1 SA 188
2018-12-27 07:22:27 avmike:< delete_sa(appl=dsld,cname=VPN MCKUSCH,id=187,what=7,reason=Lifetime expired)
2018-12-27 07:22:27 avmike:FreeIPsecSA: spi=86D44AE1 protocol=3 iotype=1
2018-12-27 07:22:27 avmike:FreeIPsecSA: spi=C2365320 protocol=3 iotype=2
2018-12-27 07:22:50 avmike:< cb_sa_deleted(name=VPN MCKUSCH,id=188,what=3)
2018-12-27 07:22:50 avmike:>r> infomode [(IP pfsense)] VPN MCKUSCH: V1.0 76 IC 928c71fe2ff76662 RC 8bac593a23c18ae1 5812faab HASH flags=e
2018-12-27 07:22:50 avmike:FreeIPsecSA: spi=CBD62308 protocol=3 iotype=1
2018-12-27 07:22:50 avmike:>r> infomode [(IP pfsense)] VPN MCKUSCH: V1.0 76 IC 928c71fe2ff76662 RC 8bac593a23c18ae1 498d3042 HASH flags=e
2018-12-27 07:22:50 avmike:FreeIPsecSA: spi=C05403E4 protocol=3 iotype=2
2018-12-27 07:22:50 avmike:>r> infomode [(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 928c71fe2ff76662 RC 8bac593a23c18ae1 b0282d8d HASH flags=e
2018-12-27 07:22:50 avmike:VPN MCKUSCH: del phase 1 SA 189
2018-12-27 07:22:55 avmike:< add(appl=dsld,cname=VPN MCKUSCH,localip=(IP Fritzbox), remoteip=255.255.255.255, p1ss=dh14/aes/sha, p2ss=esp-aes256-3des-sha/ah-no/comp-lzs-no/pfs p1mode=2 keepalive_ip=0.0.0.0 flags=0x40001 tunnel no_xauth no_cfgmode no_nat_t no_certsrv_server_auth)
2018-12-27 07:22:55 avmike:new neighbour VPN MCKUSCH:
2018-12-27 07:22:55 avmike:< create_sa(appl=dsld,cname=VPN MCKUSCH)
2018-12-27 07:22:55 avmike:VPN MCKUSCH: Phase 1 starting
2018-12-27 07:22:55 avmike:>>> identity protection mode [(IP pfsense)] VPN MCKUSCH: V1.0 220 IC 83b4f0f722b753b4 RC 00000000 0000 SA flags=
2018-12-27 07:22:55 avmike:VPN MCKUSCH: Warning: source changed from 0.0.0.0:500 to (IP pfsense):500
2018-12-27 07:22:55 avmike:<<< identity protection mode[(IP pfsense)] VPN MCKUSCH: V1.0 116 IC 83b4f0f722b753b4 RC 84484486b407c0a8 0000 SA flags=
2018-12-27 07:22:55 avmike:identity protection mode VPN MCKUSCH: selected lifetime: 3600 sec(no notify)
2018-12-27 07:22:55 avmike:VPN MCKUSCH receive VENDOR ID Payload: XAUTH
2018-12-27 07:22:55 avmike:VPN MCKUSCH receive VENDOR ID Payload: DPD
2018-12-27 07:22:55 avmike:>>> identity protection mode [(IP pfsense)] VPN MCKUSCH: V1.0 308 IC 83b4f0f722b753b4 RC 84484486b407c0a8 0000 KEY flags=
2018-12-27 07:22:56 avmike:VPN MCKUSCH: Warning: source changed from 0.0.0.0:500 to (IP pfsense):500
2018-12-27 07:22:56 avmike:<<< identity protection mode[(IP pfsense)] VPN MCKUSCH: V1.0 324 IC 83b4f0f722b753b4 RC 84484486b407c0a8 0000 KEY flags=
2018-12-27 07:22:56 avmike:VPN MCKUSCH: add phase 1 SA: DH14/AES-256/SHA1/3600sec id:1
2018-12-27 07:22:56 avmike:>>> identity protection mode [(IP pfsense)] VPN MCKUSCH: V1.0 108 IC 83b4f0f722b753b4 RC 84484486b407c0a8 0000 IDENTIFICATION flags=e
2018-12-27 07:22:56 avmike:VPN MCKUSCH: Warning: source changed from 0.0.0.0:500 to (IP pfsense):500
2018-12-27 07:22:56 avmike:<<< identity protection mode[(IP pfsense)] VPN MCKUSCH: V1.0 76 IC 83b4f0f722b753b4 RC 84484486b407c0a8 0000 IDENTIFICATION flags=e
2018-12-27 07:22:56 avmike:VPN MCKUSCH: Phase 1 ready
2018-12-27 07:22:56 avmike:VPN MCKUSCH: current=0.0.0.0 new=(IP pfsense)
2018-12-27 07:22:56 avmike:VPN MCKUSCH: no valid sa, reseting initialcontactdone flag
2018-12-27 07:22:56 avmike:VPN MCKUSCH: sending initial contact message
2018-12-27 07:22:56 avmike:>r> infomode [(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 83b4f0f722b753b4 RC 84484486b407c0a8 940ec48 HASH flags=e
2018-12-27 07:22:56 avmike:VPN MCKUSCH: start waiting connections
2018-12-27 07:22:56 avmike:VPN MCKUSCH: Phase 2 starting (start waiting)
2018-12-27 07:22:56 avmike:>>> quickmode [(IP pfsense)] VPN MCKUSCH: V1.0 508 IC 83b4f0f722b753b4 RC 84484486b407c0a8 bb9dcb6a HASH flags=e
2018-12-27 07:22:56 avmike:<<< quickmode[(IP pfsense)] VPN MCKUSCH: V1.0 444 IC 83b4f0f722b753b4 RC 84484486b407c0a8 bb9dcb6a HASH flags=e
2018-12-27 07:22:56 avmike:>>> quickmode [(IP pfsense)] VPN MCKUSCH: V1.0 60 IC 83b4f0f722b753b4 RC 84484486b407c0a8 bb9dcb6a HASH flags=e
2018-12-27 07:22:56 avmike:VPN MCKUSCH: Phase 2 ready
2018-12-27 07:22:56 avmike:NEW Phase 2 SA: ESP-AES-256/SHA1 SPI: 59C898BB LT: 3600 I/O: IN
2018-12-27 07:22:56 avmike:NEW Phase 2 SA: ESP-AES-256/SHA1 SPI: C9FC517F LT: 3600 I/O: OUT
2018-12-27 07:22:56 avmike:< cb_sa_created(name=VPN MCKUSCH,id=1,...,flags=0x00002101)
2018-12-27 07:22:56 avmike:VPN MCKUSCH: start waiting connections
2018-12-27 07:22:56 avmike:VPN MCKUSCH: NO waiting connections
2018-12-27 07:23:07 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 83b4f0f722b753b4 RC 84484486b407c0a8 cd4fbd83 HASH flags=e
2018-12-27 07:23:07 avmike:>r> infomode [(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 83b4f0f722b753b4 RC 84484486b407c0a8 cd4fbd83 HASH flags=e
2018-12-27 07:25:40 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 83b4f0f722b753b4 RC 84484486b407c0a8 e17cc7d6 HASH flags=e
2018-12-27 07:25:50 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 83b4f0f722b753b4 RC 84484486b407c0a8 e6b964ba HASH flags=e
2018-12-27 07:26:00 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 83b4f0f722b753b4 RC 84484486b407c0a8 4d99e03e HASH flags=e
2018-12-27 07:26:16 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 83b4f0f722b753b4 RC 84484486b407c0a8 40692e24 HASH flags=e
2018-12-27 07:26:26 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 83b4f0f722b753b4 RC 84484486b407c0a8 5a1176a4 HASH flags=e
2018-12-27 07:26:40 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 83b4f0f722b753b4 RC 84484486b407c0a8 e4d053b9 HASH flags=e
2018-12-27 07:26:50 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 83b4f0f722b753b4 RC 84484486b407c0a8 fc62b165 HASH flags=e
2018-12-27 07:27:00 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 83b4f0f722b753b4 RC 84484486b407c0a8 5767b485 HASH flags=e
2018-12-27 07:27:10 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 83b4f0f722b753b4 RC 84484486b407c0a8 15a82a23 HASH flags=e
2018-12-27 07:27:20 avmike:<<< infomode[(IP pfsense)] VPN MCKUSCH: V1.0 92 IC 83b4f0f722b753b4 RC 84484486b407c0a8 200be361 HASH flags=e

kuschi

I had another opportunity to test the connections from the side of the Fritzbox and from the side of the pfsense box:

pfsense box shows connection inactive, Fritzbox shows connection active: traffic direction from Fritzbox to pfsense works, e.g. ping / trace route. pfsense box changes status to connection active
pfsense box shows connection inactive, Fritzbox shows connection active: traffic direction from pfsense box to Fritzbox does not work. Traffic times out, ping/ trace route shows no result

kuschi

Any news from anybody regarding this issue? I still have troubles with dropping connections.

Thanks,
Martin

defender110

@kuschi Still no solution? I am on 2.4.5 and the problem persists.

kuschi

@defender110 Still no solution. I am on 2.4.5 too and I, too, still have the same problem. The Fritzbox connects successful but pfSense shows the connection as "inactive" after a while. The clients on the Fritzbox side, however, can still reach their targets on pfSense's side but not the other way round.

defender110

@kuschi Thank You! Well...then the Fritz!Box will have to go and be replaced by a pfSense box. Just have to figure out how to make the Fritz do the phone duties behind the pfSense.

NOCling

I got it stable only with Aggressive Mode, Tunel endpoint is a 6490.
Otherwise my Tunnel crash after some time and dont com up again.
I hope AVM react on the feature request to upgrade the vpn features.

kuschi

How did you get it stable in Aggressive Mode? Could you please share your config? Thanks!

NOCling

Phase 1:

IKEv1
IPv4
PSK
Aggressiv
Distinguished name
Distinguished name
PSK Generate by pfSense
AES 256 SHA512 DH2
DPD on

Phase 2:
IPv4
NAT None
ESP
AES 236
SHA1
PFS Key Group 2
Lifetime 3600

However, a new Netgate has been ordered and replace the Fritz shortly.