intercom / intercom-java

Java bindings for the Intercom API
https://developers.intercom.io/reference
Apache License 2.0
64 stars 68 forks source link

API hangs with JDK 9 #246

Closed ochedru closed 6 years ago

ochedru commented 6 years ago

Version info

Expected behavior

Connection to https://api.intercom.io does not hang.

Actual behavior

Connection to https://api.intercom.io hangs indefinitely.

Steps to reproduce

  1. Use JDK 9.
  2. Use intercom API to create events.

Logs

Here is a jstack of the issue occurring upon connection:

"pool-15-thread-1" #135 prio=5 os_prio=0 tid=0x00007f06dc020000 nid=0x230 runnable [0x00007f06db1f2000]
   java.lang.Thread.State: RUNNABLE
        at java.net.PlainSocketImpl.socketConnect(java.base@9.0.7.1/Native Method)
        at java.net.AbstractPlainSocketImpl.doConnect(java.base@9.0.7.1/AbstractPlainSocketImpl.java:400)
        - locked <0x00000005447597e8> (a java.net.SocksSocketImpl)
        at java.net.AbstractPlainSocketImpl.connectToAddress(java.base@9.0.7.1/AbstractPlainSocketImpl.java:243)
        at java.net.AbstractPlainSocketImpl.connect(java.base@9.0.7.1/AbstractPlainSocketImpl.java:225)
        at java.net.SocksSocketImpl.connect(java.base@9.0.7.1/SocksSocketImpl.java:402)
        at java.net.Socket.connect(java.base@9.0.7.1/Socket.java:591)
        at sun.security.ssl.SSLSocketImpl.connect(java.base@9.0.7.1/SSLSocketImpl.java:657)
        at sun.net.NetworkClient.doConnect(java.base@9.0.7.1/NetworkClient.java:177)
        at sun.net.www.http.HttpClient.openServer(java.base@9.0.7.1/HttpClient.java:474)
        at sun.net.www.http.HttpClient.openServer(java.base@9.0.7.1/HttpClient.java:569)
        - locked <0x0000000544759698> (a sun.net.www.protocol.https.HttpsClient)
        at sun.net.www.protocol.https.HttpsClient.<init>(java.base@9.0.7.1/HttpsClient.java:265)
        at sun.net.www.protocol.https.HttpsClient.New(java.base@9.0.7.1/HttpsClient.java:372)
        at sun.net.www.protocol.https.AbstractDelegateHttpsURLConnection.getNewHttpClient(java.base@9.0.7.1/AbstractDelegateHttpsURLConnection.java:191)
        at sun.net.www.protocol.http.HttpURLConnection.plainConnect0(java.base@9.0.7.1/HttpURLConnection.java:1181)
        at sun.net.www.protocol.http.HttpURLConnection.plainConnect(java.base@9.0.7.1/HttpURLConnection.java:1075)
        at sun.net.www.protocol.https.AbstractDelegateHttpsURLConnection.connect(java.base@9.0.7.1/AbstractDelegateHttpsURLConnection.java:177)
        at sun.net.www.protocol.http.HttpURLConnection.getOutputStream0(java.base@9.0.7.1/HttpURLConnection.java:1356)
        - locked <0x0000000544756580> (a sun.net.www.protocol.https.DelegateHttpsURLConnection)
        at sun.net.www.protocol.http.HttpURLConnection.getOutputStream(java.base@9.0.7.1/HttpURLConnection.java:1331)
        - locked <0x0000000544756580> (a sun.net.www.protocol.https.DelegateHttpsURLConnection)
        at sun.net.www.protocol.https.HttpsURLConnectionImpl.getOutputStream(java.base@9.0.7.1/HttpsURLConnectionImpl.java:241)
        - locked <0x0000000544756470> (a sun.net.www.protocol.https.HttpsURLConnectionImpl)
        at io.intercom.api.HttpClient.prepareRequestEntity(HttpClient.java:131)
        at io.intercom.api.HttpClient.executeHttpMethod(HttpClient.java:108)
        at io.intercom.api.HttpClient.post(HttpClient.java:100)
        at io.intercom.api.DataResource.create(DataResource.java:25)
        at io.intercom.api.Event.create(Event.java:38)

Here is a jstack of the issue occurring after connection:

