Change ExpectedLogs to include better stack-traces

Also add support for verifying the absence of a message.

----Release Notes----

[]
-------------
Created by MOE: http://code.google.com/p/moe-java
MOE_MIGRATED_REVID=94922273

Author: bchambers

sdk/src/test/java/com/google/cloud/dataflow/sdk/options/PipelineOptionsFactoryTest.java

@@ -577,8 +577,8 @@ public void testSetASingularAttributeUsingAListIsIgnoredWithoutStrictParsing() {
     String[] args = new String[] {
         "--diskSizeGb=100",
         "--diskSizeGb=200"};
-    expectedLogs.expectWarn("Strict parsing is disabled, ignoring option");
     PipelineOptionsFactory.fromArgs(args).withoutStrictParsing().create();
+    expectedLogs.verifyWarn("Strict parsing is disabled, ignoring option");
   }
 
   @Test
@@ -610,8 +610,8 @@ public void testUsingArgumentWithUnknownPropertyIsNotAllowed() {
   @Test
   public void testUsingArgumentWithUnknownPropertyIsIgnoredWithoutStrictParsing() {
     String[] args = new String[] {"--unknownProperty=value"};
-    expectedLogs.expectWarn("missing a property named 'unknownProperty'");
     PipelineOptionsFactory.fromArgs(args).withoutStrictParsing().create();
+    expectedLogs.verifyWarn("missing a property named 'unknownProperty'");
   }
 
   @Test
@@ -625,8 +625,8 @@ public void testUsingArgumentStartingWithIllegalCharacterIsNotAllowed() {
   @Test
   public void testUsingArgumentStartingWithIllegalCharacterIsIgnoredWithoutStrictParsing() {
     String[] args = new String[] {" --diskSizeGb=100"};
-    expectedLogs.expectWarn("Strict parsing is disabled, ignoring option");
     PipelineOptionsFactory.fromArgs(args).withoutStrictParsing().create();
+    expectedLogs.verifyWarn("Strict parsing is disabled, ignoring option");
   }
 
   @Test
@@ -652,8 +652,8 @@ public void testUsingArgumentWithInvalidNameIsNotAllowed() {
   @Test
   public void testUsingArgumentWithInvalidNameIsIgnoredWithoutStrictParsing() {
     String[] args = new String[] {"--=100"};
-    expectedLogs.expectWarn("Strict parsing is disabled, ignoring option");
     PipelineOptionsFactory.fromArgs(args).withoutStrictParsing().create();
+    expectedLogs.verifyWarn("Strict parsing is disabled, ignoring option");
   }
 
   @Test

sdk/src/test/java/com/google/cloud/dataflow/sdk/runners/BlockingDataflowPipelineRunnerTest.java

@@ -100,7 +100,6 @@ public synchronized boolean waitTillSet(long timeout) throws InterruptedExceptio
 
   @Test
   public void testJobWaitComplete() throws IOException, InterruptedException {
-    expectedLogs.expectInfo("Job finished with status DONE");
 
     DataflowPipelineRunner mockDataflowPipelineRunner = mock(DataflowPipelineRunner.class);
     DataflowPipelineJob mockJob = mock(DataflowPipelineJob.class);
@@ -141,6 +140,7 @@ public void run() {
     mockWait.signalJobComplete();
     assertTrue("run() should return after job completion is mocked.",
         jobCompleted.waitTillSet(2000));
+    expectedLogs.verifyInfo("Job finished with status DONE");
   }
 
   @Test

sdk/src/test/java/com/google/cloud/dataflow/sdk/testing/ExpectedLogs.java

@@ -18,8 +18,6 @@
 
 import static org.junit.Assert.fail;
 
-import com.google.common.collect.Lists;
-
 import org.hamcrest.Description;
 import org.hamcrest.Matcher;
 import org.hamcrest.TypeSafeMatcher;
@@ -28,10 +26,12 @@
 
 import java.util.Collection;
 import java.util.concurrent.ConcurrentLinkedDeque;
+import java.util.logging.Formatter;
 import java.util.logging.Handler;
 import java.util.logging.Level;
 import java.util.logging.LogRecord;
 import java.util.logging.Logger;
+import java.util.logging.SimpleFormatter;
 
 import javax.annotation.concurrent.ThreadSafe;
 
@@ -53,121 +53,168 @@ public static ExpectedLogs none(Class<?> klass) {
   }
 
   /**
-   * Expect a logging event at the trace level with the given message.
+   * Verify a logging event at the trace level with the given message.
    *
    * @param substring The message to match against.
    */
-  public void expectTrace(String substring) {
-    expect(Level.FINEST, substring);
+  public void verifyTrace(String substring) {
+    verify(Level.FINEST, substring);
   }
 
   /**
-   * Expect a logging event at the trace level with the given message and throwable.
+   * Verify a logging event at the trace level with the given message and throwable.
    *
    * @param substring The message to match against.
    * @param t The throwable to match against.
    */
-  public void expectTrace(String substring, Throwable t) {
-    expect(Level.FINEST, substring, t);
+  public void verifyTrace(String substring, Throwable t) {
+    verify(Level.FINEST, substring, t);
   }
 
   /**
-   * Expect a logging event at the debug level with the given message.
+   * Verify a logging event at the debug level with the given message.
    *
    * @param substring The message to match against.
    */
-  public void expectDebug(String substring) {
-    expect(Level.FINE, substring);
+  public void verifyDebug(String substring) {
+    verify(Level.FINE, substring);
   }
 
   /**
-   * Expect a logging event at the debug level with the given message and throwable.
+   * Verify a logging event at the debug level with the given message and throwable.
    *
    * @param message The message to match against.
    * @param t The throwable to match against.
    */
-  public void expectDebug(String message, Throwable t) {
-    expect(Level.FINE, message, t);
+  public void verifyDebug(String message, Throwable t) {
+    verify(Level.FINE, message, t);
   }
 
   /**
-   * Expect a logging event at the info level with the given message.
+   * Verify a logging event at the info level with the given message.
+   *
    * @param substring The message to match against.
    */
-  public void expectInfo(String substring) {
-    expect(Level.INFO, substring);
+  public void verifyInfo(String substring) {
+    verify(Level.INFO, substring);
   }
 
   /**
-   * Expect a logging event at the info level with the given message and throwable.
+   * Verify a logging event at the info level with the given message and throwable.
    *
    * @param message The message to match against.
    * @param t The throwable to match against.
    */
-  public void expectInfo(String message, Throwable t) {
-    expect(Level.INFO, message, t);
+  public void verifyInfo(String message, Throwable t) {
+    verify(Level.INFO, message, t);
+  }
+
+  /**
+   * Verify a logging event at the warn level with the given message.
+   *
+   * @param substring The message to match against.
+   */
+  public void verifyWarn(String substring) {
+    verify(Level.WARNING, substring);
+  }
+
+  /**
+   * Verify a logging event at the warn level with the given message and throwable.
+   *
+   * @param substring The message to match against.
+   * @param t The throwable to match against.
+   */
+  public void verifyWarn(String substring, Throwable t) {
+    verify(Level.WARNING, substring, t);
   }
 
   /**
-   * Expect a logging event at the warn level with the given message.
+   * Verify a logging event at the error level with the given message.
    *
    * @param substring The message to match against.
    */
-  public void expectWarn(String substring) {
-    expect(Level.WARNING, substring);
+  public void verifyError(String substring) {
+    verify(Level.SEVERE, substring);
   }
 
   /**
-   * Expect a logging event at the warn level with the given message and throwable.
+   * Verify a logging event at the error level with the given message and throwable.
    *
    * @param substring The message to match against.
    * @param t The throwable to match against.
    */
-  public void expectWarn(String substring, Throwable t) {
-    expect(Level.WARNING, substring, t);
+  public void verifyError(String substring, Throwable t) {
+    verify(Level.SEVERE, substring, t);
   }
 
   /**
-   * Expect a logging event at the error level with the given message.
+   * Verify there are no logging events with messages containing the given substring.
    *
    * @param substring The message to match against.
    */
-  public void expectError(String substring) {
-    expect(Level.SEVERE, substring);
+  public void verifyNotLogged(String substring) {
+    verifyNotLogged(matcher(substring));
   }
 
   /**
-   * Expect a logging event at the error level with the given message and throwable.
+   * Verify there is no logging event at the error level with the given message and throwable.
    *
    * @param substring The message to match against.
    * @param t The throwable to match against.
    */
-  public void expectError(String substring, Throwable t) {
-    expect(Level.SEVERE, substring, t);
+  public void verifyNoError(String substring, Throwable t) {
+    verifyNo(Level.SEVERE, substring, t);
+  }
+
+  private void verify(final Level level, final String substring) {
+    verifyLogged(matcher(level, substring));
   }
 
-  private void expect(final Level level, final String substring) {
-    expectations.add(new TypeSafeMatcher<LogRecord>() {
+  private TypeSafeMatcher<LogRecord> matcher(final String substring) {
+    return new TypeSafeMatcher<LogRecord>() {
+      @Override
+      public void describeTo(Description description) {
+        description.appendText(String.format("log message containing message [%s]", substring));
+      }
+
+      @Override
+      protected boolean matchesSafely(LogRecord item) {
+        return item.getMessage().contains(substring);
+      }
+    };
+  }
+
+  private TypeSafeMatcher<LogRecord> matcher(final Level level, final String substring) {
+    return new TypeSafeMatcher<LogRecord>() {
       @Override
       public void describeTo(Description description) {
         description.appendText(String.format(
-            "Expected log message of level [%s] containing message [%s]", level, substring));
+            "log message of level [%s] containing message [%s]", level, substring));
       }
 
       @Override
       protected boolean matchesSafely(LogRecord item) {
         return level.equals(item.getLevel())
             && item.getMessage().contains(substring);
       }
-    });
+    };
+  }
+
+  private void verify(final Level level, final String substring, final Throwable throwable) {
+    verifyLogged(matcher(level, substring, throwable));
   }
 
-  private void expect(final Level level, final String substring, final Throwable throwable) {
-    expectations.add(new TypeSafeMatcher<LogRecord>() {
+  private void verifyNo(final Level level, final String substring, final Throwable throwable) {
+    verifyNotLogged(matcher(level, substring, throwable));
+  }
+
+  private TypeSafeMatcher<LogRecord> matcher(
+      final Level level, final String substring, final Throwable throwable) {
+    return new TypeSafeMatcher<LogRecord>() {
       @Override
       public void describeTo(Description description) {
         description.appendText(String.format(
-            "Expected log message of level [%s] containg message [%s] with exception [%s] "
+            "log message of level [%s] containg message [%s] with exception [%s] "
             + "containing message [%s]",
             level, substring, throwable.getClass(), throwable.getMessage()));
       }
@@ -179,7 +226,26 @@ protected boolean matchesSafely(LogRecord item) {
             && item.getThrown().getClass().equals(throwable.getClass())
             && item.getThrown().getMessage().contains(throwable.getMessage());
       }
-    });
+    };
+  }
+
+  private void verifyLogged(Matcher<LogRecord> matcher) {
+    for (LogRecord record : logSaver.getLogs()) {
+      if (matcher.matches(record)) {
+        return;
+      }
+    }
+
+    fail(String.format("Missing match for [%s]", matcher));
+  }
+
+  private void verifyNotLogged(Matcher<LogRecord> matcher) {
+    // Don't use Matchers.everyItem(Matchers.not(matcher)) because it doesn't format the logRecord
+    for (LogRecord record : logSaver.getLogs()) {
+      if (matcher.matches(record)) {
+        fail(String.format("Unexpected match of [%s]: [%s]", matcher, logFormatter.format(record)));
+      }
+    }
   }
 
   @Override
@@ -193,30 +259,16 @@ protected void before() throws Throwable {
   protected void after() {
     log.removeHandler(logSaver);
     log.setLevel(previousLevel);
-    Collection<Matcher<LogRecord>> missingExpecations = Lists.newArrayList();
-    FOUND: for (Matcher<LogRecord> expectation : expectations) {
-      for (LogRecord log : logSaver.getLogs()) {
-        if (expectation.matches(log)) {
-          continue FOUND;
-        }
-      }
-      missingExpecations.add(expectation);
-    }
-
-    if (!missingExpecations.isEmpty()) {
-      fail(String.format("Missed logging expectations: %s", missingExpecations));
-    }
   }
 
   private final Logger log;
   private final LogSaver logSaver;
-  private final Collection<Matcher<LogRecord>> expectations;
+  private final Formatter logFormatter = new SimpleFormatter();
   private Level previousLevel;
 
   private ExpectedLogs(Class<?> klass) {
     log = Logger.getLogger(klass.getName());
     logSaver = new LogSaver();
-    expectations = Lists.newArrayList();
   }
 
   /**