ppkarwasz commented on issue #3792:
URL:
https://github.com/apache/logging-log4j2/issues/3792#issuecomment-3034941944
Hi @fabian-braun,
Thank you very much for the detailed debugging—it's truly appreciated! Most
users who report concurrency issues under heavy load expect us to either
reproduce the problem in our own test environments or guess what might be going
wrong. Your investigation helps a lot.
I believe your findings explain the issue quite well. A likely root cause
lies in how `InstantPatternThreadLocalCachedFormatter` handles the reuse of
`StringBuilder` instances across threads. Although each thread has **its own**
`StringBuilder` via `ThreadLocal`, the formatter’s logic exposes these reusable
builders in a read-only way to other threads.
Here’s a possible sequence of events that could trigger the bug:
1. **Thread A** formats a timestamp and, on line 113, caches the
result—making it visible to other threads.
2. **Thread B** starts formatting the *same* timestamp and retrieves the
cached value from Thread A.
3. Meanwhile, **Thread A** begins formatting the timestamp for the *next*
millisecond, executing the logic at lines 109–110.
4. Since both threads are referencing the **same** `StringBuilder` (via a
shared cache), Thread B may encounter inconsistent state, depending on exactly
where Thread A is in the formatting process. This can result in:
- An empty string (if Thread A is still at line 109).
- A partially formatted timestamp (if Thread A is mid-way through line
110).
Our new formatter decomposes the pattern `yyyy-MM-dd'T'HH:mm:ss.SSS'Z'` into:
- `yyyy-MM-dd'T'HH:mm`, evaluated once per minute,
- `ss.SSS`, evaluated every time,
- `'Z'`, a constant string evaluated once.
So if Thread B picks up a `StringBuilder` while it's only partially updated,
it might receive just one or two of these segments, leading to the incorrect or
incomplete timestamps you're observing.
Here is the relevant code for reference:
https://github.com/apache/logging-log4j2/blob/3ba9da5eef7c3a65a95a7ca547bbe2852aecb0d3/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternThreadLocalCachedFormatter.java#L89-L118
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscr...@logging.apache.org
For queries about this service, please contact Infrastructure at:
us...@infra.apache.org
