Hi, We have 2 external ACLs that take a request's data (IP, authenticated username, URL, user-agent, etc) and uses that information to determine whether a user or host should be permitted to access that URL. It almost always works well, but we have a recurring occasional issue that I can't figure out.
When it occurs, it's always around 4AM. This particular request occurs often - averages about once a second throughout the day. What we see is a "403 forbidden" for a (should be) permitted site from an authenticated user from the same IP/user and to the same site that gets a "202 connection established" every other time. The difference I see in the logs: though all the digest auth info looks okay, the %un field in the log for the usual (successful) request is the authenticated username, while in the failed request, it's "-". So though there hasn't been an authentication error or "authentication required" in the log - and the username is in the authentication details in the log entry - it seems like squid isn't recognizing that username as %un. My squid.conf first tests a request to see if an unauthenticated request from a particular host is permitted. That external ACL doesn't take a username as an argument. If that external ACL passes, the request is allowed. The next line in squid.conf is acl auth_users proxy_auth REQUIRED ... and after that, the external ACL that takes the username as well as the other info. The filter has its own log. For most authenticated requests, we see four entries in that log for each of this particular request: HostBasedRequest HostBasedResponse UserBasedRequest UserBasedResponse When the issue occurs, we see a blip in the pattern when looking at only this particular request, like: HostBasedRequest HostBasedRespons HostBasedRequest HostBasedResponse UserBasedRequest UserBasedResponse so it looks like the requests that experience the issue don't get past that "acl auth_users proxy_auth REQUIRED" directive. One more clue: The last morning the issue occurred, we saw 8 instances of "403 forbidden" responses (out of roughly 5800 that hour). When I looked at the log entry for one of them (included below) and looked for other instances of the cnonce in the digest auth info, I saw that cnonce in five of the eight log entries showing the issue. Any ideas or suggestions? Here are two logs: one illustrating the issue and the other showing how a typical successful request is logged. thanks! 12.34.56.78 - - [20/May/2024:04:00:00 -0400] "CONNECT abc.defg.net:443 HTTP/1.1" 403 4276 "-" "Java/21.0.1" TCP_DENIED:HIER_NONE [User-Agent: Java/21.0.1\r\nAccept: */*\r\nProxy-Connection: keep-alive\r\nProxy-Authorization: Digest username="service_uname", realm="squid", nonce="eca7c1c8831a2fc2b0afb3ee95862950", nc=00000035, uri="abc.defg.net:443", response="88f2110f926ba56c3b1a84a1321a051c", algorithm=MD5, cnonce="BHGEEDNBMEPIIMIDLABNJHJNAIEHLKPGGEDFCLHG", qop=auth\r\nHost: abc.defg.net:443\r\n] [HTTP/1.1 403 Forbidden\r\nServer: squid/5.7\r\nMime-Version: 1.0\r\nDate: Mon, 20 May 2024 08:00:00 GMT\r\nContent-Type: text/html;charset=utf-8\r\nContent-Length: 3884\r\nX-Squid-Error: ERR_ACCESS_DENIED 0\r\nVary: Accept-Language\r\nContent-Language: en\r\nX-Cache: MISS from proxy.acme.com\r\nX-Cache-Lookup: NONE from proxy.acme.com:3128\r\nVia: 1.1 proxy.acme.com (squid/5.7)\r\nConnection: keep-alive\r\n\r\n] 12.34.56.78 - service_uname [20/May/2024:10:50:10 -0400] "CONNECT abc.defg.net:443 HTTP/1.1" 200 2939 "-" "Java/21.0.1" TCP_TUNNEL:HIER_DIRECT [User-Agent: Java/21.0.1\r\nAccept: */*\r\nProxy-Connection: keep-alive\r\nProxy-Authorization: Digest username="service_uname", realm="squid", nonce="3e30376ba9c74cb016b3d8cfe1bf8a81", nc=0000002f, uri="abc.defg.net:443", response="f8f720d4e2bb9324e1a90bcfafecd1c5", algorithm=MD5, cnonce="KDJPEGFBCHFLMCJMAPEBMEGJNKOHOBEDOAEINPKL", qop=auth\r\nHost: abc.defg.net:443\r\n] [HTTP/1.1 200 Connection established\r\n\r\n]
_______________________________________________ squid-users mailing list squid-users@lists.squid-cache.org https://lists.squid-cache.org/listinfo/squid-users
