11-15-2011 09:14 AM
My problem is, it doesn’t seem like packets are making it to the linux/squid caching device, based on cache logs. Workstations that are being redirected in the router have no web browser access (they can ping 8.8.8.8 and google.com)
I have a linux box running squid successfully, which supports GRE WCCP. For the sake of argument, I will say that I am confident I have successfully configured that machine. If anyone wants to see those config’s I can provide them.
What’s really strange is this morning I came in and hind sight my test workstation looked like it may had restarted from an update. (maybe had internet access). The first thing I did was tweak the cisco config, as I was reading last night and saw:
“Be warned that if you are using NAT you MUST use the inbound interface otherwise the router only sees the NATted IP address as the source of your clients. This is bad, because the router is also therefore unable to see your cache engine and it will redirect the cache engine requests back upon itself.”
So I turned <ip cef> on and removed the <ip wccp web-cache redirect out> (I had in fa0/1 and out fa0/0 on overnight).
Then I proceeded to check the workstation and saw it had network access, I tested to see if it was in fact filtered by the proxy, and it was! (verified by cache logs aswell)
After some further successful testing, I made sure I saved any unsaved configuration changes, I rebooted the linux box and the router. Sadly the outcome was not good, I am back to where I was last night.
My router does routing/NAT and has two interfaces and is currently not running CEF
ip wccp web-cache redirect-list SQUID_PROXY
!
interface FastEthernet0/0
description WAN
ip address 1.2.3.4 255.255.255.248
ip nat outside
ip virtual-reassembly max-reassemblies 64
speed 100
full-duplex
!
interface FastEthernet0/1
description LAN
ip address 194.190.7.1 255.255.255.252
ip wccp web-cache redirect in
ip nat inside
ip virtual-reassembly
speed 100
full-duplex
!
ip access-list extended SQUID_PROXY
permit ip 159.84.20.0 0.0.0.255 any
deny ip any any
Here are some current details about the connection
Router0#sho ip wccp web-cache v
WCCP Routers Informed of:
194.190.7.1
WCCP Clients Visible:
159.84.10.13
WCCP Clients NOT Visible:
-none-
Router0#sho ip wccp web-cache d
WCCP Client information:
WCCP Client ID: 159.84.10.13
Protocol Version: 2.0
State: Usable
Redirection: GRE
Packet Return: GRE
Assignment: HASH
Initial Hash Info: 00000000000000000000000000000000
00000000000000000000000000000000
Assigned Hash Info: FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF
FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF
Hash Allotment: 256 (100.00%)
Packets s/w Redirected: 258
Connect Time: 00:27:07
Bypassed Packets
Process: 0
CEF: 0
Errors: 0
Router0#sho ip wccp
Global WCCP information:
Router information:
Router Identifier: 194.190.7.1
Protocol Version: 2.0
Service Identifier: web-cache
Number of Service Group Clients: 1
Number of Service Group Routers: 1
Total Packets s/w Redirected: 258
Process: 258
CEF: 0
Service mode: Open
Service Access-list: -none-
Total Packets Dropped Closed: 0
Redirect Access-list: SQUID_PROXY
Total Packets Denied Redirect: 2088
Total Packets Unassigned: 0
Group Access-list: -none-
Total Messages Denied to Group: 0
Total Authentication failures: 0
Total Bypassed Packets Received: 0
I know this was sort of log winded, I tried to keep it simple. I won't be able to sleep unless this gets resolved, please help!
Solved! Go to Solution.
11-17-2011 12:31 AM
Hi Brandon,
Let me go point by point:
I notice I never receive the following from the router, shouldn't I be?:
WCCP-PKT:S00: Received valid Here_I_Am packet
Yes, you would normally see this message if you are running the "debug ip packets" command, but despite not seeing the messages, I can guarantee that these messages are arriving to the router. How? Three reasons:
From the first post, what’s with the large "
Total Packets Denied Redirect: 2088
"?
You are using a redirect-list with your WCCP configuration. This counter is incremented for any packet that matches the WCCP service but not the redirect-list. In your case, any traffic to ports 80 or 8080 not coming from network
159.84.20.0/24
What do these wccp events mean?
Nov 16 11:39:24.391: WCCP-EVNT:wccp_update_assignment_status: enter
Nov 16 11:39:24.391: WCCP-EVNT:wccp_update_assignment_status: exit
Nov 16 11:39:24.391: WCCP-EVNT:wccp_validate_wc_assignments: enter
Nov 16 11:39:24.391: WCCP-EVNT:wccp_validate_wc_assignments: not mask assignment, exit
As part of the WCCP protocol, the assigment of buckets to the different wccp clients is dinamically updated to make sure that if one fails, traffic is distributed among the remaining ones. These messages just indicate the different steps of the process, so they are perfectly normal.
I know this may be leaving the realavence of Cisco a bit, here is some more debug, but from linux side.
- is capturing the, wccp here I am packets
- (in bold) show traffic making it to eth0 from the wccp router
- shows raw traffic in the tunnel !!
I am a bit confused, with the results. Does this mean that Squid is the problem? Why was everything up and running, and now not.
Can anyone decipher the traffic in the tunnel?
For all these captures, I would suggest you to save the traffic capture to a binary file (tcpdump -s 1600 -i eth0 -w
Anyway, looking at the last tcpdump output, we are just seeing SYN packets, but no reply to them. This looks like a problem with the Squid proxy.
Regards
Daniel
11-15-2011 09:29 AM
I found a nice write up last night http://www.reub.net/node/3
It makes mention of problems in earlier IOS versions, which sounds very similar to my problem.
“The problem I was seeing in 12.4 and late 12.3T's is that the router sees the cache and attempts to forward, but cannot redirect WCCP traffic it due to a switching bug in the router software. The bug is that the router does not seem to be able to process switch a packet to a WCCP cache over the GRE tunnel, but if you establish the CEF entry first by pinging the remote site's IP address, it works. As any cisco gurus know, for an entry to be added to the CEF table, the first packet to that destination must be process switched.
The symptoms you will see are that the cache is visible to the router and the WCCP works for a few seconds, then all redirected traffic starts timing out.”
11-15-2011 02:09 PM
BUMP!! with some debug info
Router0#show debugging WCCP: WCCP packet info debugging is on WCCP events debugging is on Router0#show log *Nov 15 19:52:46.923: WCCP-EVNT:wccp_update_assignment_status: enter *Nov 15 19:52:46.927: WCCP-EVNT:wccp_update_assignment_status: exit *Nov 15 19:52:46.927: WCCP-EVNT:wccp_validate_wc_assignments: enter *Nov 15 19:52:46.927: WCCP-EVNT:wccp_validate_wc_assignments: not mask assignment, exit *Nov 15 19:52:46.927: WCCP-PKT:S00: Sending I_See_You packet to 159.84.10.13 w/ rcv_id 00000473 *Nov 15 19:52:56.943: WCCP-EVNT:wccp_update_assignment_status: enter *Nov 15 19:52:56.943: WCCP-EVNT:wccp_update_assignment_status: exit *Nov 15 19:52:56.943: WCCP-EVNT:wccp_validate_wc_assignments: enter *Nov 15 19:52:56.943: WCCP-EVNT:wccp_validate_wc_assignments: not mask assignment, exit *Nov 15 19:52:56.943: WCCP-PKT:S00: Sending I_See_You packet to 159.84.10.13 w/ rcv_id 00000474 *Nov 15 19:53:06.955: WCCP-EVNT:wccp_update_assignment_status: enter *Nov 15 19:53:06.955: WCCP-EVNT:wccp_update_assignment_status: exit *Nov 15 19:53:06.955: WCCP-EVNT:wccp_validate_wc_assignments: enter *Nov 15 19:53:06.955: WCCP-EVNT:wccp_validate_wc_assignments: not mask assignment, exit *Nov 15 19:53:06.955: WCCP-PKT:S00: Sending I_See_You packet to 159.84.10.13 w/ rcv_id 00000475 *Nov 15 19:53:16.967: WCCP-EVNT:wccp_update_assignment_status: enter *Nov 15 19:53:16.967: WCCP-EVNT:wccp_update_assignment_status: exit *Nov 15 19:53:16.967: WCCP-EVNT:wccp_validate_wc_assignments: enter *Nov 15 19:53:16.967: WCCP-EVNT:wccp_validate_wc_assignments: not mask assignment, exit *Nov 15 19:53:16.967: WCCP-PKT:S00: Sending I_See_You packet to 159.84.10.13 w/ rcv_id 00000476
11-16-2011 12:32 AM
Hi Brandon,
According to the outputs you sent, everything is working fine from the router point of view:
Router0#sho ip wccp web-cache d
WCCP Client information:
WCCP Client ID: 159.84.10.13
Protocol Version: 2.0
State: Usable
Redirection: GRE
Packet Return: GRE
Assignment: HASH
Initial Hash Info: 00000000000000000000000000000000
00000000000000000000000000000000
Assigned Hash Info: FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF
FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF
Hash Allotment: 256 (100.00%)
Packets s/w Redirected: 258
Connect Time: 00:27:07
Bypassed Packets
Process: 0
CEF: 0
Errors: 0
The part in red indicates that the WCCP negotiation finished successfully. The part in green shows that all the traffic is going to be sent to this client (159.84.10.13) because it's the only one present. Finally, the blue part indicates that 258 packets were redirected
Moving forward, I would suggest you to check if the "Packets s/w Redirected" counter is increasing, and if so, troubleshoot on the squid proxy itself. A traffic capture between the router and the proxy would also be useful to confirm what's happening with the redirected traffic.
Regards
Daniel
11-16-2011 08:57 AM
Thanks for the response and good points.
I notice I never receive the following from the router, shouldn't I be?:
WCCP-PKT:S00: Received valid Here_I_Am packet
From the first post, what’s with the large "Total Packets Denied Redirect: 2088"?
What do these wccp events mean?
Nov 16 11:39:24.391: WCCP-EVNT:wccp_update_assignment_status: enter
Nov 16 11:39:24.391: WCCP-EVNT:wccp_update_assignment_status: exit
Nov 16 11:39:24.391: WCCP-EVNT:wccp_validate_wc_assignments: enter
Nov 16 11:39:24.391: WCCP-EVNT:wccp_validate_wc_assignments: not mask assignment, exit
I know this may be leaving the realavence of Cisco a bit, here is some more debug, but from linux side.
I am a bit confused, with the results. Does this mean that Squid is the problem? Why was everything up and running, and now not.
Can anyone decipher the traffic in the tunnel?
# tcpdump -pni eth0 port 2048
[tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on eth0, link-type EN10MB (Ethernet), capture size 96 bytes
10:07:49.852594 IP 159.84.10.13.2048 > 194.190.7.1.2048: UDP, length 144
10:07:49.853990 IP 194.190.7.1.2048 > 159.84.10.13.2048: UDP, length 140
10:07:59.862590 IP 159.84.10.13.2048 > 194.190.7.1.2048: UDP, length 144
10:07:59.863987 IP 194.190.7.1.2048 > 159.84.10.13.2048: UDP, length 140
10:08:09.872605 IP 159.84.10.13.2048 > 194.190.7.1.2048: UDP, length 144
10:08:09.873968 IP 194.190.7.1.2048 > 159.84.10.13.2048: UDP, length 140
10:08:19.882590 IP 159.84.10.13.2048 > 194.190.7.1.2048: UDP, length 144
10:08:19.883987 IP 194.190.7.1.2048 > 159.84.10.13.2048: UDP, length 140
10:08:29.892590 IP 159.84.10.13.2048 > 194.190.7.1.2048: UDP, length 144
10:08:29.893957 IP 194.190.7.1.2048 > 159.84.10.13.2048: UDP, length 140
^C
10 packets captured
10 packets received by filter
0 packets dropped by kernel
# sudo tcpdump -pni eth0
10:22:32.415110 IP 159.84.10.13.22 > 159.84.20.50.55170: Flags [P.], seq 30920:31180, ack 273, win 501, length 260
10:22:32.422618 IP 159.84.10.13.22 > 159.84.20.50.55170: Flags [P.], seq 31180:31344, ack 273, win 501, length 164
10:22:32.423197 IP 159.84.20.50.55170 > 159.84.10.13.22: Flags [.], ack 31344, win 254, length 0
10:22:32.435108 IP 159.84.10.13.22 > 159.84.20.50.55170: Flags [P.], seq 31344:31604, ack 273, win 501, length 260
10:22:32.445106 IP 159.84.10.13.22 > 159.84.20.50.55170: Flags [P.], seq 31604:31768, ack 273, win 501, length 164
10:22:32.445670 IP 159.84.20.50.55170 > 159.84.10.13.22: Flags [.], ack 31768, win 253, length 0
10:22:32.455116 IP 159.84.10.13.22 > 159.84.20.50.55170: Flags [P.], seq 31768:32028, ack 273, win 501, length 260
10:22:32.465107 IP 159.84.10.13.22 > 159.84.20.50.55170: Flags [P.], seq 32028:32192, ack 273, win 501, length 164
10:22:32.465657 IP 159.84.20.50.55170 > 159.84.10.13.22: Flags [.], ack 32192, win 251, length 0
10:22:32.466025 IP 194.190.7.1 > 159.84.10.13: GREv0, length 60: gre-proto-0x883e
10:22:32.475113 IP 159.84.10.13.22 > 159.84.20.50.55170: Flags [P.], seq 32192:32532, ack 273, win 501, length 340
10:22:32.485107 IP 159.84.10.13.22 > 159.84.20.50.55170: Flags [P.], seq 32532:32696, ack 273, win 501, length 164
10:22:32.485687 IP 159.84.20.50.55170 > 159.84.10.13.22: Flags [.], ack 32696, win 256, length 0
10:22:32.495110 IP 159.84.10.13.22 > 159.84.20.50.55170: Flags [P.], seq 32696:32956, ack 273, win 501, length 260
10:22:32.505107 IP 159.84.10.13.22 > 159.84.20.50.55170: Flags [P.], seq 32956:33120, ack 273, win 501, length 164
10:22:32.505686 IP 159.84.20.50.55170 > 159.84.10.13.22: Flags [.], ack 33120, win 254, length 0
10:22:32.515109 IP 159.84.10.13.22 > 159.84.20.50.55170: Flags [P.], seq 33120:33380, ack 273, win 501, length 260
10:22:32.525106 IP 159.84.10.13.22 > 159.84.20.50.55170: Flags [P.], seq 33380:33544, ack 273, win 501, length 164
# tcpdump -pni wccp0
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on wccp0, link-type LINUX_SLL (Linux cooked), capture size 96 bytes
10:51:59.274373 IP 159.84.20.50.55858 > 74.125.226.244.80: Flags [S], seq 991683402, win 8192, options [mss 1460,nop,wscale 2,nop,nop,sackOK], length 0
10:51:59.465761 IP 159.84.20.50.55859 > 74.125.226.244.80: Flags [S], seq 1702719715, win 8192, options [mss 1460,nop,wscale 2,nop,nop,sackOK], length 0
10:52:02.272682 IP 159.84.20.50.55858 > 74.125.226.244.80: Flags [S], seq 991683402, win 8192, options [mss 1460,nop,wscale 2,nop,nop,sackOK], length 0
10:52:02.475552 IP 159.84.20.50.55859 > 74.125.226.244.80: Flags [S], seq 1702719715, win 8192, options [mss 1460,nop,wscale 2,nop,nop,sackOK], length 0
10:52:08.278803 IP 159.84.20.50.55858 > 74.125.226.244.80: Flags [S], seq 991683402, win 8192, options [mss 1460,nop,nop,sackOK], length 0
10:52:08.481470 IP 159.84.20.50.55859 > 74.125.226.244.80: Flags [S], seq 1702719715, win 8192, options [mss 1460,nop,nop,sackOK], length 0
10:52:20.275639 IP 159.84.20.50.55860 > 74.125.226.243.80: Flags [S], seq 379732993, win 8192, options [mss 1460,nop,wscale 2,nop,nop,sackOK], length 0
10:52:20.493967 IP 159.84.20.50.55861 > 74.125.226.243.80: Flags [S], seq 1155844664, win 8192, options [mss 1460,nop,wscale 2,nop,nop,sackOK], length 0
10:52:23.285801 IP 159.84.20.50.55860 > 74.125.226.243.80: Flags [S], seq 379732993, win 8192, options [mss 1460,nop,wscale 2,nop,nop,sackOK], length 0
10:52:23.504374 IP 159.84.20.50.55861 > 74.125.226.243.80: Flags [S], seq 1155844664, win 8192, options [mss 1460,nop,wscale 2,nop,nop,sackOK], length 0
10:52:29.291769 IP 159.84.20.50.55860 > 74.125.226.243.80: Flags [S], seq 379732993, win 8192, options [mss 1460,nop,nop,sackOK], length 0
10:52:29.510363 IP 159.84.20.50.55861 > 74.125.226.243.80: Flags [S], seq 1155844664, win 8192, options [mss 1460,nop,nop,sackOK], length 0
10:52:41.304149 IP 159.84.20.50.55862 > 74.125.226.241.80: Flags [S], seq 3872894044, win 8192, options [mss 1460,nop,wscale 2,nop,nop,sackOK], length 0
10:52:41.522861 IP 159.84.20.50.55863 > 74.125.226.241.80: Flags [S], seq 2031478809, win 8192, options [mss 1460,nop,wscale 2,nop,nop,sackOK], length 0
10:52:44.314760 IP 159.84.20.50.55862 > 74.125.226.241.80: Flags [S], seq 3872894044, win 8192, options [mss 1460,nop,wscale 2,nop,nop,sackOK], length 0
10:52:44.533228 IP 159.84.20.50.55863 > 74.125.226.241.80: Flags [S], seq 2031478809, win 8192, options [mss 1460,nop,wscale 2,nop,nop,sackOK], length 0
10:52:50.320774 IP 159.84.20.50.55862 > 74.125.226.241.80: Flags [S], seq 3872894044, win 8192, options [mss 1460,nop,nop,sackOK], length 0
10:52:50.539182 IP 159.84.20.50.55863 > 74.125.226.241.80: Flags [S], seq 2031478809, win 8192, options [mss 1460,nop,nop,sackOK], length 0
^C
18 packets captured
18 packets received by filter
0 packets dropped by kernel
11-17-2011 12:31 AM
Hi Brandon,
Let me go point by point:
I notice I never receive the following from the router, shouldn't I be?:
WCCP-PKT:S00: Received valid Here_I_Am packet
Yes, you would normally see this message if you are running the "debug ip packets" command, but despite not seeing the messages, I can guarantee that these messages are arriving to the router. How? Three reasons:
From the first post, what’s with the large "
Total Packets Denied Redirect: 2088
"?
You are using a redirect-list with your WCCP configuration. This counter is incremented for any packet that matches the WCCP service but not the redirect-list. In your case, any traffic to ports 80 or 8080 not coming from network
159.84.20.0/24
What do these wccp events mean?
Nov 16 11:39:24.391: WCCP-EVNT:wccp_update_assignment_status: enter
Nov 16 11:39:24.391: WCCP-EVNT:wccp_update_assignment_status: exit
Nov 16 11:39:24.391: WCCP-EVNT:wccp_validate_wc_assignments: enter
Nov 16 11:39:24.391: WCCP-EVNT:wccp_validate_wc_assignments: not mask assignment, exit
As part of the WCCP protocol, the assigment of buckets to the different wccp clients is dinamically updated to make sure that if one fails, traffic is distributed among the remaining ones. These messages just indicate the different steps of the process, so they are perfectly normal.
I know this may be leaving the realavence of Cisco a bit, here is some more debug, but from linux side.
- is capturing the, wccp here I am packets
- (in bold) show traffic making it to eth0 from the wccp router
- shows raw traffic in the tunnel !!
I am a bit confused, with the results. Does this mean that Squid is the problem? Why was everything up and running, and now not.
Can anyone decipher the traffic in the tunnel?
For all these captures, I would suggest you to save the traffic capture to a binary file (tcpdump -s 1600 -i eth0 -w
Anyway, looking at the last tcpdump output, we are just seeing SYN packets, but no reply to them. This looks like a problem with the Squid proxy.
Regards
Daniel
11-21-2011 05:58 PM
Working config!!
Thanks for the point in the right direction!
acl manager proto cache_object
acl localhost src 127.0.0.1/32
acl to_localhost dst 127.0.0.0/8
acl SSL_ports port 443
acl Safe_ports port 80 # http
acl Safe_ports port 21 # ftp
acl Safe_ports port 443 # https
acl Safe_ports port 70 # gopher
acl Safe_ports port 210 # wais
acl Safe_ports port 1025-65535 # unregistered ports
acl Safe_ports port 280 # http-mgmt
acl Safe_ports port 488 # gss-http
acl Safe_ports port 591 # filemaker
acl Safe_ports port 777 # multiling http
acl CONNECT method CONNECT
acl Home_Network src 159.84.1.1-159.84.255.255/255.255.0.0
acl BAN_DOMAIN dstdomain .youtube.com .facebook.com
acl magic_words url_regex -i test
http_access allow manager localhost
http_access deny manager
http_access deny !Safe_ports
http_access deny CONNECT !SSL_ports
http_access allow localhost
http_access deny BAN_DOMAIN
http_access deny magic_words
http_access allow Home_Network
http_access deny all
icp_access deny all
htcp_access deny all
http_port 159.84.10.13:3128 transparent
hierarchy_stoplist cgi-bin ?
access_log /var/log/squid3/access.log squid
refresh_pattern ^ftp: 1440 20% 10080
refresh_pattern ^gopher: 1440 0% 1440
refresh_pattern (cgi-bin|\?) 0 0% 0
refresh_pattern . 0 20% 4320
wccp2_router 194.190.7.1
wccp2_forwarding_method 1
wccp2_return_method 1
wccp2_service standard 0
wccp2_address 159.84.10.13
icp_port 3130
coredump_dir /var/spool/squid3
ip tunnel add wccp0 mode gre remote 194.190.7.1 local 159.84.10.13 dev eth0 |
Find answers to your questions by entering keywords or phrases in the Search bar above. New here? Use these resources to familiarize yourself with the community: