RecyclerPool Memory leak in 2.17.0

[jkuhn1]

Search before asking

• I searched in the issues and found nothing similar.

Describe the bug

I discovered a memory leak while performing performance test in a multi threaded environment. This seems to be due to the switch to the LockFreePool introduced in 2.17.0.

I'm not sure whether this is a bug or misusage also it clearly looks like a bug considering that the behaviour is degraded compared to 2.16.2 but please advice what would be a proper usage.

Version Information

2.17.0

Reproduction

In order to reproduce the leak, I created a simple program that starts 16 threads that all serialize a simple object multiple times using a common ObjectMapper instance which is thread safe as per documentation.

package com.example.jackson.leak;

import com.fasterxml.jackson.core.JsonProcessingException;
import com.fasterxml.jackson.databind.ObjectMapper;
import java.util.ArrayList;
import java.util.List;
import java.util.concurrent.Callable;
import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;

public class Main {
	
	private static final ExecutorService EXECUTOR = Executors.newFixedThreadPool(16);
	
	private static final ObjectMapper MAPPER = new ObjectMapper();
	
	public static void main(String[] args) throws Exception {
		List<Worker> tasks = new ArrayList<Worker>();
		for(int i=0;i<16;i++) {
			tasks.add(new Worker());
		}
		
		EXECUTOR.invokeAll(tasks);
		
		System.in.read();
	}
	
	public static class Message {
		
		private final String message;

		public Message(String message) {
			this.message = message;
		}

		public String getMessage() {
			return message;
		}
	}
	
	public static class Worker implements Callable<Void> {

		public Void call() {
			System.out.println("Start " + Thread.currentThread().getName());
			try {
				for(int i=0;i<150000;i++) {
					MAPPER.writeValueAsBytes(new Message("Hello world"));
				}
			}
			catch(JsonProcessingException e) {
				e.printStackTrace();
			}
			System.out.println("End " + Thread.currentThread().getName());
			return null;
		}
	}
}

Using JConsole to monitor the heap I could see that the memory is stuck around 800MB (after GC):

The heap dump speaks for itself:

Expected behavior

I expect the tasks to complete and the heap consumption to get back to normal. The same application run with 2.16.2 terminates with a heap around 9MB after GC.

Additional context

I run the app with OpenJDK 21.0.2

[pjfanning]

This is a known issue. I only have my phone at the moment but if you search around, you'll see that this pool is not working well. Stick with Jackson 2.16 or override the recycler pool to use the thread local one. 2.17.1 goes back to that pool as the default.

[jkuhn1]

Thanks!

[pjfanning]

FasterXML/jackson-module-scala#672

[cowtowncoder]

Sort of dup of FasterXML/jackson-core#1260 as well -- by now issue that we are fully aware of, and 2.17.1 having patch (to revert situation to 2.16.x) stage. But still trying to figure out some of details to know path for 2.18+ and 3.0.
(others may feel differently but I think there are still gaps in understanding).

[cowtowncoder]

@jkuhn1 One interesting note: this is specifically about serialization -- I wrote a similar tool to reproduce, but combined reads and writes. But I am beginning to feel that this might be more about just serialization (writer) side. Would it be easy enough for you to see if fast (small) reads only would trigger this issue? (I'll modify my own test once I return home, travelling now).

The current hypothesis wrt LockFreePool is that due to unreliable method of acquire AND release operations there can be pretty unexpected imbalance so that instead of the usual cycle of:

1. Thread either succeeds to acquire (if pool has a buffer), or fails (due to contention) -- in latter case allocating new buffer
2. Thread succeeding in releasing buffer to pool, or failing due to contention -- but likely failing to release as often as failing to acquire from non-empty pool

looks like under some conditions acquire() from non-empty pool fails more often than release() back to pool -- essentially leading to unintended object retention (aka "memory leak"). And this is obviously not good.

One thing, tho, that in my reproduction imbalance only occurred during initial stages and always rebalanced after a while. This may not be enough to be acceptable (since the initial peak can be rather severe...), but is something that other reproductions might not see.

[pjfanning]

https://jmh.morethan.io/?sources=https://raw.githubusercontent.com/plokhotnyuk/jsoniter-scala/gh-pages/jdk-17-t16.json,https://raw.githubusercontent.com/plokhotnyuk/jsoniter-scala/gh-pages-jackson-recycler/jdk-17-t16.json

Shows that reading and writing are affected.

[cowtowncoder]

Ok, I was specifically curious on whether "extreme memory retention" would occur for both -- vs. in general more overhead. It would make most sense for both to be heavily affected, and possibly trigger the same imbalancing problem.

EDIT: Quick update: modifying src/test/java/per/RecyclerPoolTest.java I can confirm that any mix of small reads and writes, or either alone, is sufficient to show abnormal growth during initial part of run (with about 50% chance of showing it; there's some randomness involved).
So it is not something that only write-path would exhibit: or specific usage, I think: code I use is as simple as it gets just creating, using and closing JsonParser / JsonGenerator without even using ObjectMapper.

[cowtowncoder]

Default RecyclerPool implementation changed in 2.17.1 (via https://github.com/FasterXML/jackson-core/issues//1256) -- will default to ThreadLocal-backed pool for 2.17 and 2.18 at least, possibly all of 2.x.
But specifically, will not use "LockFreePool" that was shown to have occasional degenerate behavior.