carnold 2005/02/09 21:07:31
Modified: performance Makefile.am main.cpp
tests/input Makefile.am
Added: tests performance.xml
tests/input/ndc Makefile.am
tests/input/performance Makefile.am file-bufferedio.xml
file-noflush.xml file.xml null-appender-info.xml
null-appender.xml off.xml telnet.xml
Removed: performance logging.sh
Log:
LOGCXX-57: Rework performance test as port of log4j's
Revision Changes Path
1.8 +0 -3 logging-log4cxx/performance/Makefile.am
Index: Makefile.am
===================================================================
RCS file: /home/cvs/logging-log4cxx/performance/Makefile.am,v
retrieving revision 1.7
retrieving revision 1.8
diff -u -r1.7 -r1.8
--- Makefile.am 16 Dec 2004 00:21:46 -0000 1.7
+++ Makefile.am 10 Feb 2005 05:07:31 -0000 1.8
@@ -1,4 +1,3 @@
-SUBDIRS = xml
noinst_PROGRAMS = logging
performanceincdir = $(includedir)/log4cxx
@@ -9,5 +8,3 @@
logging_SOURCES = main.cpp nullappender.cpp
logging_LDADD = $(top_builddir)/src/liblog4cxx.la
-EXTRA_DIST = logging.sh
-
1.15 +152 -116 logging-log4cxx/performance/main.cpp
Index: main.cpp
===================================================================
RCS file: /home/cvs/logging-log4cxx/performance/main.cpp,v
retrieving revision 1.14
retrieving revision 1.15
diff -u -r1.14 -r1.15
--- main.cpp 4 Jan 2005 03:37:07 -0000 1.14
+++ main.cpp 10 Feb 2005 05:07:31 -0000 1.15
@@ -14,142 +14,178 @@
* limitations under the License.
*/
-#include <log4cxx/ndc.h>
-#include <log4cxx/logmanager.h>
#include <log4cxx/logger.h>
-#include <log4cxx/helpers/exception.h>
-#include <log4cxx/helpers/optionconverter.h>
-#include <log4cxx/xml/domconfigurator.h>
-#include <apr_general.h>
-#include <apr_pools.h>
+#include <apr.h>
#include <apr_time.h>
#include <iostream>
-
-#define _T(str) str
+#include <log4cxx/helpers/transcoder.h>
+#include <log4cxx/stream.h>
+#include <log4cxx/appender.h>
+#include <sstream>
+#include "nullappender.h"
+#include <log4cxx/consoleappender.h>
+#include <log4cxx/patternlayout.h>
+#include <log4cxx/helpers/pool.h>
+#include <log4cxx/xml/domconfigurator.h>
+#include <log4cxx/stream.h>
using namespace log4cxx;
using namespace log4cxx::helpers;
+using namespace log4cxx::performance;
+using namespace log4cxx::xml;
-int runLength;
-int delay = -1;
-/*
- A delay is applied after every <code>burstLen</code> log
- requests. The default value of this constant is 100. */
-int burstLen = 100;
-int DELAY_MULT = 1000/burstLen;
-LoggerPtr logger =
Logger::getLogger(_T("A0123456789.B0123456789.C0123456789"));
-void Usage(const std::string& processName, const std::string& msg)
-{
- std::cerr << msg << std::endl;
- std::cerr <<
- "Usage: " << processName
- << " confFile runLength [delay] [burstLen]" << std::endl
- << " confFile is an XML configuration file and" <<
std::endl
- << " runLength (integer) is the length of test loop."
<< std::endl
- << " delay is the time in millisecs to wait every
burstLen log requests." << std::endl;
- exit(EXIT_FAILURE);
-}
+/**
+ * Logs in a loop a number of times and measure the elapsed time.
+ *
+ * @author Ceki Gülcü
+ */
+class Loop {
+ static int runLength;
+ static LoggerPtr logger;
+ typedef long (*loopFunc)(long,LoggerPtr&);
+ static loopFunc loop;
+public:
+
+ static void main(std::vector<LogString>& args) {
+ LoggerPtr j(Logger::getLogger("org.apache.log4j.joran"));
+ j->setAdditivity(false);
+ j->setLevel(Level::WARN);
+ AppenderPtr a(new ConsoleAppender());
+ a->setLayout(new PatternLayout(LOG4CXX_STR("%d %level %c - %m%n")));
+ a->setName(LOG4CXX_STR("console"));
+ Pool p;
+ a->activateOptions(p);
+ j->addAppender(a);
+
+ if (args.size() >= 2) {
+ init(args);
+ } else {
+ usage("Wrong number of arguments.");
+ }
+ //memPrint();
+ (*loop)(1000, logger);
+ //memPrint();
+
+ long res = (*loop)(runLength, logger);
+ double average = (res * 1000.0) / runLength;
+ std::cout <<
+ "Loop completed in [" << res << "] milliseconds, or [" << average
+ << "] microseconds per log.";
+
+ //memPrint();
+ }
+
+ static void usage(const char* msg) {
+ std::cout << msg << '\n';
+ std::cout <<
+ "Usage: performance runLength configFile [char wide stream wide-stream
bad-stream bad-wide-stream]\n";
+ std::cout << "\trunLength (integer) is the length of test loop.";
+ std::cout << "\tconfigFile is an XML configuration file";
+
+ exit(1);
+ }
+
+ static void memPrint() {
+ }
+
+ static void init(std::vector<LogString>& args) {
+ std::basic_istringstream<logchar> is(args[0]);
+ is >> runLength;
+ DOMConfigurator::configure(args[1]);
+ if (args.size() == 3) {
+ if(args[2] == LOG4CXX_STR("char")) {
+ loop = Loop::loopChar;
+ } else if (args[2] == LOG4CXX_STR("wide")) {
+ loop = Loop::loopWide;
+ } else if (args[2] == LOG4CXX_STR("stream")) {
+ loop = Loop::loopStream;
+ } else if (args[2] == LOG4CXX_STR("wide-stream")) {
+ loop = Loop::loopWideStream;
+ } else if (args[2] == LOG4CXX_STR("bad-stream")) {
+ loop = Loop::loopBadStream;
+ } else if (args[2] == LOG4CXX_STR("bad-wide-stream")) {
+ loop = Loop::loopBadWideStream;
+ } else {
+ usage("Unrecognized loop type.");
+ }
+ }
+ }
-void init(const std::string& configFile, const std::string& runLengthStr,
- const std::string& delayStr, const std::string&
burstLenStr)
-{
- runLength = atoi(runLengthStr.c_str());
- if (runLength < 1)
- {
- throw IllegalArgumentException("run Length must be greater
than 0");
- }
- if (!delayStr.empty())
- {
- delay = atoi(delayStr.c_str());
- }
- if (!burstLenStr.empty())
- {
- burstLen = atoi(burstLenStr.c_str());
- DELAY_MULT = 1000/burstLen;
- }
+ static long loopChar(long len, LoggerPtr& logger) {
+ const char* msg = "Some fix message of medium length.";
+ apr_time_t before = apr_time_now();
+ for (int i = 0; i < len; i++) {
+ LOG4CXX_DEBUG(logger, msg);
+ }
+ return (apr_time_now() - before) / 1000;
+ }
-#ifdef LOG4CXX_HAVE_XML
- xml::DOMConfigurator::configure(configFile);
-#endif
-}
+ static long loopWide(long len, LoggerPtr& logger) {
+ const wchar_t* msg = L"Some fix message of medium length.";
+ apr_time_t before = apr_time_now();
+ for (int i = 0; i < len; i++) {
+ LOG4CXX_DEBUG(logger, msg);
+ }
+ return (apr_time_now() - before) / 1000;
+ }
-double NoDelayLoop(LoggerPtr logger, const std::string& msg)
-{
- log4cxx_time_t before = apr_time_now();
- for(int i = 0; i < runLength; i++) {
- logger->info(msg, LOG4CXX_LOCATION);
+ static long loopStream(long len, LoggerPtr& logger) {
+ const char* msg = "Some fix message of medium length.";
+ apr_time_t before = apr_time_now();
+ logstream ls(logger, Level::DEBUG);
+ for (int i = 0; i < len; i++) {
+ ls << msg << LOG4CXX_ENDMSG;
}
- log4cxx_time_t after = apr_time_now();
- return (after - before)/(runLength*1000);
-}
+ return (apr_time_now() - before) / 1000;
+ }
-double DelayedLoop(LoggerPtr logger, const std::string& msg)
-{
+ static long loopWideStream(long len, LoggerPtr& logger) {
+ const wchar_t* msg = L"Some fix message of medium length.";
+ apr_time_t before = apr_time_now();
+ logstream ls(logger, Level::DEBUG);
+ for (int i = 0; i < len; i++) {
+ ls << msg << LOG4CXX_ENDMSG;
+ }
+ return (apr_time_now() - before) / 1000;
+ }
- log4cxx_time_t before = apr_time_now();
- int j = 0;
- for(int i = 0; i < runLength; i++)
- {
- logger->info(msg, LOG4CXX_LOCATION);
- if(j++ == burstLen)
- {
- j = 0;
- try
- {
- apr_sleep(delay * 1000);
- }
- catch(Exception&)
- {
- }
- }
-
- }
- double actualTime = (apr_time_now()-before)/(runLength*1000);
- std::cout << "actual time: " << actualTime << std::endl;
- return (actualTime - delay*DELAY_MULT);
-}
+ static long loopBadStream(long len, LoggerPtr& logger) {
+ const char* msg = "Some fix message of medium length.";
+ apr_time_t before = apr_time_now();
+ for (int i = 0; i < len; i++) {
+ logstream ls(logger, Level::DEBUG);
+ ls << msg << LOG4CXX_ENDMSG;
+ }
+ return (apr_time_now() - before) / 1000;
+ }
-int main(int argc, const char* const argv[])
-{
- apr_app_initialize(&argc, &argv, NULL);
- int ret = EXIT_SUCCESS;
+ static long loopBadWideStream(long len, LoggerPtr& logger) {
+ const wchar_t* msg = L"Some fix message of medium length.";
+ apr_time_t before = apr_time_now();
+ for (int i = 0; i < len; i++) {
+ logstream ls(logger, Level::DEBUG);
+ ls << msg << LOG4CXX_ENDMSG;
+ }
+ return (apr_time_now() - before) / 1000;
+ }
- try
- {
- if(argc == 3)
- init(argv[1], argv[2], "", "");
- else if(argc == 5)
- init(argv[1], argv[2], argv[3], argv[4]);
- else
- Usage(argv[0], "Wrong number of arguments.");
-
-
- NDC::push(_T("some context"));
-
- double delta;
- std::string msg =
_T("ABCDEGHIJKLMNOPQRSTUVWXYZabcdeghijklmnopqrstuvwxyz1234567890");
- if(delay <= 0)
- {
- delta = NoDelayLoop(logger, msg);
- }
- else
- {
- delta = DelayedLoop(logger, msg);
- }
- std::cout << (int)delta << std::endl;
+};
- LogManager::shutdown();
- }
- catch(Exception&)
- {
- ret = EXIT_FAILURE;
- }
+LoggerPtr
Loop::logger(Logger::getLogger("org.apache.log4j.performance.Loop"));
+int Loop::runLength = 0;
+Loop::loopFunc Loop::loop = Loop::loopChar;
- apr_terminate();
- return ret;
+int main(int argc, const char* const argv[])
+{
+ apr_app_initialize(&argc, &argv, NULL);
+ std::vector<LogString> args(argc - 1);
+ for (int i = 1; i < argc; i++) {
+ Transcoder::decode(argv[i], args[i - 1]);
+ }
+ Loop::main(args);
}
1.1 logging-log4cxx/tests/performance.xml
Index: performance.xml
===================================================================
<project name="log4cxx-performance" default="usage" basedir="." >
<property name="runlen" value="100000"/>
<property name="loop" value="char"/>
<property name="debug" value="true"/>
<property name="log4cxx.lib.type" value="shared"/>
<target name="usage">
<echo>
These are the targets supported by this ANT build scpript:
all - run all performance tests
null - run performance tests using NullAppender
file - run performance tests using FileAppender
file-noflush - run performance tests using FileAppender without
immediate flush
file-bufferedio - run performance tests using FileAppender without
buffered IO
telnet - run performace tests with TelnetAppender
-Dloop=[char wide stream wide-stream bad-stream bad-wide-stream]
-Drunlen=100000
</echo>
</target>
<target name="clean">
<delete>
<fileset dir="./output/" includes="**"/>
</delete>
</target>
<target name="all" depends="off, null, file, file-noflush,
file-bufferedio"/>
<target name="off">
<echo message="*** logging with hierarchy threshold = off ***"/>
<antcall target="loop-group">
<param name="configFile" value="input/performance/off.xml"/>
</antcall>
</target>
<target name="null">
<echo message="*** logging with NullAppender ***"/>
<antcall target="loop-group">
<param name="configFile" value="input/performance/null-appender.xml"/>
</antcall>
</target>
<target name="file" depends="clean">
<echo message="*** logging with FileAppender ***"/>
<antcall target="loop-group">
<param name="configFile" value="input/performance/file.xml"/>
</antcall>
</target>
<target name="file-noflush" depends="clean">
<echo message="*** logging with FileAppender, ImmediateFlush=false ***"/>
<antcall target="loop-group">
<param name="configFile" value="input/performance/file-noflush.xml"/>
</antcall>
</target>
<target name="file-bufferedio" depends="clean">
<echo message="*** logging with FileAppender, BufferedIO=true ***"/>
<antcall target="loop-group">
<param name="configFile" value="input/performance/file-bufferedio.xml"/>
</antcall>
</target>
<target name="telnet" depends="clean">
<echo message="*** logging with TelnetAppender ***"/>
<antcall target="loop-group">
<param name="configFile" value="input/performance/telnet.xml"/>
</antcall>
</target>
<target name="loop">
<condition property="lib-suffix" value="d">
<istrue value="${debug}"/>
</condition>
<property name="lib-suffix" value=""/>
<condition property="log4cxx.lib.dir"
value="../build/debug/${log4cxx.lib.type}">
<istrue value="${debug}"/>
</condition>
<property name="log4cxx.lib.dir"
value="../build/release/${log4cxx.lib.type}"/>
<property name="apr.lib.dir" value="${log4cxx.lib.dir}"/>
<property name="aprutil.lib.dir" value="${apr.lib.dir}"/>
<property name="apriconv.lib.dir" value="${aprutil.lib.dir}"/>
<echo message="Pattern is ${pattern}"/>
<exec executable="${log4cxx.lib.dir}/performance">
<arg value="${runlen}"/>
<arg value="${configFile}"/>
<arg value="${loop}"/>
<env key="pattern" value="${pattern}"/>
<env key="LD_LIBRARY_PATH"
value="${log4cxx.lib.dir}:${apr.lib.dir}:${aprutil.lib.dir}:${apriconv.lib.dir}:${env.LD_LIBRARY_PATH}"/>
<env key="DYLD_LIBRARY_PATH"
value="${log4cxx.lib.dir}:${apr.lib.dir}:${aprutil.lib.dir}:${apriconv.lib.dir}:${env.DYLD_LIBRARY_PATH}"/>
</exec>
</target>
<target name="loop-group">
<mkdir dir="output"/>
<antcall target="loop">
<param name="configFile" value="${configFile}"/>
<param name="pattern" value="%p - %m%n"/>
</antcall>
<antcall target="loop">
<param name="configFile" value="${configFile}"/>
<param name="pattern" value="%-5p - %m%n"/>
</antcall>
<antcall target="loop">
<param name="configFile" value="${configFile}"/>
<param name="pattern" value="%r [%t] %-5p %c{2} %x - %m%n"/>
</antcall>
<antcall target="loop">
<param name="configFile" value="${configFile}"/>
<param name="pattern" value="%r [%t] %-5p %.10c %x - %m%n"/>
</antcall>
<antcall target="loop">
<param name="configFile" value="${configFile}"/>
<param name="pattern" value="%r [%t] %-5p %.20c %x - %m%n"/>
</antcall>
<antcall target="loop">
<param name="configFile" value="${configFile}"/>
<param name="pattern" value="%r [%t] %-5p %c - %m%n"/>
</antcall>
<antcall target="loop">
<param name="configFile" value="${configFile}"/>
<param name="pattern" value="%d{ISO8601} [%t] %-5p %c %x - %m%n"/>
</antcall>
<antcall target="loop">
<param name="configFile" value="${configFile}"/>
<param name="pattern" value="%d{yyyy-MM-dd HH:mm:ss,SSS} [%t] %-5p %c
%x - %m%n"/>
</antcall>
<antcall target="loop">
<param name="configFile" value="${configFile}"/>
<param name="pattern" value="%l - %m%n"/>
</antcall>
<!-- antcall target="loop">
<param name="configFile" value="${configFile}"/>
<param name="pattern" value="%C.%M.%L - %m%n"/>
</antcall -->
</target>
</project>
1.2 +1 -1 logging-log4cxx/tests/input/Makefile.am
Index: Makefile.am
===================================================================
RCS file: /home/cvs/logging-log4cxx/tests/input/Makefile.am,v
retrieving revision 1.1
retrieving revision 1.2
diff -u -r1.1 -r1.2
--- Makefile.am 18 Jan 2004 16:24:29 -0000 1.1
+++ Makefile.am 10 Feb 2005 05:07:31 -0000 1.2
@@ -1,2 +1,2 @@
-SUBDIRS = xml
+SUBDIRS = ndb performance xml
EXTRA_DIST = *.properties
1.1 logging-log4cxx/tests/input/ndc/Makefile.am
Index: Makefile.am
===================================================================
EXTRA_DIST = *.properties
1.1 logging-log4cxx/tests/input/performance/Makefile.am
Index: Makefile.am
===================================================================
EXTRA_DIST = *.xml
1.1
logging-log4cxx/tests/input/performance/file-bufferedio.xml
Index: file-bufferedio.xml
===================================================================
<?xml version="1.0" encoding="UTF-8" ?>
<log4j:configuration xmlns:log4j='http://logging.apache.org/'>
<appender name="FILE" class="org.apache.log4j.FileAppender">
<param name="File" value="output/temp.${build.number}"/>
<param name="BufferedIO" value="true"/>
<param name="Append" value="false"/>
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="${pattern}"/>
</layout>
</appender>
<root>
<level value="debug" />
<appender-ref ref="FILE" />
</root>
</log4j:configuration>
1.1 logging-log4cxx/tests/input/performance/file-noflush.xml
Index: file-noflush.xml
===================================================================
<?xml version="1.0" encoding="UTF-8" ?>
<log4j:configuration xmlns:log4j='http://logging.apache.org/'>
<appender name="FILE" class="org.apache.log4j.FileAppender">
<param name="File" value="output/temp.${build.number}"/>
<param name="ImmediateFlush" value="false"/>
<param name="Append" value="false"/>
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="${pattern}"/>
</layout>
</appender>
<root>
<level value="debug" />
<appender-ref ref="FILE" />
</root>
</log4j:configuration>
1.1 logging-log4cxx/tests/input/performance/file.xml
Index: file.xml
===================================================================
<?xml version="1.0" encoding="UTF-8" ?>
<log4j:configuration xmlns:log4j='http://logging.apache.org/'>
<appender name="FILE" class="org.apache.log4j.FileAppender">
<param name="File" value="output/temp.${build.number}"/>
<param name="ImmediateFlush" value="true"/>
<param name="Append" value="false"/>
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="${pattern}"/>
</layout>
</appender>
<root>
<level value="debug" />
<appender-ref ref="FILE" />
</root>
</log4j:configuration>
1.1
logging-log4cxx/tests/input/performance/null-appender-info.xml
Index: null-appender-info.xml
===================================================================
<?xml version="1.0" encoding="UTF-8" ?>
<!-- This config file has the root logger set to the "info" level. It is
used by the ANT build file "performance.xml".
-->
<log4j:configuration xmlns:log4j='http://logging.apache.org/'>
<appender name="NULL" class="org.apache.log4j.performance.NullAppender">
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="${pattern}"/>
</layout>
</appender>
<appender name="CON" class="org.apache.log4j.ConsoleAppender">
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="%d %c - %m%n"/>
</layout>
</appender>
<root>
<level value="info" />
<appender-ref ref="NULL" />
<appender-ref ref="CON" />
</root>
</log4j:configuration>
1.1 logging-log4cxx/tests/input/performance/null-appender.xml
Index: null-appender.xml
===================================================================
<?xml version="1.0" encoding="UTF-8" ?>
<log4j:configuration xmlns:log4j='http://logging.apache.org/'>
<appender name="NULL" class="org.apache.log4j.performance.NullAppender">
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="${pattern}"/>
</layout>
</appender>
<root>
<level value="debug" />
<appender-ref ref="NULL" />
</root>
</log4j:configuration>
1.1 logging-log4cxx/tests/input/performance/off.xml
Index: off.xml
===================================================================
<?xml version="1.0" encoding="UTF-8" ?>
<log4j:configuration xmlns:log4j='http://logging.apache.org/'
threshold="off"/>
1.1 logging-log4cxx/tests/input/performance/telnet.xml
Index: telnet.xml
===================================================================
<?xml version="1.0" encoding="UTF-8" ?>
<log4j:configuration xmlns:log4j='http://logging.apache.org/'>
<appender name="TELNET" class="org.apache.log4j.net.TelnetAppender">
<param name="port" value="7023"/>
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="${pattern}"/>
</layout>
</appender>
<root>
<level value="debug" />
<appender-ref ref="TELNET" />
</root>
</log4j:configuration>
