Adds VerboseTimeout to IndexingServiceTest

To help investigate a test hanging
neo4j · Jan 8, 2019 · 8f65414 · 8f65414
1 parent 8a0c11c
commit 8f65414
Show file tree

Hide file tree

Showing 2 changed files with 37 additions and 23 deletions.
diff --git a/community/kernel/src/test/java/org/neo4j/kernel/impl/api/index/IndexingServiceTest.java b/community/kernel/src/test/java/org/neo4j/kernel/impl/api/index/IndexingServiceTest.java
@@ -102,6 +102,7 @@
 import org.neo4j.test.Barrier;
 import org.neo4j.test.DoubleLatch;
 import org.neo4j.test.rule.SuppressOutput;
+import org.neo4j.test.rule.VerboseTimeout;
 import org.neo4j.values.storable.Values;
 
 import static java.lang.String.format;
@@ -166,6 +167,8 @@ public class IndexingServiceTest
     public ExpectedException expectedException = ExpectedException.none();
     @Rule
     public SuppressOutput suppressOutput = SuppressOutput.suppressAll();
+    @Rule
+    public VerboseTimeout timeoutThreadDumpRule = VerboseTimeout.builder().build();
 
     private static final LogMatcherBuilder logMatch = inLog( IndexingService.class );
     private static final IndexProviderDescriptor lucene10Descriptor = new IndexProviderDescriptor( LUCENE10.providerKey(), LUCENE10.providerVersion() );

diff --git a/community/kernel/src/test/java/org/neo4j/test/rule/VerboseTimeout.java b/community/kernel/src/test/java/org/neo4j/test/rule/VerboseTimeout.java
@@ -20,7 +20,9 @@
 package org.neo4j.test.rule;
 
 import org.apache.commons.lang3.StringUtils;
+import org.junit.rules.TestRule;
 import org.junit.rules.Timeout;
+import org.junit.runner.Description;
 import org.junit.runners.model.Statement;
 import org.junit.runners.model.TestTimedOutException;
 
@@ -53,9 +55,10 @@
  *
  * @see Timeout
  */
-public class VerboseTimeout extends Timeout
+public class VerboseTimeout extends Timeout implements TestRule
 {
     private VerboseTimeoutBuilder timeoutBuilder;
+    private Description currentTestDescription;
 
     private VerboseTimeout( VerboseTimeoutBuilder timeoutBuilder )
     {
@@ -68,6 +71,14 @@ public static VerboseTimeoutBuilder builder()
         return new VerboseTimeoutBuilder();
     }
 
+    @Override
+    public Statement apply( Statement base, Description description )
+    {
+        // Just pick up on which test we're currently running
+        currentTestDescription = description;
+        return super.apply( base, description );
+    }
+
     @Override
     protected Statement createFailOnTimeoutStatement( Statement statement )
     {
@@ -125,14 +136,13 @@ protected TimeUnit getTimeUnit()
             return timeUnit;
         }
 
-        public List<FailureParameter<?>> getAdditionalParameters()
+        List<FailureParameter<?>> getAdditionalParameters()
         {
             return additionalParameters;
         }
 
         private class FailureParameter<T>
         {
-
             private final T entity;
             private final Function<T,String> descriptor;
 
@@ -188,14 +198,14 @@ private Throwable getResult( FutureTask<Throwable> task, Thread thread ) throws
         {
             try
             {
-                if ( timeout > 0 )
+                Throwable potentialException = timeout > 0 ? task.get( timeout, timeUnit ) : task.get();
+                if ( potentialException instanceof TestTimedOutException )
                 {
-                    return task.get( timeout, timeUnit );
-                }
-                else
-                {
-                    return task.get();
+                    // This allows this rule to be used without a specific timeout and instead use whatever
+                    // timeout the test annotation specifies itself.
+                    printThreadDump();
                 }
+                return potentialException;
             }
             catch ( ExecutionException e )
             {
@@ -204,15 +214,6 @@ private Throwable getResult( FutureTask<Throwable> task, Thread thread ) throws
             }
             catch ( TimeoutException e )
             {
-                if ( !additionalParameters.isEmpty() )
-                {
-                    System.err.println( "==== Requested additional parameters: ====" );
-                    for ( VerboseTimeoutBuilder.FailureParameter<?> additionalParameter : additionalParameters )
-                    {
-                        System.err.println( additionalParameter.describe() );
-                    }
-                }
-                System.err.println( "=== Thread dump ===" );
                 printThreadDump();
                 return buildTimeoutException( thread );
             }
@@ -245,15 +246,25 @@ public Throwable call()
                 return null;
             }
 
-            public void awaitStarted() throws InterruptedException
+            void awaitStarted() throws InterruptedException
             {
                 startLatch.await();
             }
         }
-    }
 
-    private static void printThreadDump()
-    {
-        System.err.println( DumpUtils.threadDump() );
+        private void printThreadDump()
+        {
+            System.err.println( String.format( "=== Test %s timed out, dumping more information ===", currentTestDescription.getDisplayName() ) );
+            if ( !additionalParameters.isEmpty() )
+            {
+                System.err.println( "=== Requested additional parameters: ===" );
+                for ( VerboseTimeoutBuilder.FailureParameter<?> additionalParameter : additionalParameters )
+                {
+                    System.err.println( additionalParameter.describe() );
+                }
+            }
+            System.err.println( "=== Thread dump ===" );
+            System.err.println( DumpUtils.threadDump() );
+        }
     }
 }