Re: [jetty-dev] SharedBlockingCallback

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index] [List Home]

Re: [jetty-dev] SharedBlockingCallback

From: Guillaume Maillard <guillaume.maillard@xxxxxxxxx>
Date: Thu, 14 Sep 2017 23:14:34 +0200
Delivered-to: jetty-dev@xxxxxxxxxxx
List-archive: <https://dev.eclipse.org/mailman/private/jetty-dev>
List-help: <mailto:jetty-dev-request@eclipse.org?subject=help>
List-subscribe: <https://dev.eclipse.org/mailman/listinfo/jetty-dev>, <mailto:jetty-dev-request@eclipse.org?subject=subscribe>
List-unsubscribe: <https://dev.eclipse.org/mailman/options/jetty-dev>, <mailto:jetty-dev-request@eclipse.org?subject=unsubscribe>

Yes you are right, but after that Jetty is not responding anymore to resquests... blocked in outputstream write()... which is the real issue...

Looking at the source code of SharedBlockingCallback, it seems to be designed to use timeout but only by subclasses.

Is there a way to enable this timeout?

Regards,

Guillaume Maillard

2017-09-14 20:12 GMT+02:00 Joakim Erdfelt <joakim@xxxxxxxxxxx>:

2017-09-14 13:51:31.380:WARN:oejh.HttpParser:qtp1054932644-40: bad HTTP parsed: 400 Illegal character 0x16 for HttpChannelOverHttp@5c1ba46c{r=0,c=false,a=IDLE,uri=null}

That looks like a http client connecting to a HTTP port but using HTTPS (TLS/SSL) to talk.

Joakim Erdfelt / joakim@xxxxxxxxxxx

On Thu, Sep 14, 2017 at 11:03 AM, Guillaume Maillard <guillaume.maillard@xxxxxxxxx> wrote:
Hi,

It seems that our webserver (standalone Jetty 9.3.20.v20170531) get blocked forever by "strange" connections.
As far I undestand, it seems to be related to https://bugs.eclipse.org/bugs/show_bug.cgi?id=435322 but I don't want to pollute the old bug report.

After seeing in logs :

2017-09-14 13:51:31.378:WARN:oejh.HttpParser:qtp1054932644-45: bad HTTP parsed: 400 for HttpChannelOverHttp@5b6c5174{r=0,c=false,a=IDLE,uri=null}
2017-09-14 13:51:31.379:WARN:oejh.HttpParser:qtp1054932644-40: Illegal character 0x16 in state=START for buffer HeapByteBuffer@58feb427[p=1,l=112,c=8192,r=111]={\x16<<<\x03\x01\x00k\x01\x00\x00g\x03\
x01Y\xBaw;MSc...\x13\x00\x12\x00\x11\x00\xFf\x01\x00\x00\x04\x00#\x00\x00>>>\x80\x00\x00\xFf\xDc\xE5\x9f\xC9\x15\xBa\xF7\xF286\xB9H\xC9...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00}
2017-09-14 13:51:31.380:WARN:oejh.HttpParser:qtp1054932644-40: bad HTTP parsed: 400 Illegal character 0x16 for HttpChannelOverHttp@5c1ba46c{r=0,c=false,a=IDLE,uri=null}

The webserver stops to respond to requests. A thread dump shows :

"Scheduler-1100767002" #6756 prio=5 os_prio=0 tid=0x00006d158c006800 nid=0x4363 waiting on condition [0x00006d158a163000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00006d16501cc120> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1081)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)

Locked ownable synchronizers:
- None

"Scheduler-1169794610" #6728 prio=5 os_prio=0 tid=0x00006d1578003000 nid=0x3fe0 waiting on condition [0x00006d1589b67000]
java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00006d165002c898> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)

Locked ownable synchronizers:
- None

"qtp1054932644-49" #49 prio=5 os_prio=0 tid=0x00006d18546b3800 nid=0x25c3 runnable [0x00006d158b243000]
java.lang.Thread.State: RUNNABLE
at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)
at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
- locked <0x00006d1650199820> (a sun.nio.ch.Util$3)
- locked <0x00006d1650199810> (a java.util.Collections$UnmodifiableSet)
- locked <0x00006d16501996e8> (a sun.nio.ch.EPollSelectorImpl)
at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:101)
at org.eclipse.jetty.io.ManagedSelector$SelectorProducer.select(ManagedSelector.java:243)
at org.eclipse.jetty.io.ManagedSelector$SelectorProducer.produce(ManagedSelector.java:191)
at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceExecuteConsume(ExecuteProduceConsume.java:169)
at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:145)
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:748)

Locked ownable synchronizers:
- None

and a lot of

"qtp1054932644-52" #52 prio=5 os_prio=0 tid=0x00006d18546b8800 nid=0x25c6 waiting on condition [0x00006d162c116000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00006d184359f830> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
at org.eclipse.jetty.util.SharedBlockingCallback$Blocker.block(SharedBlockingCallback.java:203)
at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:220)
at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:491)
at java.io.OutputStream.write(OutputStream.java:75)
at www.PublicResourceHandler.handle(PublicResourceHandler.java:63)
at org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:52)
at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:448)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
at org.eclipse.jetty.server.Server.handle(Server.java:534)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320)
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:108)
at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:251)
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:108)
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:748)

Locked ownable synchronizers:
- None

OS : Ubuntu 16.04.2 LTS

JAVA : openjdk version "1.8.0_131"
OpenJDK Runtime Environment (build 1.8.0_131-8u131-b11-2ubuntu1.16.04.3-b11)
OpenJDK 64-Bit Server VM (build 25.131-b11, mixed mode)

Is there a mecanism to avoid such handler "blocking" ?

(The HTTPConfiguration is configured with setIdleTimeout(10 * 60 * 1000); // 10 mins )

Best regards,

Guillaume Maillard

_______________________________________________
jetty-dev mailing list
jetty-dev@xxxxxxxxxxx
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://dev.eclipse.org/mailman/listinfo/jetty-dev

_______________________________________________
jetty-dev mailing list
jetty-dev@xxxxxxxxxxx
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://dev.eclipse.org/mailman/listinfo/jetty-dev

Follow-Ups:
- Re: [jetty-dev] SharedBlockingCallback
  - From: Simone Bordet

References:
- [jetty-dev] SharedBlockingCallback
  - From: Guillaume Maillard
- Re: [jetty-dev] SharedBlockingCallback
  - From: Joakim Erdfelt

Prev by Date: Re: [jetty-dev] SharedBlockingCallback
Next by Date: Re: [jetty-dev] [jetty-users] JSP pages are recompiled at runtime
Previous by thread: Re: [jetty-dev] SharedBlockingCallback
Next by thread: Re: [jetty-dev] SharedBlockingCallback
Index(es):
- Date
- Thread

Breadcrumbs