Skip to content

Horizon: forked processes write stdout a whole line at a time (builds on #1) - #2

Merged
tevkert merged 2 commits into
mainfrom
whole-lines-from-forked-processes
Nov 9, 2026
Merged

tevkert merged 2 commits into
mainfrom
whole-lines-from-forked-processes

Conversation

@tevkert

@tevkert tevkert commented Nov 9, 2026

Copy link
Copy Markdown
Owner

Builds on #1 by @serpentblade: forked Horizon processes interleave their job lines in the log, and a write filter on STDOUT keeps each line whole. This branch is #1's commit, unchanged, with one commit on top that fixes edge cases found in review. Merging it with a merge commit marks #1 as merged too.

On top of #1

  • Exit status: a partial line still held at exit made the process exit 255 and lost the line. PHP invalidates STDOUT before the filter's last flush, so stream_bucket_new() threw. The last bucket is now made against a temporary memory stream, and the filter drops rather than throws if even that fails.
  • STDERR is not filtered: after an engine fatal error (memory or time limit), PHP stops calling user filters and a filtered stream drops everything written to it, which swallowed Laravel's fatal-error report. Job lines go to STDOUT, so only STDOUT is filtered.
  • Scope: the filter is attached only where stdout is shared: forked Horizon processes and shared-log workers. Normal-mode queue:work workers have their stub's own stdio and keep stock behaviour.
  • Forks: a process forked after the filter was attached (a job's own pcntl_fork()) no longer repeats the half-line its parent held.
  • Preload: LineBufferFilter is in Runtime::CLASSES; PreloadTest skipped it because it took extends php_user_filter for a framework parent.
  • The line scan is linear, the comments are corrected (the console kernel reroutes Symfony's command events itself after boot, outside unit tests), and the README lists the line-at-a-time stdout under "Limitations and differences from stock".

Tests

New tests in real PHP processes: the exit status and held tail, STDERR output after a memory-limit fatal, output from shutdown functions and destructors, a stream closed before exit, a child forked while its parent holds part of a line, and four forked writers sharing one pipe, which mangles lines without the filter. Each fails without its fix.

composer test passes on macOS (PHP 8.4); the new tests also pass on Linux (PHP 8.4, Docker). The Docker integration suites were not run.

🤖 Generated with Claude Code

serpentblade and others added 2 commits November 8, 2026 22:34
Stock Horizon gives each worker a pipe that its supervisor reads and relays,
so lines from different workers never mix. Forked processes write straight to
the stdout they inherited, which they all share, and queue:work writes each job
line in three or four pieces, so pieces from different workers interleave
mid-line in the container log.

A write filter on STDOUT and STDERR now holds output until a newline and passes
each complete line on as its own write. A pipe delivers a write of up to
PIPE_BUF in one piece, so each line reaches the log whole. A partial line is
held up to 4096 bytes and passed on when the stream closes.

It filters the streams themselves, which are what Symfony's ConsoleOutput
writes to outside Windows, and is attached in Wiring::child() so it is in place
before the command writes anything.
…nly shared stdout

- Only STDOUT is filtered. After an engine fatal error (a memory or time
  limit) PHP stops calling user filters, and a filtered stream drops
  everything written to it, so with STDERR filtered Laravel's report of
  the error was lost. Job lines go to STDOUT; STDERR is written as stock.
- A partial line still held when a stream was freed without fclose()
  (STDOUT at exit) made the process exit with status 255 and lost the
  line: PHP invalidates the stream before the filter's last flush, so
  stream_bucket_new() threw. The filter now makes that last bucket
  against a temporary memory stream, which still reaches the stream
  being freed, and drops rather than throws if even that fails. Output
  written later in shutdown (shutdown functions, destructors) stays
  line-buffered.
- A process forked after the filter was attached (a job's own
  pcntl_fork()) no longer repeats the part of a line its parent held:
  the filter drops what it inherited when its pid changes.
- The filter is attached only where stdout is shared: forked Horizon
  processes and shared-log workers. A normal-mode queue:work worker has
  its stub's own stdio and keeps stock output behaviour.
- One write with many lines is split with an offset instead of copying
  the rest of the buffer once per line.
- LineBufferFilter extends php_user_filter, PHP's own class, so
  PreloadTest took it for a class with a framework parent and left it
  out of Runtime::CLASSES; a forked child then autoloaded it from
  whichever release was on disk. It is preloaded now, and the test
  counts php_user_filter as no parent.
- Comments: the console kernel reroutes Symfony's command events itself
  once the app has booted (outside unit tests), so CommandStarting needs
  no opt-in; stock Horizon relays each worker's pipe but doesn't promise
  whole lines either.
- README: the line-at-a-time stdout under "Limitations and differences
  from stock".
- Tests, in real PHP processes: the exit status and held tail, STDERR
  output after a memory-limit fatal error, output from shutdown
  functions and destructors, a stream closed before exit, a child forked
  while its parent holds part of a line, and four forked writers sharing
  one pipe, which mangles lines without the filter; plus many lines in
  one write. The process tests end themselves after 30 s rather than
  hang CI.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@tevkert
tevkert merged commit ce4d35d into main Nov 9, 2026
27 checks passed
tevkert added a commit that referenced this pull request Nov 9, 2026
Forked Horizon processes and shared-log workers write their stdout a whole
line at a time, so job lines from different workers no longer interleave
in the log (#1, #2). CHANGELOG for 1.0.5.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@tevkert
tevkert deleted the whole-lines-from-forked-processes branch November 9, 2026 11:31
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants