On Thu, 2007-07-19 at 17:07 +0800, Adrian Chadd wrote: > On Thu, Jul 19, 2007, Arnaud Loonstra wrote: > > > What do you mean drifting. I've just check the clock on the router and > > the cache: > > > > cache: Thu Jul 19 10:48:29 CEST 2007 > > router: *10:39:55.771 CET Thu Jul 19 2007 > > > > So they are 10 minutes apart. > > I'll sync the cache clock using ntp which I should anyway. See if it > > helps? > > Well, WCCPv2 has 10 second event intervals, and the dead peer time is > 3 x the I_SEE_YOU time of 10 seconds; so your proxy must be not responding > to WCCPv2 for > 30 seconds. Maybe if its in a VM the event scheduling > is busted, or if the server is heavily loaded, or if somethings filtering/ > dropping the UDP packets. > > Its hard for me to diagnose further without having access to the kit. > Hopefully someone else can help you on the mailing list. > > > > > Adrian > It seems it's the other way around. A tcpdump reveals that the Cisco is not responding: 192.168.0.6 is the router. 11:55:26.386400 IP 192.168.0.6.2048 > proxy.2048: UDP, length 92 11:55:36.386101 IP proxy.2048 > 192.168.0.6.2048: UDP, length 144 11:55:36.387536 IP 192.168.0.6.2048 > proxy.2048: UDP, length 140 11:55:46.386740 IP proxy.2048 > 192.168.0.6.2048: UDP, length 144 11:55:46.387618 IP 192.168.0.6.2048 > proxy.2048: UDP, length 140 11:55:51.387101 IP proxy.2048 > 192.168.0.6.2048: UDP, length 336 11:55:56.387430 IP proxy.2048 > 192.168.0.6.2048: UDP, length 144 11:55:56.388326 IP 192.168.0.6.2048 > proxy.2048: UDP, length 140 11:56:06.388078 IP proxy.2048 > 192.168.0.6.2048: UDP, length 144 11:56:06.388889 IP 192.168.0.6.2048 > proxy.2048: UDP, length 140 11:56:16.388763 IP proxy.2048 > 192.168.0.6.2048: UDP, length 144 --- no response?? 11:56:16.389566 IP 192.168.0.6.2048 > proxy.2048: UDP, length 140 11:56:26.389433 IP proxy.2048 > 192.168.0.6.2048: UDP, length 144 11:56:36.394120 IP proxy.2048 > 192.168.0.6.2048: UDP, length 144 11:56:46.394736 IP proxy.2048 > 192.168.0.6.2048: UDP, length 144 11:56:56.395398 IP proxy.2048 > 192.168.0.6.2048: UDP, length 144 --- 11:56:56.396275 IP 192.168.0.6.2048 > proxy.2048: UDP, length 92 11:57:06.396089 IP proxy.2048 > 192.168.0.6.2048: UDP, length 144 11:57:06.397220 IP 192.168.0.6.2048 > proxy.2048: UDP, length 140 11:57:16.396732 IP proxy.2048 > 192.168.0.6.2048: UDP, length 144 11:57:16.397634 IP 192.168.0.6.2048 > proxy.2048: UDP, length 140 11:57:21.401092 IP proxy.2048 > 192.168.0.6.2048: UDP, length 336 11:57:26.397421 IP proxy.2048 > 192.168.0.6.2048: UDP, length 144 11:57:26.398209 IP 192.168.0.6.2048 > proxy.2048: UDP, length 140 11:57:36.398088 IP proxy.2048 > 192.168.0.6.2048: UDP, length 144 11:57:36.398946 IP 192.168.0.6.2048 > proxy.2048: UDP, length 140 11:57:46.398731 IP proxy.2048 > 192.168.0.6.2048: UDP, length 144 11:57:46.399609 IP 192.168.0.6.2048 > proxy.2048: UDP, length 140 11:57:56.399402 IP proxy.2048 > 192.168.0.6.2048: UDP, length 144 11:57:56.400293 IP 192.168.0.6.2048 > proxy.2048: UDP, length 140 11:58:06.400059 IP proxy.2048 > 192.168.0.6.2048: UDP, length 144 11:58:06.400903 IP 192.168.0.6.2048 > proxy.2048: UDP, length 140 Jul 19 11:56:56.382: %WCCP-1-SERVICELOST: Service web-cache lost on WCCP client 10.1.250.10 Jul 19 11:57:06.386: %WCCP-5-SERVICEFOUND: Service web-cache acquired on WCCP client 10.1.250.10 Some more wccp events debugging shows some other stuff as well Jul 19 12:57:06.809: %WCCP-1-SERVICELOST: Service web-cache lost on WCCP client 10.1.250.10 Jul 19 12:57:16.813: %WCCP-5-SERVICEFOUND: Service web-cache acquired on WCCP client 10.1.250.10 Jul 19 12:57:16.813: WCCP-EVNT:S00: Built new router view: 1 routers, 1 usable WCCP clients, change # 000028DC Jul 19 12:57:31.814: WCCP-EVNT:S00: Built new router view: 1 routers, 1 usable WCCP clients, change # 000028DC Jul 19 12:58:46.831: WCCP-EVNT:S00: Here_I_Am packet from 192.168.0.1 w/bad rcv_id 00033D1A Jul 19 12:58:56.832: WCCP-EVNT:S00: Here_I_Am packet from 192.168.0.1 w/bad rcv_id 00033D1A Jul 19 12:59:06.832: WCCP-EVNT:S00: Built new router view: 0 routers, 1 usable WCCP clients, change # 000028DD Jul 19 12:59:06.832: WCCP-EVNT:S00: Router 172.31.255.6 removed. Jul 19 12:59:06.832: WCCP-EVNT:S00: Built new router view: 0 routers, 0 usable WCCP clients, change # 000028DE Jul 19 12:59:06.832: %WCCP-1-SERVICELOST: Service web-cache lost on WCCP client 10.1.250.10 Jul 19 12:59:16.832: %WCCP-5-SERVICEFOUND: Service web-cache acquired on WCCP client 10.1.250.10 I don't know where the 192.168.0.1 comes from. That's a Cisco switch doing nothing with WCCP. 172.16.255.6 is the OSPF ID of the router. wccp packet debugging shows: ul 19 13:04:36.875: WCCP-PKT:S00: Sending I_See_You packet to 10.1.250.10 w/ rcv_id 00033D42 Jul 19 13:04:46.876: WCCP-PKT:S00: Received valid Here_I_Am packet from 10.1.250.10 w/rcv_id 00033D42 Jul 19 13:04:46.876: WCCP-PKT:S00: Sending I_See_You packet to 10.1.250.10 w/ rcv_id 00033D43 Jul 19 13:04:56.876: WCCP-PKT:S00: Received valid Here_I_Am packet from 10.1.250.10 w/rcv_id 00033D43 Jul 19 13:04:56.876: WCCP-PKT:S00: Sending I_See_You packet to 10.1.250.10 w/ rcv_id 00033D44 Jul 19 13:05:06.876: WCCP-PKT:S00: Received valid Here_I_Am packet from 10.1.250.10 w/rcv_id 00033D44 Jul 19 13:05:06.876: WCCP-PKT:S00: Sending I_See_You packet to 10.1.250.10 w/ rcv_id 00033D45 Jul 19 13:05:16.880: WCCP-PKT:S00: Received valid Here_I_Am packet from 192.168.0.1 w/rcv_id 00033D45 Jul 19 13:05:16.880: WCCP-PKT:S00: Sending I_See_You packet to 192.168.0.1 w/ rcv_id 00033D46 Jul 19 13:05:26.881: WCCP-PKT:S00: Sending I_See_You packet to 192.168.0.1 w/ rcv_id 00033D47 Jul 19 13:05:36.885: WCCP-PKT:S00: Sending I_See_You packet to 192.168.0.1 w/ rcv_id 00033D48 Jul 19 13:05:41.881: WCCP-PKT:S00: Sending Removal_Query packet to 192.168.0.1w/ rcv_id 00033D49 Jul 19 13:05:46.881: %WCCP-1-SERVICELOST: Service web-cache lost on WCCP client 10.1.250.10 Jul 19 13:05:46.885: WCCP-PKT:S00: Sending I_See_You packet to 10.1.250.10 w/ rcv_id 00033D4A Jul 19 13:05:56.893: %WCCP-5-SERVICEFOUND: Service web-cache acquired on WCCP client 10.1.250.10 Jul 19 13:05:56.893: WCCP-PKT:S00: Received valid Here_I_Am packet from 10.1.250.10 w/rcv_id 00033D4A Jul 19 13:05:56.893: WCCP-PKT:S00: Sending I_See_You packet to 10.1.250.10 w/ rcv_id 00033D4B Jul 19 13:06:06.893: WCCP-PKT:S00: Received valid Here_I_Am packet from 10.1.250.10 w/rcv_id 00033D4B Now,this is weird the cisco just suddenly starts sending wccp packets to 192.168.0.1??? Arnaud. Amarantis Onderwijsgroep is de concernorganisatie van ISA-scholen en ROC ASA
