jetty / jetty.project

Eclipse Jetty® - Web Container & Clients - supports HTTP/2, HTTP/1.1, HTTP/1.0, websocket, servlets, and more
https://eclipse.dev/jetty
Other
3.84k stars 1.91k forks source link

Jetty CPU usage remains high even without any traffic #7010

Closed andrewxian closed 1 year ago

andrewxian commented 2 years ago

Jetty version(s) 9.4.6

Java version/vendor (use: java -version) java -version java version "1.8.0_144" Java(TM) SE Runtime Environment (build 1.8.0_144-b01) Java HotSpot(TM) 64-Bit Server VM (build 25.144-b01, mixed mode)

OS type/version Windows 10

Description We had an issue of CPU spike usage on the jetty server with little or no traffic on an idle node. Restarting the app (with Jetty) would fix the problem.

I used some top tools and saw several QTP threads had consumed most of the CPU usages with similar stack trace:

"qtp89505193-419510" prio=0 tid=419510 runnable java.lang.Thread.State: RUNNABLE Locked Monitors: java.util.ArrayDeque@5d4aa1d8 at org.eclipse.jetty.server.HttpInput.addContent(HttpInput.java:595) java.util.ArrayDeque@5d4aa1d8 at org.eclipse.jetty.server.HttpInput.consumeAll(HttpInput.java:675) at org.eclipse.jetty.server.HttpInput.addContent(HttpInput.java:595) at org.eclipse.jetty.server.HttpChannel.onContent(HttpChannel.java:597) at org.eclipse.jetty.server.HttpChannelOverHttp.content(HttpChannelOverHttp.java:247) at org.eclipse.jetty.http.HttpParser.parseContent(HttpParser.java:1613) at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:1384) at org.eclipse.jetty.server.HttpConnection.parseRequestBuffer(HttpConnection.java:351) at org.eclipse.jetty.server.HttpConnection.fillAndParseForContent(HttpConnection.java:286) at org.eclipse.jetty.server.HttpInputOverHTTP.produceContent(HttpInputOverHTTP.java:33) at org.eclipse.jetty.server.HttpInput.nextContent(HttpInput.java:345) at org.eclipse.jetty.server.HttpInput.consumeAll(HttpInput.java:675) at org.eclipse.jetty.server.HttpConnection.onCompleted(HttpConnection.java:413) at org.eclipse.jetty.server.HttpChannel.onCompleted(HttpChannel.java:633) at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:442) at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251) at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:279) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:110) at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:289) at org.eclipse.jetty.io.ssl.SslConnection$3.succeeded(SslConnection.java:149) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:110) at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:124) at org.eclipse.jetty.util.thread.Invocable.invokePreferred(Invocable.java:128) at org.eclipse.jetty.util.thread.Invocable$InvocableExecutor.invoke(Invocable.java:222) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:294) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:199) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:673) at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:591)

"qtp611006329-420121" prio=0 tid=420121 runnable java.lang.Thread.State: RUNNABLE Locked Monitors: java.util.ArrayDeque@52e65627 at org.eclipse.jetty.server.HttpInput.consumeAll(HttpInput.java:675) at java.nio.HeapByteBuffer.asReadOnlyBuffer(HeapByteBuffer.java:117) at org.eclipse.jetty.http.HttpParser.parseContent(HttpParser.java:1604) at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:1384) at org.eclipse.jetty.server.HttpConnection.parseRequestBuffer(HttpConnection.java:351) at org.eclipse.jetty.server.HttpConnection.fillAndParseForContent(HttpConnection.java:286) at org.eclipse.jetty.server.HttpInputOverHTTP.produceContent(HttpInputOverHTTP.java:33) at org.eclipse.jetty.server.HttpInput.nextContent(HttpInput.java:345) at org.eclipse.jetty.server.HttpInput.consumeAll(HttpInput.java:675) at org.eclipse.jetty.server.HttpConnection.onCompleted(HttpConnection.java:413) at org.eclipse.jetty.server.HttpChannel.onCompleted(HttpChannel.java:633) at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:442) at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251) at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:279) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:110) at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:289) at org.eclipse.jetty.io.ssl.SslConnection$3.succeeded(SslConnection.java:149) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:110) at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:124) at org.eclipse.jetty.util.thread.Invocable.invokePreferred(Invocable.java:128) at org.eclipse.jetty.util.thread.Invocable$InvocableExecutor.invoke(Invocable.java:222) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:294) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:199) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:673) at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:591) at java.lang.Thread.run(Thread.java:748)

