Jetty

Hung threads consuming 100% CPU with SSL enabled and IE 8 as client

Details

  • Type: Bug Bug
  • Status: Resolved Resolved
  • Priority: Major Major
  • Resolution: Fixed
  • Affects Version/s: 7.4.0, 7.4.5
  • Fix Version/s: 7.5.1
  • Component/s: Security and SSL
  • Labels:
    None
  • Environment:
    CentOS 5.6 x64
    Oracle JDK 6u26 x64
    Webapp running on top of Jetty: OpenNMS 1.9.91 (bundled with Jetty 7.4.0, also tested with 7.4.5)
    Client browser - IE 8.0.7600.16385
  • Number of attachments :
    0

Description

Problem:

Hung threads consume 100% of CPU (and cause load averages of 40-50 on my system) when SSL-enabled Jetty 7.4.5 gets hit by an IE 8 browser. Same problem does not occur with Chrome 14.0.835.186.

Thread dump of a sample hung thread:

"qtp52888755-307799" prio=10 tid=0x00002aaabb96b000 nid=0xe18 runnable [0x000000004f4db000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at com.sun.net.ssl.internal.ssl.InputRecord.readFully(InputRecord.java:293)
at com.sun.net.ssl.internal.ssl.InputRecord.read(InputRecord.java:331)
at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:798)

  • locked <0x000000050cbd8580> (a java.lang.Object)
    at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:755)
    at com.sun.net.ssl.internal.ssl.AppInputStream.read(AppInputStream.java:75)
  • locked <0x000000050cbd8620> (a com.sun.net.ssl.internal.ssl.AppInputStream)
    at org.eclipse.jetty.io.ByteArrayBuffer.readFrom(ByteArrayBuffer.java:388)
    at org.eclipse.jetty.io.bio.StreamEndPoint.fill(StreamEndPoint.java:132)
    at org.eclipse.jetty.server.bio.SocketConnector$ConnectorEndPoint.fill(SocketConnector.java:209)
    at org.eclipse.jetty.server.ssl.SslSocketConnector$SslConnectorEndPoint.fill(SslSocketConnector.java:612)
    at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:289)
    at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:214)
    at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:411)
    at org.eclipse.jetty.server.bio.SocketConnector$ConnectorEndPoint.run(SocketConnector.java:241)
    at org.eclipse.jetty.server.ssl.SslSocketConnector$SslConnectorEndPoint.run(SslSocketConnector.java:664)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:529)
    at java.lang.Thread.run(Thread.java:662)

Steps I took to reproduce:

Setting up the test environment for Jetty 7.4.0

  • Start OpenNMS

Reproducing the bug:

  • Hit either /opennms or /opennms-remoting from an IE 8 browser, and do nothing else (don't even need to log in)
  • Wait and watch the load average start climbing from hung Jetty SSL threads. The hung threads seem to accumulate faster if more concurrent connections are opened.

Setting up the test environment for Jetty 7.4.5

  • Follow above installation steps
  • Relocate /opt/opennms/lib/jetty*7.4.0*.jar and /opt/opennms/lib/servlet*.jar somewhere else
  • (Re)start OpenNMS
  • Perform the same reproduction test as above

FYI, I have a parallel bug open with the OpenNMS team (http://issues.opennms.org/browse/NMS-4940) with some more details and thread dumps, but this is smelling more and more like a Jetty bug, so the team pointed me here.

Let me know if I can provide any more information to help. Thanks!

Activity

Ascending order - Click to sort in descending order
Hide
Permalink
Andy Ellsworth added a comment -

Also tested with Firefox 3.6.22 and the problem does not occur.

Show
Andy Ellsworth added a comment - Also tested with Firefox 3.6.22 and the problem does not occur.
Hide
Permalink
Andy Ellsworth added a comment -

Another data point - I've tried this on both a much older JDK (6u7) and a brand new JDK (7u0) and get the same results as on 6u26.

Show
Andy Ellsworth added a comment - Another data point - I've tried this on both a much older JDK (6u7) and a brand new JDK (7u0) and get the same results as on 6u26.
Hide
Permalink
Joakim Erdfelt added a comment -

Thanks for filing this with steps to reproduce.
We are building out a machine with this configuration in an attempt to reproduce this.

Show
Joakim Erdfelt added a comment - Thanks for filing this with steps to reproduce. We are building out a machine with this configuration in an attempt to reproduce this.
Hide
Permalink
Andy Ellsworth added a comment -

Thanks Joakim.

Another data point - we were able to reproduce the problem with IE9 as well (9.0.8112.16421), so IE8 and IE9 both trigger it.

Show
Andy Ellsworth added a comment - Thanks Joakim. Another data point - we were able to reproduce the problem with IE9 as well (9.0.8112.16421), so IE8 and IE9 both trigger it.
Hide
Permalink
Andy Ellsworth added a comment -

Here's a load average profile taken immediately after hitting the box with a ton of IE requests in a very short amount of time:

    • Baseline - webapp running, system idle **
      10:54:57 up 23 days, 21:06, 2 users, load average: 0.02, 0.05, 0.06
      10:55:02 up 23 days, 21:06, 2 users, load average: 0.02, 0.05, 0.06
      10:55:07 up 23 days, 21:06, 2 users, load average: 0.02, 0.05, 0.06
      10:55:12 up 23 days, 21:06, 2 users, load average: 0.02, 0.05, 0.06
      10:55:17 up 23 days, 21:06, 2 users, load average: 0.01, 0.04, 0.06
      10:55:22 up 23 days, 21:06, 2 users, load average: 0.09, 0.06, 0.06
      10:55:27 up 23 days, 21:06, 2 users, load average: 0.16, 0.08, 0.07
      10:55:32 up 23 days, 21:06, 2 users, load average: 0.15, 0.07, 0.07
      10:55:37 up 23 days, 21:06, 2 users, load average: 0.14, 0.07, 0.07
      10:55:42 up 23 days, 21:07, 2 users, load average: 0.21, 0.09, 0.07
      10:55:47 up 23 days, 21:07, 2 users, load average: 0.19, 0.09, 0.07
      10:55:52 up 23 days, 21:07, 2 users, load average: 0.18, 0.08, 0.07
      10:55:57 up 23 days, 21:07, 2 users, load average: 0.24, 0.10, 0.08
      10:56:02 up 23 days, 21:07, 2 users, load average: 0.22, 0.10, 0.08
      10:56:07 up 23 days, 21:07, 2 users, load average: 0.20, 0.10, 0.08
      10:56:12 up 23 days, 21:07, 2 users, load average: 0.35, 0.13, 0.09
      10:56:17 up 23 days, 21:07, 2 users, load average: 0.48, 0.16, 0.10
      10:56:22 up 23 days, 21:07, 2 users, load average: 0.60, 0.19, 0.11
    • IE9 logs in, pulls some reports for 5 seconds and then sits idle **
    • Hung threads start accumulating here **
      10:56:27 up 23 days, 21:07, 2 users, load average: 1.03, 0.28, 0.14
      10:56:32 up 23 days, 21:07, 2 users, load average: 1.43, 0.38, 0.17
      10:56:37 up 23 days, 21:07, 2 users, load average: 1.80, 0.47, 0.20
      10:56:42 up 23 days, 21:08, 2 users, load average: 2.13, 0.56, 0.23
      10:56:47 up 23 days, 21:08, 2 users, load average: 2.04, 0.57, 0.23
      10:56:52 up 23 days, 21:08, 2 users, load average: 2.36, 0.66, 0.27
      10:56:57 up 23 days, 21:08, 2 users, load average: 2.65, 0.75, 0.30
      10:57:02 up 23 days, 21:08, 2 users, load average: 3.72, 1.00, 0.38
      10:57:07 up 23 days, 21:08, 2 users, load average: 4.30, 1.17, 0.44
      10:57:12 up 23 days, 21:08, 2 users, load average: 4.76, 1.31, 0.49
      10:57:17 up 23 days, 21:08, 2 users, load average: 5.18, 1.46, 0.54
      10:57:22 up 23 days, 21:08, 2 users, load average: 5.56, 1.60, 0.59
      10:57:27 up 23 days, 21:08, 2 users, load average: 5.92, 1.74, 0.64
      10:57:32 up 23 days, 21:08, 2 users, load average: 6.25, 1.87, 0.69
      10:57:37 up 23 days, 21:08, 2 users, load average: 6.55, 2.01, 0.74
      10:57:42 up 23 days, 21:09, 2 users, load average: 6.82, 2.14, 0.79
      10:57:47 up 23 days, 21:09, 2 users, load average: 7.08, 2.27, 0.84
      10:57:52 up 23 days, 21:09, 2 users, load average: 7.31, 2.40, 0.89
      10:57:57 up 23 days, 21:09, 2 users, load average: 7.53, 2.53, 0.94
      10:58:02 up 23 days, 21:09, 2 users, load average: 8.20, 2.75, 1.02
      10:58:07 up 23 days, 21:09, 2 users, load average: 8.83, 2.97, 1.10
      10:58:12 up 23 days, 21:09, 2 users, load average: 9.40, 3.19, 1.18
      10:58:17 up 23 days, 21:09, 2 users, load average: 9.93, 3.40, 1.26
    • I restart the webapp process here, and the load average slowly decays back to baseline **
      11:00:59 up 23 days, 21:12, 2 users, load average: 1.62, 3.18, 1.59
      11:01:04 up 23 days, 21:12, 2 users, load average: 1.49, 3.13, 1.58
      11:01:09 up 23 days, 21:12, 2 users, load average: 1.37, 3.07, 1.57
      11:01:14 up 23 days, 21:12, 2 users, load average: 1.26, 3.02, 1.56
      11:01:19 up 23 days, 21:12, 2 users, load average: 1.16, 2.97, 1.55
      11:01:24 up 23 days, 21:12, 2 users, load average: 1.06, 2.92, 1.54
      11:01:29 up 23 days, 21:12, 2 users, load average: 0.98, 2.87, 1.54
      11:01:34 up 23 days, 21:12, 2 users, load average: 0.90, 2.83, 1.53
      11:01:39 up 23 days, 21:12, 2 users, load average: 0.83, 2.78, 1.52
      11:01:44 up 23 days, 21:13, 2 users, load average: 0.76, 2.73, 1.51
      11:01:49 up 23 days, 21:13, 2 users, load average: 0.70, 2.69, 1.50
      11:01:54 up 23 days, 21:13, 2 users, load average: 0.64, 2.64, 1.50
      11:01:59 up 23 days, 21:13, 2 users, load average: 0.59, 2.60, 1.49
      11:02:04 up 23 days, 21:13, 2 users, load average: 0.54, 2.55, 1.48
      11:02:09 up 23 days, 21:13, 2 users, load average: 0.50, 2.51, 1.47
      11:02:14 up 23 days, 21:13, 2 users, load average: 0.54, 2.49, 1.47
      11:02:19 up 23 days, 21:13, 2 users, load average: 0.58, 2.46, 1.46
      11:02:24 up 23 days, 21:13, 2 users, load average: 0.53, 2.42, 1.46
Show
Andy Ellsworth added a comment - Here's a load average profile taken immediately after hitting the box with a ton of IE requests in a very short amount of time: Baseline - webapp running, system idle ** 10:54:57 up 23 days, 21:06, 2 users, load average: 0.02, 0.05, 0.06 10:55:02 up 23 days, 21:06, 2 users, load average: 0.02, 0.05, 0.06 10:55:07 up 23 days, 21:06, 2 users, load average: 0.02, 0.05, 0.06 10:55:12 up 23 days, 21:06, 2 users, load average: 0.02, 0.05, 0.06 10:55:17 up 23 days, 21:06, 2 users, load average: 0.01, 0.04, 0.06 10:55:22 up 23 days, 21:06, 2 users, load average: 0.09, 0.06, 0.06 10:55:27 up 23 days, 21:06, 2 users, load average: 0.16, 0.08, 0.07 10:55:32 up 23 days, 21:06, 2 users, load average: 0.15, 0.07, 0.07 10:55:37 up 23 days, 21:06, 2 users, load average: 0.14, 0.07, 0.07 10:55:42 up 23 days, 21:07, 2 users, load average: 0.21, 0.09, 0.07 10:55:47 up 23 days, 21:07, 2 users, load average: 0.19, 0.09, 0.07 10:55:52 up 23 days, 21:07, 2 users, load average: 0.18, 0.08, 0.07 10:55:57 up 23 days, 21:07, 2 users, load average: 0.24, 0.10, 0.08 10:56:02 up 23 days, 21:07, 2 users, load average: 0.22, 0.10, 0.08 10:56:07 up 23 days, 21:07, 2 users, load average: 0.20, 0.10, 0.08 10:56:12 up 23 days, 21:07, 2 users, load average: 0.35, 0.13, 0.09 10:56:17 up 23 days, 21:07, 2 users, load average: 0.48, 0.16, 0.10 10:56:22 up 23 days, 21:07, 2 users, load average: 0.60, 0.19, 0.11 IE9 logs in, pulls some reports for 5 seconds and then sits idle ** Hung threads start accumulating here ** 10:56:27 up 23 days, 21:07, 2 users, load average: 1.03, 0.28, 0.14 10:56:32 up 23 days, 21:07, 2 users, load average: 1.43, 0.38, 0.17 10:56:37 up 23 days, 21:07, 2 users, load average: 1.80, 0.47, 0.20 10:56:42 up 23 days, 21:08, 2 users, load average: 2.13, 0.56, 0.23 10:56:47 up 23 days, 21:08, 2 users, load average: 2.04, 0.57, 0.23 10:56:52 up 23 days, 21:08, 2 users, load average: 2.36, 0.66, 0.27 10:56:57 up 23 days, 21:08, 2 users, load average: 2.65, 0.75, 0.30 10:57:02 up 23 days, 21:08, 2 users, load average: 3.72, 1.00, 0.38 10:57:07 up 23 days, 21:08, 2 users, load average: 4.30, 1.17, 0.44 10:57:12 up 23 days, 21:08, 2 users, load average: 4.76, 1.31, 0.49 10:57:17 up 23 days, 21:08, 2 users, load average: 5.18, 1.46, 0.54 10:57:22 up 23 days, 21:08, 2 users, load average: 5.56, 1.60, 0.59 10:57:27 up 23 days, 21:08, 2 users, load average: 5.92, 1.74, 0.64 10:57:32 up 23 days, 21:08, 2 users, load average: 6.25, 1.87, 0.69 10:57:37 up 23 days, 21:08, 2 users, load average: 6.55, 2.01, 0.74 10:57:42 up 23 days, 21:09, 2 users, load average: 6.82, 2.14, 0.79 10:57:47 up 23 days, 21:09, 2 users, load average: 7.08, 2.27, 0.84 10:57:52 up 23 days, 21:09, 2 users, load average: 7.31, 2.40, 0.89 10:57:57 up 23 days, 21:09, 2 users, load average: 7.53, 2.53, 0.94 10:58:02 up 23 days, 21:09, 2 users, load average: 8.20, 2.75, 1.02 10:58:07 up 23 days, 21:09, 2 users, load average: 8.83, 2.97, 1.10 10:58:12 up 23 days, 21:09, 2 users, load average: 9.40, 3.19, 1.18 10:58:17 up 23 days, 21:09, 2 users, load average: 9.93, 3.40, 1.26 I restart the webapp process here, and the load average slowly decays back to baseline ** 11:00:59 up 23 days, 21:12, 2 users, load average: 1.62, 3.18, 1.59 11:01:04 up 23 days, 21:12, 2 users, load average: 1.49, 3.13, 1.58 11:01:09 up 23 days, 21:12, 2 users, load average: 1.37, 3.07, 1.57 11:01:14 up 23 days, 21:12, 2 users, load average: 1.26, 3.02, 1.56 11:01:19 up 23 days, 21:12, 2 users, load average: 1.16, 2.97, 1.55 11:01:24 up 23 days, 21:12, 2 users, load average: 1.06, 2.92, 1.54 11:01:29 up 23 days, 21:12, 2 users, load average: 0.98, 2.87, 1.54 11:01:34 up 23 days, 21:12, 2 users, load average: 0.90, 2.83, 1.53 11:01:39 up 23 days, 21:12, 2 users, load average: 0.83, 2.78, 1.52 11:01:44 up 23 days, 21:13, 2 users, load average: 0.76, 2.73, 1.51 11:01:49 up 23 days, 21:13, 2 users, load average: 0.70, 2.69, 1.50 11:01:54 up 23 days, 21:13, 2 users, load average: 0.64, 2.64, 1.50 11:01:59 up 23 days, 21:13, 2 users, load average: 0.59, 2.60, 1.49 11:02:04 up 23 days, 21:13, 2 users, load average: 0.54, 2.55, 1.48 11:02:09 up 23 days, 21:13, 2 users, load average: 0.50, 2.51, 1.47 11:02:14 up 23 days, 21:13, 2 users, load average: 0.54, 2.49, 1.47 11:02:19 up 23 days, 21:13, 2 users, load average: 0.58, 2.46, 1.46 11:02:24 up 23 days, 21:13, 2 users, load average: 0.53, 2.42, 1.46
Hide
Permalink
Andy Ellsworth added a comment -

I've created a fresh clean x64 virtual machine with CentOS 5.7, OpenNMS 1.9.91, and JDK 6u27 that can reproduce this issue at will. As soon as I've got it packaged and posted I'll provide a download link.

Show
Andy Ellsworth added a comment - I've created a fresh clean x64 virtual machine with CentOS 5.7, OpenNMS 1.9.91, and JDK 6u27 that can reproduce this issue at will. As soon as I've got it packaged and posted I'll provide a download link.
Hide
Permalink
Joakim Erdfelt added a comment -

We have the VMWare image up and running and are testing it today.
Thanks for the awesome bug reporting!

Show
Joakim Erdfelt added a comment - We have the VMWare image up and running and are testing it today. Thanks for the awesome bug reporting!
Hide
Permalink
Joakim Erdfelt added a comment -

Just to confirm that we have been able to reproduce the bug as you described it.
We are investigating the root cause now.
(This might take a while, please be patient)

Show
Joakim Erdfelt added a comment - Just to confirm that we have been able to reproduce the bug as you described it. We are investigating the root cause now. (This might take a while, please be patient)
Hide
Permalink
Andy Ellsworth added a comment -

That's great news! Getting the right people to reproduce it is at least half the battle.

Show
Andy Ellsworth added a comment - That's great news! Getting the right people to reproduce it is at least half the battle.
Hide
Permalink
Joakim Erdfelt added a comment -

Just a minor update: (for the benefit of the other Jetty devs)

The spinning thread, according to jconsole (w/JTop plugin installed), has the following stackdumps.
(Depending on when the stackdumps are being taken)

"qtp1787729660-360" prio=10 tid=0x0000000047bcd800 nid=0x2187 runnable [0x000000004e605000]
java.lang.Thread.State: RUNNABLE
at java.lang.Throwable.fillInStackTrace(Native Method)

  • locked <0x00000000eba285b8> (a javax.net.ssl.SSLException)
    at java.lang.Throwable. (Throwable.java:196)
    at java.lang.Exception. (Exception.java:41)
    at java.io.IOException. (IOException.java:41)
    at javax.net.ssl.SSLException. (SSLException.java:33)
    at com.sun.net.ssl.internal.ssl.SSLSocketImpl.checkEOF(SSLSocketImpl.java:1293)
    at com.sun.net.ssl.internal.ssl.AppInputStream.read(AppInputStream.java:65)
  • locked <0x00000000f6fa1bd8> (a com.sun.net.ssl.internal.ssl.AppInputStream)
    at org.eclipse.jetty.io.ByteArrayBuffer.readFrom(ByteArrayBuffer.java:388)
    at org.eclipse.jetty.io.bio.StreamEndPoint.fill(StreamEndPoint.java:132)
    at org.eclipse.jetty.server.bio.SocketConnector$ConnectorEndPoint.fill(SocketConnector.java:209)
    at org.eclipse.jetty.server.ssl.SslSocketConnector$SslConnectorEndPoint.fill(SslSocketConnector.java:612)
    at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:289)
    at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:214)
    at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:411)
    at org.eclipse.jetty.server.bio.SocketConnector$ConnectorEndPoint.run(SocketConnector.java:241)
    at org.eclipse.jetty.server.ssl.SslSocketConnector$SslConnectorEndPoint.run(SslSocketConnector.java:664)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:529)
    at java.lang.Thread.run(Thread.java:662)

