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

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

17 Jun '09

[ http://jira.qos.ch/browse/LBCLASSIC-36?page=com.atlassian.jira.plugin.syste… ] Ralph Goers commented on LBCLASSIC-36: -------------------------------------- I am seeing similar improvements. While I recommend adopting these improvements they won't mean much while the whole appender is synchronized. > 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, DoubleCheckedLocking.patch > > > 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 Joern Huxhorn (JIRA) 17 Jun '09

17 Jun '09

[ http://jira.qos.ch/browse/LBCLASSIC-36?page=com.atlassian.jira.plugin.syste… ] Joern Huxhorn commented on LBCLASSIC-36: ---------------------------------------- More important than the performance increase is the fact that double-checked locking is broken - so it wouldn't have worked as it should have in RL. > 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, DoubleCheckedLocking.patch > > > 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 Joern Huxhorn (JIRA) 17 Jun '09

17 Jun '09

[ http://jira.qos.ch/browse/LBCLASSIC-36?page=com.atlassian.jira.plugin.syste… ] Joern Huxhorn commented on LBCLASSIC-36: ---------------------------------------- Well, the above test looks like this from within IDEA: Raw - JDK: 4992 ns Joda: 5533 ns - Difference: -10.837339% Synchronized DateFormat: 0.4826 seconds Unsynchronized DateFormat: 1.7025 seconds ThreadLocal DateFormat: 0.1858 seconds Joda DateTimeFormatter: 0.0908 seconds And values are fluctuating quite a bit on reruns, that's why I'm asking... Raw - JDK: 4864 ns Joda: 5348 ns - Difference: -9.950658% Synchronized DateFormat: 0.4799 seconds Unsynchronized DateFormat: 1.5900 seconds ThreadLocal DateFormat: 0.1806 seconds Joda DateTimeFormatter: 0.1252 seconds Raw - JDK: 5030 ns Joda: 5719 ns - Difference: -13.697813% Synchronized DateFormat: 0.4813 seconds Unsynchronized DateFormat: 1.6982 seconds ThreadLocal DateFormat: 0.1870 seconds Joda DateTimeFormatter: 0.0838 seconds ... > 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, DoubleCheckedLocking.patch > > > 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) 17 Jun '09

17 Jun '09

[ http://jira.qos.ch/browse/LBCLASSIC-36?page=com.atlassian.jira.plugin.syste… ] Ceki Gulcu commented on LBCLASSIC-36: ------------------------------------- With your patch applied: === 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 21601629 operations, or 7200 operations per millisecond SDF: total of 28017761 operations, or 9339 operations per millisecond Approx. 5 fold improvement. Very nice. I am running the test from within Eclipse. Why do you think IDEA or Eclipse influences the outcome? Do you have anything specific in mind? > 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, DoubleCheckedLocking.patch > > > 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] Updated: (LBCLASSIC-36) Synchronization of SimpleDateFormat object in DateConverter
by Joern Huxhorn (JIRA) 17 Jun '09

17 Jun '09

[ http://jira.qos.ch/browse/LBCLASSIC-36?page=com.atlassian.jira.plugin.syste… ] Joern Huxhorn updated LBCLASSIC-36: ----------------------------------- Attachment: DoubleCheckedLocking.patch === DateFormatting === java.runtime.version = 1.6.0_13-b03-211 java.vendor = Apple Inc. java.version = 1.6.0_13 os.name = Mac OS X os.version = 10.5.7 JODA: total of 52011401 operations, or 17337 operations per millisecond SDF: total of 52664135 operations, or 17554 operations per millisecond I've removed the double-checked locking from the example app. http://www.cs.umd.edu/~pugh/java/memoryModel/jsr-133-faq.html How are you executing this app? I started it from within IDEA but I fear that this influences the outcome... > 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, DoubleCheckedLocking.patch > > > 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 Joern Huxhorn (JIRA) 17 Jun '09

17 Jun '09

[ http://jira.qos.ch/browse/LBCLASSIC-36?page=com.atlassian.jira.plugin.syste… ] Joern Huxhorn commented on LBCLASSIC-36: ---------------------------------------- This was just a side-effect of trying to get logback to compile using "mvn clean install". I'll take another look at DateFormatPerftest. My suggestion above is still standing (I know, we just had a comment race-condition ;)): how about the interface? > 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) 17 Jun '09

17 Jun '09

[ http://jira.qos.ch/browse/LBCLASSIC-36?page=com.atlassian.jira.plugin.syste… ] Ceki Gulcu commented on LBCLASSIC-36: ------------------------------------- Hi Joern, Thank you for this new data. However, you should work with DateFormatPerftest in ch.qos.logback.classic.issue.lbclassic36, not Ralph's original attachment which uses Date instead of long. > 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] Issue Comment Edited: (LBCLASSIC-36) Synchronization of SimpleDateFormat object in DateConverter
by Joern Huxhorn (JIRA) 17 Jun '09

17 Jun '09

[ http://jira.qos.ch/browse/LBCLASSIC-36?page=com.atlassian.jira.plugin.syste… ] Joern Huxhorn edited comment on LBCLASSIC-36 at 6/17/09 11:34 AM: ------------------------------------------------------------------ Hi guys, I've just changed the TestDateFormatOriginal due to LBGENERAL-29. Instead of Date or DateTime a long is now used. This is a better representation of our problem, I think, since LoggingEvent contains the plain long and a new Date has to be created for SimpleDateFormat. My changes are contained in the patch for LBGENERAL-29. Below are my numbers for the following environment: Maven version: 2.0.10 Java version: 1.6.0_13 OS name: "mac os x" version: "10.5.7" arch: "x86_64" Family: "mac" Running ch.qos.logback.classic.issue.lbclassic36.TestDateFormatOriginal Raw - JDK: 3227 ns Joda: 5098 ns - Difference: -57.97955% Synchronized DateFormat: 0.1453 seconds Unsynchronized DateFormat: 1.3796 seconds ThreadLocal DateFormat: 0.0954 seconds Joda DateTimeFormatter: 0.0893 seconds I guess the bad numbers in case of Raw are caused by HotSpot compilation at that time :p Concerning the technique to use: Wouldn't it be possible to define an interface like interface TimestampFormatter { String format(long timeStamp); } and support both ThreadLocal DateFormat and Joda DateTimeFormatter? That way, Joda could be an optional dependency. If Joda would be present, the Joda implementation would be used. Otherwise ThreadLocalDateFormat could be used as a fallback. It's a speed increase of about 7% after all... was (Author: jhuxhorn): Hi guys, I've just changed the TestDateFormatOriginal due to LBGENERAL-29. Instead of Date or DateTime a long is now used. This is a better representation of our problem, I think, since LoggingEvent contains the plain long and a new Date has to be created for SimpleDateFormat. My changes are contained in the patch for LBGENERAL-29. Below are my numbers for the following environment: Maven version: 2.0.10 Java version: 1.6.0_13 OS name: "mac os x" version: "10.5.7" arch: "x86_64" Family: "mac" Running ch.qos.logback.classic.issue.lbclassic36.TestDateFormatOriginal Raw - JDK: 3227 ns Joda: 5098 ns - Difference: -57.97955% Synchronized DateFormat: 0.1453 seconds Unsynchronized DateFormat: 1.3796 seconds ThreadLocal DateFormat: 0.0954 seconds Joda DateTimeFormatter: 0.0893 seconds I guess the bad numbers in case of Raw are caused by HotSpot compilation at that time :p > 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 Joern Huxhorn (JIRA) 17 Jun '09

17 Jun '09

[ http://jira.qos.ch/browse/LBCLASSIC-36?page=com.atlassian.jira.plugin.syste… ] Joern Huxhorn commented on LBCLASSIC-36: ---------------------------------------- Hi guys, I've just changed the TestDateFormatOriginal due to LBGENERAL-29. Instead of Date or DateTime a long is now used. This is a better representation of our problem, I think, since LoggingEvent contains the plain long and a new Date has to be created for SimpleDateFormat. My changes are contained in the patch for LBGENERAL-29. Below are my numbers for the following environment: Maven version: 2.0.10 Java version: 1.6.0_13 OS name: "mac os x" version: "10.5.7" arch: "x86_64" Family: "mac" Running ch.qos.logback.classic.issue.lbclassic36.TestDateFormatOriginal Raw - JDK: 3227 ns Joda: 5098 ns - Difference: -57.97955% Synchronized DateFormat: 0.1453 seconds Unsynchronized DateFormat: 1.3796 seconds ThreadLocal DateFormat: 0.0954 seconds Joda DateTimeFormatter: 0.0893 seconds I guess the bad numbers in case of Raw are caused by HotSpot compilation at that time :p > 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] Issue Comment Edited: (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 edited comment on LBCLASSIC-36 at 6/16/09 7:57 PM: --------------------------------------------------------------- My concern is not only 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 find 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. was (Author: rgoers(a)apache.org) 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