4

I've been hitting an issue intermittently and I'm looking for help in troubleshooting it. If the best thing would be to file a case, let me know and I'll go do that, but I want to make sure I've done my diligence.

It started less than a week ago, when my Java app started throwing exceptions and hanging. I am seeing messages like (sensitive / custom info redacted):

2016-02-01 16:09:55,742 [http-nio-0.0.0.0-9200-exec-22] [152031:username:REGULAR] ERROR Error executing query against Salesforce: SELECT Owner.Type, Owner.Id, Owner.Name FROM Case WHERE Id='5005000000hgDGNAA2'
        at com.myorg.custom.code.SalesforceUtilImpl.executeQuery(SalesforceUtilImpl.java:123)
        at    ...

Caused by: java.net.SocketException: Connection reset
        at org.apache.axis.AxisFault.makeFault(AxisFault.java:101)
        at org.apache.axis.transport.http.HTTPSender.invoke(HTTPSender.java:154)
        at org.apache.axis.strategies.InvocationStrategy.visit(InvocationStrategy.java:32)
        at org.apache.axis.SimpleChain.doVisiting(SimpleChain.java:118)
        at org.apache.axis.SimpleChain.invoke(SimpleChain.java:83)
        at org.apache.axis.client.AxisClient.invoke(AxisClient.java:165)
        at org.apache.axis.client.Call.invokeEngine(Call.java:2784)
        at org.apache.axis.client.Call.invoke(Call.java:2767)
        at org.apache.axis.client.Call.invoke(Call.java:2443)
        at org.apache.axis.client.Call.invoke(Call.java:2366)
        at org.apache.axis.client.Call.invoke(Call.java:1812)
        at com.sforce.soap.enterprise.SoapBindingStub.query(SoapBindingStub.java:6626)
        ... 302 more
Caused by: java.net.SocketException: Connection reset
        at java.net.SocketInputStream.read(SocketInputStream.java:189)
        at java.net.SocketInputStream.read(SocketInputStream.java:121)
        at sun.security.ssl.InputRecord.readFully(InputRecord.java:465)
        at sun.security.ssl.InputRecord.read(InputRecord.java:503)
        at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:961)
        at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:918)
        at sun.security.ssl.AppInputStream.read(AppInputStream.java:105)
        at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
        at java.io.BufferedInputStream.read(BufferedInputStream.java:265)
        at org.apache.axis.transport.http.HTTPSender.readHeadersFromSocket(HTTPSender.java:583)
        at org.apache.axis.transport.http.HTTPSender.invoke(HTTPSender.java:143)
        ... 313 more

I managed to catch the app locked up, and took a thread dump. I saw long running threads like:

"http-nio-0.0.0.0-9200-exec-3124" #930760 daemon prio=5 os_prio=0 tid=0x00007fbe2406e000 nid=0x2be8 runnable [0x00007fbdb874e000]
   java.lang.Thread.State: RUNNABLE
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.read(SocketInputStream.java:150)
        at java.net.SocketInputStream.read(SocketInputStream.java:121)
        at sun.security.ssl.InputRecord.readFully(InputRecord.java:465)
        at sun.security.ssl.InputRecord.read(InputRecord.java:503)
        at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:961)
        - locked <0x00000006b52dd3d8> (a java.lang.Object)
        at sun.security.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1363)
        - locked <0x00000006b52dd4c8> (a java.lang.Object)
        at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1391)
        at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1375)
        at org.apache.axis.components.net.JSSESocketFactory.create(JSSESocketFactory.java:186)
        at org.apache.axis.transport.http.HTTPSender.getSocket(HTTPSender.java:191)
        at org.apache.axis.transport.http.HTTPSender.writeToSocket(HTTPSender.java:404)
        at org.apache.axis.transport.http.HTTPSender.invoke(HTTPSender.java:138)
        at org.apache.axis.strategies.InvocationStrategy.visit(InvocationStrategy.java:32)
        at org.apache.axis.SimpleChain.doVisiting(SimpleChain.java:118)
        at org.apache.axis.SimpleChain.invoke(SimpleChain.java:83)
        at org.apache.axis.client.AxisClient.invoke(AxisClient.java:165)
        at org.apache.axis.client.Call.invokeEngine(Call.java:2784)
        at org.apache.axis.client.Call.invoke(Call.java:2767)
        at org.apache.axis.client.Call.invoke(Call.java:2443)
        at org.apache.axis.client.Call.invoke(Call.java:2366)
        at org.apache.axis.client.Call.invoke(Call.java:1812)
        at com.sforce.soap.enterprise.SoapBindingStub.query(SoapBindingStub.java:6626)

I am using the Enterprise SOAP API, and nothing in my app code changed since when this started happening. In fact, this problem is very intermittent; while some queries fail, most are succeeding. Some questions I have:

  1. Is there a way to get from Salesforce application logging tracking the incoming API connections / requests?
  2. Under what circumstances might Salesforce reset connections?
  3. Can I configure connection pool size limits and / or timeouts from Salesforce?
  4. Is there any way to track SOQL query performance?
  5. Similarly, does my Salesforce instance have any performance monitoring that might give hints on being overworked?

Sorry if this was asked already. I couldn't find an answer among the other questions that were similar to this one.

1
  • the last stacktrace looks like its still doing SSL handshake stuff. Are you connecting via a proxy? – superfell Feb 3 '16 at 0:56
1

I'd check a few things.

  1. Visit trust.salesforce.com. Find your instance and check if there are any reported issues around the time of the problems.
  2. Try the same SOQL query in the developer console. It should be very quick as you are querying by the ID of the Case. How many Case records do you have in that Org? You can pull the debug log for running the query to see how fast it is running.
  3. Try the same SOQL query in an external API based tool, such as Workbench.
  4. You can check the API calls coming into Salesforce using the Event Monitoring API (Note that this is a paid feature). Maybe start with the API events.
  5. Are you using compression on the request and response? This shouldn't be a significant issue with the limited number of fields you are selecting.
  6. Where are you at with your rolling API usage and other related limits? Unlikely again due to the error you are getting.

To check the server side performance of the SOQL query:

  1. Open the developer console
  2. Debug > Open Execute Anonymous Window
  3. Enter your SOQL query along the lines of

    List accounts = [Select Id from Account];

  4. Execute the Apex and select to open the log.

  5. Then open the corresponding debug log. This should include the SOQL execution events. You can read the timing from there, or switch to the timeline view to see the duration.
6
  • Thanks, this is helpful. I checked trust.salesforce.com but nothing was there for my instance. The query executes just fine in the developer console, but I wasn't able to figure out how to pull debug log to see how fast it's running. Can you elaborate? I don't have the event monitoring functionality, unfortunately. I am not compressing the request and response (outside of what the libs do by default, if anything). API usage looks good (<50% utilization). – bwalk Feb 3 '16 at 17:37
  • @bwalk If the query is coming back reasonably quickly in the developer console I'd first check another external tool like workbench. This will use the API and give you the timing back. – Daniel Ballinger Feb 3 '16 at 23:57
  • Using workbench, I can execute the above query multiple times over and get very quick responses. – bwalk Feb 4 '16 at 18:09
  • @bwalk That would indicate the problem is then either intermittent on Salesforces side or something in your Java side. Perhaps networking related like superfell suggested. My next idea would be to repeat the workbench test when the problem starts occurring again. Then you could narrow it down a bit more. – Daniel Ballinger Feb 4 '16 at 20:27
  • I was able to repeat the workbench test while the problem was occurring, but queries were taking milliseconds to return. I am simultaneously investigating the networking side and I've opened a case with Salesforce Support. Thanks for the help. – bwalk Feb 4 '16 at 23:54

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.