"qtp1787729660-360" prio=10 tid=0x0000000047bcd800 nid=0x2187 runnable [0x000000004e605000]
java.lang.Thread.State: RUNNABLE
at java.lang.StringBuilder.append(StringBuilder.java:119)
at com.sun.net.ssl.internal.ssl.SSLSocketImpl.checkEOF(SSLSocketImpl.java:1293)
at com.sun.net.ssl.internal.ssl.AppInputStream.read(AppInputStream.java:65)

  • locked <0x00000000f6fa1bd8> (a com.sun.net.ssl.internal.ssl.AppInputStream)
    at org.eclipse.jetty.io.ByteArrayBuffer.readFrom(ByteArrayBuffer.java:388)
    at org.eclipse.jetty.io.bio.StreamEndPoint.fill(StreamEndPoint.java:132)
    at org.eclipse.jetty.server.bio.SocketConnector$ConnectorEndPoint.fill(SocketConnector.java:209)
    at org.eclipse.jetty.server.ssl.SslSocketConnector$SslConnectorEndPoint.fill(SslSocketConnector.java:612)
    at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:289)
    at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:214)
    at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:411)
    at org.eclipse.jetty.server.bio.SocketConnector$ConnectorEndPoint.run(SocketConnector.java:241)
    at org.eclipse.jetty.server.ssl.SslSocketConnector$SslConnectorEndPoint.run(SslSocketConnector.java:664)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:529)
    at java.lang.Thread.run(Thread.java:662)
