In both Squid 5.8 and 6.6 we notice unexpected behavior: the external acl helper program is sometimes called without arguments (or empty arguments). On busy times this happens once or twice each second, on quiet times maybe once per 15 minutes or not at all.
Configuration of the ACL is as follows:
external_acl_type DynProxy ttl=60 negative_ttl=60 ipv4 %DST %SRC /path/proxy_acl.php
This works as expected. However, there is the occasional empty request (the read from STDIN is an empty string). Based on the documentation, the helper program replies 'BH message=missing arguments'. Squid logs this response as
ERROR: helperHandleRead: unexpected read from external_acl_type #Hlpr8, 29 bytes 'BH message=missing arguments
In the source code, this statement has the comment "someone spoke without being spoken to", which does not seem to be entirely the case here, as the structure of the helper program is:
function run() {
while (!feof(STDIN)) {
$input = trim(fgets(STDIN));
$args = explode(' ', $input);
if (count($args) < 2) {
$output = "BH message=missing arguments\n";
} else {
// ... do something
}
fwrite(STDOUT, $output);
}
}
We have searched through log files and see the following lines in the same second that the call is made, but not sure if that's related:
2024/01/02 12:37:31.306 kid1| 5,3| Read.cc(148) HandleRead: FD 72, size 32767, retval 29, errno 0
2024/01/02 12:37:31.306 kid1| 5,3| IoCallback.cc(112) finish: called for conn171338 local=[::] remote=[::] FD 72 flags=1 (0, 0)
What could be the cause of such empty requests? And would it be safe to silently ignore these requests, instead of replying to them? We started having reliability issues with Squid after having it running for years without any problems. The log files do not indicate any problems, but after running for a few days or weeks, connections suddenly won't come through until a restart. So here we are, looking into all possible causes we can think of.
A crosspost to https://bugs.squid-cache.org/show_bug.cgi?id=5340 led to an answer to this question. Apparently PHP times out on reading from stdin (60 seconds by default). The result of fgets(STDIN) will be false and more details about the error are available by calling stream_get_meta_data.
Recent versions of Squid handle unexpected responses differently than before, killing helper processes. So the timeout has most likely always been there, but probably started causing performance problems after a recent update (if this was the root cause).