Phase 2 error for IPSec Tunnel to Cisco Router

james_ss · Jan 3, 2021, 2:22 PM

Hello,

I am trying to create the ip-sec tunnel between pfsense installed on the AWS and Cisco Router placed behind my Home Router(Fritzbox).

Here's a short topology

(192.168.88.0/24)Cisco Router--->(192.168.178.1)Internet Router--->Internet--->AWS--->AWS-(public-IP and Private-IP[10.0.0.16/28])WAN with pfsense<----AWS Local LAN[10.0.0.0/28].

I see on the Cisco Router that the phase 1 negotiation is complete.

However as soon as the phase 2 starts(I hope it is phase 2), the session gets deleted.

and I see the error as follows

peer does not do paranoid keepalives

Cisco Router Logs

Jan 3 09:55:35.187: ISAKMP (1007): received packet from <pfsense ipv4 public ip> dport 4500 sport 4500 Global (R) MM_KEY_EXCH
*Jan 3 09:55:35.187: ISAKMP:( face-sad1007):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
*Jan 3 09:55:35.187: ISAKMP:( face-sad1007):Old State = IKE_R_MM4 New State = IKE_R_MM5

*Jan 3 09:55:35.187: ISAKMP:( face-sad1007): processing ID payload. message ID = 0
*Jan 3 09:55:35.187: ISAKMP (1007): ID payload
next-payload : 8
type : 1
address : 10.0.0.26
protocol : 0
port : 0
length : 12
*Jan 3 09:55:35.187: ISAKMP:( face-sad0):: peer matches none of the profiles
*Jan 3 09:55:35.187: ISAKMP:( face-sad1007): processing HASH payload. message ID = 0
*Jan 3 09:55:35.187: ISAKMP:( face-sad1007): processing NOTIFY INITIAL_CONTACT protocol 1
spi 0, message ID = 0, sa = 0x39F49A94
*Jan 3 09:55:35.187: ISAKMP:( face-sad1007):SA authentication status:
authenticated
*Jan 3 09:55:35.187: ISAKMP:( face-sad1007):SA has been authenticated with <pfsense ipv4 public ip>
*Jan 3 09:55:35.187: ISAKMP:( face-sad1007):Detected port floating to port = 4500
*Jan 3 09:55:35.187: ISAKMP: Trying to find existing peer 192.168.178.254/<pfsense ipv4 public ip>/4500/
*Jan 3 09:55:35.187: ISAKMP:( face-sad1007):SA authentication status:
authenticated
*Jan 3 09:55:35.187: ISAKMP:( face-sad1007): Process initial contact,
bring down existing phase 1 and 2 SA's with local 192.168.178.254 remote <pfsense ipv4 public ip> remote port 4500
*Jan 3 09:55:35.187: ISAKMP: Trying to insert a peer 192.168.178.254/<pfsense ipv4 public ip>/4500/, and inserted successfully 22C82AE8.
*Jan 3 09:55:35.187: ISAKMP:( face-sad1007):Setting UDP ENC peer struct 0x3E4564A4 sa= 0x39F49A94
*Jan 3 09:55:35.187: ISAKMP:( face-sad1007):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
*Jan 3 09:55:35.187: ISAKMP:( face-sad1007):Old State = IKE_R_MM5 New State = IKE_R_MM5

*Jan 3 09:55:35.187: IPSEC(key_engine): got a queue event with 1 KMI message(s)
*Jan 3 09:55:35.187: ISAKMP:( face-sad1007):SA is doing pre-shared key authentication using id type ID_IPV4_ADDR
*Jan 3 09:55:35.187: ISAKMP (1007): ID payload
next-payload : 8
type : 1
address : 192.168.178.254
protocol : 17
port : 0
length : 12
*Jan 3 09:55:35.187: ISAKMP: (1007):Total payload length: 12
*Jan 3 09:55:35.187: ISAKMP: (1007): sending packet to <pfsense ipv4 public ip> my_port 4500 peer_port 4500 (R) MM_KEY_EXCH
*Jan 3 09:55:35.187: ISAKMP: (1007):Sending an IKE IPv4 Packet.
*Jan 3 09:55:35.187: ISAKMP: (1007):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
*Jan 3 09:55:35.187: ISAKMP: (1007):Old State = IKE_R_MM5 New State = IKE_P1_COMPLETE

