Site To Site VPN between pfsense sometimes fails
-
Hello everyone i have 2 pfsense servers and ipsec vpn connection between them everything works fine but sometimes once a week or once in 10 days vpn tunnels cant connect. Here are logs and configuration.
P.S i replaced IP adressesApr 14 17:09:10 charon 70464 12[KNL] creating acquire job for policy 1.1.1.1/32|/0 === 2.2.2.2/32|/0 with reqid {1} Apr 14 17:09:10 charon 70464 12[IKE] <con4|373> queueing ISAKMP_VENDOR task Apr 14 17:09:10 charon 70464 12[IKE] <con4|373> queueing ISAKMP_CERT_PRE task Apr 14 17:09:10 charon 70464 12[IKE] <con4|373> queueing MAIN_MODE task Apr 14 17:09:10 charon 70464 12[IKE] <con4|373> queueing ISAKMP_CERT_POST task Apr 14 17:09:10 charon 70464 12[IKE] <con4|373> queueing ISAKMP_NATD task Apr 14 17:09:10 charon 70464 12[IKE] <con4|373> queueing QUICK_MODE task Apr 14 17:09:10 charon 70464 12[IKE] <con4|373> activating new tasks Apr 14 17:09:10 charon 70464 12[IKE] <con4|373> activating ISAKMP_VENDOR task Apr 14 17:09:10 charon 70464 12[IKE] <con4|373> activating ISAKMP_CERT_PRE task Apr 14 17:09:10 charon 70464 12[IKE] <con4|373> activating MAIN_MODE task Apr 14 17:09:10 charon 70464 12[IKE] <con4|373> activating ISAKMP_CERT_POST task Apr 14 17:09:10 charon 70464 12[IKE] <con4|373> activating ISAKMP_NATD task Apr 14 17:09:10 charon 70464 12[IKE] <con4|373> sending XAuth vendor ID Apr 14 17:09:10 charon 70464 12[IKE] <con4|373> sending DPD vendor ID Apr 14 17:09:10 charon 70464 12[IKE] <con4|373> sending FRAGMENTATION vendor ID Apr 14 17:09:10 charon 70464 12[IKE] <con4|373> sending NAT-T (RFC 3947) vendor ID Apr 14 17:09:10 charon 70464 12[IKE] <con4|373> sending draft-ietf-ipsec-nat-t-ike-02\n vendor ID Apr 14 17:09:10 charon 70464 12[IKE] <con4|373> initiating Main Mode IKE_SA con4[373] to 2.2.2.2 Apr 14 17:09:10 charon 70464 12[IKE] <con4|373> IKE_SA con4[373] state change: CREATED => CONNECTING Apr 14 17:09:10 charon 70464 12[CFG] <con4|373> configured proposals: IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1536 Apr 14 17:09:10 charon 70464 12[ENC] <con4|373> generating ID_PROT request 0 [ SA V V V V V ] Apr 14 17:09:10 charon 70464 12[NET] <con4|373> sending packet: from 1.1.1.1[500] to 2.2.2.2[500] (176 bytes) Apr 14 17:09:10 charon 70464 03[NET] error writing to socket: Permission denied Apr 14 17:09:12 charon 70464 11[KNL] creating acquire job for policy 1.1.1.1/32|/0 === 2.2.2.2/32|/0 with reqid {1} Apr 14 17:09:12 charon 70464 11[CFG] ignoring acquire, connection attempt pending Apr 14 17:09:15 charon 70464 13[IKE] <con4|373> sending retransmit 1 of request message ID 0, seq 1 Apr 14 17:09:15 charon 70464 13[NET] <con4|373> sending packet: from 1.1.1.1[500] to 2.2.2.2[500] (176 bytes) Apr 14 17:09:15 charon 70464 03[NET] error writing to socket: Permission denied Apr 14 17:09:23 charon 70464 07[IKE] <con4|373> sending retransmit 2 of request message ID 0, seq 1 Apr 14 17:09:23 charon 70464 07[NET] <con4|373> sending packet: from 1.1.1.1[500] to 2.2.2.2[500] (176 bytes) Apr 14 17:09:23 charon 70464 03[NET] error writing to socket: Permission denied Apr 14 17:09:23 charon 70464 07[CFG] vici client 2527 connected Apr 14 17:09:23 charon 70464 10[CFG] vici client 2527 registered for: list-sa Apr 14 17:09:23 charon 70464 10[CFG] vici client 2527 requests: list-sas Apr 14 17:09:23 charon 70464 10[CFG] vici client 2527 disconnected Apr 14 17:09:34 charon 70464 15[KNL] creating acquire job for policy 1.1.1.1/32|/0 === 2.2.2.2/32|/0 with reqid {1} Apr 14 17:09:34 charon 70464 15[CFG] ignoring acquire, connection attempt pending Apr 14 17:09:36 charon 70464 15[IKE] <con4|373> sending retransmit 3 of request message ID 0, seq 1 Apr 14 17:09:36 charon 70464 15[NET] <con4|373> sending packet: from 1.1.1.1[500] to 2.2.2.2[500] (176 bytes) Apr 14 17:09:36 charon 70464 03[NET] error writing to socket: Permission denied Apr 14 17:09:38 charon 70464 06[CFG] vici client 2528 connected Apr 14 17:09:38 charon 70464 15[CFG] vici client 2528 registered for: list-sa Apr 14 17:09:38 charon 70464 06[CFG] vici client 2528 requests: list-sas Apr 14 17:09:38 charon 70464 05[CFG] vici client 2528 disconnected Apr 14 17:09:40 charon 70464 05[KNL] creating acquire job for policy 1.1.1.1/32|/0 === 2.2.2.2/32|/0 with reqid {1} Apr 14 17:09:40 charon 70464 06[CFG] ignoring acquire, connection attempt pending Apr 14 17:09:43 charon 70464 05[KNL] creating acquire job for policy 1.1.1.1/32|/0 === 2.2.2.2/32|/0 with reqid {1} Apr 14 17:09:43 charon 70464 05[CFG] ignoring acquire, connection attempt pending Apr 14 17:09:53 charon 70464 12[CFG] vici client 2529 connected Apr 14 17:09:53 charon 70464 12[CFG] vici client 2529 registered for: list-sa Apr 14 17:09:53 charon 70464 12[CFG] vici client 2529 requests: list-sas Apr 14 17:09:53 charon 70464 11[CFG] vici client 2529 disconnected Apr 14 17:10:00 charon 70464 13[IKE] <con4|373> sending retransmit 4 of request message ID 0, seq 1 Apr 14 17:10:00 charon 70464 13[NET] <con4|373> sending packet: from 1.1.1.1[500] to 2.2.2.2[500] (176 bytes) Apr 14 17:10:00 charon 70464 03[NET] error writing to socket: Permission denied Apr 14 17:10:06 charon 70464 13[KNL] creating acquire job for policy 1.1.1.1/32|/0 === 2.2.2.2/32|/0 with reqid {1} Apr 14 17:10:06 charon 70464 13[CFG] ignoring acquire, connection attempt pending Apr 14 17:10:10 charon 70464 13[KNL] creating acquire job for policy 1.1.1.1/32|/0 === 2.2.2.2/32|/0 with reqid {1} Apr 14 17:10:10 charon 70464 13[CFG] ignoring acquire, connection attempt pending Apr 14 17:10:26 charon 70464 13[CFG] vici client 2530 connected Apr 14 17:10:26 charon 70464 13[CFG] vici client 2530 registered for: list-sa Apr 14 17:10:26 charon 70464 07[CFG] vici client 2530 requests: list-sas Apr 14 17:10:26 charon 70464 07[CFG] vici client 2530 disconnected Apr 14 17:10:32 charon 70464 10[KNL] creating acquire job for policy 1.1.1.1/32|/0 === 2.2.2.2/32|/0 with reqid {1} Apr 14 17:10:32 charon 70464 10[CFG] ignoring acquire, connection attempt pending Apr 14 17:10:38 charon 70464 04[KNL] creating acquire job for policy 1.1.1.1/32|/0 === 2.2.2.2/32|/0 with reqid {1} Apr 14 17:10:38 charon 70464 15[CFG] ignoring acquire, connection attempt pending Apr 14 17:10:41 charon 70464 04[CFG] vici client 2531 connected Apr 14 17:10:41 charon 70464 15[CFG] vici client 2531 registered for: list-sa Apr 14 17:10:41 charon 70464 06[CFG] vici client 2531 requests: list-sas Apr 14 17:10:41 charon 70464 06[CFG] vici client 2531 disconnected Apr 14 17:10:43 charon 70464 06[IKE] <con4|373> sending retransmit 5 of request message ID 0, seq 1 Apr 14 17:10:43 charon 70464 06[NET] <con4|373> sending packet: from 1.1.1.1[500] to 2.2.2.2[500] (176 bytes) Apr 14 17:10:43 charon 70464 03[NET] error writing to socket: Permission denied Apr 14 17:10:48 charon 70464 04[KNL] creating acquire job for policy 1.1.1.1/32|/0 === 2.2.2.2/32|/0 with reqid {1} Apr 14 17:10:48 charon 70464 04[CFG] ignoring acquire, connection attempt pending Apr 14 17:10:58 charon 70464 05[CFG] vici client 2532 connected Apr 14 17:10:58 charon 70464 12[CFG] vici client 2532 registered for: list-sa Apr 14 17:10:58 charon 70464 12[CFG] vici client 2532 requests: list-sas Apr 14 17:10:58 charon 70464 12[CFG] vici client 2532 disconnected Apr 14 17:10:58 charon 70464 12[NET] <374> received packet: from 2.2.2.2[500] to 1.1.1.1[500] (176 bytes) Apr 14 17:10:58 charon 70464 12[ENC] <374> parsed ID_PROT request 0 [ SA V V V V V ] Apr 14 17:10:58 charon 70464 12[CFG] <374> looking for an IKEv1 config for 1.1.1.1...2.2.2.2 Apr 14 17:10:58 charon 70464 12[CFG] <374> candidate: 0.0.0.0/0, ::/0...0.0.0.0/0, ::/0, prio 28 Apr 14 17:10:58 charon 70464 12[CFG] <374> candidate: 1.1.1.1...2.2.2.2, prio 3100 Apr 14 17:10:58 charon 70464 12[CFG] <374> found matching ike config: 1.1.1.1...2.2.2.2 with prio 3100 Apr 14 17:10:58 charon 70464 12[IKE] <374> local endpoint changed from 0.0.0.0[500] to 1.1.1.1[500] Apr 14 17:10:58 charon 70464 12[IKE] <374> remote endpoint changed from 0.0.0.0 to 2.2.2.2[500] Apr 14 17:10:58 charon 70464 12[IKE] <374> received XAuth vendor ID Apr 14 17:10:58 charon 70464 12[IKE] <374> received DPD vendor ID Apr 14 17:10:58 charon 70464 12[IKE] <374> received FRAGMENTATION vendor ID Apr 14 17:10:58 charon 70464 12[IKE] <374> received NAT-T (RFC 3947) vendor ID Apr 14 17:10:58 charon 70464 12[IKE] <374> received draft-ietf-ipsec-nat-t-ike-02\n vendor ID Apr 14 17:10:58 charon 70464 12[IKE] <374> 2.2.2.2 is initiating a Main Mode IKE_SA Apr 14 17:10:58 charon 70464 12[IKE] <374> IKE_SA (unnamed)[374] state change: CREATED => CONNECTING Apr 14 17:10:58 charon 70464 12[CFG] <374> selecting proposal: Apr 14 17:10:58 charon 70464 12[CFG] <374> proposal matches Apr 14 17:10:58 charon 70464 12[CFG] <374> received proposals: IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1536 Apr 14 17:10:58 charon 70464 12[CFG] <374> configured proposals: IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1536 Apr 14 17:10:58 charon 70464 12[CFG] <374> selected proposal: IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1536 Apr 14 17:10:58 charon 70464 12[IKE] <374> sending XAuth vendor ID Apr 14 17:10:58 charon 70464 12[IKE] <374> sending DPD vendor ID Apr 14 17:10:58 charon 70464 12[IKE] <374> sending FRAGMENTATION vendor ID Apr 14 17:10:58 charon 70464 12[IKE] <374> sending NAT-T (RFC 3947) vendor ID Apr 14 17:10:58 charon 70464 12[ENC] <374> generating ID_PROT response 0 [ SA V V V V ] Apr 14 17:10:58 charon 70464 12[NET] <374> sending packet: from 1.1.1.1[500] to 2.2.2.2[500] (156 bytes) Apr 14 17:10:58 charon 70464 12[NET] <374> received packet: from 2.2.2.2[500] to 1.1.1.1[500] (308 bytes) Apr 14 17:10:58 charon 70464 12[ENC] <374> parsed ID_PROT request 0 [ KE No NAT-D NAT-D ] Apr 14 17:10:58 charon 70464 12[CFG] <374> candidate "con-mobile", match: 1/1/28 (me/other/ike) Apr 14 17:10:58 charon 70464 12[CFG] <374> candidate "con4", match: 1/1/3100 (me/other/ike) Apr 14 17:10:58 charon 70464 12[ENC] <374> generating ID_PROT response 0 [ KE No NAT-D NAT-D ] Apr 14 17:10:58 charon 70464 12[NET] <374> sending packet: from 1.1.1.1[500] to 2.2.2.2[500] (308 bytes) Apr 14 17:10:58 charon 70464 12[NET] <374> received packet: from 2.2.2.2[500] to 1.1.1.1[500] (100 bytes) Apr 14 17:10:58 charon 70464 12[ENC] <374> parsed ID_PROT request 0 [ ID HASH N(INITIAL_CONTACT) ] Apr 14 17:10:58 charon 70464 12[CFG] <374> looking for pre-shared key peer configs matching 1.1.1.1...2.2.2.2[2.2.2.2] Apr 14 17:10:58 charon 70464 12[CFG] <374> candidate "con-mobile", match: 1/1/28 (me/other/ike) Apr 14 17:10:58 charon 70464 12[CFG] <374> candidate "con4", match: 1/20/3100 (me/other/ike) Apr 14 17:10:58 charon 70464 12[CFG] <374> selected peer config "con4" Apr 14 17:10:58 charon 70464 12[IKE] <con4|374> IKE_SA con4[374] established between 1.1.1.1[1.1.1.1]...2.2.2.2[2.2.2.2] Apr 14 17:10:58 charon 70464 12[IKE] <con4|374> IKE_SA con4[374] state change: CONNECTING => ESTABLISHED Apr 14 17:10:58 charon 70464 12[IKE] <con4|374> scheduling reauthentication in 25238s Apr 14 17:10:58 charon 70464 12[IKE] <con4|374> maximum IKE_SA lifetime 28118s Apr 14 17:10:58 charon 70464 12[ENC] <con4|374> generating ID_PROT response 0 [ ID HASH ] Apr 14 17:10:58 charon 70464 12[NET] <con4|374> sending packet: from 1.1.1.1[500] to 2.2.2.2[500] (68 bytes) Apr 14 17:10:58 charon 70464 05[NET] <con4|374> received packet: from 2.2.2.2[500] to 1.1.1.1[500] (172 bytes) Apr 14 17:10:58 charon 70464 05[ENC] <con4|374> parsed QUICK_MODE request 3264393138 [ HASH SA No ID ID ] Apr 14 17:10:58 charon 70464 05[CFG] <con4|374> looking for a child config for 10.123.0.0/16|/0 === 10.122.0.0/16|/0 Apr 14 17:10:58 charon 70464 05[CFG] <con4|374> proposing traffic selectors for us: Apr 14 17:10:58 charon 70464 05[CFG] <con4|374> 10.123.0.0/16|/0 Apr 14 17:10:58 charon 70464 05[CFG] <con4|374> proposing traffic selectors for other: Apr 14 17:10:58 charon 70464 05[CFG] <con4|374> 10.122.0.0/16|/0 Apr 14 17:10:58 charon 70464 05[CFG] <con4|374> candidate "con4_4" with prio 5+5 Apr 14 17:10:58 charon 70464 05[CFG] <con4|374> found matching child config "con4_4" with prio 10 Apr 14 17:10:58 charon 70464 05[CFG] <con4|374> selecting traffic selectors for other: Apr 14 17:10:58 charon 70464 05[CFG] <con4|374> config: 10.122.0.0/16|/0, received: 10.122.0.0/16|/0 => match: 10.122.0.0/16|/0 Apr 14 17:10:58 charon 70464 05[CFG] <con4|374> selecting traffic selectors for us: Apr 14 17:10:58 charon 70464 05[CFG] <con4|374> config: 10.123.0.0/16|/0, received: 10.123.0.0/16|/0 => match: 10.123.0.0/16|/0 Apr 14 17:10:58 charon 70464 05[CFG] <con4|374> selecting proposal: Apr 14 17:10:58 charon 70464 05[CFG] <con4|374> no acceptable ENCRYPTION_ALGORITHM found Apr 14 17:10:58 charon 70464 05[CFG] <con4|374> selecting proposal: Apr 14 17:10:58 charon 70464 05[CFG] <con4|374> no acceptable ENCRYPTION_ALGORITHM found Apr 14 17:10:58 charon 70464 05[CFG] <con4|374> selecting proposal: Apr 14 17:10:58 charon 70464 05[CFG] <con4|374> no acceptable ENCRYPTION_ALGORITHM found Apr 14 17:10:58 charon 70464 05[CFG] <con4|374> selecting proposal: Apr 14 17:10:58 charon 70464 05[CFG] <con4|374> no acceptable ENCRYPTION_ALGORITHM found Apr 14 17:10:58 charon 70464 05[CFG] <con4|374> selecting proposal: Apr 14 17:10:58 charon 70464 05[CFG] <con4|374> no acceptable ENCRYPTION_ALGORITHM found Apr 14 17:10:58 charon 70464 05[CFG] <con4|374> selecting proposal: Apr 14 17:10:58 charon 70464 05[CFG] <con4|374> no acceptable ENCRYPTION_ALGORITHM found Apr 14 17:10:58 charon 70464 05[CFG] <con4|374> selecting proposal: Apr 14 17:10:58 charon 70464 05[CFG] <con4|374> proposal matches Apr 14 17:10:58 charon 70464 05[CFG] <con4|374> received proposals: ESP:3DES_CBC/HMAC_SHA1_96/NO_EXT_SEQ Apr 14 17:10:58 charon 70464 05[CFG] <con4|374> configured proposals: ESP:AES_GCM_16_128/NO_EXT_SEQ, ESP:AES_GCM_12_128/NO_EXT_SEQ, ESP:AES_GCM_8_128/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA1_96/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA1_96/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/NO_EXT_SEQ, ESP:3DES_CBC/HMAC_SHA1_96/NO_EXT_SEQ Apr 14 17:10:58 charon 70464 05[CFG] <con4|374> selected proposal: ESP:3DES_CBC/HMAC_SHA1_96/NO_EXT_SEQ Apr 14 17:10:58 charon 70464 05[ENC] <con4|374> generating QUICK_MODE response 3264393138 [ HASH SA No ID ID ] Apr 14 17:10:58 charon 70464 05[NET] <con4|374> sending packet: from 1.1.1.1[500] to 2.2.2.2[500] (172 bytes) Apr 14 17:10:58 charon 70464 05[NET] <con4|374> received packet: from 2.2.2.2[500] to 1.1.1.1[500] (60 bytes) Apr 14 17:10:58 charon 70464 05[ENC] <con4|374> parsed QUICK_MODE request 3264393138 [ HASH ] Apr 14 17:10:58 charon 70464 05[CHD] <con4|374> CHILD_SA con4_4{243} state change: CREATED => INSTALLING Apr 14 17:10:58 charon 70464 05[CHD] <con4|374> using 3DES_CBC for encryption Apr 14 17:10:58 charon 70464 05[CHD] <con4|374> using HMAC_SHA1_96 for integrity Apr 14 17:10:58 charon 70464 05[CHD] <con4|374> adding inbound ESP SA Apr 14 17:10:58 charon 70464 05[CHD] <con4|374> SPI 0xc4138b40, src 2.2.2.2 dst 1.1.1.1 Apr 14 17:10:58 charon 70464 05[CHD] <con4|374> adding outbound ESP SA Apr 14 17:10:58 charon 70464 05[CHD] <con4|374> SPI 0xc0e13d44, src 1.1.1.1 dst 2.2.2.2 Apr 14 17:10:58 charon 70464 05[IKE] <con4|374> CHILD_SA con4_4{243} established with SPIs c4138b40_i c0e13d44_o and TS 10.123.0.0/16|/0 === 10.122.0.0/16|/0 Apr 14 17:10:58 charon 70464 05[CHD] <con4|374> CHILD_SA con4_4{243} state change: INSTALLING => INSTALLED Apr 14 17:11:13 charon 70464 08[CFG] vici client 2533 connected Apr 14 17:11:13 charon 70464 07[CFG] vici client 2533 registered for: list-sa Apr 14 17:11:13 charon 70464 07[CFG] vici client 2533 requests: list-sas Apr 14 17:11:13 charon 70464 07[CFG] vici client 2533 disconnected Apr 14 17:11:14 charon 70464 07[CFG] vici client 2534 connected Apr 14 17:11:14 charon 70464 07[CFG] vici client 2534 registered for: list-sa Apr 14 17:11:14 charon 70464 13[CFG] vici client 2534 requests: list-sas Apr 14 17:11:14 charon 70464 10[CFG] vici client 2534 disconnected Apr 14 17:11:14 charon 70464 10[CFG] vici client 2535 connected Apr 14 17:11:14 charon 70464 10[CFG] vici client 2535 registered for: control-log Apr 14 17:11:14 charon 70464 13[CFG] vici client 2535 requests: terminate Apr 14 17:11:14 charon 70464 13[CFG] vici terminate IKE_SA #373 Apr 14 17:11:14 charon 70464 10[IKE] <con4|373> destroying IKE_SA in state CONNECTING without notification Apr 14 17:11:14 charon 70464 10[IKE] <con4|373> IKE_SA con4[373] state change: CONNECTING => DESTROYING Apr 14 17:11:14 charon 70464 13[CFG] vici client 2535 disconnected Apr 14 17:11:26 charon 70464 11[CFG] vici client 2536 connected Apr 14 17:11:26 charon 70464 11[CFG] vici client 2536 registered for: list-sa Apr 14 17:11:26 charon 70464 11[CFG] vici client 2536 requests: list-sas Apr 14 17:11:26 charon 70464 12[CFG] vici client 2536 disconnected Apr 14 17:11:41 charon 70464 14[CFG] vici client 2537 connected Apr 14 17:11:41 charon 70464 08[CFG] vici client 2537 registered for: list-sa Apr 14 17:11:41 charon 70464 08[CFG] vici client 2537 requests: list-sas Apr 14 17:11:41 charon 70464 14[CFG] vici client 2537 disconnected Apr 14 17:11:56 charon 70464 13[CFG] vici client 2538 connected Apr 14 17:11:56 charon 70464 15[CFG] vici client 2538 registered for: list-sa Apr 14 17:11:56 charon 70464 13[CFG] vici client 2538 requests: list-sas Apr 14 17:11:56 charon 70464 15[CFG] vici client 2538 disconnected Apr 14 17:12:11 charon 70464 06[CFG] vici client 2539 connected Apr 14 17:12:11 charon 70464 06[CFG] vici client 2539 registered for: list-sa Apr 14 17:12:11 charon 70464 05[CFG] vici client 2539 requests: list-sas Apr 14 17:12:11 charon 70464 05[CFG] vici client 2539 disconnected Apr 14 17:12:26 charon 70464 12[CFG] vici client 2540 connected Apr 14 17:12:26 charon 70464 12[CFG] vici client 2540 registered for: list-sa Apr 14 17:12:26 charon 70464 12[CFG] vici client 2540 requests: list-sas Apr 14 17:12:26 charon 70464 12[CFG] vici client 2540 disconnected