jetty服务器的RESTServiceProvider在从https请求读取负载时卡住

1szpjjfi  于 2021-07-03  发布在  Java
关注(0)|答案(0)|浏览(284)

我有一个基于jetty https连接器的rest服务。
当我使用SOAPUI在一个线程上运行200次时,有几个请求会间歇性地超时,如java.net.sockettimeoutexception:read在SOAPUI客户端上超时。soapui配置
在服务器上,使用

// Prints Log 1
String payload = org.glassfish.jersey.message.internal.ReaderWriter.readFromAsString(InputStream in, MediaType type)
// Prints Log 2

我看到,当请求在客户端超时时,log1和log2之间的时间间隔始终是1分钟。
所以我尝试在准确的时间获取线程转储,发现其中一个线程如下stack trace==>

"bw-flowlimit-executor-provider-17" #222 prio=5 os_prio=0 tid=0x0000000019deb800 nid=0x1468 in Object.wait() [0x000000002f1be000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    at org.eclipse.jetty.io.nio.SelectChannelEndPoint.blockReadable(SelectChannelEndPoint.java:449)
    - locked <0x00000000f6a58878> (a org.eclipse.jetty.io.nio.SelectChannelEndPoint)
    at org.eclipse.jetty.io.nio.SslConnection$SslEndPoint.blockReadable(SslConnection.java:714)
    at org.eclipse.jetty.http.HttpParser.blockForContent(HttpParser.java:1197)
    at org.eclipse.jetty.server.HttpInput.read(HttpInput.java:61)
    at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284)
    at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326)
    at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178)
    - locked <0x00000000ee57dfd0> (a java.io.InputStreamReader)
    at java.io.InputStreamReader.read(InputStreamReader.java:184)
    at java.io.Reader.read(Reader.java:140)
    at org.glassfish.jersey.message.internal.ReaderWriter.readFromAsString(ReaderWriter.java:175)
    at org.glassfish.jersey.message.internal.ReaderWriter.readFromAsString(ReaderWriter.java:160)
    at com.myCorp.myPrd.myPackage.BaseInflector.apply(BaseInflector.java:488)
    at com.myCorp.myPrd.myPackage.BaseInflector.apply(BaseInflector.java:1)
    at sun.reflect.GeneratedMethodAccessor35.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81)
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:144)
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:161)
    at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:160)
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:99)
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389)
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.access$100(ResourceMethodInvoker.java:102)
    at org.glassfish.jersey.server.model.ResourceMethodInvoker$2.call(ResourceMethodInvoker.java:336)
    at org.glassfish.jersey.server.model.ResourceMethodInvoker$2.call(ResourceMethodInvoker.java:333)
    at org.glassfish.jersey.server.ServerRuntime$AsyncResponder$2$1.run(ServerRuntime.java:865)
    at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271)
    at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:315)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:297)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:267)
    at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317)
    at org.glassfish.jersey.server.ServerRuntime$AsyncResponder$2.run(ServerRuntime.java:860)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)

   Locked ownable synchronizers:
    - <0x00000000c31e31f0> (a java.util.concurrent.ThreadPoolExecutor$Worker)

jetty details==>“服务器:jetty(8.1.16.v20140903)”
还有一点值得注意的是,这种间歇性请求超时的情况在非ssl场景中是看不到的。
已编辑==>为客户端超时的确切请求添加了服务器端日志。

2020-12-04 16:17:14.803 DEBUG [bw-flowlimit-executor-provider-56] c.t.b.b.r.r.jersey.BaseInflector - MyCorp-MyPrd-MyComponent-REST-200004: Request Received for Operation [post]
2020-12-04 16:17:14.803 DEBUG [bwResourceHTTPConnector.qtp-125] org.eclipse.jetty.io.nio.ssl - [Session-1, SSL_NULL_WITH_NULL_NULL] SslConnection@513197d9 SSL NOT_HANDSHAKING i/o/u=16421/0/0 ishut=false oshut=false {AsyncHttpConnection@11e9d4e5,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=34,c=47522},r=82} NOT_HANDSHAKING filled=16421/16421 flushed=0/0
2020-12-04 16:17:14.804 DEBUG [bwResourceHTTPConnector.qtp-125] org.eclipse.jetty.io.nio.ssl - [Session-1, SSL_NULL_WITH_NULL_NULL] unwrap OK NOT_HANDSHAKING consumed=16421 produced=16384
2020-12-04 16:17:14.804 DEBUG [bwResourceHTTPConnector.qtp-125] org.eclipse.jetty.io.nio.ssl - [Session-1, SSL_NULL_WITH_NULL_NULL] SslConnection@513197d9 SSL NOT_HANDSHAKING i/o/u=0/0/16384 ishut=false oshut=false {AsyncHttpConnection@11e9d4e5,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=34,c=47522},r=82} NOT_HANDSHAKING filled=0/0 flushed=0/0
2020-12-04 16:17:14.804 DEBUG [bw-flowlimit-executor-provider-56] org.eclipse.jetty.http.HttpParser - filled 16384/16384
2020-12-04 16:17:14.804 DEBUG [bwResourceHTTPConnector.qtp-125] o.e.jetty.server.AsyncHttpConnection - suspended AsyncHttpConnection@11e9d4e5,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=34,c=47522},r=82
2020-12-04 16:17:14.804 DEBUG [bwResourceHTTPConnector.qtp-125] org.eclipse.jetty.io.nio.ssl - [Session-1, SSL_NULL_WITH_NULL_NULL] handle SslConnection@513197d9 SSL NOT_HANDSHAKING i/o/u=0/0/0 ishut=false oshut=false {AsyncHttpConnection@11e9d4e5,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=34,c=47522},r=82} progress=false
2020-12-04 16:17:14.804 DEBUG [bw-flowlimit-executor-provider-56] org.eclipse.jetty.io.nio.ssl - [Session-1, SSL_NULL_WITH_NULL_NULL] SslConnection@513197d9 SSL NOT_HANDSHAKING i/o/u=0/0/0 ishut=false oshut=false {AsyncHttpConnection@11e9d4e5,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=34,c=47522},r=82} NOT_HANDSHAKING filled=0/0 flushed=0/0
2020-12-04 16:17:14.804 DEBUG [bw-flowlimit-executor-provider-56] org.eclipse.jetty.http.HttpParser - filled 0/0
2020-12-04 16:17:14.804 DEBUG [bw-flowlimit-executor-provider-56] org.eclipse.jetty.io.nio.ssl - [Session-1, SSL_NULL_WITH_NULL_NULL] SslConnection@513197d9 SSL NOT_HANDSHAKING i/o/u=16421/0/0 ishut=false oshut=false {AsyncHttpConnection@11e9d4e5,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=34,c=47522},r=82} NOT_HANDSHAKING filled=16421/16421 flushed=0/0
2020-12-04 16:17:14.804 DEBUG [bw-flowlimit-executor-provider-56] org.eclipse.jetty.io.nio.ssl - [Session-1, SSL_NULL_WITH_NULL_NULL] unwrap OK NOT_HANDSHAKING consumed=16421 produced=16384
2020-12-04 16:17:14.804 DEBUG [bw-flowlimit-executor-provider-56] org.eclipse.jetty.io.nio.ssl - [Session-1, SSL_NULL_WITH_NULL_NULL] SslConnection@513197d9 SSL NOT_HANDSHAKING i/o/u=0/0/0 ishut=false oshut=false {AsyncHttpConnection@11e9d4e5,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=34,c=47522},r=82} NOT_HANDSHAKING filled=0/0 flushed=0/0
2020-12-04 16:17:14.804 DEBUG [bw-flowlimit-executor-provider-56] org.eclipse.jetty.http.HttpParser - filled 16384/16384
2020-12-04 16:17:14.804 DEBUG [bw-flowlimit-executor-provider-56] org.eclipse.jetty.io.nio.ssl - [Session-1, SSL_NULL_WITH_NULL_NULL] SslConnection@513197d9 SSL NOT_HANDSHAKING i/o/u=0/0/0 ishut=false oshut=false {AsyncHttpConnection@11e9d4e5,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=34,c=47522},r=82} NOT_HANDSHAKING filled=0/0 flushed=0/0
2020-12-04 16:17:14.804 DEBUG [bw-flowlimit-executor-provider-56] org.eclipse.jetty.http.HttpParser - filled 0/0
2020-12-04 16:17:14.805 DEBUG [bw-flowlimit-executor-provider-56] org.eclipse.jetty.io.nio.ssl - [Session-1, SSL_NULL_WITH_NULL_NULL] SslConnection@513197d9 SSL NOT_HANDSHAKING i/o/u=0/0/0 ishut=false oshut=false {AsyncHttpConnection@11e9d4e5,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=34,c=47522},r=82} NOT_HANDSHAKING filled=0/0 flushed=0/0
2020-12-04 16:17:14.805 DEBUG [bw-flowlimit-executor-provider-56] org.eclipse.jetty.http.HttpParser - filled 0/0
2020-12-04 16:17:14.805 DEBUG [bwResourceHTTPConnector.qtp-123] org.eclipse.jetty.io.nio.ssl - [Session-1, SSL_NULL_WITH_NULL_NULL] SslConnection@513197d9 SSL NOT_HANDSHAKING i/o/u=14789/0/0 ishut=false oshut=false {AsyncHttpConnection@11e9d4e5,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=34,c=47522},r=82} NOT_HANDSHAKING filled=14789/14789 flushed=0/0
2020-12-04 16:17:14.805 DEBUG [bwResourceHTTPConnector.qtp-123] org.eclipse.jetty.io.nio.ssl - [Session-1, SSL_NULL_WITH_NULL_NULL] unwrap OK NOT_HANDSHAKING consumed=14789 produced=14753
2020-12-04 16:17:14.805 DEBUG [bwResourceHTTPConnector.qtp-123] org.eclipse.jetty.io.nio.ssl - [Session-1, SSL_NULL_WITH_NULL_NULL] SslConnection@513197d9 SSL NOT_HANDSHAKING i/o/u=0/0/14753 ishut=false oshut=false {AsyncHttpConnection@11e9d4e5,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=34,c=47522},r=82} NOT_HANDSHAKING filled=0/0 flushed=0/0
2020-12-04 16:17:14.805 DEBUG [bwResourceHTTPConnector.qtp-123] o.e.jetty.server.AsyncHttpConnection - suspended AsyncHttpConnection@11e9d4e5,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=34,c=47522},r=82
2020-12-04 16:17:14.805 DEBUG [bwResourceHTTPConnector.qtp-123] org.eclipse.jetty.io.nio.ssl - [Session-1, SSL_NULL_WITH_NULL_NULL] handle SslConnection@513197d9 SSL NOT_HANDSHAKING i/o/u=0/0/14753 ishut=false oshut=false {AsyncHttpConnection@11e9d4e5,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=34,c=47522},r=82} progress=false
2020-12-04 16:17:14.805 DEBUG [bw-flowlimit-executor-provider-56] org.eclipse.jetty.io.nio.ssl - [Session-1, SSL_NULL_WITH_NULL_NULL] SslConnection@513197d9 SSL NOT_HANDSHAKING i/o/u=0/0/14753 ishut=false oshut=false {AsyncHttpConnection@11e9d4e5,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=34,c=47522},r=82} NOT_HANDSHAKING filled=0/0 flushed=0/0
2020-12-04 16:18:14.807 DEBUG [bw-flowlimit-executor-provider-56] org.eclipse.jetty.io.nio.ssl - [Session-1, SSL_NULL_WITH_NULL_NULL] SslConnection@513197d9 SSL NOT_HANDSHAKING i/o/u=37/0/14753 ishut=false oshut=false {AsyncHttpConnection@11e9d4e5,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=34,c=47522},r=82} NOT_HANDSHAKING filled=37/37 flushed=0/0
2020-12-04 16:18:14.809 DEBUG [bw-flowlimit-executor-provider-56] org.eclipse.jetty.io.nio.ssl - [Session-1, SSL_NULL_WITH_NULL_NULL] unwrap CLOSED NEED_WRAP consumed=37 produced=0
2020-12-04 16:18:14.810 DEBUG [bw-flowlimit-executor-provider-56] org.eclipse.jetty.io.nio.ssl - unwrap CLOSE SslConnection@513197d9 SSL NEED_WRAP i/o/u=0/0/14753 ishut=false oshut=false {AsyncHttpConnection@11e9d4e5,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=34,c=47522},r=82} Status = CLOSED HandshakeStatus = NEED_WRAP
bytesConsumed = 37 bytesProduced = 0
2020-12-04 16:18:14.810 DEBUG [bw-flowlimit-executor-provider-56] o.e.jetty.io.nio.ChannelEndPoint - ishut SCEP@7d12c122{l(/127.0.0.1:21918)<->r(/127.0.0.1:8085),s=1,open=true,ishut=false,oshut=false,rb=false,wb=false,w=true,i=1r}-{SslConnection@513197d9 SSL NEED_WRAP i/o/u=0/0/14753 ishut=false oshut=false {AsyncHttpConnection@11e9d4e5,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=34,c=47522},r=82}}
2020-12-04 16:18:14.811 DEBUG [bw-flowlimit-executor-provider-56] org.eclipse.jetty.io.nio.ssl - [Session-1, SSL_NULL_WITH_NULL_NULL] SslConnection@513197d9 SSL NEED_WRAP i/o/u=0/0/14753 ishut=false oshut=false {AsyncHttpConnection@11e9d4e5,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=34,c=47522},r=82} NEED_WRAP filled=-1/0 flushed=0/0
2020-12-04 16:18:14.811 DEBUG [bw-flowlimit-executor-provider-56] org.eclipse.jetty.io.nio.ssl - [Session-1, SSL_NULL_WITH_NULL_NULL] wrap CLOSED NOT_HANDSHAKING consumed=0 produced=37
2020-12-04 16:18:14.811 DEBUG [bw-flowlimit-executor-provider-56] org.eclipse.jetty.io.nio.ssl - wrap CLOSE SslConnection@513197d9 SSL NOT_HANDSHAKING i/o/u=0/37/14753 ishut=false oshut=false {AsyncHttpConnection@11e9d4e5,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=34,c=47522},r=82} Status = CLOSED HandshakeStatus = NOT_HANDSHAKING
bytesConsumed = 0 bytesProduced = 37
2020-12-04 16:18:14.812 DEBUG [bw-flowlimit-executor-provider-56] org.eclipse.jetty.io.nio.ssl - [Session-1, SSL_NULL_WITH_NULL_NULL] SslConnection@513197d9 SSL NOT_HANDSHAKING i/o/u=0/0/14753 ishut=false oshut=false {AsyncHttpConnection@11e9d4e5,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=34,c=47522},r=82} NOT_HANDSHAKING filled=-1/0 flushed=37/0
2020-12-04 16:18:14.813 DEBUG [bw-flowlimit-executor-provider-56] o.e.jetty.io.nio.ChannelEndPoint - oshut SCEP@7d12c122{l(/127.0.0.1:21918)<->r(/127.0.0.1:8085),s=1,open=true,ishut=true,oshut=false,rb=false,wb=false,w=true,i=1r}-{SslConnection@513197d9 SSL NOT_HANDSHAKING i/o/u=0/0/14753 ishut=false oshut=false {AsyncHttpConnection@11e9d4e5,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=34,c=47522},r=82}}
2020-12-04 16:18:14.813 DEBUG [bw-flowlimit-executor-provider-56] o.e.jetty.io.nio.ChannelEndPoint - close SCEP@7d12c122{l(/127.0.0.1:21918)<->r(/127.0.0.1:8085),s=1,open=true,ishut=true,oshut=true,rb=false,wb=false,w=true,i=1!}-{SslConnection@513197d9 SSL NOT_HANDSHAKING i/o/u=0/0/14753 ishut=false oshut=false {AsyncHttpConnection@11e9d4e5,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=34,c=47522},r=82}}
2020-12-04 16:18:14.813 DEBUG [bw-flowlimit-executor-provider-56] org.eclipse.jetty.io.nio.ssl - [Session-1, SSL_NULL_WITH_NULL_NULL] SslConnection@513197d9 SSL NOT_HANDSHAKING i/o/u=0/0/14753 ishut=false oshut=false {AsyncHttpConnection@11e9d4e5,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=34,c=47522},r=82} NOT_HANDSHAKING filled=-1/0 flushed=0/0
2020-12-04 16:18:14.814 DEBUG [bwResourceHTTPConnector.qtp-119 Selector0] org.eclipse.jetty.io.nio - destroyEndPoint SCEP@7d12c122{l(null)<->r(0.0.0.0/0.0.0.0:8085),s=1,open=false,ishut=true,oshut=true,rb=false,wb=false,w=true,i=1!}-{SslConnection@513197d9 SSL NOT_HANDSHAKING i/o/u=0/0/14753 ishut=false oshut=false {AsyncHttpConnection@11e9d4e5,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=34,c=47522},r=82}}
2020-12-04 16:18:14.814 DEBUG [bwResourceHTTPConnector.qtp-119 Selector0] o.e.j.server.AbstractHttpConnection - closed AsyncHttpConnection@11e9d4e5,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=34,c=47522},r=82
2020-12-04 16:18:14.814 DEBUG [bwResourceHTTPConnector.qtp-129] org.eclipse.jetty.io.nio.ssl - [Session-1, SSL_NULL_WITH_NULL_NULL] SslConnection@513197d9 SSL NOT_HANDSHAKING i/o/u=0/0/14753 ishut=false oshut=false {AsyncHttpConnection@11e9d4e5,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=34,c=47522},r=82} NOT_HANDSHAKING filled=-1/0 flushed=0/0
2020-12-04 16:18:14.814 DEBUG [bw-flowlimit-executor-provider-56] org.eclipse.jetty.http.HttpParser - filled 14753/14753
2020-12-04 16:18:14.814 DEBUG [bwResourceHTTPConnector.qtp-129] o.e.jetty.server.AsyncHttpConnection - suspended AsyncHttpConnection@11e9d4e5,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=34,c=47522},r=82
2020-12-04 16:18:14.814 DEBUG [bwResourceHTTPConnector.qtp-129] org.eclipse.jetty.io.nio.ssl - [Session-1, SSL_NULL_WITH_NULL_NULL] handle SslConnection@513197d9 SSL NOT_HANDSHAKING i/o/u=0/0/0 ishut=false oshut=false {AsyncHttpConnection@11e9d4e5,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=0,l=34,c=47522},r=82} progress=false
2020-12-04 16:18:14.815 DEBUG [bw-flowlimit-executor-provider-56] c.t.b.b.r.r.jersey.BaseInflector - MyCorp-MyPrd-MyComponent-REST-200008: Payload for Request

暂无答案!

目前还没有任何答案,快来回答吧!

相关问题