Performance optimization in CloseableThreadContext.closeMap() (#2292)

[jengebr]

This substantially improves the performance of CloseableThreadContext.closeMap(), reducing the aggregate create/close cost by 40% or 20%, depending on the ThreadContext implementation in use. Further performance explanation is on the related issue,
#2292

Checklist

• Base your changes on 2.x branch if you are targeting Log4j 2; use main otherwise
• ./mvnw verify succeeds (if it fails due to code formatting issues reported by Spotless, simply run ./mvnw spotless:apply and retry)
• Non-trivial changes contain an entry file in the src/changelog/.2.x.x directory
• Tests for the changes are provided
• Commits are signed (optional, but highly recommended)

[vy]

@jengebr, thanks so much! Would you mind adding a changelog entry (i.e., src/changelog/.2.x.x/improve_CloseableThreadContext_closeMap.xml) too, please?

[ppkarwasz]

@jengebr,

Thank you for your contribution.

Personally I think there is an inherent problem in the way CloseableThreadContext.Instance works: it stores the difference between the context data available when it was created and the current context data.

Since you pointed out that Map or StringMap (a replacement of Java Map with garbage-free iteration) allocation is a performance bottleneck, maybe we could change the logic of CloseableThreadContext.Instance to:

• take a snapshot of the current context data in its constructor,
• restore the snapshot in Instance#close().

This might require API changes, that I am more than willing to accept, but it should give better results: closing Instance would be simple and garbage-free.

Unfortunately there are 3 implementations of ThreadContextMap:

• DefaultThreadContextMap keeps the data in an immutable Map,
• CopyOnWriteSortedArrayThreadContextMap keeps the data in an immutable StringMap,
• GarbageFreeSortedArrayThreadContextMap keeps the data in a mutable StringMap.

In order to work with all 3, Instance would at least need to store the appropriate native format of the context data, to prevent conversions from Map to StringMap and viceversa.

[jengebr]

@vy thanks for adding the finals! I've added the changelog entry under 2.24.0, which matches the milestone, hopefully that's correct.

@ppkarwasz I like the garbage-free proposal but I don't think I'm up for that - not enough familiarity with the log4j codebase or designs. I am however able to performance test and profile such changes in a real-life, heavy-load environment, and am happy to help in that way.

[ppkarwasz]

LGTM

@jengebr, even if we manage to further optimize the process, your implementation gives us a better alternative to compete with.

[vy]

@jengebr, could you move the changelog file to src/changelog/.2.x.x/improve_CloseableThreadContext_closeMap.xml, please? (.2.x.x is literally the folder name, not a placeholder. It denotes the changes that will be published with the next release. 2.24.0 folder will be created and populated during a release.)

[jengebr]

@vy done, I think - and sorry, my IDE was hiding that folder and I misunderstood the intent. I kept the change you made (thanks for that!).

[jengebr]

@ppkarwasz - fyi, our conversation above sparked an idea for improving DefaultThreadContextMap. I opened #2319 to discuss further, including an implementation and benchmark.