IPSEC tunnel issues to a Cisco RV320



  • Hi All,

    Looking for some help with an IPSEC tunnel thats been driving me crazy for 3 days, I have checked both Phase 1 and Phase 2 they exactly match (attached images of both sides) also attached logs from Pfsense, the tunnel just doesn't seem to want to connect and its driving round the bend.

    Was wondering if someone could cast their eye over at the logs and settings to see if theres anything I have missed.

    0_1527343798786_cisco rv320.png
    0_1527343809889_pfsense phase 1.png
    0_1527343821891_pfsense phase 2.png

    Pfsense Logs

    May 26 14:49:18	charon		07[ENC] <con2000|180> parsed ID_PROT response 0 [ SA V ]
    May 26 14:49:18	charon		07[IKE] <con2000|180> received DPD vendor ID
    May 26 14:49:18	charon		07[CFG] <con2000|180> selecting proposal:
    May 26 14:49:18	charon		07[CFG] <con2000|180> proposal matches
    May 26 14:49:18	charon		07[CFG] <con2000|180> received proposals: IKE:AES_CBC_256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024
    May 26 14:49:18	charon		07[CFG] <con2000|180> configured proposals: IKE:AES_CBC_256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024
    May 26 14:49:18	charon		07[CFG] <con2000|180> selected proposal: IKE:AES_CBC_256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024
    May 26 14:49:18	charon		07[IKE] <con2000|180> reinitiating already active tasks
    May 26 14:49:18	charon		07[IKE] <con2000|180> ISAKMP_VENDOR task
    May 26 14:49:18	charon		07[IKE] <con2000|180> MAIN_MODE task
    May 26 14:49:18	charon		07[ENC] <con2000|180> generating ID_PROT request 0 [ KE No ]
    May 26 14:49:18	charon		07[NET] <con2000|180> sending packet: from xx.159.77.xx[500] to xx.159.28.xx[500] (196 bytes)
    May 26 14:49:18	charon		07[NET] <con2000|180> received packet: from xx.159.28.xx[500] to xx.159.77.xx[500] (180 bytes)
    May 26 14:49:18	charon		07[ENC] <con2000|180> parsed ID_PROT response 0 [ KE No ]
    May 26 14:49:18	charon		07[IKE] <con2000|180> reinitiating already active tasks
    May 26 14:49:18	charon		07[IKE] <con2000|180> ISAKMP_VENDOR task
    May 26 14:49:18	charon		07[IKE] <con2000|180> MAIN_MODE task
    May 26 14:49:18	charon		07[ENC] <con2000|180> generating ID_PROT request 0 [ ID HASH N(INITIAL_CONTACT) ]
    May 26 14:49:18	charon		07[NET] <con2000|180> sending packet: from xx.159.77.xx[500] to xx.159.28.xx[500] (108 bytes)
    May 26 14:49:18	charon		07[NET] <con2000|180> received packet: from xx.159.28.xx[500] to xx.159.77.xx[500] (76 bytes)
    May 26 14:49:18	charon		07[ENC] <con2000|180> parsed ID_PROT response 0 [ ID HASH ]
    May 26 14:49:18	charon		07[IKE] <con2000|180> IKE_SA con2000[180] established between xx.159.77.xx[xx.159.77.xx]...xx.159.28.xx[xx.159.28.xx]
    May 26 14:49:18	charon		07[IKE] <con2000|180> IKE_SA con2000[180] state change: CONNECTING => ESTABLISHED
    May 26 14:49:18	charon		07[IKE] <con2000|180> activating new tasks
    May 26 14:49:18	charon		07[IKE] <con2000|180> activating QUICK_MODE task
    May 26 14:49:18	charon		07[CFG] <con2000|180> configured proposals: ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ
    May 26 14:49:18	charon		07[CFG] <con2000|180> configured proposals: ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ
    May 26 14:49:18	charon		07[CFG] <con2000|180> proposing traffic selectors for us:
    May 26 14:49:18	charon		07[CFG] <con2000|180> 192.168.50.0/24|/0
    May 26 14:49:18	charon		07[CFG] <con2000|180> proposing traffic selectors for other:
    May 26 14:49:18	charon		07[CFG] <con2000|180> 192.168.10.0/24|/0
    May 26 14:49:18	charon		07[ENC] <con2000|180> generating QUICK_MODE request 298453xx43 [ HASH SA No KE ID ID ]
    May 26 14:49:18	charon		07[NET] <con2000|180> sending packet: from xx.159.77.xx[500] to xx.159.28.xx[500] (316 bytes)
    May 26 14:49:18	charon		15[NET] <con2000|180> received packet: from xx.159.28.xx[500] to xx.159.77.xx[500] (92 bytes)
    May 26 14:49:18	charon		15[ENC] <con2000|180> parsed INFORMATIONAL_V1 request 2420651128 [ HASH D ]
    May 26 14:49:18	charon		15[IKE] <con2000|180> received DELETE for IKE_SA con2000[180]
    May 26 14:49:18	charon		15[IKE] <con2000|180> deleting IKE_SA con2000[180] between xx.159.77.xx[xx.159.77.xx]...xx.159.28.xx[xx.159.28.xx]
    May 26 14:49:18	charon		15[IKE] <con2000|180> IKE_SA con2000[180] state change: ESTABLISHED => DELETING
    May 26 14:49:18	charon		15[CHD] <con2000|180> CHILD_SA con2000{181} state change: CREATED => DESTROYING
    May 26 14:49:18	charon		15[IKE] <con2000|180> queueing ISAKMP_VENDOR task
    May 26 14:49:18	charon		15[IKE] <con2000|180> queueing ISAKMP_CERT_PRE task
    May 26 14:49:18	charon		15[IKE] <con2000|180> queueing MAIN_MODE task
    May 26 14:49:18	charon		15[IKE] <con2000|180> queueing ISAKMP_CERT_POST task
    May 26 14:49:18	charon		15[IKE] <con2000|180> queueing ISAKMP_NATD task
    May 26 14:49:18	charon		15[IKE] <con2000|180> activating new tasks
    May 26 14:49:18	charon		15[IKE] <con2000|180> activating ISAKMP_VENDOR task
    May 26 14:49:18	charon		15[IKE] <con2000|180> activating ISAKMP_CERT_PRE task
    
    May 26 14:49:32	charon		15[CFG] <con2000|266> configured proposals: ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ
    May 26 14:49:32	charon		15[CFG] <con2000|266> configured proposals: ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ
    May 26 14:49:32	charon		15[CFG] <con2000|266> proposing traffic selectors for us:
    May 26 14:49:32	charon		15[CFG] <con2000|266> 192.168.50.0/24|/0
    May 26 14:49:32	charon		15[CFG] <con2000|266> proposing traffic selectors for other:
    May 26 14:49:32	charon		15[CFG] <con2000|266> 192.168.10.0/24|/0
    May 26 14:49:32	charon		15[ENC] <con2000|266> generating QUICK_MODE request 1959359xx5 [ HASH SA No KE ID ID ]
    May 26 14:49:32	charon		15[NET] <con2000|266> sending packet: from xx.159.77.xx[500] to xx.159.28.xx[500] (316 bytes)
    May 26 14:49:32	charon		06[NET] <con2000|266> received packet: from xx.159.28.xx[500] to xx.159.77.xx[500] (92 bytes)
    May 26 14:49:32	charon		06[ENC] <con2000|266> parsed INFORMATIONAL_V1 request 840093170 [ HASH D ]
    May 26 14:49:32	charon		06[IKE] <con2000|266> received DELETE for IKE_SA con2000[266]
    May 26 14:49:32	charon		06[IKE] <con2000|266> deleting IKE_SA con2000[266] between xx.159.77.xx[xx.159.77.xx]...xx.159.28.xx[xx.159.28.xx]
    May 26 14:49:32	charon		06[IKE] <con2000|266> IKE_SA con2000[266] state change: ESTABLISHED => DELETING
    May 26 14:49:32	charon		06[CHD] <con2000|266> CHILD_SA con2000{267} state change: CREATED => DESTROYING
    May 26 14:49:32	charon		06[IKE] <con2000|266> queueing ISAKMP_VENDOR task
    May 26 14:49:32	charon		06[IKE] <con2000|266> queueing ISAKMP_CERT_PRE task
    May 26 14:49:32	charon		06[IKE] <con2000|266> queueing MAIN_MODE task
    May 26 14:49:32	charon		06[IKE] <con2000|266> queueing ISAKMP_CERT_POST task
    May 26 14:49:32	charon		06[IKE] <con2000|266> queueing ISAKMP_NATD task
    May 26 14:49:32	charon		06[IKE] <con2000|266> activating new tasks
    May 26 14:49:32	charon		06[IKE] <con2000|266> activating ISAKMP_VENDOR task
    May 26 14:49:32	charon		06[IKE] <con2000|266> activating ISAKMP_CERT_PRE task
    May 26 14:49:32	charon		06[IKE] <con2000|266> activating MAIN_MODE task
    May 26 14:49:32	charon		06[IKE] <con2000|266> activating ISAKMP_CERT_POST task
    May 26 14:49:32	charon		06[IKE] <con2000|266> activating ISAKMP_NATD task
    May 26 14:49:32	charon		06[IKE] <con2000|266> sending XAuth vendor ID
    May 26 14:49:32	charon		06[IKE] <con2000|266> sending DPD vendor ID
    May 26 14:49:32	charon		06[IKE] <con2000|266> sending FRAGMENTATION vendor ID
    May 26 14:49:32	charon		06[IKE] <con2000|266> sending NAT-T (RFC 3947) vendor ID
    May 26 14:49:32	charon		06[IKE] <con2000|266> sending draft-ietf-ipsec-nat-t-ike-02\n vendor ID
    May 26 14:49:32	charon		06[IKE] <con2000|266> initiating Main Mode IKE_SA con2000[267] to xx.159.28.xx
    May 26 14:49:32	charon		06[IKE] <con2000|266> IKE_SA con2000[267] state change: CREATED => CONNECTING
    May 26 14:49:32	charon		06[CFG] <con2000|266> configured proposals: IKE:AES_CBC_256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024
    May 26 14:49:32	charon		06[ENC] <con2000|266> generating ID_PROT request 0 [ SA V V V V V ]
    May 26 14:49:32	charon		06[NET] <con2000|266> sending packet: from xx.159.77.xx[500] to xx.159.28.xx[500] (180 bytes)
    May 26 14:49:32	charon		06[IKE] <con2000|266> IKE_SA con2000[266] state change: DELETING => DELETING
    May 26 14:49:32	charon		06[IKE] <con2000|266> IKE_SA con2000[266] state change: DELETING => DESTROYING
    May 26 14:49:32	charon		06[NET] <con2000|267> received packet: from xx.159.28.xx[500] to xx.159.77.xx[500] (104 bytes)
    May 26 14:49:32	charon		06[ENC] <con2000|267> parsed ID_PROT response 0 [ SA V ]
    May 26 14:49:32	charon		06[IKE] <con2000|267> received DPD vendor ID
    May 26 14:49:32	charon		06[CFG] <con2000|267> selecting proposal:
    May 26 14:49:32	charon		06[CFG] <con2000|267> proposal matches
    May 26 14:49:32	charon		06[CFG] <con2000|267> received proposals: IKE:AES_CBC_256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024
    May 26 14:49:32	charon		06[CFG] <con2000|267> configured proposals: IKE:AES_CBC_256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024
    May 26 14:49:32	charon		06[CFG] <con2000|267> selected proposal: IKE:AES_CBC_256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024
    May 26 14:49:32	charon		06[IKE] <con2000|267> reinitiating already active tasks
    May 26 14:49:32	charon		06[IKE] <con2000|267> ISAKMP_VENDOR task
    May 26 14:49:32	charon		06[IKE] <con2000|267> MAIN_MODE task
    May 26 14:49:32	charon		06[ENC] <con2000|267> generating ID_PROT request 0 [ KE No ]
    May 26 14:49:32	charon		06[NET] <con2000|267> sending packet: from xx.159.77.xx[500] to xx.159.28.xx[500] (196 bytes)
    

    RV320 Logs

    2018-05-26, 14:43:42	VPN Log	[g2gips0] #1220: [Tunnel Established] sent MR3, ISAKMP SA established
    2018-05-26, 14:43:42	VPN Log	[g2gips0] #1221: [Tunnel Established] sent MR3, ISAKMP SA established
    2018-05-26, 14:43:42	VPN Log	[g2gips0] #1222: [Tunnel Established] sent MR3, ISAKMP SA established
    2018-05-26, 14:43:42	VPN Log	[g2gips0] #1223: [Tunnel Established] sent MR3, ISAKMP SA established
    2018-05-26, 14:43:42	VPN Log	[g2gips0] #1224: [Tunnel Established] sent MR3, ISAKMP SA established
    2018-05-26, 14:43:42	VPN Log	[g2gips0] #1225: [Tunnel Established] sent MR3, ISAKMP SA established
    2018-05-26, 14:43:42	VPN Log	[g2gips0] #1226: [Tunnel Established] sent MR3, ISAKMP SA established
    2018-05-26, 14:43:42	VPN Log	[g2gips0] #1227: [Tunnel Established] sent MR3, ISAKMP SA established
    2018-05-26, 14:43:42	VPN Log	[g2gips0] #1228: [Tunnel Established] sent MR3, ISAKMP SA established
    2018-05-26, 14:43:42	VPN Log	[g2gips0] #1229: [Tunnel Established] sent MR3, ISAKMP SA established
    2018-05-26, 14:43:42	VPN Log	[g2gips0] #1230: [Tunnel Established] sent MR3, ISAKMP SA established
    2018-05-26, 14:43:42	VPN Log	[g2gips0] #1231: [Tunnel Established] sent MR3, ISAKMP SA established
    

    Thanks
    Steve



  • Bit further along ... Seems if the Cisco RV320 initialises the tunnel the tunnel comes up and everything is working fine, but if I initialise the tunnel on the pfSense side by pinging that subnet this is when the tunnel fails to come up

    if the pfsense side is the IKEv1 responder = IPSEC tunnel comes up and works
    if the pfsense side is the IKEv1 initiator = IPSEC tunnel fails to come up


  • Netgate

    Try unchecking that disable renegotiation checkbox on the pfSense phase 1.



  • @derelict - That fixes it! Thank you :) , cant believe I was one check box away from getting it working 👍



  • @derelict - I notice that this IPSEC tunnel tries to keep itself up all the time now, my other IPSEC tunnel disconnects after so long when theres no traffic. There any other settings I need to change on the pfsense to get the same behaviour. Thanks


  • Netgate

    Something is keeping it up or you are not waiting long enough. Your P1 lifetime is 24 hours. P2 is 6 hours.

    The P2 Automatically ping host setting is used to generate traffic interesting to IPsec and keep a tunnel up. You do not have that set.



  • @derelict - Restarted the Cisco router the other end, initiated some traffic and have left it for a couple of hours and the tunnel is still up

    ESTABLISHED 10197 seconds (02:49:57) ago
    

    Checked the Pfsense logs and seems pfsense is sending packets to the cisco side and back keeping the tunnel up

    15[IKE] <con2000|2> activating new tasks
    May 27 22:09:52	charon		15[IKE] <con2000|2> activating ISAKMP_DPD task
    May 27 22:09:52	charon		15[ENC] <con2000|2> generating INFORMATIONAL_V1 request 591633065 [ HASH N(DPD) ]
    May 27 22:09:52	charon		15[NET] <con2000|2> sending packet: from xx.159.77.xx[500] to xx.159.28.xx[500] (92 bytes)
    May 27 22:09:52	charon		15[IKE] <con2000|2> activating new tasks
    May 27 22:09:52	charon		15[IKE] <con2000|2> nothing to initiate
    May 27 22:09:52	charon		15[NET] <con2000|2> received packet: from xx.159.28.xx[500] to xx.159.77.xx[500] (92 bytes)
    May 27 22:09:52	charon		15[ENC] <con2000|2> parsed INFORMATIONAL_V1 request 2024435232 [ HASH N(DPD_ACK) ]
    May 27 22:09:52	charon		15[IKE] <con2000|2> activating new tasks
    May 27 22:09:52	charon		15[IKE] <con2000|2> nothing to initiate
    May 27 22:09:54	charon		10[CFG] vici client 253 connected
    May 27 22:09:54	charon		12[CFG] vici client 253 registered for: list-sa
    May 27 22:09:54	charon		10[CFG] vici client 253 requests: list-sas
    May 27 22:09:54	charon		12[CFG] vici client 253 disconnected
    May 27 22:10:00	charon		10[CFG] vici client 254 connected
    May 27 22:10:00	charon		08[CFG] vici client 254 registered for: list-sa
    May 27 22:10:00	charon		08[CFG] vici client 254 requests: list-sas
    May 27 22:10:00	charon		08[CFG] vici client 254 disconnected
    May 27 22:10:02	charon		08[IKE] <con2000|2> sending DPD request
    May 27 22:10:02	charon		08[IKE] <con2000|2> queueing ISAKMP_DPD task
    May 27 22:10:02	charon		08[IKE] <con2000|2> activating new tasks
    May 27 22:10:02	charon		08[IKE] <con2000|2> activating ISAKMP_DPD task
    May 27 22:10:02	charon		08[ENC] <con2000|2> generating INFORMATIONAL_V1 request 4117561926 [ HASH N(DPD) ]
    May 27 22:10:02	charon		08[NET] <con2000|2> sending packet: from xx.159.77.xx[500] to xx.159.28.xx[500] (92 bytes)
    May 27 22:10:02	charon		08[IKE] <con2000|2> activating new tasks
    May 27 22:10:02	charon		08[IKE] <con2000|2> nothing to initiate
    May 27 22:10:02	charon		08[NET] <con2000|2> received packet: from xx.159.28.xx[500] to xx.159.77.xx[500] (92 bytes)
    May 27 22:10:02	charon		08[ENC] <con2000|2> parsed INFORMATIONAL_V1 request 3487328383 [ HASH N(DPD_ACK) ]
    May 27 22:10:02	charon		08[IKE] <con2000|2> activating new tasks
    May 27 22:10:02	charon		08[IKE] <con2000|2> nothing to initiate
    May 27 22:10:05	charon		10[CFG] vici client 255 connected
    May 27 22:10:05	charon		06[CFG] vici client 255 registered for: list-sa
    May 27 22:10:05	charon		06[CFG] vici client 255 requests: list-sas
    May 27 22:10:05	charon		08[CFG] vici client 255 disconnected
    May 27 22:10:10	charon		10[CFG] vici client 256 connected
    May 27 22:10:10	charon		14[CFG] vici client 256 registered for: list-sa
    May 27 22:10:10	charon		14[CFG] vici client 256 requests: list-sas
    May 27 22:10:10	charon		14[CFG] vici client 256 disconnected
    May 27 22:10:12	charon		10[IKE] <con2000|2> sending DPD request
    May 27 22:10:12	charon		10[IKE] <con2000|2> queueing ISAKMP_DPD task
    May 27 22:10:12	charon		10[IKE] <con2000|2> activating new tasks
    May 27 22:10:12	charon		10[IKE] <con2000|2> activating ISAKMP_DPD task
    May 27 22:10:12	charon		10[ENC] <con2000|2> generating INFORMATIONAL_V1 request 3558210549 [ HASH N(DPD) ]
    May 27 22:10:12	charon		10[NET] <con2000|2> sending packet: from xx.159.77.xx[500] to xx.159.28.xx[500] (92 bytes)
    May 27 22:10:12	charon		10[IKE] <con2000|2> activating new tasks
    May 27 22:10:12	charon		10[IKE] <con2000|2> nothing to initiate
    May 27 22:10:12	charon		14[NET] <con2000|2> received packet: from xx.159.28.xx[500] to xx.159.77.xx[500] (92 bytes)
    May 27 22:10:12	charon		14[ENC] <con2000|2> parsed INFORMATIONAL_V1 request 3190363268 [ HASH N(DPD_ACK) ]
    May 27 22:10:12	charon		14[IKE] <con2000|2> activating new tasks
    May 27 22:10:12	charon		14[IKE] <con2000|2> nothing to initiate
    

    The tunnel was going down previously before I replaced the router this side from a cisco rv320 with a pfsense router.

    Thanks
    Steve


  • Netgate

    Like I said. Your timeouts are 24 hours and 6 hours.

    Why are you sweating this?

    What you are seeing is dead peer detection, not traffic that should keep the tunnel up.



  • @derelict - have amended the timeouts - was expecting the same as the other ipsec tunnel to the cisco asa. Its cool :)

    Would like to say thanks for all the help! :) Loving Pfsense so far



  • @stevetoza Off-Topic but here goes. We've experienced all sorts of things with the Cisco RV325 series. Stability however isn’t one of them when running several heavy traffic IPSec tunnels. We swapped out our RV320/325's for virtual pfSense appliances. After a lengthy support thread with a very helpful Cisco support guy they swapped all our units for the new RV340 which is a significantly better hardware platform but since we've been bitten quite a few times by RV320's just going dark on us we now use them as expensive switches. SNMP showed that each time they went offline it was because of pure memory starvation. An RV325 unit with 5 IPSec tunnels and a bunch of local attached stuff would keep running for max 2-3 weeks and then would slowly die, first the web-console would stop responding (and it's already painstakingly slow) and a few hours later all the IPSec tunnels would become unresponsive. There's no automation for these boxes and we don't have managed PDU's so instead of driving to the site location to switch them literally off & back on I rolled some selenium GUI manipulation to power-cycle them every week like that. Seriously. Also had to power cycle twice because sometimes the first reboot wouldn't bring up the IPSec tunnels and when that happened they would never become active, only a secondary reboot would fix that.
    Seeing your print screen of the web-console throws me back to a lonely, dark and painful place ;)


 

© Copyright 2002 - 2018 Rubicon Communications, LLC | Privacy Policy