Repository: netty/netty
Issue: PoolArenaMetric.numDeallocations seem to be wrong

PoolArenaMetric.numDeallocations seem to be wrong because counter are not updated when free comes from PoolThreadLocal GC.

https://github.com/netty/netty/blob/1f357fc00e68091b320ada074d198b90a7c75377/buffer/src/main/java/io/netty/buffer/PoolArena.java#L246-L256



Issue comments:
Looking at the git history, this is guarding against issues with class-loaders in e.g. Tomcat containers.

If you only allocate from `FastThreadLocalThreads`, then it won't be a problem since those always clear out their thread-locals before terminating, which makes the `PoolThreadCache` free - from within the thread itself - all the memory its holding on to, and properly update the counters.
Thank you for your reply.
I agree that it's better to use `FastThreadLocalThread` as much as possible. But this is not always possible.
I use the Reactor project (without Tomcat) and some allocation of ByteBuff can take place in a classic `Thread` (use of `Scheduler.elastic()` or use of a `CompletableFuture` from a third-party lib, etc.).
When this happens and when the Thread is terminated, the metrics seems to not correctly updated and `poolArenaMetric.numDeallocations()` is wrong and therefore `poolArenaMetric.numActiveAllocations()` is also wrong.
I found an other source of wrong deallocation  metric (also exists with `FastThreadLocalThread`) :
`byteBuf.release()` can be call in some differents Thread than initial allocator Thread.
So maybe it's better if `deallocationsSmall` and `deallocationsNormal` are `LongCounter` (like `deallocationsHuge`) for be protected against concurent use.

https://github.com/netty/netty/blob/1f357fc00e68091b320ada074d198b90a7c75377/buffer/src/main/java/io/netty/buffer/PoolArena.java#L62-L66
@xavier-b these are only modified within a synchronized block. So it should be a not a problem or I am missing something ?
Here is my Test (only one direct pool arena for easy log) : 
```java
package fr.xav.brouillon.netty;

import io.netty.buffer.*;
import io.netty.util.concurrent.FastThreadLocalThread;

import java.util.ArrayList;
import java.util.Deque;
import java.util.List;
import java.util.concurrent.ConcurrentLinkedDeque;

public class ExampleCache {

    private static volatile boolean releaseIt = false;

    private static Deque<ByteBuf> listAllByteBuff = new ConcurrentLinkedDeque<>();

    public static void main(String[] args) throws InterruptedException {

        final boolean testWithFastThread = false;
        final int nbThread = 80;

        System.out.println("Start test with " + nbThread + " " + (testWithFastThread ? "FastThreadLocalThread" : "classic Thread"));
        // Only one Direct arena for easy test
        System.setProperty("io.netty.allocator.numDirectArenas", "1");
        System.setProperty("io.netty.allocator.numHeapArenas", "0");

        System.setProperty("io.netty.allocator.cacheTrimIntervalMillis", "100");

        List<Thread> threadList = new ArrayList<>();
        for (int i = 0; i < nbThread; i++) {
            if (testWithFastThread) {
                threadList.add(new FastThreadLocalThread(() -> doInThread(400, 500)));
            } else {
                threadList.add(new Thread(() -> doInThread(400, 500)));
            }
        }

        for (Thread thread : threadList) {
            thread.start();
        }

        threadList.clear();

        System.out.println("Sleep 10s");
        Thread.sleep(10_000);

        System.out.println("releaseIt=true");
        releaseIt = true;
        System.out.println("Sleep 15s");
        Thread.sleep(15_000);

        System.out.println("GC");
        System.gc();
        System.out.println("Sleep 5s");
        Thread.sleep(10_000);

        if (!listAllByteBuff.isEmpty()) {
            throw new IllegalStateException("Error, all ByteBuf was not yet released");
        }

        printMetric(PooledByteBufAllocator.DEFAULT.metric());
    }


    private static void doInThread(int taille, int nb) {
        for (int i = 0; i < nb; i++) {
            ByteBuf byteBuf = PooledByteBufAllocator.DEFAULT.directBuffer(taille);
            listAllByteBuff.addFirst(byteBuf);
        }

        while (!releaseIt) {
            try {
                Thread.sleep(3L);
            } catch (InterruptedException e) {
                e.printStackTrace();
            }
        }

        // ByteBuf.release is not necessarily on a ByteBuf created by this Thread
        for (int i = 0; i < nb; i++) {
            ByteBuf byteBuf = listAllByteBuff.pollLast();
            if (byteBuf != null) {
                byteBuf.release();
            }
        }

    }

    private static void printMetric(PooledByteBufAllocatorMetric metric) {

        System.out.println();
        System.out.println(">>> METRICS :");
        System.out.println("numThreadLocalCaches : " + metric.numThreadLocalCaches());
        System.out.println("smallCacheSize : " + metric.smallCacheSize());
        System.out.println("normalCacheSize : " + metric.normalCacheSize());
        System.out.println(String.format("chunkSize : %,d", metric.chunkSize()));

        for (int i = 0; i < metric.directArenas().size(); i++) {
            PoolArenaMetric poolArenaMetric = metric.directArenas().get(i);
            System.out.println("=========== PoolArenaMetric direct " + i + " ===========");
            System.out.println("numThreadCaches : " + poolArenaMetric.numThreadCaches());
            System.out.println(String.format("numSmallSubpages : %,d", poolArenaMetric.numSmallSubpages()));
            System.out.println(String.format("numChunkLists : %,d", poolArenaMetric.numChunkLists()));
            System.out.println(String.format("numAllocations : %,d", poolArenaMetric.numAllocations()));
            System.out.println(String.format("numSmallAllocations : %,d", poolArenaMetric.numSmallAllocations()));
            System.out.println(String.format("numNormalAllocations : %,d", poolArenaMetric.numNormalAllocations()));
            System.out.println(String.format("numHugeAllocations : %,d", poolArenaMetric.numHugeAllocations()));
            System.out.println(String.format("numDeallocations : %,d", poolArenaMetric.numDeallocations()));
            System.out.println(String.format("numSmallDeallocations : %,d", poolArenaMetric.numSmallDeallocations()));
            System.out.println(String.format("numNormalDeallocations : %,d", poolArenaMetric.numNormalDeallocations()));
            System.out.println(String.format("numHugeDeallocations : %,d", poolArenaMetric.numHugeDeallocations()));
            System.out.println(String.format("numActiveAllocations : %,d", poolArenaMetric.numActiveAllocations()));
            System.out.println(String.format("numActiveSmallAllocations : %,d", poolArenaMetric.numActiveSmallAllocations()));
            System.out.println(String.format("numActiveNormalAllocations : %,d", poolArenaMetric.numActiveNormalAllocations()));
            System.out.println(String.format("numActiveHugeAllocations : %,d", poolArenaMetric.numActiveHugeAllocations()));
            System.out.println(String.format("numActiveBytes : %,d", poolArenaMetric.numActiveBytes()));

            if (poolArenaMetric.numActiveAllocations() != 0) {
                throw new IllegalStateException("poolArenaMetric.numActiveAllocations() must be equals to 0, here : " + poolArenaMetric.numActiveAllocations());
            } else {
                System.out.println("OK, poolArenaMetric.numActiveAllocations() is equals to zero");
            }
        }
    }
}
```

