Re: [squid-users] CISCO + WCCP Stopping forward packets

From: Alex Montoanelli <alexm_at_unetvale.com.br>
Date: Tue, 19 May 2009 11:39:40 -0300

Hello all. I again.

In last week I updated my Cisco IOS to a Release T, but the problem continues.

Then I decid back to a old IOS - 12.4.-23 - , and update my Squid to
branch 3, more exactly version 3.15.

The problems that Stop Forward Packet, aparently disappeared.

Or better, the problem continues, but squid register again, and
traffic not stopping.

So I belive that the Cisco is not the Problem, but is the Squid.

Comparing files wccp2.c between 2 versions, I see a lot of changes.

In short, my current situation is:

I have 4 Squid's registering on a Cisco 2811.

From time to time, the squid's turn it off then register again.
Is working, but I believe that this is not correct way.

Regards.

Alex Montoanelli
Administração e Gerência de Redes
Unetvale Conectividade
+55 48 3263 8700

On Fri, May 8, 2009 at 12:42 PM, Ritter, Nicholas
<Nicholas.Ritter_at_americantv.com> wrote:
>
> My experience has been, and my local cisco field engineers were the ones who told me this, that you should always use the T train of IOS releases.
>
> -----Original Message-----
> From: alexmontoanelli_at_gmail.com [mailto:alexmontoanelli_at_gmail.com] On Behalf Of Alex Montoanelli
> Sent: Friday, May 08, 2009 8:29 AM
> To: squid-users
> Subject: Re: [squid-users] CISCO + WCCP Stopping forward packets
>
> Hi all.
>
> This problem appeared when I started to use more than one Squid to
> regiter on wccp/cisco.
>
> In the past, where I just use one squid, this not the case.
>
> Browsing the Web site cisco, I found this on Cisco IOS Changelog:
>
> http://www.cisco.com/en/US/docs/ios/12_4/release/notes/124MCAVS.html#wp280492
> -------------
> Resolved Caveats-Cisco IOS Release 12.4(21)
> This section describes possibly unexpected behavior by Cisco IOS
> Release 12.4(21). All the caveats listed in this section are resolved
> in Cisco IOS Release 12.4(21).
> *************
> CSCsm12247
> Symptoms: A Cisco IOS router configured for WCCP may stop redirecting
> traffic following a change in topology.
> Conditions: The router must be configured for WCCP redirection using
> the hash assignment method. When there is only a single appliance in
> the service group, the loss of hash assignment details is permanent.
> However with multiple appliances in the group, the loss of assignment
> information is transitory; the router soon recovers.
> Workaround: To recover the assignment details, the WCCP configuration
> needs to be removed and re-added to the router. Use the no ip wccp
> service command followed by ip wccp service args command.
> Additional Information: The changes address also situation where some
> wccp clients are sending modified weight field in the wccp message and
> this way create a topology change situation.
> ------
>
> I upgraded to IOS 12.4.(23), but problems remain.
>
> What you think to migrate to the IOS release T ?
>
> Anyone has using more than one Squid registered on the same router?
>
> Regards
>
> Alex
>
>
> On Mon, May 4, 2009 at 9:08 PM, Ritter, Nicholas
> <Nicholas.Ritter_at_americantv.com> wrote:
> > Yup....looks like an IOS related problem....try a different release of IOS.
> >
> >
> > -----Original Message-----
> > From: alexmontoanelli_at_gmail.com on behalf of Alex Montoanelli
> > Sent: Mon 5/4/2009 4:00 PM
> > To: squid-users
> > Subject: Re: [squid-users] CISCO + WCCP Stopping forward packets
> >
> > Hi, after a day works fine, the problem appear.
> >
> > I see the HereIAm and ISeeYou  packets between Cisco and Squid, above
> > is the logs of both.
> >
> > I have 4 Instances of Squid, running on the same machine, I just
> > shutdown 3 of then, and start again, and every one
> > go to normal. The fourth instance back to normal without any touch.
> >
> >
> > The *** mark, is the begin of trouble.
> >
> > ------CISCO--------
> > May  4 17:21:32 cliente-1-254.unetvale.com.br 240185: 240210: *May  4
> > 21:23:36: WCCP-PKT:S00: Sending I_See_You packet to 200.193.10.140 w/
> > rcv_id 00091ACD
> > May  4 17:21:37 cliente-1-254.unetvale.com.br 240188: 240213: *May  4
> > 21:23:41: WCCP-PKT:S00: Received valid Here_I_Am packet from
> > 200.193.10.141 w/rcv_id 00091ACB
> > May  4 17:21:37 cliente-1-254.unetvale.com.br 240189: 240214: *May  4
> > 21:23:41: WCCP-PKT:S00: Sending I_See_You packet to 200.193.10.141 w/
> > rcv_id 00091ACF
> > May  4 17:21:41 cliente-1-254.unetvale.com.br 240190: 240215: *May  4
> > 21:23:44: WCCP-PKT:S00: Received valid Here_I_Am packet from
> > 200.193.10.143 w/rcv_id 00091ACC
> > May  4 17:21:41 cliente-1-254.unetvale.com.br 240191: 240216: *May  4
> > 21:23:44: WCCP-PKT:S00: Sending I_See_You packet to 200.193.10.143 w/
> > rcv_id 00091AD0
> > May  4 17:21:42 cliente-1-254.unetvale.com.br 240192: 240217: *May  4
> > 21:23:46: WCCP-PKT:S00: Received valid Here_I_Am packet from
> > 200.193.10.140 w/rcv_id 00091ACD
> > May  4 17:21:42 cliente-1-254.unetvale.com.br 240193: 240218: *May  4
> > 21:23:46: WCCP-PKT:S00: Sending I_See_You packet to 200.193.10.140 w/
> > rcv_id 00091AD1
> > May  4 17:22:31 cliente-1-254.unetvale.com.br 240244: 240269: *May  4
> > 21:24:35: WCCP-EVNT:S00: Here_I_Am packet from 200.193.10.141 w/bad
> > rcv_id 00091ACB
> > May  4 17:22:32 cliente-1-254.unetvale.com.br 240247: 240272: *May  4
> > 21:24:36: WCCP-EVNT:S00: Here_I_Am packet from 200.193.10.140 w/bad
> > rcv_id 00091AD1
> > May  4 17:23:27 cliente-1-254.unetvale.com.br 240310: 240335: *May  4
> > 21:25:30: WCCP-PKT:S00: Received valid Here_I_Am packet from
> > 200.193.10.143 w/rcv_id 00091AFE
> > ****May  4 17:23:27 cliente-1-254.unetvale.com.br 240311: 240336: *May
> >  4 21:25:30: WCCP-EVNT:S00: Assignment wait timer started
> > May  4 17:23:31 cliente-1-254.unetvale.com.br 240314: 240339: *May  4
> > 21:25:34: WCCP-EVNT:S00: Redirect_Assignment packet from
> > 200.193.10.143 w/bad rcv_id 00091AFE
> > May  4 17:24:54 cliente-1-254.unetvale.com.br 240378: 240403: *May  4
> > 21:26:58: WCCP-EVNT:S00: Here_I_Am packet from 200.193.10.140 w/bad
> > rcv_id 00091AD1
> > May  4 17:24:54 cliente-1-254.unetvale.com.br 240379: 240404: *May  4
> > 21:26:58: WCCP-PKT:S00: Sending I_See_You packet to 200.193.10.140 w/
> > rcv_id 00091B24
> > May  4 17:25:34 cliente-1-254.unetvale.com.br 240419: 240444: *May  4
> > 21:27:38: WCCP-PKT:S00: Sending I_See_You packet to 200.193.10.140 w/
> > rcv_id 00091B39
> > May  4 17:25:42 cliente-1-254.unetvale.com.br 240429: 240454: *May  4
> > 21:27:46: WCCP-EVNT:S00: Here_I_Am packet from 200.193.10.141 w/bad
> > rcv_id 00091ACB
> > May  4 17:25:51 cliente-1-254.unetvale.com.br 240437: 240462: *May  4
> > 21:27:55: WCCP-PKT:S00: Sending I_See_You packet to 200.193.10.143 w/
> > rcv_id 00091B40
> > May  4 17:25:53 cliente-1-254.unetvale.com.br 240438: 240463: *May  4
> > 21:27:57: WCCP-EVNT:S00: Here_I_Am packet from 200.193.10.141 w/bad
> > rcv_id 00091ACB
> > May  4 17:25:53 cliente-1-254.unetvale.com.br 240439: 240464: *May  4
> > 21:27:57: WCCP-PKT:S00: Sending I_See_You packet to 200.193.10.141 w/
> > rcv_id 00091B41
> > May  4 17:25:57 cliente-1-254.unetvale.com.br 240440: 240465: *May  4
> > 21:28:01: WCCP-PKT:S00: Sending Removal_Query packet to
> > 200.193.10.141w/ rcv_id 00091B42
> > May  4 17:25:58 cliente-1-254.unetvale.com.br 240441: 240466: *May  4
> > 21:28:02: WCCP-EVNT:S00: Here_I_Am packet from 200.193.10.140 w/bad
> > rcv_id 00091AD1
> > May  4 17:25:58 cliente-1-254.unetvale.com.br 240442: 240467: *May  4
> > 21:28:02: WCCP-PKT:S00: Sending I_See_You packet to 200.193.10.140 w/
> > rcv_id 00091B43
> > May  4 17:25:58 cliente-1-254.unetvale.com.br 240443: 240468: *May  4
> > 21:28:03: WCCP-EVNT:S00: Here_I_Am packet from 200.193.10.142 w/bad
> > rcv_id 00091B25
> > May  4 17:25:58 cliente-1-254.unetvale.com.br 240444: 240469: *May  4
> > 21:28:03: WCCP-PKT:S00: Sending I_See_You packet to 200.193.10.142 w/
> > rcv_id 00091B44
> > May  4 17:25:58 cliente-1-254.unetvale.com.br 240445: 240470: *May  4
> > 21:28:03: WCCP-PKT:S00: Sending Removal_Query packet to
> > 200.193.10.140w/ rcv_id 00091B45
> > May  4 17:26:00 cliente-1-254.unetvale.com.br 240446: 240471: *May  4
> > 21:28:04: WCCP-PKT:S00: Sending Removal_Query packet to
> > 200.193.10.142w/ rcv_id 00091B46
> > May  4 17:26:23 cliente-1-254.unetvale.com.br 240474: 240499: *May  4
> > 21:28:27: WCCP-EVNT:S00: Here_I_Am packet from 200.193.10.141 w/bad
> > rcv_id 00091B41
> > May  4 17:26:28 cliente-1-254.unetvale.com.br 240476: 240501: *May  4
> > 21:28:32: WCCP-PKT:S00: Sending Removal_Query packet to
> > 200.193.10.141w/ rcv_id 00091B51
> > May  4 17:26:28 cliente-1-254.unetvale.com.br 240477: 240502: *May  4
> > 21:28:32: WCCP-EVNT:S00: Here_I_Am packet from 200.193.10.140 w/bad
> > rcv_id 00091B49
> > ----------
> >
> >
> > Squid - Cachelog
> > ----------
> > 2009/05/04 17:21:33| ctx: enter level  0:
> > 'http://wm-ttv-mirror01-mia.terra.com/kboing/439755.asf'
> > 2009/05/04 17:21:33| httpProcessReplyHeader: Impossible keep-alive
> > header from 'http://wm-ttv-mirror01-mia.terra.com/kboing/439755.asf'
> > 2009/05/04 17:21:41| ctx: exit level  0
> > 2009/05/04 17:21:41| wccp2HereIam: sending to service id 0
> > 2009/05/04 17:21:41| Sending HereIam packet size 144
> > 2009/05/04 17:21:41| Incoming WCCPv2 I_SEE_YOU length 264.
> > 2009/05/04 17:21:41| Complete packet received
> > 2009/05/04 17:21:41| Incoming WCCP2_I_SEE_YOU Received ID old=596685 new=596689.
> > 2009/05/04 17:21:41| Cleaning out cache list
> > 2009/05/04 17:21:41| checking cache list: (8c0ac1c8:8c0ac1c8)
> > 2009/05/04 17:21:41| checking cache list: (8d0ac1c8:8c0ac1c8)
> > 2009/05/04 17:21:41| checking cache list: (8e0ac1c8:8c0ac1c8)
> > 2009/05/04 17:21:41| checking cache list: (8f0ac1c8:8c0ac1c8)
> > 2009/05/04 17:21:41| Change not detected (2496 = 2496)
> > 2009/05/04 17:21:44| ctx: enter level  0: 'http://br.msn.com/'
> > 2009/05/04 17:21:44| httpProcessReplyHeader: Impossible keep-alive
> > header from 'http://br.msn.com/'
> > 2009/05/04 17:21:51| ctx: exit level  0
> > 2009/05/04 17:21:51| wccp2HereIam: sending to service id 0
> > 2009/05/04 17:21:51| Sending HereIam packet size 144
> > 2009/05/04 17:22:01| wccp2HereIam: sending to service id 0
> > 2009/05/04 17:22:01| Sending HereIam packet size 144
> > 2009/05/04 17:22:11| wccp2HereIam: sending to service id 0
> > 2009/05/04 17:22:11| Sending HereIam packet size 144
> > 2009/05/04 17:22:21| wccp2HereIam: sending to service id 0
> > 2009/05/04 17:22:21| Sending HereIam packet size 144
> > 2009/05/04 17:22:25| CACHEMGR: <unknown>@10.100.0.101 requesting 'info'
> > 2009/05/04 17:22:21| wccp2HereIam: sending to service id 0
> > 2009/05/04 17:22:21| Sending HereIam packet size 144
> > 2009/05/04 17:22:25| CACHEMGR: <unknown>@10.100.0.101 requesting 'info'
> > 2009/05/04 17:22:25| CACHEMGR: <unknown>@10.100.0.101 requesting 'info'
> > 2009/05/04 17:22:30| CACHEMGR: <unknown>@10.100.0.101 requesting 'counters'
> > 2009/05/04 17:22:30| CACHEMGR: <unknown>@10.100.0.101 requesting 'info'
> > 2009/05/04 17:22:31| wccp2HereIam: sending to service id 0
> > 2009/05/04 17:22:31| Sending HereIam packet size 144
> > 2009/05/04 17:22:41| wccp2HereIam: sending to service id 0
> > 2009/05/04 17:22:41| Sending HereIam packet size 144
> > 2009/05/04 17:22:51| wccp2HereIam: sending to service id 0
> > 2009/05/04 17:22:51| Sending HereIam packet size 144
> > 2009/05/04 17:23:01| wccp2HereIam: sending to service id 0
> > 2009/05/04 17:23:01| Sending HereIam packet size 144
> > 2009/05/04 17:23:11| wccp2HereIam: sending to service id 0
> > 2009/05/04 17:23:11| Sending HereIam packet size 144
> > 2009/05/04 17:23:26| wccp2HereIam: sending to service id 0
> > 2009/05/04 17:23:26| Sending HereIam packet size 144
> > 2009/05/04 17:24:33| wccp2HereIam: sending to service id 0
> > 2009/05/04 17:24:33| Sending HereIam packet size 144
> > 2009/05/04 17:24:43| wccp2HereIam: sending to service id 0
> > 2009/05/04 17:24:43| Sending HereIam packet size 144
> > 2009/05/04 17:24:53| wccp2HereIam: sending to service id 0
> > 2009/05/04 17:24:53| Sending HereIam packet size 144
> > 2009/05/04 17:25:03| wccp2HereIam: sending to service id 0
> > 2009/05/04 17:25:03| Sending HereIam packet size 144
> > 2009/05/04 17:25:13| wccp2HereIam: sending to service id 0
> > 2009/05/04 17:25:13| Sending HereIam packet size 144
> > 2009/05/04 17:25:23| wccp2HereIam: sending to service id 0
> > 2009/05/04 17:25:23| Sending HereIam packet size 144
> > 2009/05/04 17:25:33| wccp2HereIam: sending to service id 0
> > 2009/05/04 17:25:33| Sending HereIam packet size 144
> > -------------
> >
> >
> > Alex Montoanelli
> > Administração e Gerência de Redes
> > Unetvale Conectividade
> > +55 48 3263 8700
> >
> >
> > On Mon, May 4, 2009 at 11:35 AM, Ritter, Nicholas
> > <Nicholas.Ritter_at_americantv.com> wrote:
> >>
> >> I have not noticed other faqs requiring this, but make sure your iptables is allowing UDP port 2048 on the Ethernet and gre interfaces of the squid box and coming from the IP address listed in the "sh ip wccp" (the router identifier IP.)
> >>
> >> Also, update you IOS. The loss of the hello packets is the problem, but the reason behind the packet transmission loss is the mystery. You can try running a packet sniffer on the squid box to make sure it is sending the "Here I am" packets, are increase the debug level of squid to see them.
> >>
> >> My experience as been that the problem is on the Cisco side though.
> >>
> >> -----Original Message-----
> >> From: alexmontoanelli_at_gmail.com [mailto:alexmontoanelli_at_gmail.com] On Behalf Of Alex Montoanelli
> >> Sent: Monday, May 04, 2009 8:57 AM
> >> To: Ritter, Nicholas
> >> Subject: Re: [squid-users] CISCO + WCCP Stopping forward packets
> >>
> >> Hello Nicholas.
> >>
> >> When the service break down, the related fields, are not 0, is equal
> >> 1/1. ( 1 Client / 1 Router ).
> >>
> >> I have setting up a router to log to a syslog server, and when the
> >> issue occur, the packets/messages are not transmited.
> >>
> >> My router, a Cisco 2811 has running a
> >> 'flash:c2800nm-ipbase-mz.124-21.bin' / 12.4-21 IOS Version.
> >>
> >> On Mon, May 4, 2009 at 10:45 AM, Ritter, Nicholas
> >> <Nicholas.Ritter_at_americantv.com> wrote:
> >> >
> >> > Two things you can do:
> >> >
> >> > 1) When the wccp service breaks as you describe, do a "sh ip wccp" on
> >> > the router, make sure that "Number of Service Group Clients" and "Number
> >> > of Service Group Routers" are both no zero.
> >> >
> >> > 2)
> >> >
> >> > On the router:
> >> >
> >> > Debug ip wccp
> >> >
> >> >  - make sure your logging is set to debug level on the router
> >> >
> >> > What for the "Here I am" and "I see you" packets, which identifies that
> >> > the router and the squid box see each other.
> >> >
> >> >
> >> > One important thing, make sure you router is running the most recent
> >> > version of IOS...different revisions have WCCP problems come and go. I
> >> > have been running 12.4(15)T8 without problems for months.
> >> >
> >> > I was running various sub releases of 12.4 and had problems...but
> >> > 12.4(15)T8 seems stable.
> >> >
> >> > Nick
> >> >
> >> >
> >> > -----Original Message-----
> >> > From: alexmontoanelli_at_gmail.com [mailto:alexmontoanelli_at_gmail.com] On
> >> > Behalf Of Alex Montoanelli
> >> > Sent: Monday, May 04, 2009 7:13 AM
> >> > To: squid-users
> >> > Subject: [squid-users] CISCO + WCCP Stopping forward packets
> >> >
> >> > Hello all.
> >> >
> >> > I have a FreeBSD Box, running Squid Version 2.7.STABLE6-20090306, with
> >> > WCCP2 features on, with my Cisco Router 2811.
> >> >
> >> > It's running fine, but after a few hours, the traffic is not forwarded
> >> > from Cisco do Squid Box.
> >> >
> >> > I don't see any packet on gre0 and a 'show ip wccp' in Cisco, has not
> >> > increment counters from redirected packets.
> >> >
> >> > In my logs (cisco e squid) I could not get nothing;
> >> >
> >> > someone has been there?
> >> >
> >> > Regards
> >> >
> >> > Alex Montoanelli
> >> >
> >> >
> >>
> >
> >
> >
>
Received on Tue May 19 2009 - 14:40:11 MDT

This archive was generated by hypermail 2.2.0 : Wed May 20 2009 - 12:00:02 MDT