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