*Jan 3 09:55:35.187: ISAKMP: (1007):Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE
*Jan 3 09:55:35.187: ISAKMP: (1007):Old State = IKE_P1_COMPLETE New State = IKE_P1_COMPLETE

*Jan 3 09:55:35.363: ISAKMP (1007): received packet from <pfsense ipv4 public ip> dport 4500 sport 4500 Global (R) QM_IDLE
*Jan 3 09:55:35.363: ISAKMP: set new node 1035329911 to QM_IDLE
*Jan 3 09:55:35.363: ISAKMP: (1007): processing HASH payload. message ID = 1035329911
*Jan 3 09:55:35.363: ISAKMP: (1007): processing DELETE payload. message ID = 1035329911
*Jan 3 09:55:35.363: ISAKMP: (1007):peer does not do paranoid keepalives.

*Jan 3 09:55:35.363: ISAKMP: (1007):deleting SA reason "No reason" state (R) QM_IDLE (peer <pfsense ipv4 public ip>)
*Jan 3 09:55:35.367: ISAKMP: (1007):deleting node 1035329911 error FALSE reason "Informational (in) state 1"
*Jan 3 09:55:35.367: ISAKMP: set new node -684451573 to QM_IDLE
*Jan 3 09:55:35.367: ISAKMP: (1007): sending packet to <pfsense ipv4 public ip> my_port 4500 peer_port 4500 (R) QM_IDLE
*Jan 3 09:55:35.367: ISAKMP: (1007):Sending an IKE IPv4 Packet.
*Jan 3 09:55:35.367: ISAKMP: (1007):purging node -684451573
*Jan 3 09:55:35.367: ISAKMP: (1007):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL
*Jan 3 09:55:35.367: ISAKMP: (1007):Old State = IKE_P1_COMPLETE New State = IKE_DEST_SA

*Jan 3 09:55:35.367: ISAKMP: (1007):deleting SA reason "No reason" state (R) QM_IDLE (peer <pfsense ipv4 public ip>)
*Jan 3 09:55:35.367: ISAKMP: Unlocking peer struct 0x22C82AE8 for isadb_mark_sa_deleted(), count 0
*Jan 3 09:55:35.367: ISAKMP: Deleting peer node by peer_reap for <pfsense ipv4 public ip>: 22C82AE8
*Jan 3 09:55:35.367: ISAKMP: (1007):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
*Jan 3 09:55:35.367: ISAKMP: (1007):Old State = IKE_DEST_SA New State = IKE_DEST_SA

----pfsense Logs-----

