forcedotcom / ApexUnit

ApexUnit is a powerful continuous integration tool for the Force.com platform
BSD 3-Clause "New" or "Revised" License
71 stars 51 forks source link

Connection exception brings testrun down #11

Closed 13Rise closed 8 years ago

13Rise commented 8 years ago

I startet a run with about 200 testclasses, after 134 the run stops with the following exception. Total tests executed 134 , Remaining tests 66

[com.sforce.cd.apexUnit.ApexUnitRunner.main()] ERROR com.sforce.cd.apexUnit.ApexUnitUtils - Connection exception encountered while executing query :Select Id, ApexClassId, ApexClass.Name, ExtendedStatus, ParentJobId, Status, SystemModstamp, CreatedDate From ApexTestQueueItem Where ParentJobId = '707L000000XPeYyIAL' [com.sforce.cd.apexUnit.ApexUnitRunner.main()] INFO com.sforce.cd.apexUnit.ApexUnitUtils - Shutting down ApexUnit java.lang.Exception: Stack trace at java.lang.Thread.dumpStack(Thread.java:1365) at com.sforce.cd.apexUnit.ApexUnitUtils.shutDownWithErrMsg(ApexUnitUtils.java:68) at com.sforce.cd.apexUnit.ApexUnitUtils.shutDownWithDebugLog(ApexUnitUtils.java:53) at com.sforce.cd.apexUnit.client.testEngine.TestStatusPollerAndResultHandler.waitForTestsToComplete(TestStatusPollerAndResultHandler.java:302) at com.sforce.cd.apexUnit.client.testEngine.TestStatusPollerAndResultHandler.fetchResultsFromParentJobId(TestStatusPollerAndResultHandler.java:66) at com.sforce.cd.apexUnit.client.testEngine.TestExecutor.testExecutionFlow(TestExecutor.java:68) at com.sforce.cd.apexUnit.ApexUnitRunner.main(ApexUnitRunner.java:93) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at org.codehaus.mojo.exec.ExecJavaMojo$1.run(ExecJavaMojo.java:297) at java.lang.Thread.run(Thread.java:745)

adarsh-ramakrishna-sfdc commented 8 years ago

Hello @13Rise

  1. What is the frequency of occurrence of this issue?
  2. Does it always happen after the execution of Test #134 ?
  3. How was the performance of the org when the exception was thrown? Was the env slow or unreachable? Can you please confirm?

Thanks, Adarsh

tfuda commented 8 years ago

@adarsh-ramakrishna-sfdc, @13Rise - I too am experiencing this error. The strange thing however, is that I am ONLY seeing it when running tests in a Developer Edition org on NA7. I am able to run the same suite of tests against the same source files in Developer Edition orgs on NA14 and NA16 without encountering this error. It happens EVERY time I run against my NA7 org. The org is not particularly slow (in fact, the tests seem to run significantly faster on NA7 than they do on NA14). This test suite consists of a total of 99 separate test classes. I'm observing that the tests run to completion without failure (observed via the Salesforce "Apex Test Execution" page), however, ApexUnit throws the Connection exception, and never really detects that the tests have finished.

adarsh-ramakrishna-sfdc commented 8 years ago

@13Rise @tfuda

Possible causes for ConnectionException :

  1. Session time out : If a transaction takes too much of time
  2. Loss in connectivity between Platform and client (Internet works fine but the issue is between the 2 end points)
  3. Connection drop at client end while ApexUnit is being executed (like internet error)

Description of the feature we would like to build in : Retry mechanism - provide flexibility for the users to customize the re-login mechanism bounded by duration/ number of re-logins that respect the current state(pending,in progress , aborted etc) of the transaction

Suggestions? Please let us know your thoughts on our approach to address this bug/issue

Disclaimer: The goal is to empower the user to customize the behavior of re-login module. However this does not eliminate all the possibilities of ConnectionException beyond the scope of ApexUnit

tfuda commented 8 years ago

So, I ran my test suite under the debugger to try and get some additional information about the error. The actual exception returned is an instance of UnexpectedErrorFault. The exceptionMessage property contained the following:

Invalid Session ID found in SessionHeader: Illegal Session. Session not found, missing session key: 00DA0000000ILbY!AR8AQGbFCsv3q1Oo.JT8l.LmCFSR9X0p2CAK5AQ0b23fVJb0qwTa463J7BjeGWIDEir79a1zIUS34QfV7X7p5FGsrizXIqxz
This is expected, it can happen if the session has expired and swept away, or if the user logs out, or if its just someone trying to hack in. 

Here's the full stack trace:

[com.sforce.cd.apexUnit.ApexUnitRunner.main()] ERROR com.sforce.cd.apexUnit.ApexUnitUtils - Connection exception encountered while executing query :Select Id, ApexClassId, ApexClass.Name, ExtendedStatus, ParentJobId, Status, SystemModstamp, CreatedDate From ApexTestQueueItem Where ParentJobId = '707A000002beKSiIAM'
[com.sforce.cd.apexUnit.ApexUnitRunner.main()] INFO com.sforce.cd.apexUnit.ApexUnitUtils - Shutting down ApexUnit
java.lang.Exception: Stack trace
    at java.lang.Thread.dumpStack(Thread.java:1329)
    at com.sforce.cd.apexUnit.ApexUnitUtils.shutDownWithErrMsg(ApexUnitUtils.java:68)
    at com.sforce.cd.apexUnit.ApexUnitUtils.shutDownWithDebugLog(ApexUnitUtils.java:53)
    at com.sforce.cd.apexUnit.client.testEngine.TestStatusPollerAndResultHandler.waitForTestsToComplete(TestStatusPollerAndResultHandler.java:300)
    at com.sforce.cd.apexUnit.client.testEngine.TestStatusPollerAndResultHandler.fetchResultsFromParentJobId(TestStatusPollerAndResultHandler.java:66)
    at com.sforce.cd.apexUnit.client.testEngine.TestExecutor.testExecutionFlow(TestExecutor.java:68)
    at com.sforce.cd.apexUnit.ApexUnitRunner.main(ApexUnitRunner.java:94)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:497)
    at org.codehaus.mojo.exec.ExecJavaMojo$1.run(ExecJavaMojo.java:297)
    at java.lang.Thread.run(Thread.java:745)

So, it does seem like in my case, at least, it is perhaps condition 1 (session timeout). I suspect maybe my old NA7 org has a shorter session timeout than newer DE orgs. Anyway, it does seem that having a re-login mechanism for this scenario would be useful. It seems to me that having a complicated scheme for driving the re-login mechanism might be overkill. I think it would probably be adequate to catch ConnectionException and attempt a single re-login and then try and continue the polling operation on test completion. I think it can be assumed that if your single re-login attempt still fails, there is probably something else going on. I'd suggest a "keep it simple" approach.

adarsh-ramakrishna-sfdc commented 8 years ago

Thanks @tfuda . Can you please try to increase the "Timeout Value" in your Session settings and try executing the tool again? https://help.salesforce.com/htviewhelpdoc?id=admin_sessions.htm Since I dont have an env on which this issue is reproducible, I would need your help to try increasing timeout value and see if it resolves the issue. On a side note, I am also incorporating "SessionRenewer" feature for the connections. Stay tuned!

tfuda commented 8 years ago

@adarsh-ramakrishna-sfdc my session timeout value is 2 hours (http://screencast.com/t/k2aHYQcipU8). I kicked off a test run and took a screenshot of the sessions that were active: http://screencast.com/t/2iEUehOzsi while the tests were running. About 4 minutes into the execution of my tests, I got the following error:

[com.sforce.cd.apexUnit.ApexUnitRunner.main()] ERROR com.sforce.cd.apexUnit.ApexUnitUtils - Connection exception encountered while executing query :Select Id, ApexClassId, ApexClass.Name, ExtendedStatus, ParentJobId, Status, SystemModstamp, CreatedDate From ApexTestQueueItem Where ParentJobId = '707A000002jtAZ7IAM'
[com.sforce.cd.apexUnit.ApexUnitRunner.main()] INFO com.sforce.cd.apexUnit.ApexUnitUtils - Shutting down ApexUnit
java.lang.Exception: Stack trace
    at java.lang.Thread.dumpStack(Thread.java:1329)
    at com.sforce.cd.apexUnit.ApexUnitUtils.shutDownWithErrMsg(ApexUnitUtils.java:68)
    at com.sforce.cd.apexUnit.ApexUnitUtils.shutDownWithDebugLog(ApexUnitUtils.java:53)
    at com.sforce.cd.apexUnit.client.testEngine.TestStatusPollerAndResultHandler.waitForTestsToComplete(TestStatusPollerAndResultHandler.java:303)
    at com.sforce.cd.apexUnit.client.testEngine.TestStatusPollerAndResultHandler.fetchResultsFromParentJobId(TestStatusPollerAndResultHandler.java:66)
    at com.sforce.cd.apexUnit.client.testEngine.TestExecutor.testExecutionFlow(TestExecutor.java:68)
    at com.sforce.cd.apexUnit.ApexUnitRunner.main(ApexUnitRunner.java:75)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:497)
    at org.codehaus.mojo.exec.ExecJavaMojo$1.run(ExecJavaMojo.java:297)
    at java.lang.Thread.run(Thread.java:745)

Once that happened, the "API" session was no longer present in the list of sessions, while the two "UnspecifiedType" sessions remained active. My tests continued to run (I could observe this from the "Apex Test Execution" page in the UI).

adarsh-ramakrishna-sfdc commented 8 years ago

Provided Session renewer implementation as part of PR #38 and #43
Please use version 2.3.4 and update timeout settings in config.properties as needed