1 /*
2 * Copyright (c) 2015, 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.ByteArrayInputStream;
24 import java.io.ByteArrayOutputStream;
25 import java.io.FilePermission;
26 import java.io.IOException;
27 import java.lang.ref.Reference;
28 import java.lang.ref.ReferenceQueue;
29 import java.lang.ref.WeakReference;
30 import java.nio.file.Files;
31 import java.nio.file.Paths;
32 import java.security.CodeSource;
33 import java.security.Permission;
34 import java.security.PermissionCollection;
35 import java.security.Permissions;
36 import java.security.Policy;
37 import java.security.ProtectionDomain;
38 import java.util.Arrays;
39 import java.util.Collections;
40 import java.util.Enumeration;
41 import java.util.List;
42 import java.util.Properties;
43 import java.util.UUID;
44 import java.util.concurrent.Callable;
45 import java.util.concurrent.atomic.AtomicBoolean;
46 import java.util.function.BiFunction;
47 import java.util.function.Function;
48 import java.util.logging.FileHandler;
49 import java.util.logging.LogManager;
50 import java.util.logging.Logger;
51 import java.util.logging.LoggingPermission;
52
53 /**
54 * @test
55 * @bug 8033661
56 * @summary tests that FileHandlers configured on abstract nodes in logging.properties
57 * will be properly closed and reopened on updateConfiguration().
58 * Test a complex reconfiguration where a logger with handlers
59 * suddenly appears in the hierarchy between a child logger and the
60 * root logger.
61 * @run main/othervm HandlersOnComplexUpdate UNSECURE
62 * @run main/othervm HandlersOnComplexUpdate SECURE
63 * @author danielfuchs
64 */
65 public class HandlersOnComplexUpdate {
66
67 /**
68 * We will test the handling of abstract logger nodes with file handlers in
69 * two configurations:
70 * UNSECURE: No security manager.
71 * SECURE: With the security manager present - and the required
72 * permissions granted.
73 */
74 public static enum TestCase {
75 UNSECURE, SECURE;
76 public void run(List<Properties> properties) throws Exception {
77 System.out.println("Running test case: " + name());
78 Configure.setUp(this, properties.get(0));
79 test(this.name(), properties);
80 }
81 }
82
83
84 private static final String PREFIX =
85 "FileHandler-" + UUID.randomUUID() + ".log";
86 private static final String userDir = System.getProperty("user.dir", ".");
87 private static final boolean userDirWritable = Files.isWritable(Paths.get(userDir));
88
89 private static final List<Properties> properties;
90 static {
91 // The test will call updateConfiguration() with each of these
92 // properties in sequence. The child logger is not released between each
93 // configuration. What is interesting here is mostly what happens between
94 // props4 and props5:
95 //
96 // In step 4 (props4) the configuration defines a handler for the
97 // logger com.foo (the direct parent of com.foo.child - which is the
98 // logger we hold on to).
99 //
100 // In step 5 (props5) the configuration has nothing concerning
101 // 'com.foo', but the handler has been migrated to 'com'.
102 // Since there doesn't exist any logger for 'com' (the previous
103 // configuration didn't have any configuration for 'com'), then
104 // 'com' will not be found when we process the existing loggers named
105 // in the configuration.
106 //
107 // So if we didn't also process the existing loggers not named in the
108 // configuration (such as com.foo.child) then no logger for 'com'
109 // would be created, which means that com.foo.child would not be
110 // able to inherit its configuration for 'com' until someone explicitely
111 // creates a logger for 'com'.
112 //
113 // This test check that a logger for 'com' will be created because
114 // 'com.foo.child' still exists when updateConfiguration() is called.
115
116 Properties props1 = new Properties();
117 props1.setProperty("test.name", "parent logger with handler");
118 props1.setProperty(FileHandler.class.getName() + ".pattern", PREFIX);
119 props1.setProperty(FileHandler.class.getName() + ".limit", String.valueOf(Integer.MAX_VALUE));
120 props1.setProperty(FileHandler.class.getName() + ".level", "ALL");
121 props1.setProperty(FileHandler.class.getName() + ".formatter", "java.util.logging.SimpleFormatter");
122 props1.setProperty("com.foo.handlers", FileHandler.class.getName());
123 props1.setProperty("test.checkHandlersOnParent", "true");
124 props1.setProperty("test.checkHandlersOn", "com.foo");
125 props1.setProperty("com.bar.level", "FINEST");
126
127 Properties props2 = new Properties();
128 props2.setProperty("test.name", "parent logger with handler");
129 props2.setProperty(FileHandler.class.getName() + ".pattern", PREFIX);
130 props2.setProperty(FileHandler.class.getName() + ".limit", String.valueOf(Integer.MAX_VALUE));
131 props2.setProperty(FileHandler.class.getName() + ".level", "ALL");
132 props2.setProperty(FileHandler.class.getName() + ".formatter", "java.util.logging.SimpleFormatter");
133 props2.setProperty("com.foo.handlers", FileHandler.class.getName());
134 props2.setProperty("test.checkHandlersOnParent", "true");
135 props2.setProperty("test.checkHandlersOn", "com.foo");
136 props2.setProperty("com.bar.level", "FINEST");
137
138 Properties props3 = new Properties();
139 props3.setProperty("test.name", "parent logger with handler");
140 props3.setProperty(FileHandler.class.getName() + ".pattern", PREFIX);
141 props3.setProperty(FileHandler.class.getName() + ".limit", String.valueOf(Integer.MAX_VALUE));
142 props3.setProperty(FileHandler.class.getName() + ".level", "ALL");
143 props3.setProperty(FileHandler.class.getName() + ".formatter", "java.util.logging.SimpleFormatter");
144 props3.setProperty("com.foo.handlers", FileHandler.class.getName());
145 props3.setProperty("test.checkHandlersOnParent", "true");
146 props3.setProperty("test.checkHandlersOn", "com.foo");
147 props3.setProperty("com.bar.level", "FINEST");
148
149 Properties props4 = new Properties();
150 props4.setProperty("test.name", "parent logger with handler");
151 props4.setProperty(FileHandler.class.getName() + ".pattern", PREFIX);
152 props4.setProperty(FileHandler.class.getName() + ".limit", String.valueOf(Integer.MAX_VALUE));
153 props4.setProperty(FileHandler.class.getName() + ".level", "ALL");
154 props4.setProperty(FileHandler.class.getName() + ".formatter", "java.util.logging.SimpleFormatter");
155 props4.setProperty("test.checkHandlersOnParent", "true");
156 props4.setProperty("test.checkHandlersOn", "com.foo");
157 props4.setProperty("com.foo.handlers", FileHandler.class.getName());
158
159 Properties props5 = new Properties();
160 props5.setProperty("test.name", "parent logger with handler");
161 props5.setProperty(FileHandler.class.getName() + ".pattern", PREFIX);
162 props5.setProperty(FileHandler.class.getName() + ".limit", String.valueOf(Integer.MAX_VALUE));
163 props5.setProperty(FileHandler.class.getName() + ".level", "ALL");
164 props5.setProperty(FileHandler.class.getName() + ".formatter", "java.util.logging.SimpleFormatter");
165 props5.setProperty("test.checkHandlersOnParent", "false");
166 props5.setProperty("test.checkHandlersOn", "com");
167 props5.setProperty("com.handlers", FileHandler.class.getName());
168
169 properties = Collections.unmodifiableList(Arrays.asList(
170 props1, props2, props3, props4, props5));
171 }
172
173 /**
174 * This is the main test method. The rest is infrastructure.
175 * Creates a child of the 'com.foo' logger (com.foo.child) and holds on to
176 * it.
177 * <p>
178 * Then applies all given configurations in sequence and verifies assumptions
179 * about the handlers that com.foo should have, or not have.
180 * In the last configuration (props5) it also verifies that the
181 * logger 'com' has been created and has now the expected handler.
182 * <p>
183 * Finally releases the child logger after all configurations have been
184 * applied.
185 *
186 * @param name
187 * @param properties
188 * @throws Exception
189 */
190 static void test(String name, List<Properties> properties)
191 throws Exception {
192
193 System.out.println("\nTesting: " + name);
194 if (!userDirWritable) {
195 throw new RuntimeException("Not writable: "+userDir);
196 }
197
198 // Then create a child of the com.foo logger.
199 Logger fooChild = Logger.getLogger("com.foo.child");
200 fooChild.info("hello world");
201 Logger barChild = Logger.getLogger("com.bar.child");
202 barChild.info("hello world");
203
204 ReferenceQueue<Logger> queue = new ReferenceQueue();
205 WeakReference<Logger> fooRef = new WeakReference<>(Logger.getLogger("com.foo"), queue);
206 if (fooRef.get() != fooChild.getParent()) {
207 throw new RuntimeException("Unexpected parent logger: "
208 + fooChild.getParent() +"\n\texpected: " + fooRef.get());
209 }
210 WeakReference<Logger> barRef = new WeakReference<>(Logger.getLogger("com.bar"), queue);
211 if (barRef.get() != barChild.getParent()) {
212 throw new RuntimeException("Unexpected parent logger: "
213 + barChild.getParent() +"\n\texpected: " + barRef.get());
214 }
215 Reference<? extends Logger> ref2;
216 int max = 3;
217 barChild = null;
218 while ((ref2 = queue.poll()) == null) {
219 System.gc();
220 Thread.sleep(100);
221 if (--max == 0) break;
222 }
223
224 Throwable failed = null;
225 try {
226 if (ref2 != null) {
227 String refName = ref2 == fooRef ? "fooRef" : ref2 == barRef ? "barRef" : "unknown";
228 if (ref2 != barRef) {
229 throw new RuntimeException("Unexpected logger reference cleared: " + refName);
230 } else {
231 System.out.println("Reference " + refName + " cleared as expected");
232 }
233 } else if (ref2 == null) {
234 throw new RuntimeException("Expected 'barRef' to be cleared");
235 }
236 // Now lets try to check handlers, and
237 // attempt to update the configuration again.
238 Properties previousProps = properties.get(0);
239 int expectedHandlersCount = 1;
240 boolean checkHandlersOnParent = Boolean.parseBoolean(
241 previousProps.getProperty("test.checkHandlersOnParent", "true"));
242 String checkHandlersOn = previousProps.getProperty("test.checkHandlersOn", null);
243 for (int i=1; i<properties.size(); i++) {
244 System.out.println("\n*** Reconfiguration with properties["+i+"]\n");
245 Properties nextProps = properties.get(i);
246 boolean reconfigureHandlers = true;
247
248 if (checkHandlersOnParent) {
249 assertEquals(expectedHandlersCount,
250 fooChild.getParent().getHandlers().length,
251 "fooChild.getParent().getHandlers().length");
252 }
253 if (checkHandlersOn != null) {
254 Logger loggerWithHandlers = LogManager.getLogManager().getLogger(checkHandlersOn);
255 if (loggerWithHandlers == null) {
256 throw new RuntimeException("Logger with handlers not found: " + checkHandlersOn);
257 }
258 assertEquals(expectedHandlersCount,
259 loggerWithHandlers.getHandlers().length,
260 checkHandlersOn + ".getHandlers().length");
261 }
262
263 if (i == 4) {
264 System.out.println("Last configuration...");
265 }
266 // Read configuration
267 Configure.doPrivileged(() -> Configure.updateConfigurationWith(nextProps, false));
268
269 expectedHandlersCount = reconfigureHandlers ? 1 : 0;
270 checkHandlersOnParent = Boolean.parseBoolean(
271 nextProps.getProperty("test.checkHandlersOnParent", "true"));
272 checkHandlersOn = nextProps.getProperty("test.checkHandlersOn", null);
273
274 if (checkHandlersOnParent) {
275 assertEquals(expectedHandlersCount,
276 fooChild.getParent().getHandlers().length,
277 "fooChild.getParent().getHandlers().length");
278 } else {
279 assertEquals(0,
280 fooChild.getParent().getHandlers().length,
281 "fooChild.getParent().getHandlers().length");
282 }
283 if (checkHandlersOn != null) {
284 Logger loggerWithHandlers = LogManager.getLogManager().getLogger(checkHandlersOn);
285 if (loggerWithHandlers == null) {
286 throw new RuntimeException("Logger with handlers not found: " + checkHandlersOn);
287 }
288 assertEquals(expectedHandlersCount,
289 loggerWithHandlers.getHandlers().length,
290 checkHandlersOn + ".getHandlers().length");
291 }
292 }
293 } catch (Throwable t) {
294 failed = t;
295 } finally {
296 final Throwable suppressed = failed;
297 Configure.doPrivileged(() -> LogManager.getLogManager().reset());
298 Configure.doPrivileged(() -> {
299 try {
300 StringBuilder builder = new StringBuilder();
301 Files.list(Paths.get(userDir))
302 .filter((f) -> f.toString().contains(PREFIX))
303 .filter((f) -> f.toString().endsWith(".lck"))
304 .forEach((f) -> {
305 builder.append(f.toString()).append('\n');
306 });
307 if (!builder.toString().isEmpty()) {
308 throw new RuntimeException("Lock files not cleaned:\n"
309 + builder.toString());
310 }
311 } catch(RuntimeException | Error x) {
312 if (suppressed != null) x.addSuppressed(suppressed);
313 throw x;
314 } catch(Exception x) {
315 if (suppressed != null) x.addSuppressed(suppressed);
316 throw new RuntimeException(x);
317 }
318 });
319 fooChild = null;
320 System.out.println("Setting fooChild to: " + fooChild);
321 while ((ref2 = queue.poll()) == null) {
322 System.gc();
323 Thread.sleep(1000);
324 }
325 if (ref2 != fooRef) {
326 throw new RuntimeException("Unexpected reference: "
327 + ref2 +"\n\texpected: " + fooRef);
328 }
329 if (ref2.get() != null) {
330 throw new RuntimeException("Referent not cleared: " + ref2.get());
331 }
332 System.out.println("Got fooRef after reset(), fooChild is " + fooChild);
333
334 }
335 if (failed != null) {
336 // should rarely happen...
337 throw new RuntimeException(failed);
338 }
339
340 }
341
342 public static void main(String... args) throws Exception {
343
344
345 if (args == null || args.length == 0) {
346 args = new String[] {
347 TestCase.UNSECURE.name(),
348 TestCase.SECURE.name(),
349 };
350 }
351
352 try {
353 for (String testName : args) {
354 TestCase test = TestCase.valueOf(testName);
355 test.run(properties);
356 }
357 } finally {
358 if (userDirWritable) {
359 Configure.doPrivileged(() -> {
360 // cleanup - delete files that have been created
361 try {
362 Files.list(Paths.get(userDir))
363 .filter((f) -> f.toString().contains(PREFIX))
364 .forEach((f) -> {
365 try {
366 System.out.println("deleting " + f);
367 Files.delete(f);
368 } catch(Throwable t) {
369 System.err.println("Failed to delete " + f + ": " + t);
370 }
371 });
372 } catch(Throwable t) {
373 System.err.println("Cleanup failed to list files: " + t);
374 t.printStackTrace();
375 }
376 });
377 }
378 }
379 }
380
381 static class Configure {
382 static Policy policy = null;
383 static final ThreadLocal<AtomicBoolean> allowAll = new ThreadLocal<AtomicBoolean>() {
384 @Override
385 protected AtomicBoolean initialValue() {
386 return new AtomicBoolean(false);
387 }
388 };
389 static void setUp(TestCase test, Properties propertyFile) {
390 switch (test) {
391 case SECURE:
392 if (policy == null && System.getSecurityManager() != null) {
393 throw new IllegalStateException("SecurityManager already set");
394 } else if (policy == null) {
395 policy = new SimplePolicy(TestCase.SECURE, allowAll);
396 Policy.setPolicy(policy);
397 System.setSecurityManager(new SecurityManager());
398 }
399 if (System.getSecurityManager() == null) {
400 throw new IllegalStateException("No SecurityManager.");
401 }
402 if (policy == null) {
403 throw new IllegalStateException("policy not configured");
404 }
405 break;
406 case UNSECURE:
407 if (System.getSecurityManager() != null) {
408 throw new IllegalStateException("SecurityManager already set");
409 }
410 break;
411 default:
412 new InternalError("No such testcase: " + test);
413 }
414 doPrivileged(() -> {
415 configureWith(propertyFile);
416 });
417 }
418
419 static void configureWith(Properties propertyFile) {
420 try {
421 ByteArrayOutputStream bytes = new ByteArrayOutputStream();
422 propertyFile.store(bytes, propertyFile.getProperty("test.name"));
423 ByteArrayInputStream bais = new ByteArrayInputStream(bytes.toByteArray());
424 LogManager.getLogManager().readConfiguration(bais);
425 } catch (IOException ex) {
426 throw new RuntimeException(ex);
427 }
428 }
429
430 static void updateConfigurationWith(Properties propertyFile, boolean append) {
431 try {
432 ByteArrayOutputStream bytes = new ByteArrayOutputStream();
433 propertyFile.store(bytes, propertyFile.getProperty("test.name"));
434 ByteArrayInputStream bais = new ByteArrayInputStream(bytes.toByteArray());
435 Function<String, BiFunction<String,String,String>> remapper =
436 append ? (x) -> ((o, n) -> n == null ? o : n)
437 : (x) -> ((o, n) -> n);
438 LogManager.getLogManager().updateConfiguration(bais, remapper);
439 } catch (IOException ex) {
440 throw new RuntimeException(ex);
441 }
442 }
443
444 static void doPrivileged(Runnable run) {
445 final boolean old = allowAll.get().getAndSet(true);
446 try {
447 run.run();
448 } finally {
449 allowAll.get().set(old);
450 }
451 }
452 static <T> T callPrivileged(Callable<T> call) throws Exception {
453 final boolean old = allowAll.get().getAndSet(true);
454 try {
455 return call.call();
456 } finally {
457 allowAll.get().set(old);
458 }
459 }
460 }
461
462 @FunctionalInterface
463 public static interface FileHandlerSupplier {
464 public FileHandler test() throws Exception;
465 }
466
467 static final class TestAssertException extends RuntimeException {
468 TestAssertException(String msg) {
469 super(msg);
470 }
471 }
472
473 private static void assertEquals(long expected, long received, String msg) {
474 if (expected != received) {
475 throw new TestAssertException("Unexpected result for " + msg
476 + ".\n\texpected: " + expected
477 + "\n\tactual: " + received);
478 } else {
479 System.out.println("Got expected " + msg + ": " + received);
480 }
481 }
482
483 final static class PermissionsBuilder {
484 final Permissions perms;
485 public PermissionsBuilder() {
486 this(new Permissions());
487 }
488 public PermissionsBuilder(Permissions perms) {
489 this.perms = perms;
490 }
491 public PermissionsBuilder add(Permission p) {
492 perms.add(p);
493 return this;
494 }
495 public PermissionsBuilder addAll(PermissionCollection col) {
496 if (col != null) {
497 for (Enumeration<Permission> e = col.elements(); e.hasMoreElements(); ) {
498 perms.add(e.nextElement());
499 }
500 }
501 return this;
502 }
503 public Permissions toPermissions() {
504 final PermissionsBuilder builder = new PermissionsBuilder();
505 builder.addAll(perms);
506 return builder.perms;
507 }
508 }
509
510 public static class SimplePolicy extends Policy {
511
512 final Permissions permissions;
513 final Permissions allPermissions;
514 final ThreadLocal<AtomicBoolean> allowAll; // actually: this should be in a thread locale
515 public SimplePolicy(TestCase test, ThreadLocal<AtomicBoolean> allowAll) {
516 this.allowAll = allowAll;
517 permissions = new Permissions();
518 permissions.add(new LoggingPermission("control", null));
519 permissions.add(new FilePermission(PREFIX+".lck", "read,write,delete"));
520 permissions.add(new FilePermission(PREFIX, "read,write"));
521
522 // these are used for configuring the test itself...
523 allPermissions = new Permissions();
524 allPermissions.add(new java.security.AllPermission());
525
526 }
527
528 @Override
529 public boolean implies(ProtectionDomain domain, Permission permission) {
530 if (allowAll.get().get()) return allPermissions.implies(permission);
531 return permissions.implies(permission);
532 }
533
534 @Override
535 public PermissionCollection getPermissions(CodeSource codesource) {
536 return new PermissionsBuilder().addAll(allowAll.get().get()
537 ? allPermissions : permissions).toPermissions();
538 }
539
540 @Override
541 public PermissionCollection getPermissions(ProtectionDomain domain) {
542 return new PermissionsBuilder().addAll(allowAll.get().get()
543 ? allPermissions : permissions).toPermissions();
544 }
545 }
546
547 }