Show
Joakim Erdfelt added a comment - Just a minor update: (for the benefit of the other Jetty devs) The spinning thread, according to jconsole (w/JTop plugin installed), has the following stackdumps. (Depending on when the stackdumps are being taken) "qtp1787729660-360" prio=10 tid=0x0000000047bcd800 nid=0x2187 runnable [0x000000004e605000] java.lang.Thread.State: RUNNABLE at java.lang.Throwable.fillInStackTrace(Native Method) locked <0x00000000eba285b8> (a javax.net.ssl.SSLException) at java.lang.Throwable. (Throwable.java:196) at java.lang.Exception. (Exception.java:41) at java.io.IOException. (IOException.java:41) at javax.net.ssl.SSLException. (SSLException.java:33) at com.sun.net.ssl.internal.ssl.SSLSocketImpl.checkEOF(SSLSocketImpl.java:1293) at com.sun.net.ssl.internal.ssl.AppInputStream.read(AppInputStream.java:65) locked <0x00000000f6fa1bd8> (a com.sun.net.ssl.internal.ssl.AppInputStream) at org.eclipse.jetty.io.ByteArrayBuffer.readFrom(ByteArrayBuffer.java:388) at org.eclipse.jetty.io.bio.StreamEndPoint.fill(StreamEndPoint.java:132) at org.eclipse.jetty.server.bio.SocketConnector$ConnectorEndPoint.fill(SocketConnector.java:209) at org.eclipse.jetty.server.ssl.SslSocketConnector$SslConnectorEndPoint.fill(SslSocketConnector.java:612) at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:289) at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:214) at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:411) at org.eclipse.jetty.server.bio.SocketConnector$ConnectorEndPoint.run(SocketConnector.java:241) at org.eclipse.jetty.server.ssl.SslSocketConnector$SslConnectorEndPoint.run(SslSocketConnector.java:664) at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:529) at java.lang.Thread.run(Thread.java:662) "qtp1787729660-360" prio=10 tid=0x0000000047bcd800 nid=0x2187 runnable [0x000000004e605000] java.lang.Thread.State: RUNNABLE at java.lang.StringBuilder.append(StringBuilder.java:119) at com.sun.net.ssl.internal.ssl.SSLSocketImpl.checkEOF(SSLSocketImpl.java:1293) at com.sun.net.ssl.internal.ssl.AppInputStream.read(AppInputStream.java:65) locked <0x00000000f6fa1bd8> (a com.sun.net.ssl.internal.ssl.AppInputStream) at org.eclipse.jetty.io.ByteArrayBuffer.readFrom(ByteArrayBuffer.java:388) at org.eclipse.jetty.io.bio.StreamEndPoint.fill(StreamEndPoint.java:132) at org.eclipse.jetty.server.bio.SocketConnector$ConnectorEndPoint.fill(SocketConnector.java:209) at org.eclipse.jetty.server.ssl.SslSocketConnector$SslConnectorEndPoint.fill(SslSocketConnector.java:612) at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:289) at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:214) at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:411) at org.eclipse.jetty.server.bio.SocketConnector$ConnectorEndPoint.run(SocketConnector.java:241) at org.eclipse.jetty.server.ssl.SslSocketConnector$SslConnectorEndPoint.run(SslSocketConnector.java:664) at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:529) at java.lang.Thread.run(Thread.java:662)
Hide
Permalink
Joakim Erdfelt added a comment -

