You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@lucene.apache.org by dw...@apache.org on 2018/12/18 21:04:19 UTC

lucene-solr:master: LUCENE-8604: TestRuleLimitSysouts now has an optional "hard limit" of bytes that can be written to stderr and stdout (anything beyond the hard limit is ignored). The default hard limit is 2 GB of logs per test class.

Repository: lucene-solr
Updated Branches:
  refs/heads/master 73299f0f2 -> f28c5bec9


LUCENE-8604: TestRuleLimitSysouts now has an optional "hard limit" of bytes that can be written to stderr and stdout (anything beyond the hard limit is ignored). The default hard limit is 2 GB of logs per test class.


Project: http://git-wip-us.apache.org/repos/asf/lucene-solr/repo
Commit: http://git-wip-us.apache.org/repos/asf/lucene-solr/commit/f28c5bec
Tree: http://git-wip-us.apache.org/repos/asf/lucene-solr/tree/f28c5bec
Diff: http://git-wip-us.apache.org/repos/asf/lucene-solr/diff/f28c5bec

Branch: refs/heads/master
Commit: f28c5bec9bbd06a1f70f0ddbc2d71e12a1961f65
Parents: 73299f0
Author: Dawid Weiss <da...@carrotsearch.com>
Authored: Tue Dec 18 22:03:44 2018 +0100
Committer: Dawid Weiss <da...@carrotsearch.com>
Committed: Tue Dec 18 22:03:44 2018 +0100

----------------------------------------------------------------------
 lucene/CHANGES.txt                              |   6 +
 .../org/apache/lucene/util/LuceneTestCase.java  |   4 +-
 .../lucene/util/TestRuleLimitSysouts.java       | 191 +++++++++++++------
 .../apache/lucene/util/TestSysoutsLimits.java   | 105 ++++++++++
 4 files changed, 246 insertions(+), 60 deletions(-)
----------------------------------------------------------------------


http://git-wip-us.apache.org/repos/asf/lucene-solr/blob/f28c5bec/lucene/CHANGES.txt
----------------------------------------------------------------------
diff --git a/lucene/CHANGES.txt b/lucene/CHANGES.txt
index bbb550b..069bb72 100644
--- a/lucene/CHANGES.txt
+++ b/lucene/CHANGES.txt
@@ -290,6 +290,12 @@ Optimizations
   rather than an in-place mergesort, which needs to perform fewer swaps.
   (Adrien Grand)
 
+Test Framework
+
+* LUCENE-8604: TestRuleLimitSysouts now has an optional "hard limit" of bytes that can be written
+  to stderr and stdout (anything beyond the hard limit is ignored). The default hard limit is 2 GB of 
+  logs per test class. (Dawid Weiss)
+
 Other
 
 * LUCENE-8573: BKDWriter now uses FutureArrays#mismatch to compute shared prefixes.

http://git-wip-us.apache.org/repos/asf/lucene-solr/blob/f28c5bec/lucene/test-framework/src/java/org/apache/lucene/util/LuceneTestCase.java
----------------------------------------------------------------------
diff --git a/lucene/test-framework/src/java/org/apache/lucene/util/LuceneTestCase.java b/lucene/test-framework/src/java/org/apache/lucene/util/LuceneTestCase.java
index 948b2e0..2ffb1bf 100644
--- a/lucene/test-framework/src/java/org/apache/lucene/util/LuceneTestCase.java
+++ b/lucene/test-framework/src/java/org/apache/lucene/util/LuceneTestCase.java
@@ -212,7 +212,9 @@ import static org.apache.lucene.search.DocIdSetIterator.NO_MORE_DOCS;
 @ThreadLeakFilters(defaultFilters = true, filters = {
     QuickPatchThreadsFilter.class
 })
