Odd Site-to-Site VPN Log Activity

[SamirD]

I have two rv016s connected site-to-site to Netgear FVS114 and FVS124G.  But while the SA lifetimes are set for 3600, I'm seeing tunnel activity in the logs almost every minute like this:

Mar  1 12:05:09 2014	VPN Log	[Tunnel Negotiation Info] Quick Mode Phase 2 SA Established, IPSec Tunnel Connected
Mar  1 12:05:09 2014	VPN Log	[Tunnel Negotiation Info] Quick Mode Phase 2 SA Established, IPSec Tunnel Connected
Mar  1 12:05:09 2014	VPN Log	[Tunnel Negotiation Info] >>> Initiator Send Quick Mode 3rd packet
Mar  1 12:05:09 2014	VPN Log	[Tunnel Negotiation Info] Outbound SPI value = da651654
Mar  1 12:05:09 2014	VPN Log	[Tunnel Negotiation Info] Inbound  SPI value = fe2d6610
Mar  1 12:05:09 2014	VPN Log	[Tunnel Negotiation Info] <<< Initiator Received Quick Mode 2nd packet
Mar  1 12:05:09 2014	VPN Log	[Tunnel Negotiation Info] >>> Initiator send Quick Mode 1st packet
Mar  1 12:05:09 2014	VPN Log	initiating Quick Mode PSK+ENCRYPT+TUNNEL+NAT-T to replace #865
Mar  1 12:05:01 2014	VPN Log	Informational Exchange message is invalid because it has a previously used Message ID (0x8cf47d5c)
Mar  1 12:05:01 2014	VPN Log	Informational Exchange message is invalid because it has a previously used Message ID (0x8cf47d5c)
Mar  1 12:05:00 2014	VPN Log	Discarding duplicate packet; already STATE_MAIN_I4
Mar  1 12:04:53 2014	VPN Log	Informational Exchange message is invalid because it has a previously used Message ID (0x8cf47d5c)
Mar  1 12:04:49 2014	VPN Log	ignoring Delete SA payload: ISAKMP SA not found (maybe expired)
Mar  1 12:04:00 2014	VPN Log	[Tunnel Negotiation Info] Responder Cookies = 0ac d08f fcfe 73f
Mar  1 12:04:00 2014	VPN Log	[Tunnel Negotiation Info] Initiator Cookies = 4e7c fa42 a059 c577
Mar  1 12:04:00 2014	VPN Log	[Tunnel Negotiation Info] Main Mode Phase 1 SA Established
Mar  1 12:04:00 2014	VPN Log	Main mode peer ID is ID_IPV4_ADDR: '10.168.2.2'(This is the Netgear IP address behind another router)
Mar  1 12:04:00 2014	VPN Log	[Tunnel Negotiation Info] >>> Initiator Receive Main Mode 6th packet
Mar  1 12:04:00 2014	VPN Log	[Tunnel Negotiation Info] >>> Initiator Send Main Mode 5th packet
Mar  1 12:04:00 2014	VPN Log	[Tunnel Negotiation Info] <<< Initiator Received Main Mode 4th packet
Mar  1 12:03:59 2014	VPN Log	[Tunnel Negotiation Info] >>> Initiator send Main Mode 3rd packet
Mar  1 12:03:59 2014	VPN Log	[Tunnel Negotiation Info] <<< Initiator Received Main Mode 2nd packet
Mar  1 12:03:59 2014	VPN Log	Ignoring Vendor ID payload [648982785bedbdd6...]
Mar  1 12:03:59 2014	VPN Log	Received Vendor ID payload Type = [Dead Peer Detection]
Mar  1 12:03:59 2014	VPN Log	Received Vendor ID payload Type = [draft-ietf-ipsec-nat-t-ike-00]
Mar  1 12:03:59 2014	VPN Log	[Tunnel Negotiation Info] >>> Initiator Send Main Mode 1st packet
Mar  1 12:03:59 2014	VPN Log	Initiating Main Mode to replace #863
Mar  1 12:03:32 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:03:28 2014	VPN Log	[Tunnel Negotiation Info] Quick Mode Phase 2 SA Established, IPSec Tunnel Connected
Mar  1 12:03:28 2014	VPN Log	[Tunnel Negotiation Info] <<< Responder Received Quick Mode 3rd packet
Mar  1 12:03:27 2014	VPN Log	[Tunnel Negotiation Info] >>> Responder send Quick Mode 2nd packet
Mar  1 12:03:27 2014	VPN Log	[Tunnel Negotiation Info] Outbound SPI value = c582ca66
Mar  1 12:03:27 2014	VPN Log	[Tunnel Negotiation Info] Inbound  SPI value = fe2d660f
Mar  1 12:03:27 2014	VPN Log	[Tunnel Negotiation Info] <<< Responder Received Quick Mode 1st packet
Mar  1 12:01:10 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:00:31 2014	VPN Log	Informational Exchange message is invalid because it has a previously used Message ID (0xf14a5b81)
Mar  1 12:00:28 2014	VPN Log	ignoring Delete SA payload: ISAKMP SA not found (maybe expired)
Mar  1 12:00:09 2014	VPN Log	[Tunnel Negotiation Info] Quick Mode Phase 2 SA Established, IPSec Tunnel Connected

