[
https://issues.apache.org/jira/browse/LOG4J2-2606?focusedWorklogId=246555&page=com.atlassian.jira.plugin.system.issuetabpanels:worklog-tabpanel#worklog-246555
]
ASF GitHub Bot logged work on LOG4J2-2606:
------------------------------------------
Author: ASF GitHub Bot
Created on: 22/May/19 03:17
Start Date: 22/May/19 03:17
Worklog Time Spent: 10m
Work Description: remkop commented on issue #273: LOG4J2-2606:
Substantially improve async logging performance under heavy load
URL: https://github.com/apache/logging-log4j2/pull/273#issuecomment-494636520
It still seems strange to me that the application (Log4j in this case) needs
to do synchronization when using the Disruptor.
I'm also surprised that all the WaitStrategies were reported to show the
same behaviour when the ringbuffer is full and under load. The proposed change
(synchronizing on a mutex object) seems to do the same as the
[BlockingWaitStrategy](https://github.com/LMAX-Exchange/disruptor/blob/master/src/main/java/com/lmax/disruptor/BlockingWaitStrategy.java)
provided by the Disruptor. So I would expect at least the BlockingWaitStrategy
to show some improvement...
Can we experiment a bit before moving ahead?
@carterkozak You reported this happened in your production environment. Can
I ask how you've dealt with that? Is your organization waiting for a quick
Log4j fix, or do you have some other interim solution?
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
us...@infra.apache.org
Issue Time Tracking
-------------------
Worklog Id: (was: 246555)
Time Spent: 50m (was: 40m)
> Asynchronous logging when the queue is full results heavy CPU load
> ------------------------------------------------------------------
>
> Key: LOG4J2-2606
> URL: https://issues.apache.org/jira/browse/LOG4J2-2606
> Project: Log4j 2
> Issue Type: Bug
> Affects Versions: 2.11.2
> Reporter: Carter Kozak
> Assignee: Carter Kozak
> Priority: Major
> Time Spent: 50m
> Remaining Estimate: 0h
>
> I've encountered unexpected performance characteristics when the asynchronous
> logging queue is full, resulting in the application becoming unavailable for
> an extended period of time.
> I think EventRoute.ENQUEUE is using a spin lock (or similar construct). When
> many threads attempt to log at a higher rate than we can drain the queue,
> logging throughput drops significantly while CPU utilization skyrockets
> causing instability across the system.
> I can reproduce this in a benchmark (I will clean it up and push when I have
> a moment) where I get the following results:
> Setup:
> Root logger has a random access file appender with immediateFlush disabled
> AsyncLoggerContextSelector enabled for completely asynchronous logging
> 1 thread logging, any queue full policy: ~1,400k events/second, 150% CPU
> 32 threads logging, default policy (EventRoute.ENQUEUE, default policy):
> 300k-400k events/second. 930% CPU load
> 32 threads logging, custom policy using EventRoute.SYNCHRONOUS: 1,200k
> events/second. 350% CPU load
> Using the synchronous policy results in ~1/3 the CPU load and 3-4x throughput
> when the system is loaded to the point that the logging queue is filled.
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