When I use classique Thread (`final boolean testWithFastThread = false;`), I have 20480 wrong active allocation  (80 * 256, cad nbThread * io.netty.allocator.smallCacheSize) : 
```
Start test with 80 classic Thread
Sleep 10s
releaseIt=true
Sleep 15s
GC
Sleep 5s

>>> METRICS :
numThreadLocalCaches : 0
smallCacheSize : 256
normalCacheSize : 64
chunkSize : 16 777 216
=========== PoolArenaMetric direct 0 ===========
numThreadCaches : 0
numSmallSubpages : 39
numChunkLists : 6
numAllocations : 40 000
numSmallAllocations : 40 000
numNormalAllocations : 0
numHugeAllocations : 0
numDeallocations : 19 520
numSmallDeallocations : 19 520
numNormalDeallocations : 0
numHugeDeallocations : 0
numActiveAllocations : 20 480
numActiveSmallAllocations : 20 480
numActiveNormalAllocations : 0
numActiveHugeAllocations : 0
numActiveBytes : 33 554 432
Exception in thread "main" java.lang.IllegalStateException: poolArenaMetric.numActiveAllocations() must be equals to 0, here : 20480
	at fr.xav.brouillon.netty.ExampleCache.printMetric(ExampleCache.java:119)
	at fr.xav.brouillon.netty.ExampleCache.main(ExampleCache.java:61)

Process finished with exit code 1
```
And when I use FastThreadLocalThread (`final boolean testWithFastThread = true;`), I have ~6000 wrong allocations : 
```
Start test with 80 FastThreadLocalThread
Sleep 10s
releaseIt=true
Sleep 15s
GC
Sleep 5s

>>> METRICS :
numThreadLocalCaches : 0
smallCacheSize : 256
normalCacheSize : 64
chunkSize : 16 777 216
=========== PoolArenaMetric direct 0 ===========
numThreadCaches : 0
numSmallSubpages : 39
numChunkLists : 6
numAllocations : 40 000
numSmallAllocations : 40 000
numNormalAllocations : 0
numHugeAllocations : 0
numDeallocations : 34 085
numSmallDeallocations : 34 085
numNormalDeallocations : 0
numHugeDeallocations : 0
numActiveAllocations : 5 915
numActiveSmallAllocations : 5 915
numActiveNormalAllocations : 0
numActiveHugeAllocations : 0
numActiveBytes : 33 554 432
Exception in thread "main" java.lang.IllegalStateException: poolArenaMetric.numActiveAllocations() must be equals to 0, here : 5915
	at fr.xav.brouillon.netty.ExampleCache.printMetric(ExampleCache.java:119)
	at fr.xav.brouillon.netty.ExampleCache.main(ExampleCache.java:61)

Process finished with exit code 1
```

