<!DOCTYPE html>
<html lang="en">
<head>
<meta charset="utf-8">
<title>Yioop v10 — pollett.org Log Debug Plan</title>
<style>
body { font-family: system-ui, sans-serif; max-width: 760px;
    margin: 2rem auto; padding: 0 1rem; line-height: 1.5;
    color: #1a1a1a; }
ol { margin: 0.4rem 0; }
ol ol { margin: 0.3rem 0 0.8rem; }
li { margin: 0.3rem 0; }
.check { color: #1a7f37; font-weight: bold; }
.next { color: #b35900; font-weight: bold; }
.note { color: #555; font-size: 0.92em; margin: 0.6rem 0 1.2rem; }
code { background: #f2f2f2; padding: 0 0.2em; border-radius: 3px; }
</style>
</head>
<body>
<h1>Yioop v10 &mdash; pollett.org Log Debug Plan</h1>
<p style="margin:.8rem 2rem;padding:.7rem 1rem;background:#eef2f7">
<strong>Arc Post-Mortem Summary.</strong>
A triage of the pollett.org production PHP
error log from 16-Jun-2026. It fixed a recurring &ldquo;Undefined array key
USER_ID&rdquo; warning in two public resource-serving methods, hardened and
audited the related paths, and chased down an HTTP/2 partial-transfer bug on
large responses whose root cause was a writable-set snapshot race in the
cooperative server. Fixes landed in HEAD to reach production on its next
pull.</p>
<p class="note">Triage of the production PHP error log from
pollett.org (16-Jun-2026). The running server pulled the repo the
evening before, so it is on commit <code>5f6f2b4</code>
(<code>SocialComponent.php</code> at 12666 lines) &mdash; that is how
the logged line numbers (12075 / 12171) map back to the source. The
mail arc has since shrunk that file, so the same code now lives at
<code>10240 / 10336</code> in HEAD; fixes land in HEAD and reach
production on its next pull.</p>
<ol>
  <li>&#10003; <span class="check">Recurring</span>
      &ldquo;Undefined array key USER_ID&rdquo; warning
      (<code>SocialComponent.php</code>, two sites).
    <ol>
      <li>Root cause: two public wiki/group resource-serving methods
          call
          <code>checkAuthRequirement($data, $_SESSION['USER_ID'])</code>
          without a guard. An anonymous (not-logged-in) visitor or bot
          has no <code>USER_ID</code> in the session, so PHP 8.5 warns
          on every such request &mdash; hence the all-day recurrence.</li>
      <li>It was also a latent auth bug: the undefined value is
          <code>null</code>, and <code>null != C\PUBLIC_USER_ID</code>,
          so a guest was not being treated as the public user in the
          require-signin check.</li>
      <li>&#10003; <em>Fixed: both sites now pass
          <code>$_SESSION['USER_ID'] ?? C\PUBLIC_USER_ID</code>, the
          idiom already used throughout the file.
          <code>checkAuthRequirement</code>'s own docblock names
          <code>PUBLIC_USER_ID</code> as the guest sentinel, so this
          clears the warning and corrects the guest path.</em></li>
    </ol>
  </li>
  <li>&#10003; <span class="check">Fixed</span> &ldquo;SSL: Connection
      reset by peer&rdquo; in <code>stream_get_contents</code>
      (<code>WebSite.php:2860</code>, <code>parseH1Request</code>).
    <ol>
      <li>A client / bot dropped the TLS connection while the server
          was still reading the request body. Transient and
          environmental, not a server fault (2 occurrences all day).</li>
      <li>&#10003; <em>Fixed: the request-body read is now wrapped in a
          temporary error handler that swallows only the
          &ldquo;reset by peer&rdquo; notice and lets every other
          warning through, then restores the previous handler. No
          <code>@</code> suppression; this mirrors the intent of the
          existing write-side suppression near
          <code>WebSite.php:4942</code>.</em></li>
    </ol>
  </li>
  <li>&#10003; <span class="check">Fixed (drain)</span> Memory fatal
      &mdash; 2&nbsp;GB exhausted, tried to allocate ~1.5&nbsp;GB
      (<code>WebSite.php:4942</code>, output drain).
    <ol>
      <li>A single response of ~1.5&nbsp;GB was held entirely in
          memory (<code>$out_streams[DATA][$key]</code>), and the drain
          did <code>substr($data, $offset)</code> &mdash; copying the
          <em>whole</em> unsent tail on each <code>fwrite</code>. That
          ~1.5&nbsp;GB copy on top of the buffer already in memory is
          what crossed the 2&nbsp;GB limit. One occurrence.</li>
      <li>&#10003; <em>Fixed: the drain now copies at most one
          <code>MAX_IO_LEN</code> (128&nbsp;KB) block per pass instead
          of the entire tail &mdash;
          <code>substr($data, $offset, $chunk_len)</code>. The socket
          only accepts a bounded amount per writable event anyway, so
          this costs no throughput; <code>$offset</code> still advances
          and the periodic compaction still reclaims the sent prefix.
          Peak memory is now the buffer itself, never doubled, so a
          large response drains instead of OOMing.</em></li>
      <li><em>Where the 1.5&nbsp;GB came from &mdash; corrected:</em>
          the access log at the crash second shows public-user bots
          crawling wiki <code>history&show=&lt;revision&gt;</code>
          on the public group (pages&nbsp;4/3). But that path is
          <em>not</em> the 1.5&nbsp;GB source: wiki content is capped at
          <code>MAX_GROUP_PAGE_LEN</code> (512&nbsp;KB) on save
          (<code>SocialComponent.php:7817</code>) and
          <code>WikiParser::parse</code> truncates render output to
          ~472&nbsp;KB when <code>handle_big_files</code> is false (the
          show path). So each history-show response is &le;~472&nbsp;KB.
          The 1.5&nbsp;GB buffer is a <em>different</em> request &mdash;
          most plausibly a large wiki resource / attachment served
          whole and draining slowly to a stalled client, with the
          history-crawling bots as concurrent memory pressure.</li>
      <li><span class="next">NEXT (open)</span> the drain fix
          neutralizes the OOM regardless of producer. To stop a
          ~1.5&nbsp;GB body being <em>generated/buffered</em> at all,
          pinpoint the producer: check pollett.org for a large
          file/resource on the public wiki and the access log just
          <em>before</em> the crash second. Likely follow-up: stream
          large resource bodies rather than buffering them whole.</li>
      <li><span class="check">&#10003;</span> <strong>Resolved
          (producer): the offset/limit resource branch now streams.</strong>
          A second 2&nbsp;GB OOM on 2026-06-22 (tried to allocate
          ~1.28&nbsp;GB, in WebSite.php on the response side, while a
          flood of bots crawled wiki history and source) traced to the
          one resource-serving branch that still read whole.
          ResourceController::get serves a byte window requested with
          <code>o</code> and <code>l</code> (the machine-to-machine
          sync path, and reachable on any public resource) by reading
          the span with <code>file_get_contents($path, false, null,
          $offset, $limit)</code>. The limit comes straight off the
          request as an int with no cap, so a large span (a 50&nbsp;MB
          sync chunk, or a crafted request naming a whole
          multi-hundred-megabyte file) was read entire into memory and
          then copied again into the server's response buffer, and that
          copy is what crossed the 2&nbsp;GB process limit and killed
          the single-process server. The other three serve branches
          (HTTP Range, small files under MAX_RESOURCE_SERVE_LEN, and
          large no-range files) already stream or are bounded; this was
          the lone whole-read. It now streams the same window in
          RESOURCE_STREAM_BLOCK_LEN blocks through the same web_site
          stream generator the Range and large-file branches use, with
          the headers left exactly as before, so the bytes and response
          are identical and memory stays bounded to one block. The exact
          crash request is not in the log tail because a request that
          dies mid-serve never reaches the post-serve access-log write;
          this fix removes the only path that could have produced that
          allocation.</li>
      <li><span class="check">&#10003;</span> <strong>Hardening
          (defense-in-depth): per-connection HTTP/2 memory ceilings.</strong>
          The producer fix above removes the request that built the
          oversized body, but the crash also showed the server had no
          ceiling on how much it would hold for a single HTTP/2
          connection. Because H2 multiplexes every stream's response onto
          one per-connection outbound buffer (queueResponseData appends),
          and each dispatched stream's body waits in pending_send until
          its flow-control window lets it pump, a client that pipelines
          requests faster than it reads the replies could grow that one
          connection's state without bound &mdash; the server advertised
          MAX_CONCURRENT_STREAMS=100 but did not enforce it. Now a new
          stream is refused with RST_STREAM(REFUSED_STREAM) once the
          connection is at 100 open streams or its buffered-byte ceiling
          (H2_MAX_CONN_BUFFER, 64&nbsp;MB: queued unsent + each stream's
          pending response body + each stream's still-arriving request
          body, summed by h2ConnectionBacklog). So no single connection
          can exhaust the process regardless of which route produced the
          body. A conforming client never reaches the limit since it
          honors the advertisement.</li>
      <li><span class="check">&#10003;</span> <strong>Audit of the
          ignored H2 settings for other exhaustion paths.</strong> The
          SETTINGS handler accepts but ignores most peer settings; checked
          each for an unbounded structure a client could grow. Incoming
          frames are already capped (oversized frame &rarr; GOAWAY
          FRAME_SIZE_ERROR; request body &rarr; MAX_REQUEST_LEN), and the
          header block is not accumulated across frames, so those are
          bounded. One gap remained: pending_stream_window_credit stashes
          a WINDOW_UPDATE arriving for a stream whose send window is not
          yet registered, keyed by stream id, and the new byte ceiling
          does not count these small entries &mdash; so a client sending
          WINDOW_UPDATE for many never-opened stream ids could grow that
          map without bound. Now it is capped at MAX_CONCURRENT_STREAMS
          distinct streams (more than a connection can ever have open at
          once); a client exceeding that is crediting streams it never
          opened, which is treated as a PROTOCOL_ERROR (GOAWAY).</li>
    </ol>
  </li>
  <li>&#10003; <span class="check">Fixed</span> MediaUpdater fatal
      &mdash; <code>BulkEmailJob</code> could not load
      <code>SmtpClient</code> (require of a missing
      <code>mail/Utility.php</code>).
    <ol>
      <li>The mail-library relocation moved <code>SmtpClient</code>
          into <code>src/library/mail/</code> but left two breaks the
          daemon path tripped over. First, an inline
          <code>require_once __DIR__ . "/Utility.php"</code> now
          resolved to <code>mail/Utility.php</code> (one level too
          deep) &mdash; file not found, fatal at load. Second, hidden
          behind that, the class still called <code>crawlLog</code>,
          <code>changeInMicrotime</code> and
          <code>setWorldPermissions</code> unqualified; from the new
          <code>...\library\mail</code> namespace those resolve to
          undefined functions, so the first such call would have
          fataled even once the file loaded. Web paths never hit this
          because <code>index.php</code> loads <code>Utility</code>;
          the <code>MediaUpdater</code> daemon did not.</li>
      <li>&#10003; <em>Fixed: a library class should not load
          <code>Utility</code>, so the inline require is gone; the
          <code>MediaUpdater</code> daemon now requires
          <code>Utility</code> like the other executables, and
          SmtpClient imports <code>library as L</code> and calls
          <code>L\crawlLog</code> etc. A sweep of the rest of the
          mail / ACME / media-job v10 classes found no other stray
          requires.</em></li>
    </ol>
  </li>
  <li><strong>HTTP/2 partial transfer on responses past the
      per-stream window (the Magazines page).</strong> A wiki page
      larger than the client's initial per-stream receive window
      (Firefox starts a connection at 131072 bytes) loaded
      intermittently: the same page would succeed on one request and
      fail with NS_ERROR_NET_PARTIAL_TRANSFER on the next. Smaller
      pages, which fit inside the initial window and finish in one
      burst, were never affected.
    <ol>
      <li><strong>What the traces established.</strong> The client
          does extend windows, generously: it raises
          SETTINGS_INITIAL_WINDOW_SIZE mid-connection (seen as
          peer_initial_window jumping from 131072 to 6291456) and
          sends large per-stream WINDOW_UPDATE frames (+12451840).
          So a parked stream is meant to resume the moment that
          credit lands. The behaviour we never saw was the credit
          failing to arrive; what we saw was credit arriving and the
          tail still not going out on the failing loads. Note: a
          separate class of connection advertises an initial window of
          0 and grants entirely per stream &mdash; for those,
          peer_initial_window is genuinely 0 and seeding the send
          window to 0 is correct (the default-window fallback only
          applies when the value is null, never when it is a real 0).
      </li>
      <li><strong>Dead end (recorded so it is not retried).</strong>
          Pacing a large body out in frame-sized blocks through the
          streaming generator does not help by itself: the streaming
          path is gated by the very same per-stream send window as a
          whole-body send, so it cannot push past an exhausted window
          any more than sendH2Body can. Streaming does not raise the
          window. Routing the page through it is not the lever.</li>
      <li><strong>Root cause: a writable-set snapshot race in the
          event loop.</strong> Each loop pass snapshots the set of
          connections with unsent response bytes <em>before</em>
          select, then after select reads inbound frames and finally
          drains that snapshot. When a parked stream last drained its
          window-sized slice it was removed from the writable set
          (shutdownHttpWriteStream, correct &mdash; there was nothing
          to write while its send window sat at zero). The credit
          (WINDOW_UPDATE or raised SETTINGS) then arrives in the
          read phase and re-pumps the stream, queueing the rest of
          the body and re-arming the connection &mdash; but that
          happens after the snapshot was taken, so the drain step
          skips it. The bytes wait for the next select cycle; if the
          peer has stopped reading by then, the tail never leaves and
          the transfer ends partial. Whether the window came back in
          time was a race, which is exactly why the same page passed
          on one load and failed on the next.</li>
      <li>&#10003; <em>Fixed: the drain step now operates on the live
          set of connections that have unsent bytes at that point in
          the tick rather than the pre-read snapshot, so a stream
          re-pumped by a just-read flow-control frame flushes in the
          same pass. out_streams holds only connections with bytes
          still to send, and a socket that is not yet writable simply
          takes nothing this pass and is retried, so draining the live
          set is safe.</em></li>
    </ol>
  </li>
  <li><b>Two further crashes, 2026-07-03 and 2026-07-04.</b> The error log
    shows three identical fatals: the 2&nbsp;GB process limit exhausted while
    allocating ~1.3&nbsp;MB in PackedTableTools::load. The
    <code>[website-memory]</code> lines just before each fatal read
    ~1.95&nbsp;GB used with hundreds of sessions (269, 190, 441) under a bot
    flood, so the load allocation is only the straw that crosses the line;
    the real growth is elsewhere (accumulating sessions/connections, and
    PackedTableTools' own <code>table_cache</code> which has no eviction are
    the leading suspects). The same logs carried ~8000 deprecation and
    warning lines, nearly all from one bug:
    <ul>
      <li><span class="check">&#10003;</span> <b>Cache redirect fell
        through.</b> SearchController::cacheRequest, on a missing crawl item
        with a cached link, set a Location redirect header but did not
        return, so it went on to format a <code>false</code> crawl item.
        That produced the false-to-array deprecation and the whole cascade of
        undefined-key and mb_strtolower(null) warnings on every bot hit to a
        stale cache URL. Adding the return stops it.</li>
      <li><span class="check">&#10003;</span> <b>Broken-pipe warning
        logged.</b> WebSite's streaming write wrapped fwrite in
        set_error_handler(null), which restores the logging handler rather
        than silencing it, so an expected SSL broken pipe from a client that
        hung up was logged. The failure is already handled by the return-false
        check, so the write now uses @fwrite and the warning is silenced.</li>
      <li>A handful of low-volume SocialComponent warnings (undefined
        $page_id, array offset on false) remain to be pinned down against the
        production line numbers.</li>
    </ul>
  </li>
</ol>
</body>
</html>
X