Skip to content

Commit e6c7f04

Browse files
committed
8195096: Exception printed on console with custom LogManager on starting Apache Tomcat
Make sure that loadLoggerHandler for ".handler" is called only from within addLogger Reviewed-by: mchung
1 parent cf8d433 commit e6c7f04

8 files changed

Lines changed: 490 additions & 20 deletions

File tree

src/java.logging/share/classes/java/util/logging/LogManager.java

Lines changed: 24 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,5 @@
11
/*
2-
* Copyright (c) 2000, 2017, Oracle and/or its affiliates. All rights reserved.
2+
* Copyright (c) 2000, 2018, Oracle and/or its affiliates. All rights reserved.
33
* DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
44
*
55
* This code is free software; you can redistribute it and/or modify it
@@ -396,12 +396,6 @@ public Object run() {
396396
// Create and retain Logger for the root of the namespace.
397397
owner.addLogger(root);
398398

399-
// For backward compatibility: add any handlers configured using
400-
// ".handlers"
401-
owner.createLoggerHandlers("", ".handlers")
402-
.stream()
403-
.forEach(root::addHandler);
404-
405399
// Initialize level if not yet initialized
406400
if (!root.isLevelInitialized()) {
407401
root.setLevel(defaultLevel);
@@ -995,7 +989,8 @@ private void setLoggerHandlers(final Logger logger, final String name,
995989
}
996990
}
997991

998-
private List<Handler> createLoggerHandlers(final String name, final String handlersPropertyName)
992+
private List<Handler> createLoggerHandlers(final String name,
993+
final String handlersPropertyName)
999994
{
1000995
String names[] = parseClassNames(handlersPropertyName);
1001996
List<Handler> handlers = new ArrayList<>(names.length);
@@ -1198,7 +1193,7 @@ public boolean addLogger(Logger logger) {
11981193
}
11991194
drainLoggerRefQueueBounded();
12001195
LoggerContext cx = getUserContext();
1201-
if (cx.addLocalLogger(logger)) {
1196+
if (cx.addLocalLogger(logger) || forceLoadHandlers(logger)) {
12021197
// Do we have a per logger handler too?
12031198
// Note: this will add a 200ms penalty
12041199
loadLoggerHandlers(logger, name, name + ".handlers");
@@ -1208,6 +1203,26 @@ public boolean addLogger(Logger logger) {
12081203
}
12091204
}
12101205

1206+
1207+
// Checks whether the given logger is a special logger
1208+
// that still requires handler initialization.
1209+
// This method will only return true for the root and
1210+
// global loggers and only if called by the thread that
1211+
// performs initialization of the LogManager, during that
1212+
// initialization. Must only be called by addLogger.
1213+
@SuppressWarnings("deprecation")
1214+
private boolean forceLoadHandlers(Logger logger) {
1215+
// Called just after reading the primordial configuration, in
1216+
// the same thread that reads it.
1217+
// The root and global logger would already be present in the context
1218+
// by this point, but we would not have called loadLoggerHandlers
1219+
// yet.
1220+
return (logger == rootLogger || logger == Logger.global)
1221+
&& !initializationDone
1222+
&& initializedCalled
1223+
&& configurationLock.isHeldByCurrentThread();
1224+
}
1225+
12111226
// Private method to set a level on a logger.
12121227
// If necessary, we raise privilege before doing the call.
12131228
private static void doSetLevel(final Logger logger, final Level level) {
Lines changed: 304 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,304 @@
1+
/*
2+
* Copyright (c) 2018, Oracle and/or its affiliates. All rights reserved.
3+
* DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
4+
*
5+
* This code is free software; you can redistribute it and/or modify it
6+
* under the terms of the GNU General Public License version 2 only, as
7+
* published by the Free Software Foundation.
8+
*
9+
* This code is distributed in the hope that it will be useful, but WITHOUT
10+
* ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
11+
* FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License
12+
* version 2 for more details (a copy is included in the LICENSE file that
13+
* accompanied this code).
14+
*
15+
* You should have received a copy of the GNU General Public License version
16+
* 2 along with this work; if not, write to the Free Software Foundation,
17+
* Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
18+
*
19+
* Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
20+
* or visit www.oracle.com if you need additional information or have any
21+
* questions.
22+
*/
23+
import java.io.ByteArrayOutputStream;
24+
import java.io.IOException;
25+
import java.io.OutputStream;
26+
import java.io.PrintStream;
27+
import java.nio.file.Files;
28+
import java.nio.file.Path;
29+
import java.nio.file.Paths;
30+
import java.nio.file.StandardCopyOption;
31+
import java.util.Collections;
32+
import java.util.Enumeration;
33+
import java.util.List;
34+
import java.util.Objects;
35+
import java.util.concurrent.ConcurrentHashMap;
36+
import java.util.concurrent.ConcurrentMap;
37+
import java.util.logging.Handler;
38+
import java.util.logging.Level;
39+
import java.util.logging.LogManager;
40+
import java.util.logging.Logger;
41+
import java.util.stream.Collectors;
42+
import java.util.stream.Stream;
43+
44+
/**
45+
* @test
46+
* @bug 8191033
47+
* @build custom.DotHandler custom.Handler
48+
* @run main/othervm -Dlogging.properties=badlogging.properties -Dclz=1custom.DotHandler BadRootLoggerHandlers CUSTOM
49+
* @run main/othervm -Dlogging.properties=badlogging.properties -Dclz=1custom.DotHandler BadRootLoggerHandlers DEFAULT
50+
* @run main/othervm -Dlogging.properties=badglobal.properties -Dclz=1custom.GlobalHandler BadRootLoggerHandlers CUSTOM
51+
* @run main/othervm -Dlogging.properties=badglobal.properties -Dclz=1custom.GlobalHandler BadRootLoggerHandlers DEFAULT
52+
* @run main/othervm/java.security.policy==test.policy -Dlogging.properties=badlogging.properties -Dclz=1custom.DotHandler BadRootLoggerHandlers CUSTOM
53+
* @run main/othervm/java.security.policy==test.policy -Dlogging.properties=badlogging.properties -Dclz=1custom.DotHandler BadRootLoggerHandlers DEFAULT
54+
* @run main/othervm/java.security.policy==test.policy -Dlogging.properties=badglobal.properties -Dclz=1custom.GlobalHandler BadRootLoggerHandlers CUSTOM
55+
* @run main/othervm/java.security.policy==test.policy -Dlogging.properties=badglobal.properties -Dclz=1custom.GlobalHandler BadRootLoggerHandlers DEFAULT
56+
* @author danielfuchs
57+
*/
58+
public class BadRootLoggerHandlers {
59+
60+
public static final Path SRC_DIR =
61+
Paths.get(System.getProperty("test.src", "src"));
62+
public static final Path USER_DIR =
63+
Paths.get(System.getProperty("user.dir", "."));
64+
public static final Path CONFIG_FILE = Paths.get(
65+
Objects.requireNonNull(System.getProperty("logging.properties")));
66+
public static final String BAD_HANDLER_NAME =
67+
Objects.requireNonNull(System.getProperty("clz"));
68+
69+
static enum TESTS { CUSTOM, DEFAULT}
70+
public static final class CustomLogManager extends LogManager {
71+
final ConcurrentMap<String, Logger> loggers = new ConcurrentHashMap<>();
72+
@Override
73+
public boolean addLogger(Logger logger) {
74+
return loggers.putIfAbsent(logger.getName(), logger) == null;
75+
}
76+
77+
@Override
78+
public Enumeration<String> getLoggerNames() {
79+
return Collections.enumeration(loggers.keySet());
80+
}
81+
82+
@Override
83+
public Logger getLogger(String name) {
84+
return loggers.get(name);
85+
}
86+
}
87+
88+
public static class SystemErr extends OutputStream {
89+
final ByteArrayOutputStream baos = new ByteArrayOutputStream();
90+
final OutputStream wrapped;
91+
public SystemErr(OutputStream out) {
92+
this.wrapped = out;
93+
}
94+
95+
@Override
96+
public void write(int b) throws IOException {
97+
baos.write(b);
98+
wrapped.write(b);
99+
}
100+
101+
public void close() throws IOException {
102+
flush();
103+
super.close();
104+
}
105+
106+
public void flush() throws IOException {
107+
super.flush();
108+
wrapped.flush();
109+
}
110+
111+
}
112+
113+
// Uncomment this to run the test on Java 8. Java 8 does not have
114+
// List.of(...)
115+
// static final class List {
116+
// static <T> java.util.List<T> of(T... items) {
117+
// return Collections.unmodifiableList(Arrays.asList(items));
118+
// }
119+
// }
120+
121+
public static void main(String[] args) throws IOException {
122+
Path initialProps = SRC_DIR.resolve(CONFIG_FILE);
123+
Path loggingProps = USER_DIR.resolve(CONFIG_FILE);
124+
if (args.length != 1) {
125+
throw new IllegalArgumentException("expected (only) one of " + List.of(TESTS.values()));
126+
}
127+
128+
TESTS test = TESTS.valueOf(args[0]);
129+
System.setProperty("java.util.logging.config.file", loggingProps.toString());
130+
if (test == TESTS.CUSTOM) {
131+
System.setProperty("java.util.logging.manager", CustomLogManager.class.getName());
132+
}
133+
134+
Files.copy(initialProps, loggingProps, StandardCopyOption.REPLACE_EXISTING);
135+
136+
SystemErr err = new SystemErr(System.err);
137+
System.setErr(new PrintStream(err));
138+
139+
System.out.println("Root level is: " + Logger.getLogger("").getLevel());
140+
if (Logger.getLogger("").getLevel() != Level.INFO) {
141+
throw new RuntimeException("Expected root level INFO, got: "
142+
+ Logger.getLogger("").getLevel());
143+
}
144+
145+
Class<? extends LogManager> logManagerClass =
146+
LogManager.getLogManager().getClass();
147+
Class<? extends LogManager> expectedClass =
148+
test == TESTS.CUSTOM ? CustomLogManager.class : LogManager.class;
149+
if (logManagerClass != expectedClass) {
150+
throw new RuntimeException("Bad class for log manager: " + logManagerClass
151+
+ " expected " + expectedClass + " for " + test);
152+
}
153+
154+
if (test == TESTS.DEFAULT) {
155+
// Verify that we have two handlers. One was configured with
156+
// handlers=custom.Handler, the other with
157+
// .handlers=custom.DotHandler
158+
// Verify that exactly one of the two handlers is a custom.Handler
159+
// Verify that exactly one of the two handlers is a custom.DotHandler
160+
// Verify that the two handlers have an id of '1'
161+
checkHandlers(Logger.getLogger(""),
162+
Logger.getLogger("").getHandlers(),
163+
1L,
164+
custom.Handler.class,
165+
custom.DotHandler.class);
166+
} else {
167+
// Verify that we have one handler, configured with
168+
// handlers=custom.Handler.
169+
// Verify that it is a custom.Handler
170+
// Verify that the handler have an id of '1'
171+
checkHandlers(Logger.getLogger(""),
172+
Logger.getLogger("").getHandlers(),
173+
1L,
174+
custom.Handler.class);
175+
176+
}
177+
178+
// DEFAULT: The log message "hi" should appear twice on the console.
179+
// CUSTOM: The log message "hi" should appear twice on the console.
180+
// We don't check that. This is just for log analysis in case
181+
// of test failure.
182+
Logger.getAnonymousLogger().info("hi (" + test +")");
183+
184+
// Change the root logger level to FINE in the properties file
185+
// and reload the configuration.
186+
Files.write(loggingProps,
187+
Files.lines(initialProps)
188+
.map((s) -> s.replace("INFO", "FINE"))
189+
.collect(Collectors.toList()));
190+
LogManager.getLogManager().readConfiguration();
191+
192+
System.out.println("Root level is: " + Logger.getLogger("").getLevel());
193+
if (Logger.getLogger("").getLevel() != Level.FINE) {
194+
throw new RuntimeException("Expected root level FINE, got: "
195+
+ Logger.getLogger("").getLevel());
196+
}
197+
198+
// Verify that we have now only one handler, configured with
199+
// handlers=custom.Handler, and that the other configured with
200+
// .handlers=custom.DotHandler was ignored.
201+
// Verify that the handler is a custom.Handler
202+
// Verify that the handler has an id of '2'
203+
checkHandlers(Logger.getLogger(""),
204+
Logger.getLogger("").getHandlers(),
205+
2L,
206+
custom.Handler.class);
207+
208+
// The log message "there" should appear only once on the console.
209+
// We don't check that. This is just for log analysis in case
210+
// of test failure.
211+
Logger.getAnonymousLogger().info("there!");
212+
213+
// Change the root logger level to FINER in the properties file
214+
// and reload the configuration.
215+
Files.write(loggingProps,
216+
Files.lines(initialProps)
217+
.map((s) -> s.replace("INFO", "FINER"))
218+
.collect(Collectors.toList()));
219+
LogManager.getLogManager().readConfiguration();
220+
221+
System.out.println("Root level is: " + Logger.getLogger("").getLevel());
222+
if (Logger.getLogger("").getLevel() != Level.FINER) {
223+
throw new RuntimeException("Expected root level FINER, got: "
224+
+ Logger.getLogger("").getLevel());
225+
}
226+
227+
// Verify that we have only one handler, configured with
228+
// handlers=custom.Handler, and that the other configured with
229+
// .handlers=custom.DotHandler was ignored.
230+
// Verify that the handler is a custom.Handler
231+
// Verify that the handler has an id of '3'
232+
checkHandlers(Logger.getLogger(""),
233+
Logger.getLogger("").getHandlers(),
234+
3L,
235+
custom.Handler.class);
236+
237+
// The log message "done" should appear only once on the console.
238+
// We don't check that. This is just for log analysis in case
239+
// of test failure.
240+
Logger.getAnonymousLogger().info("done!");
241+
242+
byte[] errBytes = err.baos.toByteArray();
243+
String errText = new String(errBytes);
244+
switch(test) {
245+
case CUSTOM:
246+
if (errText.contains("java.lang.ClassNotFoundException: "
247+
+ BAD_HANDLER_NAME)) {
248+
throw new RuntimeException("Error message found on System.err");
249+
}
250+
System.out.println("OK: ClassNotFoundException error message not found for " + test);
251+
break;
252+
case DEFAULT:
253+
if (!errText.contains("java.lang.ClassNotFoundException: "
254+
+ BAD_HANDLER_NAME)) {
255+
throw new RuntimeException("Error message not found on System.err");
256+
}
257+
System.err.println("OK: ClassNotFoundException error message found for " + test);
258+
break;
259+
default:
260+
throw new InternalError("unknown test case: " + test);
261+
}
262+
}
263+
264+
static void checkHandlers(Logger logger, Handler[] handlers, Long expectedID, Class<?>... clz) {
265+
// Verify that we have the expected number of handlers.
266+
if (Stream.of(handlers).count() != clz.length) {
267+
throw new RuntimeException("Expected " + clz.length + " handlers, got: "
268+
+ List.of(logger.getHandlers()));
269+
}
270+
for (Class<?> cl : clz) {
271+
// Verify that the handlers are of the expected class.
272+
// For each class, we should have exactly one handler
273+
// of that class.
274+
if (Stream.of(handlers)
275+
.map(Object::getClass)
276+
.filter(cl::equals)
277+
.count() != 1) {
278+
throw new RuntimeException("Expected one " + cl +", got: "
279+
+ List.of(logger.getHandlers()));
280+
}
281+
}
282+
// Verify that all handlers have the expected ID
283+
if (Stream.of(logger.getHandlers())
284+
.map(BadRootLoggerHandlers::getId)
285+
.filter(expectedID::equals)
286+
.count() != clz.length) {
287+
throw new RuntimeException("Expected ids to be " + expectedID + ", got: "
288+
+ List.of(logger.getHandlers()));
289+
}
290+
}
291+
292+
static long getId(Handler h) {
293+
if (h instanceof custom.Handler) {
294+
return ((custom.Handler)h).id;
295+
}
296+
if (h instanceof custom.DotHandler) {
297+
return ((custom.DotHandler)h).id;
298+
}
299+
if (h instanceof custom.GlobalHandler) {
300+
return ((custom.GlobalHandler)h).id;
301+
}
302+
return -1;
303+
}
304+
}

0 commit comments

Comments
 (0)