-@TestRuleLimitSysouts.Limit(bytes = TestRuleLimitSysouts.DEFAULT_SYSOUT_BYTES_THRESHOLD)
+@TestRuleLimitSysouts.Limit(
+    bytes = TestRuleLimitSysouts.DEFAULT_LIMIT,
+    hardLimit = TestRuleLimitSysouts.DEFAULT_HARD_LIMIT)
 public abstract class LuceneTestCase extends Assert {
 
   // --------------------------------------------------------------------

http://git-wip-us.apache.org/repos/asf/lucene-solr/blob/f28c5bec/lucene/test-framework/src/java/org/apache/lucene/util/TestRuleLimitSysouts.java
----------------------------------------------------------------------
diff --git a/lucene/test-framework/src/java/org/apache/lucene/util/TestRuleLimitSysouts.java b/lucene/test-framework/src/java/org/apache/lucene/util/TestRuleLimitSysouts.java
index fe1a172..029f317 100644
--- a/lucene/test-framework/src/java/org/apache/lucene/util/TestRuleLimitSysouts.java
+++ b/lucene/test-framework/src/java/org/apache/lucene/util/TestRuleLimitSysouts.java
@@ -16,10 +16,10 @@
  */
 package org.apache.lucene.util;
 
-import java.io.FilterOutputStream;
 import java.io.IOException;
 import java.io.OutputStream;
 import java.io.PrintStream;
+import java.io.UncheckedIOException;
 import java.io.UnsupportedEncodingException;
 import java.lang.annotation.Documented;
 import java.lang.annotation.ElementType;
@@ -31,25 +31,46 @@ import java.nio.charset.Charset;
 import java.util.List;
 import java.util.Locale;
 import java.util.concurrent.atomic.AtomicInteger;
-
-import org.apache.lucene.util.LuceneTestCase.Monster;
-import org.apache.lucene.util.LuceneTestCase.SuppressSysoutChecks;
+import java.util.concurrent.atomic.AtomicLong;
 
 import com.carrotsearch.randomizedtesting.RandomizedTest;
 import com.carrotsearch.randomizedtesting.rules.TestRuleAdapter;
+import org.apache.lucene.util.LuceneTestCase.Monster;
+import org.apache.lucene.util.LuceneTestCase.SuppressSysoutChecks;
 
 
 /**
- * Fails the suite if it prints over the given limit of bytes to either
- * {@link System#out} or {@link System#err},
- * unless the condition is not enforced (see {@link #isEnforced()}).
+ * This test rule serves two purposes:
+ *  <ul>
+ *    <li>it fails the test if it prints too much to stdout and stderr (tests that chatter too much
+ *    are discouraged)</li>
+ *    <li>the rule ensures an absolute hard limit of stuff written to stdout and stderr to prevent
+ *    accidental infinite loops from filling all available disk space with persisted output.</li>
+ *  </ul>
+ *
+ * The rule is not enforced for certain test types (see {@link #isEnforced()}).
  */
 public class TestRuleLimitSysouts extends TestRuleAdapter {
+  private static final long KB = 1024;
+  private static final long MB = KB * 1024;
+  private static final long GB = MB * 1024;
+
   /**
    * Max limit of bytes printed to either {@link System#out} or {@link System#err}. 
    * This limit is enforced per-class (suite).
    */
-  public final static int DEFAULT_SYSOUT_BYTES_THRESHOLD = 8 * 1024;
+  public final static long DEFAULT_LIMIT = 8 * KB;
+
+  /**
+   * Max hard limit of sysout bytes.
+   */
+  public final static long DEFAULT_HARD_LIMIT = 2 * GB;
+
+  /**
+   * Maximum limit allowed for {@link Limit#bytes()} before sysout check suppression
+   * is suggested.
+   */
+  public final static int MAX_LIMIT = 1 * 1024 * 1024;
 
   /**
    * An annotation specifying the limit of bytes per class.
@@ -58,15 +79,28 @@ public class TestRuleLimitSysouts extends TestRuleAdapter {
   @Inherited
   @Retention(RetentionPolicy.RUNTIME)
   @Target(ElementType.TYPE)
-  public static @interface Limit {
-    public int bytes();
+  public @interface Limit {
+    /**
+     * The maximum number of bytes written to stdout or stderr. If exceeded, a suite failure will be
+     * triggered.
+     */
+    long bytes();
+
+    /**
+     * Maximum number of bytes passed to actual stdout or stderr. Any writes beyond this limit will be
+     * ignored (will actually cause an IOException on the underlying output, but this is silently ignored
+     * by PrintStreams).
+     */
+    long hardLimit() default DEFAULT_HARD_LIMIT;
   }
 
-  private final static AtomicInteger bytesWritten = new AtomicInteger();
+  private final static AtomicLong bytesWritten = new AtomicLong();
+
+  private final static PrintStream capturedSystemOut;
+  private final static PrintStream capturedSystemErr;
+
+  private final static AtomicLong hardLimit;
 
-  private final static DelegateStream capturedSystemOut;
-  private final static DelegateStream capturedSystemErr;
-  
   /**
    * We capture system output and error streams as early as possible because
    * certain components (like the Java logging system) steal these references and
@@ -76,15 +110,35 @@ public class TestRuleLimitSysouts extends TestRuleAdapter {
    * This isn't as elegant as it should be, but there's no workaround for this.
    */
   static {
-    System.out.flush();
-    System.err.flush();
+    PrintStream sout = System.out;
+    PrintStream serr = System.err;
+
+    sout.flush();
+    serr.flush();
+
+    hardLimit = new AtomicLong(Integer.MAX_VALUE);
+    LimitPredicate limitCheck = (before, after) -> {
+      long limit = hardLimit.get();
+      if (after > limit) {
+        if (before < limit) {
+          // Crossing the boundary. Write directly to stderr.
+          serr.println("\nNOTE: Hard limit on sysout exceeded, further output truncated.\n");
+          serr.flush();
+        }
+        throw new IOException("Hard limit on sysout exceeded.");
+      }
+    };
 
     final String csn = Charset.defaultCharset().name();
-    capturedSystemOut = new DelegateStream(System.out, csn, bytesWritten);
-    capturedSystemErr = new DelegateStream(System.err, csn, bytesWritten);
+    try {
+      capturedSystemOut = new PrintStream(new DelegateStream(sout, bytesWritten, limitCheck), true, csn);
+      capturedSystemErr = new PrintStream(new DelegateStream(serr, bytesWritten, limitCheck), true, csn);
+    } catch (UnsupportedEncodingException e) {
+      throw new UncheckedIOException(e);
+    }
 
-    System.setOut(capturedSystemOut.printStream);
-    System.setErr(capturedSystemErr.printStream);
+    System.setOut(capturedSystemOut);
+    System.setErr(capturedSystemErr);
   }
 
   /**
@@ -92,46 +146,58 @@ public class TestRuleLimitSysouts extends TestRuleAdapter {
    */
   private final TestRuleMarkFailure failureMarker;
 
+  static interface LimitPredicate {
+    void check(long before, long after) throws IOException;
+  }
+
   /**
    * Tracks the number of bytes written to an underlying stream by
    * incrementing an {@link AtomicInteger}.
    */
-  static class DelegateStream extends FilterOutputStream {
-    final PrintStream printStream;
-    final AtomicInteger bytesCounter;
-
-    public DelegateStream(OutputStream delegate, String charset, AtomicInteger bytesCounter) {
-      super(delegate);
-      try {
-        this.printStream = new PrintStream(this, true, charset);
-        this.bytesCounter = bytesCounter;
-      } catch (UnsupportedEncodingException e) {
-        throw new RuntimeException(e);
-      }
-    }
+  final static class DelegateStream extends OutputStream {
+    private final OutputStream delegate;
+    private final LimitPredicate limitPredicate;
+    private final AtomicLong bytesCounter;
 
-    // Do override all three write() methods to make sure nothing slips through.
+    public DelegateStream(OutputStream delegate, AtomicLong bytesCounter, LimitPredicate limitPredicate) {
+      this.delegate = delegate;
+      this.bytesCounter = bytesCounter;
+      this.limitPredicate = limitPredicate;
+    }
 
     @Override
     public void write(byte[] b) throws IOException {
-      if (b.length > 0) {
-        bytesCounter.addAndGet(b.length);
-      }
-      super.write(b);
+      this.write(b, 0, b.length);
     }
     
     @Override
     public void write(byte[] b, int off, int len) throws IOException {
       if (len > 0) {
-        bytesCounter.addAndGet(len);
+        checkLimit(len);
       }
-      super.write(b, off, len);
+      delegate.write(b, off, len);
     }
 
     @Override
     public void write(int b) throws IOException {
-      bytesCounter.incrementAndGet();
-      super.write(b);
+      checkLimit(1);
+      delegate.write(b);
+    }
+
+    @Override
+    public void flush() throws IOException {
+      delegate.flush();
+    }
+
+    @Override
+    public void close() throws IOException {
+      delegate.close();
+    }
+
+    private void checkLimit(int bytes) throws IOException {
+      long after = bytesCounter.addAndGet(bytes);
+      long before = after - bytes;
+      limitPredicate.check(before, after);
     }
   }
 
@@ -139,7 +205,6 @@ public class TestRuleLimitSysouts extends TestRuleAdapter {
     this.failureMarker = failureMarker;
   }
 
-  
   /** */
   @Override
   protected void before() throws Throwable {
@@ -147,18 +212,21 @@ public class TestRuleLimitSysouts extends TestRuleAdapter {
       checkCaptureStreams();
     }
     resetCaptureState();
-    validateClassAnnotations();
+    applyClassAnnotations();
   }
 
-  private void validateClassAnnotations() {
+  private void applyClassAnnotations() {
     Class<?> target = RandomizedTest.getContext().getTargetClass();
     if (target.isAnnotationPresent(Limit.class)) {
-      int bytes = target.getAnnotation(Limit.class).bytes();
-      if (bytes < 0 || bytes > 1 * 1024 * 1024) {
-        throw new AssertionError("The sysout limit is insane. Did you want to use "
+      Limit limitAnn = target.getAnnotation(Limit.class);
+      long bytes = limitAnn.bytes();
+      if (bytes < 0 || bytes > MAX_LIMIT) {
+        throw new AssertionError("This sysout limit is very high: " + bytes + ". Did you want to use "
             + "@" + LuceneTestCase.SuppressSysoutChecks.class.getName() + " annotation to "
-            + "avoid sysout checks entirely?");
+            + "avoid sysout checks entirely (this is discouraged)?");
       }
+
+      hardLimit.set(limitAnn.hardLimit());
     }
   }
 
@@ -167,10 +235,10 @@ public class TestRuleLimitSysouts extends TestRuleAdapter {
    */
   public static void checkCaptureStreams() {
     // Make sure we still hold the right references to wrapper streams.
-    if (System.out != capturedSystemOut.printStream) {
+    if (System.out != capturedSystemOut) {
       throw new AssertionError("Something has changed System.out to: " + System.out.getClass().getName());
     }
-    if (System.err != capturedSystemErr.printStream) {
+    if (System.err != capturedSystemErr) {
       throw new AssertionError("Something has changed System.err to: " + System.err.getClass().getName());
     }
   }
@@ -202,18 +270,22 @@ public class TestRuleLimitSysouts extends TestRuleAdapter {
       checkCaptureStreams();
   
       // Flush any buffers.
-      capturedSystemOut.printStream.flush();
-      capturedSystemErr.printStream.flush();
+      capturedSystemOut.flush();
+      capturedSystemErr.flush();
   
       // Check for offenders, but only if everything was successful so far.
-      int limit = RandomizedTest.getContext().getTargetClass().getAnnotation(Limit.class).bytes();
-      if (bytesWritten.get() >= limit && failureMarker.wasSuccessful()) {
+      Limit ann = RandomizedTest.getContext().getTargetClass().getAnnotation(Limit.class);
+      long limit = ann.bytes();
+      long hardLimit = ann.hardLimit();
+      long written = bytesWritten.get();
+      if (written >= limit && failureMarker.wasSuccessful()) {
         throw new AssertionError(String.format(Locale.ENGLISH, 
             "The test or suite printed %d bytes to stdout and stderr," +
-            " even though the limit was set to %d bytes. Increase the limit with @%s, ignore it completely" +
+            " even though the limit was set to %d bytes.%s Increase the limit with @%s, ignore it completely" +
             " with @%s or run with -Dtests.verbose=true",
-            bytesWritten.get(),
+            written,
             limit,
+            written <= hardLimit ? "" : "Hard limit was enforced so output is truncated.",
             Limit.class.getSimpleName(),
             SuppressSysoutChecks.class.getSimpleName()));
       }
@@ -226,9 +298,10 @@ public class TestRuleLimitSysouts extends TestRuleAdapter {
   }
 
   private void resetCaptureState() {
-    capturedSystemOut.printStream.flush();
-    capturedSystemErr.printStream.flush();
+    capturedSystemOut.flush();
+    capturedSystemErr.flush();
     bytesWritten.set(0);
+    hardLimit.set(Integer.MAX_VALUE);
   }
 }
 

http://git-wip-us.apache.org/repos/asf/lucene-solr/blob/f28c5bec/lucene/test-framework/src/test/org/apache/lucene/util/TestSysoutsLimits.java
----------------------------------------------------------------------
diff --git a/lucene/test-framework/src/test/org/apache/lucene/util/TestSysoutsLimits.java b/lucene/test-framework/src/test/org/apache/lucene/util/TestSysoutsLimits.java
new file mode 100644
index 0000000..76c724b
--- /dev/null
+++ b/lucene/test-framework/src/test/org/apache/lucene/util/TestSysoutsLimits.java
@@ -0,0 +1,105 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one or more
+ * contributor license agreements.  See the NOTICE file distributed with
+ * this work for additional information regarding copyright ownership.
+ * The ASF licenses this file to You under the Apache License, Version 2.0
+ * (the "License"); you may not use this file except in compliance with
+ * the License.  You may obtain a copy of the License at
+ *
+ *     http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+package org.apache.lucene.util;
+
+import java.util.stream.Collectors;
+
+import com.carrotsearch.randomizedtesting.RandomizedTest;
+import org.junit.Assert;
+import org.junit.BeforeClass;
+import org.junit.Test;
+import org.junit.runner.JUnitCore;
+import org.junit.runner.Result;
+
+/**
+ * @see TestRuleLimitSysouts
+ */
+public class TestSysoutsLimits extends WithNestedTests {
+  public TestSysoutsLimits() {
+    super(false);
+  }
+
+  public static class ParentNestedTest extends LuceneTestCase
+    implements TestRuleIgnoreTestSuites.NestedTestSuite {
+    @BeforeClass
+    public static void onlyWhenNested() {
+      assumeTrue("Only runs when nested", TestRuleIgnoreTestSuites.isRunningNested());
+    }
+  }
+
+  @TestRuleLimitSysouts.Limit(bytes = 10)
+  public static class OverSoftLimit extends ParentNestedTest {
+    public void testWrite() {
+      System.out.print(RandomizedTest.randomAsciiLettersOfLength(10));
+    }
+  }
+
+  @Test
+  public void testOverSoftLimit() {
+    JUnitCore core = new JUnitCore();
+    Result result = core.run(OverSoftLimit.class);
+
+    String msg = result.getFailures().stream()
+        .map(failure -> failure.getMessage())
+        .collect(Collectors.joining("\n"));
+
+    Assert.assertTrue(msg, msg.contains("The test or suite printed 10 bytes"));
+  }
+
+  @TestRuleLimitSysouts.Limit(bytes = 10)
+  public static class UnderLimit extends ParentNestedTest {
+    public void testWrite() {
+      System.out.print(RandomizedTest.randomAsciiLettersOfLength(9));
+    }
+  }
+
+  @Test
+  public void testUnderLimit() {
+    JUnitCore core = new JUnitCore();
+    Result result = core.run(UnderLimit.class);
+
+    String msg = result.getFailures().stream()
+        .map(failure -> failure.getMessage())
+        .collect(Collectors.joining("\n"));
+
+    Assert.assertTrue(msg, msg.isEmpty());
+  }
+
+  @TestRuleLimitSysouts.Limit(bytes = 10, hardLimit = 20)
+  public static class OverHardLimit extends ParentNestedTest {
+    public void testWrite() {
+      System.out.print("1234567890");
+      System.out.print("-marker1-");
+      System.out.print("-marker2-"); System.out.flush();
+      System.out.print("-marker3-"); System.out.flush();
+      System.out.print("-marker4-"); System.out.flush();
+    }
+  }
+
+  @Test
+  public void OverHardLimit() {
+    JUnitCore core = new JUnitCore();
+    Result result = core.run(OverHardLimit.class);
+
+    String msg = result.getFailures().stream()
+        .map(failure -> failure.getMessage())
+        .collect(Collectors.joining("\n"));
+
+    Assert.assertTrue(msg, msg.contains("Hard limit was enforced"));
+    Assert.assertTrue(msg, msg.contains("The test or suite printed 46 bytes"));
+  }
+}