[logback-dev] svn commit: r2293 - in logback/trunk: logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic36 logback-core/src/test/java/ch/qos/logback/core/issue
noreply.ceki at qos.ch
noreply.ceki at qos.ch
Mon Jun 15 20:55:02 CEST 2009
Author: ceki
Date: Mon Jun 15 20:55:01 2009
New Revision: 2293
Added:
logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic36/DateFormattingThreadedThroughputCalculator.java
logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic36/SelectiveDateFormattingRunnable.java
logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/RunnableForThrougputComputation.java
logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/SelectiveLockRunnable.java
logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/ThreadedThroughputCalculator.java
Modified:
logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic36/DateFormatPerfTest.java
logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/LockThroughput.java
Log:
Added ThreadedThroughputCalculator which is a scaffolding class to
perform threaded computations.
This commit is related to LBCLASSIC-36 as well as LBCORE-97
Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic36/DateFormatPerfTest.java
==============================================================================
--- logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic36/DateFormatPerfTest.java (original)
+++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic36/DateFormatPerfTest.java Mon Jun 15 20:55:01 2009
@@ -16,15 +16,10 @@
for (int i = 0; i < 5; i++) {
doRawJoda();
doRawSDF();
- doGuardedJoda();
- doGuardedSDF();
}
print("Raw Joda: ", doRawJoda());
print("Raw SDF: ", doRawSDF());
- print("Guarded Joda: ", doGuardedJoda());
- print("Guarded SDF: ", doGuardedSDF());
-
}
static void print(String msg, double avg) {
@@ -41,22 +36,6 @@
return (System.nanoTime() - start) * 1.0d / RUN_LENGTH;
}
- static double doGuardedJoda() {
- DateTimeFormatter jodaFormat = DateTimeFormat.forPattern(ISO8601_PATTERN);
- long start = System.nanoTime();
- long cache = 0;
- for (int i = 0; i < RUN_LENGTH; ++i) {
- synchronized (jodaFormat) {
- long now = System.currentTimeMillis();
- if (cache != now) {
- cache = now;
- jodaFormat.print(now);
- }
- }
- }
- return (System.nanoTime() - start) * 1.0d / RUN_LENGTH;
- }
-
static double doRawSDF() {
SimpleDateFormat simpleFormat = new SimpleDateFormat(ISO8601_PATTERN);
long timeInMillis = new Date().getTime();
@@ -67,19 +46,4 @@
return (System.nanoTime() - start) * 1.0d / RUN_LENGTH;
}
- static double doGuardedSDF() {
- SimpleDateFormat simpleFormat = new SimpleDateFormat(ISO8601_PATTERN);
- long start = System.nanoTime();
- long cache = 0;
- for (int i = 0; i < RUN_LENGTH; ++i) {
- synchronized (simpleFormat) {
- long now = System.currentTimeMillis();
- if (cache != now) {
- cache = now;
- simpleFormat.format(now);
- }
- }
- }
- return (System.nanoTime() - start) * 1.0d / RUN_LENGTH;
- }
}
Added: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic36/DateFormattingThreadedThroughputCalculator.java
==============================================================================
--- (empty file)
+++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic36/DateFormattingThreadedThroughputCalculator.java Mon Jun 15 20:55:01 2009
@@ -0,0 +1,45 @@
+package ch.qos.logback.classic.issue.lbclassic36;
+
+import ch.qos.logback.classic.issue.lbclassic36.SelectiveDateFormattingRunnable.FormattingModel;
+import ch.qos.logback.core.issue.ThreadedThroughputCalculator;
+
+/**
+ * Measure the threaded throughtput of date formatting operations
+ *
+ * @author Joern Huxhorn
+ * @author Ceki Gulcu
+ */
+public class DateFormattingThreadedThroughputCalculator {
+
+ static int THREAD_COUNT = 16;
+ static long OVERALL_DURATION_IN_MILLIS = 3000;
+
+ public static void main(String args[]) throws InterruptedException {
+
+ ThreadedThroughputCalculator tp = new ThreadedThroughputCalculator(
+ OVERALL_DURATION_IN_MILLIS);
+ tp.printEnvironmentInfo("DateFormatting");
+
+ for (int i = 0; i < 2; i++) {
+ tp.execute(buildArray(FormattingModel.SDF));
+ tp.execute(buildArray(FormattingModel.JODA));
+ }
+
+ tp.execute(buildArray(FormattingModel.JODA));
+ tp.printThroughput("JODA: ");
+
+ tp.execute(buildArray(FormattingModel.SDF));
+ tp.printThroughput("SDF: ");
+
+
+ }
+
+ static SelectiveDateFormattingRunnable[] buildArray(FormattingModel model) {
+ SelectiveDateFormattingRunnable[] array = new SelectiveDateFormattingRunnable[THREAD_COUNT];
+ for (int i = 0; i < THREAD_COUNT; i++) {
+ array[i] = new SelectiveDateFormattingRunnable(model);
+ }
+ return array;
+ }
+
+}
Added: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic36/SelectiveDateFormattingRunnable.java
==============================================================================
--- (empty file)
+++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic36/SelectiveDateFormattingRunnable.java Mon Jun 15 20:55:01 2009
@@ -0,0 +1,86 @@
+package ch.qos.logback.classic.issue.lbclassic36;
+
+import java.text.SimpleDateFormat;
+import org.joda.time.format.DateTimeFormat;
+import org.joda.time.format.DateTimeFormatter;
+
+import ch.qos.logback.core.issue.RunnableForThrougputComputation;
+
+/**
+ * A runnable which behaves differently depending on the desired locking model.
+ *
+ * @author Raplh Goers
+ * @author Ceki Gulcu
+ */
+public class SelectiveDateFormattingRunnable extends
+ RunnableForThrougputComputation {
+
+ public static final String ISO8601_PATTERN = "yyyy-MM-dd HH:mm:ss,SSS";
+
+ enum FormattingModel {
+ SDF, JODA;
+ }
+
+ FormattingModel model;
+ static long CACHE = 0;
+
+ static SimpleDateFormat SDF = new SimpleDateFormat(ISO8601_PATTERN);
+ static final DateTimeFormatter JODA = DateTimeFormat
+ .forPattern(ISO8601_PATTERN);
+
+ SelectiveDateFormattingRunnable(FormattingModel model) {
+ this.model = model;
+ }
+
+ public void run() {
+ switch (model) {
+ case SDF:
+ sdfRun();
+ break;
+ case JODA:
+ jodaRun();
+ break;
+ }
+ }
+
+ void sdfRun() {
+
+ for (;;) {
+ synchronized (SDF) {
+ long now = System.currentTimeMillis();
+ if (CACHE != now) {
+ CACHE = now;
+ SDF.format(now);
+ }
+ }
+ counter++;
+ if (done) {
+ return;
+ }
+ }
+ }
+
+ void jodaRun() {
+ for (;;) {
+ long now = System.currentTimeMillis();
+ if (isCacheStale(now)) {
+ JODA.print(now);
+ }
+ counter++;
+ if (done) {
+ return;
+ }
+ }
+ }
+
+ private static boolean isCacheStale(long now) {
+ synchronized (JODA) {
+ if (CACHE != now) {
+ CACHE = now;
+ return true;
+ }
+ }
+ return false;
+ }
+
+}
Modified: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/LockThroughput.java
==============================================================================
--- logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/LockThroughput.java (original)
+++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/LockThroughput.java Mon Jun 15 20:55:01 2009
@@ -1,7 +1,6 @@
package ch.qos.logback.core.issue;
-import java.util.concurrent.locks.Lock;
-import java.util.concurrent.locks.ReentrantLock;
+import ch.qos.logback.core.issue.SelectiveLockRunnable.LockingModel;
/**
* Short sample code testing the throughput of a fair lock.
@@ -9,133 +8,39 @@
* @author Joern Huxhorn
* @author Ceki Gulcu
*/
-public class LockThroughput implements Runnable {
+public class LockThroughput {
- enum LockingModel {
- SYNC, FAIR, UNFAIR;
- }
-
- static int THREAD_COUNT = 2;
+ static int THREAD_COUNT = 10;
static long OVERALL_DURATION_IN_MILLIS = 5000;
- static LockThroughput[] RUNNABLE_ARRAY = new LockThroughput[THREAD_COUNT];
- static Thread[] THREAD_ARRAY = new Thread[THREAD_COUNT];
-
- static Object LOCK = new Object();
- static Lock FAIR_LOCK = new ReentrantLock(true);
- static Lock UNFAIR_LOCK = new ReentrantLock(false);
-
- static private int COUNTER = 0;
-
- LockingModel model;
- boolean done = false;
public static void main(String args[]) throws InterruptedException {
- printEnvironmentInfo();
- execute(LockingModel.SYNC);
- execute(LockingModel.UNFAIR);
- execute(LockingModel.FAIR);
-
- COUNTER = 0;
- execute(LockingModel.SYNC);
- cleanUpAndPrintResults("Sync: ");
- execute(LockingModel.UNFAIR);
- cleanUpAndPrintResults("Unfair: ");
- execute(LockingModel.FAIR);
- cleanUpAndPrintResults("Fair: ");
-
- }
-
- public static void printEnvironmentInfo() {
- System.out.println("java.runtime.version = "
- + System.getProperty("java.runtime.version"));
- System.out.println("java.vendor = "
- + System.getProperty("java.vendor"));
- System.out.println("java.version = "
- + System.getProperty("java.version"));
- System.out.println("os.name = "
- + System.getProperty("os.name"));
- System.out.println("os.version = "
- + System.getProperty("os.version"));
- }
-
- public static void execute(LockingModel model) throws InterruptedException {
- for (int i = 0; i < THREAD_COUNT; i++) {
- RUNNABLE_ARRAY[i] = new LockThroughput(model);
- THREAD_ARRAY[i] = new Thread(RUNNABLE_ARRAY[i]);
- }
- for (Thread t : THREAD_ARRAY) {
- t.start();
- }
- // let the threads run for a while
- Thread.sleep(OVERALL_DURATION_IN_MILLIS);
-
- for (int i = 0; i < THREAD_COUNT; i++) {
- RUNNABLE_ARRAY[i].done = true;
- }
- }
-
- public static void cleanUpAndPrintResults(String model) throws InterruptedException {
- for (int i = 0; i < THREAD_COUNT; i++) {
- THREAD_ARRAY[i].join();
- }
- System.out.println(model + COUNTER+", or "+ ((OVERALL_DURATION_IN_MILLIS*1000*1000L)/COUNTER) +" nanos per cycle");
- COUNTER = 0;
- }
-
- LockThroughput(LockingModel model) {
- this.model = model;
- }
+ ThreadedThroughputCalculator tp = new ThreadedThroughputCalculator(
+ OVERALL_DURATION_IN_MILLIS);
+ tp.printEnvironmentInfo("LockThroughput");
- void fairLockRun() {
- for (;;) {
- FAIR_LOCK.lock();
- COUNTER++;
- FAIR_LOCK.unlock();
- if (done) {
- return;
- }
+ for (int i = 0; i < 2; i++) {
+ tp.execute(buildArray(LockingModel.SYNC));
+ tp.execute(buildArray(LockingModel.UNFAIR));
+ tp.execute(buildArray(LockingModel.FAIR));
}
- }
+
+ tp.execute(buildArray(LockingModel.SYNC));
+ tp.printThroughput("Sync: ");
- void unfairLockRun() {
- for (;;) {
- UNFAIR_LOCK.lock();
- COUNTER++;
- UNFAIR_LOCK.unlock();
- if (done) {
- return;
- }
- }
- }
+ tp.execute(buildArray(LockingModel.UNFAIR));
+ tp.printThroughput("Unfair: ");
- void synchronizedRUn() {
- for (;;) {
- synchronized (LOCK) {
- COUNTER++;
- if (done) {
- return;
- }
- }
- }
+ tp.execute(buildArray(LockingModel.FAIR));
+ tp.printThroughput("Fair: ");
}
- public void run() {
- switch (model) {
- case SYNC:
- synchronizedRUn();
- break;
- case FAIR:
- fairLockRun();
- break;
- case UNFAIR:
- unfairLockRun();
- break;
+ static SelectiveLockRunnable[] buildArray(LockingModel model) {
+ SelectiveLockRunnable[] array = new SelectiveLockRunnable[THREAD_COUNT];
+ for (int i = 0; i < THREAD_COUNT; i++) {
+ array[i] = new SelectiveLockRunnable(model);
}
- }
-
- public String toString() {
- return "counter=" + COUNTER;
+ return array;
}
}
Added: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/RunnableForThrougputComputation.java
==============================================================================
--- (empty file)
+++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/RunnableForThrougputComputation.java Mon Jun 15 20:55:01 2009
@@ -0,0 +1,26 @@
+package ch.qos.logback.core.issue;
+
+/**
+ * A runnable with 'done' and 'counter' fields.
+ *
+ * @author ceki
+ *
+ */
+abstract public class RunnableForThrougputComputation implements Runnable {
+
+ protected boolean done = false;
+ protected int counter = 0;
+
+ public int getCounter() {
+ return counter;
+ }
+
+ public void setDone(boolean done) {
+ this.done = done;
+ }
+
+ public boolean isDone() {
+ return done;
+ }
+
+}
Added: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/SelectiveLockRunnable.java
==============================================================================
--- (empty file)
+++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/SelectiveLockRunnable.java Mon Jun 15 20:55:01 2009
@@ -0,0 +1,74 @@
+package ch.qos.logback.core.issue;
+
+import java.util.concurrent.locks.Lock;
+import java.util.concurrent.locks.ReentrantLock;
+
+/**
+ * A runnable which behaves differently depending on the desired locking model.
+ *
+ * @author Joern Huxhorn
+ * @author Ceki Gulcu
+ */
+public class SelectiveLockRunnable extends RunnableForThrougputComputation {
+
+ enum LockingModel {
+ SYNC, FAIR, UNFAIR;
+ }
+
+ static Object LOCK = new Object();
+ static Lock FAIR_LOCK = new ReentrantLock(true);
+ static Lock UNFAIR_LOCK = new ReentrantLock(false);
+
+
+ LockingModel model;
+
+ SelectiveLockRunnable(LockingModel model) {
+ this.model = model;
+ }
+
+ public void run() {
+ switch (model) {
+ case SYNC:
+ synchronizedRUn();
+ break;
+ case FAIR:
+ fairLockRun();
+ break;
+ case UNFAIR:
+ unfairLockRun();
+ break;
+ }
+ }
+ void fairLockRun() {
+ for (;;) {
+ FAIR_LOCK.lock();
+ counter++;
+ FAIR_LOCK.unlock();
+ if (done) {
+ return;
+ }
+ }
+ }
+
+ void unfairLockRun() {
+ for (;;) {
+ UNFAIR_LOCK.lock();
+ counter++;
+ UNFAIR_LOCK.unlock();
+ if (done) {
+ return;
+ }
+ }
+ }
+
+ void synchronizedRUn() {
+ for (;;) {
+ synchronized (LOCK) {
+ counter++;
+ }
+ if (done) {
+ return;
+ }
+ }
+ }
+}
Added: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/ThreadedThroughputCalculator.java
==============================================================================
--- (empty file)
+++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/ThreadedThroughputCalculator.java Mon Jun 15 20:55:01 2009
@@ -0,0 +1,67 @@
+package ch.qos.logback.core.issue;
+
+/**
+ *
+ * Useful scaffolding to measure the throughput of certain operations when
+ * invoked by multiple threads.
+ *
+ * @author Joern Huxhorn
+ * @author Ralph Goers
+ * @author Ceki Gulcu
+ */
+public class ThreadedThroughputCalculator {
+
+ RunnableForThrougputComputation[] runnableArray;
+ Thread[] threadArray;
+ final long overallDurationInMillis;
+
+ public ThreadedThroughputCalculator(long overallDurationInMillis) {
+ this.overallDurationInMillis = overallDurationInMillis;
+ }
+
+ public void printEnvironmentInfo(String msg) {
+ System.out.println("=== "+ msg +" ===");
+ System.out.println("java.runtime.version = "
+ + System.getProperty("java.runtime.version"));
+ System.out.println("java.vendor = "
+ + System.getProperty("java.vendor"));
+ System.out.println("java.version = "
+ + System.getProperty("java.version"));
+ System.out.println("os.name = "
+ + System.getProperty("os.name"));
+ System.out.println("os.version = "
+ + System.getProperty("os.version"));
+ }
+
+ public void execute(RunnableForThrougputComputation[] runnableArray)
+ throws InterruptedException {
+ this.runnableArray = runnableArray;
+ Thread[] threadArray = new Thread[runnableArray.length];
+
+ for (int i = 0; i < runnableArray.length; i++) {
+ threadArray[i] = new Thread(runnableArray[i]);
+ }
+ for (Thread t : threadArray) {
+ t.start();
+ }
+ // let the threads run for a while
+ Thread.sleep(overallDurationInMillis);
+
+ for (RunnableForThrougputComputation r : runnableArray) {
+ r.setDone(true);
+ }
+ for (Thread t : threadArray) {
+ t.join();
+ }
+ }
+
+ public void printThroughput(String msg) throws InterruptedException {
+ int sum = 0;
+ for (RunnableForThrougputComputation r : runnableArray) {
+ sum += r.getCounter();
+ }
+ System.out.println(msg + "total of " + sum + " operations, or "
+ + (sum / overallDurationInMillis) + " operations per millisecond");
+ }
+
+}
More information about the logback-dev
mailing list