Apache kicking proxy connection every 1000 seconds?

TL;DR: This is a story about a (nearly fully automated via codex; I did an initial bug description as well as some steering which tools to use and how to perform runtime testing, the remaining story unfolded autonomously) mini bug search for a timeout for slow backends behind an Apache mod_proxy reverse proxy. It describes a pretty simple datatype conversion error due to truncation from 64 to 32 bit integers and is a mini example that one can fully automate debugging on the live systems as well as by inspecting binaries or source code using large language models.

Some infrastructure failures look like an intentional timeout although there is no corresponding configuration. A request runs for a while and Apache then returns a 502 Proxy Error with Error reading from remote server. The timeout is neither the default value nor the configured proxy timeout. It is close to one thousand seconds.

Most ordinary HTTP requests do not reach this limit. It becomes visible with workloads that take a long time before producing their first byte of output. Non-streaming LLM requests are one example. Depending on model, context size and hardware, a long prefill can take twenty or thirty minutes; with some large models and inference configurations it can take considerably longer. A reverse proxy intended for such workloads should not terminate the backend connection after roughly sixteen minutes.

This article documents how I tracked down such a timeout on FreeBSD and why the eventual answer was neither the firewall nor Apaches proxy module configuration - or any direct source mistake in Apaches httpd or the mod_proxy itself. It was a very small integer conversion in APR.

Versions: The problem and solution described here was observed on FreeBSD 13.3 running Apache httpd 2.4.66 with APR 1.7.6.

• The configuration looked correct
• A timeout test server
• What Apache is actually timing out
• The integer conversion in APR
• Use of LLMs for debugging
• The fix
• Conclusion
• References

The configuration looked correct

The proxy had deliberately generous limits. A simplified version looked like this:

Timeout 172800
ProxyTimeout 172800

<Proxy "unix:/path/to/backend.sock|http://backend/">
    ProxySet connectiontimeout=10 timeout=172800 disablereuse=On
</Proxy>

ProxyPass "/service/" "unix:/path/to/backend.sock|http://backend/" \
    connectiontimeout=10 timeout=172800 disablereuse=On

The intention is straightforward: a backend response may take up to two days (this was intended to also accomodate the prefill of colibri running GLM) before Apache gives up. The same result appeared with a normal TCP backend instead of a Unix domain socket. Reloading Apache and doing full restarts changed nothing. The error log showed the usual proxy-side result:

AH01102: error reading status line from remote server
AH00898: Error reading from remote server

At this stage it is tempting to suspect that one of the directives was ignored, that a reused worker retained an older configuration, or that a firewall state expired. All of these are plausible in other situations and have obviously been the first points to investigate. They were not the explanation here.

A timeout test server

The next step was to temporarily replace the real application with a small HTTP service that has a single endpoint like

/timeouttest?duration=1200

The service records the start time, waits for the requested duration without writing a response, then returns a small JSON document. The same process listened both on a Unix domain socket and on a local TCP listener. Apache exposed one route through the Unix socket and a second route through TCP.

That gives three useful comparisons:

A thirty-second wait completed successfully through all three paths. A 1200-second wait completed successfully when accessed directly. Both proxied variants failed at almost the same point: about 1000 seconds after the request started. This now narrowed down the error to happen inside Apache.

A Unix domain socket does not traverse ipfw or the TCP stack. The TCP proxy route used a local TCP connection but failed at the same time. Direct TCP succeeded for the full twenty minutes. The application, protocol and firewall were therefore excluded as common causes. The remaining common components were Apache and the library below its socket I/O.

The test server also uncovered a useful detail. It only noticed that Apache had closed the Unix socket when it finally tried to write the delayed response. That is expected: a backend which sends no data has no earlier reason to discover that the peer went away. A later successful application log message is therefore not proof that the original client connection still existed.

What Apache is actually timing out

Apache was not inventing the 502. The proxy HTTP module reads the backend status line using ap_proxygetline(). That ultimately reads from the backend connection. If the read returns APR’s timeout status, APR_TIMEUP, mod_proxy_http logs AH01102 and translates the failure into the proxy error seen by the client.

The important point is that the configured timeout really was being used by Apache. The timeout= parameter of a ProxyPass worker is parsed in seconds and converted using apr_time_from_sec(). When Apache opens the backend connection it calls apr_socket_timeout_set() with that value. The socket timeout is stored in microseconds, as APR specifies.

