PlatformLogger: isLoggable performance / waste due to HashMap<Integer, Level> leads to Integer allocations (boxing)
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/view_bug.do?bug_id= 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