For other jetty devs (above tests are using the jetty embedded within the OpenNMS distribution)

[root@localhost opennms]# find lib -name "jetty"
lib/jetty-jsp-2.1-7.4.0.v20110414.jar
lib/jetty-xml-7.4.0.v20110414.jar
lib/jetty-http-7.4.0.v20110414.jar
lib/opennms-jetty-1.9.91.jar
lib/jetty-security-7.4.0.v20110414.jar
lib/jetty-continuation-7.4.0.v20110414.jar
lib/jetty-server-7.4.0.v20110414.jar
lib/jetty-util-7.4.0.v20110414.jar
lib/jetty-webapp-7.4.0.v20110414.jar
lib/jetty-ajp-7.4.0.v20110414.jar
lib/jetty-io-7.4.0.v20110414.jar
lib/jetty-servlet-7.4.0.v20110414.jar

Show
Joakim Erdfelt added a comment - For other jetty devs (above tests are using the jetty embedded within the OpenNMS distribution) [root@localhost opennms] # find lib -name " jetty " lib/jetty-jsp-2.1-7.4.0.v20110414.jar lib/jetty-xml-7.4.0.v20110414.jar lib/jetty-http-7.4.0.v20110414.jar lib/opennms-jetty-1.9.91.jar lib/jetty-security-7.4.0.v20110414.jar lib/jetty-continuation-7.4.0.v20110414.jar lib/jetty-server-7.4.0.v20110414.jar lib/jetty-util-7.4.0.v20110414.jar lib/jetty-webapp-7.4.0.v20110414.jar lib/jetty-ajp-7.4.0.v20110414.jar lib/jetty-io-7.4.0.v20110414.jar lib/jetty-servlet-7.4.0.v20110414.jar
Hide
Permalink
Joakim Erdfelt added a comment -

