You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Mark Miller <ma...@gmail.com> on 2013/03/22 03:09:05 UTC

Test Framework Logging Stack Traces

There are some fails like the below where they are not logged by an internal component, just caught as a thrown exception. The one below has a caused by exception and I'd love to know what it is, but it cuts off with "... 46 more". I pulled this from some jenkins output.

Anyone know if there is a way we can force the entire stack trace no matter what or is this some hard limitation we have? I always need the caused by and we can have some pretty deep stacks.

- Mark


[junit4:junit4]    > Throwable #1: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: https://127.0.0.1:36643/solr
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([595EC9D8441A026A:B2887C7C3F5D879]:0)
[junit4:junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:416)
[junit4:junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
[junit4:junit4]    > 	at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
[junit4:junit4]    > 	at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:168)
[junit4:junit4]    > 	at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:146)
[junit4:junit4]    > 	at org.apache.solr.client.solrj.TestBatchUpdate.doIt(TestBatchUpdate.java:130)
[junit4:junit4]    > 	at org.apache.solr.client.solrj.TestBatchUpdate.testWithBinary(TestBatchUpdate.java:62)
[junit4:junit4]    > 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4:junit4]    > 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[junit4:junit4]    > 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4:junit4]    > 	at java.lang.reflect.Method.invoke(Method.java:601)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
[junit4:junit4]    > 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4]    > 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4]    > 	at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]    > Caused by: org.apache.http.NoHttpResponseException: The target server failed to respond
[junit4:junit4]    > 	at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:95)
[junit4:junit4]    > 	at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:62)
[junit4:junit4]    > 	at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:254)
[junit4:junit4]    > 	at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:289)
[junit4:junit4]    > 	at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:252)
[junit4:junit4]    > 	at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:191)
[junit4:junit4]    > 	at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:300)
[junit4:junit4]    > 	at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:127)
[junit4:junit4]    > 	at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:717)
[junit4:junit4]    > 	at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:522)
[junit4:junit4]    > 	at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
[junit4:junit4]    > 	at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
[junit4:junit4]    > 	at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
[junit4:junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:353)
[junit4:junit4]    > 	... 46 more
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org


Re: Test Framework Logging Stack Traces

Posted by Dawid Weiss <da...@cs.put.poznan.pl>.
http://stackoverflow.com/questions/1167888/howto-increase-lines-of-java-stack-trace-dump

This is Java's mechanism of reducing stack trace verbosity, Mark. The
information is still there, you just need to read it from the outer
exception (they share a common 46 bottom stack frames).

This usually happens when you rethrow like this:

try {
  meWillThrowException1();
} catch (t) {
  throw new Exception(t);
}

then Exception1 will be the 'cause' but they will both share a lot of the
stack leading to when they were thrown. So the stack dump will include a
full stack to the Exception(t) and anything from the divergence point on
(so it'll start at meWillThrowException1 line and show you where inside the
exception is thrown.

Coming back to your example:

[junit4:junit4]    >    at
org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:353)
[junit4:junit4]    >    ... 46 more

if you copy-paste the last 46 lines of the previous exception you'll get:

[junit4:junit4]    >    at
org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:353)
[junit4:junit4]    >    ... 46 more
[junit4:junit4]    >    at
org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
[junit4:junit4]    >    at
org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
[junit4:junit4]    >    at
org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:168)

So the process of inspecting such stack traces is typically: look at the
topmost stack first, it's the rethrow point. If you want to see where the
call site was look at the bottom of the "caused by" clause
(HttpSolrServer.java:353).
If you want to know what exactly threw that caused-by exception look at its
top again (DefaultHttpResponseParser.java:95) and so on, recursively, for
nested stacks.

If you unfold these into full stacks some of this info will be gone (the
divergence point). It may take some getting used to but once you get the
swing of it it's actually pretty convenient.

Dawid

On Fri, Mar 22, 2013 at 3:09 AM, Mark Miller <ma...@gmail.com> wrote:

> There are some fails like the below where they are not logged by an
> internal component, just caught as a thrown exception. The one below has a
> caused by exception and I'd love to know what it is, but it cuts off with
> "... 46 more". I pulled this from some jenkins output.
>
> Anyone know if there is a way we can force the entire stack trace no
> matter what or is this some hard limitation we have? I always need the
> caused by and we can have some pretty deep stacks.
>
> - Mark
>
>
> [junit4:junit4]    > Throwable #1:
> org.apache.solr.client.solrj.SolrServerException: IOException occured when
> talking to server at: https://127.0.0.1:36643/solr
> [junit4:junit4]    >    at
> __randomizedtesting.SeedInfo.seed([595EC9D8441A026A:B2887C7C3F5D879]:0)
> [junit4:junit4]    >    at
> org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:416)
> [junit4:junit4]    >    at
> org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
> [junit4:junit4]    >    at
> org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
> [junit4:junit4]    >    at
> org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:168)
> [junit4:junit4]    >    at
> org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:146)
> [junit4:junit4]    >    at
> org.apache.solr.client.solrj.TestBatchUpdate.doIt(TestBatchUpdate.java:130)
> [junit4:junit4]    >    at
> org.apache.solr.client.solrj.TestBatchUpdate.testWithBinary(TestBatchUpdate.java:62)
> [junit4:junit4]    >    at
> sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> [junit4:junit4]    >    at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> [junit4:junit4]    >    at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> [junit4:junit4]    >    at java.lang.reflect.Method.invoke(Method.java:601)
> [junit4:junit4]    >    at
> com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
> [junit4:junit4]    >    at
> com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
> [junit4:junit4]    >    at
> com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
> [junit4:junit4]    >    at
> com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
> [junit4:junit4]    >    at
> com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
> [junit4:junit4]    >    at
> com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
> [junit4:junit4]    >    at
> org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
> [junit4:junit4]    >    at
> org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
> [junit4:junit4]    >    at
> org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
> [junit4:junit4]    >    at
> com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
> [junit4:junit4]    >    at
> org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
> [junit4:junit4]    >    at
> org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
> [junit4:junit4]    >    at
> org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
> [junit4:junit4]    >    at
> com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> [junit4:junit4]    >    at
> com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
> [junit4:junit4]    >    at
> com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
> [junit4:junit4]    >    at
> com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
> [junit4:junit4]    >    at
> com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
> [junit4:junit4]    >    at
> com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
> [junit4:junit4]    >    at
> com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
> [junit4:junit4]    >    at
> com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
> [junit4:junit4]    >    at
> com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> [junit4:junit4]    >    at
> com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
> [junit4:junit4]    >    at
> org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
> [junit4:junit4]    >    at
> org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
> [junit4:junit4]    >    at
> com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
> [junit4:junit4]    >    at
> com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
> [junit4:junit4]    >    at
> com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
> [junit4:junit4]    >    at
> com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> [junit4:junit4]    >    at
> org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
> [junit4:junit4]    >    at
> org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
> [junit4:junit4]    >    at
> org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
> [junit4:junit4]    >    at
> org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
> [junit4:junit4]    >    at
> com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> [junit4:junit4]    >    at
> com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
> [junit4:junit4]    >    at java.lang.Thread.run(Thread.java:722)
> [junit4:junit4]    > Caused by: org.apache.http.NoHttpResponseException:
> The target server failed to respond
> [junit4:junit4]    >    at
> org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:95)
> [junit4:junit4]    >    at
> org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:62)
> [junit4:junit4]    >    at
> org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:254)
> [junit4:junit4]    >    at
> org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:289)
> [junit4:junit4]    >    at
> org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:252)
> [junit4:junit4]    >    at
> org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:191)
> [junit4:junit4]    >    at
> org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:300)
> [junit4:junit4]    >    at
> org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:127)
> [junit4:junit4]    >    at
> org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:717)
> [junit4:junit4]    >    at
> org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:522)
> [junit4:junit4]    >    at
> org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
> [junit4:junit4]    >    at
> org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
> [junit4:junit4]    >    at
> org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
> [junit4:junit4]    >    at
> org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:353)
> [junit4:junit4]    >    ... 46 more
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
> For additional commands, e-mail: dev-help@lucene.apache.org
>
>