Uploaded image for project: 'Maven Surefire'
  1. Maven Surefire
  2. SUREFIRE-1268

With JUnit listener, redirectTestOutputToFile is ignored

    Details

      Description

      When specifying, according to this doc, a JUnit listener, the test output is sent to STDOUT, even though redirectTestOutputToFile is set to true.

      This happens with log4j2 configuration for SYSTEM_OUT, regular System.out.println works fine.

      With no properties element, redirectTestOutputToFile is honored.

        Activity

        Hide
        ilgrosso Francesco Chicchiriccò added a comment -

        Thank you very much!

        Show
        ilgrosso Francesco Chicchiriccò added a comment - Thank you very much!
        Hide
        hudson Hudson added a comment -

        SUCCESS: Integrated in Jenkins build maven-surefire #1605 (See https://builds.apache.org/job/maven-surefire/1605/)
        SUREFIRE-1268 With JUnit listener, redirectTestOutputToFile is ignored (tibor17: rev 658230b69241fc87588e9b007391f9ae4a2b416a)

        • (edit) surefire-providers/surefire-junit47/src/main/java/org/apache/maven/surefire/junitcore/JUnitCoreProvider.java
        • (edit) surefire-providers/surefire-junit4/src/main/java/org/apache/maven/surefire/junit4/JUnit4Provider.java
        Show
        hudson Hudson added a comment - SUCCESS: Integrated in Jenkins build maven-surefire #1605 (See https://builds.apache.org/job/maven-surefire/1605/ ) SUREFIRE-1268 With JUnit listener, redirectTestOutputToFile is ignored (tibor17: rev 658230b69241fc87588e9b007391f9ae4a2b416a) (edit) surefire-providers/surefire-junit47/src/main/java/org/apache/maven/surefire/junitcore/JUnitCoreProvider.java (edit) surefire-providers/surefire-junit4/src/main/java/org/apache/maven/surefire/junit4/JUnit4Provider.java
        Hide
        tibor17 Tibor Digana added a comment -

        commit 658230b69241fc87588e9b007391f9ae4a2b416a

        Show
        tibor17 Tibor Digana added a comment - commit 658230b69241fc87588e9b007391f9ae4a2b416a
        Hide
        tibor17 Tibor Digana added a comment -

        I see now. The problem is that the listeners are instantiated first in Surefire and the stream System.out gets replaced after that. Most probably LOG4J handles the original System.out when the static class context was called.
        I should reorder listener and call of setOut() in providers.

        Show
        tibor17 Tibor Digana added a comment - I see now. The problem is that the listeners are instantiated first in Surefire and the stream System.out gets replaced after that. Most probably LOG4J handles the original System.out when the static class context was called. I should reorder listener and call of setOut() in providers.
        Hide
        tibor17 Tibor Digana added a comment -

        ... and this configuration with RollingRandomAccessFile has the same symptoms of the bug?
        Please tell me the artifact name including version of log4jXXX you use and I will ask
        Gary Gregory if the Log4J calls System.setOut() without wrapping the stream origin.

        Show
        tibor17 Tibor Digana added a comment - ... and this configuration with RollingRandomAccessFile has the same symptoms of the bug? Please tell me the artifact name including version of log4jXXX you use and I will ask Gary Gregory if the Log4J calls System.setOut() without wrapping the stream origin.
        Hide
        ilgrosso Francesco Chicchiriccò added a comment - - edited

        I have created https://github.com/ilgrosso/surefire1268

        When you run mvn clean test, you will get an output like as

        Running net.tirasa.test.surefire1268.BaseTest
        Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.02 sec - in net.tirasa.test.surefire1268.BaseTest
        11:39:56.407 INFO  net.tirasa.test.surefire1268.BaseTest - ********* You should not be viewing this from console
        
        Results :
        
        Tests run: 1, Failures: 0, Errors: 0, Skipped: 0
        

        The line

        11:39:56.407 INFO  net.tirasa.test.surefire1268.BaseTest - ********* You should not be viewing this from console
        

        is supposed to be included in target/surefire-reports/net.tirasa.test.surefire1268.BaseTest-output.txt, but such file is not created.

        When commenting out

                  <properties>
                    <property>
                      <name>listener</name>
                      <value>net.tirasa.test.surefire1268.NotDoingSoMuchListener</value>
                    </property>
                  </properties>
        

        in the pom.xml, everything works as expected.

        Moreover, I have noticed that everything works also if not commenting the listener property in the pom.xml but removing this line

        private static final Logger LOG = LoggerFactory.getLogger(NotDoingSoMuchListener.class);
        

        in the listener class.

        Show
        ilgrosso Francesco Chicchiriccò added a comment - - edited I have created https://github.com/ilgrosso/surefire1268 When you run mvn clean test , you will get an output like as Running net.tirasa.test.surefire1268.BaseTest Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.02 sec - in net.tirasa.test.surefire1268.BaseTest 11:39:56.407 INFO net.tirasa.test.surefire1268.BaseTest - ********* You should not be viewing this from console Results : Tests run: 1, Failures: 0, Errors: 0, Skipped: 0 The line 11:39:56.407 INFO net.tirasa.test.surefire1268.BaseTest - ********* You should not be viewing this from console is supposed to be included in target/surefire-reports/net.tirasa.test.surefire1268.BaseTest-output.txt , but such file is not created. When commenting out <properties> <property> <name>listener</name> <value>net.tirasa.test.surefire1268.NotDoingSoMuchListener</value> </property> </properties> in the pom.xml , everything works as expected. Moreover, I have noticed that everything works also if not commenting the listener property in the pom.xml but removing this line private static final Logger LOG = LoggerFactory.getLogger(NotDoingSoMuchListener.class); in the listener class.
        Hide
        ilgrosso Francesco Chicchiriccò added a comment -

        It could even be (not sure): but why this should happen only when adding a listener? Without it, everything works as expected.

        Show
        ilgrosso Francesco Chicchiriccò added a comment - It could even be (not sure): but why this should happen only when adding a listener? Without it, everything works as expected.
        Hide
        tibor17 Tibor Digana added a comment -

        It looks to me that log4j calls System.setOut() and completely violates our stream which means the corrupted stream appears directly on the console of main process. Could this happen?

        Show
        tibor17 Tibor Digana added a comment - It looks to me that log4j calls System.setOut() and completely violates our stream which means the corrupted stream appears directly on the console of main process. Could this happen?
        Hide
        tibor17 Tibor Digana added a comment -

        Francesco Chicchiriccò
        Pls create plain github project that I can try out.

        Show
        tibor17 Tibor Digana added a comment - Francesco Chicchiriccò Pls create plain github project that I can try out.
        Hide
        ilgrosso Francesco Chicchiriccò added a comment - - edited

        Also noticed that target/surefire-reports/null-output.txt is created.

        I have currently switched, in log4j2.xml, from

            <console name="main" target="SYSTEM_OUT">
              <PatternLayout>
                <pattern>%d{HH:mm:ss.SSS} %-5level %logger - %msg%n</pattern>
              </PatternLayout>
            </console>
        

        to

            <RollingRandomAccessFile name="main" fileName="${log.directory}/offline-tests.log"
                                     filePattern="${log.directory}/core-%d{yyyy-MM-dd}.log.gz"
                                     immediateFlush="false" append="true">
              <PatternLayout>
                <pattern>%d{HH:mm:ss.SSS} %-5level %logger - %msg%n</pattern>
              </PatternLayout>
              <Policies>
                <TimeBasedTriggeringPolicy/>
                <SizeBasedTriggeringPolicy size="250 MB"/>
              </Policies>
            </RollingRandomAccessFile>
        

        to keep my console output clean.

        Show
        ilgrosso Francesco Chicchiriccò added a comment - - edited Also noticed that target/surefire-reports/null-output.txt is created. I have currently switched, in log4j2.xml , from <console name= "main" target= "SYSTEM_OUT" > <PatternLayout> <pattern>%d{HH:mm:ss.SSS} %-5level %logger - %msg%n</pattern> </PatternLayout> </console> to <RollingRandomAccessFile name= "main" fileName= "${log.directory}/offline-tests.log" filePattern= "${log.directory}/core-%d{yyyy-MM-dd}.log.gz" immediateFlush= " false " append= " true " > <PatternLayout> <pattern>%d{HH:mm:ss.SSS} %-5level %logger - %msg%n</pattern> </PatternLayout> <Policies> <TimeBasedTriggeringPolicy/> <SizeBasedTriggeringPolicy size= "250 MB" /> </Policies> </RollingRandomAccessFile> to keep my console output clean.

          People

          • Assignee:
            tibor17 Tibor Digana
            Reporter:
            ilgrosso Francesco Chicchiriccò
          • Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development