Note:
Upgrading opennms to jetty-7.5.1.v20110908 eliminates this bug apparently.

How to upgrade OpenNMS to jetty-7.5.1

In the original opennms/lib/ directory remove the following files.

ecj-3.5.1.jar
jetty-ajp-7.4.0.v20110414.jar
jetty-continuation-7.4.0.v20110414.jar
jetty-http-7.4.0.v20110414.jar
jetty-io-7.4.0.v20110414.jar
jetty-jsp-2.1-7.4.0.v20110414.jar
jetty-security-7.4.0.v20110414.jar
jetty-server-7.4.0.v20110414.jar
jetty-servlet-7.4.0.v20110414.jar
jetty-util-7.4.0.v20110414.jar
jetty-webapp-7.4.0.v20110414.jar
jetty-xml-7.4.0.v20110414.jar
jsp-2.1-glassfish-2.1.v20100127.jar
jsp-api-2.1-glassfish-2.1.v20100127.jar
jstl-1.1.2.jar
slf4j-api-1.5.11.jar
slf4j-log4j12-1.5.11.jar
standard-1.1.2.jar

Download the jetty distribution for 7.5.1
$ cd /opt/opennms
$ curl -O http://repo1.maven.org/maven2/org/eclipse/jetty/jetty-distribution/7.5.1.v20110908/jetty-distribution-7.5.1.v20110908.tar.gz

Unpack the distribution
$ jar -cvf jetty-distribution-7.5.1.v20110908.tar.gz

