You are viewing a plain text version of this content. The canonical link for it is here.
Posted to notifications@logging.apache.org by "xendo (via GitHub)" <gi...@apache.org> on 2023/04/05 14:23:28 UTC
[PR] Add discard buffer to prevent unsychronized access when RinbBuffer almost full (logging-log4j2)
xendo opened a new pull request, #1406:
URL: https://github.com/apache/logging-log4j2/pull/1406
A service that we maintain occasionally hangs when the rate of incoming logs is higher than the throughput of writing logs to a disk. We have a discard policy at ERROR level and use default `SynchronizeEnqueueWhenQueueFull`. We believe that this is due to corrupted LMAX disruptor. We did some initial attempts to produce minimal reproducer (using jcstress) but were not able to succeed so far.
While reviewing the log4j code we noticed that there are code paths that avoid SynchronizeEnqueueWhenQueueFull and may be responsible for RingBuffer corruption, I prepared a small change that should prevent any unsynchronized access and wanted to get initial feedback from log4j maintainers. I also wanted to use this pull request to pick you brain on what else we can do to troubleshoot the issue futher.
Writer threads hang on following stack trace:
```
java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:338)
at com.lmax.disruptor.MultiProducerSequencer.next(MultiProducerSequencer.java:136)
at com.lmax.disruptor.MultiProducerSequencer.next(MultiProducerSequencer.java:105)
at com.lmax.disruptor.RingBuffer.publishEvent(RingBuffer.java:465)
at com.lmax.disruptor.dsl.Disruptor.publishEvent(Disruptor.java:326)
at org.apache.logging.log4j.core.async.AsyncLoggerDisruptor.enqueueLogMessageWhenQueueFull(AsyncLoggerDisruptor.java:236)
- locked <0x000000052818a2c0> (a java.lang.Object)
at org.apache.logging.log4j.core.async.AsyncLogger.handleRingBufferFull(AsyncLogger.java:246)
at org.apache.logging.log4j.core.async.AsyncLogger.publish(AsyncLogger.java:230)
at org.apache.logging.log4j.core.async.AsyncLogger.logWithThreadLocalTranslator(AsyncLogger.java:225)
at org.apache.logging.log4j.core.async.AsyncLogger.access$000(AsyncLogger.java:67)
at org.apache.logging.log4j.core.async.AsyncLogger$1.log(AsyncLogger.java:152)
at org.apache.logging.log4j.core.async.AsyncLogger.log(AsyncLogger.java:136)
at org.apache.logging.log4j.spi.AbstractLogger.tryLogMessage(AbstractLogger.java:2205)
at org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2159)
at org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2142)
at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2022)
at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1875)
at org.apache.logging.slf4j.Log4jLogger.error(Log4jLogger.java:299)
```
While the event processor is runnable, but is not making any progress, i.e. no logs are produced
````
java.lang.Thread.State: RUNNABLE
at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
at java.lang.Thread.run(Thread.java:750)
```
## Checklist
* Base your changes on `2.x` branch if you are targeting Log4j 2; use `main` otherwise
DONE
* `./mvnw verify` succeeds (if it fails due to code formatting issues reported by Spotless, simply run `spotless:apply` and retry)
DONE
* Changes contain an entry file in the `src/changelog/.2.x.x` directory
TBD
* Tests for the changes are provided
TBD
* [Commits are signed](https://docs.github.com/en/authentication/managing-commit-signature-verification/signing-commits) (optional, but highly recommended)
--
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-unsubscribe@logging.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [PR] Add discard buffer to prevent unsychronized access when RingBuffer almost full (logging-log4j2)
Posted by "xendo (via GitHub)" <gi...@apache.org>.
xendo closed pull request #1406: Add discard buffer to prevent unsychronized access when RingBuffer almost full
URL: https://github.com/apache/logging-log4j2/pull/1406
--
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-unsubscribe@logging.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [PR] Add discard buffer to prevent unsychronized access when RingBuffer almost full (logging-log4j2)
Posted by "xendo (via GitHub)" <gi...@apache.org>.
xendo commented on PR #1406:
URL: https://github.com/apache/logging-log4j2/pull/1406#issuecomment-1497618820
I noticed a but in the request, let me fix it.
--
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-unsubscribe@logging.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org