Link to home
Create AccountLog in
Avatar of Ubertam
UbertamFlag for United States of America

asked on

Watchguard BOVPN Up, but no data flowing

I've been banging my head against a wall on this.  Our internet went down yesterday (Megapath outage) and when it finally came back up, the VPN was no longer working.  I checked Firebox System Manager and see the VPN is up on both sides, and Tacoma is sending and receiving (few packets), but Seattle is Sending only (small packets).  I can't ping across the VPN (usually not an issue) either direction.

I've rebooted both Fireboxes (Core x550e in Tacoma, Edge x55e in Seattle).
I've rebooted both Edgemarc's (phone system/router)
I've rebooted Tacoma's Cisco Bonded T1 router.
I've contacted Megapath who checked that nothing in the configuration changed, no firewall, and that our T1 lines are good.
I've submitted a ticket with Watchguard...that was about 12 hours ago.
Now I'm contacting the Experts.

It seems like it's done this before and come back up on its own, but after 16 hours of downtime, it's not coming back on its own.

I've tried rekeying the VPN, which is recognized on both sides, and the VPN stays up, but still no traffic flows.  


Recent logs:
Type	Date-Time	Detailed Message	
Debug	2011-08-10 07:42:36	 Sending DPD R_U_THERE_ACK message to 216.254.1.146:500, priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:36	******** RECV message on fd_server(7) ********, priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:36	RECV cmd:7, xpath:/ping (status:1, action:2, notification:5, wgcmd:7), priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:36	******** RECV an IKE packet at 64.81.14.238:500(socket:11 ifIndex:2) from Peer 216.254.1.146:500 ********, priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:36	IkeFindIsakmpPolicy: -->, priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:36	ike_match_if_name: Match pcy [Tacoma] dev:eth0, pkt if[2]:eth0, priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:36	Found IKE Policy [Tacoma, dev:eth0] for peer IP:216.254.1.146, numXform:1, pkt ifIndex:2, priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:36	IKE Policy details: 1th xform: grp:1 auth:1 encrypt:5 hash:1 lifeTime:86400 lifeKB:0, priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:36	IkeFindIsakmpPolicy: <--, priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:36	Use IKE Policy[Tacoma], priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:36	SetCipherAlg[DES-EDE3-CBC], priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:36	IkeNotifyPayloadNtoH : SPI Size 16 first4(0xf83a9e45), priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:36	Process Notify Payload : NOTIFY-TYPE : 36136 , priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:36	Process ISAKMP Notify : from peer 0xd8fe0192 protocol 1 SPI 459e3af8, priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:36	IkeInNotifyProcess: Recieved a DPD R_U_THERE message from 216.254.1.146:500 Seq:165337989 DataSz:4, priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:36	Received a DPD R_U_THERE message from 216.254.1.146:500, priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:36	IkeInNotifyProcess: Notify kernel - peer gateway is UP (peerIp:216.254.1.146, ifIdx:2, pcyName:Tacoma), priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:36	ike_p1_status_chg: ikePcyName:Tacoma, status:UP, priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:36	ikeMultiWanVpnFailBack: -->, priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:36	ikeMultiWanVpnFailBack: MWAN notify ikePcy:0x8287b94(Tacoma), p1said:0x2219c43 UP, priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:36	ikeMultiWanMarkIkePcyObj: MWAN using ikePcyGrp(Tacoma) and ipsecPcy(PCVKVPNTunnel), priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:36	ikeMultiWanMarkIkePcyObj: MWAN ikePcyGroup(Tacoma)'s ikePcy(Tacoma) ifStatus:0x80000002, mark it as UP, priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:36	ikeMultiWanVpnFailBack: MWAN ikePcyGrp(Tacoma)'s numofMbrs is eqaul to 1, do nothing, priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:36	IkeNotifyPayloadHtoN : net order spi(0x45 0x9e 0x3a 0xf8)  , priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:36	SetCipherAlg[DES-EDE3-CBC], priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:36	 Sending DPD R_U_THERE_ACK message to 216.254.1.146:500, priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:56	******** RECV message on fd_server(7) ********, priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:56	RECV cmd:7, xpath:/ping (status:1, action:2, notification:5, wgcmd:7), priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:56	******** RECV an IKE packet at 64.81.14.238:500(socket:11 ifIndex:2) from Peer 216.254.1.146:500 ********, priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:56	IkeFindIsakmpPolicy: -->, priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:56	ike_match_if_name: Match pcy [Tacoma] dev:eth0, pkt if[2]:eth0, priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:56	Found IKE Policy [Tacoma, dev:eth0] for peer IP:216.254.1.146, numXform:1, pkt ifIndex:2, priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:56	IKE Policy details: 1th xform: grp:1 auth:1 encrypt:5 hash:1 lifeTime:86400 lifeKB:0, priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:56	IkeFindIsakmpPolicy: <--, priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:56	Use IKE Policy[Tacoma], priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:56	SetCipherAlg[DES-EDE3-CBC], priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:56	IkeNotifyPayloadNtoH : SPI Size 16 first4(0xf83a9e45), priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:56	Process Notify Payload : NOTIFY-TYPE : 36136 , priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:56	Process ISAKMP Notify : from peer 0xd8fe0192 protocol 1 SPI 459e3af8, priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:56	IkeInNotifyProcess: Recieved a DPD R_U_THERE message from 216.254.1.146:500 Seq:165337990 DataSz:4, priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:56	Received a DPD R_U_THERE message from 216.254.1.146:500, priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:56	IkeInNotifyProcess: Notify kernel - peer gateway is UP (peerIp:216.254.1.146, ifIdx:2, pcyName:Tacoma), priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:56	ike_p1_status_chg: ikePcyName:Tacoma, status:UP, priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:56	ikeMultiWanVpnFailBack: -->, priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:56	ikeMultiWanVpnFailBack: MWAN notify ikePcy:0x8287b94(Tacoma), p1said:0x2219c43 UP, priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:56	ikeMultiWanMarkIkePcyObj: MWAN using ikePcyGrp(Tacoma) and ipsecPcy(PCVKVPNTunnel), priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:56	ikeMultiWanMarkIkePcyObj: MWAN ikePcyGroup(Tacoma)'s ikePcy(Tacoma) ifStatus:0x80000002, mark it as UP, priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:56	ikeMultiWanVpnFailBack: MWAN ikePcyGrp(Tacoma)'s numofMbrs is eqaul to 1, do nothing, priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:56	IkeNotifyPayloadHtoN : net order spi(0x45 0x9e 0x3a 0xf8)  , priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:42:56	SetCipherAlg[DES-EDE3-CBC], priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:43:19	 Sending DPD R_U_THERE_ACK message to 216.254.1.146:500, priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:43:19	******** RECV message on fd_server(7) ********, priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:43:19	RECV cmd:7, xpath:/ping (status:1, action:2, notification:5, wgcmd:7), priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:43:19	******** RECV an IKE packet at 64.81.14.238:500(socket:11 ifIndex:2) from Peer 216.254.1.146:500 ********, priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:43:19	IkeFindIsakmpPolicy: -->, priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:43:19	ike_match_if_name: Match pcy [Tacoma] dev:eth0, pkt if[2]:eth0, priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:43:19	Found IKE Policy [Tacoma, dev:eth0] for peer IP:216.254.1.146, numXform:1, pkt ifIndex:2, priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:43:19	IKE Policy details: 1th xform: grp:1 auth:1 encrypt:5 hash:1 lifeTime:86400 lifeKB:0, priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:43:19	IkeFindIsakmpPolicy: <--, priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:43:19	Use IKE Policy[Tacoma], priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:43:19	SetCipherAlg[DES-EDE3-CBC], priority=7, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:43:19	IkeNotifyPayloadNtoH : SPI Size 16 first4(0xf83a9e45), priority=6, proc_id=iked, msg_id=, tag=1002
Debug	2011-08-10 07:43:19	Process Notify Payload : NOTIFY-TYPE : 36136 , priority=7, proc_id=iked, msg_id=, tag=1002

