4

I have following sample code:

public class Test {
    static {
        System.setProperty("isThreadContextMapInheritable", "true");
    }

    private static final Logger LOGGER = LogManager.getLogger(Test.class);

    public static void main(String[] args) {
        ThreadContext.put("UUID", UUID.randomUUID().toString());
        LOGGER.info("in main method start");
        new Test().run();
        LOGGER.info("in main method end");    
    }

    private void run() {
        Collections.nCopies(10, 1)
                .parallelStream()
                .forEach(i->LOGGER.info("Inside thread"));    
    }
}

Log4j2 pattern is following:

<pattern>%X{UUID} [%t] %msg %n</pattern>

Running above produce result:

2cf774ff-03c8-483e-9828-451b61349221 [main] in main method start 
2cf774ff-03c8-483e-9828-451b61349221 [main] Inside thread 
2cf774ff-03c8-483e-9828-451b61349221 [main] Inside thread 
2cf774ff-03c8-483e-9828-451b61349221 [main] Inside thread 
2cf774ff-03c8-483e-9828-451b61349221 [main] Inside thread 
2cf774ff-03c8-483e-9828-451b61349221 [main] Inside thread 
2cf774ff-03c8-483e-9828-451b61349221 [ForkJoinPool.commonPool-worker-3] Inside thread 
2cf774ff-03c8-483e-9828-451b61349221 [ForkJoinPool.commonPool-worker-1] Inside thread 
 [ForkJoinPool.commonPool-worker-1] Inside thread 
 [ForkJoinPool.commonPool-worker-1] Inside thread 
 [ForkJoinPool.commonPool-worker-3] Inside thread 
2cf774ff-03c8-483e-9828-451b61349221 [main] in main method end

As you can see, the first time in [ForkJoinPool.commonPool-worker-1] and [ForkJoinPool.commonPool-worker-3] threads UUID variable was logged, but other times were not logged.

Why Log4j2 skips ThreadContext variable for some threads and how to fix this?

Thanks for any help!

Yaroslav Boichuk
  • 1,763
  • 20
  • 31
  • Only threads started by your thread may inherit values from your thread. Are you sure that all these entries show the name `ForkJoinPool.commonPool-worker-1` and not `ForkJoinPool.commonPool-worker-some-other-number`? – Holger Apr 05 '18 at 16:19
  • Sample is completely working and result is just copy-pasted, without any modifications. – Yaroslav Boichuk Apr 05 '18 at 20:25
  • @Holger I have tried to run more times, and got different result. Just updted the question. So per mine understanding, ThreadContext only inherits values from [main] thread, and when ForkJoinPool creates forked thread, it is not created from [main]. So, is this possible to resolve such issue somehow? – Yaroslav Boichuk Apr 06 '18 at 07:56
  • 3
    It’s a well-known problem of inheritable thread locals and thread pools that you don’t have control over who creates a thread, as re-using already existing threads is the very purpose of thread pools. So you may inherit a value or not or may even inherit a wrong value. But what’s irritating, is that the log output suggests that the same thread appears to have the value in one log entry but not in the next. – Holger Apr 06 '18 at 08:56
  • @YaroslavBoichuk I have the same problem, did you find any workaround ? – IQbrod Sep 29 '20 at 13:38

1 Answers1

0

I know this is an old post,
But I struggled on the same problem and it took me few days to find a working solution.
Here's the answer, creating a custom ThreadPoolExecutor did fix my problem.

IQbrod
  • 2,060
  • 1
  • 6
  • 28