I have some questions for the above two stack traces:

  1. Is the jetty server busy handling SSL connections?
  2. What could trigger the issue when the jetty server has little or no traffic?

How to reproduce? Unfortunately, I had no idea how to reproduce it.  The only thing worth mention is that issue happened every Saturday.

lachlan-roberts commented 2 years ago

@andrewxian Version 9.4.6 is very old, please upgrade to the latest version Jetty 9 (currently 9.4.44.v20210927). There has been many bug fixes and security fixes since 9.4.6 so it is likely the issue you are experiencing is fixed in the latest version.

andrewxian commented 2 years ago

Hi @lachlan-roberts,

Unfortunately, it is not easy for us to upgrade the jetty version as the issue happened on customer's site.
I agree with you that upgrading the jetty version is the best option, but it takes some procedures.

In the meantime, can I ask what jetty is trying to do in the stack trace? I would be very grateful if that could be explained to me.

Thanks.

joakime commented 2 years ago

In the meantime, can I ask what jetty is trying to do in the stack trace? I would be very grateful if that could be explained to me.

It appears to be reading/parsing from an SSL/TLS connection. Without a DEBUG log, the exact reason for this read/parse is unknown, the stacktrace just tells us a generic detail at that 1 point in time.

Also, an important note, since you are using SSL/TLS you must keep your JVM up to date.

Java 1.8.0_144 expired on October 17, 2017, and contains none of the updated SSL/TLS cryptograph databases and updated security configurations that being on the public facing internet requires when using SSL/TLS. See:

The reasons for your high CPU usage can easily be explained by the out of date cryptographic configuration with your JVM version. (Your JVM is working way harder to satisfy the requirements from everyone else that has upgraded HTTP clients or client environments. Example: your JVM is likely falling back to highly inefficient crypto providers as the better ones are simply not available on your JVM).

Since Java 1.8.0_144 entire SSL/TLS protocol levels have been whittled down and are now completely disabled in the JVM. Your configuration in 1.8.0_144 is almost guaranteed to be considered unsafe as you don't even have the newer protocols (and cipher suites) present in that old version of Java. Go ahead, test your site and see - https://www.ssllabs.com/ssltest/

The primary reasons for keeping your JVM up to date are (in order of priority)

  1. You are using SSL/TLS and need the current public internet crypto security settings. (this is changed and updated with every JVM release, see jdk crypto roadmap)
  2. You are a heavy user of Date / Time features, serving users from across multiple countries, and need up to date TimeZone / Locale data. (this is updated every month, every JVM release gets a new one. some environments like Linux can get this data updated separately from the JVM release)
  3. You need bug fixes of newer releases.
dimas commented 2 years ago

Given your CPU remains high even without any traffic, it could be something similar to the issue we had even though stacktrace is different - https://github.com/eclipse/jetty.project/issues/6973 In our case issue was triggered by problems in logback library but I believe the root cause is somewhere in Jetty code where some edge case allowed reading from already closed connection or something like that.

If you affected by something similar, I doubt you can just tune something to improve things. My suspicion is that in our case problem was triggered by some some guys running vulnerability scanners against us so we were seeing some invalid requests that kicked things off.

github-actions[bot] commented 1 year ago

This issue has been automatically marked as stale because it has been a full year without activity. It will be closed if no further activity occurs. Thank you for your contributions.

github-actions[bot] commented 1 year ago

This issue has been closed due to it having no activity.