Note that if I use
```java
System.setProperty("io.netty.allocator.smallCacheSize", "0");
System.setProperty("io.netty.allocator.normalCacheSize", "0");
```
There is no problem.
> @xavier-b these are only modified within a synchronized block. So it should be a not a problem or I am missing something ?

@normanmaurer, effectively.

I don't understand why I have `poolArenaMetric.numActiveAllocations != 0` when all byteBuf was released and when `PoolArenaMetric.numThreadCaches==0` in the Arena.

I'm trying to follow this issue.

So, if I understand correctly what @chrisvest described earlier, when you use a FastThreadLocalThreads, then when this one terminates, it will clear the PoolThreadCache which will release the memory it holds and the metrics will then be updated.

But, when using a PooledByteBufAllocator from a classic Thread (like the use case from @xavier-b), then when the Thread terminates, it won't clear the PoolThreadCache (because of the issue #8955 if I'm correct).

So, this means that even if you release all buffers to the pool before the Thread terminates, then since the PooledByteBufAllocator maintains a cache of  buffers, then few buffers won't be released when the Thread terminates (for example, for small buffers, the pool caches at least 256 buffers, see 
PooledByteBufAllocator DEFAULT_SMALL_CACHE_SIZE).

@chrisvest,

so, in this case, do we have a memory leak in case many threads are terminated and getting re created ?  In this case,  maybe there is a way to force the PooledByteBufAllocator to release all its cached buffers ? I tried to call the PooledByteBufAllocator.trimCurrentThreadCache() just before exiting from the Thread, but the numActiveAllocations meter is still positive ?

thanks !


@chrisvest 
> But, when using a PooledByteBufAllocator from a classic Thread (like the use case from @xavier-b), then when the Thread terminates, it won't clear the PoolThreadCache (because of the issue #8955 if I'm correct).

No, in the case of using a standard thread, it seems only the metric value is wrong. Threads cache seems to be correctly freed.
In the case of using FastThreadLocalThread, poolArenaMetric.numActiveAllocations != 0 at the end of the test, but I don't know why. (a wrong metric too ? An other cache ?)

I think I understood why, with FastThreadLocalThread, my test does not end with 0 active allocation.
It's because PoolThreadCache is cleaned directly at the end of runnable action :
https://github.com/netty/netty/blob/dc8bb40bba2dc4b86fcfb62a4ff02b9ef852014a/common/src/main/java/io/netty/util/concurrent/FastThreadLocalRunnable.java#L28-L34

A ByteBuf is created in FastThreadLocalThread A and released in FastThreadLocalThread B.
But if FastThreadLocalThread A is ended before release action in Thread B, there is the problem : an entry is added to the already freed and unused PoolThreadCache. And when GC free PoolThreadCache, PoolThreadCache is already marked internally as freed, so no other entry release action is performed.: 
https://github.com/netty/netty/blob/dc8bb40bba2dc4b86fcfb62a4ff02b9ef852014a/buffer/src/main/java/io/netty/buffer/PoolThreadCache.java#L214-L217

We can have a small leak.
Of course, FastThreadLocalThread is usually used in a pool with fixed size, so never ended.

For standard thread, there is no such problem, PoolThreadCache is cleaned only when the PoolThreadCache is released by GC. And because ByteBuf keep a ref to its PoolThreadCache, it's not possible to have an early release.

Here is a little test with a FastThreadLocalThread  :
```java
import io.netty.buffer.ByteBuf;
import io.netty.buffer.PoolArenaMetric;
import io.netty.buffer.PooledByteBufAllocator;
import io.netty.buffer.PooledByteBufAllocatorMetric;
import io.netty.util.concurrent.FastThreadLocalThread;

import java.util.concurrent.atomic.AtomicReference;

public class ExampleCache2 {


  public static void main(String[] args) throws InterruptedException {
    System.out.println("Start test");
    // Only one Direct arena for easy test
    System.setProperty("io.netty.allocator.numDirectArenas", "1");
    System.setProperty("io.netty.allocator.numHeapArenas", "0");
    System.setProperty("io.netty.allocator.cacheTrimIntervalMillis", "100");
    
    AtomicReference<ByteBuf> refByteBuf = new AtomicReference<>();
    
    Thread threadA = new FastThreadLocalThread(() -> {
      refByteBuf.set(PooledByteBufAllocator.DEFAULT.directBuffer(400));
    });
    System.out.println("Start Thread A");
    threadA.start();
    threadA = null;
    System.out.println("Sleep 10s");
    Thread.sleep(10_000);
    
    System.out.println("Release in main thread");
    refByteBuf.getAndSet(null).release();
    
    printMetric(PooledByteBufAllocator.DEFAULT.metric());
  }
  
  private static void printMetric(PooledByteBufAllocatorMetric metric) {
    
    System.out.println();
    System.out.println(">>> METRICS :");
    System.out.println("numThreadLocalCaches : " + metric.numThreadLocalCaches());
    
    for (int i = 0; i < metric.directArenas().size(); i++) {
      PoolArenaMetric poolArenaMetric = metric.directArenas().get(i);
      System.out.println("=========== PoolArenaMetric direct " + i + " ===========");
      System.out.println("numThreadCaches : " + poolArenaMetric.numThreadCaches());
      System.out.println(String.format("numAllocations : %,d", poolArenaMetric.numAllocations()));
      System.out.println(String.format("numDeallocations : %,d", poolArenaMetric.numDeallocations()));
      System.out.println(String.format("numActiveAllocations : %,d", poolArenaMetric.numActiveAllocations()));
      
      if (poolArenaMetric.numActiveAllocations() != 0) {
        throw new IllegalStateException("poolArenaMetric.numActiveAllocations() must be equals to 0, here : " + poolArenaMetric.numActiveAllocations());
      } else {
        System.out.println("OK, poolArenaMetric.numActiveAllocations() is equals to zero");
      }
    }
  }
}
````

Pull request review comments:

Patch that resolved the issue:
diff --git a/buffer/src/main/java/io/netty/buffer/PooledByteBufAllocator.java b/buffer/src/main/java/io/netty/buffer/PooledByteBufAllocator.java
index d3445b524ea..4a55a469a88 100644
--- a/buffer/src/main/java/io/netty/buffer/PooledByteBufAllocator.java
+++ b/buffer/src/main/java/io/netty/buffer/PooledByteBufAllocator.java
@@ -144,7 +144,7 @@ public void run() {
         }
 
         DEFAULT_USE_CACHE_FOR_ALL_THREADS = SystemPropertyUtil.getBoolean(
-                "io.netty.allocator.useCacheForAllThreads", true);
+                "io.netty.allocator.useCacheForAllThreads", false);
 
         // Use 1023 by default as we use an ArrayDeque as backing storage which will then allocate an internal array
         // of 1024 elements. Otherwise we would allocate 2048 and only use 1024 which is wasteful.


Test patch:
diff --git a/buffer/src/test/java/io/netty/buffer/PooledByteBufAllocatorTest.java b/buffer/src/test/java/io/netty/buffer/PooledByteBufAllocatorTest.java
index fd4c4d3cf0d..f79d8def0ab 100644
--- a/buffer/src/test/java/io/netty/buffer/PooledByteBufAllocatorTest.java
+++ b/buffer/src/test/java/io/netty/buffer/PooledByteBufAllocatorTest.java
@@ -149,7 +149,7 @@ public void testArenaMetricsNoCache() {
 
     @Test
     public void testArenaMetricsCache() {
-        testArenaMetrics0(new PooledByteBufAllocator(true, 2, 2, 8192, 9, 1000, 1000, 1000), 100, 1, 1, 0);
+        testArenaMetrics0(new PooledByteBufAllocator(true, 2, 2, 8192, 9, 1000, 1000, 1000, true, 0), 100, 1, 1, 0);
     }
 
     @Test