Copy the following files from
$ cd jetty-distribution-7.5.1.v20110908/lib/
$ cp jetty-ajp-*.jar /opt/opennms/lib/
$ cp jetty-http-*.jar /opt/opennms/lib/
$ cp jetty-io-*.jar /opt/opennms/lib/
$ cp jetty-security-*.jar /opt/opennms/lib/
$ cp jetty-server-*.jar /opt/opennms/lib/
$ cp jetty-servlet-*.jar /opt/opennms/lib/
$ cp jetty-util-*.jar /opt/opennms/lib/
$ cp jetty-webapp-*.jar /opt/opennms/lib/
$ cp jetty-xml-*.jar /opt/opennms/lib/
$ cp jsp/* /opt/opennms/lib/

Almost done, we need updated SLF4J jars too.
$ cd /opt/opennms/lib
$ curl -O http://repo1.maven.org/maven2/org/slf4j/slf4j-api/1.6.1/slf4j-api-1.6.1.jar
$ curl -O http://repo1.maven.org/maven2/org/slf4j/slf4j-log4j12/1.6.1/slf4j-log4j12-1.6.1.jar

Now, since we have an updated JSTL usage we need to upgrade our use of JSTL with these opennms webapps.
However, opennms assumes that the webapp can access jar file resources through the WebAppClassloader barrier
(which is false), so we have to copy the JSTL jar into place for those webapps to use in the WebApp isolated
classloader.

$ cd /opt/opennms/jetty-webapps/opennms/WEB-INF/lib
$ curl -O http://repo1.maven.org/maven2/javax/servlet/jstl/1.2/jstl-1.2.jar

Done.
Restart OpenNMS.

Note: here's the difference in the lib directory after the changes.

[root@localhost opennms]# diff -rq lib-orig/ lib-7.5.1/ | sort
Only in lib-7.5.1/: com.sun.el_1.0.0.v201004190952.jar
Only in lib-7.5.1/: ecj-3.6.jar
Only in lib-7.5.1/: javax.el_2.1.0.v201004190952.jar
Only in lib-7.5.1/: javax.servlet.jsp_2.1.0.v201004190952.jar
Only in lib-7.5.1/: javax.servlet.jsp.jstl_1.2.0.v201004190952.jar
Only in lib-7.5.1/: jetty-ajp-7.5.1.v20110908.jar
Only in lib-7.5.1/: jetty-continuation-7.5.1.v20110908.jar
Only in lib-7.5.1/: jetty-http-7.5.1.v20110908.jar
Only in lib-7.5.1/: jetty-io-7.5.1.v20110908.jar
Only in lib-7.5.1/: jetty-jsp-2.1-7.5.1.v20110908.jar
Only in lib-7.5.1/: jetty-security-7.5.1.v20110908.jar
Only in lib-7.5.1/: jetty-server-7.5.1.v20110908.jar
Only in lib-7.5.1/: jetty-servlet-7.5.1.v20110908.jar
Only in lib-7.5.1/: jetty-util-7.5.1.v20110908.jar
Only in lib-7.5.1/: jetty-webapp-7.5.1.v20110908.jar
Only in lib-7.5.1/: jetty-xml-7.5.1.v20110908.jar
Only in lib-7.5.1/: jsp-impl-2.1.3-b10.jar
Only in lib-7.5.1/: org.apache.taglibs.standard.glassfish_1.2.0.v201004190952.jar
Only in lib-7.5.1/: slf4j-api-1.6.1.jar
Only in lib-7.5.1/: slf4j-log4j12-1.6.1.jar
Only in lib-orig/: ecj-3.5.1.jar
Only in lib-orig/: jetty-ajp-7.4.0.v20110414.jar
Only in lib-orig/: jetty-continuation-7.4.0.v20110414.jar
Only in lib-orig/: jetty-http-7.4.0.v20110414.jar
Only in lib-orig/: jetty-io-7.4.0.v20110414.jar
Only in lib-orig/: jetty-jsp-2.1-7.4.0.v20110414.jar
Only in lib-orig/: jetty-security-7.4.0.v20110414.jar
Only in lib-orig/: jetty-server-7.4.0.v20110414.jar
Only in lib-orig/: jetty-servlet-7.4.0.v20110414.jar
Only in lib-orig/: jetty-util-7.4.0.v20110414.jar
Only in lib-orig/: jetty-webapp-7.4.0.v20110414.jar
Only in lib-orig/: jetty-xml-7.4.0.v20110414.jar
Only in lib-orig/: jsp-2.1-glassfish-2.1.v20100127.jar
Only in lib-orig/: jsp-api-2.1-glassfish-2.1.v20100127.jar
Only in lib-orig/: jstl-1.1.2.jar
Only in lib-orig/: slf4j-api-1.5.11.jar
Only in lib-orig/: slf4j-log4j12-1.5.11.jar
Only in lib-orig/: standard-1.1.2.jar

Show
Joakim Erdfelt added a comment - Note: Upgrading opennms to jetty-7.5.1.v20110908 eliminates this bug apparently. How to upgrade OpenNMS to jetty-7.5.1 In the original opennms/lib/ directory remove the following files. ecj-3.5.1.jar jetty-ajp-7.4.0.v20110414.jar jetty-continuation-7.4.0.v20110414.jar jetty-http-7.4.0.v20110414.jar jetty-io-7.4.0.v20110414.jar jetty-jsp-2.1-7.4.0.v20110414.jar jetty-security-7.4.0.v20110414.jar jetty-server-7.4.0.v20110414.jar jetty-servlet-7.4.0.v20110414.jar jetty-util-7.4.0.v20110414.jar jetty-webapp-7.4.0.v20110414.jar jetty-xml-7.4.0.v20110414.jar jsp-2.1-glassfish-2.1.v20100127.jar jsp-api-2.1-glassfish-2.1.v20100127.jar jstl-1.1.2.jar slf4j-api-1.5.11.jar slf4j-log4j12-1.5.11.jar standard-1.1.2.jar Download the jetty distribution for 7.5.1 $ cd /opt/opennms $ curl -O http://repo1.maven.org/maven2/org/eclipse/jetty/jetty-distribution/7.5.1.v20110908/jetty-distribution-7.5.1.v20110908.tar.gz Unpack the distribution $ jar -cvf jetty-distribution-7.5.1.v20110908.tar.gz Copy the following files from $ cd jetty-distribution-7.5.1.v20110908/lib/ $ cp jetty-ajp-*.jar /opt/opennms/lib/ $ cp jetty-http-*.jar /opt/opennms/lib/ $ cp jetty-io-*.jar /opt/opennms/lib/ $ cp jetty-security-*.jar /opt/opennms/lib/ $ cp jetty-server-*.jar /opt/opennms/lib/ $ cp jetty-servlet-*.jar /opt/opennms/lib/ $ cp jetty-util-*.jar /opt/opennms/lib/ $ cp jetty-webapp-*.jar /opt/opennms/lib/ $ cp jetty-xml-*.jar /opt/opennms/lib/ $ cp jsp/* /opt/opennms/lib/ Almost done, we need updated SLF4J jars too. $ cd /opt/opennms/lib $ curl -O http://repo1.maven.org/maven2/org/slf4j/slf4j-api/1.6.1/slf4j-api-1.6.1.jar $ curl -O http://repo1.maven.org/maven2/org/slf4j/slf4j-log4j12/1.6.1/slf4j-log4j12-1.6.1.jar Now, since we have an updated JSTL usage we need to upgrade our use of JSTL with these opennms webapps. However, opennms assumes that the webapp can access jar file resources through the WebAppClassloader barrier (which is false), so we have to copy the JSTL jar into place for those webapps to use in the WebApp isolated classloader. $ cd /opt/opennms/jetty-webapps/opennms/WEB-INF/lib $ curl -O http://repo1.maven.org/maven2/javax/servlet/jstl/1.2/jstl-1.2.jar Done. Restart OpenNMS. Note: here's the difference in the lib directory after the changes. [root@localhost opennms] # diff -rq lib-orig/ lib-7.5.1/ | sort Only in lib-7.5.1/: com.sun.el_1.0.0.v201004190952.jar Only in lib-7.5.1/: ecj-3.6.jar Only in lib-7.5.1/: javax.el_2.1.0.v201004190952.jar Only in lib-7.5.1/: javax.servlet.jsp_2.1.0.v201004190952.jar Only in lib-7.5.1/: javax.servlet.jsp.jstl_1.2.0.v201004190952.jar Only in lib-7.5.1/: jetty-ajp-7.5.1.v20110908.jar Only in lib-7.5.1/: jetty-continuation-7.5.1.v20110908.jar Only in lib-7.5.1/: jetty-http-7.5.1.v20110908.jar Only in lib-7.5.1/: jetty-io-7.5.1.v20110908.jar Only in lib-7.5.1/: jetty-jsp-2.1-7.5.1.v20110908.jar Only in lib-7.5.1/: jetty-security-7.5.1.v20110908.jar Only in lib-7.5.1/: jetty-server-7.5.1.v20110908.jar Only in lib-7.5.1/: jetty-servlet-7.5.1.v20110908.jar Only in lib-7.5.1/: jetty-util-7.5.1.v20110908.jar Only in lib-7.5.1/: jetty-webapp-7.5.1.v20110908.jar Only in lib-7.5.1/: jetty-xml-7.5.1.v20110908.jar Only in lib-7.5.1/: jsp-impl-2.1.3-b10.jar Only in lib-7.5.1/: org.apache.taglibs.standard.glassfish_1.2.0.v201004190952.jar Only in lib-7.5.1/: slf4j-api-1.6.1.jar Only in lib-7.5.1/: slf4j-log4j12-1.6.1.jar Only in lib-orig/: ecj-3.5.1.jar Only in lib-orig/: jetty-ajp-7.4.0.v20110414.jar Only in lib-orig/: jetty-continuation-7.4.0.v20110414.jar Only in lib-orig/: jetty-http-7.4.0.v20110414.jar Only in lib-orig/: jetty-io-7.4.0.v20110414.jar Only in lib-orig/: jetty-jsp-2.1-7.4.0.v20110414.jar Only in lib-orig/: jetty-security-7.4.0.v20110414.jar Only in lib-orig/: jetty-server-7.4.0.v20110414.jar Only in lib-orig/: jetty-servlet-7.4.0.v20110414.jar Only in lib-orig/: jetty-util-7.4.0.v20110414.jar Only in lib-orig/: jetty-webapp-7.4.0.v20110414.jar Only in lib-orig/: jetty-xml-7.4.0.v20110414.jar Only in lib-orig/: jsp-2.1-glassfish-2.1.v20100127.jar Only in lib-orig/: jsp-api-2.1-glassfish-2.1.v20100127.jar Only in lib-orig/: jstl-1.1.2.jar Only in lib-orig/: slf4j-api-1.5.11.jar Only in lib-orig/: slf4j-log4j12-1.5.11.jar Only in lib-orig/: standard-1.1.2.jar
Hide
Permalink
Andy Ellsworth added a comment -

Very nice! Thanks for the detail on how to drop in 7.5.1 on top of OpenNMS. I tried to test that version with OpenNMS when isolating the bug, but wasn't clueful enough to pull it off.

I'll apply your changes to our environment and test.

Show
Andy Ellsworth added a comment - Very nice! Thanks for the detail on how to drop in 7.5.1 on top of OpenNMS. I tried to test that version with OpenNMS when isolating the bug, but wasn't clueful enough to pull it off. I'll apply your changes to our environment and test.
Hide
Permalink
Joakim Erdfelt added a comment -

btw, a very handy blog entry on identifying a thread with high cpu usage.
http://www.onkarjoshi.com/blog/166/identifying-a-thread-with-high-cpu-usage-in-a-java-app/

(added here for reference at a later date)

Show
Joakim Erdfelt added a comment - btw, a very handy blog entry on identifying a thread with high cpu usage. http://www.onkarjoshi.com/blog/166/identifying-a-thread-with-high-cpu-usage-in-a-java-app/ (added here for reference at a later date)
Hide
Permalink
Andy Ellsworth added a comment -

Confirmed - OpenNMS 1.9.91 + Jetty 7.5.1 = no bug. Thanks for your diligence.

I'll suggest to the OpenNMS team that they migrate to 7.5.1 since it seems to work fine there. Out of curiosity, is the 7.4 line still being developed?

Show
Andy Ellsworth added a comment - Confirmed - OpenNMS 1.9.91 + Jetty 7.5.1 = no bug. Thanks for your diligence. I'll suggest to the OpenNMS team that they migrate to 7.5.1 since it seems to work fine there. Out of curiosity, is the 7.4 line still being developed?
Hide
Permalink
Greg Wilkins added a comment -

7.4 is not being developed and 7.5 is a pretty natural upgrade path, with only a few uncommonly used API changes.

Show
Greg Wilkins added a comment - 7.4 is not being developed and 7.5 is a pretty natural upgrade path, with only a few uncommonly used API changes.
Hide
Permalink
Andy Ellsworth added a comment -

Sounds reasonable. I'll let you gentlemen close the bug with whatever resolved-in version you see fit. Thanks for the assist.

Show
Andy Ellsworth added a comment - Sounds reasonable. I'll let you gentlemen close the bug with whatever resolved-in version you see fit. Thanks for the assist.
Hide
Permalink
Joakim Erdfelt added a comment -

Fixed at some point between jetty 7.4.0 and 7.5.1.
Exact cause of bug in 7.4.0 still not known.

Show
Joakim Erdfelt added a comment - Fixed at some point between jetty 7.4.0 and 7.5.1. Exact cause of bug in 7.4.0 still not known.

People

  • Assignee:
    Joakim Erdfelt
    Reporter:
    Andy Ellsworth
Vote (0)
Watch (0)

Dates

  • Created:
    Updated:
    Resolved: