Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Connection timeout Jetty-9.3.11 #1155

Closed
vikram1234 opened this issue Dec 8, 2016 · 4 comments
Closed

Connection timeout Jetty-9.3.11 #1155

vikram1234 opened this issue Dec 8, 2016 · 4 comments
Labels
More Info Required

Comments

@vikram1234
Copy link

vikram1234 commented Dec 8, 2016 •
edited
Loading

I get below two exceptions after some hours of testing with Jetty 9.3.11, it says connection timedout even the timeout set to 10 Minutes, can anybody please help if its related to connection threadpool or network, ssl?

java.io.IOException: java.util.concurrent.TimeoutException: Idle timeout expired: 600001/600000 ms
        at org.eclipse.jetty.server.HttpInput$ErrorState.noContent(HttpInput.java:788)
        at org.eclipse.jetty.server.HttpInput.read(HttpInput.java:160)
        at java.io.InputStream.read(InputStream.java:101)
        at com.pkg.research.datarouter.node.NodeServlet.common(NodeServlet.java:313)
        at com.pkg.research.datarouter.node.NodeServlet.doPut(NodeServlet.java:159)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:710)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
        at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:845)
        at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:583)
        at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180)
        at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:511)
        at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
        at org.eclipse.jetty.server.Server.handle(Server.java:524)
        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:319)
        at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:253)
        at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
        at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
        at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:202)
        at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
        at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
        at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
        at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
        at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
        at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
        at java.lang.Thread.run(Thread.java:745)
Caused by: java.util.concurrent.TimeoutException: Idle timeout expired: 600001/600000 ms
        at org.eclipse.jetty.io.IdleTimeout.checkIdleTimeout(IdleTimeout.java:166)
        at org.eclipse.jetty.io.IdleTimeout$1.run(IdleTimeout.java:50)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        ... 1 more

12/06-23:53:40.282|org.eclipse.jetty.util.thread.QueuedThreadPool|qtp2083117811-1522|WARN|
java.lang.IllegalStateException: Internal error
        at sun.security.ssl.SSLEngineImpl.initHandshaker(SSLEngineImpl.java:470)
        at sun.security.ssl.SSLEngineImpl.readRecord(SSLEngineImpl.java:1007)
        at sun.security.ssl.SSLEngineImpl.readNetRecord(SSLEngineImpl.java:907)
        at sun.security.ssl.SSLEngineImpl.unwrap(SSLEngineImpl.java:781)
        at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:624)
        at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.fill(SslConnection.java:525)
        at org.eclipse.jetty.server.HttpConnection.fillRequestBuffer(HttpConnection.java:325)
        at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:233)
        at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
        at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
        at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:202)
        at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
        at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
        at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
        at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
        at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
        at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
        at java.lang.Thread.run(Thread.java:745)
12/06-23:53:40.282|org.eclipse.jetty.util.thread.QueuedThreadPool|qtp2083117811-1522|WARN|Unexpected thread death: org.eclipse.jetty.util.thread.QueuedThreadPool$2@2d8ac107 in qtp2083117811{STARTED,10<=13<=200,i=2,q=0}
12/06-23:56:37.773|org.eclipse.jetty.util.thread.QueuedThreadPool|qtp2083117811-1524|WARN|
java.lang.IllegalStateException: Internal error
        at sun.security.ssl.SSLEngineImpl.initHandshaker(SSLEngineImpl.java:470)
        at sun.security.ssl.SSLEngineImpl.readRecord(SSLEngineImpl.java:1007)
        at sun.security.ssl.SSLEngineImpl.readNetRecord(SSLEngineImpl.java:907)
        at sun.security.ssl.SSLEngineImpl.unwrap(SSLEngineImpl.java:781)
        at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:624)
        at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.fill(SslConnection.java:525)
        at org.eclipse.jetty.server.HttpConnection.fillRequestBuffer(HttpConnection.java:325)
        at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:233)
        at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
        at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
@sbordet
Copy link
Contributor

sbordet commented Dec 15, 2016

The first one looks like a normal case where the client is not sending to the server all the required data, and the server times out waiting for the client to finish to send the data.

