Skip to content

Print the post-analysis summary to stdout in CI when the error output before it went to stdout - #6740

Open
phpstan-bot wants to merge 1 commit into
phpstan:2.3.xfrom
phpstan-bot:create-pull-request/patch-9qpma5f
Open

phpstan-bot wants to merge 1 commit into
phpstan:2.3.xfrom
phpstan-bot:create-pull-request/patch-9qpma5f

Conversation

@phpstan-bot

Copy link
Copy Markdown
Collaborator

Summary

In CI, the performance summary ("Elapsed time", "Peak memory") and the --debug diagnose output sometimes landed in the middle of the error table. PHPStan writes the error table to stdout and the summary to stderr. CI runners like GitHub Actions read the two streams through separate pipes and merge them in no fixed order, so flushing in PHP can't fix it (Symfony's StreamOutput already calls fflush() after every write).

With this change, PHPStan writes everything that follows human-readable stdout output to stdout as well, but only when a CI is detected. The order is then decided by a single stream.

Changes

  • src/Command/AnalyseCommand.php: added a $summaryOutput that is stdout when CiDetector detects a CI and the error format is table (or --generate-baseline is used), and stderr otherwise. It is used for:
    • diagnose extension output (-vvv/--debug)
    • the "Result is incomplete because of severe errors" note
    • the missing-result-cache tip in CI
    • elapsed time and peak memory
  • src/Command/InceptionResult.php: handleReturn() takes an optional ?Output $summaryOutput (defaults to the error output).
  • Same issue fixed in the --generate-baseline path. Its success, warning and error messages go to stdout and the summary used to follow on stderr.
  • Machine-readable formats (json, checkstyle, junit, gitlab, raw, …) still write the summary to stderr so their stdout stays parseable. Outside CI, nothing changes.

Root cause

Output that should appear after stdout content was written to a different stream (stderr). When the consumer reads the two streams independently, as CI runners do, there is no ordering guarantee between them.

Test

Added AnalyseCommandTest cases that set GITHUB_ACTIONS=true and capture stderr separately:

  • table format: diagnose output, elapsed time and peak memory are on stdout, not stderr (fails without the fix)
  • json format: they stay on stderr
  • --generate-baseline: the elapsed time follows the baseline message on stdout (fails without the fix)

Fixes phpstan/phpstan#15455

🤖 Generated with Claude Code

… before it went to stdout

- CI runners (GitHub Actions etc.) read stdout and stderr through separate pipes and merge them non-deterministically, so stderr lines written after the stdout error table (diagnose output, "Elapsed time", "Peak memory", result cache tip, "Result is incomplete") could show up in the middle of the table.
- AnalyseCommand now picks a summary output: stdout when CI is detected and the human-readable `table` error format is used (or a baseline is being generated, whose messages also go to stdout), stderr otherwise. Machine-readable formats (json, checkstyle, ...) keep stdout clean.
- InceptionResult::handleReturn() accepts an optional output for the elapsed time and peak memory lines.
- Also applied to the --generate-baseline path, which prints its result to stdout followed by the summary.

@staabm staabm left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In which commit did this regress?

@phpstan-bot

Copy link
Copy Markdown
Collaborator Author

It isn't a regression. The summary has gone to stderr, while the error table goes to stdout, ever since each piece of it was added:

Output Commit First release Stream
"Used memory" (now "Peak memory") a90b290 "Used memory will be printed with -v" 0.12.26 $this->getErrorOutput() in InceptionResult::handleReturn()
--debug diagnose output d55933f "DiagnoseExtension" 1.11.7 runDiagnoseExtensions($container, $inceptionResult->getErrorOutput())
"Elapsed time" 574c557 "Print analysis time with -vvv" 1.11.8 $this->getErrorOutput()

I looked for later changes with git log -S across src/Command/. Later commits (082f0a3, 6108f12) changed when these lines print and what they say, but not which stream they go to. The error formatter has always written to getStdOutput().

So the order was never guaranteed when stdout and stderr are read separately. It only looks right in a terminal, where both streams write to the same TTY in order. GitHub Actions reads them through separate pipes and merges them, so the summary can end up in the middle of the table. That's why the linked issue is a feature request rather than a bug report, and why this PR changes behaviour in CI instead of reverting an earlier commit.

I didn't change any code, so there's nothing new to commit or push.

@ondrejmirtes

Copy link
Copy Markdown
Member

I wouldn't rush to fix this issue in a nasty way.

In reality it's a bug to be reported to GitHub.

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.

Performance summary is placed randomly

3 participants