From 2ca495dd4333388f244de28b834ccbd3381501c8 Mon Sep 17 00:00:00 2001 From: Peter Levart Date: Thu, 28 Mar 2013 13:14:09 -0700 Subject: [PATCH] 8010309: Improve PlatformLogger.isLoggable performance by direct mapping from an integer to Level Co-authored-by: Laurent Bourges Reviewed-by: mchung --- .../sun/util/logging/PlatformLogger.java | 387 ++++++++++-------- .../sun/util/logging/PlatformLoggerTest.java | 78 +++- 2 files changed, 296 insertions(+), 169 deletions(-) diff --git a/jdk/src/share/classes/sun/util/logging/PlatformLogger.java b/jdk/src/share/classes/sun/util/logging/PlatformLogger.java index 000a1603fe9..ef9789b7bf1 100644 --- a/jdk/src/share/classes/sun/util/logging/PlatformLogger.java +++ b/jdk/src/share/classes/sun/util/logging/PlatformLogger.java @@ -27,14 +27,11 @@ package sun.util.logging; import java.lang.ref.WeakReference; -import java.lang.reflect.InvocationTargetException; -import java.lang.reflect.Method; import java.io.PrintStream; import java.io.PrintWriter; import java.io.StringWriter; import java.security.AccessController; import java.security.PrivilegedAction; -import java.text.MessageFormat; import java.util.Date; import java.util.HashMap; import java.util.Map; @@ -87,18 +84,51 @@ import sun.misc.SharedSecrets; * @since 1.7 */ public class PlatformLogger { - // Same values as java.util.logging.Level for easy mapping - public static final int OFF = Integer.MAX_VALUE; - public static final int SEVERE = 1000; - public static final int WARNING = 900; - public static final int INFO = 800; - public static final int CONFIG = 700; - public static final int FINE = 500; - public static final int FINER = 400; - public static final int FINEST = 300; - public static final int ALL = Integer.MIN_VALUE; + // shortcut to PlatformLogger.Level enums + public static final Level OFF = Level.OFF; + public static final Level SEVERE = Level.SEVERE; + public static final Level WARNING = Level.WARNING; + public static final Level INFO = Level.INFO; + public static final Level CONFIG = Level.CONFIG; + public static final Level FINE = Level.FINE; + public static final Level FINER = Level.FINER; + public static final Level FINEST = Level.FINEST; + public static final Level ALL = Level.ALL; - private static final int defaultLevel = INFO; + /** + * PlatformLogger logging levels. + */ + public static enum Level { + // The name and value must match that of {@code java.util.logging.Level} objects. + ALL(Integer.MIN_VALUE), + FINEST(300), + FINER(400), + FINE(500), + CONFIG(700), + INFO(800), + WARNING(900), + SEVERE(1000), + OFF(Integer.MAX_VALUE); + + /** + * Associated java.util.logging.Level lazily initialized in + * JavaLoggerProxy's static initializer only once + * when java.util.logging is available and enabled. + * Only accessed by JavaLoggerProxy. + */ + /* java.util.logging.Level */ Object javaLevel; + + private final int value; + public int intValue() { + return value; + } + + Level(int value) { + this.value = value; + } + } + + private static final Level DEFAULT_LEVEL = INFO; private static boolean loggingEnabled; static { loggingEnabled = AccessController.doPrivileged( @@ -109,6 +139,20 @@ public class PlatformLogger { return (cname != null || fname != null); } }); + + // force loading of all JavaLoggerProxy (sub)classes to make JIT de-optimizations + // less probable. Don't initialize JavaLoggerProxy class since + // java.util.logging may not be enabled. + try { + Class.forName("sun.util.logging.PlatformLogger$DefaultLoggerProxy", + false, + PlatformLogger.class.getClassLoader()); + Class.forName("sun.util.logging.PlatformLogger$JavaLoggerProxy", + false, // do not invoke class initializer + PlatformLogger.class.getClassLoader()); + } catch (ClassNotFoundException ex) { + throw new InternalError(ex); + } } // Table of known loggers. Maps names to PlatformLoggers. @@ -143,27 +187,32 @@ public class PlatformLogger { WeakReference ref = entry.getValue(); PlatformLogger plog = ref.get(); if (plog != null) { - plog.newJavaLogger(); + plog.redirectToJavaLoggerProxy(); } } } /** - * Creates a new JavaLogger that the platform logger uses + * Creates a new JavaLoggerProxy and redirects the platform logger to it */ - private void newJavaLogger() { - logger = new JavaLogger(logger.name, logger.effectiveLevel); + private void redirectToJavaLoggerProxy() { + DefaultLoggerProxy lp = DefaultLoggerProxy.class.cast(this.loggerProxy); + JavaLoggerProxy jlp = new JavaLoggerProxy(lp.name, lp.level); + // the order of assignments is important + this.javaLoggerProxy = jlp; // isLoggable checks javaLoggerProxy if set + this.loggerProxy = jlp; } - // logger may be replaced with a JavaLogger object - // when the logging facility is enabled - private volatile LoggerProxy logger; - + // DefaultLoggerProxy may be replaced with a JavaLoggerProxy object + // when the java.util.logging facility is enabled + private volatile LoggerProxy loggerProxy; + // javaLoggerProxy is only set when the java.util.logging facility is enabled + private volatile JavaLoggerProxy javaLoggerProxy; private PlatformLogger(String name) { if (loggingEnabled) { - this.logger = new JavaLogger(name); + this.loggerProxy = this.javaLoggerProxy = new JavaLoggerProxy(name); } else { - this.logger = new LoggerProxy(name); + this.loggerProxy = new DefaultLoggerProxy(name); } } @@ -172,204 +221,248 @@ public class PlatformLogger { * (i.e. its level is OFF). */ public boolean isEnabled() { - return logger.isEnabled(); + return loggerProxy.isEnabled(); } /** * Gets the name for this platform logger. */ public String getName() { - return logger.name; + return loggerProxy.name; } /** * Returns true if a message of the given level would actually * be logged by this logger. */ - public boolean isLoggable(int level) { - return logger.isLoggable(level); + public boolean isLoggable(Level level) { + // performance-sensitive method: use two monomorphic call-sites + JavaLoggerProxy jlp = javaLoggerProxy; + return jlp != null ? jlp.isLoggable(level) : loggerProxy.isLoggable(level); } /** - * Gets the current log level. Returns 0 if the current effective level - * is not set (equivalent to Logger.getLevel() returns null). + * Get the log level that has been specified for this PlatformLogger. + * The result may be null, which means that this logger's + * effective level will be inherited from its parent. + * + * This method is primarily for testing purpose and not recommended + * to be used at runtime since it does not support custom j.u.l.Level. + * + * @return this PlatformLogger's level + * + * @throw IllegalArgumentException if j.u.l.Logger is set to + * a custom j.u.l.Level when java.util.logging facility is enabled */ - public int getLevel() { - return logger.getLevel(); + public Level getLevel() { + return loggerProxy.getLevel(); } /** - * Sets the log level. + * Set the log level specifying which message levels will be + * logged by this logger. Message levels lower than this + * value will be discarded. The level value {@link #OFF} + * can be used to turn off logging. + *

+ * If the new level is null, it means that this node should + * inherit its level from its nearest ancestor with a specific + * (non-null) level value. + * + * @param newLevel the new value for the log level (may be null) */ - public void setLevel(int newLevel) { - logger.setLevel(newLevel); + public void setLevel(Level newLevel) { + loggerProxy.setLevel(newLevel); } /** * Logs a SEVERE message. */ public void severe(String msg) { - logger.doLog(SEVERE, msg); + loggerProxy.doLog(SEVERE, msg); } public void severe(String msg, Throwable t) { - logger.doLog(SEVERE, msg, t); + loggerProxy.doLog(SEVERE, msg, t); } public void severe(String msg, Object... params) { - logger.doLog(SEVERE, msg, params); + loggerProxy.doLog(SEVERE, msg, params); } /** * Logs a WARNING message. */ public void warning(String msg) { - logger.doLog(WARNING, msg); + loggerProxy.doLog(WARNING, msg); } public void warning(String msg, Throwable t) { - logger.doLog(WARNING, msg, t); + loggerProxy.doLog(WARNING, msg, t); } public void warning(String msg, Object... params) { - logger.doLog(WARNING, msg, params); + loggerProxy.doLog(WARNING, msg, params); } /** * Logs an INFO message. */ public void info(String msg) { - logger.doLog(INFO, msg); + loggerProxy.doLog(INFO, msg); } public void info(String msg, Throwable t) { - logger.doLog(INFO, msg, t); + loggerProxy.doLog(INFO, msg, t); } public void info(String msg, Object... params) { - logger.doLog(INFO, msg, params); + loggerProxy.doLog(INFO, msg, params); } /** * Logs a CONFIG message. */ public void config(String msg) { - logger.doLog(CONFIG, msg); + loggerProxy.doLog(CONFIG, msg); } public void config(String msg, Throwable t) { - logger.doLog(CONFIG, msg, t); + loggerProxy.doLog(CONFIG, msg, t); } public void config(String msg, Object... params) { - logger.doLog(CONFIG, msg, params); + loggerProxy.doLog(CONFIG, msg, params); } /** * Logs a FINE message. */ public void fine(String msg) { - logger.doLog(FINE, msg); + loggerProxy.doLog(FINE, msg); } public void fine(String msg, Throwable t) { - logger.doLog(FINE, msg, t); + loggerProxy.doLog(FINE, msg, t); } public void fine(String msg, Object... params) { - logger.doLog(FINE, msg, params); + loggerProxy.doLog(FINE, msg, params); } /** * Logs a FINER message. */ public void finer(String msg) { - logger.doLog(FINER, msg); + loggerProxy.doLog(FINER, msg); } public void finer(String msg, Throwable t) { - logger.doLog(FINER, msg, t); + loggerProxy.doLog(FINER, msg, t); } public void finer(String msg, Object... params) { - logger.doLog(FINER, msg, params); + loggerProxy.doLog(FINER, msg, params); } /** * Logs a FINEST message. */ public void finest(String msg) { - logger.doLog(FINEST, msg); + loggerProxy.doLog(FINEST, msg); } public void finest(String msg, Throwable t) { - logger.doLog(FINEST, msg, t); + loggerProxy.doLog(FINEST, msg, t); } public void finest(String msg, Object... params) { - logger.doLog(FINEST, msg, params); + loggerProxy.doLog(FINEST, msg, params); } /** - * Default platform logging support - output messages to - * System.err - equivalent to ConsoleHandler with SimpleFormatter. + * Abstract base class for logging support, defining the API and common field. */ - static class LoggerProxy { - private static final PrintStream defaultStream = System.err; - + private static abstract class LoggerProxy { final String name; - volatile int levelValue; - volatile int effectiveLevel = 0; // current effective level value - LoggerProxy(String name) { - this(name, defaultLevel); + protected LoggerProxy(String name) { + this.name = name; } - LoggerProxy(String name, int level) { - this.name = name; - this.levelValue = level == 0 ? defaultLevel : level; + abstract boolean isEnabled(); + + abstract Level getLevel(); + abstract void setLevel(Level newLevel); + + abstract void doLog(Level level, String msg); + abstract void doLog(Level level, String msg, Throwable thrown); + abstract void doLog(Level level, String msg, Object... params); + + abstract boolean isLoggable(Level level); + } + + + private static final class DefaultLoggerProxy extends LoggerProxy { + /** + * Default platform logging support - output messages to System.err - + * equivalent to ConsoleHandler with SimpleFormatter. + */ + private static PrintStream outputStream() { + return System.err; + } + + volatile Level effectiveLevel; // effective level (never null) + volatile Level level; // current level set for this node (may be null) + + DefaultLoggerProxy(String name) { + super(name); + this.effectiveLevel = deriveEffectiveLevel(null); + this.level = null; } boolean isEnabled() { - return levelValue != OFF; + return effectiveLevel != OFF; } - int getLevel() { - return effectiveLevel; + Level getLevel() { + return level; } - void setLevel(int newLevel) { - levelValue = newLevel; - effectiveLevel = newLevel; - } - - void doLog(int level, String msg) { - if (level < levelValue || levelValue == OFF) { - return; + void setLevel(Level newLevel) { + Level oldLevel = level; + if (oldLevel != newLevel) { + level = newLevel; + effectiveLevel = deriveEffectiveLevel(newLevel); } - defaultStream.print(format(level, msg, null)); } - void doLog(int level, String msg, Throwable thrown) { - if (level < levelValue || levelValue == OFF) { - return; + void doLog(Level level, String msg) { + if (isLoggable(level)) { + outputStream().print(format(level, msg, null)); } - defaultStream.print(format(level, msg, thrown)); } - void doLog(int level, String msg, Object... params) { - if (level < levelValue || levelValue == OFF) { - return; + void doLog(Level level, String msg, Throwable thrown) { + if (isLoggable(level)) { + outputStream().print(format(level, msg, thrown)); } - String newMsg = formatMessage(msg, params); - defaultStream.print(format(level, newMsg, null)); } - public boolean isLoggable(int level) { - if (level < levelValue || levelValue == OFF) { - return false; + void doLog(Level level, String msg, Object... params) { + if (isLoggable(level)) { + String newMsg = formatMessage(msg, params); + outputStream().print(format(level, newMsg, null)); } - return true; + } + + boolean isLoggable(Level level) { + Level effectiveLevel = this.effectiveLevel; + return level.intValue() >= effectiveLevel.intValue() && effectiveLevel != OFF; + } + + // derive effective level (could do inheritance search like j.u.l.Logger) + private Level deriveEffectiveLevel(Level level) { + return level == null ? DEFAULT_LEVEL : level; } // Copied from java.util.logging.Formatter.formatMessage @@ -401,7 +494,7 @@ public class PlatformLogger { // minimize memory allocation private Date date = new Date(); - private synchronized String format(int level, String msg, Throwable thrown) { + private synchronized String format(Level level, String msg, Throwable thrown) { date.setTime(System.currentTimeMillis()); String throwable = ""; if (thrown != null) { @@ -417,7 +510,7 @@ public class PlatformLogger { date, getCallerInfo(), name, - PlatformLogger.getLevelName(level), + level.name(), msg, throwable); } @@ -464,58 +557,41 @@ public class PlatformLogger { } /** - * JavaLogger forwards all the calls to its corresponding + * JavaLoggerProxy forwards all the calls to its corresponding * java.util.logging.Logger object. */ - static class JavaLogger extends LoggerProxy { - private static final Map levelObjects = - new HashMap<>(); - + private static final class JavaLoggerProxy extends LoggerProxy { + // initialize javaLevel fields for mapping from Level enum -> j.u.l.Level object static { - if (LoggingSupport.isAvailable()) { - // initialize the map to Level objects - getLevelObjects(); + for (Level level : Level.values()) { + level.javaLevel = LoggingSupport.parseLevel(level.name()); } } - private static void getLevelObjects() { - // get all java.util.logging.Level objects - int[] levelArray = new int[] {OFF, SEVERE, WARNING, INFO, CONFIG, FINE, FINER, FINEST, ALL}; - for (int l : levelArray) { - Object level = LoggingSupport.parseLevel(getLevelName(l)); - levelObjects.put(l, level); - } + private final /* java.util.logging.Logger */ Object javaLogger; + + JavaLoggerProxy(String name) { + this(name, null); } - private final Object javaLogger; - JavaLogger(String name) { - this(name, 0); - } - - JavaLogger(String name, int level) { - super(name, level); + JavaLoggerProxy(String name, Level level) { + super(name); this.javaLogger = LoggingSupport.getLogger(name); - if (level != 0) { + if (level != null) { // level has been updated and so set the Logger's level - LoggingSupport.setLevel(javaLogger, levelObjects.get(level)); + LoggingSupport.setLevel(javaLogger, level.javaLevel); } } - /** - * Let Logger.log() do the filtering since if the level of a - * platform logger is altered directly from - * java.util.logging.Logger.setLevel(), the levelValue will - * not be updated. - */ - void doLog(int level, String msg) { - LoggingSupport.log(javaLogger, levelObjects.get(level), msg); + void doLog(Level level, String msg) { + LoggingSupport.log(javaLogger, level.javaLevel, msg); } - void doLog(int level, String msg, Throwable t) { - LoggingSupport.log(javaLogger, levelObjects.get(level), msg, t); + void doLog(Level level, String msg, Throwable t) { + LoggingSupport.log(javaLogger, level.javaLevel, msg, t); } - void doLog(int level, String msg, Object... params) { + void doLog(Level level, String msg, Object... params) { if (!isLoggable(level)) { return; } @@ -526,49 +602,32 @@ public class PlatformLogger { for (int i = 0; i < len; i++) { sparams [i] = String.valueOf(params[i]); } - LoggingSupport.log(javaLogger, levelObjects.get(level), msg, sparams); + LoggingSupport.log(javaLogger, level.javaLevel, msg, sparams); } boolean isEnabled() { - Object level = LoggingSupport.getLevel(javaLogger); - return level == null || level.equals(levelObjects.get(OFF)) == false; + return LoggingSupport.isLoggable(javaLogger, Level.OFF.javaLevel); } - int getLevel() { - Object level = LoggingSupport.getLevel(javaLogger); - if (level != null) { - for (Map.Entry l : levelObjects.entrySet()) { - if (level == l.getValue()) { - return l.getKey(); - } - } - } - return 0; + /** + * Returns the PlatformLogger.Level mapped from j.u.l.Level + * set in the logger. + * @throw IllegalArgumentException if j.u.l.Logger is set to + * a custom j.u.l.Level + */ + Level getLevel() { + Object javaLevel = LoggingSupport.getLevel(javaLogger); + return javaLevel == null + ? null + : Level.valueOf(LoggingSupport.getLevelName(javaLevel)); } - void setLevel(int newLevel) { - levelValue = newLevel; - LoggingSupport.setLevel(javaLogger, levelObjects.get(newLevel)); + void setLevel(Level level) { + LoggingSupport.setLevel(javaLogger, level == null ? null : level.javaLevel); } - public boolean isLoggable(int level) { - return LoggingSupport.isLoggable(javaLogger, levelObjects.get(level)); + boolean isLoggable(Level level) { + return LoggingSupport.isLoggable(javaLogger, level.javaLevel); } } - - private static String getLevelName(int level) { - switch (level) { - case OFF : return "OFF"; - case SEVERE : return "SEVERE"; - case WARNING : return "WARNING"; - case INFO : return "INFO"; - case CONFIG : return "CONFIG"; - case FINE : return "FINE"; - case FINER : return "FINER"; - case FINEST : return "FINEST"; - case ALL : return "ALL"; - default : return "UNKNOWN"; - } - } - } diff --git a/jdk/test/sun/util/logging/PlatformLoggerTest.java b/jdk/test/sun/util/logging/PlatformLoggerTest.java index 25018874af4..7fc007aae0f 100644 --- a/jdk/test/sun/util/logging/PlatformLoggerTest.java +++ b/jdk/test/sun/util/logging/PlatformLoggerTest.java @@ -23,7 +23,7 @@ /* * @test - * @bug 6882376 6985460 + * @bug 6882376 6985460 8010309 * @summary Test if java.util.logging.Logger is created before and after * logging is enabled. Also validate some basic PlatformLogger * operations. othervm mode to make sure java.util.logging @@ -33,11 +33,11 @@ * @run main/othervm PlatformLoggerTest */ +import java.lang.reflect.Field; import java.util.logging.*; import sun.util.logging.PlatformLogger; public class PlatformLoggerTest { - private static final int defaultEffectiveLevel = 0; public static void main(String[] args) throws Exception { final String FOO_PLATFORM_LOGGER = "test.platformlogger.foo"; final String BAR_PLATFORM_LOGGER = "test.platformlogger.bar"; @@ -72,6 +72,7 @@ public class PlatformLoggerTest { foo.setLevel(PlatformLogger.SEVERE); checkLogger(FOO_PLATFORM_LOGGER, Level.SEVERE); + checkPlatformLoggerLevels(foo, bar); } private static void checkPlatformLogger(PlatformLogger logger, String name) { @@ -80,9 +81,9 @@ public class PlatformLoggerTest { logger.getName() + " but expected " + name); } - if (logger.getLevel() != defaultEffectiveLevel) { + if (logger.getLevel() != null) { throw new RuntimeException("Invalid default level for logger " + - logger.getName()); + logger.getName() + ": " + logger.getLevel()); } if (logger.isLoggable(PlatformLogger.FINE) != false) { @@ -91,7 +92,7 @@ public class PlatformLoggerTest { } logger.setLevel(PlatformLogger.FINER); - if (logger.getLevel() != Level.FINER.intValue()) { + if (logger.getLevel() != PlatformLogger.FINER) { throw new RuntimeException("Invalid level for logger " + logger.getName() + " " + logger.getLevel()); } @@ -125,6 +126,73 @@ public class PlatformLoggerTest { logger.info("Test info(String)"); } + private static void checkPlatformLoggerLevels(PlatformLogger... loggers) { + final Level[] levels = new Level[] { + Level.ALL, Level.CONFIG, Level.FINE, Level.FINER, Level.FINEST, + Level.INFO, Level.OFF, Level.SEVERE, Level.WARNING + }; + + int count = PlatformLogger.Level.values().length; + if (levels.length != count) { + throw new RuntimeException("There are " + count + + " PlatformLogger.Level members, but " + levels.length + + " standard java.util.logging levels - the numbers should be equal."); + } + // check mappings + for (Level level : levels) { + checkPlatformLoggerLevelMapping(level); + } + + for (Level level : levels) { + PlatformLogger.Level platformLevel = PlatformLogger.Level.valueOf(level.getName()); + for (PlatformLogger logger : loggers) { + // verify PlatformLogger.setLevel to a given level + logger.setLevel(platformLevel); + PlatformLogger.Level retrievedPlatformLevel = logger.getLevel(); + if (platformLevel != retrievedPlatformLevel) { + throw new RuntimeException("Retrieved PlatformLogger level " + + retrievedPlatformLevel + + " is not the same as set level " + platformLevel); + } + + // check the level set in java.util.logging.Logger + Logger javaLogger = LogManager.getLogManager().getLogger(logger.getName()); + Level javaLevel = javaLogger.getLevel(); + if (javaLogger.getLevel() != level) { + throw new RuntimeException("Retrieved backing java.util.logging.Logger level " + + javaLevel + " is not the expected " + level); + } + } + } + } + + private static void checkPlatformLoggerLevelMapping(Level level) { + // map the given level to PlatformLogger.Level of the same name and value + PlatformLogger.Level platformLevel = PlatformLogger.Level.valueOf(level.getName()); + if (platformLevel.intValue() != level.intValue()) { + throw new RuntimeException("Mismatched level: " + level + + " PlatformLogger.Level" + platformLevel); + } + + PlatformLogger.Level plevel; + try { + // validate if there is a public static final field in PlatformLogger + // matching the level name + Field platformLevelField = PlatformLogger.class.getField(level.getName()); + plevel = (PlatformLogger.Level) platformLevelField.get(null); + } catch (Exception e) { + throw new RuntimeException("No public static PlatformLogger." + level.getName() + + " field", e); + } + if (!plevel.name().equals(level.getName())) + throw new RuntimeException("The value of PlatformLogger." + level.getName() + ".name() is " + + platformLevel.name() + " but expected " + level.getName()); + + if (plevel.intValue() != level.intValue()) + throw new RuntimeException("The value of PlatformLogger." + level.intValue() + ".intValue() is " + + platformLevel.intValue() + " but expected " + level.intValue()); + } + static Point[] getPoints() { Point[] res = new Point[3]; res[0] = new Point(0,0);