IPsec tunnel pfSense - Fortigate disconnects and reconnects



  • Hello all,

    I am experiencing a problem with an IPsec tunnel setup between a pfSense 2.4.4-p3 (public IP addess A.A.A.A) and a Fortigate (public IP address B.B.B.B).

    On pfSense side I have configured the routed-mode, with transit network defined as 172.17.17.0/30.

    The tunnel is always up and running, traffic flows properly, but from time to time, every 5 minutes, or every 30 minutes, or every a couple of hours, the IPsec disconnects, traffic stops to pass for 5to 60 seconds, and then automatically reconnects and everything works properly, until the next brief disconnnect.

    Unfortunately I have no control whatsoever on the Fortigate, so I can only provide the pfSense box.

    The same pfSense box also holds another touted-mode IPsec tunnel to another remote pfSense 2.4.4-p3 box, and, needless to say, this is rock solid and never ever loses a single ping.

    Here below you can find an excerpt from the command "clog -f /var/log/ipsec.log | grep con1000" during a brief (5 seconds) disconnect/reconnect sequence:

    Jan 31 02:27:38 MXSAL-NFW-PFS01 charon: 15[IKE] <con1000|411> sending retransmit 3 of request message ID 760932414, seq 4
    Jan 31 02:27:38 MXSAL-NFW-PFS01 charon: 15[NET] <con1000|411> sending packet: from A.A.A.A[500] to B.B.B.B[500] (460 bytes)
    
    Jan 31 02:28:01 MXSAL-NFW-PFS01 charon: 15[IKE] <con1000|411> sending retransmit 4 of request message ID 760932414, seq 4
    Jan 31 02:28:01 MXSAL-NFW-PFS01 charon: 15[NET] <con1000|411> sending packet: from A.A.A.A[500] to B.B.B.B[500] (460 bytes)
    
    Jan 31 02:28:43 MXSAL-NFW-PFS01 charon: 05[IKE] <con1000|411> sending retransmit 5 of request message ID 760932414, seq 4
    Jan 31 02:28:43 MXSAL-NFW-PFS01 charon: 05[NET] <con1000|411> sending packet: from A.A.A.A[500] to B.B.B.B[500] (460 bytes)
    
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[IKE] <con1000|411> giving up after 5 retransmits
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[IKE] <con1000|411> restarting CHILD_SA con1000
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[IKE] <con1000|411> queueing ISAKMP_VENDOR task
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[IKE] <con1000|411> queueing ISAKMP_CERT_PRE task
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[IKE] <con1000|411> queueing MAIN_MODE task
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[IKE] <con1000|411> queueing ISAKMP_CERT_POST task
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[IKE] <con1000|411> queueing ISAKMP_NATD task
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[IKE] <con1000|411> queueing QUICK_MODE task
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[IKE] <con1000|411> activating new tasks
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[IKE] <con1000|411>   activating ISAKMP_VENDOR task
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[IKE] <con1000|411>   activating ISAKMP_CERT_PRE task
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[IKE] <con1000|411>   activating MAIN_MODE task
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[IKE] <con1000|411>   activating ISAKMP_CERT_POST task
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[IKE] <con1000|411>   activating ISAKMP_NATD task
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[IKE] <con1000|411> sending XAuth vendor ID
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[IKE] <con1000|411> sending DPD vendor ID
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[IKE] <con1000|411> sending FRAGMENTATION vendor ID
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[IKE] <con1000|411> sending NAT-T (RFC 3947) vendor ID
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[IKE] <con1000|411> sending draft-ietf-ipsec-nat-t-ike-02\n vendor ID
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[IKE] <con1000|411> initiating Main Mode IKE_SA con1000[412] to B.B.B.B
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[IKE] <con1000|411> IKE_SA con1000[412] state change: CREATED => CONNECTING
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[CFG] <con1000|411> configured proposals: IKE:AES_CBC_256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_2048
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[ENC] <con1000|411> generating ID_PROT request 0 [ SA V V V V V ]
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[NET] <con1000|411> sending packet: from A.A.A.A[500] to B.B.B.B[500] (180 bytes)
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[IKE] <con1000|411> restarting CHILD_SA con1000
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[IKE] <con1000|411> queueing QUICK_MODE task
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[IKE] <con1000|411> delaying task initiation, ID_PROT exchange in progress
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[IKE] <con1000|411> restarting CHILD_SA con1000
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[IKE] <con1000|411> queueing QUICK_MODE task
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[IKE] <con1000|411> delaying task initiation, ID_PROT exchange in progress
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[CHD] <con1000|411> CHILD_SA con1000{1088} state change: CREATED => DESTROYING
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[KNL] <con1000|411> unable to delete SAD entry with SPI c29735c0: No such process (3)
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[IKE] <con1000|411> IKE_SA con1000[411] state change: ESTABLISHED => DESTROYING
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[CHD] <con1000|411> CHILD_SA con1000{1091} state change: INSTALLED => DESTROYING
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[CHD] <con1000|411> CHILD_SA con1000{1090} state change: INSTALLED => DESTROYING
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 12[CHD] <con1000|411> CHILD_SA con1000{1089} state change: INSTALLED => DESTROYING
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[NET] <con1000|412> received packet: from B.B.B.B[500] to A.A.A.A[500] (188 bytes)
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[ENC] <con1000|412> parsed ID_PROT response 0 [ SA V V V V V ]
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[IKE] <con1000|412> received NAT-T (RFC 3947) vendor ID
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[IKE] <con1000|412> received DPD vendor ID
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[ENC] <con1000|412> received unknown vendor ID: 82:99:03:17:57:a3:60:82:c6:a6:21:de:00:00:00:00
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[IKE] <con1000|412> received FRAGMENTATION vendor ID
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[IKE] <con1000|412> received FRAGMENTATION vendor ID
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[CFG] <con1000|412> selecting proposal:
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[CFG] <con1000|412>   proposal matches
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[CFG] <con1000|412> received proposals: IKE:AES_CBC_256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_2048
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[CFG] <con1000|412> configured proposals: IKE:AES_CBC_256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_2048
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[CFG] <con1000|412> selected proposal: IKE:AES_CBC_256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_2048
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[IKE] <con1000|412> reinitiating already active tasks
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[IKE] <con1000|412>   ISAKMP_VENDOR task
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[IKE] <con1000|412>   MAIN_MODE task
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[ENC] <con1000|412> generating ID_PROT request 0 [ KE No NAT-D NAT-D ]
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[NET] <con1000|412> sending packet: from A.A.A.A[500] to B.B.B.B[500] (396 bytes)
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[NET] <con1000|412> received packet: from B.B.B.B[500] to A.A.A.A[500] (380 bytes)
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[ENC] <con1000|412> parsed ID_PROT response 0 [ KE No NAT-D NAT-D ]
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[IKE] <con1000|412> reinitiating already active tasks
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[IKE] <con1000|412>   ISAKMP_VENDOR task
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[IKE] <con1000|412>   MAIN_MODE task
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[ENC] <con1000|412> generating ID_PROT request 0 [ ID HASH N(INITIAL_CONTACT) ]
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[NET] <con1000|412> sending packet: from A.A.A.A[500] to B.B.B.B[500] (108 bytes)
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[NET] <con1000|412> received packet: from B.B.B.B[500] to A.A.A.A[500] (92 bytes)
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[ENC] <con1000|412> invalid HASH_V1 payload length, decryption failed?
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[ENC] <con1000|412> could not decrypt payloads
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[IKE] <con1000|412> message parsing failed
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[IKE] <con1000|412> ignore malformed INFORMATIONAL request
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 16[IKE] <con1000|412> INFORMATIONAL_V1 request with message ID 3815661156 processing failed
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 13[NET] <con1000|412> received packet: from B.B.B.B[500] to A.A.A.A[500] (92 bytes)
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 13[ENC] <con1000|412> invalid HASH_V1 payload length, decryption failed?
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 13[ENC] <con1000|412> could not decrypt payloads
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 13[IKE] <con1000|412> message parsing failed
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 13[IKE] <con1000|412> ignore malformed INFORMATIONAL request
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 13[IKE] <con1000|412> INFORMATIONAL_V1 request with message ID 2676923576 processing failed
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 10[NET] <con1000|412> received packet: from B.B.B.B[500] to A.A.A.A[500] (92 bytes)
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 10[ENC] <con1000|412> invalid HASH_V1 payload length, decryption failed?
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 10[ENC] <con1000|412> could not decrypt payloads
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 10[IKE] <con1000|412> message parsing failed
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 10[IKE] <con1000|412> ignore malformed INFORMATIONAL request
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 10[IKE] <con1000|412> INFORMATIONAL_V1 request with message ID 3593862444 processing failed
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 06[NET] <con1000|412> received packet: from B.B.B.B[500] to A.A.A.A[500] (92 bytes)
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 06[ENC] <con1000|412> parsed ID_PROT response 0 [ ID HASH ]
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 06[IKE] <con1000|412> IKE_SA con1000[412] established between A.A.A.A[A.A.A.A]...B.B.B.B[B.B.B.B]
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 06[IKE] <con1000|412> IKE_SA con1000[412] state change: CONNECTING => ESTABLISHED
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 06[IKE] <con1000|412> scheduling reauthentication in 28255s
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 06[IKE] <con1000|412> maximum IKE_SA lifetime 28795s
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 06[IKE] <con1000|412> activating new tasks
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 06[IKE] <con1000|412>   activating QUICK_MODE task
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412> configured proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412> configured proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412> proposing traffic selectors for us:
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412>  172.17.17.0/30|/0
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412>  0.0.0.0/0|/0
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412> proposing traffic selectors for other:
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412>  172.17.17.1/32|/0
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412>  0.0.0.0/0|/0
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 06[ENC] <con1000|412> generating QUICK_MODE request 1350685403 [ HASH SA No KE ID ID ]
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 06[NET] <con1000|412> sending packet: from A.A.A.A[500] to B.B.B.B[500] (460 bytes)
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[NET] <con1000|412> received packet: from B.B.B.B[500] to A.A.A.A[500] (476 bytes)
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[ENC] <con1000|412> parsed QUICK_MODE request 2362096667 [ HASH SA No KE ID ID ]
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[CFG] <con1000|412> looking for a child config for 172.24.136.0/21|/0 === 10.0.0.0/8|/0
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[CFG] <con1000|412> proposing traffic selectors for us:
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[CFG] <con1000|412>  172.17.17.0/30|/0
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[CFG] <con1000|412>  0.0.0.0/0|/0
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[CFG] <con1000|412> proposing traffic selectors for other:
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[CFG] <con1000|412>  172.17.17.1/32|/0
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[CFG] <con1000|412>  0.0.0.0/0|/0
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[CFG] <con1000|412>   candidate "con1000" with prio 1+1
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[CFG] <con1000|412> found matching child config "con1000" with prio 2
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[CFG] <con1000|412> selecting traffic selectors for other:
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[CFG] <con1000|412>  config: 172.17.17.1/32|/0, received: 10.0.0.0/8|/0 => no match
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[CFG] <con1000|412>  config: 0.0.0.0/0|/0, received: 10.0.0.0/8|/0 => match: 10.0.0.0/8|/0
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[CFG] <con1000|412> selecting traffic selectors for us:
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[CFG] <con1000|412>  config: 172.17.17.0/30|/0, received: 172.24.136.0/21|/0 => no match
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[CFG] <con1000|412>  config: 0.0.0.0/0|/0, received: 172.24.136.0/21|/0 => match: 172.24.136.0/21|/0
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[CFG] <con1000|412> selecting proposal:
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[CFG] <con1000|412>   proposal matches
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[CFG] <con1000|412> received proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[CFG] <con1000|412> configured proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[CFG] <con1000|412> selected proposal: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[IKE] <con1000|412> received 43200s lifetime, configured 3600s
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[ENC] <con1000|412> generating QUICK_MODE response 2362096667 [ HASH SA No KE ID ID ]
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[NET] <con1000|412> sending packet: from A.A.A.A[500] to B.B.B.B[500] (460 bytes)
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[NET] <con1000|412> received packet: from B.B.B.B[500] to A.A.A.A[500] (76 bytes)
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[ENC] <con1000|412> parsed QUICK_MODE request 2362096667 [ HASH ]
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[CHD] <con1000|412> CHILD_SA con1000{1093} state change: CREATED => INSTALLING
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[CHD] <con1000|412>   using AES_CBC for encryption
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[CHD] <con1000|412>   using HMAC_SHA2_256_128 for integrity
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[CHD] <con1000|412> adding inbound ESP SA
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[CHD] <con1000|412>   SPI 0xc9c7ae3b, src B.B.B.B dst A.A.A.A
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[CHD] <con1000|412> adding outbound ESP SA
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[CHD] <con1000|412>   SPI 0x235d5b6a, src A.A.A.A dst B.B.B.B
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[IKE] <con1000|412> CHILD_SA con1000{1093} established with SPIs c9c7ae3b_i 235d5b6a_o and TS 172.24.136.0/21|/0 === 10.0.0.0/8|/0
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[CHD] <con1000|412> CHILD_SA con1000{1093} state change: INSTALLING => INSTALLED
    Jan 31 02:29:59 MXSAL-NFW-PFS01 charon: 14[IKE] <con1000|412> delaying task initiation, QUICK_MODE exchange in progress
    
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[IKE] <con1000|412> sending retransmit 1 of request message ID 1350685403, seq 4
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[NET] <con1000|412> sending packet: from A.A.A.A[500] to B.B.B.B[500] (460 bytes)
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[NET] <con1000|412> received packet: from B.B.B.B[500] to A.A.A.A[500] (476 bytes)
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[ENC] <con1000|412> parsed QUICK_MODE request 3604961641 [ HASH SA No KE ID ID ]
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412> looking for a child config for 172.24.136.0/21|/0 === 172.24.228.0/24|/0
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412> proposing traffic selectors for us:
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412>  172.17.17.0/30|/0
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412>  0.0.0.0/0|/0
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412> proposing traffic selectors for other:
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412>  172.17.17.1/32|/0
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412>  0.0.0.0/0|/0
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412>   candidate "con1000" with prio 1+1
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412> found matching child config "con1000" with prio 2
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412> selecting traffic selectors for other:
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412>  config: 172.17.17.1/32|/0, received: 172.24.228.0/24|/0 => no match
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412>  config: 0.0.0.0/0|/0, received: 172.24.228.0/24|/0 => match: 172.24.228.0/24|/0
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412> selecting traffic selectors for us:
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412>  config: 172.17.17.0/30|/0, received: 172.24.136.0/21|/0 => no match
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412>  config: 0.0.0.0/0|/0, received: 172.24.136.0/21|/0 => match: 172.24.136.0/21|/0
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412> selecting proposal:
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412>   no acceptable ENCRYPTION_ALGORITHM found
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412> selecting proposal:
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412>   proposal matches
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412> received proposals: ESP:AES_CBC_128/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412> configured proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CFG] <con1000|412> selected proposal: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[IKE] <con1000|412> received 43200s lifetime, configured 3600s
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[ENC] <con1000|412> generating QUICK_MODE response 3604961641 [ HASH SA No KE ID ID ]
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[NET] <con1000|412> sending packet: from A.A.A.A[500] to B.B.B.B[500] (460 bytes)
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[NET] <con1000|412> received packet: from B.B.B.B[500] to A.A.A.A[500] (76 bytes)
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[ENC] <con1000|412> parsed QUICK_MODE request 3604961641 [ HASH ]
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CHD] <con1000|412> CHILD_SA con1000{1094} state change: CREATED => INSTALLING
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CHD] <con1000|412>   using AES_CBC for encryption
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CHD] <con1000|412>   using HMAC_SHA2_256_128 for integrity
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CHD] <con1000|412> adding inbound ESP SA
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CHD] <con1000|412>   SPI 0xca554505, src B.B.B.B dst A.A.A.A
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CHD] <con1000|412> adding outbound ESP SA
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CHD] <con1000|412>   SPI 0x235d5b6b, src A.A.A.A dst B.B.B.B
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[IKE] <con1000|412> CHILD_SA con1000{1094} established with SPIs ca554505_i 235d5b6b_o and TS 172.24.136.0/21|/0 === 172.24.228.0/24|/0
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[CHD] <con1000|412> CHILD_SA con1000{1094} state change: INSTALLING => INSTALLED
    Jan 31 02:30:03 MXSAL-NFW-PFS01 charon: 06[IKE] <con1000|412> delaying task initiation, QUICK_MODE exchange in progress
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[NET] <con1000|412> received packet: from B.B.B.B[500] to A.A.A.A[500] (476 bytes)
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[ENC] <con1000|412> parsed QUICK_MODE request 1854948861 [ HASH SA No KE ID ID ]
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CFG] <con1000|412> looking for a child config for 172.24.136.0/21|/0 === 172.24.24.0/21|/0
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CFG] <con1000|412> proposing traffic selectors for us:
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CFG] <con1000|412>  172.17.17.0/30|/0
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CFG] <con1000|412>  0.0.0.0/0|/0
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CFG] <con1000|412> proposing traffic selectors for other:
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CFG] <con1000|412>  172.17.17.1/32|/0
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CFG] <con1000|412>  0.0.0.0/0|/0
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CFG] <con1000|412>   candidate "con1000" with prio 1+1
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CFG] <con1000|412> found matching child config "con1000" with prio 2
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CFG] <con1000|412> selecting traffic selectors for other:
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CFG] <con1000|412>  config: 172.17.17.1/32|/0, received: 172.24.24.0/21|/0 => no match
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CFG] <con1000|412>  config: 0.0.0.0/0|/0, received: 172.24.24.0/21|/0 => match: 172.24.24.0/21|/0
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CFG] <con1000|412> selecting traffic selectors for us:
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CFG] <con1000|412>  config: 172.17.17.0/30|/0, received: 172.24.136.0/21|/0 => no match
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CFG] <con1000|412>  config: 0.0.0.0/0|/0, received: 172.24.136.0/21|/0 => match: 172.24.136.0/21|/0
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CFG] <con1000|412> selecting proposal:
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CFG] <con1000|412>   no acceptable ENCRYPTION_ALGORITHM found
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CFG] <con1000|412> selecting proposal:
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CFG] <con1000|412>   proposal matches
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CFG] <con1000|412> received proposals: ESP:AES_CBC_128/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CFG] <con1000|412> configured proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CFG] <con1000|412> selected proposal: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[IKE] <con1000|412> received 43200s lifetime, configured 3600s
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[ENC] <con1000|412> generating QUICK_MODE response 1854948861 [ HASH SA No KE ID ID ]
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[NET] <con1000|412> sending packet: from A.A.A.A[500] to B.B.B.B[500] (460 bytes)
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[NET] <con1000|412> received packet: from B.B.B.B[500] to A.A.A.A[500] (76 bytes)
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[ENC] <con1000|412> parsed QUICK_MODE request 1854948861 [ HASH ]
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CHD] <con1000|412> CHILD_SA con1000{1095} state change: CREATED => INSTALLING
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CHD] <con1000|412>   using AES_CBC for encryption
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CHD] <con1000|412>   using HMAC_SHA2_256_128 for integrity
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CHD] <con1000|412> adding inbound ESP SA
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CHD] <con1000|412>   SPI 0xc1706fe2, src B.B.B.B dst A.A.A.A
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CHD] <con1000|412> adding outbound ESP SA
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CHD] <con1000|412>   SPI 0x235d5b6c, src A.A.A.A dst B.B.B.B
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[IKE] <con1000|412> CHILD_SA con1000{1095} established with SPIs c1706fe2_i 235d5b6c_o and TS 172.24.136.0/21|/0 === 172.24.24.0/21|/0
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[CHD] <con1000|412> CHILD_SA con1000{1095} state change: INSTALLING => INSTALLED
    Jan 31 02:30:04 MXSAL-NFW-PFS01 charon: 16[IKE] <con1000|412> delaying task initiation, QUICK_MODE exchange in progress
    

    Attached you can also find screenshots for the P1 and P2 configuration on the pfSense.

    P1.PNG

    P2.PNG

    Any help is appreciated.
    Thank you
    Gino


  • LAYER 8

    @ilGino said in IPsec tunnel pfSense - Fortigate disconnects and reconnects:

    invalid HASH_V1 payload length, decryption failed

    It is some mismatch on the ID or Phase1 configuration
    "My Identifier" and "Peer Identifier" fields in the Phase 1 Proposal for example

    also i would check IKE_SA lifetime if they are the same
    you need to compare it with the fortigate


Log in to reply