Here's another one that just seems like it's going bezerk with establishing tunnels:

Mar  1 12:30:49 2014	VPN Log	[Tunnel Negotiation Info] >>> Responder send Quick Mode 2nd packet
Mar  1 12:30:49 2014	VPN Log	[Tunnel Negotiation Info] Outbound SPI value = ee1d9944
Mar  1 12:30:49 2014	VPN Log	[Tunnel Negotiation Info] Inbound  SPI value = ea54adfc
Mar  1 12:30:49 2014	VPN Log	[Tunnel Negotiation Info] <<< Responder Received Quick Mode 1st packet
Mar  1 12:30:49 2014	VPN Log	[Tunnel Negotiation Info] Responder Cookies = e7bb 8999 0bb 55f1
Mar  1 12:30:49 2014	VPN Log	[Tunnel Negotiation Info] Initiator Cookies = 1a2 43e6 50e7 c24b
Mar  1 12:30:49 2014	VPN Log	[Tunnel Negotiation Info] Main Mode Phase 1 SA Established
Mar  1 12:30:49 2014	VPN Log	[Tunnel Negotiation Info] >>> Responder Send Main Mode 6th packet
Mar  1 12:30:49 2014	VPN Log	Main mode peer ID is ID_IPV4_ADDR: '69.73.703.187'
Mar  1 12:30:49 2014	VPN Log	[Tunnel Negotiation Info] <<< Responder Received Main Mode 5th packet
Mar  1 12:30:49 2014	VPN Log	[Tunnel Negotiation Info] >>> Responder send Main Mode 4th packet
Mar  1 12:30:48 2014	VPN Log	[Tunnel Negotiation Info] <<< Responder Received Main Mode 3rd packet
Mar  1 12:30:48 2014	VPN Log	[Tunnel Negotiation Info] <<< Responder Received Main Mode 3rd packet
Mar  1 12:30:48 2014	VPN Log	[Tunnel Negotiation Info] >>> Responder Send Main Mode 2nd packet
Mar  1 12:30:48 2014	VPN Log	[Tunnel Negotiation Info] <<< Responder Received Main Mode 1st packet
Mar  1 12:30:48 2014	VPN Log	received Delete SA payload: deleting ISAKMP State #11132
Mar  1 12:30:45 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:45 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:45 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:45 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:40 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:40 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:40 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:40 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:40 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:40 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:40 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:36 2014	VPN Log	[Tunnel Negotiation Info] Quick Mode Phase 2 SA Established, IPSec Tunnel Connected
Mar  1 12:30:36 2014	VPN Log	[Tunnel Negotiation Info] Quick Mode Phase 2 SA Established, IPSec Tunnel Connected
Mar  1 12:30:36 2014	VPN Log	[Tunnel Negotiation Info] Quick Mode Phase 2 SA Established, IPSec Tunnel Connected
Mar  1 12:30:36 2014	VPN Log	[Tunnel Negotiation Info] Quick Mode Phase 2 SA Established, IPSec Tunnel Connected
Mar  1 12:30:36 2014	VPN Log	[Tunnel Negotiation Info] Quick Mode Phase 2 SA Established, IPSec Tunnel Connected
Mar  1 12:30:36 2014	VPN Log	[Tunnel Negotiation Info] <<< Responder Received Quick Mode 3rd packet
Mar  1 12:30:36 2014	VPN Log	[Tunnel Negotiation Info] >>> Responder send Quick Mode 2nd packet
Mar  1 12:30:36 2014	VPN Log	[Tunnel Negotiation Info] Outbound SPI value = 9afb9a70
Mar  1 12:30:36 2014	VPN Log	[Tunnel Negotiation Info] Inbound  SPI value = ea54adfb
Mar  1 12:30:36 2014	VPN Log	[Tunnel Negotiation Info] <<< Responder Received Quick Mode 1st packet
Mar  1 12:30:35 2014	VPN Log	[Tunnel Negotiation Info] Responder Cookies = f39f a167 9a76 a182
Mar  1 12:30:35 2014	VPN Log	[Tunnel Negotiation Info] Initiator Cookies = 3e15 253 fde4 3a35
Mar  1 12:30:35 2014	VPN Log	[Tunnel Negotiation Info] Main Mode Phase 1 SA Established
Mar  1 12:30:35 2014	VPN Log	[Tunnel Negotiation Info] >>> Responder Send Main Mode 6th packet
Mar  1 12:30:35 2014	VPN Log	Main mode peer ID is ID_IPV4_ADDR: '69.73.703.187'
Mar  1 12:30:35 2014	VPN Log	[Tunnel Negotiation Info] <<< Responder Received Main Mode 5th packet
Mar  1 12:30:35 2014	VPN Log	[Tunnel Negotiation Info] >>> Responder send Main Mode 4th packet
Mar  1 12:30:35 2014	VPN Log	[Tunnel Negotiation Info] <<< Responder Received Main Mode 3rd packet
Mar  1 12:30:34 2014	VPN Log	[Tunnel Negotiation Info] >>> Responder Send Main Mode 2nd packet
Mar  1 12:30:34 2014	VPN Log	[Tunnel Negotiation Info] <<< Responder Received Main Mode 1st packet
Mar  1 12:30:34 2014	VPN Log	received Delete SA payload: deleting ISAKMP State #11130
Mar  1 12:30:31 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:31 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:31 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:31 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:31 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:26 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:26 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:26 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:26 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:26 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:22 2014	VPN Log	[Tunnel Negotiation Info] Quick Mode Phase 2 SA Established, IPSec Tunnel Connected
Mar  1 12:30:22 2014	VPN Log	[Tunnel Negotiation Info] Quick Mode Phase 2 SA Established, IPSec Tunnel Connected
Mar  1 12:30:22 2014	VPN Log	[Tunnel Negotiation Info] Quick Mode Phase 2 SA Established, IPSec Tunnel Connected
Mar  1 12:30:22 2014	VPN Log	[Tunnel Negotiation Info] Quick Mode Phase 2 SA Established, IPSec Tunnel Connected
Mar  1 12:30:22 2014	VPN Log	[Tunnel Negotiation Info] Quick Mode Phase 2 SA Established, IPSec Tunnel Connected
Mar  1 12:30:22 2014	VPN Log	[Tunnel Negotiation Info] Quick Mode Phase 2 SA Established, IPSec Tunnel Connected
Mar  1 12:30:22 2014	VPN Log	[Tunnel Negotiation Info] <<< Responder Received Quick Mode 3rd packet
Mar  1 12:30:22 2014	VPN Log	[Tunnel Negotiation Info] >>> Responder send Quick Mode 2nd packet
Mar  1 12:30:22 2014	VPN Log	[Tunnel Negotiation Info] Outbound SPI value = 9a21d322
Mar  1 12:30:22 2014	VPN Log	[Tunnel Negotiation Info] Inbound  SPI value = ea54adfa
Mar  1 12:30:22 2014	VPN Log	[Tunnel Negotiation Info] <<< Responder Received Quick Mode 1st packet
Mar  1 12:30:22 2014	VPN Log	[Tunnel Negotiation Info] Responder Cookies = 33d1 9cc0 a279 7d4d
Mar  1 12:30:22 2014	VPN Log	[Tunnel Negotiation Info] Initiator Cookies = fff2 8d26 78e4 4845
Mar  1 12:30:22 2014	VPN Log	[Tunnel Negotiation Info] Main Mode Phase 1 SA Established
Mar  1 12:30:22 2014	VPN Log	[Tunnel Negotiation Info] >>> Responder Send Main Mode 6th packet
Mar  1 12:30:22 2014	VPN Log	Main mode peer ID is ID_IPV4_ADDR: '69.73.703.187'
Mar  1 12:30:22 2014	VPN Log	[Tunnel Negotiation Info] <<< Responder Received Main Mode 5th packet
Mar  1 12:30:21 2014	VPN Log	[Tunnel Negotiation Info] >>> Responder send Main Mode 4th packet
Mar  1 12:30:21 2014	VPN Log	[Tunnel Negotiation Info] <<< Responder Received Main Mode 3rd packet
Mar  1 12:30:21 2014	VPN Log	[Tunnel Negotiation Info] >>> Responder Send Main Mode 2nd packet
Mar  1 12:30:21 2014	VPN Log	[Tunnel Negotiation Info] >>> Responder Send Main Mode 2nd packet
Mar  1 12:30:21 2014	VPN Log	[Tunnel Negotiation Info] >>> Responder Send Main Mode 2nd packet
Mar  1 12:30:21 2014	VPN Log	[Tunnel Negotiation Info] <<< Responder Received Main Mode 1st packet
Mar  1 12:30:21 2014	VPN Log	received Delete SA payload: deleting ISAKMP State #11128
Mar  1 12:30:18 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:18 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:18 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:13 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:13 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:13 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:13 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:13 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:08 2014	VPN Log	[Tunnel Negotiation Info] Quick Mode Phase 2 SA Established, IPSec Tunnel Connected
Mar  1 12:30:08 2014	VPN Log	[Tunnel Negotiation Info] Quick Mode Phase 2 SA Established, IPSec Tunnel Connected
Mar  1 12:30:08 2014	VPN Log	[Tunnel Negotiation Info] Quick Mode Phase 2 SA Established, IPSec Tunnel Connected
Mar  1 12:30:08 2014	VPN Log	[Tunnel Negotiation Info] Quick Mode Phase 2 SA Established, IPSec Tunnel Connected
Mar  1 12:30:08 2014	VPN Log	[Tunnel Negotiation Info] Quick Mode Phase 2 SA Established, IPSec Tunnel Connected
Mar  1 12:30:08 2014	VPN Log	[Tunnel Negotiation Info] Quick Mode Phase 2 SA Established, IPSec Tunnel Connected
Mar  1 12:30:08 2014	VPN Log	[Tunnel Negotiation Info] <<< Responder Received Quick Mode 3rd packet
Mar  1 12:30:08 2014	VPN Log	[Tunnel Negotiation Info] >>> Responder send Quick Mode 2nd packet
Mar  1 12:30:08 2014	VPN Log	[Tunnel Negotiation Info] Outbound SPI value = f4dc2980
Mar  1 12:30:08 2014	VPN Log	[Tunnel Negotiation Info] Inbound  SPI value = ea54adf9
Mar  1 12:30:08 2014	VPN Log	[Tunnel Negotiation Info] <<< Responder Received Quick Mode 1st packet
Mar  1 12:30:08 2014	VPN Log	[Tunnel Negotiation Info] Responder Cookies = be4b c078 afac 9ef6
Mar  1 12:30:08 2014	VPN Log	[Tunnel Negotiation Info] Initiator Cookies = 7c8e dd4d a0db 71d2
Mar  1 12:30:08 2014	VPN Log	[Tunnel Negotiation Info] Main Mode Phase 1 SA Established
Mar  1 12:30:08 2014	VPN Log	[Tunnel Negotiation Info] >>> Responder Send Main Mode 6th packet
Mar  1 12:30:08 2014	VPN Log	Main mode peer ID is ID_IPV4_ADDR: '69.73.703.187'
Mar  1 12:30:08 2014	VPN Log	[Tunnel Negotiation Info] <<< Responder Received Main Mode 5th packet
Mar  1 12:30:08 2014	VPN Log	[Tunnel Negotiation Info] >>> Responder send Main Mode 4th packet
Mar  1 12:30:08 2014	VPN Log	[Tunnel Negotiation Info] >>> Responder send Main Mode 4th packet
Mar  1 12:30:08 2014	VPN Log	[Tunnel Negotiation Info] <<< Responder Received Main Mode 3rd packet
Mar  1 12:30:07 2014	VPN Log	[Tunnel Negotiation Info] >>> Responder Send Main Mode 2nd packet
Mar  1 12:30:07 2014	VPN Log	[Tunnel Negotiation Info] <<< Responder Received Main Mode 1st packet
Mar  1 12:30:07 2014	VPN Log	received Delete SA payload: deleting ISAKMP State #11126
Mar  1 12:30:04 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:04 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:04 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:04 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:04 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:00 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:00 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2
Mar  1 12:30:00 2014	VPN Log	Discarding duplicate packet; already STATE_QUICK_R2

I've highlighted in yellow all the things that I think are odd on the first one.  Almost everything on the second one is odd to me.  Any ideas why there's so much re-negotiation?

Huntsville's Premiere Car and Bike e-magazine: www.huntsvillecarscene.com       

[mpyhala]

Samir,

The logs are interesting. I would like to see the tunnel settings on the RV016 and Netgear. Can you post some screenshots? (Mask sensitive information)

- Marty