Bug 1114714

Summary: When squid returns an ACL tag utilizing an external ACL, sometimes the incorrect tag is used for redirection.
Product: Red Hat Enterprise Linux 6 Reporter: jstephen
Component: squidAssignee: Luboš Uhliarik <luhliari>
Status: CLOSED ERRATA QA Contact: Ondřej Pták <optak>
Severity: high Docs Contact:
Priority: high    
Version: 6.4CC: cww, dkutalek, jstephen, mluscon, optak, psimerda, thozza
Target Milestone: rcKeywords: OtherQA, Patch, Reopened
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: squid-3.1.10-35.el6 Doc Type: Bug Fix
Doc Text:
Previously, squid sometimes returned an incorrect tag from the Access Control List (ACL) code when using an external ACL. The bug has been fixed, and squid no longer returns the incorrect ACL tag in this situation.
Story Points: ---
Clone Of: Environment:
Last Closed: 2015-07-22 06:26:24 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description jstephen 2014-06-30 18:08:53 UTC
Description of problem:
When squid returns an ACL tag utilizing an external ACL, sometimes the incorrect tag is used for redirection.

In the customer's environment: A GET request comes in to the squid proxy, squid passes control over to the 'clientLocationDNSv2.pl' perl script to parse client IP/MAC/ssid information. This script returns the specific 'tag' to squid.conf utilizing 'tag=', this tag is then used for acl creation and eventually deny_info redirection.

With our testing, we added %et to the logformat and noticed that in a few occasions, squid is not identifying the tag properly from what is being returned from the perl script,

---------------------------------------------------------------------------------------------

 		et	Tag returned by external acl 

---------------------------------------------------------------------------------------------

Utilizing the logformat squid %{%Y-%m-%d:%H:%M:%S}tg.%03tu GMT %6trms dport=%04lp %014>a %012Ss/%03>Hs %07<st %rm %ru %un %Sh/%<A %mt "%{Location}<h" %ea %et we see that the tag returned for %ea and %et are different. It seems that the re-directs are occurring based on the '%et' tag returned

%ea shows tag elsewhere, %et shows ShawOpenGenericGuest

access.log:2014-06-26:20:48:26.220 GMT      2ms dport=8081    10.64.22.30   TCP_DENIED/302 0000463 GET http://173.194.33.132/generate_204 - NONE/- text/html "https://wifisignon.shaw.ca/1FEAB4ADE8/?cpurl=http%3A%2F%2F173.194.33.132%2Fgenerate_204";; ssid:ShawOpen,ap_mac:1c:e6:c7:2b:18:60,client_mac:e4:92:fb:dc:7d:5d,tag:elsewhere ShawOpenGenericGuest

- And the debug output in cache.log shows tag=elsewhere which is the intended helper tag

2014/06/26 14:48:26.217| aclMatchExternal: wifi_clientinfo("10.64.22.30") = lookup needed
2014/06/26 14:48:26.217| aclMatchExternal: "10.64.22.30": entry=@0x7fa461e73dc8, age=137
2014/06/26 14:48:26.217| aclMatchExternal: "10.64.22.30": queueing a call.
2014/06/26 14:48:26.217| aclMatchExternal: wifi_clientinfo = 1
2014/06/26 14:48:26.217| externalAclLookup: lookup in 'wifi_clientinfo' for '10.64.22.30'
2014/06/26 14:48:26.217| externalAclLookup: looking up for '10.64.22.30' in 'wifi_clientinfo'.
2014/06/26 14:48:26.217| externalAclLookup: will wait for the result of '10.64.22.30' in 'wifi_clientinfo' (ch=0x7fa461187968).
2014/06/26 14:48:26.219| externalAclHandleReply: reply="OK tag=elsewhere message=ssid:ShawOpen,ap_mac:1c:e6:c7:2b:18:60,client_mac:e4:92:fb:dc:7d:5d,tag:elsewhere log=ssid:ShawOpen,ap_mac:1c:e6:c7:2b:18:60,client_mac:e4:92:fb:dc:7d:5d,tag:elsewhere"
2014/06/26 14:48:26.219| external_acl_cache_add: Adding '10.64.22.30' = 1
2014/06/26 14:48:26.219| ExternalACLEntry::update: updating existing entry

This issue is rare, but is causing re-direct problems based on the customers squid.conf(attached)


A second instance:

access.log:2014-06-26:20:48:32.497 GMT      2ms dport=8081    10.66.1.254   TCP_DENIED/302 0000460 GET http://gsp1.apple.com/pep/gcc - NONE/- text/html "https://wifisignon.shaw.ca/1FEAB4ADE8/?cpurl=http%3A%2F%2Fgsp1.apple.com%2Fpep%2Fgcc";; ssid:ShawOpen,ap_mac:1c:e6:c7:2b:0a:a0,client_mac:b8:c7:5d:7b:42:8e,tag:elsewhere ShawOpenGenericGuest


2014/06/26 14:48:32.495| aclMatchExternal: wifi_clientinfo("10.66.1.254") = lookup needed
2014/06/26 14:48:32.495| aclMatchExternal: "10.66.1.254": entry=@0x7fa46179d548, age=111
2014/06/26 14:48:32.495| aclMatchExternal: "10.66.1.254": queueing a call.
2014/06/26 14:48:32.495| aclMatchExternal: wifi_clientinfo = 1
2014/06/26 14:48:32.495| externalAclLookup: lookup in 'wifi_clientinfo' for '10.66.1.254'
2014/06/26 14:48:32.495| externalAclLookup: looking up for '10.66.1.254' in 'wifi_clientinfo'.
2014/06/26 14:48:32.495| externalAclLookup: will wait for the result of '10.66.1.254' in 'wifi_clientinfo' (ch=0x7fa46118f6e8).
2014/06/26 14:48:32.497| externalAclHandleReply: reply="OK tag=elsewhere message=ssid:ShawOpen,ap_mac:1c:e6:c7:2b:0a:a0,client_mac:b8:c7:5d:7b:42:8e,tag:elsewhere log=ssid:ShawOpen,ap_mac:1c:e6:c7:2b:0a:a0,client_mac:b8:c7:5d:7b:42:8e,tag:elsewhere"
2014/06/26 14:48:32.497| external_acl_cache_add: Adding '10.66.1.254' = 1
2014/06/26 14:48:32.497| ExternalACLEntry::update: updating existing entry

Version-Release number of selected component (if applicable):
squid-3.1.10-20.el6_5.3

How reproducible:
Intermittent

Steps to Reproduce:
1. Configure external ACL helper script to return tag
2. Create acl and use 'deny_info' rules to redirect requests
3. 

Actual results:
Occasionally Re-direct go to the wrong place

Expected results:
Re-directs should be 100% consistent

Additional info:

Comment 13 jstephen 2014-12-01 15:23:01 UTC
Apologies, I should have been more clear.

A test rpm was provided by Michal Lucson for the RHEL6 version of squid which included the following two patches:

- http://bugs.squid-cache.org/show_bug.cgi?id=3412 
- http://bugs.squid-cache.org/show_bug.cgi?id=3226

I am not sure if a backport is required for an official release of squid which includes these two patches, or if we need to wait until these patches are included into RHEL from upstream.

Please update the bug as you see fit Tomas. The customer encountering this issue is content with the test rpm provided already.

-Justin

Comment 14 Tomáš Hozza 2014-12-01 16:01:09 UTC
(In reply to jstephen from comment #13)
> Apologies, I should have been more clear.
> 
> A test rpm was provided by Michal Lucson for the RHEL6 version of squid
> which included the following two patches:
> 
> - http://bugs.squid-cache.org/show_bug.cgi?id=3412 
> - http://bugs.squid-cache.org/show_bug.cgi?id=3226
> 
> I am not sure if a backport is required for an official release of squid
> which includes these two patches, or if we need to wait until these patches
> are included into RHEL from upstream.

In that case we still need this to be fixed in RHEL.

> Please update the bug as you see fit Tomas. The customer encountering this
> issue is content with the test rpm provided already.

Note that those testing packages are completely unsupported and the customer is basically on their own if using this in production.


Adding OtherQA since the customer has verified the testing packages. However QA is welcome to test it anyway :)

Comment 19 Ondřej Pták 2015-06-10 13:20:06 UTC
This problem is quite hard to reproduce outside of production environment.
I tried to alter configuration and scripts to create reproducer, but there are many obstacles and so far I couldn't reproduce this issue.
On the other hand, customer verified that it solves the problem, so it doesn't worth extreme time investment.
This fix is already in upstream version, there is no regression detected and patch looks good.

Comment 21 errata-xmlrpc 2015-07-22 06:26:24 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://rhn.redhat.com/errata/RHBA-2015-1314.html