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
diff --git a/sdk/src/test/java/com/google/cloud/dataflow/sdk/options/PipelineOptionsFactoryTest.java b/sdk/src/test/java/com/google/cloud/dataflow/sdk/options/PipelineOptionsFactoryTest.java
index 6ffbc8e..576bdaf 100644
--- a/sdk/src/test/java/com/google/cloud/dataflow/sdk/options/PipelineOptionsFactoryTest.java
+++ b/sdk/src/test/java/com/google/cloud/dataflow/sdk/options/PipelineOptionsFactoryTest.java
@@ -577,8 +577,8 @@
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 @@
@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 @@
@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 @@
@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
diff --git a/sdk/src/test/java/com/google/cloud/dataflow/sdk/runners/BlockingDataflowPipelineRunnerTest.java b/sdk/src/test/java/com/google/cloud/dataflow/sdk/runners/BlockingDataflowPipelineRunnerTest.java
index 069284d..fed862d 100644
--- a/sdk/src/test/java/com/google/cloud/dataflow/sdk/runners/BlockingDataflowPipelineRunnerTest.java
+++ b/sdk/src/test/java/com/google/cloud/dataflow/sdk/runners/BlockingDataflowPipelineRunnerTest.java
@@ -100,7 +100,6 @@
@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 @@
mockWait.signalJobComplete();
assertTrue("run() should return after job completion is mocked.",
jobCompleted.waitTillSet(2000));
+ expectedLogs.verifyInfo("Job finished with status DONE");
}
@Test
diff --git a/sdk/src/test/java/com/google/cloud/dataflow/sdk/testing/ExpectedLogs.java b/sdk/src/test/java/com/google/cloud/dataflow/sdk/testing/ExpectedLogs.java
index 8b1a688..e262e68 100644
--- a/sdk/src/test/java/com/google/cloud/dataflow/sdk/testing/ExpectedLogs.java
+++ b/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,105 +53,143 @@
}
/**
- * 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);
}
/**
- * Expect a logging event at the warn level with the given message.
+ * Verify a logging event at the warn level with the given message.
*
* @param substring The message to match against.
*/
- public void expectWarn(String substring) {
- expect(Level.WARNING, substring);
+ public void verifyWarn(String substring) {
+ verify(Level.WARNING, substring);
}
/**
- * Expect a logging event at the warn level with the given message and throwable.
+ * 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 expectWarn(String substring, Throwable t) {
- expect(Level.WARNING, substring, t);
+ public void verifyWarn(String substring, Throwable t) {
+ verify(Level.WARNING, substring, t);
}
/**
- * Expect a logging event at the error 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 expectError(String substring) {
- expect(Level.SEVERE, substring);
+ public void verifyError(String substring) {
+ verify(Level.SEVERE, substring);
}
/**
- * Expect a logging event at the error 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 expectError(String substring, Throwable t) {
- expect(Level.SEVERE, substring, t);
+ public void verifyError(String substring, Throwable t) {
+ verify(Level.SEVERE, substring, t);
}
- private void expect(final Level level, final String substring) {
- expectations.add(new TypeSafeMatcher<LogRecord>() {
+ /**
+ * Verify there are no logging events with messages containing the given substring.
+ *
+ * @param substring The message to match against.
+ */
+ public void verifyNotLogged(String substring) {
+ verifyNotLogged(matcher(substring));
+ }
+
+ /**
+ * 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 verifyNoError(String substring, Throwable t) {
+ verifyNo(Level.SEVERE, substring, t);
+ }
+
+ private void verify(final Level level, final String substring) {
+ verifyLogged(matcher(level, substring));
+ }
+
+ 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
@@ -159,15 +197,24 @@
return level.equals(item.getLevel())
&& item.getMessage().contains(substring);
}
- });
+ };
}
- private void expect(final Level level, final String substring, final Throwable throwable) {
- expectations.add(new TypeSafeMatcher<LogRecord>() {
+ private void verify(final Level level, final String substring, final Throwable throwable) {
+ verifyLogged(matcher(level, substring, throwable));
+ }
+
+ 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 @@
&& 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 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();
}
/**
diff --git a/sdk/src/test/java/com/google/cloud/dataflow/sdk/testing/ExpectedLogsTest.java b/sdk/src/test/java/com/google/cloud/dataflow/sdk/testing/ExpectedLogsTest.java
index e10d58f..44b0b60 100644
--- a/sdk/src/test/java/com/google/cloud/dataflow/sdk/testing/ExpectedLogsTest.java
+++ b/sdk/src/test/java/com/google/cloud/dataflow/sdk/testing/ExpectedLogsTest.java
@@ -16,7 +16,7 @@
package com.google.cloud.dataflow.sdk.testing;
-import org.junit.Before;
+import org.junit.Rule;
import org.junit.Test;
import org.junit.runner.RunWith;
import org.junit.runners.JUnit4;
@@ -24,6 +24,8 @@
import org.slf4j.LoggerFactory;
import java.io.IOException;
+import java.util.ArrayList;
+import java.util.List;
import java.util.Random;
import java.util.concurrent.Callable;
import java.util.concurrent.CompletionService;
@@ -35,74 +37,89 @@
public class ExpectedLogsTest {
private static final Logger LOG = LoggerFactory.getLogger(ExpectedLogsTest.class);
- private ExpectedLogs expectedLogs;
+ private Random random = new Random();
- @Before
- public void setUp() {
- expectedLogs = ExpectedLogs.none(ExpectedLogsTest.class);
- }
+ @Rule public ExpectedLogs expectedLogs = ExpectedLogs.none(ExpectedLogsTest.class);
@Test
public void testWhenNoExpectations() throws Throwable {
- expectedLogs.before();
LOG.error(generateRandomString());
- expectedLogs.after();
}
@Test
- public void testWhenExpectationIsMatchedFully() throws Throwable {
+ public void testVerifyWhenMatchedFully() throws Throwable {
String expected = generateRandomString();
- expectedLogs.before();
- expectedLogs.expectError(expected);
+
LOG.error(expected);
- expectedLogs.after();
+ expectedLogs.verifyError(expected);
}
@Test
- public void testWhenExpectationIsMatchedPartially() throws Throwable {
+ public void testVerifyWhenMatchedPartially() throws Throwable {
String expected = generateRandomString();
- expectedLogs.before();
- expectedLogs.expectError(expected);
LOG.error("Extra stuff around expected " + expected + " blah");
- expectedLogs.after();
+ expectedLogs.verifyError(expected);
}
@Test
- public void testWhenExpectationIsMatchedWithExceptionBeingLogged() throws Throwable {
+ public void testVerifyWhenMatchedWithExceptionBeingLogged() throws Throwable {
String expected = generateRandomString();
- expectedLogs.before();
- expectedLogs.expectError(expected);
LOG.error(expected, new IOException("Fake Exception"));
- expectedLogs.after();
+ expectedLogs.verifyError(expected);
}
@Test(expected = AssertionError.class)
- public void testWhenExpectationIsNotMatched() throws Throwable {
+ public void testVerifyWhenNotMatched() throws Throwable {
String expected = generateRandomString();
- expectedLogs.before();
- expectedLogs.expectError(expected);
- expectedLogs.after();
+
+ expectedLogs.verifyError(expected);
+ }
+
+ @Test(expected = AssertionError.class)
+ public void testVerifyNotLoggedWhenMatchedFully() throws Throwable {
+ String expected = generateRandomString();
+
+ LOG.error(expected);
+ expectedLogs.verifyNotLogged(expected);
+ }
+
+ @Test(expected = AssertionError.class)
+ public void testVerifyNotLoggedWhenMatchedPartially() throws Throwable {
+ String expected = generateRandomString();
+ LOG.error("Extra stuff around expected " + expected + " blah");
+ expectedLogs.verifyNotLogged(expected);
+ }
+
+ @Test(expected = AssertionError.class)
+ public void testVerifyNotLoggedWhenMatchedWithException() throws Throwable {
+ String expected = generateRandomString();
+ LOG.error(expected, new IOException("Fake Exception"));
+ expectedLogs.verifyNotLogged(expected);
+ }
+
+ @Test
+ public void testVerifyNotLoggedWhenNotMatched() throws Throwable {
+ String expected = generateRandomString();
+ expectedLogs.verifyNotLogged(expected);
}
@Test
public void testLogCaptureOccursAtLowestLogLevel() throws Throwable {
String expected = generateRandomString();
- expectedLogs.before();
- expectedLogs.expectTrace(expected);
LOG.trace(expected);
- expectedLogs.after();
+ expectedLogs.verifyTrace(expected);
}
@Test
public void testThreadSafetyOfLogSaver() throws Throwable {
- expectedLogs.before();
-
CompletionService<Void> completionService =
new ExecutorCompletionService<>(Executors.newCachedThreadPool());
final long scheduledLogTime = System.currentTimeMillis() + 500L;
+
+ List<String> expectedStrings = new ArrayList<>();
for (int i = 0; i < 100; i++) {
final String expected = generateRandomString();
- expectedLogs.expectTrace(expected);
+ expectedStrings.add(expected);
completionService.submit(new Callable<Void>() {
@Override
public Void call() throws Exception {
@@ -119,12 +136,13 @@
completionService.take();
}
- expectedLogs.after();
+ for (String expected : expectedStrings) {
+ expectedLogs.verifyTrace(expected);
+ }
}
// Generates a random fake error message.
- private static String generateRandomString() {
- Random random = new Random();
+ private String generateRandomString() {
return "Fake error message: " + random.nextInt();
}
}
