Return-Path: X-Original-To: apmail-logging-commits-archive@minotaur.apache.org Delivered-To: apmail-logging-commits-archive@minotaur.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id CA75CFA32 for ; Wed, 17 Apr 2013 23:36:14 +0000 (UTC) Received: (qmail 52069 invoked by uid 500); 17 Apr 2013 23:36:14 -0000 Delivered-To: apmail-logging-commits-archive@logging.apache.org Received: (qmail 52046 invoked by uid 500); 17 Apr 2013 23:36:14 -0000 Mailing-List: contact commits-help@logging.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@logging.apache.org Delivered-To: mailing list commits@logging.apache.org Received: (qmail 52038 invoked by uid 99); 17 Apr 2013 23:36:14 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 17 Apr 2013 23:36:14 +0000 X-ASF-Spam-Status: No, hits=-2000.0 required=5.0 tests=ALL_TRUSTED X-Spam-Check-By: apache.org Received: from [140.211.11.4] (HELO eris.apache.org) (140.211.11.4) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 17 Apr 2013 23:36:10 +0000 Received: from eris.apache.org (localhost [127.0.0.1]) by eris.apache.org (Postfix) with ESMTP id 496C32388A32; Wed, 17 Apr 2013 23:35:50 +0000 (UTC) Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit Subject: svn commit: r1469103 [2/3] - in /logging/log4j/log4j2/trunk/core/src: main/java/org/apache/logging/log4j/core/appender/ main/java/org/apache/logging/log4j/core/appender/rolling/ main/java/org/apache/logging/log4j/core/async/ test/java/org/apache/loggin... Date: Wed, 17 Apr 2013 23:35:47 -0000 To: commits@logging.apache.org From: rgoers@apache.org X-Mailer: svnmailer-1.0.8-patched Message-Id: <20130417233550.496C32388A32@eris.apache.org> X-Virus-Checked: Checked by ClamAV on apache.org Added: logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEvent.java URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEvent.java?rev=1469103&view=auto ============================================================================== --- logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEvent.java (added) +++ logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEvent.java Wed Apr 17 23:35:45 2013 @@ -0,0 +1,208 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache license, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the license for the specific language governing permissions and + * limitations under the license. + */ +package org.apache.logging.log4j.core.async; + +import java.util.HashMap; +import java.util.Map; + +import org.apache.logging.log4j.Level; +import org.apache.logging.log4j.Marker; +import org.apache.logging.log4j.ThreadContext.ContextStack; +import org.apache.logging.log4j.core.LogEvent; +import org.apache.logging.log4j.core.config.Property; +import org.apache.logging.log4j.core.lookup.StrSubstitutor; +import org.apache.logging.log4j.message.Message; +import org.apache.logging.log4j.message.SimpleMessage; + +import com.lmax.disruptor.EventFactory; + +/** + * When the Disruptor is started, the RingBuffer is populated with event + * objects. These objects are then re-used during the life of the RingBuffer. + */ +public class RingBufferLogEvent implements LogEvent { + private static final long serialVersionUID = 8462119088943934758L; + + /** + * Creates the events that will be put in the RingBuffer. + */ + private static class Factory implements EventFactory { + // @Override + public RingBufferLogEvent newInstance() { + return new RingBufferLogEvent(); + } + } + + /** The {@code EventFactory} for {@code RingBufferLogEvent}s. */ + public static final Factory FACTORY = new Factory(); + + private AsyncLogger asyncLogger; + private String loggerName; + private Marker marker; + private String fqcn; + private Level level; + private Message message; + private Throwable thrown; + private Map contextMap; + private ContextStack contextStack; + private String threadName; + private StackTraceElement location; + private long currentTimeMillis; + private boolean endOfBatch; + private boolean includeLocation; + + public void setValues(AsyncLogger asyncLogger, String loggerName, + Marker marker, String fqcn, Level level, Message data, Throwable t, + Map map, ContextStack contextStack, + String threadName, StackTraceElement location, + long currentTimeMillis) { + this.asyncLogger = asyncLogger; + this.loggerName = loggerName; + this.marker = marker; + this.fqcn = fqcn; + this.level = level; + this.message = data; + this.thrown = t; + this.contextMap = map; + this.contextStack = contextStack; + this.threadName = threadName; + this.location = location; + this.currentTimeMillis = currentTimeMillis; + } + + /** + * Event processor that reads the event from the ringbuffer can call this + * method. + * + * @param endOfBatch flag to indicate if this is the last event in a batch + * from the RingBuffer + */ + public void execute(boolean endOfBatch) { + this.endOfBatch = endOfBatch; + asyncLogger.actualAsyncLog(this); + } + + /** + * Returns {@code true} if this event is the end of a batch, {@code false} + * otherwise. + * + * @return {@code true} if this event is the end of a batch, {@code false} + * otherwise + */ + public boolean isEndOfBatch() { + return endOfBatch; + } + + public void setEndOfBatch(boolean endOfBatch) { + this.endOfBatch = endOfBatch; + } + + public boolean isIncludeLocation() { + return includeLocation; + } + + public void setIncludeLocation(boolean includeLocation) { + this.includeLocation = includeLocation; + } + + // @Override + public String getLoggerName() { + return loggerName; + } + + // @Override + public Marker getMarker() { + return marker; + } + + // @Override + public String getFQCN() { + return fqcn; + } + + // @Override + public Level getLevel() { + return level; + } + + // @Override + public Message getMessage() { + if (message == null) { + message = new SimpleMessage(""); + } + return message; + } + + // @Override + public Throwable getThrown() { + return thrown; + } + + // @Override + public Map getContextMap() { + return contextMap; + } + + // @Override + public ContextStack getContextStack() { + return contextStack; + } + + // @Override + public String getThreadName() { + return threadName; + } + + // @Override + public StackTraceElement getSource() { + return location; + } + + // @Override + public long getMillis() { + return currentTimeMillis; + } + + /** + * Merges the contents of the specified map into the contextMap, after + * replacing any variables in the property values with the + * StrSubstitutor-supplied actual values. + * + * @param properties configured properties + * @param strSubstitutor used to lookup values of variables in properties + */ + public void mergePropertiesIntoContextMap( + Map properties, StrSubstitutor strSubstitutor) { + if (properties == null) { + return; // nothing to do + } + + Map map = (contextMap == null) ? new HashMap() + : new HashMap(contextMap); + + for (Map.Entry entry : properties.entrySet()) { + Property prop = entry.getKey(); + if (map.containsKey(prop.getName())) { + continue; // contextMap overrides config properties + } + String value = entry.getValue() ? strSubstitutor.replace(prop + .getValue()) : prop.getValue(); + map.put(prop.getName(), value); + } + contextMap = map; + } +} Added: logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEventHandler.java URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEventHandler.java?rev=1469103&view=auto ============================================================================== --- logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEventHandler.java (added) +++ logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEventHandler.java Wed Apr 17 23:35:45 2013 @@ -0,0 +1,54 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache license, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the license for the specific language governing permissions and + * limitations under the license. + */ +package org.apache.logging.log4j.core.async; + +import com.lmax.disruptor.Sequence; +import com.lmax.disruptor.SequenceReportingEventHandler; + +/** + * This event handler gets passed messages from the RingBuffer as they become + * available. Processing of these messages is done in a separate thread, + * controlled by the {@code Executor} passed to the {@code Disruptor} + * constructor. + */ +public class RingBufferLogEventHandler implements + SequenceReportingEventHandler { + + private static final int NOTIFY_PROGRESS_THRESHOLD = 50; + private Sequence sequenceCallback; + private int counter; + + @Override + public void setSequenceCallback(Sequence sequenceCallback) { + this.sequenceCallback = sequenceCallback; + } + + @Override + public void onEvent(RingBufferLogEvent event, long sequence, + boolean endOfBatch) throws Exception { + event.execute(endOfBatch); + + // notify the BatchEventProcessor that the sequence has progressed. + // Without this callback the sequence would not be progressed + // until the batch has completely finished. + if (++counter > NOTIFY_PROGRESS_THRESHOLD) { + sequenceCallback.set(sequence); + counter = 0; + } + } + +} Added: logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEventTranslator.java URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEventTranslator.java?rev=1469103&view=auto ============================================================================== --- logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEventTranslator.java (added) +++ logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEventTranslator.java Wed Apr 17 23:35:45 2013 @@ -0,0 +1,76 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache license, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the license for the specific language governing permissions and + * limitations under the license. + */ +package org.apache.logging.log4j.core.async; + +import java.util.Map; + +import org.apache.logging.log4j.Level; +import org.apache.logging.log4j.Marker; +import org.apache.logging.log4j.ThreadContext.ContextStack; +import org.apache.logging.log4j.message.Message; + +import com.lmax.disruptor.EventTranslator; + +/** + * This class is responsible for writing elements that make up a log event into + * the ringbuffer {@code RingBufferLogEvent}. After this translator populated + * the ringbuffer event, the disruptor will update the sequence number so that + * the event can be consumed by another thread. + */ +public class RingBufferLogEventTranslator implements + EventTranslator { + + private AsyncLogger asyncLogger; + private String loggerName; + private Marker marker; + private String fqcn; + private Level level; + private Message message; + private Throwable thrown; + private Map contextMap; + private ContextStack contextStack; + private String threadName; + private StackTraceElement location; + private long currentTimeMillis; + + // @Override + public void translateTo(RingBufferLogEvent event, long sequence) { + event.setValues(asyncLogger, loggerName, marker, fqcn, level, message, + thrown, contextMap, contextStack, threadName, location, + currentTimeMillis); + } + + public void setValues(AsyncLogger asyncLogger, String loggerName, + Marker marker, String fqcn, Level level, Message message, + Throwable thrown, Map contextMap, + ContextStack contextStack, String threadName, + StackTraceElement location, long currentTimeMillis) { + this.asyncLogger = asyncLogger; + this.loggerName = loggerName; + this.marker = marker; + this.fqcn = fqcn; + this.level = level; + this.message = message; + this.thrown = thrown; + this.contextMap = contextMap; + this.contextStack = contextStack; + this.threadName = threadName; + this.location = location; + this.currentTimeMillis = currentTimeMillis; + } + +} Added: logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/async/SystemClock.java URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/async/SystemClock.java?rev=1469103&view=auto ============================================================================== --- logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/async/SystemClock.java (added) +++ logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/async/SystemClock.java Wed Apr 17 23:35:45 2013 @@ -0,0 +1,33 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache license, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the license for the specific language governing permissions and + * limitations under the license. + */ +package org.apache.logging.log4j.core.async; + +/** + * Implementation of the {@code Clock} interface that returns the system time. + */ +public class SystemClock implements Clock { + + /** + * Returns the system time. + * @return the result of calling {@code System.currentTimeMillis()} + */ + @Override + public long currentTimeMillis() { + return System.currentTimeMillis(); + } + +} Added: logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/async/package-info.java URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/async/package-info.java?rev=1469103&view=auto ============================================================================== --- logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/async/package-info.java (added) +++ logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/async/package-info.java Wed Apr 17 23:35:45 2013 @@ -0,0 +1,20 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache license, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the license for the specific language governing permissions and + * limitations under the license. + */ +/** + * Provides Asynchronous Logger classes and interfaces for low-latency logging. + */ +package org.apache.logging.log4j.core.async; Added: logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/FastFileAppenderLocationTest.java URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/FastFileAppenderLocationTest.java?rev=1469103&view=auto ============================================================================== --- logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/FastFileAppenderLocationTest.java (added) +++ logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/FastFileAppenderLocationTest.java Wed Apr 17 23:35:45 2013 @@ -0,0 +1,60 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache license, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the license for the specific language governing permissions and + * limitations under the license. + */ +package org.apache.logging.log4j.core.appender; + +import static org.junit.Assert.*; + +import java.io.BufferedReader; +import java.io.File; +import java.io.FileReader; + +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.core.LifeCycle; +import org.apache.logging.log4j.core.config.XMLConfigurationFactory; +import org.junit.BeforeClass; +import org.junit.Test; + +public class FastFileAppenderLocationTest { + + @BeforeClass + public static void beforeClass() { + System.setProperty(XMLConfigurationFactory.CONFIGURATION_FILE_PROPERTY, + "FastFileAppenderLocationTest.xml"); + } + + @Test + public void testLocationIncluded() throws Exception { + File f = new File("target", "FastFileAppenderLocationTest.log"); + // System.out.println(f.getAbsolutePath()); + f.delete(); + Logger log = LogManager.getLogger("com.foo.Bar"); + String msg = "Message with location, flushed with immediate flush=false"; + log.info(msg); + ((LifeCycle) LogManager.getContext()).stop(); // stop async thread + + BufferedReader reader = new BufferedReader(new FileReader(f)); + String line1 = reader.readLine(); + reader.close(); + f.delete(); + assertNotNull("line1", line1); + assertTrue("line1 correct", line1.contains(msg)); + + String location = "testLocationIncluded"; + assertTrue("has location", line1.contains(location)); + } +} Added: logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/FastFileAppenderTest.java URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/FastFileAppenderTest.java?rev=1469103&view=auto ============================================================================== --- logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/FastFileAppenderTest.java (added) +++ logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/FastFileAppenderTest.java Wed Apr 17 23:35:45 2013 @@ -0,0 +1,60 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache license, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the license for the specific language governing permissions and + * limitations under the license. + */ +package org.apache.logging.log4j.core.appender; + +import static org.junit.Assert.*; + +import java.io.BufferedReader; +import java.io.File; +import java.io.FileReader; + +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.core.LifeCycle; +import org.apache.logging.log4j.core.config.XMLConfigurationFactory; +import org.junit.BeforeClass; +import org.junit.Test; + +public class FastFileAppenderTest { + + @BeforeClass + public static void beforeClass() { + System.setProperty(XMLConfigurationFactory.CONFIGURATION_FILE_PROPERTY, + "FastFileAppenderTest.xml"); + } + + @Test + public void testFlushAtEndOfBatch() throws Exception { + File f = new File("target", "FastFileAppenderTest.log"); + // System.out.println(f.getAbsolutePath()); + f.delete(); + Logger log = LogManager.getLogger("com.foo.Bar"); + String msg = "Message flushed with immediate flush=false"; + log.info(msg); + ((LifeCycle) LogManager.getContext()).stop(); // stop async thread + + BufferedReader reader = new BufferedReader(new FileReader(f)); + String line1 = reader.readLine(); + reader.close(); + f.delete(); + assertNotNull("line1", line1); + assertTrue("line1 correct", line1.contains(msg)); + + String location = "testFlushAtEndOfBatch"; + assertTrue("no location", !line1.contains(location)); + } +} Added: logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/FastRollingFileAppenderLocationTest.java URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/FastRollingFileAppenderLocationTest.java?rev=1469103&view=auto ============================================================================== --- logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/FastRollingFileAppenderLocationTest.java (added) +++ logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/FastRollingFileAppenderLocationTest.java Wed Apr 17 23:35:45 2013 @@ -0,0 +1,60 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache license, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the license for the specific language governing permissions and + * limitations under the license. + */ +package org.apache.logging.log4j.core.appender; + +import static org.junit.Assert.*; + +import java.io.BufferedReader; +import java.io.File; +import java.io.FileReader; + +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.core.LifeCycle; +import org.apache.logging.log4j.core.config.XMLConfigurationFactory; +import org.junit.BeforeClass; +import org.junit.Test; + +public class FastRollingFileAppenderLocationTest { + + @BeforeClass + public static void beforeClass() { + System.setProperty(XMLConfigurationFactory.CONFIGURATION_FILE_PROPERTY, + "FastRollingFileAppenderLocationTest.xml"); + } + + @Test + public void testLocationIncluded() throws Exception { + File f = new File("target", "FastRollingFileAppenderLocationTest.log"); + // System.out.println(f.getAbsolutePath()); + f.delete(); + Logger log = LogManager.getLogger("com.foo.Bar"); + String msg = "Message with location, flushed with immediate flush=false"; + log.info(msg); + ((LifeCycle) LogManager.getContext()).stop(); // stop async thread + + BufferedReader reader = new BufferedReader(new FileReader(f)); + String line1 = reader.readLine(); + reader.close(); + f.delete(); + assertNotNull("line1", line1); + assertTrue("line1 correct", line1.contains(msg)); + + String location = "testLocationIncluded"; + assertTrue("has location", line1.contains(location)); + } +} Added: logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/FastRollingFileAppenderRolloverTest.java URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/FastRollingFileAppenderRolloverTest.java?rev=1469103&view=auto ============================================================================== --- logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/FastRollingFileAppenderRolloverTest.java (added) +++ logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/FastRollingFileAppenderRolloverTest.java Wed Apr 17 23:35:45 2013 @@ -0,0 +1,92 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache license, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the license for the specific language governing permissions and + * limitations under the license. + */ +package org.apache.logging.log4j.core.appender; + +import static org.junit.Assert.*; + +import java.io.BufferedReader; +import java.io.File; +import java.io.FileReader; +import java.util.Arrays; + +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.core.LifeCycle; +import org.apache.logging.log4j.core.config.XMLConfigurationFactory; +import org.junit.BeforeClass; +import org.junit.Test; + +public class FastRollingFileAppenderRolloverTest { + + @BeforeClass + public static void beforeClass() { + System.setProperty(XMLConfigurationFactory.CONFIGURATION_FILE_PROPERTY, + "FastRollingFileAppenderTest.xml"); + } + + @Test + public void testRollover() throws Exception { + File f = new File("target", "FastRollingFileAppenderTest.log"); + // System.out.println(f.getAbsolutePath()); + File after1 = new File("target", "afterRollover-1.log"); + f.delete(); + after1.delete(); + + Logger log = LogManager.getLogger("com.foo.Bar"); + String msg = "First a short message that does not trigger rollover"; + log.info(msg); + Thread.sleep(50); + + BufferedReader reader = new BufferedReader(new FileReader(f)); + String line1 = reader.readLine(); + assertTrue(line1.contains(msg)); + reader.close(); + + assertFalse("afterRollover-1.log not created yet", after1.exists()); + + String exceed = "Long message that exceeds rollover size... "; + char[] padding = new char[250]; + Arrays.fill(padding, 'X'); + exceed += new String(padding); + log.warn(exceed); + assertFalse("exceeded size but afterRollover-1.log not created yet", after1.exists()); + + String trigger = "This message triggers rollover."; + log.warn(trigger); + + ((LifeCycle) LogManager.getContext()).stop(); // stop async thread + + assertTrue("afterRollover-1.log created", after1.exists()); + + reader = new BufferedReader(new FileReader(f)); + String new1 = reader.readLine(); + assertTrue("after rollover only new msg", new1.contains(trigger)); + assertNull("No more lines", reader.readLine()); + reader.close(); + f.delete(); + + reader = new BufferedReader(new FileReader(after1)); + String old1 = reader.readLine(); + assertTrue("renamed file line 1", old1.contains(msg)); + String old2 = reader.readLine(); + assertTrue("renamed file line 2", old2.contains(exceed)); + String line = reader.readLine(); + assertNull("No more lines", line); + reader.close(); + after1.delete(); + } +} Added: logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/FastRollingFileAppenderTest.java URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/FastRollingFileAppenderTest.java?rev=1469103&view=auto ============================================================================== --- logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/FastRollingFileAppenderTest.java (added) +++ logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/FastRollingFileAppenderTest.java Wed Apr 17 23:35:45 2013 @@ -0,0 +1,60 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache license, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the license for the specific language governing permissions and + * limitations under the license. + */ +package org.apache.logging.log4j.core.appender; + +import static org.junit.Assert.*; + +import java.io.BufferedReader; +import java.io.File; +import java.io.FileReader; + +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.core.LifeCycle; +import org.apache.logging.log4j.core.config.XMLConfigurationFactory; +import org.junit.BeforeClass; +import org.junit.Test; + +public class FastRollingFileAppenderTest { + + @BeforeClass + public static void beforeClass() { + System.setProperty(XMLConfigurationFactory.CONFIGURATION_FILE_PROPERTY, + "FastRollingFileAppenderTest.xml"); + } + + @Test + public void testFlushAtEndOfBatch() throws Exception { + File f = new File("target", "FastRollingFileAppenderTest.log"); + // System.out.println(f.getAbsolutePath()); + f.delete(); + Logger log = LogManager.getLogger("com.foo.Bar"); + String msg = "Message flushed with immediate flush=false"; + log.info(msg); + ((LifeCycle) LogManager.getContext()).stop(); // stop async thread + + BufferedReader reader = new BufferedReader(new FileReader(f)); + String line1 = reader.readLine(); + reader.close(); + f.delete(); + assertNotNull("line1", line1); + assertTrue("line1 correct", line1.contains(msg)); + + String location = "testFlushAtEndOfBatch"; + assertTrue("no location", !line1.contains(location)); + } +} Added: logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggerConfigTest.java URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggerConfigTest.java?rev=1469103&view=auto ============================================================================== --- logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggerConfigTest.java (added) +++ logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggerConfigTest.java Wed Apr 17 23:35:45 2013 @@ -0,0 +1,65 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache license, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the license for the specific language governing permissions and + * limitations under the license. + */ +package org.apache.logging.log4j.core.async; + +import static org.junit.Assert.*; + +import java.io.BufferedReader; +import java.io.File; +import java.io.FileReader; + +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.core.LifeCycle; +import org.apache.logging.log4j.core.config.XMLConfigurationFactory; +import org.junit.BeforeClass; +import org.junit.Test; + +public class AsyncLoggerConfigTest { + + @BeforeClass + public static void beforeClass() { + System.setProperty(XMLConfigurationFactory.CONFIGURATION_FILE_PROPERTY, + "AsyncLoggerConfigTest.xml"); + } + + @Test + public void testAdditivity() throws Exception { + File f = new File("target", "AsyncLoggerConfigTest.log"); + // System.out.println(f.getAbsolutePath()); + f.delete(); + Logger log = LogManager.getLogger("com.foo.Bar"); + String msg = "Additive logging: 2 for the price of 1!"; + log.info(msg); + ((LifeCycle) LogManager.getContext()).stop(); // stop async thread + + BufferedReader reader = new BufferedReader(new FileReader(f)); + String line1 = reader.readLine(); + String line2 = reader.readLine(); + reader.close(); + f.delete(); + assertNotNull("line1", line1); + assertNotNull("line2", line2); + assertTrue("line1 correct", line1.contains(msg)); + assertTrue("line2 correct", line2.contains(msg)); + + String location = "testAdditivity"; + assertTrue("location", + line1.contains(location) || line2.contains(location)); + } + +} Added: logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggerContextSelectorTest.java URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggerContextSelectorTest.java?rev=1469103&view=auto ============================================================================== --- logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggerContextSelectorTest.java (added) +++ logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggerContextSelectorTest.java Wed Apr 17 23:35:45 2013 @@ -0,0 +1,63 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache license, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the license for the specific language governing permissions and + * limitations under the license. + */ +package org.apache.logging.log4j.core.async; + +import static org.junit.Assert.*; + +import java.util.List; + +import org.apache.logging.log4j.core.LoggerContext; +import org.apache.logging.log4j.core.async.AsyncLoggerContext; +import org.apache.logging.log4j.core.async.AsyncLoggerContextSelector; +import org.junit.Test; + +public class AsyncLoggerContextSelectorTest { + + @Test + public void testContextReturnsAsyncLoggerContext() { + AsyncLoggerContextSelector selector = new AsyncLoggerContextSelector(); + LoggerContext context = selector.getContext(null, null, false); + + assertTrue(context instanceof AsyncLoggerContext); + } + + @Test + public void testContext2ReturnsAsyncLoggerContext() { + AsyncLoggerContextSelector selector = new AsyncLoggerContextSelector(); + LoggerContext context = selector.getContext(null, null, false, null); + + assertTrue(context instanceof AsyncLoggerContext); + } + + @Test + public void testLoggerContextsReturnsAsyncLoggerContext() { + AsyncLoggerContextSelector selector = new AsyncLoggerContextSelector(); + List list = selector.getLoggerContexts(); + + assertEquals(1, list.size()); + assertTrue(list.get(0) instanceof AsyncLoggerContext); + } + + @Test + public void testContextNameIsAsyncLoggerContext() { + AsyncLoggerContextSelector selector = new AsyncLoggerContextSelector(); + LoggerContext context = selector.getContext(null, null, false); + + assertEquals("AsyncLoggerContext", context.getName()); + } + +} Added: logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggerContextTest.java URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggerContextTest.java?rev=1469103&view=auto ============================================================================== --- logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggerContextTest.java (added) +++ logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggerContextTest.java Wed Apr 17 23:35:45 2013 @@ -0,0 +1,39 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache license, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the license for the specific language governing permissions and + * limitations under the license. + */ +package org.apache.logging.log4j.core.async; + +import static org.junit.Assert.*; + +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.core.LifeCycle; +import org.apache.logging.log4j.core.LoggerContext; +import org.apache.logging.log4j.core.async.AsyncLogger; +import org.apache.logging.log4j.core.async.AsyncLoggerContext; +import org.junit.Test; + +public class AsyncLoggerContextTest { + + @Test + public void testNewInstanceReturnsAsyncLogger() { + Logger logger = new AsyncLoggerContext("a").newInstance( + new LoggerContext("a"), "a", null); + assertTrue(logger instanceof AsyncLogger); + + ((LifeCycle) LogManager.getContext()).stop(); // stop async thread + } +} Added: logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggerLocationTest.java URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggerLocationTest.java?rev=1469103&view=auto ============================================================================== --- logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggerLocationTest.java (added) +++ logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggerLocationTest.java Wed Apr 17 23:35:45 2013 @@ -0,0 +1,71 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache license, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the license for the specific language governing permissions and + * limitations under the license. + */ +package org.apache.logging.log4j.core.async; + +import static org.junit.Assert.*; + +import java.io.BufferedReader; +import java.io.File; +import java.io.FileReader; + +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.core.LifeCycle; +import org.apache.logging.log4j.core.async.AsyncLoggerContextSelector; +import org.apache.logging.log4j.core.config.XMLConfigurationFactory; +import org.apache.logging.log4j.core.helpers.Constants; +import org.junit.AfterClass; +import org.junit.BeforeClass; +import org.junit.Test; + +public class AsyncLoggerLocationTest { + + @BeforeClass + public static void beforeClass() { + System.setProperty(Constants.LOG4J_CONTEXT_SELECTOR, + AsyncLoggerContextSelector.class.getName()); + System.setProperty(XMLConfigurationFactory.CONFIGURATION_FILE_PROPERTY, + "AsyncLoggerLocationTest.xml"); + } + + @AfterClass + public static void afterClass() { + System.setProperty(Constants.LOG4J_CONTEXT_SELECTOR, ""); + } + + @Test + public void testAsyncLogWritesToLog() throws Exception { + File f = new File("target", "AsyncLoggerLocationTest.log"); + // System.out.println(f.getAbsolutePath()); + f.delete(); + Logger log = LogManager.getLogger("com.foo.Bar"); + String msg = "Async logger msg with location"; + log.info(msg); + ((LifeCycle) LogManager.getContext()).stop(); // stop async thread + + BufferedReader reader = new BufferedReader(new FileReader(f)); + String line1 = reader.readLine(); + reader.close(); + f.delete(); + assertNotNull("line1", line1); + assertTrue("line1 correct", line1.contains(msg)); + + String location = "testAsyncLogWritesToLog"; + assertTrue("has location", line1.contains(location)); + } + +} Added: logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggerTest.java URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggerTest.java?rev=1469103&view=auto ============================================================================== --- logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggerTest.java (added) +++ logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggerTest.java Wed Apr 17 23:35:45 2013 @@ -0,0 +1,71 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache license, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the license for the specific language governing permissions and + * limitations under the license. + */ +package org.apache.logging.log4j.core.async; + +import static org.junit.Assert.*; + +import java.io.BufferedReader; +import java.io.File; +import java.io.FileReader; + +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.core.LifeCycle; +import org.apache.logging.log4j.core.async.AsyncLoggerContextSelector; +import org.apache.logging.log4j.core.config.XMLConfigurationFactory; +import org.apache.logging.log4j.core.helpers.Constants; +import org.junit.AfterClass; +import org.junit.BeforeClass; +import org.junit.Test; + +public class AsyncLoggerTest { + + @BeforeClass + public static void beforeClass() { + System.setProperty(Constants.LOG4J_CONTEXT_SELECTOR, + AsyncLoggerContextSelector.class.getName()); + System.setProperty(XMLConfigurationFactory.CONFIGURATION_FILE_PROPERTY, + "AsyncLoggerTest.xml"); + } + + @AfterClass + public static void afterClass() { + System.setProperty(Constants.LOG4J_CONTEXT_SELECTOR, ""); + } + + @Test + public void testAsyncLogWritesToLog() throws Exception { + File f = new File("target", "AsyncLoggerTest.log"); + // System.out.println(f.getAbsolutePath()); + f.delete(); + Logger log = LogManager.getLogger("com.foo.Bar"); + String msg = "Async logger msg"; + log.info(msg); + ((LifeCycle) LogManager.getContext()).stop(); // stop async thread + + BufferedReader reader = new BufferedReader(new FileReader(f)); + String line1 = reader.readLine(); + reader.close(); + f.delete(); + assertNotNull("line1", line1); + assertTrue("line1 correct", line1.contains(msg)); + + String location = "testAsyncLogWritesToLog"; + assertTrue("no location", !line1.contains(location)); + } + +} Added: logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/CachedClockTest.java URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/CachedClockTest.java?rev=1469103&view=auto ============================================================================== --- logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/CachedClockTest.java (added) +++ logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/CachedClockTest.java Wed Apr 17 23:35:45 2013 @@ -0,0 +1,47 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache license, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the license for the specific language governing permissions and + * limitations under the license. + */ +package org.apache.logging.log4j.core.async; + +import static org.junit.Assert.*; + +import org.apache.logging.log4j.core.async.CachedClock; +import org.junit.Test; + +public class CachedClockTest { + + @Test + public void testLessThan17Millis() { + long millis1 = CachedClock.instance().currentTimeMillis(); + long sysMillis = System.currentTimeMillis(); + + long diff = sysMillis - millis1; + + assertTrue("diff too large: " + diff, diff <= 16); + } + + @Test + public void testAfterWaitStillLessThan17Millis() throws Exception { + Thread.sleep(100); + long millis1 = CachedClock.instance().currentTimeMillis(); + long sysMillis = System.currentTimeMillis(); + + long diff = sysMillis - millis1; + + assertTrue("diff too large: " + diff, diff <= 16); + } + +} Added: logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/ClockFactoryTest.java URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/ClockFactoryTest.java?rev=1469103&view=auto ============================================================================== --- logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/ClockFactoryTest.java (added) +++ logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/ClockFactoryTest.java Wed Apr 17 23:35:45 2013 @@ -0,0 +1,85 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache license, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the license for the specific language governing permissions and + * limitations under the license. + */ +package org.apache.logging.log4j.core.async; + +import static org.junit.Assert.*; + +import org.apache.logging.log4j.core.async.CachedClock; +import org.apache.logging.log4j.core.async.Clock; +import org.apache.logging.log4j.core.async.ClockFactory; +import org.apache.logging.log4j.core.async.CoarseCachedClock; +import org.apache.logging.log4j.core.async.SystemClock; +import org.junit.Test; + +public class ClockFactoryTest { + + @Test + public void testDefaultIsSystemClock() { + System.clearProperty(ClockFactory.PROPERTY_NAME); + assertEquals(SystemClock.class, ClockFactory.getClock().getClass()); + } + + @Test + public void testSpecifySystemClockShort() { + System.setProperty(ClockFactory.PROPERTY_NAME, "SystemClock"); + assertEquals(SystemClock.class, ClockFactory.getClock().getClass()); + } + + @Test + public void testSpecifySystemClockLong() { + System.setProperty(ClockFactory.PROPERTY_NAME, SystemClock.class.getName()); + assertEquals(SystemClock.class, ClockFactory.getClock().getClass()); + } + + @Test + public void testSpecifyCachedClockShort() { + System.setProperty(ClockFactory.PROPERTY_NAME, "CachedClock"); + assertEquals(CachedClock.class, ClockFactory.getClock().getClass()); + } + + @Test + public void testSpecifyCachedClockLong() { + System.setProperty(ClockFactory.PROPERTY_NAME, CachedClock.class.getName()); + assertEquals(CachedClock.class, ClockFactory.getClock().getClass()); + } + + @Test + public void testSpecifyCoarseCachedClockShort() { + System.setProperty(ClockFactory.PROPERTY_NAME, "CoarseCachedClock"); + assertEquals(CoarseCachedClock.class, ClockFactory.getClock().getClass()); + } + + @Test + public void testSpecifyCoarseCachedClockLong() { + System.setProperty(ClockFactory.PROPERTY_NAME, CoarseCachedClock.class.getName()); + assertEquals(CoarseCachedClock.class, ClockFactory.getClock().getClass()); + } + + static class MyClock implements Clock { + @Override + public long currentTimeMillis() { + return 42; + } + } + + @Test + public void testCustomClock() { + System.setProperty(ClockFactory.PROPERTY_NAME, MyClock.class.getName()); + assertEquals(MyClock.class, ClockFactory.getClock().getClass()); + } + +} Added: logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/SystemClockTest.java URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/SystemClockTest.java?rev=1469103&view=auto ============================================================================== --- logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/SystemClockTest.java (added) +++ logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/SystemClockTest.java Wed Apr 17 23:35:45 2013 @@ -0,0 +1,47 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache license, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the license for the specific language governing permissions and + * limitations under the license. + */ +package org.apache.logging.log4j.core.async; + +import static org.junit.Assert.*; + +import org.apache.logging.log4j.core.async.SystemClock; +import org.junit.Test; + +public class SystemClockTest { + + @Test + public void testLessThan2Millis() { + long millis1 = new SystemClock().currentTimeMillis(); + long sysMillis = System.currentTimeMillis(); + + long diff = sysMillis - millis1; + + assertTrue("diff too large: " + diff, diff <= 1); + } + + @Test + public void testAfterWaitStillLessThan2Millis() throws Exception { + Thread.sleep(100); + long millis1 = new SystemClock().currentTimeMillis(); + long sysMillis = System.currentTimeMillis(); + + long diff = sysMillis - millis1; + + assertTrue("diff too large: " + diff, diff <= 1); + } + +} Added: logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/perftest/IPerfTestRunner.java URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/perftest/IPerfTestRunner.java?rev=1469103&view=auto ============================================================================== --- logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/perftest/IPerfTestRunner.java (added) +++ logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/perftest/IPerfTestRunner.java Wed Apr 17 23:35:45 2013 @@ -0,0 +1,17 @@ +package org.apache.logging.log4j.core.async.perftest; + +import com.lmax.disruptor.collections.Histogram; + +public interface IPerfTestRunner { + static final String LINE100 = "ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz1234567890!\"#$%&'()-=^~|\\@`[]{};:+*,.<>/?_123456"; + static final String THROUGHPUT_MSG = LINE100 + LINE100 + LINE100 + LINE100 + + LINE100; + static final String LATENCY_MSG = "Short msg"; + + void runThroughputTest(int lines, Histogram histogram); + + void runLatencyTest(int samples, Histogram histogram, long nanoTimeCost, + int threadCount); + void shutdown(); + void log(String finalMessage); +} Added: logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/perftest/MTPerfTest.java URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/perftest/MTPerfTest.java?rev=1469103&view=auto ============================================================================== --- logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/perftest/MTPerfTest.java (added) +++ logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/perftest/MTPerfTest.java Wed Apr 17 23:35:45 2013 @@ -0,0 +1,93 @@ +package org.apache.logging.log4j.core.async.perftest; + +import java.io.File; + +import com.lmax.disruptor.collections.Histogram; + +public class MTPerfTest extends PerfTest { + + public static void main(String[] args) throws Exception { + new MTPerfTest().doMain(args); + } + + @Override + public void runTestAndPrintResult(final IPerfTestRunner runner, + final String name, final int threadCount, String resultFile) + throws Exception { + + // ThreadContext.put("aKey", "mdcVal"); + PerfTest.println("Warming up the JVM..."); + long t1 = System.nanoTime(); + + // warmup at least 2 rounds and at most 1 minute + final Histogram warmupHist = PerfTest.createHistogram(); + final long stop = System.currentTimeMillis() + (60 * 1000); + Runnable run1 = new Runnable() { + public void run() { + for (int i = 0; i < 10; i++) { + final int LINES = PerfTest.throughput ? 50000 : 200000; + runTest(runner, LINES, null, warmupHist, 2); + if (i > 0 && System.currentTimeMillis() >= stop) { + return; + } + } + } + }; + Thread thread1 = new Thread(run1); + Thread thread2 = new Thread(run1); + thread1.start(); + thread2.start(); + thread1.join(); + thread2.join(); + + PerfTest.printf("Warmup complete in %.1f seconds%n", + (System.nanoTime() - t1) / (1000.0 * 1000.0 * 1000.0)); + PerfTest.println("Waiting 10 seconds for buffers to drain warmup data..."); + Thread.sleep(10000); + new File("perftest.log").delete(); + new File("perftest.log").createNewFile(); + + PerfTest.println("Starting the main test..."); + PerfTest.throughput = false; + multiThreadedTestRun(runner, name, threadCount, resultFile); + + Thread.sleep(1000); + PerfTest.throughput = true; + multiThreadedTestRun(runner, name, threadCount, resultFile); + } + + private void multiThreadedTestRun(final IPerfTestRunner runner, + final String name, final int threadCount, String resultFile) + throws Exception { + + final Histogram[] histograms = new Histogram[threadCount]; + for (int i = 0; i < histograms.length; i++) { + histograms[i] = PerfTest.createHistogram(); + } + final int LINES = 256 * 1024; + + Thread[] threads = new Thread[threadCount]; + for (int i = 0; i < threads.length; i++) { + final Histogram histogram = histograms[i]; + threads[i] = new Thread() { + public void run() { +// int latencyCount = threadCount >= 16 ? 1000000 : 5000000; + int latencyCount = 5000000; + int count = PerfTest.throughput ? LINES / threadCount + : latencyCount; + runTest(runner, count, "end", histogram, threadCount); + } + }; + } + for (Thread thread : threads) { + thread.start(); + } + for (Thread thread : threads) { + thread.join(); + } + + for (Histogram histogram : histograms) { + PerfTest.reportResult(resultFile, name, histogram); + } + } +} \ No newline at end of file Added: logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/perftest/PerfTest.java URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/perftest/PerfTest.java?rev=1469103&view=auto ============================================================================== --- logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/perftest/PerfTest.java (added) +++ logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/perftest/PerfTest.java Wed Apr 17 23:35:45 2013 @@ -0,0 +1,168 @@ +package org.apache.logging.log4j.core.async.perftest; + +import java.io.FileWriter; +import java.io.IOException; + +import com.lmax.disruptor.collections.Histogram; + +public class PerfTest { + + private static final String LINE100 = "ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz1234567890!\"#$%&'()-=^~|\\@`[]{};:+*,.<>/?_123456"; + public static final String LINE500 = LINE100 + LINE100 + LINE100 + LINE100 + + LINE100; + + static boolean verbose = false; + static boolean throughput; + + // determine how long it takes to call System.nanoTime() (on average) + static long calcNanoTimeCost() { + final long iterations = 10000000; + long start = System.nanoTime(); + long finish = start; + + for (int i = 0; i < iterations; i++) { + finish = System.nanoTime(); + } + + if (finish <= start) { + throw new IllegalStateException(); + } + + finish = System.nanoTime(); + return (finish - start) / iterations; + } + + static Histogram createHistogram() { + long[] intervals = new long[31]; + long intervalUpperBound = 1L; + for (int i = 0, size = intervals.length - 1; i < size; i++) { + intervalUpperBound *= 2; + intervals[i] = intervalUpperBound; + } + + intervals[intervals.length - 1] = Long.MAX_VALUE; + return new Histogram(intervals); + } + + public static void main(String[] args) throws Exception { + new PerfTest().doMain(args); + } + + public void doMain(String[] args) throws Exception { + String runnerClass = args[0]; + IPerfTestRunner runner = (IPerfTestRunner) Class.forName(runnerClass) + .newInstance(); + String name = args[1]; + String resultFile = args.length > 2 ? args[2] : null; + for (String arg : args) { + if ("-verbose".equalsIgnoreCase(arg)) { + verbose = true; + } + if ("-throughput".equalsIgnoreCase(arg)) { + throughput = true; + } + } + int threadCount = args.length > 2 ? Integer.parseInt(args[3]) : 3; + printf("Starting %s %s (%d)...%n", getClass().getSimpleName(), name, + threadCount); + runTestAndPrintResult(runner, name, threadCount, resultFile); + runner.shutdown(); + System.exit(0); + } + + public void runTestAndPrintResult(IPerfTestRunner runner, + final String name, int threadCount, String resultFile) + throws Exception { + Histogram warmupHist = createHistogram(); + + // ThreadContext.put("aKey", "mdcVal"); + println("Warming up the JVM..."); + long t1 = System.nanoTime(); + + // warmup at least 2 rounds and at most 1 minute + final long stop = System.currentTimeMillis() + (60 * 1000); + for (int i = 0; i < 10; i++) { + final int LINES = throughput ? 50000 : 200000; + runTest(runner, LINES, null, warmupHist, 1); + if (i > 0 && System.currentTimeMillis() >= stop) { + return; + } + } + + printf("Warmup complete in %.1f seconds%n", (System.nanoTime() - t1) + / (1000.0 * 1000.0 * 1000.0)); + println("Waiting 10 seconds for buffers to drain warmup data..."); + Thread.sleep(10000); + + println("Starting the main test..."); + // test + throughput = false; + runSingleThreadedTest(runner, name, resultFile); + + Thread.sleep(1000); + + throughput = true; + runSingleThreadedTest(runner, name, resultFile); + } + + private int runSingleThreadedTest(IPerfTestRunner runner, String name, + String resultFile) throws IOException { + Histogram latency = createHistogram(); + final int LINES = throughput ? 50000 : 5000000; + runTest(runner, LINES, "end", latency, 1); + reportResult(resultFile, name, latency); + return LINES; + } + + static void reportResult(String file, String name, Histogram histogram) + throws IOException { + String result = createSamplingReport(name, histogram); + println(result); + + if (file != null) { + FileWriter writer = new FileWriter(file, true); + writer.write(result); + writer.write(System.getProperty("line.separator")); + writer.close(); + } + } + + static void printf(String msg, Object... objects) { + if (verbose) { + System.out.printf(msg, objects); + } + } + + static void println(String msg) { + if (verbose) { + System.out.println(msg); + } + } + + static String createSamplingReport(String name, Histogram histogram) { + Histogram data = histogram; + if (throughput) { + return data.getMax() + " operations/second"; + } + String result = String.format( + "avg=%.0f 99%%=%d 99.99%%=%d sampleCount=%d", data.getMean(), // + data.getTwoNinesUpperBound(), // + data.getFourNinesUpperBound(), // + data.getCount() // + ); + return result; + } + + public void runTest(IPerfTestRunner runner, int lines, String finalMessage, + Histogram histogram, int threadCount) { + if (throughput) { + runner.runThroughputTest(lines, histogram); + } else { + long nanoTimeCost = calcNanoTimeCost(); + runner.runLatencyTest(lines, histogram, nanoTimeCost, threadCount); + } + if (finalMessage != null) { + runner.log(finalMessage); + } + } +} Added: logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/perftest/PerfTestDriver.java URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/perftest/PerfTestDriver.java?rev=1469103&view=auto ============================================================================== --- logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/perftest/PerfTestDriver.java (added) +++ logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/perftest/PerfTestDriver.java Wed Apr 17 23:35:45 2013 @@ -0,0 +1,359 @@ +package org.apache.logging.log4j.core.async.perftest; + +import java.io.BufferedReader; +import java.io.File; +import java.io.FileReader; +import java.io.IOException; +import java.io.InputStreamReader; +import java.nio.CharBuffer; +import java.util.ArrayList; +import java.util.Arrays; +import java.util.List; + +import org.apache.logging.log4j.core.async.AsyncLoggerContextSelector; + +/** + * Runs a sequence of performance tests. + */ +public class PerfTestDriver { + static enum WaitStrategy { + Sleep, Yield, Block + }; + + /** + * Defines the setup for a java process running a performance test. + */ + static class Setup implements Comparable { + private Class _class; + private String _log4jConfig; + private String _name; + private String[] _systemProperties; + private int _threadCount; + private File _temp; + public Stats _stats; + private WaitStrategy _wait; + private String _runner; + + public Setup(Class klass, String runner, String name, + String log4jConfig, int threadCount, WaitStrategy wait, + String... systemProperties) throws IOException { + _class = klass; + _runner = runner; + _name = name; + _log4jConfig = log4jConfig; + _threadCount = threadCount; + _systemProperties = systemProperties; + _wait = wait; + _temp = File.createTempFile("log4jperformance", ".txt"); + } + + List processArguments(String java) { + List args = new ArrayList(); + args.add(java); + args.add("-server"); + args.add("-Xms1g"); + args.add("-Xmx1g"); + + // args.add("-XX:+UseParallelOldGC"); + // args.add("-Xloggc:gc.log"); + // args.add("-XX:+PrintGCTimeStamps"); + // args.add("-XX:+PrintGCDetails"); + // args.add("-XX:+PrintGCDateStamps"); + // args.add("-XX:+PrintGCApplicationStoppedTime"); + // args.add("-XX:+PrintGCApplicationConcurrentTime"); + // args.add("-XX:+PrintSafepointStatistics"); + + args.add("-Dlog4j.configuration=" + _log4jConfig); // log4j1.2 + args.add("-Dlog4j.configurationFile=" + _log4jConfig); // log4j2 + args.add("-Dlogback.configurationFile=" + _log4jConfig);// logback + + int ringBufferSize = getUserSpecifiedRingBufferSize(); + if (ringBufferSize >= 128) { + args.add("-DAsyncLoggerConfig.RingBufferSize=" + ringBufferSize); + args.add("-DAsyncLogger.RingBufferSize=" + ringBufferSize); + } + args.add("-DAsyncLoggerConfig.WaitStrategy=" + _wait); + args.add("-DAsyncLogger.WaitStrategy=" + _wait); + if (_systemProperties != null) { + for (String property : _systemProperties) { + args.add(property); + } + } + args.add("-cp"); + args.add(System.getProperty("java.class.path")); + args.add(_class.getName()); + args.add(_runner); + args.add(_name); + args.add(_temp.getAbsolutePath()); + args.add(String.valueOf(_threadCount)); + return args; + } + + private int getUserSpecifiedRingBufferSize() { + try { + return Integer.parseInt(System.getProperty("RingBufferSize", + "-1")); + } catch (Exception ignored) { + return -1; + } + } + + ProcessBuilder latencyTest(String java) { + return new ProcessBuilder(processArguments(java)); + } + + ProcessBuilder throughputTest(String java) { + List args = processArguments(java); + args.add("-throughput"); + return new ProcessBuilder(args); + } + + @Override + public int compareTo(Setup other) { + // largest ops/sec first + return (int) Math.signum(other._stats._averageOpsPerSec + - _stats._averageOpsPerSec); + } + + public String description() { + String detail = _class.getSimpleName(); + if (PerfTest.class == _class) { + detail = "single thread"; + } else if (MTPerfTest.class == _class) { + detail = _threadCount + " threads"; + } + String target = _runner.substring(_runner.indexOf(".Run") + 4); + return target + ": " + _name + " (" + detail + ")"; + } + } + + /** + * Results of a performance test. + */ + static class Stats { + int _count; + long _average; + long _pct99; + long _pct99_99; + double _latencyRowCount; + int _throughputRowCount; + private long _averageOpsPerSec; + + // example line: avg=828 99%=1118 99.99%=5028 Count=3125 + public Stats(String raw, int repeat) { + String[] lines = raw.split("[\\r\\n]+"); + long totalOps = 0; + for (String line : lines) { + if (line.startsWith("avg")) { + _latencyRowCount++; + String[] parts = line.split(" "); + int i = 0; + _average += Long.parseLong(parts[i++].split("=")[1]); + _pct99 += Long.parseLong(parts[i++].split("=")[1]); + _pct99_99 += Long.parseLong(parts[i++].split("=")[1]); + _count += Integer.parseInt(parts[i++].split("=")[1]); + } else { + _throughputRowCount++; + String number = line.substring(0, line.indexOf(' ')); + long opsPerSec = Long.parseLong(number); + totalOps += opsPerSec; + } + } + _averageOpsPerSec = totalOps / (int) _throughputRowCount; + } + + public String toString() { + String fmt = "throughput: %,d ops/sec. latency(ns): avg=%.1f 99%% < %.1f 99.99%% < %.1f (%d samples)"; + return String.format(fmt, _averageOpsPerSec, // + _average / _latencyRowCount, // mean latency + _pct99 / _latencyRowCount, // 99% observations less than + _pct99_99 / _latencyRowCount,// 99.99% observs less than + _count); + } + } + + // single-threaded performance test + private static Setup s(String config, String runner, String name, + String... systemProperties) throws IOException { + WaitStrategy wait = WaitStrategy.valueOf(System.getProperty( + "WaitStrategy", "Sleep")); + return new Setup(PerfTest.class, runner, name, config, 1, wait, + systemProperties); + } + + // multi-threaded performance test + private static Setup m(String config, String runner, String name, + int threadCount, String... systemProperties) throws IOException { + WaitStrategy wait = WaitStrategy.valueOf(System.getProperty( + "WaitStrategy", "Sleep")); + return new Setup(MTPerfTest.class, runner, name, config, threadCount, + wait, systemProperties); + } + + public static void main(String[] args) throws Exception { + final String ALL_ASYNC = "-DLog4jContextSelector=" + + AsyncLoggerContextSelector.class.getName(); + final String CACHEDCLOCK = "-DAsyncLogger.Clock=CachedClock"; + final String SYSCLOCK = ""; + final String LOG12 = RunLog4j1.class.getName(); + final String LOG20 = RunLog4j2.class.getName(); + final String LOGBK = RunLogback.class.getName(); + + long start = System.nanoTime(); + List tests = new ArrayList(); + // includeLocation=false + tests.add(s("perf3PlainNoLoc.xml", LOG20, "Loggers all async", + ALL_ASYNC, SYSCLOCK)); + tests.add(s("perf7MixedNoLoc.xml", LOG20, "Loggers mixed sync/async")); + tests.add(s("perf-logback.xml", LOGBK, "Sync")); + tests.add(s("perf-log4j12.xml", LOG12, "Sync")); + tests.add(s("perf3PlainNoLoc.xml", LOG20, "Sync")); + tests.add(s("perf-logback-async.xml", LOGBK, "Async Appender")); + tests.add(s("perf-log4j12-async.xml", LOG12, "Async Appender")); + tests.add(s("perf5AsyncApndNoLoc.xml", LOG20, "Async Appender")); + + // includeLocation=true + // tests.add(s("perf6AsyncApndLoc.xml", LOG20, + // "Async Appender includeLocation")); + // tests.add(s("perf8MixedLoc.xml", LOG20, + // "Mixed sync/async includeLocation")); + // tests.add(s("perf4PlainLocation.xml", LOG20, + // "Loggers all async includeLocation", ALL_ASYNC)); + // tests.add(s("perf4PlainLocation.xml", LOG20, + // "Loggers all async includeLocation CachedClock", ALL_ASYNC, + // CACHEDCLOCK)); + // tests.add(s("perf4PlainLocation.xml", LOG20, + // "Sync includeLocation")); + + // appenders + // tests.add(s("perf1syncFile.xml", LOG20, "FileAppender")); + // tests.add(s("perf1syncFastFile.xml", LOG20, "FastFileAppender")); + // tests.add(s("perf2syncRollFile.xml", LOG20, "RollFileAppender")); + // tests.add(s("perf2syncRollFastFile.xml", LOG20, + // "RollFastFileAppender")); + + final int MAX_THREADS = 16; // 64 takes a LONG time + for (int i = 2; i <= MAX_THREADS; i *= 2) { + // includeLocation = false + tests.add(m("perf-logback.xml", LOGBK, "Sync", i)); + tests.add(m("perf-log4j12.xml", LOG12, "Sync", i)); + tests.add(m("perf3PlainNoLoc.xml", LOG20, "Sync", i)); + tests.add(m("perf-logback-async.xml", LOGBK, "Async Appender", i)); + tests.add(m("perf-log4j12-async.xml", LOG12, "Async Appender", i)); + tests.add(m("perf5AsyncApndNoLoc.xml", LOG20, "Async Appender", i)); + tests.add(m("perf3PlainNoLoc.xml", LOG20, "Loggers all async", i, + ALL_ASYNC, SYSCLOCK)); + tests.add(m("perf7MixedNoLoc.xml", LOG20, + "Loggers mixed sync/async", i)); + + // includeLocation=true + // tests.add(m("perf6AsyncApndLoc.xml", LOG20, + // "Async Appender includeLocation", i)); + // tests.add(m("perf8MixedLoc.xml", LOG20, + // "Mixed sync/async includeLocation", i)); + // tests.add(m("perf4PlainLocation.xml", LOG20, + // "Loggers all async includeLocation", i, ALL_ASYNC)); + // tests.add(m("perf4PlainLocation.xml", LOG20, + // "Loggers all async includeLocation CachedClock", i, + // ALL_ASYNC, CACHEDCLOCK)); + // tests.add(m("perf4PlainLocation.xml", LOG20, + // "Sync includeLocation", i)); + + // appenders + // tests.add(m("perf1syncFile.xml", LOG20, "FileAppender", i)); + // tests.add(m("perf1syncFastFile.xml", LOG20, "FastFileAppender", + // i)); + // tests.add(m("perf2syncRollFile.xml", LOG20, "RollFileAppender", + // i)); + // tests.add(m("perf2syncRollFastFile.xml", LOG20, + // "RollFastFileAppender", i)); + } + + String java = args.length > 0 ? args[0] : "java"; + int repeat = args.length > 1 ? Integer.parseInt(args[1]) : 5; + int x = 0; + for (Setup config : tests) { + System.out.print(config.description()); + ProcessBuilder pb = config.throughputTest(java); + pb.redirectErrorStream(true); // merge System.out and System.err + long t1 = System.nanoTime(); + // int count = config._threadCount >= 16 ? 2 : repeat; + int count = repeat; + runPerfTest(count, x++, config, pb); + System.out.printf(" took %.1f seconds%n", (System.nanoTime() - t1) + / (1000.0 * 1000.0 * 1000.0)); + + FileReader reader = new FileReader(config._temp); + CharBuffer buffer = CharBuffer.allocate(256 * 1024); + reader.read(buffer); + reader.close(); + config._temp.delete(); + buffer.flip(); + + String raw = buffer.toString(); + System.out.print(raw); + Stats stats = new Stats(raw, repeat); + System.out.println(stats); + System.out.println("-----"); + config._stats = stats; + } + new File("perftest.log").delete(); + System.out + .printf("Done. Total duration: %.1f minutes%n", + (System.nanoTime() - start) + / (60.0 * 1000.0 * 1000.0 * 1000.0)); + + printRanking((Setup[]) tests.toArray(new Setup[tests.size()])); + } + + private static void printRanking(Setup[] tests) { + System.out.println(); + System.out.println("Ranking:"); + Arrays.sort(tests); + for (int i = 0; i < tests.length; i++) { + Setup setup = tests[i]; + System.out.println((i + 1) + ". " + setup.description() + ": " + + setup._stats); + } + } + + private static void runPerfTest(int repeat, int setupIndex, Setup config, + ProcessBuilder pb) throws IOException, InterruptedException { + for (int i = 0; i < repeat; i++) { + System.out.print(" (" + (i + 1) + "/" + repeat + ")..."); + final Process process = pb.start(); + + final boolean[] stop = { false }; + printProcessOutput(process, stop); + process.waitFor(); + stop[0] = true; + + File gc = new File("gc" + setupIndex + "_" + i + + config._log4jConfig + ".log"); + if (gc.exists()) { + gc.delete(); + } + new File("gc.log").renameTo(gc); + } + } + + private static Thread printProcessOutput(final Process process, + final boolean[] stop) { + + Thread t = new Thread("OutputWriter") { + public void run() { + BufferedReader in = new BufferedReader(new InputStreamReader( + process.getInputStream())); + try { + String line = null; + while (!stop[0] && (line = in.readLine()) != null) { + System.out.println(line); + } + } catch (Exception ignored) { + } + } + }; + t.start(); + return t; + } +} Added: logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/perftest/PerfTestResultFormatter.java URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/perftest/PerfTestResultFormatter.java?rev=1469103&view=auto ============================================================================== --- logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/perftest/PerfTestResultFormatter.java (added) +++ logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/async/perftest/PerfTestResultFormatter.java Wed Apr 17 23:35:45 2013 @@ -0,0 +1,167 @@ +package org.apache.logging.log4j.core.async.perftest; + +import java.io.BufferedReader; +import java.io.InputStreamReader; +import java.text.DecimalFormat; +import java.text.NumberFormat; +import java.text.ParseException; +import java.util.Arrays; +import java.util.Comparator; +import java.util.List; +import java.util.Map; +import java.util.Set; +import java.util.TreeMap; + +/** + * Utility class that can read the "Ranking" output of the PerfTestDriver and + * format it for pasting into Excel. + */ +class PerfTestResultFormatter { + static final String LF = System.getProperty("line.separator"); + static final NumberFormat NUM = new DecimalFormat("#,##0"); + + static class Stats { + long throughput; + double avgLatency; + double latency99Pct; + double latency99_99Pct; + + Stats(String throughput, String avg, String lat99, String lat99_99) + throws ParseException { + this.throughput = NUM.parse(throughput.trim()).longValue(); + this.avgLatency = Double.parseDouble(avg.trim()); + this.latency99Pct = Double.parseDouble(lat99.trim()); + this.latency99_99Pct = Double.parseDouble(lat99_99.trim()); + } + } + + private Map> results = new TreeMap>(); + + public PerfTestResultFormatter() { + } + + public String format(String text) throws ParseException { + results.clear(); + String[] lines = text.split("[\\r\\n]+"); + for (String line : lines) { + process(line); + } + return latencyTable() + LF + throughputTable(); + } + + private String latencyTable() { + StringBuilder sb = new StringBuilder(4 * 1024); + Set subKeys = results.values().iterator().next().keySet(); + char[] tabs = new char[subKeys.size()]; + Arrays.fill(tabs, '\t'); + String sep = new String(tabs); + sb.append("\tAverage latency" + sep + "99% less than" + sep + + "99.99% less than"); + sb.append(LF); + for (int i = 0; i < 3; i++) { + for (String subKey : subKeys) { + sb.append("\t").append(subKey); + } + } + sb.append(LF); + for (String key : results.keySet()) { + sb.append(key); + for (int i = 0; i < 3; i++) { + Map sub = results.get(key); + for (String subKey : sub.keySet()) { + Stats stats = sub.get(subKey); + switch (i) { + case 0: + sb.append("\t").append((long) stats.avgLatency); + break; + case 1: + sb.append("\t").append((long) stats.latency99Pct); + break; + case 2: + sb.append("\t").append((long) stats.latency99_99Pct); + break; + } + } + } + sb.append(LF); + } + return sb.toString(); + } + + private String throughputTable() { + StringBuilder sb = new StringBuilder(4 * 1024); + Set subKeys = results.values().iterator().next().keySet(); + sb.append("\tThroughput per thread (msg/sec)"); + sb.append(LF); + for (String subKey : subKeys) { + sb.append("\t").append(subKey); + } + sb.append(LF); + for (String key : results.keySet()) { + sb.append(key); + Map sub = results.get(key); + for (String subKey : sub.keySet()) { + Stats stats = sub.get(subKey); + sb.append("\t").append((long) stats.throughput); + } + sb.append(LF); + } + return sb.toString(); + } + + private void process(String line) throws ParseException { + String key = line.substring(line.indexOf('.') + 1, line.indexOf('(')); + String sub = line.substring(line.indexOf('(') + 1, line.indexOf(')')); + String throughput = line.substring(line.indexOf("throughput: ") + + "throughput: ".length(), line.indexOf(" ops")); + String avg = line.substring(line.indexOf("avg=") + "avg=".length(), + line.indexOf(" 99%")); + String pct99 = line.substring( + line.indexOf("99% < ") + "99% < ".length(), + line.indexOf(" 99.99%")); + String pct99_99 = line.substring(line.indexOf("99.99% < ") + + "99.99% < ".length(), line.lastIndexOf('(') - 1); + Stats stats = new Stats(throughput, avg, pct99, pct99_99); + Map map = results.get(key.trim()); + if (map == null) { + map = new TreeMap(sort()); + results.put(key.trim(), map); + } + String subKey = sub.trim(); + if ("single thread".equals(subKey)) { + subKey = "1 thread"; + } + map.put(subKey, stats); + } + + private Comparator sort() { + return new Comparator() { + List expected = Arrays.asList("1 thread", "2 threads", + "4 threads", "8 threads", "16 threads", "32 threads", + "64 threads"); + + @Override + public int compare(String o1, String o2) { + int i1 = expected.indexOf(o1); + int i2 = expected.indexOf(o2); + if (i1 < 0 || i2 < 0) { + return o1.compareTo(o2); + } + return i1 - i2; + } + }; + } + + public static void main(String[] args) throws Exception { + PerfTestResultFormatter fmt = new PerfTestResultFormatter(); + BufferedReader reader = new BufferedReader(new InputStreamReader( + System.in)); + String line = null; + while ((line = reader.readLine()) != null) { + fmt.process(line); + } + System.out.println(fmt.latencyTable()); + System.out.println(); + System.out.println(fmt.throughputTable()); + } +} \ No newline at end of file