IPSec not connecting sometimes
-
Hello,
I have IPSec Vpn with our remote office. The problem is that when I click connect, sometimes it is stuck on connecting, so some of phase 2 entries shows "Status: Connecting" and there is a "Connect VPN" button in front of it. I click disconnect And then i click connect it is not connecting. I stop IPSec service and start again, connect vpn then it is ok. It doesn't always happen, but I usually encounter this issue. Is it bug?
-
You'll have to look at the IPsec logs to see who is complaining about what.
https://www.netgate.com/docs/pfsense/vpn/ipsec/ipsec-troubleshooting.html
-
Thank you for your reply. I am attaching logs.
Situation 1:
Sep 17 10:44:45 charon 07[CFG] vici client 924 disconnected
Sep 17 10:44:45 charon 07[CFG] vici client 924 requests: list-sas
Sep 17 10:44:45 charon 13[CFG] vici client 924 registered for: list-sa
Sep 17 10:44:45 charon 13[CFG] vici client 924 connected
Sep 17 10:44:44 charon 15[IKE] <con1000|16> nothing to initiate
Sep 17 10:44:44 charon 15[IKE] <con1000|16> activating new tasks
Sep 17 10:44:44 charon 15[NET] <con1000|16> sending packet: from 95.66.128.14[500] to 95.86.129.13[500] (60 bytes)
Sep 17 10:44:44 charon 15[ENC] <con1000|16> generating QUICK_MODE request 2675818011 [ HASH ]
Sep 17 10:44:44 charon 15[IKE] <con1000|16> QUICK_MODE task
Sep 17 10:44:44 charon 15[IKE] <con1000|16> reinitiating already active tasks
Sep 17 10:44:44 charon 15[CHD] <con1000|16> CHILD_SA con1002{38} state change: INSTALLING => INSTALLED
Sep 17 10:44:44 charon 15[IKE] <con1000|16> CHILD_SA con1002{38} established with SPIs cfe31d10_i 9a42f52c_o and TS 192.168.4.245/32|/0 === 192.168.81.5/32|/0
Sep 17 10:44:44 charon 15[CHD] <con1000|16> SPI 0x9a42f52c, src 95.66.128.14 dst 95.86.129.13
Sep 17 10:44:44 charon 15[CHD] <con1000|16> adding outbound ESP SA
Sep 17 10:44:44 charon 15[CHD] <con1000|16> SPI 0xcfe31d10, src 95.86.129.13 dst 95.66.128.14
Sep 17 10:44:44 charon 15[CHD] <con1000|16> adding inbound ESP SA
Sep 17 10:44:44 charon 15[CHD] <con1000|16> using HMAC_SHA1_96 for integrity
Sep 17 10:44:44 charon 15[CHD] <con1000|16> using AES_CBC for encryption
Sep 17 10:44:44 charon 15[CHD] <con1000|16> CHILD_SA con1002{38} state change: CREATED => INSTALLING
Sep 17 10:44:44 charon 15[CFG] <con1000|16> selected proposal: ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ
Sep 17 10:44:44 charon 15[CFG] <con1000|16> configured proposals: ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ
Sep 17 10:44:44 charon 15[CFG] <con1000|16> received proposals: ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ
Sep 17 10:44:44 charon 15[CFG] <con1000|16> proposal matches
Sep 17 10:44:44 charon 15[CFG] <con1000|16> selecting proposal:
Sep 17 10:44:44 charon 15[ENC] <con1000|16> parsed QUICK_MODE response 2675818011 [ HASH SA No KE ID ID N((24576)) ]
Sep 17 10:44:44 charon 15[NET] <con1000|16> received packet: from 95.86.129.13[500] to 95.66.128.14[500] (316 bytes)
Sep 17 10:44:44 charon 15[NET] <con1000|16> sending packet: from 95.66.128.14[500] to 95.86.129.13[500] (380 bytes)
Sep 17 10:44:44 charon 15[ENC] <con1000|16> generating QUICK_MODE request 2675818011 [ HASH SA No KE ID ID ]
Sep 17 10:44:44 charon 15[CFG] <con1000|16> 192.168.81.5/32|/0
Sep 17 10:44:44 charon 15[CFG] <con1000|16> proposing traffic selectors for other:
Sep 17 10:44:44 charon 15[CFG] <con1000|16> 192.168.4.245/32|/0
Sep 17 10:44:44 charon 15[CFG] <con1000|16> proposing traffic selectors for us:
Sep 17 10:44:44 charon 15[CFG] <con1000|16> configured proposals: ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ
Sep 17 10:44:44 charon 15[CFG] <con1000|16> configured proposals: ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ
Sep 17 10:44:44 charon 15[IKE] <con1000|16> activating QUICK_MODE task
Sep 17 10:44:44 charon 15[IKE] <con1000|16> activating new tasks
Sep 17 10:44:44 charon 15[NET] <con1000|16> sending packet: from 95.66.128.14[500] to 95.86.129.13[500] (60 bytes)
Sep 17 10:44:44 charon 15[ENC] <con1000|16> generating QUICK_MODE request 1245685972 [ HASH ]
Sep 17 10:44:44 charon 15[IKE] <con1000|16> QUICK_MODE task
Sep 17 10:44:44 charon 15[IKE] <con1000|16> reinitiating already active tasks
Sep 17 10:44:44 charon 15[CHD] <con1000|16> CHILD_SA con1001{37} state change: INSTALLING => INSTALLED
Sep 17 10:44:44 charon 15[IKE] <con1000|16> CHILD_SA con1001{37} established with SPIs c6400d7c_i 54addced_o and TS 192.168.4.245/32|/0 === 192.168.81.4/32|/0
Sep 17 10:44:44 charon 15[CHD] <con1000|16> SPI 0x54addced, src 95.66.128.14 dst 95.86.129.13
Sep 17 10:44:44 charon 15[CHD] <con1000|16> adding outbound ESP SA
Sep 17 10:44:44 charon 15[CHD] <con1000|16> SPI 0xc6400d7c, src 95.86.129.13 dst 95.66.128.14
Sep 17 10:44:44 charon 15[CHD] <con1000|16> adding inbound ESP SA
Sep 17 10:44:44 charon 15[CHD] <con1000|16> using HMAC_SHA1_96 for integrity
Sep 17 10:44:44 charon 15[CHD] <con1000|16> using AES_CBC for encryption
Sep 17 10:44:44 charon 15[CHD] <con1000|16> CHILD_SA con1001{37} state change: CREATED => INSTALLING
Sep 17 10:44:44 charon 15[CFG] <con1000|16> selected proposal: ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQSituation 2:
Sep 17 10:47:29 charon 11[IKE] <con1000|17> nothing to initiate
Sep 17 10:47:29 charon 11[IKE] <con1000|17> activating new tasks
Sep 17 10:47:29 charon 11[NET] <con1000|17> sending packet: from 95.66.128.14[500] to 95.86.129.13[500] (60 bytes)
Sep 17 10:47:29 charon 11[ENC] <con1000|17> generating QUICK_MODE request 267475125 [ HASH ]
Sep 17 10:47:29 charon 11[IKE] <con1000|17> QUICK_MODE task
Sep 17 10:47:29 charon 11[IKE] <con1000|17> reinitiating already active tasks
Sep 17 10:47:29 charon 11[CHD] <con1000|17> CHILD_SA con1000{39} state change: INSTALLING => INSTALLED
Sep 17 10:47:29 charon 11[IKE] <con1000|17> CHILD_SA con1000{39} established with SPIs c3bb2f87_i ad4ae885_o and TS 192.168.4.245/32|/0 === 192.168.81.3/32|/0
Sep 17 10:47:29 charon 11[CHD] <con1000|17> SPI 0xad4ae885, src 95.66.128.14 dst 95.86.129.13
Sep 17 10:47:29 charon 11[CHD] <con1000|17> adding outbound ESP SA
Sep 17 10:47:29 charon 11[CHD] <con1000|17> SPI 0xc3bb2f87, src 95.86.129.13 dst 95.66.128.14
Sep 17 10:47:29 charon 11[CHD] <con1000|17> adding inbound ESP SA
Sep 17 10:47:29 charon 11[CHD] <con1000|17> using HMAC_SHA1_96 for integrity
Sep 17 10:47:29 charon 11[CHD] <con1000|17> using AES_CBC for encryption
Sep 17 10:47:29 charon 11[CHD] <con1000|17> CHILD_SA con1000{39} state change: CREATED => INSTALLING
Sep 17 10:47:29 charon 11[CFG] <con1000|17> selected proposal: ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ
Sep 17 10:47:29 charon 11[CFG] <con1000|17> configured proposals: ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ
Sep 17 10:47:29 charon 11[CFG] <con1000|17> received proposals: ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ
Sep 17 10:47:29 charon 11[CFG] <con1000|17> proposal matches
Sep 17 10:47:29 charon 11[CFG] <con1000|17> selecting proposal:
Sep 17 10:47:29 charon 11[ENC] <con1000|17> parsed QUICK_MODE response 267475125 [ HASH SA No KE ID ID N((24576)) ]
Sep 17 10:47:29 charon 11[NET] <con1000|17> received packet: from 95.86.129.13[500] to 95.66.128.14[500] (316 bytes)
Sep 17 10:47:29 charon 11[NET] <con1000|17> sending packet: from 95.66.128.14[500] to 95.86.129.13[500] (380 bytes)
Sep 17 10:47:29 charon 11[ENC] <con1000|17> generating QUICK_MODE request 267475125 [ HASH SA No KE ID ID ]
Sep 17 10:47:29 charon 11[CFG] <con1000|17> 192.168.81.3/32|/0
Sep 17 10:47:29 charon 11[CFG] <con1000|17> proposing traffic selectors for other:
Sep 17 10:47:29 charon 11[CFG] <con1000|17> 192.168.4.245/32|/0
Sep 17 10:47:29 charon 11[CFG] <con1000|17> proposing traffic selectors for us:
Sep 17 10:47:29 charon 11[CFG] <con1000|17> configured proposals: ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ
Sep 17 10:47:29 charon 11[CFG] <con1000|17> configured proposals: ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ
Sep 17 10:47:29 charon 11[IKE] <con1000|17> activating QUICK_MODE task
Sep 17 10:47:29 charon 11[IKE] <con1000|17> activating new tasks
Sep 17 10:47:29 charon 11[IKE] <con1000|17> maximum IKE_SA lifetime 86390s
Sep 17 10:47:29 charon 11[IKE] <con1000|17> scheduling reauthentication in 85850s
Sep 17 10:47:29 charon 11[IKE] <con1000|17> IKE_SA con1000[17] state change: CONNECTING => ESTABLISHED
Sep 17 10:47:29 charon 11[IKE] <con1000|17> IKE_SA con1000[17] established between 95.66.128.14[95.66.128.14]...95.86.129.13[95.86.129.13]
Sep 17 10:47:29 charon 11[IKE] <con1000|17> received DPD vendor ID
Sep 17 10:47:29 charon 11[ENC] <con1000|17> parsed ID_PROT response 0 [ ID HASH V ]
Sep 17 10:47:29 charon 11[NET] <con1000|17> received packet: from 95.86.129.13[500] to 95.66.128.14[500] (92 bytes)
Sep 17 10:47:29 charon 11[NET] <con1000|17> sending packet: from 95.66.128.14[500] to 95.86.129.13[500] (108 bytes)
Sep 17 10:47:29 charon 11[ENC] <con1000|17> generating ID_PROT request 0 [ ID HASH N(INITIAL_CONTACT) ]
Sep 17 10:47:29 charon 11[IKE] <con1000|17> MAIN_MODE task
Sep 17 10:47:29 charon 11[IKE] <con1000|17> ISAKMP_VENDOR task
Sep 17 10:47:29 charon 11[IKE] <con1000|17> reinitiating already active tasks
Sep 17 10:47:29 charon 11[ENC] <con1000|17> received unknown vendor ID: 1f:07:f7:0e:aa:65:14:d3:b0:fa:96:54:2a:50:01:00
Sep 17 10:47:29 charon 11[ENC] <con1000|17> received unknown vendor ID: 84:5f:05:b5:25:53:78:f5:f7:aa:a3:aa:5c:7d:70:52
Sep 17 10:47:29 charon 11[IKE] <con1000|17> received XAuth vendor ID
Sep 17 10:47:29 charon 11[IKE] <con1000|17> received Cisco Unity vendor ID
Sep 17 10:47:29 charon 11[ENC] <con1000|17> parsed ID_PROT response 0 [ KE No V V V V ]
Sep 17 10:47:29 charon 11[NET] <con1000|17> received packet: from 95.86.129.13[500] to 95.66.128.14[500] (256 bytes) -
Both of those logs look like successful tunnel events. Are you certain that the logs posted match the state shown in the status page? Is there a CHILD_SA delete event somewhere after that?
-
Could you also please look at his logs?
Sep 18 12:12:28 charon 14[CFG] vici client 3603 disconnected
Sep 18 12:12:28 charon 13[CFG] vici client 3603 requests: list-sas
Sep 18 12:12:28 charon 13[CFG] vici client 3603 registered for: list-sa
Sep 18 12:12:28 charon 09[CFG] vici client 3603 connected
Sep 18 12:12:27 charon 13[CFG] vici client 3602 disconnected
Sep 18 12:12:27 charon 13[CFG] vici client 3602 requests: list-sas
Sep 18 12:12:27 charon 09[CFG] vici client 3602 registered for: list-sa
Sep 18 12:12:27 charon 09[CFG] vici client 3602 connected
Sep 18 12:12:25 charon 06[CFG] vici client 3601 disconnected
Sep 18 12:12:25 charon 06[CFG] vici client 3601 requests: list-sas
Sep 18 12:12:25 charon 06[CFG] vici client 3601 registered for: list-sa
Sep 18 12:12:25 charon 06[CFG] vici client 3601 connected
Sep 18 12:12:25 charon 07[IKE] <con1000|24> delaying task initiation, ID_PROT exchange in progress
Sep 18 12:12:25 charon 07[IKE] <con1000|24> queueing QUICK_MODE task
Sep 18 12:12:25 charon 16[CFG] received stroke: initiate 'con1001'
Sep 18 12:12:25 charon 07[IKE] <con1000|24> delaying task initiation, ID_PROT exchange in progress
Sep 18 12:12:25 charon 07[IKE] <con1000|24> queueing QUICK_MODE task
Sep 18 12:12:25 charon 16[IKE] <con1000|24> delaying task initiation, ID_PROT exchange in progress
Sep 18 12:12:25 charon 16[IKE] <con1000|24> queueing QUICK_MODE task
Sep 18 12:12:25 charon 05[CFG] received stroke: initiate 'con1002'
Sep 18 12:12:25 charon 11[CFG] received stroke: initiate 'con1000'
Sep 18 12:12:25 charon 16[CFG] no IKE_SA named 'con1001' found
Sep 18 12:12:25 charon 16[CFG] received stroke: terminate 'con1001'
Sep 18 12:12:25 charon 16[IKE] <con1000|25> IKE_SA con1000[25] state change: DELETING => DESTROYING
Sep 18 12:12:25 charon 16[NET] <con1000|25> sending packet: from 95.66.128.14[500] to 95.86.129.13[500] (92 bytes)
Sep 18 12:12:25 charon 16[ENC] <con1000|25> generating INFORMATIONAL_V1 request 645467201 [ HASH D ]
Sep 18 12:12:25 charon 16[IKE] <con1000|25> IKE_SA con1000[25] state change: ESTABLISHED => DELETING
Sep 18 12:12:25 charon 16[IKE] <con1000|25> sending DELETE for IKE_SA con1000[25]
Sep 18 12:12:25 charon 16[IKE] <con1000|25> deleting IKE_SA con1000[25] between 95.66.128.14[95.66.128.14]...95.86.129.13[95.86.129.13]
Sep 18 12:12:25 charon 16[IKE] <con1000|25> activating ISAKMP_DELETE task
Sep 18 12:12:25 charon 16[IKE] <con1000|25> activating new tasks
Sep 18 12:12:25 charon 16[NET] <con1000|25> sending packet: from 95.66.128.14[500] to 95.86.129.13[500] (76 bytes)
Sep 18 12:12:25 charon 16[ENC] <con1000|25> generating INFORMATIONAL_V1 request 883743667 [ HASH D ]
Sep 18 12:12:25 charon 16[IKE] <con1000|25> sending DELETE for ESP CHILD_SA with SPI c7411cc6
Sep 18 12:12:25 charon 16[CHD] <con1000|25> CHILD_SA con1002{54} state change: DELETING => DESTROYING
Sep 18 12:12:25 charon 16[IKE] <con1000|25> closing CHILD_SA con1002{54} with SPIs c7411cc6_i (0 bytes) 0d1b08f5_o (0 bytes) and TS 192.168.4.245/32|/0 === 192.168.81.5/32|/0
Sep 18 12:12:25 charon 16[CHD] <con1000|25> CHILD_SA con1002{54} state change: INSTALLED => DELETING
Sep 18 12:12:25 charon 16[IKE] <con1000|25> activating QUICK_DELETE task
Sep 18 12:12:25 charon 16[IKE] <con1000|25> activating new tasks
Sep 18 12:12:25 charon 16[NET] <con1000|25> sending packet: from 95.66.128.14[500] to 95.86.129.13[500] (76 bytes)
Sep 18 12:12:25 charon 16[ENC] <con1000|25> generating INFORMATIONAL_V1 request 2161405465 [ HASH D ]
Sep 18 12:12:25 charon 16[IKE] <con1000|25> sending DELETE for ESP CHILD_SA with SPI c4edb022
Sep 18 12:12:25 charon 16[CHD] <con1000|25> CHILD_SA con1001{53} state change: DELETING => DESTROYING
Sep 18 12:12:25 charon 16[IKE] <con1000|25> closing CHILD_SA con1001{53} with SPIs c4edb022_i (0 bytes) 99998231_o (0 bytes) and TS 192.168.4.245/32|/0 === 192.168.81.4/32|/0
Sep 18 12:12:25 charon 16[CHD] <con1000|25> CHILD_SA con1001{53} state change: INSTALLED => DELETING
Sep 18 12:12:25 charon 16[IKE] <con1000|25> activating QUICK_DELETE task
Sep 18 12:12:25 charon 16[IKE] <con1000|25> activating new tasks
Sep 18 12:12:25 charon 16[IKE] <con1000|25> queueing ISAKMP_DELETE task
Sep 18 12:12:25 charon 16[IKE] <con1000|25> queueing QUICK_DELETE task
Sep 18 12:12:25 charon 16[IKE] <con1000|25> queueing QUICK_DELETE task2:
Sep 18 12:14:58 charon 05[NET] <con1000|27> sending packet: from 95.66.128.14[500] to 95.86.129.13[500] (108 bytes)
Sep 18 12:14:58 charon 05[IKE] <con1000|27> sending retransmit 1 of request message ID 0, seq 3
Sep 18 12:14:58 charon 05[NET] <con1000|28> sending packet: from 95.66.128.14[500] to 95.86.129.13[500] (108 bytes)
Sep 18 12:14:58 charon 05[IKE] <con1000|28> sending retransmit 1 of request message ID 0, seq 3
Sep 18 12:14:54 charon 09[CFG] vici client 3636 disconnected
Sep 18 12:14:54 charon 11[CFG] vici client 3636 requests: list-sas
Sep 18 12:14:54 charon 11[CFG] vici client 3636 registered for: list-sa
Sep 18 12:14:54 charon 11[CFG] vici client 3636 connected
Sep 18 12:14:54 charon 05[IKE] <con1000|26> nothing to initiate
Sep 18 12:14:54 charon 05[IKE] <con1000|26> activating new tasks
Sep 18 12:14:54 charon 05[NET] <con1000|26> sending packet: from 95.66.128.14[500] to 95.86.129.13[500] (60 bytes)
Sep 18 12:14:54 charon 05[ENC] <con1000|26> generating QUICK_MODE request 3185272466 [ HASH ]
Sep 18 12:14:54 charon 05[IKE] <con1000|26> QUICK_MODE task
Sep 18 12:14:54 charon 05[IKE] <con1000|26> reinitiating already active tasks
Sep 18 12:14:54 charon 05[CHD] <con1000|26> CHILD_SA con1000{59} state change: INSTALLING => INSTALLED
Sep 18 12:14:54 charon 05[IKE] <con1000|26> CHILD_SA con1000{59} established with SPIs c0a470fc_i 0c847e13_o and TS 192.168.4.245/32|/0 === 192.168.81.3/32|/0
Sep 18 12:14:54 charon 05[CHD] <con1000|26> SPI 0x0c847e13, src 95.66.128.14 dst 95.86.129.13
Sep 18 12:14:54 charon 05[CHD] <con1000|26> adding outbound ESP SA
Sep 18 12:14:54 charon 05[CHD] <con1000|26> SPI 0xc0a470fc, src 95.86.129.13 dst 95.66.128.14
Sep 18 12:14:54 charon 05[CHD] <con1000|26> adding inbound ESP SA
Sep 18 12:14:54 charon 05[CHD] <con1000|26> using HMAC_SHA1_96 for integrity
Sep 18 12:14:54 charon 05[CHD] <con1000|26> using AES_CBC for encryption
Sep 18 12:14:54 charon 05[CHD] <con1000|26> CHILD_SA con1000{59} state change: CREATED => INSTALLING
Sep 18 12:14:54 charon 05[CFG] <con1000|26> selected proposal: ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ
Sep 18 12:14:54 charon 05[CFG] <con1000|26> configured proposals: ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ
Sep 18 12:14:54 charon 05[CFG] <con1000|26> received proposals: ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ
Sep 18 12:14:54 charon 05[CFG] <con1000|26> proposal matches
Sep 18 12:14:54 charon 05[CFG] <con1000|26> selecting proposal:
Sep 18 12:14:54 charon 05[ENC] <con1000|26> parsed QUICK_MODE response 3185272466 [ HASH SA No KE ID ID N((24576)) ]
Sep 18 12:14:54 charon 05[NET] <con1000|26> received packet: from 95.86.129.13[500] to 95.66.128.14[500] (316 bytes)
Sep 18 12:14:54 charon 05[NET] <con1000|26> sending packet: from 95.66.128.14[500] to 95.86.129.13[500] (380 bytes)
Sep 18 12:14:54 charon 05[ENC] <con1000|26> generating QUICK_MODE request 3185272466 [ HASH SA No KE ID ID ]
Sep 18 12:14:54 charon 05[CFG] <con1000|26> 192.168.81.3/32|/0
Sep 18 12:14:54 charon 05[CFG] <con1000|26> proposing traffic selectors for other:
Sep 18 12:14:54 charon 05[CFG] <con1000|26> 192.168.4.245/32|/0
Sep 18 12:14:54 charon 05[CFG] <con1000|26> proposing traffic selectors for us:
Sep 18 12:14:54 charon 12[IKE] <con1000|27> INFORMATIONAL_V1 request with message ID 2939440172 processing failed
Sep 18 12:14:54 charon 12[IKE] <con1000|27> ignore malformed INFORMATIONAL request
Sep 18 12:14:54 charon 12[IKE] <con1000|27> message parsing failed
Sep 18 12:14:54 charon 12[ENC] <con1000|27> could not decrypt payloads
Sep 18 12:14:54 charon 12[ENC] <con1000|27> invalid HASH_V1 payload length, decryption failed?
Sep 18 12:14:54 charon 12[NET] <con1000|27> received packet: from 95.86.129.13[500] to 95.66.128.14[500] (92 bytes)
Sep 18 12:14:54 charon 09[NET] <con1000|27> sending packet: from 95.66.128.14[500] to 95.86.129.13[500] (108 bytes)
Sep 18 12:14:54 charon 09[ENC] <con1000|27> generating ID_PROT request 0 [ ID HASH N(INITIAL_CONTACT) ]
Sep 18 12:14:54 charon 09[IKE] <con1000|27> MAIN_MODE task
Sep 18 12:14:54 charon 09[IKE] <con1000|27> ISAKMP_VENDOR task
Sep 18 12:14:54 charon 09[IKE] <con1000|27> reinitiating already active tasks
Sep 18 12:14:54 charon 05[CFG] <con1000|26> configured proposals: ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ
Sep 18 12:14:54 charon 05[CFG] <con1000|26> configured proposals: ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ
Sep 18 12:14:54 charon 05[IKE] <con1000|26> activating QUICK_MODE task3
Sep 18 12:15:59 charon 13[CFG] vici client 3649 disconnected
Sep 18 12:15:59 charon 10[CFG] vici client 3649 requests: list-sas
Sep 18 12:15:59 charon 10[CFG] vici client 3649 registered for: list-sa
Sep 18 12:15:59 charon 13[CFG] vici client 3649 connected
Sep 18 12:15:58 charon 13[IKE] unable to terminate IKE_SA: ID 26 not found
Sep 18 12:15:58 charon 05[CFG] received stroke: terminate 'con1000[26]'
Sep 18 12:15:55 charon 13[CFG] vici client 3648 disconnected
Sep 18 12:15:55 charon 05[CFG] vici client 3648 requests: list-sas
Sep 18 12:15:55 charon 05[CFG] vici client 3648 registered for: list-sa
Sep 18 12:15:55 charon 05[CFG] vici client 3648 connected
Sep 18 12:15:55 charon 05[IKE] <con1000|26> IKE_SA con1000[26] state change: DELETING => DESTROYING
Sep 18 12:15:55 charon 05[NET] <con1000|26> sending packet: from 95.66.128.14[500] to 95.86.129.13[500] (92 bytes)
Sep 18 12:15:55 charon 05[ENC] <con1000|26> generating INFORMATIONAL_V1 request 2886315804 [ HASH D ]
Sep 18 12:15:55 charon 05[IKE] <con1000|26> IKE_SA con1000[26] state change: ESTABLISHED => DELETING
Sep 18 12:15:55 charon 05[IKE] <con1000|26> sending DELETE for IKE_SA con1000[26]
Sep 18 12:15:55 charon 05[IKE] <con1000|26> deleting IKE_SA con1000[26] between 95.66.128.14[95.66.128.14]...95.86.129.13[95.86.129.13]
Sep 18 12:15:55 charon 05[IKE] <con1000|26> activating ISAKMP_DELETE task
Sep 18 12:15:55 charon 05[IKE] <con1000|26> activating new tasks
Sep 18 12:15:55 charon 05[NET] <con1000|26> sending packet: from 95.66.128.14[500] to 95.86.129.13[500] (76 bytes)
Sep 18 12:15:55 charon 05[ENC] <con1000|26> generating INFORMATIONAL_V1 request 2879275084 [ HASH D ]
Sep 18 12:15:55 charon 05[IKE] <con1000|26> sending DELETE for ESP CHILD_SA with SPI c0a470fc
Sep 18 12:15:55 charon 05[CHD] <con1000|26> CHILD_SA con1000{59} state change: DELETING => DESTROYING
Sep 18 12:15:55 charon 05[IKE] <con1000|26> closing CHILD_SA con1000{59} with SPIs c0a470fc_i (0 bytes) 0c847e13_o (0 bytes) and TS 192.168.4.245/32|/0 === 192.168.81.3/32|/0
Sep 18 12:15:55 charon 05[CHD] <con1000|26> CHILD_SA con1000{59} state change: INSTALLED => DELETING
Sep 18 12:15:55 charon 05[IKE] <con1000|26> activating QUICK_DELETE task
Sep 18 12:15:55 charon 05[IKE] <con1000|26> activating new tasks
Sep 18 12:15:55 charon 05[IKE] <con1000|26> queueing ISAKMP_DELETE task
Sep 18 12:15:55 charon 05[IKE] <con1000|26> queueing QUICK_DELETE task
Sep 18 12:15:55 charon 14[CFG] received stroke: terminate 'con1000[26]'
Sep 18 12:15:54 charon 05[IKE] <con1000|26> nothing to initiate
Sep 18 12:15:54 charon 05[IKE] <con1000|26> activating new tasks
Sep 18 12:15:54 charon 05[ENC] <con1000|26> parsed INFORMATIONAL_V1 request 3056708360 [ HASH N(DPD_ACK) ]
Sep 18 12:15:54 charon 05[NET] <con1000|26> received packet: from 95.86.129.13[500] to 95.66.128.14[500] (92 bytes)
Sep 18 12:15:54 charon 05[IKE] <con1000|26> nothing to initiate
Sep 18 12:15:54 charon 05[IKE] <con1000|26> activating new tasks -
What is on the other side?
-
I don't know what is happening on the other side. I will ask the remote side network administrator. There is same configurations on both sides. What could be the problem in your opinion?