Jan 3 14:20:40 charon 07[CFG] vici client 5535 disconnected
Jan 3 14:20:40 charon 07[CFG] vici client 5535 requests: list-sas
Jan 3 14:20:40 charon 07[CFG] vici client 5535 registered for: list-sa
Jan 3 14:20:40 charon 10[CFG] vici client 5535 connected
Jan 3 14:20:35 charon 12[CFG] vici client 5534 disconnected
Jan 3 14:20:35 charon 12[CFG] vici client 5534 requests: list-sas
Jan 3 14:20:35 charon 11[CFG] vici client 5534 registered for: list-sa
Jan 3 14:20:35 charon 16[CFG] vici client 5534 connected
Jan 3 14:20:30 charon 16[IKE] <con2000|202> IKE_SA con2000[202] state change: DELETING => DESTROYING
Jan 3 14:20:30 charon 16[NET] <con2000|202> sending packet: from 10.0.0.26[4500] to <Internet Router ipv4 public ip>[4500] (108 bytes)
Jan 3 14:20:30 charon 16[ENC] <con2000|202> generating INFORMATIONAL_V1 request 2332646188 [ HASH D ]
Jan 3 14:20:30 charon 16[IKE] <con2000|202> IKE_SA con2000[202] state change: CONNECTING => DELETING
Jan 3 14:20:30 charon 16[IKE] <con2000|202> sending DELETE for IKE_SA con2000[202]
Jan 3 14:20:30 charon 16[IKE] <con2000|202> deleting IKE_SA con2000[202] between 10.0.0.26[10.0.0.26]...<Internet Router ipv4 public ip>[%any]
Jan 3 14:20:30 charon 16[IKE] <con2000|202> activating ISAKMP_DELETE task
Jan 3 14:20:30 charon 16[IKE] <con2000|202> activating new tasks
Jan 3 14:20:30 charon 16[IKE] <con2000|202> queueing ISAKMP_DELETE task
Jan 3 14:20:30 charon 16[IKE] <con2000|202> IDir '192.168.178.254' does not match to '<Internet Router ipv4 public ip>'
Jan 3 14:20:30 charon 16[ENC] <con2000|202> parsed ID_PROT response 0 [ ID HASH ]
Jan 3 14:20:30 charon 16[NET] <con2000|202> received packet: from <Internet Router ipv4 public ip>[4500] to 10.0.0.26[4500] (92 bytes)
Jan 3 14:20:30 charon 16[NET] <con2000|202> sending packet: from 10.0.0.26[4500] to <Internet Router ipv4 public ip>[4500] (108 bytes)
Jan 3 14:20:30 charon 16[ENC] <con2000|202> generating ID_PROT request 0 [ ID HASH N(INITIAL_CONTACT) ]
Jan 3 14:20:30 charon 16[IKE] <con2000|202> MAIN_MODE task
Jan 3 14:20:30 charon 16[IKE] <con2000|202> ISAKMP_VENDOR task
Jan 3 14:20:30 charon 16[IKE] <con2000|202> reinitiating already active tasks
Jan 3 14:20:30 charon 16[IKE] <con2000|202> remote host is behind NAT
Jan 3 14:20:30 charon 16[IKE] <con2000|202> local host is behind NAT, sending keep alives
Jan 3 14:20:30 charon 16[IKE] <con2000|202> received XAuth vendor ID
Jan 3 14:20:30 charon 16[ENC] <con2000|202> received unknown vendor ID: 50:11:4d:d1:71:7e:12:57:06:20:d9:d7:30:ad:9a:37
Jan 3 14:20:30 charon 16[IKE] <con2000|202> received DPD vendor ID
Jan 3 14:20:30 charon 16[IKE] <con2000|202> received Cisco Unity vendor ID
Jan 3 14:20:30 charon 16[ENC] <con2000|202> parsed ID_PROT response 0 [ KE No V V V V NAT-D NAT-D ]
Jan 3 14:20:30 charon 16[NET] <con2000|202> received packet: from <Internet Router ipv4 public ip>[500] to 10.0.0.26[500] (456 bytes)
Jan 3 14:20:30 charon 16[CFG] vici client 5533 disconnected
Jan 3 14:20:30 charon 11[CFG] vici client 5533 requests: list-sas
Jan 3 14:20:30 charon 16[CFG] vici client 5533 registered for: list-sa
Jan 3 14:20:30 charon 09[CFG] vici client 5533 connected
Jan 3 14:20:30 charon 09[NET] <con2000|202> sending packet: from 10.0.0.26[500] to <Internet Router ipv4 public ip>[500] (396 bytes)
Jan 3 14:20:30 charon 09[ENC] <con2000|202> generating ID_PROT request 0 [ KE No NAT-D NAT-D ]
Jan 3 14:20:30 charon 09[IKE] <con2000|202> MAIN_MODE task
Jan 3 14:20:30 charon 09[IKE] <con2000|202> ISAKMP_VENDOR task
Jan 3 14:20:30 charon 09[IKE] <con2000|202> reinitiating already active tasks
Jan 3 14:20:30 charon 09[CFG] <con2000|202> selected proposal: IKE:AES_CBC_256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_2048
Jan 3 14:20:30 charon 09[CFG] <con2000|202> configured proposals: IKE:AES_CBC_256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_2048
Jan 3 14:20:30 charon 09[CFG] <con2000|202> received proposals: IKE:AES_CBC_256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_2048
Jan 3 14:20:30 charon 09[CFG] <con2000|202> proposal matches
Jan 3 14:20:30 charon 09[CFG] <con2000|202> selecting proposal:
Jan 3 14:20:30 charon 09[IKE] <con2000|202> received NAT-T (RFC 3947) vendor ID
Jan 3 14:20:30 charon 09[ENC] <con2000|202> parsed ID_PROT response 0 [ SA V ]
Jan 3 14:20:30 charon 09[NET] <con2000|202> received packet: from <Internet Router ipv4 public ip>[500] to 10.0.0.26[500] (108 bytes)
Jan 3 14:20:30 charon 09[NET] <con2000|202> sending packet: from 10.0.0.26[500] to <Internet Router ipv4 public ip>[500] (184 bytes)
Jan 3 14:20:30 charon 09[ENC] <con2000|202> generating ID_PROT request 0 [ SA V V V V V ]
Jan 3 14:20:30 charon 09[CFG] <con2000|202> configured proposals: IKE:AES_CBC_256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_2048
Jan 3 14:20:30 charon 09[IKE] <con2000|202> IKE_SA con2000[202] state change: CREATED => CONNECTING
Jan 3 14:20:30 charon 09[IKE] <con2000|202> initiating Main Mode IKE_SA con2000[202] to <Internet Router ipv4 public ip>
Jan 3 14:20:30 charon 09[IKE] <con2000|202> sending draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Jan 3 14:20:30 charon 09[IKE] <con2000|202> sending NAT-T (RFC 3947) vendor ID
Jan 3 14:20:30 charon 09[IKE] <con2000|202> sending FRAGMENTATION vendor ID
Jan 3 14:20:30 charon 09[IKE] <con2000|202> sending DPD vendor ID
Jan 3 14:20:30 charon 09[IKE] <con2000|202> sending XAuth vendor ID
Jan 3 14:20:30 charon 09[IKE] <con2000|202> activating ISAKMP_NATD task
Jan 3 14:20:30 charon 09[IKE] <con2000|202> activating ISAKMP_CERT_POST task
Jan 3 14:20:30 charon 09[IKE] <con2000|202> activating MAIN_MODE task
Jan 3 14:20:30 charon 09[IKE] <con2000|202> activating ISAKMP_CERT_PRE task
Jan 3 14:20:30 charon 09[IKE] <con2000|202> activating ISAKMP_VENDOR task
Jan 3 14:20:30 charon 09[IKE] <con2000|202> activating new tasks
Jan 3 14:20:30 charon 09[IKE] <con2000|202> queueing QUICK_MODE task
Jan 3 14:20:30 charon 09[IKE] <con2000|202> queueing ISAKMP_NATD task
Jan 3 14:20:30 charon 09[IKE] <con2000|202> queueing ISAKMP_CERT_POST task
Jan 3 14:20:30 charon 09[IKE] <con2000|202> queueing MAIN_MODE task
Jan 3 14:20:30 charon 09[IKE] <con2000|202> queueing ISAKMP_CERT_PRE task
Jan 3 14:20:30 charon 09[IKE] <con2000|202> queueing ISAKMP_VENDOR task
Jan 3 14:20:30 charon 12[CFG] received stroke: initiate 'con2000'
Jan 3 14:20:29 charon 05[CFG] no IKE_SA named 'con2000' found
Jan 3 14:20:29 charon 05[CFG] received stroke: terminate 'con2000'
Jan 3 14:20:28 charon 14[CFG] vici client 5532 disconnected
Jan 3 14:20:28 charon 06[CFG] vici client 5532 requests: list-sas
Jan 3 14:20:28 charon 14[CFG] vici client 5532 registered for: list-sa
Jan 3 14:20:28 charon 13[CFG] vici client 5532 connected
Jan 3 14:19:59 charon 07[CFG] vici client 5531 disconnected
Jan 3 14:19:59 charon 07[CFG] vici client 5531 requests: list-sas
Jan 3 14:19:59 charon 08[CFG] vici client 5531 registered for: list-sa
Jan 3 14:19:59 charon 10[CFG] vici client 5531 connected
Jan 3 14:19:54 charon 16[CFG] vici client 5530 disconnected
Jan 3 14:19:54 charon 12[CFG] vici client 5530 requests: list-sas
Jan 3 14:19:54 charon 12[CFG] vici client 5530 registered for: list-sa
Jan 3 14:19:54 charon 11[CFG] vici client 5530 connected

Any help would be greatly appreciated.

Thanks

philec · Oct 31, 2023, 2:46 PM

Hi,
I'm facing exactly the same issue. I presume that after 2 years, you found the root cause.
Could it be possible to let us know the solution ?
Thanks for your feedback.
Cheers.