[squid-users] The user/password pair is correct, yet squid keeps sending me TCP_DENIED/407

[Yanko Hernández Álvarez]

Hello :-)

How is it possible that some user tried to log in with the correct
password and squid response was a TCP_DENIED/407?

This is my squid log format
----------------------------
logformat mysquidlog %ts.%03tu %6tr %>a %Ss/%03>Hs %<st %rm %ru %un
%Sh/%<A %mt %>A [%>h] [%<h]
access_log daemon:/var/log/squid/access.log mysquidlog
----------------------------

Please notice it includes Request headers([%>h]) and Response headers ([%<h]).

This is the first (of many) relevant squid log entry. (Empty
user/password combination filtered)
----------------------------
# grep TCP_DENIED/407 /var/log/squid/access.log | grep
"Proxy-Authorization: Basic" | grep -v Og== | head -n1
1613138245.113     28 10.128.141.38 TCP_DENIED/407 2609 GET
http://detectportal.firefox.com/success.txt o.suarez HIER_NONE/-
text/html pcmtto.example.com [User-Agent: Mozilla/5.0 (Windows NT 6.1;
Win64; x64; rv:85.0) Gecko/20100101 Firefox/85.0\r\nAccept:
*/*\r\nAccept-Language:
es-ES,es;q=0.8,en-US;q=0.5,en;q=0.3\r\nAccept-Encoding: gzip,
deflate\r\nCache-Control: no-cache\r\nPragma: no-cache\r\nConnection:
keep-alive\r\nProxy-Authorization: Basic
by5zdWFyZXo6TWFudGVuaW1pZW50bzIwMjEr\r\nHost:
detectportal.firefox.com\r\n] [HTTP/1.1 407 Proxy Authentication
Required\r\nServer: squid/4.6\r\nMime-Version: 1.0\r\nDate: Fri, 12
Feb 2021 13:57:25 GMT\r\nContent-Type:
text/html;charset=utf-8\r\nContent-Length: 2110\r\nX-Squid-Error:
ERR_CACHE_ACCESS_DENIED 0\r\nVary:
Accept-Language\r\nContent-Language: es-es\r\n\r]
----------------------------

Same squid log entry (pretty printed)
----------------------------
1613138245.113     28 10.128.141.38 TCP_DENIED/407 2609 GET
http://detectportal.firefox.com/success.txt o.suarez HIER_NONE/-
text/html pcmtto.example.com

Request headers (sent by firefox):
User-Agent: Mozilla/5.0 (Windows NT 6.1; Win64; x64; rv:85.0)
Gecko/20100101 Firefox/85.0
Accept: */*
Accept-Language: es-ES,es;q=0.8,en-US;q=0.5,en;q=0.3
Accept-Encoding: gzip, deflate
Cache-Control: no-cache
Pragma: no-cache
Connection: keep-alive
Proxy-Authorization: Basic by5zdWFyZXo6TWFudGVuaW1pZW50bzIwMjEr
Host: detectportal.firefox.com


Response headers (sent by squid)
HTTP/1.1 407 Proxy Authentication Required
Server: squid/4.6
Mime-Version: 1.0
Date: Fri, 12 Feb 2021 13:57:25 GMT
Content-Type: text/html;charset=utf-8
Content-Length: 2110
X-Squid-Error: ERR_CACHE_ACCESS_DENIED 0
Vary: Accept-Language
Content-Language: es-es
----------------------------

This is my squid configuration regarding ACLs (redacted for brevity
and relevance)
----------------------------
auth_param basic program /usr/lib/squid/basic_ldap_auth -b
"OU=UsersOU,DC=example,DC=com" -D ldapquery at example.com -W
/etc/squid/Other/Password -f
"(&(objectclass=person)(sAMAccountName=%s)(!(userAccountControl:1.2.840.113556.1.4.803:=2)))"
ads.example.com
auth_param basic children 5 startup=5 idle=1
auth_param basic realm Servidor Squid (HTTP-Proxy) example.com
auth_param basic credentialsttl 2 hours
auth_param basic casesensitive off

http_access deny !Safe_ports # Safe_ports = default config ports: 80,
21, 443, 70, 210, 1025-65535, 280, 488, 591, 777
http_access deny CONNECT !SSL_ports # CONNECT = method CONNECT,
SSL_ports = 443, 8006, 8443
http_access allow localhost manager
http_access deny manager
http_access allow InternalServers # InternalServers = arp
'/etc/squid/PCs/MACInternalServers'
http_access deny REPorn # REPorn = dstdom_regex -i
'/etc/squid/Sites/Forbbiden/REPorn'
http_access deny FQPornDN # FQPornDN = dstdomain -n
'/etc/squid/Sites/Forbbiden/FQPornDN'
http_access allow localhost
http_access allow MySite # MySite = dstdomain -n .example.com
acl RestrictedPCsGroup1         arp     '/etc/squid/PCs/MACPCsGrp1'
acl RestrictedPCsGroup2         arp     '/etc/squid/PCs/MACPCsGrp2'
acl RestrictedPCsGroup21        arp     '/etc/squid/PCs/MACPCsGrp21'
http_access deny !RestrictedPCsGroup1 !RestrictedPCsGroup2 !RestrictedPCsGroup21
http_access allow AutoConnections # AutoConnections = dstdomain -n
'/etc/squid/Sites/Allowed/AutoConnections'
http_access deny !LoggedIn # LoggedIn = proxy_auth REQUIRED

#
# Some more rules here, but not relevant to that problematic request
as squid stops processing rules on this one.
#
----------------------------

The rule failing should be "http_access deny !LoggedIn". Its the only
one that generates a TCP_DENIED/407. All the other "deny" rules
generate a TCP_DENIED/403.

My auth is configured to use an Active Directory DC and as seen on the
request header, the auth data is
----------------------------
$ echo by5zdWFyZXo6TWFudGVuaW1pZW50bzIwMjEr | base64 -d
o.suarez:Mantenimiento2021+
----------------------------

And it is correct:
----------------------------
# echo o.suarez Mantenimiento2021+ | /usr/lib/squid/basic_ldap_auth -b
"OU=UsersOU,DC=example,DC=com" -D ldapquery at example.com -W
/etc/squid/Other/Password -f
'(&(objectclass=person)(sAMAccountName=%s)(!(userAccountControl:1.2.840.113556.1.4.803:=2)))'
ads.example.com
OK
----------------------------

So... is it a bug? Is there something I misunderstood? I'm using
debian's squid (4.6-1+deb10u4)

I won't be back until monday.