Repository: vackosar/gitflow-incremental-builder
Pull request #80 (2019-01-18 22:02:36)

Issue #74: Log via SLF4J (with Logback for tests)
I went for `LoggerFactory` (not `@Inject`), as well as non-`static` & non-`final` members in classes underneath `main` which (IMO) provides the best mixture of all approaches:
Even non-injectable classes can now look up a logger and only those tests that want to check for specific messages have to set up the respective logger (which ist easy with the new `LoggerSpyUtil`).

PS: I fiddled around with Powermock's ability to mock static methods (`LoggerFactory.getLogger(...)`) but that turned out to be too complicated and would have introduced too much complexity.


Patch:
diff --git a/pom.xml b/pom.xml
index 8c38ffc..c4ba57b 100644
--- a/pom.xml
+++ b/pom.xml
@@ -43,6 +43,8 @@
         <!-- Dependency versions -->
         <version.jgit>5.1.3.201810200350-r</version.jgit>
         <version.maven-core>3.3.9</version.maven-core>
+        <version.slf4j>1.7.5</version.slf4j>    <!-- must match the version that is provided by maven -->
+        <version.logback>1.1.3</version.logback>    <!-- the latest that appears to work properly with slf4j 1.7.5 -->
         <version.javax.inject>1</version.javax.inject>
         <version.junit>4.12</version.junit>
         <version.powermock-reflect>1.7.4</version.powermock-reflect>
@@ -82,6 +84,13 @@
             <groupId>org.eclipse.jgit</groupId>
             <artifactId>org.eclipse.jgit</artifactId>
             <version>${version.jgit}</version>
+            <exclusions>
+                <!-- we use a version that matches the one that is provided by maven (and has to be compatible with jgit) -->
+                <exclusion>
+                    <groupId>org.slf4j</groupId>
+                    <artifactId>slf4j-api</artifactId>
+                </exclusion>
+            </exclusions>
         </dependency>
         <dependency>
             <groupId>org.apache.maven</groupId>
@@ -96,6 +105,12 @@
                 </exclusion>
             </exclusions>
         </dependency>
+        <dependency>
+            <groupId>org.slf4j</groupId>
+            <artifactId>slf4j-api</artifactId>
+            <version>${version.slf4j}</version>
+            <scope>provided</scope>
+        </dependency>
         <dependency>
             <groupId>javax.inject</groupId>
             <artifactId>javax.inject</artifactId>
@@ -120,6 +135,12 @@
             <version>${version.mockito-all}</version>
             <scope>test</scope>
         </dependency>
+        <dependency>
+            <groupId>ch.qos.logback</groupId>
+            <artifactId>logback-classic</artifactId>
+            <version>${version.logback}</version>
+            <scope>test</scope>
+        </dependency>
     </dependencies>
     <profiles>
         <profile>
@@ -274,6 +295,7 @@
                         <systemPropertyVariables>
                             <gibIntegrationTestRepo>${gibIntegrationTestRepo}</gibIntegrationTestRepo>
                             <gibIntegrationTestVersion>${project.version}</gibIntegrationTestVersion>
+                            <logback.FILE.name>test-integration</logback.FILE.name>
                         </systemPropertyVariables>
                     </configuration>
                     <dependencies>
diff --git a/src/main/java/com/vackosar/gitflowincrementalbuild/boundary/MavenLifecycleParticipant.java b/src/main/java/com/vackosar/gitflowincrementalbuild/boundary/MavenLifecycleParticipant.java
index 453c564..71fc36e 100644
--- a/src/main/java/com/vackosar/gitflowincrementalbuild/boundary/MavenLifecycleParticipant.java
+++ b/src/main/java/com/vackosar/gitflowincrementalbuild/boundary/MavenLifecycleParticipant.java
@@ -5,7 +5,8 @@ import com.vackosar.gitflowincrementalbuild.entity.SkipExecutionException;
 import org.apache.maven.AbstractMavenLifecycleParticipant;
 import org.apache.maven.MavenExecutionException;
 import org.apache.maven.execution.MavenSession;
-import org.codehaus.plexus.logging.Logger;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 
 import javax.inject.Inject;
 import javax.inject.Named;
@@ -15,7 +16,7 @@ import javax.inject.Singleton;
 @Named("gib")
 public class MavenLifecycleParticipant extends AbstractMavenLifecycleParticipant {
 
-    @Inject private Logger logger;
+    private Logger logger = LoggerFactory.getLogger(MavenLifecycleParticipant.class);
 
     @Inject private UnchangedProjectsRemover unchangedProjectsRemover;
 
@@ -29,7 +30,6 @@ public class MavenLifecycleParticipant extends AbstractMavenLifecycleParticipant
             return;
         }
 
