invalid HASH_V1 payload length, decryption failed after registering several P2's



  • I'm getting really strange issues with 2.4.4-p2 and IPSec tunnels. At first none of the tunnels with more than 1 P2 would come up.
    Applying the fix from https://forum.netgate.com/topic/139536/phase-2-invalid-hash_v1-payload-length-error/10 fixed it somewhat but the behaviour varies a lot, I tried entering different values for max_ikey1_exchanges and although the result is that at least 1 P2 is registered it does not do much to register all 4 consentintly.

    I'm seeing errors in the log file with regard to invalid HASH_V1 payload length, decryption failed?.

    Below is a log from when it fails after is already configured 3 P2's. (remote is redacted to 100.100.100.100 and local public is redacted to 200.200.200.200)
    It configures 3 (out fo 4) P2's but then will suddenly throw invalid HASH_V1 payload length, decryption failed?..

    However, and this is the strange part: clicking on Disconnect and Connect a few times I get each time a different number of registered P2's, sometimes it can even register all 4, sometimes 3 or sometimes just 1.

    During the P1 lifetime all is well, traffic gets routed etc but when P1 reneg is up it's again pretty random how many P2's it can register.

    Didn't have this problem with 2.4.3-p2 and it's really doing my head in... šŸ¤¢

    Thanks for any help!

    Jan 28 17:27:28 pfsense2 charon: 13[NET] <37> received packet: from 100.100.100.100[4500] to 172.16.0.110[4500] (108 bytes)
    Jan 28 17:27:28 pfsense2 charon: 13[ENC] <37> parsed ID_PROT request 0 [ ID HASH N(INITIAL_CONTACT) ]
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <37> looking for pre-shared key peer configs matching 172.16.0.110...100.100.100.100[100.100.100.100]
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <37>   candidate "con3000", match: 1/20/3100 (me/other/ike)
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <37> selected peer config "con3000"
    Jan 28 17:27:28 pfsense2 charon: 13[IKE] <con3000|37> IKE_SA con3000[37] established between 172.16.0.110[200.200.200.200]...100.100.100.100[100.100.100.100]
    Jan 28 17:27:28 pfsense2 charon: 13[IKE] <con3000|37> IKE_SA con3000[37] state change: CONNECTING => ESTABLISHED
    Jan 28 17:27:28 pfsense2 charon: 13[IKE] <con3000|37> scheduling reauthentication in 3584s
    Jan 28 17:27:28 pfsense2 charon: 13[IKE] <con3000|37> maximum IKE_SA lifetime 3594s
    Jan 28 17:27:28 pfsense2 charon: 13[ENC] <con3000|37> generating ID_PROT response 0 [ ID HASH ]
    Jan 28 17:27:28 pfsense2 charon: 13[NET] <con3000|37> sending packet: from 172.16.0.110[4500] to 100.100.100.100[4500] (92 bytes)
    Jan 28 17:27:28 pfsense2 charon: 04[NET] sending packet: from 172.16.0.110[4500] to 100.100.100.100[4500]
    Jan 28 17:27:28 pfsense2 charon: 03[NET] received packet: from 100.100.100.100[4500] to 172.16.0.110[4500]
    Jan 28 17:27:28 pfsense2 charon: 03[NET] waiting for data on sockets
    Jan 28 17:27:28 pfsense2 charon: 03[NET] received packet: from 100.100.100.100[4500] to 172.16.0.110[4500]
    Jan 28 17:27:28 pfsense2 charon: 03[NET] waiting for data on sockets
    Jan 28 17:27:28 pfsense2 charon: 03[NET] received packet: from 100.100.100.100[4500] to 172.16.0.110[4500]
    Jan 28 17:27:28 pfsense2 charon: 03[NET] waiting for data on sockets
    Jan 28 17:27:28 pfsense2 charon: 03[NET] received packet: from 100.100.100.100[4500] to 172.16.0.110[4500]
    Jan 28 17:27:28 pfsense2 charon: 03[NET] waiting for data on sockets
    Jan 28 17:27:28 pfsense2 charon: 13[NET] <con3000|37> received packet: from 100.100.100.100[4500] to 172.16.0.110[4500] (380 bytes)
    Jan 28 17:27:28 pfsense2 charon: 13[ENC] <con3000|37> parsed QUICK_MODE request 470394056 [ HASH SA No KE ID ID ]
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37> looking for a child config for 172.17.2.0/24|/0 === 10.31.0.0/22|/0
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37> proposing traffic selectors for us:
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37>  172.17.2.0/24|/0
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37> proposing traffic selectors for other:
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37>  10.132.121.0/24|/0
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37> proposing traffic selectors for us:
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37>  172.17.2.0/24|/0
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37> proposing traffic selectors for other:
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37>  10.0.0.0/21|/0
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37> proposing traffic selectors for us:
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37>  172.17.2.0/24|/0
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37> proposing traffic selectors for other:
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37>  10.11.0.0/21|/0
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37> proposing traffic selectors for us:
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37>  172.17.2.0/24|/0
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37> proposing traffic selectors for other:
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37>  10.31.0.0/22|/0
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37>   candidate "con3003" with prio 5+5
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37> found matching child config "con3003" with prio 10
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37> selecting traffic selectors for other:
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37>  config: 10.31.0.0/22|/0, received: 10.31.0.0/22|/0 => match: 10.31.0.0/22|/0
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37> selecting traffic selectors for us:
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37>  config: 172.17.2.0/24|/0, received: 172.17.2.0/24|/0 => match: 172.17.2.0/24|/0
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37> selecting proposal:
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37>   no acceptable INTEGRITY_ALGORITHM found
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37> selecting proposal:
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37>   no acceptable INTEGRITY_ALGORITHM found
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37> selecting proposal:
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37>   proposal matches
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37> received proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_1536/NO_EXT_SEQ
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37> configured proposals: ESP:AES_CBC_256/HMAC_MD5_96/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_384_192/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_512_256/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_MD5_96/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA1_96/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_256_128/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_384_192/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_512_256/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_MD5_96/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_256_128/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_384_192/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_512_256/MODP_1536/NO_EXT_SEQ, ESP:AES_GCM_16_128/MODP_1536/NO_EXT_SEQ, ESP:AES_GCM_16_128/MODP_1536/NO_EXT_SEQ, ESP:AES_GCM_16_128/MODP_1536/NO_EXT_SEQ, ESP:AES_GCM_16_128/MODP
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] <con3000|37> selected proposal: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_1536/NO_EXT_SEQ
    Jan 28 17:27:28 pfsense2 charon: 13[LIB] <con3000|37> size of DH secret exponent: 1535 bits
    Jan 28 17:27:28 pfsense2 charon: 13[KNL] <con3000|37> got SPI cb786f0f
    Jan 28 17:27:28 pfsense2 charon: 13[ENC] <con3000|37> generating QUICK_MODE response 470394056 [ HASH SA No KE ID ID ]
    Jan 28 17:27:28 pfsense2 charon: 13[NET] <con3000|37> sending packet: from 172.16.0.110[4500] to 100.100.100.100[4500] (396 bytes)
    Jan 28 17:27:28 pfsense2 charon: 04[NET] sending packet: from 172.16.0.110[4500] to 100.100.100.100[4500]
    Jan 28 17:27:28 pfsense2 charon: 15[NET] <con3000|37> received packet: from 100.100.100.100[4500] to 172.16.0.110[4500] (380 bytes)
    Jan 28 17:27:28 pfsense2 charon: 15[ENC] <con3000|37> parsed QUICK_MODE request 1896057272 [ HASH SA No KE ID ID ]
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37> looking for a child config for 172.17.2.0/24|/0 === 10.11.0.0/21|/0
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37> proposing traffic selectors for us:
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37>  172.17.2.0/24|/0
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37> proposing traffic selectors for other:
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37>  10.132.121.0/24|/0
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37> proposing traffic selectors for us:
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37>  172.17.2.0/24|/0
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37> proposing traffic selectors for other:
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37>  10.0.0.0/21|/0
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37> proposing traffic selectors for us:
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37>  172.17.2.0/24|/0
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37> proposing traffic selectors for other:
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37>  10.11.0.0/21|/0
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37>   candidate "con3002" with prio 5+5
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37> proposing traffic selectors for us:
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37>  172.17.2.0/24|/0
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37> proposing traffic selectors for other:
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37>  10.31.0.0/22|/0
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37> found matching child config "con3002" with prio 10
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37> selecting traffic selectors for other:
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37>  config: 10.11.0.0/21|/0, received: 10.11.0.0/21|/0 => match: 10.11.0.0/21|/0
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37> selecting traffic selectors for us:
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37>  config: 172.17.2.0/24|/0, received: 172.17.2.0/24|/0 => match: 172.17.2.0/24|/0
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37> selecting proposal:
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37>   no acceptable INTEGRITY_ALGORITHM found
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37> selecting proposal:
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37>   no acceptable INTEGRITY_ALGORITHM found
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37> selecting proposal:
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37>   proposal matches
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37> received proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_1536/NO_EXT_SEQ
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37> configured proposals: ESP:AES_CBC_256/HMAC_MD5_96/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_384_192/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_512_256/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_MD5_96/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA1_96/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_256_128/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_384_192/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_512_256/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_MD5_96/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_256_128/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_384_192/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_512_256/MODP_1536/NO_EXT_SEQ, ESP:AES_GCM_16_128/MODP_1536/NO_EXT_SEQ, ESP:AES_GCM_16_128/MODP_1536/NO_EXT_SEQ, ESP:AES_GCM_16_128/MODP_1536/NO_EXT_SEQ, ESP:AES_GCM_16_128/MODP
    Jan 28 17:27:28 pfsense2 charon: 15[CFG] <con3000|37> selected proposal: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_1536/NO_EXT_SEQ
    Jan 28 17:27:28 pfsense2 charon: 15[LIB] <con3000|37> size of DH secret exponent: 1535 bits
    Jan 28 17:27:28 pfsense2 charon: 15[KNL] <con3000|37> got SPI c60728d1
    Jan 28 17:27:28 pfsense2 charon: 15[ENC] <con3000|37> generating QUICK_MODE response 1896057272 [ HASH SA No KE ID ID ]
    Jan 28 17:27:28 pfsense2 charon: 15[NET] <con3000|37> sending packet: from 172.16.0.110[4500] to 100.100.100.100[4500] (396 bytes)
    Jan 28 17:27:28 pfsense2 charon: 03[NET] received packet: from 100.100.100.100[4500] to 172.16.0.110[4500]
    Jan 28 17:27:28 pfsense2 charon: 03[NET] waiting for data on sockets
    Jan 28 17:27:28 pfsense2 charon: 09[NET] <con3000|37> received packet: from 100.100.100.100[4500] to 172.16.0.110[4500] (380 bytes)
    Jan 28 17:27:28 pfsense2 charon: 09[ENC] <con3000|37> parsed QUICK_MODE request 3026735026 [ HASH SA No KE ID ID ]
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37> looking for a child config for 172.17.2.0/24|/0 === 10.0.0.0/21|/0
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37> proposing traffic selectors for us:
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37>  172.17.2.0/24|/0
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37> proposing traffic selectors for other:
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37>  10.132.121.0/24|/0
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37> proposing traffic selectors for us:
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37>  172.17.2.0/24|/0
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37> proposing traffic selectors for other:
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37>  10.0.0.0/21|/0
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37>   candidate "con3001" with prio 5+5
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37> proposing traffic selectors for us:
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37>  172.17.2.0/24|/0
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37> proposing traffic selectors for other:
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37>  10.11.0.0/21|/0
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37> proposing traffic selectors for us:
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37>  172.17.2.0/24|/0
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37> proposing traffic selectors for other:
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37>  10.31.0.0/22|/0
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37> found matching child config "con3001" with prio 10
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37> selecting traffic selectors for other:
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37>  config: 10.0.0.0/21|/0, received: 10.0.0.0/21|/0 => match: 10.0.0.0/21|/0
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37> selecting traffic selectors for us:
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37>  config: 172.17.2.0/24|/0, received: 172.17.2.0/24|/0 => match: 172.17.2.0/24|/0
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37> selecting proposal:
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37>   no acceptable INTEGRITY_ALGORITHM found
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37> selecting proposal:
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37>   no acceptable INTEGRITY_ALGORITHM found
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37> selecting proposal:
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37>   proposal matches
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37> received proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_1536/NO_EXT_SEQ
    Jan 28 17:27:28 pfsense2 charon: 04[NET] sending packet: from 172.16.0.110[4500] to 100.100.100.100[4500]
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37> configured proposals: ESP:AES_CBC_256/HMAC_MD5_96/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_384_192/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_512_256/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_MD5_96/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA1_96/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_256_128/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_384_192/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_512_256/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_MD5_96/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_256_128/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_384_192/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_512_256/MODP_1536/NO_EXT_SEQ, ESP:AES_GCM_16_128/MODP_1536/NO_EXT_SEQ, ESP:AES_GCM_16_128/MODP_1536/NO_EXT_SEQ, ESP:AES_GCM_16_128/MODP_1536/NO_EXT_SEQ, ESP:AES_GCM_16_128/MODP
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] <con3000|37> selected proposal: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_1536/NO_EXT_SEQ
    Jan 28 17:27:28 pfsense2 charon: 09[LIB] <con3000|37> size of DH secret exponent: 1535 bits
    Jan 28 17:27:28 pfsense2 charon: 09[KNL] <con3000|37> got SPI cd991df4
    Jan 28 17:27:28 pfsense2 charon: 09[ENC] <con3000|37> generating QUICK_MODE response 3026735026 [ HASH SA No KE ID ID ]
    Jan 28 17:27:28 pfsense2 charon: 09[NET] <con3000|37> sending packet: from 172.16.0.110[4500] to 100.100.100.100[4500] (396 bytes)
    Jan 28 17:27:28 pfsense2 charon: 04[NET] sending packet: from 172.16.0.110[4500] to 100.100.100.100[4500]
    Jan 28 17:27:28 pfsense2 charon: 03[NET] received packet: from 100.100.100.100[4500] to 172.16.0.110[4500]
    Jan 28 17:27:28 pfsense2 charon: 03[NET] waiting for data on sockets
    Jan 28 17:27:28 pfsense2 charon: 15[NET] <con3000|37> received packet: from 100.100.100.100[4500] to 172.16.0.110[4500] (76 bytes)
    Jan 28 17:27:28 pfsense2 charon: 15[ENC] <con3000|37> parsed QUICK_MODE request 470394056 [ HASH ]
    Jan 28 17:27:28 pfsense2 charon: 15[CHD] <con3000|37> CHILD_SA con3003{58} state change: CREATED => INSTALLING
    Jan 28 17:27:28 pfsense2 charon: 15[CHD] <con3000|37>   using AES_CBC for encryption
    Jan 28 17:27:28 pfsense2 charon: 15[CHD] <con3000|37>   using HMAC_SHA2_256_128 for integrity
    Jan 28 17:27:28 pfsense2 charon: 15[CHD] <con3000|37> adding inbound ESP SA
    Jan 28 17:27:28 pfsense2 charon: 15[CHD] <con3000|37>   SPI 0xcb786f0f, src 100.100.100.100 dst 172.16.0.110
    Jan 28 17:27:28 pfsense2 charon: 15[KNL] <con3000|37> deleting SAD entry with SPI cb786f0f
    Jan 28 17:27:28 pfsense2 charon: 15[KNL] <con3000|37> deleted SAD entry with SPI cb786f0f
    Jan 28 17:27:28 pfsense2 charon: 15[KNL] <con3000|37> adding SAD entry with SPI cb786f0f and reqid {22}
    Jan 28 17:27:28 pfsense2 charon: 15[KNL] <con3000|37>   using encryption algorithm AES_CBC with key size 256
    Jan 28 17:27:28 pfsense2 charon: 15[KNL] <con3000|37>   using integrity algorithm HMAC_SHA2_256_128 with key size 256
    Jan 28 17:27:28 pfsense2 charon: 15[CHD] <con3000|37> adding outbound ESP SA
    Jan 28 17:27:28 pfsense2 charon: 15[CHD] <con3000|37>   SPI 0xac510665, src 172.16.0.110 dst 100.100.100.100
    Jan 28 17:27:28 pfsense2 charon: 15[KNL] <con3000|37> adding SAD entry with SPI ac510665 and reqid {22}
    Jan 28 17:27:28 pfsense2 charon: 15[KNL] <con3000|37>   using encryption algorithm AES_CBC with key size 256
    Jan 28 17:27:28 pfsense2 charon: 15[KNL] <con3000|37>   using integrity algorithm HMAC_SHA2_256_128 with key size 256
    Jan 28 17:27:28 pfsense2 charon: 15[KNL] <con3000|37> adding policy 10.31.0.0/22|/0 === 172.17.2.0/24|/0 in
    Jan 28 17:27:28 pfsense2 charon: 15[KNL] <con3000|37> adding policy 172.17.2.0/24|/0 === 10.31.0.0/22|/0 out
    Jan 28 17:27:28 pfsense2 charon: 15[IKE] <con3000|37> CHILD_SA con3003{58} established with SPIs cb786f0f_i ac510665_o and TS 172.17.2.0/24|/0 === 10.31.0.0/22|/0
    Jan 28 17:27:28 pfsense2 charon: 15[CHD] <con3000|37> CHILD_SA con3003{58} state change: INSTALLING => INSTALLED
    Jan 28 17:27:28 pfsense2 charon: 13[NET] <con3000|37> received packet: from 100.100.100.100[4500] to 172.16.0.110[4500] (76 bytes)
    Jan 28 17:27:28 pfsense2 charon: 13[ENC] <con3000|37> parsed QUICK_MODE request 1896057272 [ HASH ]
    Jan 28 17:27:28 pfsense2 charon: 13[CHD] <con3000|37> CHILD_SA con3002{59} state change: CREATED => INSTALLING
    Jan 28 17:27:28 pfsense2 charon: 13[CHD] <con3000|37>   using AES_CBC for encryption
    Jan 28 17:27:28 pfsense2 charon: 13[CHD] <con3000|37>   using HMAC_SHA2_256_128 for integrity
    Jan 28 17:27:28 pfsense2 charon: 13[CHD] <con3000|37> adding inbound ESP SA
    Jan 28 17:27:28 pfsense2 charon: 13[CHD] <con3000|37>   SPI 0xc60728d1, src 100.100.100.100 dst 172.16.0.110
    Jan 28 17:27:28 pfsense2 charon: 13[KNL] <con3000|37> deleting SAD entry with SPI c60728d1
    Jan 28 17:27:28 pfsense2 charon: 13[KNL] <con3000|37> deleted SAD entry with SPI c60728d1
    Jan 28 17:27:28 pfsense2 charon: 13[KNL] <con3000|37> adding SAD entry with SPI c60728d1 and reqid {23}
    Jan 28 17:27:28 pfsense2 charon: 13[KNL] <con3000|37>   using encryption algorithm AES_CBC with key size 256
    Jan 28 17:27:28 pfsense2 charon: 13[KNL] <con3000|37>   using integrity algorithm HMAC_SHA2_256_128 with key size 256
    Jan 28 17:27:28 pfsense2 charon: 13[CHD] <con3000|37> adding outbound ESP SA
    Jan 28 17:27:28 pfsense2 charon: 13[CHD] <con3000|37>   SPI 0xac510668, src 172.16.0.110 dst 100.100.100.100
    Jan 28 17:27:28 pfsense2 charon: 13[KNL] <con3000|37> adding SAD entry with SPI ac510668 and reqid {23}
    Jan 28 17:27:28 pfsense2 charon: 13[KNL] <con3000|37>   using encryption algorithm AES_CBC with key size 256
    Jan 28 17:27:28 pfsense2 charon: 13[KNL] <con3000|37>   using integrity algorithm HMAC_SHA2_256_128 with key size 256
    Jan 28 17:27:28 pfsense2 charon: 13[KNL] <con3000|37> adding policy 10.11.0.0/21|/0 === 172.17.2.0/24|/0 in
    Jan 28 17:27:28 pfsense2 charon: 13[KNL] <con3000|37> adding policy 172.17.2.0/24|/0 === 10.11.0.0/21|/0 out
    Jan 28 17:27:28 pfsense2 charon: 13[IKE] <con3000|37> CHILD_SA con3002{59} established with SPIs c60728d1_i ac510668_o and TS 172.17.2.0/24|/0 === 10.11.0.0/21|/0
    Jan 28 17:27:28 pfsense2 charon: 13[CHD] <con3000|37> CHILD_SA con3002{59} state change: INSTALLING => INSTALLED
    Jan 28 17:27:28 pfsense2 charon: 05[NET] <con3000|37> received packet: from 100.100.100.100[4500] to 172.16.0.110[4500] (380 bytes)
    Jan 28 17:27:28 pfsense2 charon: 05[ENC] <con3000|37> parsed QUICK_MODE request 2633624910 [ HASH SA No KE ID ID ]
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37> looking for a child config for 172.17.2.0/24|/0 === 10.132.121.0/24|/0
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37> proposing traffic selectors for us:
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37>  172.17.2.0/24|/0
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37> proposing traffic selectors for other:
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37>  10.132.121.0/24|/0
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37>   candidate "con3000" with prio 5+5
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37> proposing traffic selectors for us:
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37>  172.17.2.0/24|/0
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37> proposing traffic selectors for other:
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37>  10.0.0.0/21|/0
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37> proposing traffic selectors for us:
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37>  172.17.2.0/24|/0
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37> proposing traffic selectors for other:
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37>  10.11.0.0/21|/0
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37> proposing traffic selectors for us:
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37>  172.17.2.0/24|/0
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37> proposing traffic selectors for other:
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37>  10.31.0.0/22|/0
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37> found matching child config "con3000" with prio 10
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37> selecting traffic selectors for other:
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37>  config: 10.132.121.0/24|/0, received: 10.132.121.0/24|/0 => match: 10.132.121.0/24|/0
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37> selecting traffic selectors for us:
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37>  config: 172.17.2.0/24|/0, received: 172.17.2.0/24|/0 => match: 172.17.2.0/24|/0
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37> selecting proposal:
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37>   no acceptable INTEGRITY_ALGORITHM found
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37> selecting proposal:
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37>   no acceptable INTEGRITY_ALGORITHM found
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37> selecting proposal:
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37>   proposal matches
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37> received proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_1536/NO_EXT_SEQ
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37> configured proposals: ESP:AES_CBC_256/HMAC_MD5_96/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_384_192/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_512_256/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_MD5_96/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA1_96/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_256_128/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_384_192/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_512_256/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_MD5_96/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_256_128/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_384_192/MODP_1536/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_512_256/MODP_1536/NO_EXT_SEQ, ESP:AES_GCM_16_128/MODP_1536/NO_EXT_SEQ, ESP:AES_GCM_16_128/MODP_1536/NO_EXT_SEQ, ESP:AES_GCM_16_128/MODP_1536/NO_EXT_SEQ, ESP:AES_GCM_16_128/MODP
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] <con3000|37> selected proposal: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_1536/NO_EXT_SEQ
    Jan 28 17:27:28 pfsense2 charon: 05[LIB] <con3000|37> size of DH secret exponent: 1535 bits
    Jan 28 17:27:28 pfsense2 charon: 05[KNL] <con3000|37> got SPI c2f4d92e
    Jan 28 17:27:28 pfsense2 charon: 05[ENC] <con3000|37> generating QUICK_MODE response 2633624910 [ HASH SA No KE ID ID ]
    Jan 28 17:27:28 pfsense2 charon: 05[NET] <con3000|37> sending packet: from 172.16.0.110[4500] to 100.100.100.100[4500] (396 bytes)
    Jan 28 17:27:28 pfsense2 charon: 04[NET] sending packet: from 172.16.0.110[4500] to 100.100.100.100[4500]
    Jan 28 17:27:28 pfsense2 charon: 03[NET] received packet: from 100.100.100.100[4500] to 172.16.0.110[4500]
    Jan 28 17:27:28 pfsense2 charon: 03[NET] waiting for data on sockets
    Jan 28 17:27:28 pfsense2 charon: 05[NET] <con3000|37> received packet: from 100.100.100.100[4500] to 172.16.0.110[4500] (76 bytes)
    Jan 28 17:27:28 pfsense2 charon: 05[ENC] <con3000|37> invalid HASH_V1 payload length, decryption failed?
    Jan 28 17:27:28 pfsense2 charon: 05[ENC] <con3000|37> could not decrypt payloads
    Jan 28 17:27:28 pfsense2 charon: 05[IKE] <con3000|37> message parsing failed
    Jan 28 17:27:28 pfsense2 charon: 05[ENC] <con3000|37> generating INFORMATIONAL_V1 request 1428140749 [ HASH N(PLD_MAL) ]
    Jan 28 17:27:28 pfsense2 charon: 05[NET] <con3000|37> sending packet: from 172.16.0.110[4500] to 100.100.100.100[4500] (92 bytes)
    Jan 28 17:27:28 pfsense2 charon: 05[IKE] <con3000|37> QUICK_MODE request with message ID 3026735026 processing failed
    Jan 28 17:27:28 pfsense2 charon: 04[NET] sending packet: from 172.16.0.110[4500] to 100.100.100.100[4500]
    Jan 28 17:27:28 pfsense2 charon: 03[NET] received packet: from 100.100.100.100[4500] to 172.16.0.110[4500]
    Jan 28 17:27:28 pfsense2 charon: 03[NET] waiting for data on sockets
    Jan 28 17:27:28 pfsense2 charon: 05[NET] <con3000|37> received packet: from 100.100.100.100[4500] to 172.16.0.110[4500] (76 bytes)
    Jan 28 17:27:28 pfsense2 charon: 05[ENC] <con3000|37> parsed QUICK_MODE request 2633624910 [ HASH ]
    Jan 28 17:27:28 pfsense2 charon: 05[CHD] <con3000|37> CHILD_SA con3000{61} state change: CREATED => INSTALLING
    Jan 28 17:27:28 pfsense2 charon: 05[CHD] <con3000|37>   using AES_CBC for encryption
    Jan 28 17:27:28 pfsense2 charon: 05[CHD] <con3000|37>   using HMAC_SHA2_256_128 for integrity
    Jan 28 17:27:28 pfsense2 charon: 05[CHD] <con3000|37> adding inbound ESP SA
    Jan 28 17:27:28 pfsense2 charon: 05[CHD] <con3000|37>   SPI 0xc2f4d92e, src 100.100.100.100 dst 172.16.0.110
    Jan 28 17:27:28 pfsense2 charon: 05[KNL] <con3000|37> deleting SAD entry with SPI c2f4d92e
    Jan 28 17:27:28 pfsense2 charon: 05[KNL] <con3000|37> deleted SAD entry with SPI c2f4d92e
    Jan 28 17:27:28 pfsense2 charon: 05[KNL] <con3000|37> adding SAD entry with SPI c2f4d92e and reqid {24}
    Jan 28 17:27:28 pfsense2 charon: 05[KNL] <con3000|37>   using encryption algorithm AES_CBC with key size 256
    Jan 28 17:27:28 pfsense2 charon: 05[KNL] <con3000|37>   using integrity algorithm HMAC_SHA2_256_128 with key size 256
    Jan 28 17:27:28 pfsense2 charon: 05[CHD] <con3000|37> adding outbound ESP SA
    Jan 28 17:27:28 pfsense2 charon: 05[CHD] <con3000|37>   SPI 0xac510666, src 172.16.0.110 dst 100.100.100.100
    Jan 28 17:27:28 pfsense2 charon: 05[KNL] <con3000|37> adding SAD entry with SPI ac510666 and reqid {24}
    Jan 28 17:27:28 pfsense2 charon: 05[KNL] <con3000|37>   using encryption algorithm AES_CBC with key size 256
    Jan 28 17:27:28 pfsense2 charon: 05[KNL] <con3000|37>   using integrity algorithm HMAC_SHA2_256_128 with key size 256
    Jan 28 17:27:28 pfsense2 charon: 05[KNL] <con3000|37> adding policy 10.132.121.0/24|/0 === 172.17.2.0/24|/0 in
    Jan 28 17:27:28 pfsense2 charon: 05[KNL] <con3000|37> adding policy 172.17.2.0/24|/0 === 10.132.121.0/24|/0 out
    Jan 28 17:27:28 pfsense2 charon: 05[IKE] <con3000|37> CHILD_SA con3000{61} established with SPIs c2f4d92e_i ac510666_o and TS 172.17.2.0/24|/0 === 10.132.121.0/24|/0
    Jan 28 17:27:28 pfsense2 charon: 05[CHD] <con3000|37> CHILD_SA con3000{61} state change: INSTALLING => INSTALLED
    Jan 28 17:27:28 pfsense2 charon: 09[CFG] vici client 279 connected
    Jan 28 17:27:28 pfsense2 charon: 05[CFG] vici client 279 registered for: list-sa
    Jan 28 17:27:28 pfsense2 charon: 13[CFG] vici client 279 requests: list-sas
    Jan 28 17:27:28 pfsense2 charon: 13[KNL] <con3000|37> querying SAD entry with SPI cb786f0f
    Jan 28 17:27:28 pfsense2 charon: 13[KNL] <con3000|37> querying SAD entry with SPI ac510665
    Jan 28 17:27:28 pfsense2 charon: 13[KNL] <con3000|37> querying SAD entry with SPI c60728d1
    Jan 28 17:27:28 pfsense2 charon: 13[KNL] <con3000|37> querying SAD entry with SPI ac510668
    Jan 28 17:27:28 pfsense2 charon: 13[KNL] <con3000|37> querying SAD entry with SPI c2f4d92e
    Jan 28 17:27:28 pfsense2 charon: 13[KNL] <con3000|37> querying SAD entry with SPI ac510666
    


  • This is ipsec statusall output:

    Status of IKE charon daemon (strongSwan 5.7.1, FreeBSD 11.2-RELEASE-p6, amd64):
      uptime: 45 minutes, since Jan 28 17:13:41 2019
      worker threads: 11 of 16 idle, 5/0/0/0 working, job queue: 0/0/0/0, scheduled: 37
      loaded plugins: charon unbound aes des blowfish rc2 sha2 sha1 md4 md5 random nonce x509 revocation constraints pubkey pkcs1 pkcs7 pkcs8 pkcs12 pgp dnskey sshkey ipseckey pem openssl fips-prf curve25519 xcbc cmac hmac curl attr kernel-pfkey kernel-pfroute resolve socket-default stroke vici updown eap-identity eap-sim eap-md5 eap-mschapv2 eap-dynamic eap-radius eap-tls eap-ttls eap-peap xauth-generic xauth-eap whitelist addrblock counters
    Listening IP addresses:
      172.16.0.110
    Connections:
         con3000:  172.16.0.110...100.100.100.100  IKEv1, dpddelay=10s
         con3000:   local:  [200.200.200.200] uses pre-shared key authentication
         con3000:   remote: [100.100.100.100] uses pre-shared key authentication
         con3000:   child:  172.17.2.0/24|/0 === 10.132.121.0/24|/0 TUNNEL, dpdaction=clear
         con3001:   child:  172.17.2.0/24|/0 === 10.0.0.0/21|/0 TUNNEL, dpdaction=clear
         con3002:   child:  172.17.2.0/24|/0 === 10.11.0.0/21|/0 TUNNEL, dpdaction=clear
         con3003:   child:  172.17.2.0/24|/0 === 10.31.0.0/22|/0 TUNNEL, dpdaction=clear
    Security Associations (1 up, 0 connecting):
         con3000[37]: ESTABLISHED 31 minutes ago, 172.16.0.110[200.200.200.200]...100.100.100.100[100.100.100.100]
         con3000[37]: IKEv1 SPIs: cb1564ac1f3158ca_i 9cfd2d0f9f0ce781_r*, pre-shared key reauthentication in 28 minutes
         con3000[37]: IKE proposal: AES_CBC_256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_1536
         con3000[37]: Tasks passive: QUICK_MODE
         con3003{58}:  INSTALLED, TUNNEL, reqid 22, ESP in UDP SPIs: cb786f0f_i ac510665_o
         con3003{58}:  AES_CBC_256/HMAC_SHA2_256_128/MODP_1536, 0 bytes_i (0 pkts, 1888s ago), 0 bytes_o (0 pkts, 1888s ago), rekeying in 28 minutes
         con3003{58}:   172.17.2.0/24|/0 === 10.31.0.0/22|/0
         con3002{59}:  INSTALLED, TUNNEL, reqid 23, ESP in UDP SPIs: c60728d1_i ac510668_o
         con3002{59}:  AES_CBC_256/HMAC_SHA2_256_128/MODP_1536, 2016 bytes_i (24 pkts, 205s ago), 3744 bytes_o (24 pkts, 205s ago), rekeying in 28 minutes
         con3002{59}:   172.17.2.0/24|/0 === 10.11.0.0/21|/0
         con3000{61}:  INSTALLED, TUNNEL, reqid 24, ESP in UDP SPIs: c2f4d92e_i ac510666_o
         con3000{61}:  AES_CBC_256/HMAC_SHA2_256_128/MODP_1536, 168 bytes_i (2 pkts, 1283s ago), 4056 bytes_o (26 pkts, 245s ago), rekeying in 28 minutes
         con3000{61}:   172.17.2.0/24|/0 === 10.132.121.0/24|/0
    


  • I click disconnect & reconnect a few times and with some luck out of 6 clicks it will register/enable the 4 P2's.