On Fri, Jan 10, 2014 at 10:38:30AM +1300, Amos Jeffries wrote: > On 2014-01-10 01:17, Peter Benko wrote: > >Hi squid users, > > > >I'm trying to upgrade squid from 3.3.11 to 3.4.2 on Debian 6. Both > >squids are > >compiled from source with the same compilation flags and their > >config files are > >equal. > > > >I have problem with Negotiate/kerberos authentication against > >Active Directory > >in squid 3.4.2 (squid 3.3.11 works without problems). > > > >First 2 lines of access.log are produced by command: > >$ curl -q --proxy-negotiate -x proxy2.example.com:8080 -U : -L > >--max-redirs 1 http://www.six.sk/ > >curl: (47) Maximum (1) redirects followed > >...curl doesn't obtain the required html page (it works against > >squid 3.3.11). > > > >Last 3 lines of access.log are produced by command: > >$ curl -q --proxy-negotiate -x proxy2.example.com:8080 -U : -L > >--max-redirs 2 http://www.six.sk/ > >...curl obtains the required html page. > > > >What's wrong with my squid configuration? > > > >squid@proxy2:~ $ diff -s squid33/etc/squid.conf squid34/etc/squid.conf > >Files squid33/etc/squid.conf and squid34/etc/squid.conf are identical > > > > So the only difference there is a curl parameter about how many > "redirects" it will follow? > That sounds to me like they are counting 407 challenges as a redirect. > > Is this exactly the same version of curl being used to test each of > the proxies? > > > Does the results change if you reverse the order of the tests? From > what I have seen below it just might (caching group lookup results > from first test may let second attempt pass). > > > <snip> > > > >squid@proxy2:~ $ cat /var/log/squid/access.log > > TCP connection #1 from client port 42736: > > >1389267633.593 0 10.106.68.14 TCP_DENIED/407 3519 GET > >http://www.six.sk/ - HIER_NONE/- text/html > >1389267633.603 4 10.106.68.14 TCP_DENIED/407 6116 GET > >http://www.six.sk/ benko_peter HIER_NONE/- text/html > > ... which could be interpreted as request #1 redirected, request #2 > redirected, then stop. > > TCP connection #2 from client port 42737: > > >1389267662.100 0 10.106.68.14 TCP_DENIED/407 3519 GET > >http://www.six.sk/ - HIER_NONE/- text/html > >1389267662.110 4 10.106.68.14 TCP_DENIED/407 6116 GET > >http://www.six.sk/ benko_peter HIER_NONE/- text/html > >1389267662.150 34 10.106.68.14 TCP_MISS/200 4387 GET > >http://www.six.sk/ benko_peter HIER_DIRECT/194.160.23.5 text/html > > > > ... which could be interpreted as request #1 redirected, request #2 > redirected, then request #3 with result. > > As you can see Squid is emitting the same 407 results each time. Not > that Negotiate should be needing that many 407 to begin with, but > the outright failure seems to be coming from curl. > > > >squid@proxy2:~ $ cat /var/log/squid/cache.log > > >2014/01/09 12:39:12 kid1| Set Current Directory to /var/spool/squid > >2014/01/09 12:39:12 kid1| Starting Squid Cache version 3.4.2 for > >x86_64-unknown-linux-gnu... > >2014/01/09 12:39:12 kid1| Process ID 25457 > >2014/01/09 12:39:12 kid1| Process Roles: worker > > >2014/01/09 12:40:33.592 kid1| Checklist.cc(62) preCheck: 0x13ec528 > >checking slow rules > >2014/01/09 12:40:33.592 kid1| Ip.cc(560) match: aclIpMatchIp: > >'10.106.68.14:42736' found > >2014/01/09 12:40:33.592 kid1| Acl.cc(176) matches: checked: > >FromLocalNet = 1 > >2014/01/09 12:40:33.592 kid1| Acl.cc(176) matches: checked: > >!FromLocalNet = 0 > >2014/01/09 12:40:33.592 kid1| Acl.cc(176) matches: checked: > >http_access#1 = 0 > >2014/01/09 12:40:33.592 kid1| Checklist.cc(55) markFinished: 0x13ec528 > >answer AUTH_REQUIRED for aclMatchExternal exception > >2014/01/09 12:40:33.592 kid1| Acl.cc(176) matches: checked: group1 = -1 > >2014/01/09 12:40:33.592 kid1| Acl.cc(176) matches: checked: > >!group1 = -1 > >2014/01/09 12:40:33.592 kid1| Acl.cc(176) matches: checked: > >http_access#2 = -1 > >2014/01/09 12:40:33.592 kid1| Acl.cc(176) matches: checked: > >http_access = -1 > >2014/01/09 12:40:33.592 kid1| Checklist.cc(148) checkCallback: > >ACLChecklist::checkCallback: 0x13ec528 answer=AUTH_REQUIRED > > No credentials. So exit with a 407 challenge to get them. > > LOG for port 42736: > ## 1389267633.593 0 10.106.68.14 TCP_DENIED/407 3519 GET > ## http://www.six.sk/ - HIER_NONE/- text/html > > > >2014/01/09 12:40:33.598 kid1| Checklist.cc(62) preCheck: 0x13ec528 > >checking slow rules > >2014/01/09 12:40:33.598 kid1| Ip.cc(560) match: aclIpMatchIp: > >'10.106.68.14:42736' found > >2014/01/09 12:40:33.598 kid1| Acl.cc(176) matches: checked: > >FromLocalNet = 1 > >2014/01/09 12:40:33.598 kid1| Acl.cc(176) matches: checked: > >!FromLocalNet = 0 > >2014/01/09 12:40:33.598 kid1| Acl.cc(176) matches: checked: > >http_access#1 = 0 > >2014/01/09 12:40:33.598 kid1| AclProxyAuth.cc(143) checkForAsync: > >checking password via authenticator > >2014/01/09 12:40:33.598 kid1| Acl.cc(176) matches: checked: group1 > >= -1 async > >2014/01/09 12:40:33.598 kid1| Acl.cc(176) matches: checked: > >!group1 = -1 async > >2014/01/09 12:40:33.598 kid1| Acl.cc(176) matches: checked: > >http_access#2 = -1 async > >2014/01/09 12:40:33.598 kid1| Acl.cc(176) matches: checked: > >http_access = -1 async > >2014/01/09 12:40:33.602 kid1| Checklist.cc(119) goAsync: 0x13ec528 a > >slow ACL resumes by going async again! > >2014/01/09 12:40:33.602 kid1| Checklist.cc(55) markFinished: 0x13ec528 > >answer DUNNO for aclMatchExternal exception > > Hmm. Maybe its confused between loop and external_acl triggering > both auth helper and external helper lookups in the same test > sequence. What happens if you change your ACLs to these? > > acl auth proxy_auth REQUIRED > http_access deny !FromLocalNet > http_access deny !auth > http_access deny !group1 all > > If that makes it "work", would you mind testing a patch with the old > config? > > >2014/01/09 12:40:33.602 kid1| Acl.cc(176) matches: checked: group1 = -1 > >2014/01/09 12:40:33.602 kid1| InnerNode.cc(104) resumeMatchingAt: > >checked: !group1 = -1 > >2014/01/09 12:40:33.602 kid1| InnerNode.cc(104) resumeMatchingAt: > >checked: http_access#2 = -1 > >2014/01/09 12:40:33.602 kid1| InnerNode.cc(104) resumeMatchingAt: > >checked: http_access = -1 > >2014/01/09 12:40:33.602 kid1| Checklist.cc(148) checkCallback: > >ACLChecklist::checkCallback: 0x13ec528 answer=DUNNO > > LOG for port 42736: > ## 1389267633.603 4 10.106.68.14 TCP_DENIED/407 6116 GET > ## http://www.six.sk/ benko_peter HIER_NONE/- text/html > > Hmm, another strangeness. DUNNO result logging as 407, even with the > "all" hack in place. > > > PS. Thank you for a most excellent debug trace of the problem. > > Amos I just close this thread by confirming that in squid 3.4.3 this bug is fixed and authentication works as expected. -- Peter Benko