-
         // check prerequisites
         if (session.getProjectDependencyGraph() == null) {
             logger.warn("Execution of gitflow-incremental-builder is not supported in this environment: "
@@ -44,7 +44,7 @@ public class MavenLifecycleParticipant extends AbstractMavenLifecycleParticipant
         } catch (Exception e) {
             boolean isSkipExecException = e instanceof SkipExecutionException;
             if (!configProvider.get().failOnError || isSkipExecException) {
-                logger.info("gitflow-incremental-builder execution skipped: " + (isSkipExecException ? e.getMessage() : e.toString()));
+                logger.info("gitflow-incremental-builder execution skipped: {}", (isSkipExecException ? e.getMessage() : e.toString()));
                 logger.debug("Full exception:", e);
             } else {
                 throw new MavenExecutionException("Exception during gitflow-incremental-builder execution occurred.", e);
diff --git a/src/main/java/com/vackosar/gitflowincrementalbuild/boundary/UnchangedProjectsRemover.java b/src/main/java/com/vackosar/gitflowincrementalbuild/boundary/UnchangedProjectsRemover.java
index b57863c..cf79371 100644
--- a/src/main/java/com/vackosar/gitflowincrementalbuild/boundary/UnchangedProjectsRemover.java
+++ b/src/main/java/com/vackosar/gitflowincrementalbuild/boundary/UnchangedProjectsRemover.java
@@ -3,8 +3,9 @@ package com.vackosar.gitflowincrementalbuild.boundary;
 import com.vackosar.gitflowincrementalbuild.control.ChangedProjects;
 import org.apache.maven.execution.MavenSession;
 import org.apache.maven.project.MavenProject;
-import org.codehaus.plexus.logging.Logger;
 import org.eclipse.jgit.api.errors.GitAPIException;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 
 import javax.inject.Inject;
 import javax.inject.Named;
@@ -22,10 +23,11 @@ class UnchangedProjectsRemover {
 
     private static final String MAVEN_TEST_SKIP = "maven.test.skip";
     private static final String MAVEN_TEST_SKIP_EXEC = "skipTests";
-    static final String TEST_JAR_DETECTED = "Dependency with test-jar goal detected. Will compile test sources.";
+    private static final String TEST_JAR_DETECTED = "Dependency with test-jar goal detected. Will compile test sources.";
     private static final String GOAL_TEST_JAR = "test-jar";
 
-    @Inject private Logger logger;
+    private Logger logger = LoggerFactory.getLogger(UnchangedProjectsRemover.class);
+
     @Inject private ChangedProjects changedProjects;
     @Inject private MavenSession mavenSession;
     @Inject private Configuration.Provider configProvider;
@@ -81,7 +83,7 @@ class UnchangedProjectsRemover {
         final Properties projectProperties = mavenProject.getProperties();
         if (configProvider.get().skipTestsForNotImpactedModules) {
             if (projectDeclaresTestJarGoal(mavenProject)) {
-                logger.debug(mavenProject.getArtifactId() + ": " + TEST_JAR_DETECTED);
+                logger.debug("{}: {}", mavenProject.getArtifactId(), TEST_JAR_DETECTED);
                 projectProperties.setProperty(MAVEN_TEST_SKIP_EXEC, Boolean.TRUE.toString());
             } else {
                 projectProperties.setProperty(MAVEN_TEST_SKIP, Boolean.TRUE.toString());
diff --git a/src/main/java/com/vackosar/gitflowincrementalbuild/control/ChangedProjects.java b/src/main/java/com/vackosar/gitflowincrementalbuild/control/ChangedProjects.java
index 675f799..de8c74b 100644
--- a/src/main/java/com/vackosar/gitflowincrementalbuild/control/ChangedProjects.java
+++ b/src/main/java/com/vackosar/gitflowincrementalbuild/control/ChangedProjects.java
@@ -2,8 +2,9 @@ package com.vackosar.gitflowincrementalbuild.control;
 
 import org.apache.maven.execution.MavenSession;
 import org.apache.maven.project.MavenProject;
-import org.codehaus.plexus.logging.Logger;
 import org.eclipse.jgit.api.errors.GitAPIException;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 
 import javax.inject.Inject;
 import javax.inject.Named;
@@ -19,7 +20,8 @@ import java.util.stream.Collectors;
 @Named("gib.changedProjects")
 public class ChangedProjects {
 
-    @Inject private Logger logger;
+    private Logger logger = LoggerFactory.getLogger(ChangedProjects.class);
+
     @Inject private DifferentFiles differentFiles;
     @Inject private MavenSession mavenSession;
     @Inject private Modules modules;
@@ -38,10 +40,10 @@ public class ChangedProjects {
             path = path.getParent();
         }
         if (path != null) {
-            logger.debug("Changed file: " + diffPath);
+            logger.debug("Changed file: {}", diffPath);
             return map.get(path);
         } else {
-            logger.warn("Changed file outside build project: " + diffPath);
+            logger.warn("Changed file outside build project: {}", diffPath);
             return null;
         }
     }
diff --git a/src/main/java/com/vackosar/gitflowincrementalbuild/control/DifferentFiles.java b/src/main/java/com/vackosar/gitflowincrementalbuild/control/DifferentFiles.java
index 2dea61f..4742b84 100644
--- a/src/main/java/com/vackosar/gitflowincrementalbuild/control/DifferentFiles.java
+++ b/src/main/java/com/vackosar/gitflowincrementalbuild/control/DifferentFiles.java
@@ -4,7 +4,6 @@ import com.vackosar.gitflowincrementalbuild.boundary.Configuration;
 import com.vackosar.gitflowincrementalbuild.entity.SkipExecutionException;
 
 import org.apache.maven.execution.MavenSession;
-import org.codehaus.plexus.logging.Logger;
 import org.eclipse.jgit.api.Git;
 import org.eclipse.jgit.api.Status;
 import org.eclipse.jgit.api.errors.GitAPIException;
@@ -16,6 +15,8 @@ import org.eclipse.jgit.storage.file.FileRepositoryBuilder;
 import org.eclipse.jgit.transport.RefSpec;
 import org.eclipse.jgit.treewalk.TreeWalk;
 import org.eclipse.jgit.treewalk.filter.TreeFilter;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 
 import javax.inject.Inject;
 import javax.inject.Named;
@@ -26,7 +27,6 @@ import java.io.IOException;
 import java.nio.file.Path;
 import java.util.HashSet;
 import java.util.Set;
-import java.util.function.Predicate;
 import java.util.stream.Collectors;
 
 @Singleton
@@ -39,7 +39,8 @@ public class DifferentFiles {
     private static final String REFS_REMOTES = "refs/remotes/";
     private static final String REFS_HEADS = "refs/heads/";
 
-    @Inject private Logger logger;
+    private Logger logger = LoggerFactory.getLogger(DifferentFiles.class);
+
     @Inject private MavenSession mavenSession;
     @Inject private Configuration.Provider configProvider;
 


Test patch:
diff --git a/src/test/java/com/vackosar/gitflowincrementalbuild/BaseRepoTest.java b/src/test/java/com/vackosar/gitflowincrementalbuild/BaseRepoTest.java
index cc14fff..d085309 100644
--- a/src/test/java/com/vackosar/gitflowincrementalbuild/BaseRepoTest.java
+++ b/src/test/java/com/vackosar/gitflowincrementalbuild/BaseRepoTest.java
@@ -11,9 +11,7 @@ import org.junit.Before;
 import org.junit.Rule;
 import org.junit.rules.TemporaryFolder;
 
-import java.io.ByteArrayOutputStream;
 import java.io.File;
-import java.io.PrintStream;
 import java.nio.file.Files;
 import java.nio.file.Path;
 import java.util.Properties;
@@ -29,9 +27,6 @@ public abstract class BaseRepoTest {
     /** {@link LocalRepoMock#getBaseCanonicalBaseFolder()} of {@link #localRepoMock}. */
     protected Path repoPath;
 
-    protected ByteArrayOutputStream consoleOut;
-    private final PrintStream normalOut;
-
     @Rule
     public TemporaryFolder temporaryFolder = new TemporaryFolder();
 
@@ -40,7 +35,6 @@ public abstract class BaseRepoTest {
     }
 
     public BaseRepoTest(boolean useSymLinkedFolder, boolean withRemote) {
-        this.normalOut = System.out;
         this.useSymLinkedFolder = useSymLinkedFolder;
         this.withRemote = withRemote;
     }
@@ -75,26 +69,17 @@ public abstract class BaseRepoTest {
     }
 
     private void init() {
-        resetConsoleOut();
-
         projectProperties.setProperty(Property.uncommited.fullName(), "false");
         projectProperties.setProperty(Property.untracked.fullName(), "false");
         projectProperties.setProperty(Property.referenceBranch.fullName(), "refs/heads/develop");
         projectProperties.setProperty(Property.compareToMergeBase.fullName(), "false");
     }
 
-    private void resetConsoleOut() {
-        consoleOut = new ByteArrayOutputStream();
-        System.setOut(new PrintStream(consoleOut));
-    }
-
     @After
     public void after() throws Exception {
         if (localRepoMock != null) {
             localRepoMock.close();
         }
-        System.setOut(normalOut);
-        normalOut.print(consoleOut.toString());
     }
 
     protected MavenSession getMavenSessionMock() throws Exception {
diff --git a/src/test/java/com/vackosar/gitflowincrementalbuild/LoggerSpyUtil.java b/src/test/java/com/vackosar/gitflowincrementalbuild/LoggerSpyUtil.java
new file mode 100644
index 0000000..5e4a62b
--- /dev/null
+++ b/src/test/java/com/vackosar/gitflowincrementalbuild/LoggerSpyUtil.java
@@ -0,0 +1,16 @@
+package com.vackosar.gitflowincrementalbuild;
+
+import org.mockito.AdditionalAnswers;
+import org.mockito.Mockito;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+
+public class LoggerSpyUtil {
+
+    public static Logger buildSpiedLoggerFor(Class<?> owningClazz) {
+        Logger logger = LoggerFactory.getLogger(owningClazz);
+        // note: cannot directly use Mockito.spy(logger) because logback loggers are final
+        Logger spiedLogger = Mockito.mock(Logger.class, AdditionalAnswers.delegatesTo(logger));
+        return spiedLogger;
+    }
+}
diff --git a/src/test/java/com/vackosar/gitflowincrementalbuild/ProcessUtils.java b/src/test/java/com/vackosar/gitflowincrementalbuild/ProcessUtils.java
index c4eecc2..3061c58 100644
--- a/src/test/java/com/vackosar/gitflowincrementalbuild/ProcessUtils.java
+++ b/src/test/java/com/vackosar/gitflowincrementalbuild/ProcessUtils.java
@@ -7,24 +7,29 @@ import java.util.stream.Stream;
 
 import org.apache.commons.lang3.SystemUtils;
 import org.junit.Assert;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 
 public class ProcessUtils {
 
+    private static final Logger LOGGER = LoggerFactory.getLogger(ProcessUtils.class);
+
     public static String awaitProcess(Process process) throws InterruptedException {
         final String stdOut = convertStreamToString(process.getInputStream());
         final String stdErr = convertStreamToString(process.getErrorStream());
         final int returnCode = process.waitFor();
         if (returnCode > 0) {
-            System.err.println(stdOut);
-            System.err.println(stdErr);
+            LOGGER.info("stdOut:\n{}", stdOut);
+            LOGGER.error("stdErr:\n{}", stdErr);
             Assert.fail("Process failed with return code " + returnCode);
         }
         return stdOut;
     }
 
     public static String convertStreamToString(java.io.InputStream is) {
-        java.util.Scanner s = new java.util.Scanner(is).useDelimiter("\\A");
-        return s.hasNext() ? s.next() : "";
+        try (java.util.Scanner s = new java.util.Scanner(is)) {
+            return s.useDelimiter("\\A").hasNext() ? s.next() : "";
+        }
     }
 
     public static List<String> cmdArgs(String... args) {
diff --git a/src/test/java/com/vackosar/gitflowincrementalbuild/boundary/MavenIntegrationTest.java b/src/test/java/com/vackosar/gitflowincrementalbuild/boundary/MavenIntegrationTest.java
index ceb5da5..90c200e 100644
--- a/src/test/java/com/vackosar/gitflowincrementalbuild/boundary/MavenIntegrationTest.java
+++ b/src/test/java/com/vackosar/gitflowincrementalbuild/boundary/MavenIntegrationTest.java
@@ -11,7 +11,11 @@ import org.eclipse.jgit.api.ResetCommand;
 import org.junit.Assert;
 import org.junit.Before;
 import org.junit.BeforeClass;
+import org.junit.Rule;
 import org.junit.Test;
+import org.junit.rules.TestName;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 
 import java.io.IOException;
 import java.util.Arrays;
@@ -31,6 +35,8 @@ import java.util.stream.Stream;
  */
 public class MavenIntegrationTest extends BaseRepoTest {
 
+    private static final Logger LOGGER = LoggerFactory.getLogger(MavenIntegrationTest.class);
+
     private static final String DEFAULT_POMFILE_ARG = "--file=parent/pom.xml";
 
     private static String localRepoArg;
@@ -38,6 +44,9 @@ public class MavenIntegrationTest extends BaseRepoTest {
     private static String gibVersionArg;
     private static boolean initialInstallDone;
 
+    @Rule
+    public final TestName testNameRule = new TestName();
+
     @BeforeClass
     public static void evaluateSystemProperties() throws IOException, InterruptedException {
         localRepoArg = "-Dmaven.repo.local="
@@ -45,10 +54,9 @@ public class MavenIntegrationTest extends BaseRepoTest {
         gibVersion = Validate.notEmpty(System.getProperty("gibIntegrationTestVersion"), "gibIntegrationTestVersion not set");
         gibVersionArg = "-DgibVersion=" + gibVersion;
 
-        System.out.println(
-                "The first test method will execute an initial 'mvn install ...' on the test project to populate the test repo."
+        LOGGER.info("The first test method will execute an initial 'mvn install ...' on the test project to populate the test repo."
                 + " This might take a while.");
-        System.out.println("Arguments: " + gibVersionArg + ", " + localRepoArg);
+        LOGGER.info("Arguments: {}, {}", gibVersionArg, localRepoArg);
     }
 
     /**
@@ -78,28 +86,24 @@ public class MavenIntegrationTest extends BaseRepoTest {
     @Test
     public void logVersion() throws IOException, InterruptedException {
         final String output = executeBuild("-N");
-        System.out.println(output);
         Assert.assertTrue(output.contains("gitflow-incremental-builder " + gibVersion + " starting..."));
     }
     
     @Test
     public void worktreeFails() throws Exception {
         final String output = executeBuild("--file=wrkf2/parent/pom.xml");
-        System.out.println(output);
         Assert.assertTrue(output.contains(DifferentFiles.UNSUPPORTED_WORKTREE));
     }
 
     @Test
     public void logChanges() throws Exception {
         final String output = executeBuild("-X", "-N");
-        System.out.println(output);
         Assert.assertTrue(output.contains("[DEBUG] Changed file: "));
     }
 
     @Test
     public void buildAllSkipTest() throws Exception {
         final String output = executeBuild(prop(Property.buildAll, "true"), prop(Property.skipTestsForNotImpactedModules, "true"));
-        System.out.println(output);
 
         Assert.assertTrue(output.contains(" child1"));
         Assert.assertTrue(output.contains(" child2"));
@@ -116,7 +120,6 @@ public class MavenIntegrationTest extends BaseRepoTest {
     @Test
     public void buildWithAlsoMake() throws Exception {
         final String output = executeBuild("-am");
-        System.out.println(output);
 
         Assert.assertFalse(output.contains(" child1"));
         Assert.assertFalse(output.contains(" child2"));
@@ -154,7 +157,6 @@ public class MavenIntegrationTest extends BaseRepoTest {
     @Test
     public void buildWithAlsoMakeSkip() throws Exception {
         final String output = executeBuild("-am", prop(Property.skipTestsForNotImpactedModules, "true"));
-        System.out.println(output);
 
         Assert.assertFalse(output.contains(" child1"));
         Assert.assertFalse(output.contains(" child2"));
@@ -172,7 +174,6 @@ public class MavenIntegrationTest extends BaseRepoTest {
     @Test
     public void buildWithoutAlsoMake() throws Exception {
         final String output = executeBuild();
-        System.out.println(output);
 
         Assert.assertFalse(output.contains(" child1"));
         Assert.assertFalse(output.contains(" child2"));
@@ -199,7 +200,9 @@ public class MavenIntegrationTest extends BaseRepoTest {
                 new ProcessBuilder(command)
                         .directory(localRepoMock.getBaseCanonicalBaseFolder())
                         .start();
-        return ProcessUtils.awaitProcess(process);
+        String output = ProcessUtils.awaitProcess(process);
+        LOGGER.info("Output of {}():\n{}", testNameRule.getMethodName(), output);
+        return output;
     }
 
     private static String prop(Property property, String value) {
diff --git a/src/test/java/com/vackosar/gitflowincrementalbuild/boundary/MavenLifecycleParticipantTest.java b/src/test/java/com/vackosar/gitflowincrementalbuild/boundary/MavenLifecycleParticipantTest.java
index fd0c77b..8b61204 100644
--- a/src/test/java/com/vackosar/gitflowincrementalbuild/boundary/MavenLifecycleParticipantTest.java
+++ b/src/test/java/com/vackosar/gitflowincrementalbuild/boundary/MavenLifecycleParticipantTest.java
@@ -1,5 +1,6 @@
 package com.vackosar.gitflowincrementalbuild.boundary;
 
+import com.vackosar.gitflowincrementalbuild.LoggerSpyUtil;
 import com.vackosar.gitflowincrementalbuild.control.Property;
 import com.vackosar.gitflowincrementalbuild.entity.SkipExecutionException;
 
@@ -8,7 +9,6 @@ import org.apache.maven.execution.MavenExecutionRequest;
 import org.apache.maven.execution.MavenSession;
 import org.apache.maven.execution.ProjectDependencyGraph;
 import org.apache.maven.project.MavenProject;
-import org.codehaus.plexus.logging.Logger;
 import org.hamcrest.core.IsSame;
 import org.junit.Before;
 import org.junit.Rule;
@@ -17,8 +17,10 @@ import org.junit.rules.ExpectedException;
 import org.junit.runner.RunWith;
 import org.mockito.InjectMocks;
 import org.mockito.Mock;
+import org.mockito.Mockito;
 import org.mockito.runners.MockitoJUnitRunner;
 import org.powermock.reflect.Whitebox;
+import org.slf4j.Logger;
 
 import java.util.Properties;
 
@@ -38,8 +40,7 @@ public class MavenLifecycleParticipantTest {
     @Rule
     public final ExpectedException thrown = ExpectedException.none();
 
-    @Mock
-    private Logger loggerMock;
+    private Logger loggerSpy = LoggerSpyUtil.buildSpiedLoggerFor(MavenLifecycleParticipant.class);
 
     @Mock
     private MavenSession mavenSessionMock;
@@ -71,7 +72,7 @@ public class MavenLifecycleParticipantTest {
 
         underTest.afterProjectsRead(mavenSessionMock);
 
-        verify(loggerMock).info(contains("disabled"));
+        verify(loggerSpy).info(contains("disabled"));
         verifyZeroInteractions(unchangedProjectsRemoverMock);
         verify(mavenSessionMock, never()).getProjectDependencyGraph();
     }
@@ -81,7 +82,7 @@ public class MavenLifecycleParticipantTest {
 
         underTest.afterProjectsRead(mavenSessionMock);
 
-        verify(loggerMock).info(contains("starting..."));
+        verify(loggerSpy).info(contains("starting..."));
         verify(unchangedProjectsRemoverMock).act();
     }
 
@@ -103,8 +104,8 @@ public class MavenLifecycleParticipantTest {
 
         underTest.afterProjectsRead(mavenSessionMock);
 
-        verify(loggerMock).info(contains(" skipped:"));
-        verify(loggerMock).debug(anyString(), eq(runtimeException));
+        verify(loggerSpy).info(contains(" skipped:"), (Object) Mockito.any());
+        verify(loggerSpy).debug(anyString(), eq(runtimeException));
     }
 
     @Test
@@ -114,8 +115,8 @@ public class MavenLifecycleParticipantTest {
 
         underTest.afterProjectsRead(mavenSessionMock);
 
-        verify(loggerMock).info(contains(" skipped:"));
-        verify(loggerMock).debug(anyString(), eq(skipExecutionException));
+        verify(loggerSpy).info(contains(" skipped:"), (Object) Mockito.any());
+        verify(loggerSpy).debug(anyString(), eq(skipExecutionException));
     }
 
     @Test
@@ -124,7 +125,7 @@ public class MavenLifecycleParticipantTest {
 
         underTest.afterProjectsRead(mavenSessionMock);
 
-        verify(loggerMock).warn(contains("ProjectDependencyGraph"));
+        verify(loggerSpy).warn(contains("ProjectDependencyGraph"));
         verifyZeroInteractions(unchangedProjectsRemoverMock);
     }
 }
diff --git a/src/test/java/com/vackosar/gitflowincrementalbuild/boundary/UnchangedProjectsRemoverTest.java b/src/test/java/com/vackosar/gitflowincrementalbuild/boundary/UnchangedProjectsRemoverTest.java
index fbccc07..2bf64c1 100644
--- a/src/test/java/com/vackosar/gitflowincrementalbuild/boundary/UnchangedProjectsRemoverTest.java
+++ b/src/test/java/com/vackosar/gitflowincrementalbuild/boundary/UnchangedProjectsRemoverTest.java
@@ -23,7 +23,6 @@ import org.apache.maven.execution.MavenExecutionRequest;
 import org.apache.maven.execution.MavenSession;
 import org.apache.maven.execution.ProjectDependencyGraph;
 import org.apache.maven.project.MavenProject;
-import org.codehaus.plexus.logging.Logger;
 import org.eclipse.jgit.api.errors.GitAPIException;
 import org.junit.Before;
 import org.junit.Test;
@@ -61,9 +60,6 @@ public class UnchangedProjectsRemoverTest {
     @Mock
     private ProjectDependencyGraph projectDependencyGraphMock;
 
-    @Mock
-    private Logger loggerMock;
-
     @Mock
     private ChangedProjects changedProjectsMock;
 
diff --git a/src/test/java/com/vackosar/gitflowincrementalbuild/control/BaseChangedProjectsTest.java b/src/test/java/com/vackosar/gitflowincrementalbuild/control/BaseChangedProjectsTest.java
index e3e7570..9531405 100644
--- a/src/test/java/com/vackosar/gitflowincrementalbuild/control/BaseChangedProjectsTest.java
+++ b/src/test/java/com/vackosar/gitflowincrementalbuild/control/BaseChangedProjectsTest.java
@@ -5,13 +5,11 @@ import com.vackosar.gitflowincrementalbuild.boundary.Configuration;
 
 import org.apache.maven.execution.MavenSession;
 import org.apache.maven.project.MavenProject;
-import org.codehaus.plexus.logging.Logger;
 import org.junit.Assert;
 import org.junit.Before;
 import org.junit.Test;
 import org.junit.runner.RunWith;
 import org.mockito.InjectMocks;
-import org.mockito.Mock;
 import org.mockito.Spy;
 import org.mockito.runners.MockitoJUnitRunner;
 import org.powermock.reflect.Whitebox;
@@ -35,9 +33,6 @@ import java.util.stream.Collectors;
 @RunWith(MockitoJUnitRunner.class)
 public abstract class BaseChangedProjectsTest extends BaseRepoTest {
 
-    @Mock
-    private Logger loggerMock;
-
     @Spy
     @InjectMocks    // note: this won't populate mavenSession because the mock for this is created later via getMavenSessionMock()
     protected DifferentFiles differentFilesSpy;
diff --git a/src/test/java/com/vackosar/gitflowincrementalbuild/control/DifferentFilesTest.java b/src/test/java/com/vackosar/gitflowincrementalbuild/control/DifferentFilesTest.java
index c026e49..3748511 100644
--- a/src/test/java/com/vackosar/gitflowincrementalbuild/control/DifferentFilesTest.java
+++ b/src/test/java/com/vackosar/gitflowincrementalbuild/control/DifferentFilesTest.java
@@ -1,5 +1,8 @@
 package com.vackosar.gitflowincrementalbuild.control;
 
+import static org.mockito.Matchers.contains;
+import static org.mockito.Mockito.verify;
+
 import java.io.IOException;
 import java.nio.file.Files;
 import java.nio.file.Path;
@@ -12,29 +15,29 @@ import java.util.Set;
 import java.util.regex.Pattern;
 
 import org.apache.maven.execution.MavenSession;
-import org.codehaus.plexus.logging.Logger;
-import org.codehaus.plexus.logging.console.ConsoleLoggerManager;
 import org.eclipse.jgit.api.Git;
 import org.eclipse.jgit.api.ResetCommand;
 import org.junit.Assert;
 import org.junit.Test;
 import org.powermock.reflect.Whitebox;
+import org.slf4j.Logger;
 
 import com.vackosar.gitflowincrementalbuild.BaseRepoTest;
+import com.vackosar.gitflowincrementalbuild.LoggerSpyUtil;
 import com.vackosar.gitflowincrementalbuild.boundary.Configuration;
 import com.vackosar.gitflowincrementalbuild.entity.SkipExecutionException;
 import com.vackosar.gitflowincrementalbuild.mocks.MavenSessionMock;
 
 public class DifferentFilesTest extends BaseRepoTest {
 
-    private static final Logger CONSOLE_LOGGER = new ConsoleLoggerManager().getLoggerForComponent("Test");
-
     private static final String REFS_HEADS_FEATURE_2 = "refs/heads/feature/2";
     private static final String HEAD = "HEAD";
     private static final String FETCH_FILE = "fetch-file";
     private static final String DEVELOP = "refs/heads/develop";
     private static final String REMOTE_DEVELOP = "refs/remotes/origin/develop";
 
+    private Logger loggerSpy = LoggerSpyUtil.buildSpiedLoggerFor(DifferentFiles.class);
+
     public DifferentFilesTest() {
         super(/* useSymLinkedFolder */ false, /* withRemote */ true);
     }
@@ -104,7 +107,7 @@ public class DifferentFilesTest extends BaseRepoTest {
 
         invokeUnderTest();
 
-        Assert.assertTrue(consoleOut.toString().contains("Checking out base branch refs/heads/feature/2"));
+        verify(loggerSpy).info(contains("Checking out base branch refs/heads/feature/2"));
     }
 
     @Test
@@ -162,7 +165,8 @@ public class DifferentFilesTest extends BaseRepoTest {
         projectProperties.setProperty(Property.compareToMergeBase.fullName(), "true");
 
         Assert.assertTrue(invokeUnderTest().stream().anyMatch(repoPath.resolve("parent/feature2-only-file.txt")::equals));
-        Assert.assertTrue(consoleOut.toString().contains("59dc82fa887d9ca82a0d3d1790c6d767e738e71a"));
+
+        verify(loggerSpy).info(contains("59dc82fa887d9ca82a0d3d1790c6d767e738e71a"));
     }
 
     @Test
@@ -215,7 +219,7 @@ public class DifferentFilesTest extends BaseRepoTest {
         mavenSessionMock.getTopLevelProject().getProperties().putAll(projectProperties);
 
         DifferentFiles underTest = new DifferentFiles();
-        Whitebox.setInternalState(underTest, mavenSessionMock, CONSOLE_LOGGER, new Configuration.Provider(mavenSessionMock));
+        Whitebox.setInternalState(underTest, mavenSessionMock, new Configuration.Provider(mavenSessionMock), loggerSpy);
 
         Set<Path> result = underTest.get();
 
diff --git a/src/test/java/com/vackosar/gitflowincrementalbuild/control/PropertyTest.java b/src/test/java/com/vackosar/gitflowincrementalbuild/control/PropertyTest.java
index 067db41..8726f97 100644
--- a/src/test/java/com/vackosar/gitflowincrementalbuild/control/PropertyTest.java
+++ b/src/test/java/com/vackosar/gitflowincrementalbuild/control/PropertyTest.java
@@ -1,11 +1,15 @@
 package com.vackosar.gitflowincrementalbuild.control;
 
 import org.junit.Test;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 
 public class PropertyTest {
 
+    private static final Logger LOGGER = LoggerFactory.getLogger(PropertyTest.class);
+
     @Test
     public void exemplifyAll() {
-        System.out.println(Property.exemplifyAll());
+        LOGGER.info("exemplifyAll():\n{}", Property.exemplifyAll());
     }
 }
diff --git a/src/test/java/com/vackosar/gitflowincrementalbuild/mocks/MavenSessionMock.java b/src/test/java/com/vackosar/gitflowincrementalbuild/mocks/MavenSessionMock.java
index 8de2744..425cb43 100644
--- a/src/test/java/com/vackosar/gitflowincrementalbuild/mocks/MavenSessionMock.java
+++ b/src/test/java/com/vackosar/gitflowincrementalbuild/mocks/MavenSessionMock.java
@@ -5,6 +5,8 @@ import org.apache.maven.execution.MavenSession;
 import org.apache.maven.execution.ProjectDependencyGraph;
 import org.apache.maven.model.Model;
 import org.apache.maven.project.MavenProject;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 
 import java.io.IOException;
 import java.nio.file.FileVisitResult;
@@ -22,6 +24,8 @@ import static org.mockito.Mockito.when;
 
 public class MavenSessionMock {
 
+    private static final Logger LOGGER = LoggerFactory.getLogger(MavenSessionMock.class);
+
     public static MavenSession get(Path workDir, Properties topLevelProjectProperties) throws Exception {
         PomFinder finder = new PomFinder();
         Files.walkFileTree(workDir, finder);
@@ -74,8 +78,7 @@ public class MavenSessionMock {
 
         @Override
         public FileVisitResult visitFileFailed(Path file, IOException exc) throws IOException {
-            System.err.println("WARNING: Failed to visit " + file);
-            exc.printStackTrace(System.err);
+            LOGGER.warn("Failed to visit " + file, exc);
             return FileVisitResult.CONTINUE;
         }
 
diff --git a/src/test/java/org/slf4j/impl/StaticLoggerBinder.java b/src/test/java/org/slf4j/impl/StaticLoggerBinder.java
deleted file mode 100644
index 1aeac21..0000000
--- a/src/test/java/org/slf4j/impl/StaticLoggerBinder.java
+++ /dev/null
@@ -1,101 +0,0 @@
-package org.slf4j.impl;
-
-import org.codehaus.plexus.logging.console.ConsoleLoggerManager;
-import org.slf4j.ILoggerFactory;
-import org.slf4j.Logger;
-import org.slf4j.Marker;
-import org.slf4j.spi.LoggerFactoryBinder;
-
-import java.util.Arrays;
-
-public class StaticLoggerBinder implements LoggerFactoryBinder {
-
-    private final org.codehaus.plexus.logging.Logger logger;
-
-    private StaticLoggerBinder(org.codehaus.plexus.logging.Logger logger) {
-        this.logger = logger;
-    }
-
-    public static final StaticLoggerBinder getSingleton() {
-        return LazyHolder.INSTANCE;
-    }
-
-    public String getLoggerFactoryClassStr() {return null;}
-
-    public ILoggerFactory getLoggerFactory() {
-        return s -> new Logger() {
-            @Override public String getName() {return logger.getName();}
-
-            @Override public boolean isTraceEnabled() {return false;}
-            @Override public void trace(String s) {}
-            @Override public void trace(String s, Object o) {}
-            @Override public void trace(String s, Object o, Object o1) {}
-            @Override public void trace(String s, Object... objects) {}
-            @Override public void trace(String s, Throwable throwable) {}
-            @Override public boolean isTraceEnabled(Marker marker) {return false;}
-            @Override public void trace(Marker marker, String s) {}
-            @Override public void trace(Marker marker, String s, Object o) {}
-            @Override public void trace(Marker marker, String s, Object o, Object o1) {}
-            @Override public void trace(Marker marker, String s, Object... objects) {}
-            @Override public void trace(Marker marker, String s, Throwable throwable) {}
-
-            @Override public boolean isDebugEnabled() {return false;}
-            @Override public void debug(String s) {logger.debug(s);}
-            @Override public void debug(String s, Object o) {debug(s, new Object[] {o});}
-            @Override public void debug(String s, Object o, Object o1) {debug(s, new Object[] {o, o1});;}
-            @Override public void debug(String s, Object... objects) {logger.debug(s + "-" + Arrays.deepToString(objects));}
-            @Override public void debug(String s, Throwable throwable) {logger.debug(s, throwable);}
-            @Override public boolean isDebugEnabled(Marker marker) {return logger.isDebugEnabled();}
-            @Override public void debug(Marker marker, String s) {logger.debug(s);}
-            @Override public void debug(Marker marker, String s, Object o) {debug(s,o);}
-            @Override public void debug(Marker marker, String s, Object o, Object o1) {debug(s, new Object[]{o, o1});}
-            @Override public void debug(Marker marker, String s, Object... objects) {debug(s, objects);}
-            @Override public void debug(Marker marker, String s, Throwable throwable) {debug(s, throwable);}
-
-            @Override public boolean isInfoEnabled() {return false;}
-            @Override public void info(String s) {logger.info(s);}
-            @Override public void info(String s, Object o) {info(s, new Object[] {o});}
-            @Override public void info(String s, Object o, Object o1) {info(s, new Object[] {o, o1});;}
-            @Override public void info(String s, Object... objects) {logger.info(s + "-" + Arrays.deepToString(objects));}
-            @Override public void info(String s, Throwable throwable) {logger.info(s, throwable);}
-            @Override public boolean isInfoEnabled(Marker marker) {return logger.isInfoEnabled();}
-            @Override public void info(Marker marker, String s) {logger.info(s);}
-            @Override public void info(Marker marker, String s, Object o) {info(s,o);}
-            @Override public void info(Marker marker, String s, Object o, Object o1) {info(s, new Object[]{o, o1});}
-            @Override public void info(Marker marker, String s, Object... objects) {info(s, objects);}
-            @Override public void info(Marker marker, String s, Throwable throwable) {info(s, throwable);}
-
-            @Override public boolean isWarnEnabled() {return false;}
-            @Override public void warn(String s) {logger.warn(s);}
-            @Override public void warn(String s, Object o) {warn(s, new Object[] {o});}
-            @Override public void warn(String s, Object o, Object o1) {warn(s, new Object[] {o, o1});;}
-            @Override public void warn(String s, Object... objects) {logger.warn(s + "-" + Arrays.deepToString(objects));}
-            @Override public void warn(String s, Throwable throwable) {logger.warn(s, throwable);}
-            @Override public boolean isWarnEnabled(Marker marker) {return logger.isWarnEnabled();}
-            @Override public void warn(Marker marker, String s) {logger.warn(s);}
-            @Override public void warn(Marker marker, String s, Object o) {warn(s,o);}
-            @Override public void warn(Marker marker, String s, Object o, Object o1) {warn(s, new Object[]{o, o1});}
-            @Override public void warn(Marker marker, String s, Object... objects) {warn(s, objects);}
-            @Override public void warn(Marker marker, String s, Throwable throwable) {warn(s, throwable);}
-
-            @Override public boolean isErrorEnabled() {return false;}
-            @Override public void error(String s) {logger.error(s);}
-            @Override public void error(String s, Object o) {error(s, new Object[] {o});}
-            @Override public void error(String s, Object o, Object o1) {error(s, new Object[] {o, o1});;}
-            @Override public void error(String s, Object... objects) {logger.error(s + "-" + Arrays.deepToString(objects));}
-            @Override public void error(String s, Throwable throwable) {logger.error(s, throwable);}
-            @Override public boolean isErrorEnabled(Marker marker) {return logger.isErrorEnabled();}
-            @Override public void error(Marker marker, String s) {logger.error(s);}
-            @Override public void error(Marker marker, String s, Object o) {error(s,o);}
-            @Override public void error(Marker marker, String s, Object o, Object o1) {error(s, new Object[]{o, o1});}
-            @Override public void error(Marker marker, String s, Object... objects) {error(s, objects);}
-            @Override public void error(Marker marker, String s, Throwable throwable) {error(s, throwable);}
-        };
-    }
-
-    // https://en.wikipedia.org/wiki/Initialization-on-demand_holder_idiom
-    private static class LazyHolder {
-
-        public static final StaticLoggerBinder INSTANCE = new StaticLoggerBinder(new ConsoleLoggerManager().getLoggerForComponent("Test"));
-    }
-}
diff --git a/src/test/resources/logback-test.xml b/src/test/resources/logback-test.xml
new file mode 100644
index 0000000..3a22e60
--- /dev/null
+++ b/src/test/resources/logback-test.xml
@@ -0,0 +1,26 @@
+<configuration>
+
+    <!-- https://logback.qos.ch/manual/appenders.html#ConsoleAppender -->
+    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
+        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
+            <level>INFO</level>
+        </filter>
+        <encoder>
+            <pattern>%date{"HH:mm:ss,SSS"} %-5level [%logger{0}] %msg%n</pattern>
+        </encoder>
+    </appender>
+
+    <!-- https://logback.qos.ch/manual/appenders.html#FileAppender -->
+    <appender name="FILE" class="ch.qos.logback.core.FileAppender">
+        <file>target/${logback.FILE.name:-test}.log</file>
+        <append>false</append>
+        <encoder>
+            <pattern>%date{"yyyy.MM.dd HH:mm:ss,SSS"} %-5level [%logger] \(%thread\) %msg%n</pattern>
+        </encoder>
+    </appender>
+
+    <root level="DEBUG">
+        <appender-ref ref="CONSOLE" />
+        <appender-ref ref="FILE" />
+    </root>
+</configuration>
\ No newline at end of file