Note that there are some explanatory texts on larger screens.

plurals
  1. POJUnit Test "Times Out" Despite Executing Quickly?
    primarykey
    data
    text
    <p>I've got a couple of test cases that JUnit is telling me time out in 10000ms when the whole test run only lasts a couple of seconds. Here's the output:</p> <pre><code>Tests run: 3, Failures: 0, Errors: 2, Skipped: 0, Time elapsed: 2.528 sec &lt;&lt;&lt; FAILURE! closeTest1(com.w2ogroup.analytics.sibyl.transport.impl.http.server.HttpServerTransportTests) Time elapsed: 1.654 sec &lt;&lt;&lt; ERROR! java.lang.Exception: test timed out after 10000 milliseconds closeTest2(com.w2ogroup.analytics.sibyl.transport.impl.http.server.HttpServerTransportTests) Time elapsed: 0.672 sec &lt;&lt;&lt; ERROR! java.lang.Exception: test timed out after 50000 milliseconds Results : Tests in error: HttpServerTransportTests » test timed out after 10000 milliseconds HttpServerTransportTests » test timed out after 50000 milliseconds Tests run: 3, Failures: 0, Errors: 2, Skipped: 0 [INFO] ------------------------------------------------------------------------ [INFO] BUILD FAILURE [INFO] ------------------------------------------------------------------------ [INFO] Total time: 4.383s [INFO] Finished at: Sun Jun 09 19:00:09 PDT 2013 [INFO] Final Memory: 9M/129M [INFO] ------------------------------------------------------------------------ </code></pre> <p>It seems unlikely that my tests have timed out by taking more than 10 (or 50) seconds to run when the whole test run only lasted 4.3s. :)</p> <p>Here's the surefire configuration from the POM I'm using to run the tests:</p> <pre><code>&lt;plugin&gt; &lt;groupId&gt;org.apache.maven.plugins&lt;/groupId&gt; &lt;artifactId&gt;maven-surefire-plugin&lt;/artifactId&gt; &lt;version&gt;${maven-surefire-plugin.version}&lt;/version&gt; &lt;configuration&gt; &lt;!-- We always want to exclude provided deps. I'm not sure why this isn't the default. --&gt; &lt;classpathDependencyScopeExclude&gt;provided&lt;/classpathDependencyScopeExclude&gt; &lt;includes&gt; &lt;include&gt;**/*Tests.*&lt;/include&gt; &lt;/includes&gt; &lt;/configuration&gt; &lt;/plugin&gt; </code></pre> <p>Does anyone have any thoughts about why this could be happening?</p> <p><strong>EDIT</strong>: Here's some more information, as requested below. </p> <p>Here is the output of one of the tests. I'm building a simple transport mechanism, so I'm building unit tests that close streams and interrupt NIO threads to make them quit, which is why there are all those (expected) IO-type <code>Exception</code>s.</p> <pre><code>Running com.siggroup.analytics.sibyl.transport.impl.http.server.HttpServerTransportTests 2013-06-10 08:32:53.195:INFO:oejs.Server:Thread-0: jetty-9.0.3.v20130506 Jun 10, 2013 8:32:53 AM com.sun.jersey.server.impl.application.WebApplicationImpl _initiate INFO: Initiating Jersey application, version 'Jersey: 1.17.1 02/28/2013 12:47 PM' 2013-06-10 08:32:53.925:INFO:oejsh.ContextHandler:Thread-0: Started o.e.j.s.ServletContextHandler@30db7df3{/,null,AVAILABLE} 2013-06-10 08:32:54.136:INFO:oejs.ServerConnector:Thread-0: Started ServerConnector@4584e5a8{HTTP/1.1}{0.0.0.0:8080} org.eclipse.jetty.server.HttpConnection$Input$1: SelectChannelEndPoint@329ecdd9{/127.0.0.1:58667&lt;r-l&gt;/127.0.0.1:8080,o=true,is=false,os=false,fi=FillInterest@32f4dc3$ EOF at org.eclipse.jetty.server.HttpConnection$Input.blockForContent(HttpConnection.java:588) at org.eclipse.jetty.server.HttpInput.read(HttpInput.java:130) at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:283) at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:325) at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:177) at sun.nio.cs.StreamDecoder.read0(StreamDecoder.java:126) at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:112) at java.io.InputStreamReader.read(InputStreamReader.java:168) at com.siggroup.analytics.sibyl.transport.impl.http.server.WorkerTrackingDelegatingReader$2.work(WorkerTrackingDelegatingReader.java:64) at com.siggroup.analytics.sibyl.transport.impl.http.server.WorkerTrackingDelegatingReader$2.work(WorkerTrackingDelegatingReader.java:1) at com.siggroup.analytics.commons.concurrent.Scope.work(Scope.java:49) at com.siggroup.analytics.sibyl.transport.impl.http.server.WorkerTrackingDelegatingReader.read(WorkerTrackingDelegatingReader.java:60) at java.io.FilterReader.read(FilterReader.java:65) at java.io.PushbackReader.read(PushbackReader.java:90) at com.siggroup.sibyl.transport.impl.readerwriter.ReaderWriterTransportReaderThread.readPacket(ReaderWriterTransportReaderThread.java:32) at com.siggroup.sibyl.transport.impl.queued.QueuedTransportReaderThread.run(QueuedTransportReaderThread.java:21) Caused by: java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:996) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1303) at java.util.concurrent.Semaphore.acquire(Semaphore.java:317) at org.eclipse.jetty.util.BlockingCallback.block(BlockingCallback.java:96) at org.eclipse.jetty.server.HttpConnection$Input.blockForContent(HttpConnection.java:559) ... 15 more 2013-06-10 08:32:54.958:WARN:oejs.HttpConnection:qtp557611759-26: HttpConnection@6a341611{FILLING_BLOCKED},g=HttpGenerator{s=END},p=HttpParser{s=CHUNKED_CONTENT,1 of$ java.lang.IllegalStateException: Already Blocked at org.eclipse.jetty.io.AbstractConnection.block(AbstractConnection.java:233) at org.eclipse.jetty.server.HttpConnection.access$400(HttpConnection.java:50) at org.eclipse.jetty.server.HttpConnection$Input.blockForContent(HttpConnection.java:557) at org.eclipse.jetty.server.HttpInput.consumeAll(HttpInput.java:282) at org.eclipse.jetty.server.HttpConnection.completed(HttpConnection.java:460) at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:333) at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:225) at org.eclipse.jetty.io.AbstractConnection$ReadCallback.run(AbstractConnection.java:358) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:596) at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:527) at java.lang.Thread.run(Thread.java:722) java.io.EOFException at com.siggroup.sibyl.transport.impl.readerwriter.ReaderWriterTransportReaderThread.readPacket(ReaderWriterTransportReaderThread.java:36) at com.siggroup.sibyl.transport.impl.queued.QueuedTransportReaderThread.run(QueuedTransportReaderThread.java:21) </code></pre> <p>The tests are run with <code>@Test(timeout=/* number */)</code>. Here's the signature of one of the test cases:</p> <pre><code>@Test(timeout = 10000) public void closeTest1() throws IOException, InterruptedException { /* Test goes here */ } </code></pre> <p><strong>EDIT</strong>: Here is the entire contents of the surefire log:</p> <pre><code>------------------------------------------------------------------------------- Test set: com.w2ogroup.analytics.sibyl.transport.impl.http.server.HttpServerTransportTests ------------------------------------------------------------------------------- Tests run: 3, Failures: 0, Errors: 2, Skipped: 0, Time elapsed: 3.136 sec &lt;&lt;&lt; FAILURE! closeTest1(com.w2ogroup.analytics.sibyl.transport.impl.http.server.HttpServerTransportTests) Time elapsed: 2.218 sec &lt;&lt;&lt; ERROR! java.lang.Exception: test timed out after 10000 milliseconds closeTest2(com.w2ogroup.analytics.sibyl.transport.impl.http.server.HttpServerTransportTests) Time elapsed: 0.661 sec &lt;&lt;&lt; ERROR! java.lang.Exception: test timed out after 50000 milliseconds </code></pre> <p><strong>EDIT</strong>: For posterity, @MatthewFarwell's answer below is correct, as indicated. I found that JUnit 4.12-SNAPSHOT was not available in Maven Central, so rather than set up more repositories and have a dependency on a SNAPSHOT artifact, I simply wrapped my test case in a <code>try</code>/<code>catch</code> for <code>InterruptedException</code>s, which kept the test case from propagating the <code>InterruptedException</code>, which fixed the problem.</p>
    singulars
    1. This table or related slice is empty.
    plurals
    1. This table or related slice is empty.
    1. This table or related slice is empty.
    1. This table or related slice is empty.
 

Querying!

 
Guidance

SQuiL has stopped working due to an internal error.

If you are curious you may find further information in the browser console, which is accessible through the devtools (F12).

Reload