[
https://issues.apache.org/jira/browse/LOG4J2-154?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13667444#comment-13667444
]
Remko Popma commented on LOG4J2-154:
------------------------------------
Just FYI, I'm seeing some nice performance improvements with this change.
1 thread: 33% more throughput (2.4M ops/sec -> 3.2M ops/sec), avg. latency down
630 ns/op -> 450 ns/op
2 threads: 62% more throughput (0.96M ops/sec -> 1.56M ops/sec), avg. latency
down 787 ns/op -> 600 ns/op
(With all loggers async on Solaris 10 (64bit) with JDK1.7.0_06, 4-core Xeon
X5570 dual CPU @2.93Ghz with hyperthreading switched on (16 virtual cores))
Darn! I guess this means I have to redo all the performance testing for the
http://logging.apache.org/log4j/2.x/manual/async.html#Performance page...
That's a lot of work! :-( Oh well... :-)
> ThreadContext performance improvement: shallow copies for reads, deep copies
> for writes
> ---------------------------------------------------------------------------------------
>
> Key: LOG4J2-154
> URL: https://issues.apache.org/jira/browse/LOG4J2-154
> Project: Log4j 2
> Issue Type: Improvement
> Components: Core
> Affects Versions: 2.0-beta3
> Reporter: Remko Popma
> Assignee: Remko Popma
> Attachments: LOG4J2-154.patch,
> LOG4J2-154-patch-DefaultThreadContextMap.txt,
> LOG4J2-154-patch-ThreadContextMap.txt, LOG4J2-154-patch-ThreadContext.txt
>
>
> Currently, every time a Log4jLogEvent object is created, a deep copy is made
> of both the context map and the context stack. However, expected usage is
> that only a few objects are pushed onto the stack or put in the context map,
> while the number of LogEvents is in the thousands or millions.
> Essentially, there are far more reads than writes, so using a copy-on-write
> mechanism should give us better performance.
> Example context map put: deep copy (expensive but rare)
> public static void put(String key, String value) {
> if (!useMap) {
> return;
> }
> Map<String, String> map = localMap.get();
> Map<String, String> copy = null;
> if (map == null) {
> copy = new HashMap<String, String>();
> } else {
> copy = new HashMap<String, String>(map);
> }
> copy.put(key, value);
> localMap.set(copy);
> }
> Example context stack push: deep copy (expensive but rare)
> public static void push(String message) {
> if (!useStack) {
> return;
> }
> ContextStack stack = localStack.get();
> ContextStack copy = null;
> if (stack == null) {
> copy = new ThreadContextStack();
> } else {
> copy = stack.copy();
> }
> copy.push(message);
> localStack.set(copy);
> }
> Now, when the Log4jLogEvents are created, they just call
> ThreadContext.getImmutableContext and getImmutableStack. These methods return
> an unmodifiable wrapper around the most recent copy.
> Example for context map:
> public static Map<String, String> getImmutableContext() {
> Map<String, String> map = localMap.get();
> return map == null ? EMPTY_MAP : Collections.unmodifiableMap(map);
> }
> Example for context stack:
> public static ContextStack getImmutableStack() {
> ContextStack stack = localStack.get();
> return stack == null ? EMPTY_STACK : new
> ImmutableStack(stack.asList());
> }
> Note that ThreadContext.ThreadContextStack needs to be changed to contain an
> ArrayList rather than extend it, to facilitate making both deep mutable
> copies and shallow immutable copies.
> private static class ThreadContextStack implements ContextStack {
> private static final long serialVersionUID = 5050501L;
> private List<String> list;
> public ThreadContextStack() {
> list = new ArrayList<String>();
> }
> /**
> * This constructor uses the specified list as its internal data
> * structure unchanged. It does not make a defensive copy.
> */
> public ThreadContextStack(List<String> aList) {
> list = aList; // don't copy!
> }
> /**
> * This constructor copies the elements of the specified collection
> into
> * a new list. Changes to the specified collection will not affect
> this
> * {@code ThreadContextStack}.
> */
> public ThreadContextStack(Collection<String> collection) {
> list = new ArrayList<String>(collection);
> }
> public void clear() {
> list.clear();
> }
> public String pop() {
> int index = list.size() - 1;
> if (index >= 0) {
> String result = list.get(index);
> list.remove(index);
> return result;
> }
> throw new NoSuchElementException("The ThreadContext stack is
> empty");
> }
> public String peek() {
> int index = list.size() - 1;
> if (index >= 0) {
> return list.get(index);
> }
> return null;
> }
> public void push(String message) {
> list.add(message);
> }
> public int getDepth() {
> return list.size();
> }
> public List<String> asList() {
> return list;
> }
> public void trim(int depth) {
> if (depth < 0) {
> throw new IllegalArgumentException(
> "Maximum stack depth cannot be negative");
> }
> while (list.size() > depth) {
> list.remove(list.size() - 1);
> }
> }
> /**
> * Returns a deep copy of this stack.
> */
> public ContextStack copy() {
> return new ThreadContextStack(new ArrayList<>(list));
> }
> }
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscr...@logging.apache.org
For additional commands, e-mail: log4j-dev-h...@logging.apache.org