Open in new window

User generated image
Avatar of Ubertam
Ubertam
Flag of United States of America image

ASKER

I am pinging a computer in Seattle from Tacoma and vice versa.  The pings are timing out.  The interesting thing is that they are all logged on the Tacoma Watchguard (see code).

They aren't logged in Seattle.

This tells me that traffic does indeed work from Seattle to Tacoma, but Tacoma isn't responding.
2011-08-10 09:02:08 Allow 192.168.17.167 192.168.16.2 icmp    1-Trusted Allowed 60 126 (BOVPN-Allow.in-00)  proc_id="firewall" rc="100" 	Traffic
2011-08-10 09:02:10 Allow 192.168.16.203 192.168.17.167 icmp   1-Trusted 0-External Allowed 60 127 (BOVPN-Allow.out-00)  proc_id="firewall" rc="100" 	Traffic
2011-08-10 09:02:13 Allow 192.168.17.167 192.168.16.2 icmp    1-Trusted Allowed 60 126 (BOVPN-Allow.in-00)  proc_id="firewall" rc="100" 	Traffic
2011-08-10 09:02:15 Allow 192.168.16.203 192.168.17.167 icmp   1-Trusted 0-External Allowed 60 127 (BOVPN-Allow.out-00)  proc_id="firewall" rc="100" 	Traffic
2011-08-10 09:02:18 Allow 192.168.17.167 192.168.16.2 icmp    1-Trusted Allowed 60 126 (BOVPN-Allow.in-00)  proc_id="firewall" rc="100" 	Traffic
2011-08-10 09:02:20 Allow 192.168.16.203 192.168.17.167 icmp   1-Trusted 0-External Allowed 60 127 (BOVPN-Allow.out-00)  proc_id="firewall" rc="100" 	Traffic
2011-08-10 09:02:23 Allow 192.168.17.167 192.168.16.2 icmp    1-Trusted Allowed 60 126 (BOVPN-Allow.in-00)  proc_id="firewall" rc="100" 	Traffic
2011-08-10 09:02:25 Allow 192.168.16.203 192.168.17.167 icmp   1-Trusted 0-External Allowed 60 127 (BOVPN-Allow.out-00)  proc_id="firewall" rc="100" 	Traffic
2011-08-10 09:02:28 Allow 192.168.17.167 192.168.16.2 icmp    1-Trusted Allowed 60 126 (BOVPN-Allow.in-00)  proc_id="firewall" rc="100" 	Traffic
2011-08-10 09:02:30 Allow 192.168.16.203 192.168.17.167 icmp   1-Trusted 0-External Allowed 60 127 (BOVPN-Allow.out-00)  proc_id="firewall" rc="100" 	Traffic
2011-08-10 09:02:33 Allow 192.168.17.167 192.168.16.2 icmp    1-Trusted Allowed 60 126 (BOVPN-Allow.in-00)  proc_id="firewall" rc="100" 	Traffic
2011-08-10 09:02:35 Allow 192.168.16.203 192.168.17.167 icmp   1-Trusted 0-External Allowed 60 127 (BOVPN-Allow.out-00)  proc_id="firewall" rc="100" 	Traffic
2011-08-10 09:02:38 Allow 192.168.17.167 192.168.16.2 icmp    1-Trusted Allowed 60 126 (BOVPN-Allow.in-00)  proc_id="firewall" rc="100" 	Traffic
2011-08-10 09:02:40 Allow 192.168.16.203 192.168.17.167 icmp   1-Trusted 0-External Allowed 60 127 (BOVPN-Allow.out-00)  proc_id="firewall" rc="100" 	Traffic
2011-08-10 09:02:43 Allow 192.168.17.167 192.168.16.2 icmp    1-Trusted Allowed 60 126 (BOVPN-Allow.in-00)  proc_id="firewall" rc="100" 	Traffic
2011-08-10 09:02:45 Allow 192.168.16.203 192.168.17.167 icmp   1-Trusted 0-External Allowed 60 127 (BOVPN-Allow.out-00)  proc_id="firewall" rc="100" 	Traffic
2011-08-10 09:02:48 Allow 192.168.17.167 192.168.16.2 icmp    1-Trusted Allowed 60 126 (BOVPN-Allow.in-00)  proc_id="firewall" rc="100" 	Traffic
2011-08-10 09:02:50 Allow 192.168.16.203 192.168.17.167 icmp   1-Trusted 0-External Allowed 60 127 (BOVPN-Allow.out-00)  proc_id="firewall" rc="100" 	Traffic
2011-08-10 09:02:53 Allow 192.168.17.167 192.168.16.2 icmp    1-Trusted Allowed 60 126 (BOVPN-Allow.in-00)  proc_id="firewall" rc="100" 	Traffic

