On Thu, Feb 7, 2013 at 1:11 PM, Nick Rogers <ncrogers@xxxxxxxxx> wrote: > On Thu, Feb 7, 2013 at 12:41 PM, Nick Rogers <ncrogers@xxxxxxxxx> wrote: >> Hello, >> >> I am running squid 3.2.7 under FreeBSD 9.1. Recently I noticed that >> the tcp_outgoing_tos directive no longer uses the X-Forwarded-For >> header for the purposes of ACL comparisons. Other directives (e.g., >> tcp_outgoing_address) work with the X-Forwarded-For IP against the >> SAME ACL. >> >> My squid version and options... >> # squid -v >> Squid Cache: Version 3.2.7 >> configure options: '--with-default-user=squid' >> '--bindir=/usr/local/sbin' '--sbindir=/usr/local/sbin' >> '--datadir=/usr/local/etc/squid' >> '--libexecdir=/usr/local/libexec/squid' '--localstatedir=/var/squid' >> '--sysconfdir=/usr/local/etc/squid' '--with-logdir=/var/log/squid' >> '--with-pidfile=/var/run/squid/squid.pid' '--enable-auth' >> '--enable-build-info' '--enable-loadable-modules' >> '--enable-removal-policies=lru heap' '--disable-epoll' >> '--disable-linux-netfilter' '--disable-linux-tproxy' >> '--disable-translation' '--enable-auth-basic=DB MSNT MSNT-multi-domain >> NCSA PAM POP3 RADIUS fake getpwnam NIS' '--enable-auth-digest=file' >> '--enable-external-acl-helpers=file_userip unix_group' >> '--enable-auth-negotiate=kerberos wrapper' '--enable-auth-ntlm=fake >> smb_lm' '--enable-storeio=diskd rock ufs aufs' '--enable-disk-io=AIO >> Blocking DiskDaemon IpcIo Mmapped DiskThreads' >> '--enable-log-daemon-helpers=file' '--enable-url-rewrite-helpers=fake' >> '--enable-delay-pools' '--enable-htcp' '--disable-forw-via-db' >> '--disable-cache-digests' '--enable-wccp' '--enable-wccpv2' >> '--disable-eui' '--disable-ipfw-transparent' '--enable-pf-transparent' >> '--disable-ipf-transparent' '--enable-follow-x-forwarded-for' >> '--disable-ecap' '--disable-icap-client' '--disable-esi' >> '--enable-kqueue' '--prefix=/usr/local' '--mandir=/usr/local/man' >> '--infodir=/usr/local/info/' '--build=amd64-portbld-freebsd9.1' >> 'build_alias=amd64-portbld-freebsd9.1' 'CC=cc' 'CFLAGS=-O2 -pipe >> -fno-strict-aliasing' 'LDFLAGS= -pthread' 'CPPFLAGS=' 'CXX=c++' >> 'CXXFLAGS=-O2 -pipe -fno-strict-aliasing' 'CPP=cpp' >> --enable-ltdl-convenience >> >> Notice that I have enable-follow-x-forwarded-for compiled in. >> >> Here is part of an example configuration: >> >> follow_x_forwarded_for allow all >> acl_uses_indirect_client on >> log_uses_indirect_client on >> >> # Uplink ACLs >> acl Uplink_1 src "/usr/local/etc/squid/Uplink_1.acl" >> tcp_outgoing_address 50.37.26.109 Uplink_1 >> tcp_outgoing_tos 0xaa Uplink_1 >> >> Here is some relevant debug output: >> >> 2013/02/07 12:31:35.579 kid1| Acl.cc(321) matches: ACLList::matches: >> checking Uplink_1 >> 2013/02/07 12:31:35.579 kid1| Acl.cc(310) checklistMatches: >> ACL::checklistMatches: checking 'Uplink_1' >> 2013/02/07 12:31:35.579 kid1| Ip.cc(135) aclIpAddrNetworkCompare: >> aclIpAddrNetworkCompare: compare: >> 10.8.8.100/[ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff] (10.8.8.100) vs >> 10.8.8.120-[::]/[ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff] >> 2013/02/07 12:31:35.579 kid1| Ip.cc(135) aclIpAddrNetworkCompare: >> aclIpAddrNetworkCompare: compare: >> 10.8.8.100/[ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff] (10.8.8.100) vs >> 10.8.8.103-[::]/[ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff] >> 2013/02/07 12:31:35.579 kid1| Ip.cc(135) aclIpAddrNetworkCompare: >> aclIpAddrNetworkCompare: compare: >> 10.8.8.100/[ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff] (10.8.8.100) vs >> 10.8.8.100-[::]/[ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff] >> 2013/02/07 12:31:35.579 kid1| Ip.cc(571) match: aclIpMatchIp: '10.8.8.100' found >> 2013/02/07 12:31:35.579 kid1| Acl.cc(312) checklistMatches: >> ACL::ChecklistMatches: result for 'Uplink_1' is 1 >> 2013/02/07 12:31:35.579 kid1| Acl.cc(328) matches: ACLList::matches: >> result is true >> 2013/02/07 12:31:35.579 kid1| Checklist.cc(251) matchAclList: >> aclmatchAclList: 0x7fffffffbe60 returning true (AND list satisfied) >> 2013/02/07 12:31:35.579 kid1| Checklist.cc(156) markFinished: >> ACLChecklist::markFinished: 0x7fffffffbe60 checklist processing >> finished >> 2013/02/07 12:31:35.579 kid1| cbdata.cc(455) cbdataInternalUnlock: >> cbdataUnlock: 0x803498318=10 >> 2013/02/07 12:31:35.579 kid1| FilledChecklist.cc(100) >> ~ACLFilledChecklist: ACLFilledChecklist destroyed 0x7fffffffbe60 >> 2013/02/07 12:31:35.579 kid1| Checklist.cc(275) ~ACLChecklist: >> ACLChecklist::~ACLChecklist: destroyed 0x7fffffffbe60 >> 2013/02/07 12:31:35.580 kid1| peer_select.cc(298) peerSelectDnsPaths: >> Found sources for 'http://www.speedtest.net/' >> 2013/02/07 12:31:35.580 kid1| peer_select.cc(299) peerSelectDnsPaths: >> always_direct = 0 >> 2013/02/07 12:31:35.580 kid1| peer_select.cc(300) peerSelectDnsPaths: >> never_direct = 0 >> 2013/02/07 12:31:35.580 kid1| peer_select.cc(303) peerSelectDnsPaths: >> DIRECT = local=50.37.26.109 remote=74.209.160.12:80 flags=1 >> 2013/02/07 12:31:35.580 kid1| peer_select.cc(311) peerSelectDnsPaths: >> timedout = 0 >> 2013/02/07 12:31:35.580 kid1| cbdata.cc(509) cbdataReferenceValid: >> cbdataReferenceValid: 0x80af07dd8 >> 2013/02/07 12:31:35.580 kid1| cbdata.cc(455) cbdataInternalUnlock: >> cbdataUnlock: 0x80af07dd8=1 >> 2013/02/07 12:31:35.580 kid1| forward.cc(337) startConnectionOrFail: >> http://www.speedtest.net/ >> 2013/02/07 12:31:35.580 kid1| HttpRequest.cc(535) clearError: old >> error details: 0/0 >> 2013/02/07 12:31:35.580 kid1| forward.cc(858) connectStart: >> fwdConnectStart: http://www.speedtest.net/ >> 2013/02/07 12:31:35.580 kid1| pconn.cc(339) key: >> PconnPool::key(local=50.37.26.109 remote=74.209.160.12:80 flags=1, >> www.speedtest.net) is {74.209.160.12:80/www.speedtest.net} >> 2013/02/07 12:31:35.580 kid1| pconn.cc(435) pop: lookup for key >> {74.209.160.12:80/www.speedtest.net} failed. >> 2013/02/07 12:31:35.580 kid1| cbdata.cc(509) cbdataReferenceValid: >> cbdataReferenceValid: 0x803498318 >> 2013/02/07 12:31:35.580 kid1| cbdata.cc(509) cbdataReferenceValid: >> cbdataReferenceValid: 0x803498318 >> 2013/02/07 12:31:35.581 kid1| cbdata.cc(418) cbdataInternalLock: >> cbdataLock: 0x803498318=11 >> 2013/02/07 12:31:35.581 kid1| Acl.cc(321) matches: ACLList::matches: >> checking Uplink_1 >> 2013/02/07 12:31:35.581 kid1| Acl.cc(310) checklistMatches: >> ACL::checklistMatches: checking 'Uplink_1' >> 2013/02/07 12:31:35.581 kid1| Ip.cc(135) aclIpAddrNetworkCompare: >> aclIpAddrNetworkCompare: compare: >> 127.0.0.1:36008/[ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff] >> (127.0.0.1:36008) vs >> 10.8.8.100-[::]/[ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff] >> 2013/02/07 12:31:35.581 kid1| Ip.cc(135) aclIpAddrNetworkCompare: >> aclIpAddrNetworkCompare: compare: >> 127.0.0.1:36008/[ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff] >> (127.0.0.1:36008) vs >> 10.8.8.103-[::]/[ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff] >> 2013/02/07 12:31:35.581 kid1| Ip.cc(135) aclIpAddrNetworkCompare: >> aclIpAddrNetworkCompare: compare: >> 127.0.0.1:36008/[ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff] >> (127.0.0.1:36008) vs >> 10.8.8.120-[::]/[ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff] >> 2013/02/07 12:31:35.581 kid1| Ip.cc(571) match: aclIpMatchIp: >> '127.0.0.1:36008' NOT found >> 2013/02/07 12:31:35.581 kid1| Acl.cc(312) checklistMatches: >> ACL::ChecklistMatches: result for 'Uplink_1' is 0 >> 2013/02/07 12:31:35.581 kid1| Acl.cc(324) matches: ACLList::matches: >> result is false >> 2013/02/07 12:31:35.581 kid1| Checklist.cc(229) matchAclList: >> aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 >> lastACLResult() = 0 finished() = 0 >> 2013/02/07 12:31:35.581 kid1| Checklist.cc(243) matchAclList: >> aclmatchAclList: 0x7fffffffbc60 returning (AND list entry awaiting an >> async lookup) >> 2013/02/07 12:31:35.581 kid1| cbdata.cc(455) cbdataInternalUnlock: >> cbdataUnlock: 0x803498318=10 >> 2013/02/07 12:31:35.581 kid1| FilledChecklist.cc(100) >> ~ACLFilledChecklist: ACLFilledChecklist destroyed 0x7fffffffbc60 >> 2013/02/07 12:31:35.581 kid1| Checklist.cc(275) ~ACLChecklist: >> ACLChecklist::~ACLChecklist: destroyed 0x7fffffffbc60 >> 2013/02/07 12:31:35.581 kid1| forward.cc(986) connectStart: >> fwdConnectStart: got outgoing addr 50.37.26.109, tos 0 >> >> >> The first match attempt is for the the tcp_outgoing_address directive. >> This correctly compares 10.8.8.100 (the X-Forwarded-For IP) with the >> ACL and determines that it matches the Uplink_1 ACL. >> >> The next match attempt is for the tcp_outgoing_tos directive, which >> incorrectly compares 127.0.0.1 with the ACL (the SAME ACL as the first >> match for tcp_outgoing_address), and determines it does not match. >> This is where I believe tcp_outgoing_tos is failing to use the >> X-Forwarded-For header. >> >> Note that the request coming from 127.0.0.1 is from another proxy >> running on the same host. >> >> In the past I had this working correctly with squid 2.7.x. I am not >> sure if this is a bug or if there is some configuration directive I am >> missing to make tcp_outgoing_tos behave the same as >> tcp_outgoing_address with respect to ACLs and X-Forwarded-For headers. >> Any help is greatly appreciated. >> >> -Nick > > Further analysis of squid 3.2.7 code makes me think this is a pretty > obvious bug. > > It seems like some change similar to the following patch is needed. I > am not yet sure if this works... > > I also believe this affects the netfilter directive as the code is > nearly identical. > > --- forward.cc.orig 2013-02-07 13:02:26.000000000 -0800 > +++ forward.cc 2013-02-07 13:05:24.000000000 -0800 > @@ -1352,7 +1352,12 @@ > ACLFilledChecklist ch(NULL, request, NULL); > > if (request) { > - ch.src_addr = request->client_addr; > +#if FOLLOW_X_FORWARDED_FOR > + if (Config.onoff.acl_uses_indirect_client) > + ch.src_addr = request->indirect_client_addr; > + else > +#endif /* FOLLOW_X_FORWARDED_FOR */ > + ch.src_addr = request->client_addr; > ch.my_addr = request->my_addr; > } Previously mentioned patch fixes the problem for me. I have created a bug report. http://bugs.squid-cache.org/show_bug.cgi?id=3767