Major websocket memory change in 9.4.36

[slipcon]

Jetty version(s)

We've been using 9.4.18 for a long time, but having trouble updating to the latest 9.4.x.
I've narrowed the problem down to starting in 9.4.36.

Java version/vendor (use: java -version)

openjdk version "11.0.2" 2019-01-15

OS type/version

Seen on multiple OSes - MacOS, Windows & Linux.

Description

Our application has a websocket servlet, which creates a class that extends WebSocketAdapter and calls session.getRemote().sendString( data, this ) to transmit JSON messages to the clients. The clients send data back to the server over the same websocket, but it is very minimal heartbeat/keepalive JSON objects.

Starting in 9.4.36, we start to see significant memory utilization very quickly - specifically in the HeapByteBuffer objects, eventually leading to memory exhaustion and crashes.

Disabling the permessage-deflate extension on the websocket fixes the issue, but we'd like to keep compression of the JSON messages on. Our largest JSON messages are on the order of 200Kbytes. We are not doing any sort of jetty memory tuning - and it has worked great prior to 9.4.36.

I suspect this change may be relevant: #5499

Please let me know if there is any more information I can provide or steps to try.

How to reproduce?

[joakime]

Upgrade.

Jetty 9.4.36 has a buffer aggregation bug fixed in PR #6056 that could be biting you.

Please always upgrade to the newest version in your major version space (you are using 9.4.x, which means 9.4.44.v20210927 is your best choice for upgrade)

BTW, version 9.4.36 is subject to several published security advisories - https://www.eclipse.org/jetty/security_reports.php

[slipcon]

Sorry I should have been clearer - all versions 9.4.36 and newer, including 9.4.44, show the same behavior for us. The security advisories are why we are trying to move forward from 9.4.18

[joakime]

openjdk version "11.0.2" 2019-01-15

This should be upgraded as well.
Version 11.0.2 expired on April 16, 2019
Version 11.0.12 is available. (note that this version expires on Oct 19, 2021, so keep an eye out for a newer release soon)

specifically in the HeapByteBuffer objects

I take it you did a memory dump?
Where are those HeapByteBuffers being held? Do you know the object and/or field that it holding them?

[slipcon]

Thanks again for your help - I have tried other JVMs, I don't think thats the issue but I will update to the latest next week to be sure.

I am using YourKit - have taken many memory dumps. Here's a path view of the object's path just a few minutes after starting the server, with just a couple of clients connected. On older Jetty (<= 9.4.35) the HeapByteBuffer retained size sticks around 500Kbyte, regardless of how long we run. On 9.4.36 and newer it grows quite quickly - like I said this example has only been running a couple of minutes.

That all said.... I upgraded to Jetty 10.0.6, and at initial tests, it appears to be fixed there, so maybe its a moot point for us.

[joakime]

@lachlan-roberts can you take a look here too?

[lachlan-roberts]

This looks like it would be related to this change from PR #5574 which was introduced in 9.4.36. This changes the WebSocket CompressExtension to use buffers from the ByteBufferPool instead of allocating temporary ones. I can't see any possible causes for a memory leak here. The logic for this is contained within ByteAccumulator which is always used from a try with resources block, so it should always be closed which will release the buffers.

@slipcon do you have a simple reproducer that I could run to debug this problem?

[ekoemets]

I think I am able to reproduce a similar issue in 9.4.44 that will lead to high heap memory usage with the following steps:

1. Start a basic WebSocket server that will just consume the message
2. Create a WebSocket client that uses the permessage-deflate extension
3. With client send a string message of random characters with size of ~200KB
4. Repeat the last step multiple times, each time increasing the message size by 10KB

I think what's happening here is that since each new message is larger than the last one, the already allocated buffers in the MappedByteBufferPool, which is the default ByteBufferPool implementation used in WebSocketServerFactory, cannot be used and so each time a new bigger buffer is allocated. Also by default maximum memory limit is not set on the MappedByteBufferPool so the allocated memory will never be actually released from the pool.

[gregw]