There was no separate hidden ap_proxygetline timeout of one thousand seconds, and neither mod_reqtimeout nor an Apache core default was replacing the worker’s value in this backend response path. The next question was therefore: “what does APR do with a socket timeout of 172800 seconds when it is about to wait for data?”

The integer conversion in APR

On FreeBSD, APR uses poll(2) for this particular blocking socket wait. poll(2) accepts its timeout as a signed 32-bit integer in milliseconds. APR’s public socket timeout type, however, is a signed 64-bit integer in microseconds.

The affected APR 1.7.6 source contained the following pattern in support/unix/waitio.c:

struct pollfd pfd;
int rc, timeout;

timeout = f ? f->timeout : s->timeout;

if (timeout > 0) {
    timeout = (timeout + 999) / 1000;
}
rc = poll(&pfd, 1, timeout);

The assignment to timeout happens before the conversion from microseconds to milliseconds. That is the bug. f->timeout and s->timeout are 64-bit apr_interval_time_t values, but the local variable is a 32-bit int.

The configured two-day timeout is:

After narrowing to 32 bits it often wraps modulo 2³² (though this behaviour is of course implementation defined so one cannot rely on wrapover in any case:

APR then converts that already-wrapped value to milliseconds:

This produces the observed 1000 second timeout. It was not a limit configured anywhere; it was the low 32 bits of the intended timeout being treated as the complete timeout.

The installed APR library was checked without tracing running processes: its disassembly showed the 32-bit load of the socket timeout in apr_wait_for_io_or_timeout(). This is also why the same result occurred for both TCP and Unix domain sockets. Both routes eventually use the same APR wait function.

Use of LLMs for debugging

Codex was used during this investigation to inspect the Apache and APR source trees, follow the proxy read path, compare the timing with the test service and finally identify the narrowing conversion. It was also used upfront to inspect the server side system - configuration variables, firewall rules, sysctl values. The decisive part was not guessing from the number 1000, but reducing the failure to a simple reproducible experiment and then checking the exact implementation below Apache. All nearly fully automated with an LLM orchestrator.

The fix

As it turned out APR fixed this upstream as PR 69542 (Bugzilla) / PR 62 (GitHub), but I patched it locally as an exercise anyways. The corrected code keeps the raw timeout in an apr_interval_time_t, converts it to milliseconds only after checking its range, and caps values beyond INT_MAX milliseconds:

apr_interval_time_t raw_timeout;
int rc, timeout;

raw_timeout = f ? f->timeout : s->timeout;
if (raw_timeout > ((apr_interval_time_t)INT_MAX) * 1000) {
    timeout = INT_MAX;
}
else {
    timeout = raw_timeout > 0
        ? (int)((raw_timeout + 999) / 1000)
        : (int)raw_timeout;
}

For a two-day timeout this produces 172800000 milliseconds, which is well inside the range accepted by poll(2). Values above roughly 25 days are capped to the largest representable poll(2) interval rather than overflowing.

For FreeBSDs devel/apr1 port, which provided APR 1.7.6 in my case, the appropriate solution is to add this upstream change as a port patch, rebuild and reinstall APR, then restart Apache so that it loads the corrected shared library. The port already carried a small patch in this file for negative timeout handling; the replacement patch should retain that behaviour while adding the overflow fix.

The following patch file was placed in /usr/ports/devel/apr1/files/patch-apr-1.7.6_support_unix_waitio.c:

--- apr-1.7.6/support/unix/waitio.c.orig
+++ apr-1.7.6/support/unix/waitio.c
@@ -40,15 +40,24 @@ apr_status_t apr_wait_for_io_or_timeout(
                                         int for_read)
 {
     struct pollfd pfd;
-    int rc, timeout;
+    apr_interval_time_t raw_timeout;
+    int rc, timeout;
 
-    timeout    = f        ? f->timeout        : s->timeout;
+    raw_timeout = f ? f->timeout : s->timeout;
+    if (raw_timeout > ((apr_interval_time_t)INT_MAX) * 1000) {
+        /* poll(2) takes an int timeout in milliseconds (~25 days max). */
+        timeout = INT_MAX;
+    }
+    else {
+        /* Convert microseconds to milliseconds, rounding up. */
+        timeout = raw_timeout > 0
+            ? (int)((raw_timeout + 999) / 1000)
+            : (int)raw_timeout;
+    }
+
     pfd.fd     = f        ? f->filedes        : s->socketdes;
     pfd.events = for_read ? POLLIN            : POLLOUT;
 
-    if (timeout > 0) {
-        timeout = (timeout + 999) / 1000;
-    }
     do {
         rc = poll(&pfd, 1, timeout);
     } while (rc == -1 && errno == EINTR);

After rebuilding and reinstalling APR via

cd /usr/ports/devel/apr
make clean
make
make deinstall
make reinstall

the bug was gone and the longer timeout was honored as expected.

Conclusion

This bug is a classic that appears all over software engineering - and when quickly skimming code it is easy to pass. Especially when if affects configurations that are not covered by test cases. Codex was extremly helpful in debugging this in an fully automatic fashion after it was instructed to also perform runtime probes.

In addition, this kind of bug shows why formal verification solutions such as Frama-C’s RTE checks together with WP or Eva), as well as sufficiently strict compiler warnings, can be so useful. In this particular case, Frama-C RTE can generate range assertions for signed integer downcasts when -warn-signed-downcast is enabled; proving these assertions would expose that an apr_interval_time_t cannot in general be represented by the destination int. Likewise, compilers can diagnose this kind of narrowing conversion when conversion warnings are enabled, for example by building C code with -Wall -Wextra -Wconversion -Werror.

Other sanitizers remain valuable parts of the same defensive toolbox, although they target different classes of errors: ASan detects illegal memory accesses, MSan use of uninitialized memory and TSan data races, while UBSan detects many forms of undefined behaviour. Clang additionally provides integer-conversion sanitizers such as -fsanitize=implicit-integer-truncation for lossy implicit conversions. These tools do not all detect this particular APR bug, but together with static analysis, strict compiler diagnostics and formal range checks they eliminate large classes of bugs before they become obscure runtime failures. The upfront cost of properly annotating code and maintaining suitably strict build and verification configurations may be significant, but for long-lived infrastructure software the long-term gain can be substantial. And especially when coding with coding agents those tools are highly valueable in the testing loop.

References

• The FreeBSD operating system, which I operate on all of my machines
• The Apache HTTP Server, which is in many cases my preferred webserver besides nginx
• Apache specifics:
  • Apache mod_proxy documentation highlighting ProxyTimeout, ProxyPass and proxy worker configuration
  • The Apache Portable Runtime (APR), the portability and runtime library used below Apache httpd
  • APR bug 69542 / GitHub PR #62, an upstream report and fix for the timeout integer overflow in apr_wait_for_io_or_timeout() that I just discovered after I fixed it by myself. I am in no way associated with that upstream bug report and patch request
  • Apache Bugzilla PR 69542, which is the original bug report (I am not in any way associated with that bug report)
  • Apache mod_proxy source
  • APR source repository
• FreeBSD poll(2) manual page - Documentation of the poll(2) interface and its millisecond int timeout argument
• OpenAIs Codex, the coding agent used to assist source inspection, system investigation and runtime probing during debugging
• Frama-C
  • The Frama-C framework for analysis and verification of C programs
  • Frama-C RTE: Runtime-error annotation generation, including integer downcast checks
  • Frama-C WP: Weakest-precondition based deductive verification
  • Frama-C Eva: Abstract-interpretation based value analysis
  • ACSL, the ANSI/ISO C Specification Language used to state contracts and properties for C programs
• Compiler options:
  • Clang warning options including -Wconversion and -Werror
  • Clang AddressSanitizer
  • Clang MemorySanitizer
  • Clang ThreadSanitizer
  • Clang UndefinedBehaviorSanitizer which checks for undefined behaviour and optional checks for suspicious integer conversions
• Books for interested readers
  • Seacord, R. Effective C, 2nd Edition: An Introduction to Professional C Programming
  • Seacord, R. Secure Coding in C and C++ (SEI Series in Software Engineering)
  • Gustedt, J. Modern C, Third Edition: Covers the C23 standard

This article is tagged: Programming, Frama C, FreeBSD, Web, ANSI C, Large Language Models, Repair, Network