[typ] Capture subprocess stdio [catapult : main]
Jonathan Lee (Gerrit)
Jonathan Lee added 1 comment![]( "Open in Gerrit")
Tested downstream: https://crrev.com/c/7129507
Seems to work on all platforms:
- [Linux](https://luci-milo.appspot.com/ui/inv/task-chromium-swarm.appspot.com-747a39e8b0f9c311/test-results?q=ExactID%3Aninja%3A%2F%2Fchrome%2Ftest%3Atelemetry_gpu_integration_test%2Fgpu_tests.pixel_integration_test.PixelIntegrationTest.Pixel_Canvas2DRedBox_SwiftShader+VHash%3A107e3078410cf59d)
- [macOS](https://luci-milo.appspot.com/ui/inv/task-chromium-swarm.appspot.com-747a39e8c6275111/test-results?q=ExactID%3Aninja%3A%2F%2Fchrome%2Ftest%3Atelemetry_gpu_integration_test%2Fgpu_tests.trace_integration_test.TraceIntegrationTest.TraceTest_Video_MP4_FourColors_Rot_270+VHash%3Ac172f60347ad71f8)
- [Windows](https://luci-milo.appspot.com/ui/inv/task-chromium-swarm.appspot.com-747a610fa235f111/test-results?q=ExactID%3Aninja%3A%2F%2Fchrome%2Ftest%3Atelemetry_gpu_integration_test%2Fgpu_tests.trace_integration_test.TraceIntegrationTest.OverlayModeTraceTest_DirectComposition_Video_MP4_FourColors_Rot_270+VHash%3A9616b31d15cafe36)
Related details
- Brian Sheedy
Code-Owners
Code-Review
Review-Enforcement
| Inspect html for hidden footers to help with email filtering. To unsubscribe visit settings. |
Brian Sheedy (Gerrit)
Brian Sheedy added 1 comment![]( "Open in Gerrit")
# Set up redirection lazily so that `sys.std(out|err)` remains unalteredI believe this won't work correctly for GPU tests which use the browser instance that is created during `SetUpProcess()`, e.g. [here](https://source.chromium.org/chromium/chromium/src/+/main:content/test/gpu/gpu_tests/webgpu_cts_integration_test_base.py;l=252)
This is called once per child process when setting up the pool [here](https://source.chromium.org/chromium/chromium/src/+/main:third_party/catapult/third_party/typ/typ/runner.py;l=665), but `capture_output` is called [once for every test that is run](https://source.chromium.org/chromium/chromium/src/+/main:third_party/catapult/third_party/typ/typ/runner.py;l=1191).
This should resolve itself when the browser is restarted, but we want consistent behavior regardless of when a test happens to run.
Related details
- Jonathan Lee
Code-Owners
Code-Review
No-Unresolved-Comments
Review-Enforcement
| Inspect html for hidden footers to help with email filtering. To unsubscribe visit settings. |
Jonathan Lee (Gerrit)
Jonathan Lee added 3 comments![]( "Open in Gerrit")
Tested downstream: https://crrev.com/c/7129507
Seems to work on all platforms:
- [Linux](https://luci-milo.appspot.com/ui/inv/task-chromium-swarm.appspot.com-747a39e8b0f9c311/test-results?q=ExactID%3Aninja%3A%2F%2Fchrome%2Ftest%3Atelemetry_gpu_integration_test%2Fgpu_tests.pixel_integration_test.PixelIntegrationTest.Pixel_Canvas2DRedBox_SwiftShader+VHash%3A107e3078410cf59d)
- [macOS](https://luci-milo.appspot.com/ui/inv/task-chromium-swarm.appspot.com-747a39e8c6275111/test-results?q=ExactID%3Aninja%3A%2F%2Fchrome%2Ftest%3Atelemetry_gpu_integration_test%2Fgpu_tests.trace_integration_test.TraceIntegrationTest.TraceTest_Video_MP4_FourColors_Rot_270+VHash%3Ac172f60347ad71f8)
- [Windows](https://luci-milo.appspot.com/ui/inv/task-chromium-swarm.appspot.com-747a610fa235f111/test-results?q=ExactID%3Aninja%3A%2F%2Fchrome%2Ftest%3Atelemetry_gpu_integration_test%2Fgpu_tests.trace_integration_test.TraceIntegrationTest.OverlayModeTraceTest_DirectComposition_Video_MP4_FourColors_Rot_270+VHash%3A9616b31d15cafe36)
This time, I checked the test results for `expected_color` tests. In PS8, the `chrome` log was missing from the first few tests, but aren't anymore:
- [Linux]
- [macOS]
- [Windows]
[Linux]: https://luci-milo.appspot.com/ui/inv/task-chromium-swarm.appspot.com-74892d2046de4811/test-results
[macOS]: https://luci-milo.appspot.com/ui/inv/task-chromium-swarm.appspot.com-74890cb0e98cb611/test-results
[Windows]: https://luci-milo.appspot.com/ui/inv/task-chromium-swarm.appspot.com-74892ba10e757811/test-results
cmd, stdout=sys.stdout, stderr=sys.stderr, env=env)For Windows, `desktop_browser_backend.py` must pass FDs 1/2 to the `chrome` process. Passing the `alt_fd`s doesn't seem to work (see https://crrev.com/c/7124053/6, tested [here]).
In PS8, `desktop_browser_backend.py` implicitly honored this because `sys.std(out|err)` was either:
1. A `_TeedStream` (fell back to `sys.__std(out|err)__` via `io.UnsupportedOperation`)
2. The original `sys.std(out|err) is sys.__std(out|err)__`
However, in the new `runner._setup_process`, this `sys.std(out|err)` can now be the stream backed by `alt_fd`, so we need to pass `sys.__std(out|err)__` directly now.
[here]: https://ci.chromium.org/ui/p/chromium/builders/try/gpu-fyi-try-win10-nvidia-rel-64/658/overview
# Set up redirection lazily so that `sys.std(out|err)` remains unalteredI believe this won't work correctly for GPU tests which use the browser instance that is created during `SetUpProcess()`, e.g. [here](https://source.chromium.org/chromium/chromium/src/+/main:content/test/gpu/gpu_tests/webgpu_cts_integration_test_base.py;l=252)
This is called once per child process when setting up the pool [here](https://source.chromium.org/chromium/chromium/src/+/main:third_party/catapult/third_party/typ/typ/runner.py;l=665), but `capture_output` is called [once for every test that is run](https://source.chromium.org/chromium/chromium/src/+/main:third_party/catapult/third_party/typ/typ/runner.py;l=1191).
This should resolve itself when the browser is restarted, but we want consistent behavior regardless of when a test happens to run.
I see. Changed to expose and rename `{init => setup}_stdio_for_process` and call that from `runner._setup_process` in the necessary order.
I don't think we should reassign `sys.std*` in `Host.__init__`, since web tests need a `typ.host.Host` instance to use with `typ.artifacts.Artifacts`, but the web test runners don't call `capture_ouptut()` and don't need `sys.std*` redirection.
Related details
- Brian Sheedy
Code-Owners
Code-Review
Review-Enforcement
| Inspect html for hidden footers to help with email filtering. To unsubscribe visit settings. |
Brian Sheedy (Gerrit)
Brian Sheedy added 2 comments![]( "Open in Gerrit")
# Set up redirection lazily so that `sys.std(out|err)` remains unalteredJonathan LeeI believe this won't work correctly for GPU tests which use the browser instance that is created during `SetUpProcess()`, e.g. [here](https://source.chromium.org/chromium/chromium/src/+/main:content/test/gpu/gpu_tests/webgpu_cts_integration_test_base.py;l=252)
This is called once per child process when setting up the pool [here](https://source.chromium.org/chromium/chromium/src/+/main:third_party/catapult/third_party/typ/typ/runner.py;l=665), but `capture_output` is called [once for every test that is run](https://source.chromium.org/chromium/chromium/src/+/main:third_party/catapult/third_party/typ/typ/runner.py;l=1191).
This should resolve itself when the browser is restarted, but we want consistent behavior regardless of when a test happens to run.
I see. Changed to expose and rename `{init => setup}_stdio_for_process` and call that from `runner._setup_process` in the necessary order.
I don't think we should reassign `sys.std*` in `Host.__init__`, since web tests need a `typ.host.Host` instance to use with `typ.artifacts.Artifacts`, but the web test runners don't call `capture_ouptut()` and don't need `sys.std*` redirection.
Not doing this in `__init__` SGTM.
I'm still seeing some unexpected behavior around tests that use the first launched browser, though.
In your linked `expected_color` examples, the first test to run (`ExpectedColor_MediaRecorderFrom2DCanvas`) does not have any logging captured for browser startup. However, the third test (`ExpectedColor_maps`) does, as it restarts the browser to pick up different browser args.
I don't think this is a big enough issue to block submission until it's fully fixed, but it would be good to do some investigation into why this is the case. If you're unable to track down the root cause quickly or if the fix isn't simple, then I think it's fine to add a TODO and come back to this later.
getattr(sys, stream_name).write(line)Nit: Perhaps this isn't called frequently enough to actually matter, but it seems wasteful to look up the stream every single time we write a line. At this point, is `sys.std(out|err)` ever expected to be replaced out from under the forwarder? If not, then it seems like it would be better to to `stream = getattr(sys, stream_name)` at the top of the function and use that.
Related details
- Jonathan Lee
Code-Owners
Code-Review
No-Unresolved-Comments
Review-Enforcement
| Inspect html for hidden footers to help with email filtering. To unsubscribe visit settings. |
Brian Sheedy (Gerrit)
Brian Sheedy added 1 comment![]( "Open in Gerrit")
# Set up redirection lazily so that `sys.std(out|err)` remains unalteredJonathan LeeI believe this won't work correctly for GPU tests which use the browser instance that is created during `SetUpProcess()`, e.g. [here](https://source.chromium.org/chromium/chromium/src/+/main:content/test/gpu/gpu_tests/webgpu_cts_integration_test_base.py;l=252)
This is called once per child process when setting up the pool [here](https://source.chromium.org/chromium/chromium/src/+/main:third_party/catapult/third_party/typ/typ/runner.py;l=665), but `capture_output` is called [once for every test that is run](https://source.chromium.org/chromium/chromium/src/+/main:third_party/catapult/third_party/typ/typ/runner.py;l=1191).
This should resolve itself when the browser is restarted, but we want consistent behavior regardless of when a test happens to run.
Brian SheedyI see. Changed to expose and rename `{init => setup}_stdio_for_process` and call that from `runner._setup_process` in the necessary order.
I don't think we should reassign `sys.std*` in `Host.__init__`, since web tests need a `typ.host.Host` instance to use with `typ.artifacts.Artifacts`, but the web test runners don't call `capture_ouptut()` and don't need `sys.std*` redirection.
Not doing this in `__init__` SGTM.
I'm still seeing some unexpected behavior around tests that use the first launched browser, though.
In your linked `expected_color` examples, the first test to run (`ExpectedColor_MediaRecorderFrom2DCanvas`) does not have any logging captured for browser startup. However, the third test (`ExpectedColor_maps`) does, as it restarts the browser to pick up different browser args.
I don't think this is a big enough issue to block submission until it's fully fixed, but it would be good to do some investigation into why this is the case. If you're unable to track down the root cause quickly or if the fix isn't simple, then I think it's fine to add a TODO and come back to this later.
Ah, it's because even if we swap out stdio, we don't start capturing until the test actually starts.
Related details
- Jonathan Lee
Code-Owners
Code-Review
No-Unresolved-Comments
Review-Enforcement
| Inspect html for hidden footers to help with email filtering. To unsubscribe visit settings. |
Brian Sheedy (Gerrit)
Brian Sheedy voted and added 2 comments![]( "Open in Gerrit")
Votes added by Brian Sheedy
| Code-Review | +1 |
2 comments
# Set up redirection lazily so that `sys.std(out|err)` remains unalteredJonathan LeeI believe this won't work correctly for GPU tests which use the browser instance that is created during `SetUpProcess()`, e.g. [here](https://source.chromium.org/chromium/chromium/src/+/main:content/test/gpu/gpu_tests/webgpu_cts_integration_test_base.py;l=252)
This is called once per child process when setting up the pool [here](https://source.chromium.org/chromium/chromium/src/+/main:third_party/catapult/third_party/typ/typ/runner.py;l=665), but `capture_output` is called [once for every test that is run](https://source.chromium.org/chromium/chromium/src/+/main:third_party/catapult/third_party/typ/typ/runner.py;l=1191).
This should resolve itself when the browser is restarted, but we want consistent behavior regardless of when a test happens to run.
Brian SheedyI see. Changed to expose and rename `{init => setup}_stdio_for_process` and call that from `runner._setup_process` in the necessary order.
I don't think we should reassign `sys.std*` in `Host.__init__`, since web tests need a `typ.host.Host` instance to use with `typ.artifacts.Artifacts`, but the web test runners don't call `capture_ouptut()` and don't need `sys.std*` redirection.
Brian SheedyNot doing this in `__init__` SGTM.
I'm still seeing some unexpected behavior around tests that use the first launched browser, though.
In your linked `expected_color` examples, the first test to run (`ExpectedColor_MediaRecorderFrom2DCanvas`) does not have any logging captured for browser startup. However, the third test (`ExpectedColor_maps`) does, as it restarts the browser to pick up different browser args.
I don't think this is a big enough issue to block submission until it's fully fixed, but it would be good to do some investigation into why this is the case. If you're unable to track down the root cause quickly or if the fix isn't simple, then I think it's fine to add a TODO and come back to this later.
Ah, it's because even if we swap out stdio, we don't start capturing until the test actually starts.
In that case, I think it's fine to stick with the current behavior since it expected behavior. We don't care too much about the browser startup output and it'll be easy enough to find in the Swarming task if it's actually needed.
Related details
- Jonathan Lee
Code-Owners
Code-Review
No-Unresolved-Comments
Review-Enforcement
| Inspect html for hidden footers to help with email filtering. To unsubscribe visit settings. |
Jonathan Lee (Gerrit)
Jonathan Lee voted and added 1 comment![]( "Open in Gerrit")
Votes added by Jonathan Lee
| Commit-Queue | +2 |
1 comment
Nit: Perhaps this isn't called frequently enough to actually matter, but it seems wasteful to look up the stream every single time we write a line. At this point, is `sys.std(out|err)` ever expected to be replaced out from under the forwarder? If not, then it seems like it would be better to to `stream = getattr(sys, stream_name)` at the top of the function and use that.
This is actually needed for correctness, since `sys.std(out|err)` can switch between `alt_stream` and `_TeedStream(alt_stream)` over the process's lifetime as the `Host` captures/restores. Reworded the comment to hopefully make that clearer.
Regarding performance, [this benchmark] claims `getattr()` is 2x slower than a theoretically optimal direct access, but both seem negligible relative [to `TextIOWrapper.write()`][0] and all of the underlying buffering machinery. Also, the `getattr()` cost is bounded by how frequently the subprocesses are producing lines, which shouldn't be that frequent except in pathological cases like invoking the `yes` binary.
[0]: https://github.com/python/cpython/blob/92741c59f89e114474bdb2cb539107ef6bae0b9c/Lib/_pyio.py#L2269
[this benchmark]: https://stackoverflow.com/a/41129351
Related details
Code-Owners
Code-Review
Review-Enforcement
| Inspect html for hidden footers to help with email filtering. To unsubscribe visit settings. |
Jonathan Lee (Gerrit)
Jonathan Lee voted Commit-Queue+2![]( "Open in Gerrit")
| Commit-Queue | +2 |
Related details
Code-Owners
Code-Review
Review-Enforcement
| Inspect html for hidden footers to help with email filtering. To unsubscribe visit settings. |
Catapult LUCI CQ (Gerrit)
Catapult LUCI CQ submitted the change with unreviewed changes![]( "Open in Gerrit")
Unreviewed changes
11 is the latest approved patch-set.
The change was submitted with unreviewed changes in the following files:
```
The name of the file: third_party/typ/typ/host.py
Insertions: 6, Deletions: 5.
@@ -324,11 +324,12 @@
encoding = getattr(sys, stream_name).encoding
with os.fdopen(read_fd, encoding=encoding, newline='') as reader:
for line in reader:
- # For nested `_TeedStream`s, send the line to the current
- # outermost stream and let the write propagate inward towards the
- # backing OS stream. These writes are line-buffered and mutually
- # exclusive with other threads, so the captured output won't have
- # interwoven line fragments.
+ # `sys.std(out|err)` can switch at any point between the
+ # `alt_stream` created in `_remap_stream()` and
+ # `_TeedStream(alt_stream)` when capturing. Therefore, we need to
+ # resolve the current stream for each write. These writes are
+ # line-buffered and mutually exclusive with other threads, so the
+ # captured output won't have interwoven line fragments.
getattr(sys, stream_name).write(line)
```
Change information
[typ] Capture subprocess stdio
When initializing a typ runner child process, permanently replace the
`STD(OUT|ERR)_FILENO` file descriptors with a pipe that subprocesses can
inherit. A helper thread forwards lines from the pipe to
`sys.std(out|err).write()`, which is either:
* The remapped std(out|err) object
* One or more wrapping `_TeedStream`s, which have been made threadsafe
Remapping is how real shells implement file redirection (e.g.,
`>/path/to/file`).
- M telemetry/telemetry/internal/backends/chrome/desktop_browser_backend.py
- M third_party/typ/typ/host.py
- M third_party/typ/typ/runner.py
- M third_party/typ/typ/tests/main_test.py
Code-Review: +1 by Brian Sheedy
| Inspect html for hidden footers to help with email filtering. To unsubscribe visit settings. |