[
https://issues.apache.org/jira/browse/SUREFIRE-1881?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17312051#comment-17312051
]
Alexander Kriegisch edited comment on SUREFIRE-1881 at 3/31/21, 4:51 AM:
-------------------------------------------------------------------------
If you channge the corresponding section to ...
!screenshot-2.png!
then Surefire will terminate, of course, but nothing from the forked process
will be printed. (*Edit:* I know that this change is basically the same as the
one you made, as I just noticed now when opening your [Surefire PR
#343|https://github.com/apache/maven-surefire/pull/343].)
But now it gets interesting: If, just for fun, you do not throw any exceptions
here, ...
!image-2021-03-31-11-22-50-682.png!
then Surefire will log all of the forked VM's output before terminating with an
error. So somehow the log output arrives. Just step-debug throught this section
of {{AbstractSurefireMojo::executeProvider}} after commenting out the {{throw
new IOException()}} line in {{SurefireForkChannel::connectToClient}}. After
stepping over the line containing {{out = forkChannel.bindEventHandler(..)}}
(highlighted in red below), you will see the first batch of class-loading log
output from the forked VM on the console, see the right half of the screenshot
(you might have to scroll horizontally):
!image-2021-03-31-11-38-11-119.png!
You shall see more class-loading logs, triggered by the next lines executed.
So even though {{worker = server.accept().get( 10, TimeUnit.SECONDS )}} times
out because the {{Future}} is empty, a connection is established and a Maven
logger can see the forked VM's output. Having established that, maybe we can
now together find out more.
was (Author: kriegaex):
If you channge the corresponding section to ...
!screenshot-2.png!
then Surefire will terminate, of course, but nothing from the forked process
will be printed.
If, not because it makes sense but just for fun, you do not throw any
exceptions here, ...
!image-2021-03-31-11-22-50-682.png!
then Surefire will log all of the forked VM's output before terminating with an
error. So somehow the log output arrives. Just step-debug throught this section
of {{AbstractSurefireMojo::executeProvider}} after commenting out the {{throw
new IOException()}} line in {{SurefireForkChannel::connectToClient}}. After
stepping over the line containing {{out = forkChannel.bindEventHandler(..)}}
(highlighted in red below), you will see the first batch of class-loading log
output from the forked VM on the console, see the right half of the screenshot
(you might have to scroll horizontally):
!image-2021-03-31-11-38-11-119.png!
You shall see more class-loading logs, triggered by the next lines executed.
So even though {{worker = server.accept().get( 10, TimeUnit.SECONDS )}} times
out because the {{Future}} is empty, a connection is established and a Maven
logger can see the forked VM's output. Having established that, maybe we can
now together find out more.
> Java agent printing to native console makes build block when using
> SurefireForkNodeFactory
> ------------------------------------------------------------------------------------------
>
> Key: SUREFIRE-1881
> URL: https://issues.apache.org/jira/browse/SUREFIRE-1881
> Project: Maven Surefire
> Issue Type: Bug
> Components: Maven Failsafe Plugin, Maven Surefire Plugin
> Affects Versions: 3.0.0-M5
> Reporter: Alexander Kriegisch
> Assignee: Tibor Digana
> Priority: Major
> Attachments: Bildschirmfoto von 2021-03-29 21-50-25.png,
> image-2021-02-08-12-07-34-183.png, image-2021-03-26-09-48-11-398.png,
> image-2021-03-26-09-52-36-881.png, image-2021-03-26-18-00-37-889.png,
> image-2021-03-31-11-22-50-682.png, image-2021-03-31-11-38-11-119.png,
> maven-failsafe-debug-log.txt, screenshot-1.png, screenshot-2.png
>
>
> This is a follow-up to SUREFIRE-1788 which was closed prematurely even though
> there still were open issues which were discussed there initially. Basically
> the situation is as follows:
> * I use Java agents writing to stdOut and stdErr in my tests.
> * I was annoyed that Surefire/Failsafe were writing lots of {{[WARNING]
> Corrupted STDOUT by directly writing to native stream in forked JVM}} lines
> into {{*-jvmRun1.dumpstream}} files. [~tibordigana] then told me to use
> {{<forkNode
> implementation="org.apache.maven.plugin.surefire.extensions.SurefireForkNodeFactory"/>}}
> in my POM in order to fix the issue.
> * I tried this in version 3.0.0-M5, but unfortunately, it makes
> Surefire/Failsafe freeze if a Java agent prints something to stdOut or
> stdErr. This happens both in M5 and in M6-SNAPSHOT after both SUREFIRE-1788
> and SUREFIRE-1809 have been merged in already.
> * My [sample
> project|https://github.com/kriegaex/Maven_Surefire_PrintToConsoleProblems]
> reproduces the issue as soon as you uncomment the option in the POM and run
> {{mvn clean verify}}.
> * The second issue is: *Not* using this option leads to garbled log output
> when a Java agent writes to both stdOut and stdErr before/during tests. See
> comments in class
> [{{Agent.DummyTransformer}}|https://github.com/kriegaex/Maven_Surefire_PrintToConsoleProblems/blob/master/src/main/java/de/scrum_master/dummy/Agent.java]
> for examples for garbled log lines and also comments in
> [pom.xml|https://github.com/kriegaex/Maven_Surefire_PrintToConsoleProblems/blob/master/pom.xml#L36]
> for further information.
> * If the garbled output would also appear with this option activated, cannot
> be tested at present due to the Surefire/Failsafe freeze. I will re-test that
> after the freeze has been fixed and before this issue can be closed.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
