PlatformLogger: isLoggable performance / waste due to HashMap<Integer, Level (original) (raw)

Jim Gish jim.gish at oracle.com
Wed Mar 20 18:39:17 UTC 2013

Hi Laurent,

If you'd like to submit an improved patch, I'll take a look. The best way to do this is to post a webrev: http://openjdk.java.net/guide/webrevHelp.html

Looking forward to your participation and contributions. Welcome!

Thanks, Jim Gish

On 03/20/2013 08:45 AM, Laurent Bourgès wrote: > Hi mandy, >> Do you want me to propose an improved patch to remove the former Map and > fix the getLevel() method ? or you prefer fix on your own ? >> Is it better to discuss the fix on the bug database (still not visible) ? >> Laurent >> 2013/3/19 Mandy Chung <mandy.chung at oracle.com> >>> Hi Laurent, >>>> Thanks for the contribution. I agree that the map can be replaced with a >> direct mapping from a int value to Level object and avoid the autoboxing >> conversion. >>>> I have filed a bug to track this and target this for JDK8: >> http://bugs.sun.com/bugdatabase/viewbug.do?bugid= 8010309 >>>> Thanks >> Mandy >>>>>> On 3/19/13 5:19 AM, Laurent Bourgès wrote: >>>> Dear all, >>>> I run recently netbeans profiler on my swing application (Aspro2:http://www.jmmc.fr/aspro >> ) under linux x64 platform and figured out a >> performance and waste issue related to PlatformLogger. >>>> Actually, the JavaLogger implementation uses a Map<Integer, Object> >> levelObjects to store mapping between PlatformLogger's levels (int) and JUL >> Level instances. >>>> However, the isLoggable(int level) method is highly used by awt project and >> other JDK projects and it leads to many Integer allocations as autoboxing >> converts the level as int to an Integer instance used by the Map.get() call. >>>> /** >> * JavaLogger forwards all the calls to its corresponding >> * java.util.logging.Logger object. >> */ >> static class JavaLogger extends LoggerProxy { >> private static final* Map<Integer, Object>* levelObjects = new >> HashMap<>(); >> ... >> public boolean isLoggable(int level) { >> return LoggingSupport.isLoggable(javaLogger, * >> levelObjects.get(level)*); >> } >> } >>>> I wrote a simple test to illustrate that performance / waste problem: >> PlatformLoggerTest that simply performs 1 million DISABLED log statements: >> if (log.isLoggable(PlatformLogger.FINEST)) { >> log.finest("test PlatformLogger.FINEST"); >> } >>>> As you can see in screenshots: >> - 5 million Integer instances are allocated >> - Integer.valueOf(int) is called 5 million times (autoboxing) >> - HashMap.get() represents 30% of the test time >> - patched PlatformLogger is 3x times faster >> [jvm options: -Xms8m -Xmx8m -verbose:gc] >>>> I suggest you to use an alternative way to map PlatformLogger's levels >> (int) and JUL Level instances to fix that performance / memory issue: I >> added the getLevel(int level) method that performs a switch case to return >> the corresponding Level object (quick and dirty solution). >>>> I advocate this is not a very clean solution but I prefer efficiency here: >> any better solution may be appropriate to avoid at least Integer allocation >> and maybe enhance performance. >>>> Best regards, >> Laurent Bourgès >>>> PS: here is the patch as text: >>>> # This patch file was generated by NetBeans IDE >> # It uses platform neutral UTF-8 encoding and \n newlines. >> --- PlatformLogger.java (6767) >> +++ PlatformLogger.java (6768) >> @@ -468,31 +468,13 @@ >> * java.util.logging.Logger object. >> */ >> static class JavaLogger extends LoggerProxy { >> - /** Note: using Integer keys leads to a lot of new Integer >> instances !! */ >> - private static final Map<Integer, Object> levelObjects = new >> HashMap<>(); >> - /** fastest mapping to Level instances from PlatformLogger level >> as integer */ >> - private static final Object[] fastLevelObjects; >> - >> - >> + private static final Map<Integer, Object> levelObjects = >> + new HashMap<>(); >> + >> static { >> if (LoggingSupport.isAvailable()) { >> // initialize the map to Level objects >> getLevelObjects(); >> - >> - // initialize the fastLevelObjects: >> - fastLevelObjects = new Object[] { >> - LoggingSupport.parseLevel(getLevelName(OFF)), // >> 0 >> - LoggingSupport.parseLevel(getLevelName(SEVERE)), // >> 1 >> - LoggingSupport.parseLevel(getLevelName(WARNING)), // >> 2 >> - LoggingSupport.parseLevel(getLevelName(INFO)), // >> 3 >> - LoggingSupport.parseLevel(getLevelName(CONFIG)), // >> 4 >> - LoggingSupport.parseLevel(getLevelName(FINE)), // >> 5 >> - LoggingSupport.parseLevel(getLevelName(FINER)), // >> 6 >> - LoggingSupport.parseLevel(getLevelName(FINEST)), // >> 7 >> - LoggingSupport.parseLevel(getLevelName(ALL)) // >> 8 >> - }; >> - } else { >> - fastLevelObjects = null; // check null >> } >> } >>>> @@ -515,7 +497,7 @@ >> this.javaLogger = LoggingSupport.getLogger(name); >> if (level != 0) { >> // level has been updated and so set the Logger's level >> - LoggingSupport.setLevel(javaLogger, getLevel(level)); >> + LoggingSupport.setLevel(javaLogger, >> levelObjects.get(level)); >> } >> } >>>> @@ -526,11 +508,11 @@ >> * not be updated. >> */ >> void doLog(int level, String msg) { >> - LoggingSupport.log(javaLogger, getLevel(level), msg); >> + LoggingSupport.log(javaLogger, levelObjects.get(level), msg); >> } >>>> void doLog(int level, String msg, Throwable t) { >> - LoggingSupport.log(javaLogger, getLevel(level), msg, t); >> + LoggingSupport.log(javaLogger, levelObjects.get(level), msg, >> t); >> } >>>> void doLog(int level, String msg, Object... params) { >> @@ -544,12 +526,12 @@ >> _for (int i = 0; i < len; i++) {_ >> sparams [i] = String.valueOf(params[i]); >> } >> - LoggingSupport.log(javaLogger, getLevel(level), msg, sparams); >> + LoggingSupport.log(javaLogger, levelObjects.get(level), msg, >> sparams); >> } >>>> boolean isEnabled() { >> Object level = LoggingSupport.getLevel(javaLogger); >> - return level == null || level.equals(getLevel(OFF)) == false; >> + return level == null || level.equals(levelObjects.get(OFF)) == >> false; >> } >>>> int getLevel() { >> @@ -566,34 +548,12 @@ >>>> void setLevel(int newLevel) { >> levelValue = newLevel; >> - LoggingSupport.setLevel(javaLogger, getLevel(newLevel)); >> + LoggingSupport.setLevel(javaLogger, >> levelObjects.get(newLevel)); >> } >>>> public boolean isLoggable(int level) { >> - return LoggingSupport.isLoggable(javaLogger, getLevel(level)); >> + return LoggingSupport.isLoggable(javaLogger, >> levelObjects.get(level)); >> } >> - >> - /** >> - * Return the corresponding level object (fastest implementation) >> - * @param level PlatformLogger level as primitive integer >> - * @return Object (JUL Level instance) >> - */ >> - private static Object getLevel(final int level) { >> - // higher occurences first (finest, fine, finer, info): >> - switch (level) { >> - case FINEST : return fastLevelObjects[7]; >> - case FINE : return fastLevelObjects[5]; >> - case FINER : return fastLevelObjects[6]; >> - case INFO : return fastLevelObjects[3]; >> - case CONFIG : return fastLevelObjects[4]; >> - case WARNING : return fastLevelObjects[2]; >> - case SEVERE : return fastLevelObjects[1]; >> - case ALL : return fastLevelObjects[8]; >> - case OFF : return fastLevelObjects[0]; >> - default : return null; >> - } >> - } >> - >> } >>>> private static String getLevelName(int level) { >>>>>>

Jim Gish | Consulting Member of Technical Staff | +1.781.442.0304 Oracle Java Platform Group | Core Libraries Team 35 Network Drive Burlington, MA 01803 jim.gish at oracle.com

More information about the core-libs-dev mailing list