The second case looks like the client is sending corrupt TLS data.

Without other information, we can't help you more.

@vikram1234
Copy link
Author

vikram1234 commented Dec 15, 2016 •
edited by sbordet
Loading

@sbordet thanks for your reply, we see following two exceptions on client, and server sometimes reports and sometimes does not. I do not have more details in server logs, could you please suggest if its really due to corrupted TLS data or Server can not recognize ciphers?

* Closing connection 0
* TLSv1.2 (OUT), TLS alert, Client hello (1):
} [2 bytes data]
* Issue another request to this URL: 'https://HOST/publish/170/perf_stats_1481332118_13'
*   Trying 135.213.24.131...
* Connected to HOSTport 443 (#1)
* Cipher selection: ALL:!EXPORT:!EXPORT40:!EXPORT56:!aNULL:!LOW:!RC4:@STRENGTH
* successfully set certificate verify locations:
*   CAfile: /etc/pki/tls/certs/ca-bundle.crt
  CApath: none
* TLSv1.2 (OUT), TLS handshake, Client hello (1):
} [268 bytes data]
* TLSv1.2 (IN), TLS handshake, Server hello (2):
{ [85 bytes data]
* TLSv1.2 (IN), TLS handshake, Certificate (11):
{ [4168 bytes data]
* TLSv1.2 (IN), TLS handshake, Server key exchange (12):
{ [401 bytes data]
* TLSv1.2 (IN), TLS handshake, Server finished (14):
{ [4 bytes data]
* TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
} [138 bytes data]
* TLSv1.2 (OUT), TLS change cipher, Client hello (1):
} [1 bytes data]
* TLSv1.2 (OUT), TLS handshake, Finished (20):
} [16 bytes data]
* TLSv1.2 (IN), TLS change cipher, Client hello (1):
{ [1 bytes data]
* TLSv1.2 (IN), TLS handshake, Finished (20):
{ [16 bytes data]
* SSL connection using TLSv1.2 / ECDHE-RSA-AES128-SHA256
* Server certificate:
* 	 subject: cert sub
* 	 start date: Nov 29 00:00:00 2016 GMT
* 	 expire date: May 15 23:59:59 2017 GMT
* 	 subjectAltName: host.com matched
* 	 issuer: C=US; O=Symantec Corporation; OU=Symantec Trust Network; CN=Symantec Class 3 Secure Server CA - G4
* 	 SSL certificate verify ok.
* Server auth using Basic with user 'user_p03'
> PUT /publish/170/perf_stats_1481332118_13 HTTP/1.1
> Host: HOST[REMOVED].com
> Authorization: Basic c2FmZWRldl9wMDM6c2FmZWRldi5wMDM=
> User-Agent: curl/7.47.1
> Accept: */*
> Content-Type: application/octet-stream
> X-META: {"fileType":"csv_anon","frequency":"Dail"}
> Content-Length: 8788263316
> Expect: 100-continue
> 
< HTTP/1.1 100 Continue
} [16384 bytes data]
* SSL read: error:00000000:lib(0):func(0):reason(0), errno 104
* Closing connection 1

* Closing connection 0
* TLSv1.2 (OUT), TLS alert, Client hello (1):
} [2 bytes data]
* Issue another request to this URL: 'https://serverhost.com/publish/170/perf_stats_1481373022_82'
*   Trying 135.213.24.131...
* connect to 135.213.24.131 port 443 failed: Connection refused
* Failed to connect to SERVERHOST[REMOVED HOST NAME].com port 443: Connection refused
* Closing connection 1

@sbordet
Copy link
Contributor

sbordet commented Dec 20, 2016

The first log you reported show that the connection has been closed by the server, so you will need debug information on the server to know why.

The second log shows a connection refused, so probably the server was down.

Have you tried to make the request without Expect: 100-continue ?

@sbordet
Copy link
Contributor

sbordet commented Mar 29, 2018

No more info provided by original poster, closing. Please reopen if it's still an issue for you.

@sbordet sbordet closed this as completed Mar 29, 2018
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
More Info Required
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@joakime @sbordet @vikram1234