We definitely need to have a max pool size turned on by default. However, I think we also need to consider have exp. buffer buckets on by default (see #6538) as there is no good reason a 200KB message should use buffers from a different bucket to a 210KB message or 220KB message. Linear buckets are just wasteful.

@sbordet @lorban I remember that one of you had objections to the exp. buckets so we only did them as a demo rather than as a core algorithm. But I can't remember what that reason was? What is the reason to use linear bucket sizes again? Why are we violating Weber's Law?

[gregw]

@sbordet @lorban ping lachlan and me when you are up. We need to talk through a couple of things related to buffer pools

[slipcon]

To add a bit of context - and I'm happy to try to gather specific data if anyone wants me to.... unfortunately I don't have a simple reproducer example.... our application is pretty complex. I can reproduce it easily enough in my test environment, however, and would be happy to enable debug logging or run with a test release if it could help narrow the problem down.

Our Jetty application is the websocket server - the clients are javascript/browser based, so no Jetty involved on the client side of the websocket.

The messages are probably 99% or greater sent from the server to the clients. The clients only send back an empty JSON object ("{}") as a heartbeat every few seconds. The messages from server to clients are going to be a wide mix of sizes. Some are small, maybe a few hundred bytes. Others are quite large - maybe 150Kbytes. There is no reason that the messages would be growing significantly over time. I'd guess that within a few minutes a client would have seen a "normal" range of message sizes.

In an operational system, the server may have 100 or more clients connected simultaneously - each client would receive similar messages, but not necessarily exactly the same - the contents will vary depending on a lot of factors specific to our application.

Clearly when we test with the "bad" versions of Jetty for our usage, the heap grows faster when we have many clients connected - however I am able to see the problem (as above in YourKit) with only one client connected.

[gregw]

So looking through our buffer pool handling (mostly from 10, but perhaps also in 9.4) I have the following comments:

• We lack a lot of javadoc, specially with regards to what -1 means for max limits (does it mean no limit of a heuristic).
• In HttpConnection we findOrAdapt a RetainableByteBufferPool from a ByteBufferPool:
  • why is this necessary since AbstractConnector ensures a RetainableByteBufferPool exists?
  • The adapted pool isn't really retainable, can't we make it both retainable and use the underlying pool?
• In jetty-bytebufferpool.xml we pass in -1 for the max sizes. This is unlimited (rather than heuristic). I think an unlimited pool is just asking to be wasteful of memory.
• The pool default constructors are unlimited in size. Again, just asking to be wasteful.
• In AbstractConnector we will make a new default RetainableByteBufferPool with no size limits, even if a size limit has been placed on the ByteBufferPool in jetty-bytebufferpool.xml
  • At the very least the same limits should be used.
  • Better yet, the retainable pool should use the normal pool for it's buffers, so a single max size will apply to both pools

[lorban]

@gregw my objection with the exp. buffer buckets is the amount of "waste" that it's going to introduce which may have an impact on the minimal memory requirement one need to serve a certain throughput. What I call waste is memory that is reserved but isn't used, so it can be at most 1023 bytes with linear buckets, and next power / 2 - 1 with exp buckets.

TLS is a prime example because it needs buffers that are a just a few bytes over 16 KB, so the current impl uses 17 KB buffer, "wasting" a bit less than 1 KB per request. If we were going to use 32 KB buffers, we would waste a bit less than 16 KB per request, meaning that we'd potentially need around twice the amount of RAM in buffers for serving the same throughput.

[gregw]

Yep, the idea of building a RetainableByteBufferPool from an old ByteBufferPool is fundamentally broken because of the different paradigms. With the RBBP, buffers are always members of the pool, even if they are in-use (perhaps multiple times), whilst for a BBP, once a buffer is allocated, it is forgotten until it is released. Thus the max heap sizes are different things -for the RBBP it is the total memory in play, whilst for BBP it is only the memory that is currently un-allocated that is counted. Moreover, users of BBP can be lazy and if an error condition occurs they can just discard any buffers they hold without leaking, but for RBBP we have to ensure that a buffer is always released no matter what!

So these problems make it hard to have only one BP in the system as the two uses are incompatible and it is hard/impossible to mimic one BP as the other safely. Thus I think in the short term we need to expose configuration of both BPs types and then work to remove usage of the BBP in jetty-12 so there is only 1.

[sveniu]

Fwiw, we're likely seeing this issue as well, on Jetty v9.4.43. The jvm keeps growing in rss memory, most of which ends up in zlib's deflateInit2 (i.e. it's neither in the heap, non-heap, nor jvm "native memory"). With our workload, we run out of memory within a week or two, on 16 GB servers.

Profiler outputs attached, generated by libjemalloc's jeprof. One is with all compression extensions enabled (i.e. not explicitly disabled), while the other is with all three supported extensions disabled (deflate-frame, permessage-deflate, x-webkit-deflate-frame). I suspect it's jeprof's drop thresholds that make the outputs look so different. The main point about Deflater leakage gets across quite clearly, though.

For completeness sake, we're running with:

• LD_PRELOAD=/path/to/libjemalloc.so.2 (using jemalloc 5.2.1)
• MALLOC_CONF="prof:true,lg_prof_interval:30,lg_prof_sample:17" (writes jeprof.pid.x.y.heap files)
• perl jeprof --gif *.heap > out.gif (to generate the profile dumps)

I'm having trouble resolving the top-level symbols to see where java.util.zip.Deflater (and Inflater) is actually coming from. Any hints on that would be greatly appreciated. We're on Oracle jdk 8.

Instead, I managed to dump a 6 GB memory region (our heap is fixed at 3 GB) from /proc/pid/smaps:

7fc71c302000-7fc8b5c00000 rw-p 00000000 00:00 0 [stack:32042]
Size:            6710264 kB
Rss:             6636216 kB
Pss:             6636216 kB
[...]

Dumped in chunks using gdb (otherwise it would segfault):

gdb --batch --pid 24903 -ex "dump memory mem.0 0x7fc71c302000 0x7fc757cae9ff"
gdb --batch --pid 24903 -ex "dump memory mem.1 0x7fc757caea00 0x7fc79365b3ff"
gdb --batch --pid 24903 -ex "dump memory mem.2 0x7fc79365b400 0x7fc7cf007dff"
gdb --batch --pid 24903 -ex "dump memory mem.3 0x7fc7cf007e00 0x7fc80a9b47ff"
gdb --batch --pid 24903 -ex "dump memory mem.4 0x7fc80a9b4800 0x7fc8463611ff"
gdb --batch --pid 24903 -ex "dump memory mem.5 0x7fc846361200 0x7fc881d0dbff"
gdb --batch --pid 24903 -ex "dump memory mem.6 0x7fc881d0dc00 0x7fc8bd6ba600"

That memory consists mostly of uncompressed websocket payload, hence the suspicion that this issue is related.

[lachlan-roberts]

@sveniu with this issue you should only be seeing a build up in heap memory usage in the ByteBufferPool. I think your issue is more related to #300 than this one. We had attempted to fix by implementing pooling for Inflater / Deflater instances. In jetty-10 the default is sized to the max number of threads from the ThreadPool but looks to be default unlimited size in 9.4.

Can you take a Jetty Server dump? You should then be able to see lines indicating the size and capacity of the InflaterPools & DeflaterPools and we will see if this is related.

[sveniu]

@lachlan-roberts I've finally been able to produce the server dump. Here's the abridged dump, showing the InflaterPool and DeflaterPool info, with all other branches pruned.

+= o.e.j.s.ServletContextHandler@12d4bf7e{/,null,AVAILABLE} - STARTED
|  += ServletHandler@25d250c6{STARTED} - STARTED
|  |  +> filters ServletHandler@25d250c6{STARTED} size=2
|  |  |  +> Jetty_WebSocketUpgradeFilter==org.eclipse.jetty.websocket.server.WebSocketUpgradeFilter@28701274{inst=true,async=true,src=EMBEDDED:null} - STARTED
|  |  |  |  +> WebSocketUpgradeFilter[configuration=NativeWebSocketConfiguration@6a400542{STARTED}]
|  |  |  |  |  +> NativeWebSocketConfiguration@6a400542{STARTED} - STARTED
|  |  |  |  |     += WebSocketServerFactory@4b14c583[defaultPolicy=WebSocketPolicy@e056f20[behavior=SERVER,maxTextMessageSize=262044,maxTextMessageBufferSize=262044,maxBinaryMessageSize=65536,maxBinaryMessageBufferSize=262044,asyncWriteTimeout=60000,idleTimeout=300000,inputBufferSize=4096],creator=org.eclipse.jetty.websocket.server.WebSocketServerFactory] - STARTED
|  |  |  |  |     |  += WebSocketExtensionFactory@3e92efc3{STARTED} - STARTED
|  |  |  |  |     |     += InflaterPool@1622f1b{STARTED,size=7140,capacity=UNLIMITED} - STARTED
|  |  |  |  |     |     += DeflaterPool@72a7c7e0{STARTED,size=9932,capacity=UNLIMITED} - STARTED
|  += NativeWebSocketConfiguration@6a400542{STARTED} - STARTED
|  |  += WebSocketServerFactory@4b14c583[defaultPolicy=WebSocketPolicy@e056f20[behavior=SERVER,maxTextMessageSize=262044,maxTextMessageBufferSize=262044,maxBinaryMessageSize=65536,maxBinaryMessageBufferSize=262044,asyncWriteTimeout=60000,idleTimeout=300000,inputBufferSize=4096],creator=org.eclipse.jetty.websocket.server.WebSocketServerFactory] - STARTED
|  |  |  += WebSocketExtensionFactory@3e92efc3{STARTED} - STARTED
|  |  |     += InflaterPool@1622f1b{STARTED,size=7140,capacity=UNLIMITED} - STARTED
|  |  |     += DeflaterPool@72a7c7e0{STARTED,size=9932,capacity=UNLIMITED} - STARTED

Some context:

• The JVM was at 6.3 RSS mem when stopping; the JVM heap is fixed at 3.0 GB.
• Without websocket compression, the JVM runs at a steady 3.6 GB RSS mem.
• The server was idle, with traffic moved away from it after some hours of full traffic.
• Some idle websocket connections remain, perhaps around ~30 of them.
• I can post the full dump if necessary.

[lachlan-roberts]

@sveniu thanks for the info. I have also opened #7078 as a speculative cause. It would also be useful to know some extra information, so can you post the whole dump if possible. Unfortunately the ByteBufferPool information isn't available from the dump so if you could get that from JMX that would also be useful.

• the max number of threads for your ThreadPool.
• if you have any other contexts that also have websocket enabled (they would have different instance of Inflater/Deflater Pool).
• the result of getDirectMemory() and getHeapMemory() methods from the ByteBufferPool which can be accessed with JMX.

[lachlan-roberts]

Both #7203 and #7079 have been merged.
This should resolve the WS memory issues in the upcoming 9.4.45 release.