"pool-15-thread-1" #135 prio=5 os_prio=0 tid=0x00007f06dc020000 nid=0x230 runnable [0x00007f06db1f3000]
   java.lang.Thread.State: RUNNABLE
        at java.net.SocketInputStream.socketRead0(java.base@9.0.7.1/Native Method)
        at java.net.SocketInputStream.socketRead(java.base@9.0.7.1/SocketInputStream.java:116)
        at java.net.SocketInputStream.read(java.base@9.0.7.1/SocketInputStream.java:171)
        at java.net.SocketInputStream.read(java.base@9.0.7.1/SocketInputStream.java:141)
        at sun.security.ssl.SSLSocketInputRecord.read(java.base@9.0.7.1/SSLSocketInputRecord.java:425)
        at sun.security.ssl.SSLSocketInputRecord.bytesInCompletePacket(java.base@9.0.7.1/SSLSocketInputRecord.java:65)
        at sun.security.ssl.SSLSocketImpl.bytesInCompletePacket(java.base@9.0.7.1/SSLSocketImpl.java:918)
        - locked <0x000000059fe2b580> (a java.lang.Object)
        at sun.security.ssl.AppInputStream.read(java.base@9.0.7.1/AppInputStream.java:144)
        - locked <0x000000059fe2baa0> (a sun.security.ssl.AppInputStream)
        at java.io.BufferedInputStream.fill(java.base@9.0.7.1/BufferedInputStream.java:246)
        at java.io.BufferedInputStream.read1(java.base@9.0.7.1/BufferedInputStream.java:286)
        at java.io.BufferedInputStream.read(java.base@9.0.7.1/BufferedInputStream.java:345)
        - locked <0x000000059fe85dd8> (a java.io.BufferedInputStream)
        at sun.net.www.http.HttpClient.parseHTTPHeader(java.base@9.0.7.1/HttpClient.java:746)
        at sun.net.www.http.HttpClient.parseHTTP(java.base@9.0.7.1/HttpClient.java:689)
        at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(java.base@9.0.7.1/HttpURLConnection.java:1604)
        - locked <0x000000059fe28210> (a sun.net.www.protocol.https.DelegateHttpsURLConnection)
        at sun.net.www.protocol.http.HttpURLConnection.getInputStream(java.base@9.0.7.1/HttpURLConnection.java:1509)
        - locked <0x000000059fe28210> (a sun.net.www.protocol.https.DelegateHttpsURLConnection)
        at java.net.HttpURLConnection.getResponseCode(java.base@9.0.7.1/HttpURLConnection.java:527)
        at sun.net.www.protocol.https.HttpsURLConnectionImpl.getResponseCode(java.base@9.0.7.1/HttpsURLConnectionImpl.java:329)
        at io.intercom.api.HttpClient.runRequest(HttpClient.java:151)
        at io.intercom.api.HttpClient.executeHttpMethod(HttpClient.java:110)
        at io.intercom.api.HttpClient.post(HttpClient.java:100)
        at io.intercom.api.DataResource.create(DataResource.java:25)
        at io.intercom.api.Event.create(Event.java:38)

Note we are using a single-thread executor to send events to intercom. There are no concurrent connections to intercom.

thewheat commented 6 years ago

Hi @ochedru just tested this on my end on macOS 10.14 and it is working on my end.

Do you have any other details such as the OS that you're using just to see if there is anyway we can try replicate the issue you're having?

Perhaps even provide details like how you're building the code as well.

My test code is as follows

Intercom.setToken(TOKEN);
Event event = new Event();
event.setEventName("test-event");
event.setUserID("13");
System.out.println(event);
Event.create(event);

image

ochedru commented 6 years ago

Hi @thewheat,

Thank you for looking into this!

We are using debian (with docker):

root@0f149f395dce:/app# cat /etc/debian_version
9.5
root@0f149f395dce:/app# uname -a
Linux 0f149f395dce 4.9.65-xxxx-std-ipv6-64 #1 SMP Tue Nov 28 14:31:16 UTC 2017 x86_64 GNU/Linux

The code is not fancy at all and basically does the same thing as your test code. We configure the token, and leave all the other properties to their default values. The only difference is that we add some metadata to the event with Event.putMetadata(). That should not make any difference.

Note we are using the Intercom java client successfully within another backend service running on debian, but with JDK 8.

Since I cannot go back from JDK 9 to JDK 8, I am in the process of upgrading to JDK 11. I will let you know if this fixes the problem.

thewheat commented 6 years ago

Still can't replicate with these details @ochedru (I did a clean netinstall)

image

Did you manage to get things working with JDK11?

ochedru commented 6 years ago

Well, I am a bit ashamed: after further scrutiny, the issue has nothing to do with connection problems. The caller method was sending events to intercom.io in an infinite loop (though rate limited).
So, closing and apoligizing. 👎 👎 👎

thewheat commented 6 years ago

No worries @ochedru ! Glad we were able to figure out what happened 😄 Onwards and upwards from here! 🚀