[jira] [Commented] (LOG4J2-2606) Asynchronous logging when the queue is full results heavy CPU load

["ASF subversion and git services (JIRA)" <ji...@apache.org>]

    [ https://issues.apache.org/jira/browse/LOG4J2-2606?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16866116#comment-16866116 ] 

ASF subversion and git services commented on LOG4J2-2606:
---------------------------------------------------------

Commit 7908b79560c2ce9b115ca9ed6a7bfd3d311a6159 in logging-log4j2's branch refs/heads/release-2.x from Carter Kozak
[ https://gitbox.apache.org/repos/asf?p=logging-log4j2.git;h=7908b79 ]

LOG4J2-2606 documentation


> 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: 3.5h
>  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)