On 3/12/18 1:51 PM, Chris Plummer wrote:
Hi Igor,
On 3/12/18 1:26 PM, Igor Ignatyev wrote:
On Mar 12, 2018, at 8:53 AM, Chris Plummer <chris.plum...@oracle.com
<mailto:chris.plum...@oracle.com>> wrote:
On 3/11/18 7:52 PM, David Holmes wrote:
Hi Chris,
On 10/03/2018 6:46 AM, Chris Plummer wrote:
Hello,
Please help review the following:
https://bugs.openjdk.java.net/browse/JDK-8198655
http://cr.openjdk.java.net/~cjplummer/8198655/webrev.00/webrev/
In the end there were two issues. The first was that the
pb.redirectError() call was redirecting the LingeredApp's stderr
to the console, which we don't want. The second was that nothing
was capturing the LingeredApp's output and sending it to the
driver app's output (jtr file). These changes make all the
LingeredApp's output end up in the jtr file.
It isn't clear to me how the interleaving of the two streams by the
two threads is handled in the copy routine. Are we guaranteed to
get complete lines of output from each stream before writing to
System.out?
Hi David,
I'm hoping Igor will chime in here, since this is just cloned from
some closed code he wrote, and he recommended this fix. Perhaps we
are just doing something a bit non standard here. When spawning a
separate test process, don't we normally just dump stdout and stderr
separately via OutputAnalyzer.reportDiagnosticSummary() after the
test completes, and then only if there is an error. I'm not sure why
Igor felt LingeredApp tests should be handled differently.
I recommended this fix as one of possibilities and never claimed it's
the best solution ;) I don't know much of LingeredApp tests, so I
just suggested the patch which only solves the problem I noticed
(LingeredApp's cerr being printed into jtreg agent's cerr).
If by "into jtreg agent's cerr" you are referring to the presence of
JDWP "ERROR" messages in the jtreg console, that is fixed simply by
removing the following:
pb.redirectError(ProcessBuilder.Redirect.INHERIT);
And that is already part of this fix. But it actually makes the ERROR
messages completely disappear. The copy() part of the fix makes all
the LingeredApp output appear in the .jtr file (including the JDWP
"ERROR" messages).
OutputAnalyzer might not fit the use case of LingeredApp b/c it
blocks till the process is finished. again, I don't know much about
LingeredApp itself and the tests which use it.
My point was that other jtreg tests that use ProcessBuilder and
OutputAnalyzer don't print out anything from the spawned process/app
until it is done, and even then usually only if there was a test
failure. Why is there a need here to print out messages as they are
generated.
I played around with OutputAnalyzer a bit to see if we can do something
more like are other uses of ProcessBuilder. Unfortunately it did not work:
appProcess = pb.start();
OutputAnalyzer output = new OutputAnalyzer(appProcess);
The problem is that OutputAnalyzer(appProcess) will not return until
appProcess exits, but the test requires interaction with appProcess
before it will exit, and this is done from the same thread. So unless
appProcess aborts unexpectedly, we block in OutputAnalyzer(appProcess).
So next I tried getting the InputGobbler output by calling
LingeredApp.getOutput(). This was missing the stderr output. So I
created a separate gobbler for LingeredApp.getErrorStream(). It only
contained the following:
[Debugger failed to attach: ERROR: Peer not allowed to connect:
127.0.0.1, ]------------
Yet the console (without disabling the
pb.redirectError(ProcessBuilder.Redirect.INHERIT) code) normally would
contain:
[2018-03-14 09:49:38,354] Agent[1]: stderr: Debugger failed to attach:
ERROR: Peer not allowed to connect: 127.0.0.1
[2018-03-14 09:49:38,355] Agent[1]: stderr:
[2018-03-14 09:49:39,075] Agent[1]: stderr: Error in allow option:
'127.0.0.1;192.168.0.0/24'
[2018-03-14 09:49:39,075] Agent[1]: stderr: ERROR: transport error 103:
invalid IP address in allow option
[2018-03-14 09:49:39,075] Agent[1]: stderr: ERROR: JDWP Transport
dt_socket failed to initialize, TRANSPORT_INIT(510)
[2018-03-14 09:49:39,075] Agent[1]: stderr: JDWP exit error
AGENT_ERROR_TRANSPORT_INIT(197): No transports initialized [:732]
[2018-03-14 09:49:40,064] Agent[1]: stderr: ERROR: JDWP option syntax
error:
-agentlib:jdwp=transport=dt_socket,server=y,suspend=n,address=*:50103,allow=
[2018-03-14 09:49:41,289] Agent[1]: stderr: Error in allow option:
'*+allow=127.0.0.1'
[2018-03-14 09:49:41,289] Agent[1]: stderr: ERROR: transport error 103:
allow option '*' cannot be expanded
[2018-03-14 09:49:41,289] Agent[1]: stderr: ERROR: JDWP Transport
dt_socket failed to initialize, TRANSPORT_INIT(510)
[2018-03-14 09:49:41,289] Agent[1]: stderr: JDWP exit error
AGENT_ERROR_TRANSPORT_INIT(197): No transports initialized [:732]
[2018-03-14 09:49:42,418] Agent[1]: stderr: Error in allow option:
'allow=127.0.0.1+*'
[2018-03-14 09:49:42,418] Agent[1]: stderr: ERROR: transport error 103:
invalid IP address in allow option
[2018-03-14 09:49:42,418] Agent[1]: stderr: ERROR: JDWP Transport
dt_socket failed to initialize, TRANSPORT_INIT(510)
[2018-03-14 09:49:42,418] Agent[1]: stderr: JDWP exit error
AGENT_ERROR_TRANSPORT_INIT(197): No transports initialized [:732]
Just to summarize, if I don't disable
pb.redirectError(ProcessBuilder.Redirect.INHERIT), all the above appears
in the console. If I disable it, none of the above is in the console. It
is just lost. If I disable and try to capture it from
LingeredApp.getErrorStream() using an InputGobller, I only get the first
ERROR, and the rest seem to be lost. (note the copy() approach in the
original fix does capture all the ERROR messages).
I looked a bit closer at what InputGobbler does vs Igor's copy()
approach. They are both very similar in that they spawn a separate
thread to read from the InputStream. The difference is the InputGobbler
uses BufferedReader.readline() whereas Igor's copy() directly uses
InputStream.read(). So it seems the InputGobbler buffering is preventing
us from seeing all the stderr output.
So one conclusion is that there probably is not much point in having two
approaches to getting the LingeredApp's output. I think we should just
create an InputGobbler for both stdout and stderr (currently we only
created one for stdout), and then fix the buffering issue with
InputGobbler on stderr. That still leaves the question of whether we
should always dump stdout and stderr. I think that should be left to the
test to decide, and probably only done if there is an error.
Chris
answering to David's question, copy routine handles interleaving of
two streams similarly to printf routine, it does not do that at all.
we are writing to System.out as we read data, the only guarantee we
have is all the bytes we read into buffer will be written together
(which might mean 1 byte at a time), no guarantees about lines. the
behavior is pretty much the same as you expect to get from an
interactive shell w/ both cout and cerr are being printed on the
console.
Not quite. If a single threaded app is sending to both System.out and
System.err (and/or stdout and stderr) and does something to ensure
flushing after each print or each line, then the output should appear
cleanly in the order executed. By having two different threads read
these two streams, order might be changed, and possibly even
interleaved within lines.
cheers,
Chris
Thanks,
-- Igor
thanks,
Chris
Thanks,
David
-----
Tested by running all tests that use LingeredApp.
thanks,
Chris
