pants: Inconsistent goal output

On Pants main @ 6037e699 I encountered this failure with no information about why Flake8 failed:

$ ./pants --changed-since=upstream/main fmt lint check test
10:47:55.31 [INFO] Initializing scheduler...
10:47:55.41 [INFO] Scheduler initialized.
10:47:58.52 [INFO] Completed: Building autoflake.pex from autoflake_default_lockfile.txt
10:47:58.64 [WARN] Completed: Format with Autoflake - autoflake made changes.
10:48:03.67 [INFO] Completed: Building black.pex from black_default_lockfile.txt
10:48:04.21 [WARN] Completed: Format with Black - Black made changes.
reformatted src/python/pants/engine/process_test.py
All done! ✨ 🍰 ✨
1 file reformatted, 1 file left unchanged.


10:48:07.37 [INFO] Completed: Building docformatter.pex from docformatter_default_lockfile.txt
10:48:07.48 [INFO] Completed: Format with docformatter - Docformatter made no changes.
10:48:08.47 [INFO] Completed: Building isort.pex from isort_default_lockfile.txt
10:48:08.56 [INFO] Completed: Format with isort - isort made no changes.

+ Black made changes.
✓ Docformatter made no changes.
+ autoflake made changes.
✓ isort made no changes.
10:48:08.65 [INFO] Completed: Lint with isort - isort succeeded.
10:48:08.68 [INFO] Completed: Lint with autoflake - autoflake succeeded.
10:48:08.73 [INFO] Completed: Lint with docformatter - Docformatter succeeded.
10:48:09.02 [INFO] Completed: Lint with Black - Black succeeded.
All done! ✨ 🍰 ✨
2 files would be left unchanged.


10:48:11.36 [INFO] Completed: Building flake8.pex from 3rdparty/python/lockfiles/flake8.txt

✓ Black succeeded.
✓ Docformatter succeeded.
𐄂 Flake8 failed.
✓ autoflake succeeded.
✓ isort succeeded.

I re-ran and found:

$ ./pants --changed-since=upstream/main fmt lint check test
10:49:05.17 [INFO] Completed: Format with Autoflake - autoflake made no changes.
10:49:05.56 [INFO] Completed: Format with Black - Black made no changes.
All done! ✨ 🍰 ✨
2 files left unchanged.


10:49:05.56 [INFO] Completed: Format with docformatter - Docformatter made no changes.
10:49:05.56 [INFO] Completed: Format with isort - isort made no changes.

✓ Black made no changes.
✓ Docformatter made no changes.
✓ autoflake made no changes.
✓ isort made no changes.
10:49:05.57 [INFO] Completed: Lint with autoflake - autoflake succeeded.
10:49:05.57 [INFO] Completed: Lint with docformatter - Docformatter succeeded.
10:49:05.57 [INFO] Completed: Lint with Black - Black succeeded.
All done! ✨ 🍰 ✨
2 files would be left unchanged.


10:49:05.57 [INFO] Completed: Lint with isort - isort succeeded.
10:49:05.77 [ERROR] Completed: Lint with Flake8 - Flake8 failed (exit code 1).
src/python/pants/engine/process.py:537:1: W293 blank line contains whitespace



✓ Black succeeded.
✓ Docformatter succeeded.
𐄂 Flake8 failed.
✓ autoflake succeeded.
✓ isort succeeded.

So the issue was src/python/pants/engine/process.py:537:1: W293 blank line contains whitespace but that was not reported on the 1st run. In the 1st run it’s just reported that the flake8.pex was built 10:48:11.36 [INFO] Completed: Building flake8.pex from 3rdparty/python/lockfiles/flake8.txt, but not what the Completed: ... of that pex’s execution was.

The pantsd.log shows the following for this session:

10:47:54.88 [INFO] handling request: `--changed-since=upstream/main fmt lint check test`
10:48:08.57 [INFO] notify invalidation: cleared 2 and dirtied 109 nodes for: {"src/python/pants/engine/process.py", "src/python/pants/engine"}
10:48:08.57 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/pants/engine/process.py", "src/python/pants/engine"}
10:48:08.57 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/pants/engine", "src/python/pants/engine/process.py"}
10:48:08.57 [INFO] notify invalidation: cleared 1 and dirtied 15 nodes for: {"src/python/pants/engine", "src/python/pants/engine/process_test.py"}
10:48:08.57 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/pants/engine/process_test.py", "src/python/pants/engine"}
10:48:08.57 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/pants/engine", "src/python/pants/engine/process_test.py"}
10:48:08.57 [INFO] notify invalidation: cleared 2 and dirtied 111 nodes for: {"src/python/pants/engine/process.py", "src/python/pants/engine"}
10:48:08.57 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/pants/engine", "src/python/pants/engine/process_test.py"}
10:48:08.57 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/pants/engine/process.py", "src/python/pants/engine"}
10:48:08.57 [INFO] Filesystem changed during run: retrying `PySnapshot` in 500ms...
10:48:08.57 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/pants/engine", "src/python/pants/engine/process.py"}
10:48:08.57 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/pants/engine", "src/python/pants/engine/process_test.py"}
10:48:08.57 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/pants/engine", "src/python/pants/engine/process_test.py"}
10:48:11.56 [INFO] request completed: `--changed-since=upstream/main fmt lint check test`
10:49:04.98 [INFO] handling request: `--changed-since=upstream/main fmt lint check test`
10:49:05.77 [INFO] request completed: `--changed-since=upstream/main fmt lint check test`
10:49:15.41 [INFO] Extending leases
10:49:15.43 [INFO] Done extending leases
...