Re: [jetty-dev] Jetty 9.3.15 stopped accepting incoming connections (too

[Michele Rossi <michele.rossi@xxxxxxxxx>]

hi Joakim,

our system just stopped working again - nothing obvious in the thread stack, and netstat produces something like this:

tcp      248      0 ::ffff:10.100.216.60:9443   ::ffff:80.169.48.109:51852  CLOSE_WAIT  20652/java

tcp      240      0 ::ffff:10.100.216.60:9443   ::ffff:207.45.249.138:14197 CLOSE_WAIT  20652/java

tcp      221      0 ::ffff:10.100.216.60:9443   ::ffff:38.122.227.195:16131 CLOSE_WAIT  20652/java

tcp      248      0 ::ffff:10.100.216.60:9443   ::ffff:121.241.121.2:58682  CLOSE_WAIT  20652/java

tcp      216      0 ::ffff:10.100.216.60:9443   ::ffff:194.243.28.165:55252 CLOSE_WAIT  20652/java

tcp      221      0 ::ffff:10.100.216.60:9443   ::ffff:121.241.121.2:65116  CLOSE_WAIT  20652/java

tcp      216      0 ::ffff:10.100.216.60:9443   ::ffff:38.122.227.195:49217 CLOSE_WAIT  20652/java

tcp      240      0 ::ffff:10.100.216.60:9443   ::ffff:121.241.121.2:50618  CLOSE_WAIT  20652/java

tcp      221      0 ::ffff:10.100.216.60:9443   ::ffff:213.61.68.3:55767    CLOSE_WAIT  20652/java

tcp      221      0 ::ffff:10.100.216.60:9443   ::ffff:213.61.68.3:55909    CLOSE_WAIT  20652/java

tcp      253      0 ::ffff:10.100.216.60:9443   ::ffff:80.169.48.109:23584  CLOSE_WAIT  20652/java

tcp      221      0 ::ffff:10.100.216.60:9443   ::ffff:38.122.227.195:3441  CLOSE_WAIT  20652/java

tcp      248      0 ::ffff:10.100.216.60:9443   ::ffff:80.169.48.109:35601  CLOSE_WAIT  20652/java

tcp      248      0 ::ffff:10.100.216.60:9443   ::ffff:80.169.48.109:48369  CLOSE_WAIT  20652/java

tcp      216      0 ::ffff:10.100.216.60:9443   ::ffff:38.122.227.195:4476  CLOSE_WAIT  20652/java

tcp      221      0 ::ffff:10.100.216.60:9443   ::ffff:194.243.28.165:52506 CLOSE_WAIT  20652/java

tcp      221      0 ::ffff:10.100.216.60:9443   ::ffff:38.122.227.195:51688 CLOSE_WAIT  20652/java

tcp      248      0 ::ffff:10.100.216.60:9443   ::ffff:121.241.121.2:58626  CLOSE_WAIT  20652/java

tcp      221      0 ::ffff:10.100.216.60:9443   ::ffff:194.243.28.165:60347 CLOSE_WAIT  20652/java

tcp      216      0 ::ffff:10.100.216.60:9443   ::ffff:194.243.28.165:1966  CLOSE_WAIT  20652/java

tcp      248      0 ::ffff:10.100.216.60:9443   ::ffff:80.169.48.109:20451  CLOSE_WAIT  20652/java

tcp      221      0 ::ffff:10.100.216.60:9443   ::ffff:121.241.121.2:65156  CLOSE_WAIT  20652/java

tcp      240      0 ::ffff:10.100.216.60:9443   ::ffff:121.241.121.2:61156  CLOSE_WAIT  20652/java

tcp      248      0 ::ffff:10.100.216.60:9443   ::ffff:80.169.48.109:18541  CLOSE_WAIT  20652/java

tcp      220      0 ::ffff:10.100.216.60:9443   ::ffff:38.122.227.195:8983  ESTABLISHED 20652/java

tcp      221      0 ::ffff:10.100.216.60:9443   ::ffff:38.122.227.195:26369 CLOSE_WAIT  20652/java

tcp      216      0 ::ffff:10.100.216.60:9443   ::ffff:38.122.227.195:16549 CLOSE_WAIT  20652/java

tcp      253      0 ::ffff:10.100.216.60:9443   ::ffff:80.169.48.109:19282  CLOSE_WAIT  20652/java

tcp      221      0 ::ffff:10.100.216.60:9443   ::ffff:121.241.121.2:65110  CLOSE_WAIT  20652/java

tcp      248      0 ::ffff:10.100.216.60:9443   ::ffff:80.169.48.109:30697  CLOSE_WAIT  20652/java

tcp      221      0 ::ffff:10.100.216.60:9443   ::ffff:38.122.227.195:58197 CLOSE_WAIT  20652/java

tcp      248      0 ::ffff:10.100.216.60:9443   ::ffff:80.169.48.109:15884  CLOSE_WAIT  20652/java

tcp      221      0 ::ffff:10.100.216.60:9443   ::ffff:213.61.68.3:55921    CLOSE_WAIT  20652/java

tcp      240      0 ::ffff:10.100.216.60:9443   ::ffff:121.241.121.2:61108  CLOSE_WAIT  20652/java

tcp      216      0 ::ffff:10.100.216.60:9443   ::ffff:38.122.227.195:29143 CLOSE_WAIT  20652/java

tcp      221      0 ::ffff:10.100.216.60:9443   ::ffff:213.61.68.3:55892    CLOSE_WAIT  20652/java

tcp      221      0 ::ffff:10.100.216.60:9443   ::ffff:38.122.227.195:36939 CLOSE_WAIT  20652/java

tcp      240      0 ::ffff:10.100.216.60:9443   ::ffff:121.241.121.2:50619  CLOSE_WAIT  20652/java

tcp      216      0 ::ffff:10.100.216.60:9443   ::ffff:194.243.28.165:8275  CLOSE_WAIT  20652/java

tcp      240      0 ::ffff:10.100.216.60:9443   ::ffff:121.241.121.2:50651  CLOSE_WAIT  20652/java

tcp      240      0 ::ffff:10.100.216.60:9443   ::ffff:207.45.249.138:22678 CLOSE_WAIT  20652/java

tcp      248      0 ::ffff:10.100.216.60:9443   ::ffff:80.169.48.109:55934  CLOSE_WAIT  20652/java

tcp      221      0 ::ffff:10.100.216.60:9443   ::ffff:38.122.227.195:10946 CLOSE_WAIT  20652/java

tcp      221      0 ::ffff:10.100.216.60:9443   ::ffff:38.122.227.195:58036 CLOSE_WAIT  20652/java

tcp      221      0 ::ffff:10.100.216.60:9443   ::ffff:38.122.227.195:32016 CLOSE_WAIT  20652/java

tcp      221      0 ::ffff:10.100.216.60:9443   ::ffff:213.61.68.3:55724    CLOSE_WAIT  20652/java

tcp      240      0 ::ffff:10.100.216.60:9443   ::ffff:207.45.249.138:51785 CLOSE_WAIT  20652/java

tcp      248      0 ::ffff:10.100.216.60:9443   ::ffff:121.241.121.2:58641  CLOSE_WAIT  20652/java

tcp      221      0 ::ffff:10.100.216.60:9443   ::ffff:38.122.227.195:56102 CLOSE_WAIT  20652/java

We basically see an increasing number of connections in CLOSE_WAIT

We will revert to the previous jetty build and will let you guys know if the problem disappears.

thanks,

Michele

On 13 January 2017 at 13:33, Joakim Erdfelt <joakim@xxxxxxxxxxx> wrote:

The line ...

WARN |       o.e.j.h.HttpParser||bad HTTP parsed: 400 Illegal character 0x16 for HttpChannelOverHttp@6d081ff2

Smells like a connection using normal HTTP was made to a connector on your server specified as HTTPS.

Would suggest you also check the netstat output.

On Jan 13, 2017 7:10 AM, "Michele Rossi" <michele.rossi@xxxxxxxxx> wrote:

hi all,

our production system running Jetty 9.3.15 this morning stopped accepting incoming connection producing the following suspicious log lines:

10:26:52.121|WARN |        o.e.j.s.HttpInput||

java.util.concurrent.TimeoutException: Idle timeout expired: 30000/30000 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)

        at java.lang.Thread.run(Thread.java:745)

