June 2009 - logback-dev - mailman3.qos.ch

[JIRA] Commented: (LBCLASSIC-36) Synchronization of SimpleDateFormat object in DateConverter
by Ralph Goers (JIRA) 16 Jun '09

16 Jun '09

[ http://jira.qos.ch/browse/LBCLASSIC-36?page=com.atlassian.jira.plugin.syste… ] Ralph Goers commented on LBCLASSIC-36: -------------------------------------- My concern is not about the performance. It is reducing or, preferably, eliminating the locking that is required to the very minimum. So instead of assuming that the lock is held while the layout is processed, layout processing should be changed to only lock where absolutely necessary. If using Joda-time instead of SDF can completely eliminate locking while processing the layout I found view that as extremely beneficial. But if the locking scope is reduced to just encapsulate the date formatting that would be much better than it currently is. > Synchronization of SimpleDateFormat object in DateConverter > ----------------------------------------------------------- > > Key: LBCLASSIC-36 > URL: http://jira.qos.ch/browse/LBCLASSIC-36 > Project: logback-classic > Issue Type: Bug > Components: Other > Affects Versions: unspecified > Environment: Operating System: All > Platform: All > Reporter: Anders Hammar > Assignee: Ceki Gulcu > Attachments: DateConverter_patch.java, DateFormatPerfTest.java, dateformattest.zip > > > According to the API documentation of SimpleDateFormat, date formats are not synchronized and it is recommended to create separate format instances for each thread. > However, a possibly simpler (mer efficient) solution would be to synchronize on the SimpleDateFormat object in the convert() method to prevent two threads to access it concurrently. -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

1 0

[JIRA] Commented: (LBCLASSIC-36) Synchronization of SimpleDateFormat object in DateConverter
by Ceki Gulcu (JIRA) 16 Jun '09

16 Jun '09

[ http://jira.qos.ch/browse/LBCLASSIC-36?page=com.atlassian.jira.plugin.syste… ] Ceki Gulcu commented on LBCLASSIC-36: ------------------------------------- Thank you for these new figures. Your computer is obvious much faster than mine. I don't think the additional dependence on Jodatime is justified by the above figures. Do you? > Synchronization of SimpleDateFormat object in DateConverter > ----------------------------------------------------------- > > Key: LBCLASSIC-36 > URL: http://jira.qos.ch/browse/LBCLASSIC-36 > Project: logback-classic > Issue Type: Bug > Components: Other > Affects Versions: unspecified > Environment: Operating System: All > Platform: All > Reporter: Anders Hammar > Assignee: Ceki Gulcu > Attachments: DateConverter_patch.java, DateFormatPerfTest.java, dateformattest.zip > > > According to the API documentation of SimpleDateFormat, date formats are not synchronized and it is recommended to create separate format instances for each thread. > However, a possibly simpler (mer efficient) solution would be to synchronize on the SimpleDateFormat object in the convert() method to prevent two threads to access it concurrently. -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

1 0

[JIRA] Commented: (LBCLASSIC-36) Synchronization of SimpleDateFormat object in DateConverter
by Ralph Goers (JIRA) 16 Jun '09

16 Jun '09

[ http://jira.qos.ch/browse/LBCLASSIC-36?page=com.atlassian.jira.plugin.syste… ] Ralph Goers commented on LBCLASSIC-36: -------------------------------------- My results on my Macbook Pro. The difference is a little bit more significant, possibly since it is obviously a much faster machine. If this holds true then in production this would be even more significant. Unfortunately, I don't have a quad or 8-way processor to test this. === DateFormatting === java.runtime.version = 1.5.0_16-b06-284 java.vendor = Apple Inc. java.version = 1.5.0_16 os.name = Mac OS X os.version = 10.5.7 JODA: total of 13410524 operations, or 4470 operations per millisecond SDF: total of 10319665 operations, or 3439 operations per millisecond > Synchronization of SimpleDateFormat object in DateConverter > ----------------------------------------------------------- > > Key: LBCLASSIC-36 > URL: http://jira.qos.ch/browse/LBCLASSIC-36 > Project: logback-classic > Issue Type: Bug > Components: Other > Affects Versions: unspecified > Environment: Operating System: All > Platform: All > Reporter: Anders Hammar > Assignee: Ceki Gulcu > Attachments: DateConverter_patch.java, DateFormatPerfTest.java, dateformattest.zip > > > According to the API documentation of SimpleDateFormat, date formats are not synchronized and it is recommended to create separate format instances for each thread. > However, a possibly simpler (mer efficient) solution would be to synchronize on the SimpleDateFormat object in the convert() method to prevent two threads to access it concurrently. -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

1 0

svn commit: r2296 - logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue
by noreply.ceki＠qos.ch 15 Jun '09

15 Jun '09

Author: ceki Date: Mon Jun 15 22:00:57 2009 New Revision: 2296 Modified: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/NoLockThroughput.java Log: tweak the numbers Modified: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/NoLockThroughput.java ============================================================================== --- logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/NoLockThroughput.java (original) +++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/NoLockThroughput.java Mon Jun 15 22:00:57 2009 @@ -10,8 +10,8 @@ */ public class NoLockThroughput { - static int THREAD_COUNT = 10; - static long OVERALL_DURATION_IN_MILLIS = 5000; + static int THREAD_COUNT = 3; + static long OVERALL_DURATION_IN_MILLIS = 2000; public static void main(String args[]) throws InterruptedException {

1 0

svn commit: r2295 - logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue
by noreply.ceki＠qos.ch 15 Jun '09

15 Jun '09

Author: ceki Date: Mon Jun 15 21:55:46 2009 New Revision: 2295 Added: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/NoLockThroughput.java Modified: 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 Log: - testing behaviour when there are no locks. Added: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/NoLockThroughput.java ============================================================================== --- (empty file) +++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/NoLockThroughput.java Mon Jun 15 21:55:46 2009 @@ -0,0 +1,38 @@ +package ch.qos.logback.core.issue; + +import ch.qos.logback.core.issue.SelectiveLockRunnable.LockingModel; + +/** + * Short sample code testing the throughput of a fair lock. + * + * @author Joern Huxhorn + * @author Ceki Gulcu + */ +public class NoLockThroughput { + + static int THREAD_COUNT = 10; + static long OVERALL_DURATION_IN_MILLIS = 5000; + + public static void main(String args[]) throws InterruptedException { + + ThreadedThroughputCalculator tp = new ThreadedThroughputCalculator( + OVERALL_DURATION_IN_MILLIS); + tp.printEnvironmentInfo("NoLockThroughput"); + + for (int i = 0; i < 2; i++) { + tp.execute(buildArray(LockingModel.NOLOCK)); + } + + tp.execute(buildArray(LockingModel.NOLOCK)); + tp.printThroughput("No lock: ", true); + } + + static SelectiveLockRunnable[] buildArray(LockingModel model) { + SelectiveLockRunnable[] array = new SelectiveLockRunnable[THREAD_COUNT]; + for (int i = 0; i < THREAD_COUNT; i++) { + array[i] = new SelectiveLockRunnable(model); + } + return array; + } + +} Modified: 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/RunnableForThrougputComputation.java (original) +++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/RunnableForThrougputComputation.java Mon Jun 15 21:55:46 2009 @@ -9,9 +9,9 @@ abstract public class RunnableForThrougputComputation implements Runnable { protected boolean done = false; - protected int counter = 0; + protected long counter = 0; - public int getCounter() { + public long getCounter() { return counter; } Modified: 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/SelectiveLockRunnable.java (original) +++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/SelectiveLockRunnable.java Mon Jun 15 21:55:46 2009 @@ -12,22 +12,24 @@ public class SelectiveLockRunnable extends RunnableForThrougputComputation { enum LockingModel { - SYNC, FAIR, UNFAIR; + NOLOCK, 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 NOLOCK: + nolockRun(); + break; case SYNC: synchronizedRUn(); break; @@ -39,6 +41,7 @@ break; } } + void fairLockRun() { for (;;) { FAIR_LOCK.lock(); @@ -61,6 +64,15 @@ } } + void nolockRun() { + for (;;) { + counter++; + if (done) { + return; + } + } + } + void synchronizedRUn() { for (;;) { synchronized (LOCK) { @@ -71,4 +83,9 @@ } } } + + @Override + public String toString() { + return "SelectiveLockRunnable "+model; + } } Modified: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/ThreadedThroughputCalculator.java ============================================================================== --- logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/ThreadedThroughputCalculator.java (original) +++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/ThreadedThroughputCalculator.java Mon Jun 15 21:55:46 2009 @@ -20,7 +20,7 @@ } public void printEnvironmentInfo(String msg) { - System.out.println("=== "+ msg +" ==="); + System.out.println("=== " + msg + " ==="); System.out.println("java.runtime.version = " + System.getProperty("java.runtime.version")); System.out.println("java.vendor = " @@ -54,14 +54,20 @@ t.join(); } } - public void printThroughput(String msg) throws InterruptedException { - int sum = 0; + printThroughput(msg, false); + } + + public void printThroughput(String msg, boolean detailed) throws InterruptedException { + long sum = 0; for (RunnableForThrougputComputation r : runnableArray) { + if(detailed) { + System.out.println(r +" count="+r.getCounter()); + } sum += r.getCounter(); } + System.out.println(msg + "total of " + sum + " operations, or " - + (sum / overallDurationInMillis) + " operations per millisecond"); + + ((sum) / overallDurationInMillis) + " operations per millisecond"); } - }

1 0

[JIRA] Commented: (LBCLASSIC-36) Synchronization of SimpleDateFormat object in DateConverter
by Ceki Gulcu (JIRA) 15 Jun '09

15 Jun '09

[ http://jira.qos.ch/browse/LBCLASSIC-36?page=com.atlassian.jira.plugin.syste… ] Ceki Gulcu commented on LBCLASSIC-36: ------------------------------------- In a threaded environment (16 threads) the overall throughput for SDF and JodaTime are very close. === DateFormatting === java.runtime.version = 1.6.0_05-b13 java.vendor = Sun Microsystems Inc. java.version = 1.6.0_05 os.name = Windows XP os.version = 5.1 JODA: total of 4810206 operations, or 1603 operations per millisecond SDF: total of 4685053 operations, or 1561 operations per millisecond > Synchronization of SimpleDateFormat object in DateConverter > ----------------------------------------------------------- > > Key: LBCLASSIC-36 > URL: http://jira.qos.ch/browse/LBCLASSIC-36 > Project: logback-classic > Issue Type: Bug > Components: Other > Affects Versions: unspecified > Environment: Operating System: All > Platform: All > Reporter: Anders Hammar > Assignee: Ceki Gulcu > Attachments: DateConverter_patch.java, DateFormatPerfTest.java, dateformattest.zip > > > According to the API documentation of SimpleDateFormat, date formats are not synchronized and it is recommended to create separate format instances for each thread. > However, a possibly simpler (mer efficient) solution would be to synchronize on the SimpleDateFormat object in the convert() method to prevent two threads to access it concurrently. -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

1 0

svn commit: r2294 - logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net
by noreply.ceki＠qos.ch 15 Jun '09

15 Jun '09

Author: ceki Date: Mon Jun 15 20:57:20 2009 New Revision: 2294 Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/SMTPAppender_SubethaSMTPTest.java Log: stopping the wiser seems like a good idea... Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/SMTPAppender_SubethaSMTPTest.java ============================================================================== --- logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/SMTPAppender_SubethaSMTPTest.java (original) +++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/SMTPAppender_SubethaSMTPTest.java Mon Jun 15 20:57:20 2009 @@ -93,6 +93,7 @@ @After public void tearDown() throws Exception { + wiser.stop(); } private static String getWholeMessage(Part msg) {

1 0

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
by noreply.ceki＠qos.ch 15 Jun '09

15 Jun '09

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"); + } + +}

1 0

[JIRA] Issue Comment Edited: (LBCLASSIC-36) Synchronization of SimpleDateFormat object in DateConverter
by Ceki Gulcu (JIRA) 15 Jun '09

15 Jun '09

[ http://jira.qos.ch/browse/LBCLASSIC-36?page=com.atlassian.jira.plugin.syste… ] Ceki Gulcu edited comment on LBCLASSIC-36 at 6/15/09 3:33 PM: -------------------------------------------------------------- > 1. There is no reason to synchronize in the Joda test. DateTimeFormatter should be declared external to the > method and the synchronization should be removed since DateTimeFormatter is thread safe. I believe that to be incorrect. While Joda's DateTimeFormatter may be thread safe, assignment to a long is not an atomic operation in Java. The synchronized block exist to protect the "cache" not DateTimeFormatter. Just read modified DateFormatPerfTest you provided, I see that you already protected the "cache." In that case, there is indeed no need to protect DateTimeFormatter. Sorry for jumping to conclusions. was (Author: noreply.ceki(a)qos.ch) > 1. There is no reason to synchronize in the Joda test. DateTimeFormatter should be declared external to the > method and the synchronization should be removed since DateTimeFormatter is thread safe. I beleive that to be incorrect. While Joda's DateTimeFormatter may be thread safe, assignment to a long is not an atomic operation in Java. The synchronized block exist to protect the "cache" not DateTimeFormatter. > Synchronization of SimpleDateFormat object in DateConverter > ----------------------------------------------------------- > > Key: LBCLASSIC-36 > URL: http://jira.qos.ch/browse/LBCLASSIC-36 > Project: logback-classic > Issue Type: Bug > Components: Other > Affects Versions: unspecified > Environment: Operating System: All > Platform: All > Reporter: Anders Hammar > Assignee: Ceki Gulcu > Attachments: DateConverter_patch.java, DateFormatPerfTest.java, dateformattest.zip > > > According to the API documentation of SimpleDateFormat, date formats are not synchronized and it is recommended to create separate format instances for each thread. > However, a possibly simpler (mer efficient) solution would be to synchronize on the SimpleDateFormat object in the convert() method to prevent two threads to access it concurrently. -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

1 0

[JIRA] Commented: (LBCLASSIC-36) Synchronization of SimpleDateFormat object in DateConverter
by Ceki Gulcu (JIRA) 15 Jun '09

15 Jun '09

[ http://jira.qos.ch/browse/LBCLASSIC-36?page=com.atlassian.jira.plugin.syste… ] Ceki Gulcu commented on LBCLASSIC-36: ------------------------------------- > 1. There is no reason to synchronize in the Joda test. DateTimeFormatter should be declared external to the > method and the synchronization should be removed since DateTimeFormatter is thread safe. I beleive that to be incorrect. While Joda's DateTimeFormatter may be thread safe, assignment to a long is not an atomic operation in Java. The synchronized block exist to protect the "cache" not DateTimeFormatter. > Synchronization of SimpleDateFormat object in DateConverter > ----------------------------------------------------------- > > Key: LBCLASSIC-36 > URL: http://jira.qos.ch/browse/LBCLASSIC-36 > Project: logback-classic > Issue Type: Bug > Components: Other > Affects Versions: unspecified > Environment: Operating System: All > Platform: All > Reporter: Anders Hammar > Assignee: Ceki Gulcu > Attachments: DateConverter_patch.java, DateFormatPerfTest.java, dateformattest.zip > > > According to the API documentation of SimpleDateFormat, date formats are not synchronized and it is recommended to create separate format instances for each thread. > However, a possibly simpler (mer efficient) solution would be to synchronize on the SimpleDateFormat object in the convert() method to prevent two threads to access it concurrently. -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

1 0