Capture Async logs. Add assertions to assert on result.

jsalinaspolo · Aug 23, 2017 · 79783ba · 79783ba
1 parent 353babf
commit 79783ba
Show file tree

Hide file tree

Showing 8 changed files with 179 additions and 42 deletions.
diff --git a/build.gradle b/build.gradle
@@ -32,6 +32,7 @@ dependencies {
   compile "org.slf4j:slf4j-api:1.7.22"
   compile "ch.qos.logback:logback-classic:1.1.8"
   compile "org.hamcrest:hamcrest-library:1.3"
+  compile "com.jayway.awaitility:awaitility:1.7.0"
 
   testCompile "junit:junit:4.12"
   testCompile "org.assertj:assertj-core:3.6.1"

diff --git a/src/main/java/com/logcapture/Await.java b/src/main/java/com/logcapture/Await.java
@@ -0,0 +1,11 @@
+package com.logcapture;
+
+import com.logcapture.assertion.ExpectedLoggingMessage;
+
+import java.time.Duration;
+
+@FunctionalInterface
+public interface Await<T> {
+
+  LogCapture<T> waitAtMost(Duration duration, ExpectedLoggingMessage condition);
+}
diff --git a/src/main/java/com/logcapture/CaptureLogs.java b/src/main/java/com/logcapture/CaptureLogs.java
@@ -2,26 +2,87 @@
 
 import ch.qos.logback.classic.Logger;
 import ch.qos.logback.classic.spi.ILoggingEvent;
+import com.logcapture.assertion.ExpectedLoggingMessage;
 import com.logcapture.infrastructure.logback.StubAppender;
 import org.slf4j.LoggerFactory;
 
+import java.time.Duration;
 import java.util.List;
+import java.util.concurrent.Callable;
+import java.util.function.Supplier;
 
+import static com.jayway.awaitility.Awaitility.await;
+import static java.util.concurrent.TimeUnit.SECONDS;
 import static org.slf4j.Logger.ROOT_LOGGER_NAME;
 
 public class CaptureLogs {
 
-  public static List<ILoggingEvent> captureLogEvents(Runnable codeBlock) {
+  public static LogCapture<Void> captureLogEvents(Runnable codeBlock) {
     StubAppender logAppender = new StubAppender();
     Logger root = (Logger) LoggerFactory.getLogger(ROOT_LOGGER_NAME);
 
     root.addAppender(logAppender);
     try {
       codeBlock.run();
+      return new LogCapture<>(logAppender.events(), null);
     } finally {
       root.detachAppender(logAppender);
     }
+  }
+
+  public static <T> LogCapture<T> captureLogEvents(Supplier<T> codeBlock) {
+    StubAppender logAppender = new StubAppender();
+    Logger root = (Logger) LoggerFactory.getLogger(ROOT_LOGGER_NAME);
+
+    root.addAppender(logAppender);
+    try {
+      T result = codeBlock.get();
+      return new LogCapture<>(logAppender.events(), result);
+    } finally {
+      root.detachAppender(logAppender);
+    }
+  }
+
+  public static <T> LogCapture<T> captureLogEventsAsync(Runnable codeBlock, Duration duration, ExpectedLoggingMessage expectedLoggingMessage) {
+    StubAppender logAppender = new StubAppender();
+    Logger root = (Logger) LoggerFactory.getLogger(ROOT_LOGGER_NAME);
+
+    root.addAppender(logAppender);
+    try {
+      codeBlock.run();
+      awaitForLogMessage(duration, hasLoggedMessage(logAppender.events(), expectedLoggingMessage));
+      return new LogCapture<>(logAppender.events(), null);
+    } finally {
+      root.detachAppender(logAppender);
+    }
+  }
+
+  public static <T> LogCapture<T> captureLogEventsAsync(Supplier<T> codeBlock, Duration duration, ExpectedLoggingMessage expectedLoggingMessage) {
+    StubAppender logAppender = new StubAppender();
+    Logger root = (Logger) LoggerFactory.getLogger(ROOT_LOGGER_NAME);
+
+    root.addAppender(logAppender);
+    try {
+      T result = codeBlock.get();
+      awaitForLogMessage(duration, hasLoggedMessage(logAppender.events(), expectedLoggingMessage));
+      return new LogCapture<>(logAppender.events(), result);
+    } finally {
+      root.detachAppender(logAppender);
+    }
+  }
+
+  private static Callable<Boolean> hasLoggedMessage(List<ILoggingEvent> events, ExpectedLoggingMessage expectedLoggingMessage) {
+    return () -> {
+      try {
+        new LogCapture<>(events, null).logged(expectedLoggingMessage);
+        return true;
+      } catch (Exception e) {
+        return false;
+      }
+    };
+  }
 
-    return logAppender.events();
+  private static void awaitForLogMessage(Duration duration, Callable<Boolean> condition) {
+    await().atMost(duration.getSeconds(), SECONDS).until(condition);
   }
 }
diff --git a/src/main/java/com/logcapture/LogCapture.java b/src/main/java/com/logcapture/LogCapture.java
@@ -4,16 +4,20 @@
 import com.logcapture.assertion.ExpectedLoggingMessage;
 
 import java.util.List;
+import java.util.function.Consumer;
+import java.util.function.Supplier;
 
-public class LogCapture {
+public class LogCapture<T> {
 
   private final List<ILoggingEvent> events;
+  private final T result;
 
-  private LogCapture(List<ILoggingEvent> events) {
+  public LogCapture(List<ILoggingEvent> events, T result) {
     this.events = events;
+    this.result = result;
   }
 
-  public LogCapture containMessage(ExpectedLoggingMessage expectedLoggingMessage) {
+  public LogCapture<T> logged(ExpectedLoggingMessage expectedLoggingMessage) {
     for (ILoggingEvent event : events) {
       if (expectedLoggingMessage.matches(event)) {
         return this;
@@ -23,7 +27,23 @@ public LogCapture containMessage(ExpectedLoggingMessage expectedLoggingMessage)
     throw new RuntimeException("No Log Found for [" + expectedLoggingMessage + "]");
   }
 
-  public static LogCapture captureLogEvents(Runnable codeBlock) {
-    return new LogCapture(CaptureLogs.captureLogEvents(codeBlock));
+  public LogCapture<T> assertions(Consumer<T> assertions) {
+    assertions.accept(result);
+    return this;
+  }
+
+  public static LogCapture<Void> captureLogEvents(Runnable codeBlock) {
+    return CaptureLogs.captureLogEvents(codeBlock);
+  }
+
+  public static <T> LogCapture<T> captureLogEvents(Supplier<T> codeBlock) {
+    return CaptureLogs.captureLogEvents(codeBlock);
+  }
+
+  public static Await<Void> captureLogEventsAsync(Runnable codeBlock) {
+    return (duration, condition) -> CaptureLogs.captureLogEventsAsync(codeBlock, duration, condition);
+  }
+  public static <T> Await<T> captureLogEventsAsync(Supplier<T> codeBlock) {
+    return (duration, condition) -> CaptureLogs.captureLogEventsAsync(codeBlock, duration, condition);
   }
 }
diff --git a/src/main/java/com/logcapture/assertion/ExpectedLoggingMessage.java b/src/main/java/com/logcapture/assertion/ExpectedLoggingMessage.java
@@ -23,7 +23,7 @@ public class ExpectedLoggingMessage {
   private ExpectedLoggingMessage() {
   }
 
-  public static ExpectedLoggingMessage logMessage() {
+  public static ExpectedLoggingMessage aMessage() {
     return new ExpectedLoggingMessage();
   }
 

diff --git a/src/test/java/com/logcapture/CaptureLogsShould.java b/src/test/java/com/logcapture/CaptureLogsShould.java
@@ -1,35 +1,19 @@
 package com.logcapture;
 
-import ch.qos.logback.classic.spi.ILoggingEvent;
 import org.junit.Test;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
-import org.slf4j.event.Level;
-
-import java.util.List;
 
 import static com.logcapture.CaptureLogs.captureLogEvents;
 import static com.logcapture.infrastructure.logback.StubAppender.STUB_APPENDER_NAME;
 import static org.assertj.core.api.Assertions.assertThat;
 import static org.assertj.core.api.Assertions.assertThatThrownBy;
 import static org.slf4j.Logger.ROOT_LOGGER_NAME;
-import static org.slf4j.event.Level.INFO;
 
 public class CaptureLogsShould {
 
   private final Logger log = LoggerFactory.getLogger(this.getClass());
 
-  @Test
-  public void capture_events() {
-    List<ILoggingEvent> logEvents = captureLogEvents(() -> log.info("a message"));
-
-    boolean anyMatch = logEvents.stream().anyMatch(e ->
-      Level.valueOf(e.getLevel().levelStr) == INFO && e.getMessage().equals("a message"));
-
-    assertThat(logEvents).hasSize(1);
-    assertThat(anyMatch).isTrue();
-  }
-
   @Test
   public void detach_appender_when_events_are_captured() {
     captureLogEvents(() -> log.info("a message"));

diff --git a/src/test/java/com/logcapture/LogCaptureShould.java b/src/test/java/com/logcapture/LogCaptureShould.java
@@ -1,13 +1,18 @@
 package com.logcapture;
 
-import org.assertj.core.api.Assertions;
 import org.junit.Test;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 
+import java.util.concurrent.CompletableFuture;
+
 import static ch.qos.logback.classic.Level.INFO;
 import static com.logcapture.LogCapture.captureLogEvents;
-import static com.logcapture.assertion.ExpectedLoggingMessage.logMessage;
+import static com.logcapture.LogCapture.captureLogEventsAsync;
+import static com.logcapture.assertion.ExpectedLoggingMessage.aMessage;
+import static java.time.Duration.ofSeconds;
+import static org.assertj.core.api.Assertions.assertThat;
+import static org.assertj.core.api.Assertions.assertThatThrownBy;
 import static org.hamcrest.Matchers.equalTo;
 
 public class LogCaptureShould {
@@ -16,15 +21,69 @@ public class LogCaptureShould {
   @Test
   public void verify_captured_events() {
     captureLogEvents(() -> log.info("a message"))
-      .containMessage(logMessage()
+      .logged(aMessage()
+        .withLevel(equalTo(INFO))
+        .withMessage(equalTo("a message")));
+  }
+
+  @Test
+  public void verify_captured_events_without_result_assertion_null() {
+    captureLogEvents(() -> log.info("a message"))
+      .logged(aMessage()
+        .withLevel(equalTo(INFO))
+        .withMessage(equalTo("a message")))
+    .assertions(result -> assertThat(result).isNull());
+  }
+
+  @Test
+  public void verify_captured_events_having_assertions_as_result() {
+    captureLogEvents(() -> {
+      log.info("a message");
+      return "aResult";
+    })
+      .assertions((result) -> assertThat(result).isEqualTo("aResult"))
+      .logged(aMessage()
         .withLevel(equalTo(INFO))
         .withMessage(equalTo("a message")));
   }
 
+  @Test
+  public void verify_captured_events_without_assertions() {
+    captureLogEvents(() -> {
+      log.info("a message");
+      return "aResult";
+    })
+      .logged(aMessage()
+        .withLevel(equalTo(INFO))
+        .withMessage(equalTo("a message")))
+      .assertions((result) -> assertThat(result).isEqualTo("aResult"));
+  }
+
+  @Test
+  public void verify_captured_async_logs_of_runnable() {
+    captureLogEventsAsync(() -> new Thread(() -> log.info("a message")).start())
+      .waitAtMost(ofSeconds(1), aMessage()
+        .withLevel(equalTo(INFO))
+        .withMessage(equalTo("a message")))
+    .assertions(result -> assertThat(result).isNull());
+  }
+
+  @Test
+  public void verify_captured_events_async_with_assertions() {
+    captureLogEventsAsync(() -> CompletableFuture.supplyAsync(() -> {
+      log.info("a message");
+      return "aResult";
+    }))
+      .waitAtMost(ofSeconds(1), aMessage()
+        .withLevel(equalTo(INFO))
+        .withMessage(equalTo("a message")))
+      .assertions(result -> assertThat(result).isCompletedWithValue("aResult"));
+  }
+
   @Test
   public void fail_when_verify_captured_events_not_found() {
-    Assertions.assertThatThrownBy(() ->     captureLogEvents(() -> log.info("a message"))
-      .containMessage(logMessage()
+    assertThatThrownBy(() -> captureLogEvents(() -> log.info("a message"))
+      .logged(aMessage()
         .withLevel(equalTo(INFO))
         .withMessage(equalTo("a different message"))))
       .isInstanceOf(RuntimeException.class)