From 8f654142072b2bcbb1db56e92847d0e0bb75e3e0 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Mattias=20Finn=C3=A9?= Date: Fri, 4 Jan 2019 20:55:01 +0100 Subject: [PATCH] Adds VerboseTimeout to IndexingServiceTest To help investigate a test hanging --- .../impl/api/index/IndexingServiceTest.java | 3 + .../org/neo4j/test/rule/VerboseTimeout.java | 57 +++++++++++-------- 2 files changed, 37 insertions(+), 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 index 54a0141f7c7cb..09d58db064554 100644 --- 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 index 88a4ed8cad377..9496fce8c9e54 100644 --- 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> getAdditionalParameters() + List> getAdditionalParameters() { return additionalParameters; } private class FailureParameter { - private final T entity; private final Function descriptor; @@ -188,14 +198,14 @@ private Throwable getResult( FutureTask 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 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() ); + } } }