• websrvr: FastCGI EOF returns 0 from fastcgi_read_wait_timeout(), busy-

    From Rob Swindell@1:103/705 to GitLab issue in main/sbbs on Saturday, September 19, 2026 23:42:30
    open https://gitlab.synchro.net/main/sbbs/-/work_items/1246

    ## Summary

    When a FastCGI backend closes its socket (for example php-fpm restarting during a routine package upgrade), `fastcgi_read_wait_timeout()` reports the resulting EOF by returning `0`. But `0` is that function's "nothing ready, keep waiting" value, not an error value. The caller therefore re-polls immediately, and since a closed socket is always instantly readable there is no delay between iterations. The web server busy-spins at roughly 250,000 iterations per second, logging at `LOG_ERR` on every one, until `max_cgi_inactivity` finally expires up
    to two minutes later.

    On 2026-09-19 this produced about 7.5 million log messages in 90 seconds on Vertrauen and took the whole Synchronet IRC network apart as a side effect.

    ## The defect

    `src/sbbs3/websrvr.cpp:4515`, in `fastcgi_read_wait_timeout()`:

    ```c
    if (socket_readable(cd->sock, startup->max_cgi_inactivity * 1000)) {
    if (recv(cd->sock, (char *)&cd->header, offsetof(struct fastcgi_header, len), MSG_WAITALL)
    != offsetof(struct fastcgi_header, len)) {
    errprintf(LOG_ERR, WHERE, "FastCGI failed to read header");
    return ret; // ret is still 0
    }
    ```

    On EOF `recv()` returns 0, which fails the `!=` comparison, so the function logs
    and returns `ret`, which is still `0`.

    The caller, `do_cgi_stuff()` at `src/sbbs3/websrvr.cpp:4868`:

    ```c
    while (!done_reading) {
    ready = cgi->read_wait_timeout(cgi->arg);
    if (ready) {
    ...
    if (ready & CGI_PROCESS_TERMINATED) {
    ret |= CGI_STUFF_PROCESS_EXITED;
    done_wait = true;
    }
    ...
    }
    else {
    if ((time(NULL) - start) >= startup->max_cgi_inactivity) { ... }
    }
    }
    ```

    `ready == 0` skips the entire body, including the `CGI_PROCESS_TERMINATED` check, and the loop immediately calls `read_wait_timeout()` again. There is no sleep and no backoff. `socket_readable()` returns true instantly on a socket at EOF, so nothing paces the loop.

    The same defect appears twice more in the same function, at the unknown-version check (`:4521`) and the unknown-session-ID check (`:4525`). Both log and `return ret` with `ret` still `0`.

    The loop is bounded rather than infinite: the `else` branch exits once `max_cgi_inactivity` elapses. That bound is the only thing stopping it.

    ## Why it escalates beyond noise

    `errprintf()` calls `lputs(LOG_ERR, ...)`, which writes to the log stream **and**
    appends to `data/error.log`. On any install where the Synchronet directory is on
    network storage, every iteration of the spin becomes a network filesystem write.

    On the affected host the install directory is a loopback CIFS mount of the machine's own Samba server, so the spin turned into a write storm against the local `smbd`. That wedged the CIFS client in `smb2_reconnect`, which blocked every filesystem operation under the install directory for about 90 seconds, including those of unrelated Synchronet services. The IRCd froze past its ping thresholds and about 50 server links were dropped at once. See #1245 for that half of the failure.

    ## Evidence

    ```
    17:00:29 systemd: Stopping php8.4-fpm.service (routine package upgrade) 17:00:29.302 first "FastCGI failed to read header"
    17:00:33 ircd stops logging (blocked on a stat under the install dir) 17:00:42 sbbs.service stops logging
    17:01:59.407 last "FastCGI failed to read header" (max_cgi_inactivity expires) 17:02:04.343 kernel: CIFS: VFS: reconnect tcon failed rc = -11
    17:02:04 ircd and sbbs.service both resume in the same second
    ```

    Volume in that 90 second window: 52,501 messages reached the journal, about 7.5 million more were dropped by journald rate limiting, and 6,985 lines were appended to `data/error.log` before the mount stalled.

    ## Suggested fix

    Return `CGI_PROCESS_TERMINATED` on EOF or error rather than `0`. The function already does exactly that at `:4505` for `cd->request_ended`, and the caller handles it correctly at `:5019`, so the fix is to use the value that already exists for this purpose. The version and session-ID checks want the same treatment.

    That converts a two minute, multi-million-line busy-spin into a prompt session teardown.

    Note this is not an exotic condition. Any php-fpm restart reproduces it, including an unattended security upgrade, so it has most likely been firing quietly on this and other installs for some time and only became visible when it
    collided with network storage.

    -- *Authored by Claude (Claude Code), on behalf of @rswindell*
    --- SBBSecho 3.37-Linux
    * Origin: Vertrauen - [vert/cvs/bbs].synchro.net (1:103/705)
  • From Rob Swindell@1:103/705 to GitLab note in main/sbbs on Saturday, September 19, 2026 23:49:00
    https://gitlab.synchro.net/main/sbbs/-/work_items/1246#note_10388

    ## Correction: the "write storm against smbd" mechanism above is wrong

    Testing the fix surfaced a detail that refutes part of the original report. The defect and the fix are unaffected; the claimed escalation path is not.

    `errprintf()` calls `repeated_error()`, which promotes the level from `LOG_ERR` to `LOG_WARNING` on every repeat. `lputs()` only reaches `errorlog()` when `level <= LOG_ERR`. So after the first repetition the spin **stops writing to `data/error.log` altogether**.

    Measured with the harness below: 3,256,235 iterations produced **3 lines** in `error.log`. The production incident showed 6,985 lines across the whole 90-second window and many sessions, which is about 78 per second: not a write storm.

    What the spin does produce at full rate is `mqtt_lputs()` on every iteration plus a `startup->lputs()` write to stderr (and from there to the journal), since
    neither is gated by the `LOG_ERR` check. That accounts for the roughly 7.5 million journal messages.

    So the accurate statement is: the spin generates an extreme volume of logging and burns a core, and the CIFS client wedged during the same window. **Whether the spin caused that wedge is not established, and the write-volume mechanism I gave does not support it.** Other load was present at the same time, including an in-progress package upgrade and a sustained web-scraping load. The section "Why it escalates beyond noise" should be read with that correction.

    This does not change the severity of the bug itself. A single FastCGI backend restart puts an affected session into a multi-million-iteration spin for up to `max_cgi_inactivity`.

    ## Verification of the fix

    Harness compiled against the real source (`#include`ing `websrvr.cpp` so the static function can be called directly), driving a socket whose peer has been closed, built once against `HEAD` and once against the patch:

    ```
    ===== ORIGINAL (HEAD, unpatched) =====
    single call returned 0x0 (CGI_PROCESS_TERMINATED=0x4)
    iterations before a non-zero (loop-exiting) return: 3256235
    RESULT: FAIL

    ===== PATCHED =====
    single call returned 0x4 (CGI_PROCESS_TERMINATED=0x4)
    iterations before a non-zero (loop-exiting) return: 0
    RESULT: PASS
    ```

    About 1.6 million iterations per second on this hardware, versus immediate termination with the fix.

    -- *Authored by Claude (Claude Code), on behalf of @rswindell*
    --- SBBSecho 3.37-Linux
    * Origin: Vertrauen - [vert/cvs/bbs].synchro.net (1:103/705)