[ ........................... removed application log lines ......................................]

10:43:30.148|WARN |       o.e.j.h.HttpParser||Illegal character 0x16 in state=START for buffer HeapByteBuffer@23931b7a[p=1,l=265,c=8192,r=264]={\x16<<<\x03\x01\x01\x04\x01\x00\x01\x00\x03\x03Xx\xA1B\xF3h\x9a...\x03\x02\x03\x03\x02\x01\x02\x02\x02\x03\x00\x0f\x00\x01\x01>>>,application/xml;...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00}

10:43:30.148|WARN |       o.e.j.h.HttpParser||bad HTTP parsed: 400 Illegal character 0x16 for HttpChannelOverHttp@6d081ff2{r=0,c=false,a=IDLE,uri=null}

10:43:30.974|WARN |o.e.j.s.AbstractConnector||

java.io.IOException: Too many open files

        at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method)

        at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422)

        at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250)

        at org.eclipse.jetty.server.ServerConnector.accept(ServerConnector.java:373)

        at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:601)

        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)

We have only just recently upgraded the system to Jetty 9.3.15 and with the previous build we never saw anything like this happening.

And the load on the system wasn't high at all.

I am letting you guys know in case some of you is aware of changes made that could cause this kind a problem.

A simple bounce of the system resolved the problem.

I am now considering a roll-back to the previous Jetty release while I try to gather more data on what happened.

If the problem re-occurs I am planning to attempt to diagnose it by dumping the threads and also by running unix's "lsof"on the jetty process to determine the number of open files.

thanks,

Michele

_______________________________________________
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