selenium: [🐛 Bug]: ExternalProcess produces a huge amount of excessive records which prevents to fetch/read CI logs
What happened?
We use SIGINT to kill Appium process created using process builder (e.g. graceful shutdown). This closes the process stdout, but the process remains alive for a while.
There is this code in the ExternalProcess:
new Thread(
() -> {
InputStream input = process.getInputStream();
// use the CircularOutputStream as mandatory, we know it will never raise a
// IOException
OutputStream output = new MultiOutputStream(circular, copyOutputTo);
while (process.isAlive()) {
try {
// we must read the output to ensure the process will not lock up
input.transferTo(output);
} catch (IOException ex) {
LOG.log(
Level.WARNING,
"failed to copy the output of process " + process.pid(),
ex);
}
}
})
.start();
As a result the above while loop spins for a few seconds thus producing a huge amount of warnings that significantly increase the overall log size, so it cannot be even fetched from the CI properly or read in the browser. A single record looks like:
Nov 04, 2023 8:10:01 AM org.openqa.selenium.os.ExternalProcess$Builder lambda$start$0
WARNING: failed to copy the output of process 63950
java.io.IOException: Stream closed
at java.base/java.io.BufferedInputStream.getBufIfOpen(BufferedInputStream.java:168)
at java.base/java.io.BufferedInputStream.read(BufferedInputStream.java:334)
at java.base/java.io.InputStream.transferTo(InputStream.java:782)
at org.openqa.selenium.os.ExternalProcess$Builder.lambda$start$0(ExternalProcess.java:209)
at java.base/java.lang.Thread.run(Thread.java:833)
How can we reproduce the issue?
Run Appium Java client CI. Example: https://github.com/appium/java-client/actions/runs/6751224992/job/18359734036?pr=2067
Relevant log output
https://github.com/appium/java-client/actions/runs/6751224992/job/18359734036?pr=2067
Operating System
macos
Selenium version
4.15.2
What are the browser(s) and version(s) where you see this issue?
Appium
What are the browser driver(s) and version(s) where you see this issue?
Are you using Selenium Grid?
no
About this issue
- Original URL
- State: closed
- Created 8 months ago
- Comments: 20 (15 by maintainers)
Commits related to this issue
- [java] close the streams after I/O failure #13096 — committed to SeleniumHQ/selenium by joerg1985 8 months ago
- Revert "[java] close the streams after I/O failure #13096" This reverts commit e4d31f2dba0c131f8d3b4faeaf3ac0519187214c. — committed to SeleniumHQ/selenium by joerg1985 8 months ago
- Revert "Revert "[java] close the streams after I/O failure #13096"" This reverts commit 61074047fd7408ecd3e1307cbc661ae65ad3c130. — committed to SeleniumHQ/selenium by joerg1985 8 months ago
The loop is still removed, so this issue should still be fixed.
I removed closing the streams, this somehow disturbs the process. The CI should now flip to green again, will keep an eye on it.
@mykola-mokhnach i just pushed a fix to this, thanks for reporting it!