Thread-local successor for object pooling

[Erik Osterlund]

Hi,

I am curious what kind of GC issues you observed when you accidentally allocated memory. Could you please elaborate?
I would like to know what GC was used and on what version of the JDK, and how big the latency issues you observed were.

Thanks,
/Erik

On 31 Oct 2022, at 21:48, Volkan Yazıcı <volkan at yazi.ci<mailto:volkan at yazi.ci>> wrote:

Below is a list of TL usages in the Log4j code base. Note that some serve other purposes than object pooling, yet I wanted to share them anyway for completeness.

- Log `Message`s and `LogEvent`s – all `log.info<http://log.info/>()` calls get converted into a `LogEvent` wrapping a `Message`

- Context Stack and Context Data (aka. NDC and MDC) stacks and lists, respectively. TLs, besides providing an efficient way to mutate these data structures, also serve another important purpose: storing the logging context along the lifetime of an _operation_, which can be an HTTP request-response, database transaction, etc. Ideally, these should all be replaced with dynamic/scoped variables. Nevertheless, there will (might?) be still a need for object pooling to avoid instantiating a new MDC/NDC each time. Though this can be efficiently implemented without needing TLs.

- `StringBuilder`s – used in various layout implementations for encoding the user input into a `ByteBuffer`. The user input is first written to a `StringBuilder`, then the `StringBuilder#getChars()` is used to dump its contents to a `ByteBuffer`, and finally a `CharsetEncoder` is used to encode these characters to another target `ByteBuffer`[1]. As you might guess, both the input and the output `ByteBuffer`s are also received from TLs.

- Recursion prevention and depth limiting – again, a use case that better be addressed with dynamic variables, though Java is not there yet.

I personally don't think we can replace the garbage-free machinery on the hot path with GC-friendly(?) alternatives. Even though logging is mostly regarded as a troubleshooting aid, in essence, a logging framework is a fully-fledged message bus in disguise of a string formatter. There are numerous deployments we know of that leverage Log4j as a crucial component of their business logic, e.g., for audit logging. For those use cases, logging becomes indispensable and it should simply work. Some of such code bases, mostly in the financial domain, are very sensitive to latency. Even if we provide GC-friendly alternatives, users still need to migrate to modern GCs, which is already a problem on its own. I happen to be the author of Log4j's JSON Template Layout – a garbage-free layout encoding log events to JSON. We use it heavily at bol.com<http://bol.com/>, the Dutch e-commerce giant. Once I had introduced a bug causing slight garbage in the logger calls; multiple teams reported unexpected GC latencies in their dashboards the next day. The point I am trying to make is, you don't need to OpEx an HFT service in Nasdaq, GC latencies simply might not be acceptable depending on your environment.

I look forward to your response on how we shall replace TLs given the above use cases.

[1] https://github.com/apache/logging-log4j2/blob/3a4de2b0a92b59f02c640d915e5c22e5a0e4aff1/log4j-core/src/main/java/org/apache/logging/log4j/core/layout/TextEncoderHelper.java


On Mon, Oct 31, 2022 at 12:58 PM Alan Bateman <Alan.Bateman at oracle.com<mailto:Alan.Bateman at oracle.com>> wrote:


On 31/10/2022 10:20, Volkan Yazıcı wrote:
> Hello,
>
> Log4j heavily relies on thread-locals (TLs) for object pooling.

It would be interesting to know if log4j has done any recent evaluation
with newer JDK releases and GCs to see their object pooling has a
positive or negative benefit. It would also be useful to get a summary
of what they are caching. Examples such as SimpleDateFormat are
expensive to create and aren't thread safe but have immutable and thread
safe alternatives.


> This becomes of particular importance for caching and garbage-free
> logging purposes. With JEP 425 (Virtual Threads), this becomes
> problematic due to two main issues:
>
> 1. TLs on vthreads yield no allocation benefits since vhtreads are
> short-lived. On the contrary, it becomes a redundant memory cost due
> to the excessive vthread count. In this case, Log4j still works,
> though slower and with increased memory footprint.
>
> 2. TL mutation can be disabled for vthreads. In this case, Log4j
> doesn't work, since TL setters throw UnsupportedOperationException.

That's right but not specific to virtual threads. It is also possible to
create platform threads that do not support TLs. This is something that
we need a lot more feedback on before deciding if that part of the API
should be made permanent.

BTW: The LOG4J2-3622 issue linked appears to be Helidon Nima issue in
that it needs to work with general purpose libraries.

-Alan.

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://mail.openjdk.org/pipermail/loom-dev/attachments/20221102/680910bd/attachment-0001.htm>