Open in new window

Avatar of Robert Sutton Jr
It seems more like you have a receive issue on your Seattle side. When you rebooted that box was there a config change? Keys? Did it boot with the proper config? Let us know.
Avatar of Ubertam

ASKER

It booted up just fine; same config.  I even changed the keys on the tunnels on both sides and got the same exact result.  AFAI can tell, no config changes have happened on the Fireboxes - 99.99% certainty on that.  The only config changes have been post-mortem repair attempts by me.
I would be suspicious of MegaPath at this point. The configs did not change and the tunnel is up. Either the phase 2 settngs are off or something changed in the downtime. What kind of MegaPath service do you have? Do you have any management, MPLS or other special services on the MegaPath lines?
ASKER CERTIFIED SOLUTION
Avatar of Gig-A-Dee
Gig-A-Dee
Flag of United States of America image

Link to home
membership
Create an account to see this answer
Signing up is free. No credit card required.
Create Account
Avatar of Ubertam

ASKER

@Gig-A-Dee - This exactly what I ended up doing.  It worked.  I updated to the latest version of Fireware (11.4.x, I think).  I still don't know what sparked the problem, but deleting and recreating fixed it.

HINT: I was connected to my remote office via public IP address through WatchGuard System Manager, so the status of the VPN didn't matter and I could configure it as long as it was connected to the internet.  I had previously been worried that if I broke the VPN, I'd have to drive to the other office if no one else was there to get it back up.  This is probably obvious to most of you, but it helped me.
Wow! It amazes me WG hasn't resolved this "bug"!

Avatar of Ubertam

ASKER

I was using 11.2.x when it went down.  Upgrading to 11.4.x didn't fix it straight out.  It is possible the "bug" is fixed on newly created or non-problematic VPNs on 11.4.x.  If it happens again, I'll let you know that the bug is still out there.  :)
Great! Thanks and take care.