8024525: Make Logger log methods call isLoggable()
Summary: This changeset makes the various Logger logging method call isLoggable() instead of inlining the level checks.
Reviewed-by: mchung, alanb
/*
* Copyright (c) 2013, Oracle and/or its affiliates. All rights reserved.
* DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
*
* This code is free software; you can redistribute it and/or modify it
* under the terms of the GNU General Public License version 2 only, as
* published by the Free Software Foundation.
*
* This code is distributed in the hope that it will be useful, but WITHOUT
* ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
* FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License
* version 2 for more details (a copy is included in the LICENSE file that
* accompanied this code).
*
* You should have received a copy of the GNU General Public License version
* 2 along with this work; if not, write to the Free Software Foundation,
* Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
*
* Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
* or visit www.oracle.com if you need additional information or have any
* questions.
*/
import java.util.Collections;
import java.util.HashMap;
import java.util.List;
import java.util.Locale;
import java.util.Map;
import java.util.concurrent.CopyOnWriteArrayList;
import java.util.logging.Handler;
import java.util.logging.Level;
import java.util.logging.LogManager;
import java.util.logging.LogRecord;
import java.util.logging.Logger;
/**
* @test
* @bug 8024525
* @summary checks that isLoggable() can be overridden to control logging.
* @author danielfuchs
* @run main/othervm TestIsLoggable
*/
public class TestIsLoggable {
// This logger can be configured to override its default level
// for a particular set of thread ids
public static final class ThreadLogger extends Logger {
final Map<Long, Level> threadMap =
Collections.synchronizedMap(new HashMap<Long, Level>());
public ThreadLogger(String name) {
super(name, null);
}
@Override
public boolean isLoggable(Level level) {
final Level threadLevel = threadMap.get(Thread.currentThread().getId());
if (threadLevel == null) return super.isLoggable(level);
final int levelValue = threadLevel.intValue();
final int offValue = Level.OFF.intValue();
if (level.intValue() < levelValue || levelValue == offValue) {
return false;
}
return true;
}
}
public static final class TestHandler extends Handler {
final List<String> messages = new CopyOnWriteArrayList<>();
@Override
public void publish(LogRecord record) {
messages.add(record.getMessage());
}
@Override
public void flush() {
}
@Override
public void close() throws SecurityException {
messages.clear();
}
}
// Sorted list of standard levels
static final List<Level> LEVELS = Collections.unmodifiableList(
java.util.Arrays.asList(new Level[] {
Level.SEVERE, Level.WARNING, Level.INFO, Level.CONFIG,
Level.FINE, Level.FINER, Level.FINEST
}));
// Test cases:
// LEV_ test logger.severe(msg) .. logger.finest(msg)
// LOG_ logger.log(Level.SEVERE, msg) ... logger.log(Level.FINEST, msg)
// LOG1_ logger.log(Level.SEVERE, msg, param1) ...
// LOG2_ logger.log(Level.SEVERE, msg, params[]) ...
// LOG3_ logger.log(Level.SEVERE, msg, throwable) ...
// LOGP_ logger.logp(Level.SEVERE, class, method, msg) ...
// LOGP1_ logger.logp(Level.SEVERE, class, method, msg, param1) ...
// LOGP2_ logger.logp(Level.SEVERE, class, method, msg, params[]) ...
// LOGP3_ logger.logp(Level.SEVERE, class, method, msg, throwable) ...
public static enum LogTest {
LEV_SEVERE, LEV_WARNING, LEV_INFO, LEV_CONFIG, LEV_FINE, LEV_FINER, LEV_FINEST,
LOG_SEVERE, LOG_WARNING, LOG_INFO, LOG_CONFIG, LOG_FINE, LOG_FINER, LOG_FINEST,
LOG1_SEVERE, LOG1_WARNING, LOG1_INFO, LOG1_CONFIG, LOG1_FINE, LOG1_FINER, LOG1_FINEST,
LOG2_SEVERE, LOG2_WARNING, LOG2_INFO, LOG2_CONFIG, LOG2_FINE, LOG2_FINER, LOG2_FINEST,
LOG3_SEVERE, LOG3_WARNING, LOG3_INFO, LOG3_CONFIG, LOG3_FINE, LOG3_FINER, LOG3_FINEST,
LOGP_SEVERE, LOGP_WARNING, LOGP_INFO, LOGP_CONFIG, LOGP_FINE, LOGP_FINER, LOGP_FINEST,
LOGP1_SEVERE, LOGP1_WARNING, LOGP1_INFO, LOGP1_CONFIG, LOGP1_FINE, LOGP1_FINER, LOGP1_FINEST,
LOGP2_SEVERE, LOGP2_WARNING, LOGP2_INFO, LOGP2_CONFIG, LOGP2_FINE, LOGP2_FINER, LOGP2_FINEST,
LOGP3_SEVERE, LOGP3_WARNING, LOGP3_INFO, LOGP3_CONFIG, LOGP3_FINE, LOGP3_FINER, LOGP3_FINEST;
// call the method Logger.severe() ... Logger.finest() corresponding
// to the given level 'l' (severe() for SEVERE etc...)
public void loglevel(Level l, Logger logger, String message) {
LogTest test = LogTest.valueOf("LEV_"+l.getName());
switch(test) {
case LEV_SEVERE:
logger.severe(message);
break;
case LEV_WARNING:
logger.warning(message);
break;
case LEV_INFO:
logger.info(message);
break;
case LEV_CONFIG:
logger.config(message);
break;
case LEV_FINE:
logger.fine(message);
break;
case LEV_FINER:
logger.finer(message);
break;
case LEV_FINEST:
logger.finest(message);
break;
}
}
// The threshold at which the logger is expected to start logging.
// trick: we derive the threshold level from the testcase name...
public Level threshold() {
for (Level l : LEVELS ) {
if (this.toString().endsWith(l.getName())) {
return l;
}
}
return Level.OFF;
}
// Levels for which the logger is expected to log something.
public List<Level> loggable() {
return LEVELS.subList(0, LEVELS.indexOf(threshold())+1);
}
// Levels which will be blocked because they are weaker than the
// threshold()
public List<Level> weaker() {
return LEVELS.subList(LEVELS.indexOf(threshold())+1, LEVELS.size());
}
// Log a message at this testcase threshold, using this testcase method.
public void log(Logger logger, String message) {
log(threshold(), logger, message);
}
// Log a message at the given level, using this testcase method.
public void log(Level level, Logger logger, String message) {
if (this.toString().startsWith("LOG_")) {
logger.log(level, message);
} else if (this.toString().startsWith("LOG1_")) {
logger.log(level, message, "dummy param");
} else if (this.toString().startsWith("LOG2_")) {
logger.log(level, message, new Object[] {"dummy", "param"});
} else if (this.toString().startsWith("LOG3_")) {
logger.log(level, message, new Exception("dummy exception"));
} else if (this.toString().startsWith("LOGP_")) {
logger.logp(level, "TestCase", "log", message);
} else if (this.toString().startsWith("LOGP1_")) {
logger.logp(level, "TestCase", "log", message, "dummy param");
} else if (this.toString().startsWith("LOGP2_")) {
logger.logp(level, "TestCase", "log", message,
new Object[] {"dummy", "param"});
} else if (this.toString().startsWith("LOGP3_")) {
logger.logp(level, "TestCase", "log", message,
new Exception("dummy exception"));
} else if (this.toString().startsWith("LEV_")) {
loglevel(level, logger, message);
}
}
// String description of the logging method called.
public String method() {
if (this.toString().startsWith("LOG_")) {
return "Logger.log(Level." + threshold().getName() +", msg): ";
} else if (this.toString().startsWith("LOG1_")) {
return "Logger.log(Level." + threshold().getName() +", msg, param1): ";
} else if (this.toString().startsWith("LOG2_")) {
return "Logger.log(Level." + threshold().getName() +", msg, params[]): ";
} else if (this.toString().startsWith("LOG3_")) {
return "Logger.log(Level." + threshold().getName() +", msg, throwable): ";
} else if (this.toString().startsWith("LEV_")) {
return "Logger."+threshold().getName().toLowerCase(Locale.ROOT)+"(): ";
} else if (this.toString().startsWith("LOGP_")) {
return "Logger.logp(Level." + threshold().getName() +", msg): ";
} else if (this.toString().startsWith("LOGP1_")) {
return "Logger.logp(Level." + threshold().getName() +", msg, param1): ";
} else if (this.toString().startsWith("LOGP2_")) {
return "Logger.logp(Level." + threshold().getName() +", msg, params[]): ";
} else if (this.toString().startsWith("LOGP3_")) {
return "Logger.logp(Level." + threshold().getName() +", msg, throwable): ";
}
throw new RuntimeException("Unknown test case: "+this);
}
}
// The purpose of this test is to verify that the various log methods in
// Logger now call Logger.isLoggable().
// To do that - we're going to use a subclass of Logger, ThreadLogger, which
// only overrides isLoggable() - and compare the level it is given to a level
// it finds in a map indexed with the current thread id.
// We will register a TestHandler with our ThreadLogger which will store
// the messages in a messages map. This will allow us to verify whether the
// logging method we're testing has or hasn't logged.
//
// The TestCase enum above allows us to test a combination of every possible
// log method with every possible level inside a loop - with the
// exception of exiting/entering/throwing that we will be testing
// outside of that loop.
//
public static void main(String... args) {
LogManager manager = LogManager.getLogManager();
ThreadLogger logger = new ThreadLogger("foo.bar");
//manager.addLogger(logger);
TestHandler handler = new TestHandler();
logger.addHandler(handler);
//By default, logger's level is Level.INFO
final List<Level> loggable = LEVELS.subList(0, LEVELS.indexOf(Level.INFO)+1);
// Check our test implementation of logger.isLoggable();
//
// Since we haven't put anything in the threadMap, isLoggable() should
// return true for all levels stronger or equals to Level.INFO.
// here we're just checking that our implementation of
// ThreadLogger.isLoggable() returns what we want - we're just testing
// the test code...
for (Level level : LEVELS) {
if (logger.isLoggable(level) != loggable.contains(level)) {
throw new RuntimeException(level +
": unexpected result for isLoggable(): expected " +
(loggable.contains(level)));
}
}
// Test that entering/exiting/throwing call isLoggable()
// Here we test the default behavior: this call shouldn't log anything
// because by default the logger level is Level.INFO and these
// methods log at Level.FINER.
// So by default - these methods don't log anything. We check it here.
logger.entering("blah", "blah");
logger.entering("blah", "blah", "blah");
logger.entering("blah", "blah", new Object[] {"blah"});
if (!handler.messages.isEmpty()) {
throw new RuntimeException("Expected empty, got "+handler.messages);
}
logger.exiting("blah", "blah");
logger.exiting("blah", "blah", "blah");
logger.exiting("blah", "blah", new Object[] {"blah"});
if (!handler.messages.isEmpty()) {
throw new RuntimeException("Expected empty, got "+handler.messages);
}
logger.throwing("blah", "blah", new Exception("blah"));
if (!handler.messages.isEmpty()) {
throw new RuntimeException("Expected empty, got "+handler.messages);
}
// Now we're going to put each level in turn in the threadMap.
// This means that isLoggable(Level.FINER) should now return true if the
// level in the map is not one of the level in the 'stronger' list below
// (here stronger=stronger than FINER)
final List<Level> stronger = LEVELS.subList(0, LEVELS.indexOf(Level.FINER));
for (Level l : LEVELS) {
logger.threadMap.put(Thread.currentThread().getId(), l);
// Check that our implementation of isLoggable(level) now returns true
// if 'level' is stronger or equals to 'l' - here we're just checking
// that our implementation of ThreadLogger.isLoggable() returns what
// we want - we're just testing the test code...
final List<Level> loggableLevels = LEVELS.subList(0, LEVELS.indexOf(l)+1);
for (Level level : LEVELS) {
if (logger.isLoggable(level) != loggableLevels.contains(level)) {
throw new RuntimeException(level +
": unexpected result for isLoggable(): expected " +
(loggableLevels.contains(level)));
}
}
// These methods should now start to log when the level we put in
// the map is weaker or equals to Level.FINER.
// This validates that these methods now call ThreadLogger.isLoggable()
// since the default level for our logger is still Level.INFO.
// If the methods didn't call ThreadLogger.isLoggable() they wouldn't
// log anything, whatever we put in the threadMap...
logger.entering("blah", "blah");
logger.entering("blah", "blah", "blah");
logger.entering("blah", "blah", new Object[] {"blah"});
if (stronger.contains(l)) {
if (!handler.messages.isEmpty()) {
throw new RuntimeException(l +
": Expected empty, got " + handler.messages);
}
} else {
if (handler.messages.size() != 3) {
throw new RuntimeException(l +
": Expected size 3, got " + handler.messages);
}
}
logger.exiting("blah", "blah");
logger.exiting("blah", "blah", "blah");
logger.exiting("blah", "blah", new Object[] {"blah"});
if (stronger.contains(l)) {
if (!handler.messages.isEmpty()) {
throw new RuntimeException(l +
": Expected empty, got " + handler.messages);
}
} else {
if (handler.messages.size() != 6) {
throw new RuntimeException(l +
": Expected size 6, got " + handler.messages);
}
}
logger.throwing("blah", "blah", new Exception("blah"));
if (stronger.contains(l)) {
if (!handler.messages.isEmpty()) {
throw new RuntimeException(l +
": Expected empty, got " + handler.messages);
}
} else {
if (handler.messages.size() != 7) {
throw new RuntimeException(l +
": Expected size 7, got " + handler.messages);
}
}
if (!stronger.contains(l)) {
System.out.println(l + ": Logger.entering/exiting/throwing: " +
handler.messages);
}
handler.messages.clear();
}
// Cleanup so that we can start the next test with a clean plate...
handler.messages.clear();
logger.threadMap.clear();
// Test that each logging method calls isLoggable()
//
for (LogTest testCase : LogTest.values()) {
// Each test case is a combination of:
// 1. A level to put in the threadMap.
// 2. A log method to call
final String method = testCase.method();
// check our implementation of logger.isLoggable();
// by default the logger level is Level.INFO, so our implementation
// of isLoggable() should return true for all levels stronger or
// equal to INFO and false for the others.
// We check that here.
for (Level level : LEVELS) {
if (logger.isLoggable(level) != loggable.contains(level)) {
throw new RuntimeException(level +
": unexpected result for isLoggable(): expected " +
(loggable.contains(level)));
}
}
// Check that by default the log method will not log for level
// weaker than Level.INFO.
for (Level l : LEVELS.subList(LEVELS.indexOf(Level.INFO) + 1, LEVELS.size())) {
final String test = method + l + ": ";
testCase.log(l, logger, "blah");
if (!handler.messages.isEmpty()) {
throw new RuntimeException(test +
"Expected empty, got " + handler.messages);
}
}
// Let's put Level.OFF in the threadMap. Nothing should be logged,
// whichever level is used...
logger.threadMap.put(Thread.currentThread().getId(), Level.OFF);
// Check that isLoggable() now always return false.
for (Level level : LEVELS) {
if (logger.isLoggable(level)) {
throw new RuntimeException(level +
": unexpected result for isLoggable(): expected " +
false);
}
}
// Check that the log method of the test case won't log, whatever
// level we pass to it. This validates that level method calls
// isLoggable() - because otherwise it would log for levels stronger
// or equal to INFO.
for (Level l : LEVELS) {
final String test = "[threadMap=OFF] " + method + l + ": ";
testCase.log(l, logger, "blah");
if (!handler.messages.isEmpty()) {
throw new RuntimeException(test +
"Expected empty, got " + handler.messages);
}
}
System.out.println("[threadMap=OFF] " + method + "logged " + handler.messages);
// Now put the testcase's level in the threadMap.
logger.threadMap.put(Thread.currentThread().getId(), testCase.threshold());
// The levels for which logging should happen are those that are stronger
// or equals to the testcase's thresholds.
final List<Level> loggableLevels =
LEVELS.subList(0, LEVELS.indexOf(testCase.threshold())+1);
// Check that our implementation of isLoggable() is taking into account
// what we put in the map.
for (Level level : LEVELS) {
if (logger.isLoggable(level) != loggableLevels.contains(level)) {
throw new RuntimeException(level +
": unexpected result for isLoggable(): expected " +
(loggableLevels.contains(level)));
}
}
// Now check that the log method is indeed calling our implementation
// of isLoggable(). We do this by first verifying that it won't log
// for levels weaker than what we put in the map.
//
for (Level l : testCase.weaker()) {
final String test = method + l + ": ";
testCase.log(l, logger, "blah");
if (!handler.messages.isEmpty()) {
throw new RuntimeException(test +
"Expected empty, got " + handler.messages);
}
}
// Then we check that it will log for the testcase threshold.
final String test2 = method + testCase.threshold() + ": ";
testCase.log(logger, testCase.threshold() + " blah");
if (handler.messages.isEmpty()) {
throw new RuntimeException(test2 +
"Expected 1 message, but list is empty");
}
if (!handler.messages.contains(testCase.threshold() + " blah")) {
throw new RuntimeException(test2 + " blah not found: "
+ handler.messages);
}
handler.messages.clear();
// Now we check that it logs for all 'loggable' level (and doesn't
// log for the others).
for (Level l : LEVELS) {
final String test = method + l + ": ";
testCase.log(l, logger, l + ": blah");
if (testCase.loggable().contains(l)) {
if (!handler.messages.contains(l + ": blah")) {
throw new RuntimeException(test + "blah not found: " +
handler.messages);
}
} else {
if (handler.messages.contains(l + ": blah")) {
throw new RuntimeException(test + "blah found: " +
handler.messages);
}
}
}
if (handler.messages.size() != testCase.loggable().size()) {
throw new RuntimeException(method +
" Sizes don't match: expected " +
testCase.loggable().size() + " got " +
handler.messages);
}
// Some visual feedback on what happened.
System.out.println(method + "logged " + handler.messages);
// Cleanup for next step.
// Since we're iterating over all possible levels we can be
// sure that we haven't missed anything.
// For instance - it could be argued that logger.severe() will
// always log. But since we have 1 case where we put Level.OFF in
// the map and we have verified that severe() didn't log in that
// case, but that it logged in any other case, then we know
// beyond doubt that it called our implementation of isLoggable().
logger.threadMap.clear();
handler.messages.clear();
}
}
}