Chapter generation SSE closes before writing a byte, so the reader hangs forever

[rsml]

What happens

POST /api/books/:id/generate-next answers 200 with an empty body. The reader submits chapter feedback, enters its generating state, and sits there with a blinking caret forever. Generation itself completes and the chapter is written to disk correctly, so a reload recovers, but the streaming UI never receives a single event and never leaves the generating phase.

Found by the Phase 6 end-to-end journey suite, which is exactly the class of bug it was built to catch.

Root cause

server/routes/generation.ts, in pipeHubToSse:

request.raw.on('close', () => {
  unsubscribe()
  if (!ended) { ended = true; reply.raw.end() }
})

On Node 16 and later, IncomingMessage's close event fires when the request stream is finished, not only when the client disconnects. For a POST whose body Fastify has already read and parsed, that is immediately. The handler therefore unsubscribes and ends the reply before the generation has produced its first chunk.

server/services/chapter-generation-stream.ts keeps running, finishes the chapter, and saves it, so nothing is lost. The client just never hears about it.

Blast radius

All three routes that share pipeHubToSse.

• POST /api/books/:id/generate-next
• POST /api/books/:id/chapters/:num/regenerate
• GET /api/books/:id/generation-stream (the reconnect path)

The other streaming routes are unaffected, because openSseStream attaches no close listener. That is why creating a book and generating chapter 1 through the wizard both work, and why this went unnoticed.

Reproduction, no browser and no fakes involved

A standalone script against the production startServer path, with a seeded book on disk and a real socket:

PROBE listening on 61110
PROBE status 200 hasBody true
PROBE stream ended. bytes: 0
PROBE content: ""

The same request through fastify.inject returns the full event stream, because light-my-request does not model the socket lifecycle, which is why the existing inject-based tests pass.

Suggested direction

Distinguish a real disconnect from a completed request body. request.raw.on('aborted', ...) covers the pre-Node-17 signal, and checking reply.raw.writableEnded or request.raw.destroyed inside the close handler distinguishes the two cases on current Node. Whatever the fix, it wants a test that exercises a real socket rather than inject, since inject cannot see this failure mode.

Related

Phase 6 quarantines two journey assertions on this, each with a test.fixme citing this issue. They flip to green when this is fixed.

[rsml]

Fixed, with provenance and one correction to the root cause

Fixed on phase-7-durability in 33af121 (failing real-socket test) and 5ef7797 (the fix).

Provenance: original code, not a Phase 2 regression

Traced with git log -S "request.raw.on('close'":

dc7bb01 refactor(routes): rebuild generation routes as wiring over the new services
8a008fa refactor(routes): extract book generation routes into their own module
f0a0374 Fix stuck chapters, quiz gaps, and progress tracking
22d49a8 initial commit

git grep -n "request.raw.on('close'" 22d49a8 puts it at server/routes/books.ts:360 and :396 in the initial commit. Phase 2's HTTP and SSE extraction moved it faithfully and did not introduce it.

This settles the question the issue raises about the frozen characterization suite: no characterization test ever protected this path, and none could have. They all drive the server through fastify.inject, and light-my-request does not model the socket lifecycle the bug depends on. The suite was not weakened by the refactor here, it was structurally blind to this failure mode from the start.

Correction: only one of the three routes actually failed

The issue lists three affected routes. Measured over a real socket, only POST /api/books/:id/generate-next was broken:

PROBE POST /generate-next   : status=200 bytes=0   EMPTY <-- BUG
PROBE POST /1/regenerate    : status=200 bytes=129 OK

regenerate shares the same helper but its handler is async and awaits ports.bookRepository.getBook(bookId) before reaching it. The premature close fires during that await, before the listener is attached, so it is missed. generate-next's handler is synchronous, attaches in the same tick, and catches it.

That route's correctness was therefore an accident of timing. Deleting one await would have silently broken it. Both routes are now pinned by the real-socket test.

A fourth site the issue did not list

server/routes/tasks.ts (GET /api/tasks/stream) carried the identical listener. It is a GET whose body Fastify never reads, so its request stream is not finished early and the listener happened not to misfire, which is why the task tray worked while chapter generation did not. That is a coincidence of the HTTP verb, not a property worth relying on, and it is the stream resumed background jobs are reported through in Phase 7. Fixed in the same commit.

The fix

Listen on the response, not the request. A ServerResponse emits close when the response finishes or the connection is torn down early, which is the question the code meant to ask. On a normal finish the guard flag is already set and unsubscribing is the cleanup that was always wanted; on a real disconnect the subscriber is dropped and the reply closed, exactly as before.

After the fix, same probe: POST /generate-next: status=200 bytes=177 OK.

Test

server/routes/generation.sse.test.ts binds an ephemeral port and speaks HTTP over a real socket. It fails against the old code with expected '' not to be '', the exact symptom reported here. Its header comment states why it pays for a real listener and asks that anything not depending on socket lifecycle stay in the cheaper inject-based suites.

Phase 6's two test.fixme quarantines citing this issue can be deleted; that happens in Phase 7's deferred E2E integration step once Phase 6 merges.

[rsml]

Merged to master as part of PR #55. Fix commit 4b8892b, failing real-socket test bf89fe0. Provenance is in the comment above: the listener dates to 22d49a8, the initial commit, so Phase 2 preserved it faithfully rather than introducing it, and no fastify.inject based test could ever have caught it.

All three test.fixme quarantines citing this issue now run. Web suite green at 23 journeys, including a 4x contention stress pass at 92 passed.