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 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 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 reset() and 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("java.util.logging.LogManager.reconfigureHandlers", "true"); 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("java.util.logging.LogManager.reconfigureHandlers", "true"); 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 reset, check that ref2 has no handlers, and 237 // attempt to configure 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 // Reset 264 Configure.doPrivileged(() -> LogManager.getLogManager().reset()); 265 assertEquals(0, fooChild.getParent().getHandlers().length, "fooChild.getParent().getHandlers().length"); 266 if (checkHandlersOn != null) { 267 Logger loggerWithHandlers = LogManager.getLogManager().getLogger(checkHandlersOn); 268 if (loggerWithHandlers == null) { 269 throw new RuntimeException("Logger with handlers not found: " + checkHandlersOn); 270 } 271 assertEquals(0, loggerWithHandlers.getHandlers().length, 272 checkHandlersOn + ".getHandlers().length"); 273 } 274 275 if (i == 4) { 276 System.out.println("Last configuration..."); 277 } 278 // Read configuration 279 Configure.doPrivileged(() -> Configure.updateConfigurationWith(nextProps, false)); 280 281 expectedHandlersCount = reconfigureHandlers ? 1 : 0; 282 checkHandlersOnParent = Boolean.parseBoolean( 283 nextProps.getProperty("test.checkHandlersOnParent", "true")); 284 checkHandlersOn = nextProps.getProperty("test.checkHandlersOn", null); 285 286 if (checkHandlersOnParent) { 287 assertEquals(expectedHandlersCount, 288 fooChild.getParent().getHandlers().length, 289 "fooChild.getParent().getHandlers().length"); 290 } else { 291 assertEquals(0, 292 fooChild.getParent().getHandlers().length, 293 "fooChild.getParent().getHandlers().length"); 294 } 295 if (checkHandlersOn != null) { 296 Logger loggerWithHandlers = LogManager.getLogManager().getLogger(checkHandlersOn); 297 if (loggerWithHandlers == null) { 298 throw new RuntimeException("Logger with handlers not found: " + checkHandlersOn); 299 } 300 assertEquals(expectedHandlersCount, 301 loggerWithHandlers.getHandlers().length, 302 checkHandlersOn + ".getHandlers().length"); 303 } 304 } 305 } catch (Throwable t) { 306 failed = t; 307 } finally { 308 final Throwable suppressed = failed; 309 Configure.doPrivileged(() -> LogManager.getLogManager().reset()); 310 Configure.doPrivileged(() -> { 311 try { 312 StringBuilder builder = new StringBuilder(); 313 Files.list(Paths.get(userDir)) 314 .filter((f) -> f.toString().contains(PREFIX)) 315 .filter((f) -> f.toString().endsWith(".lck")) 316 .forEach((f) -> { 317 builder.append(f.toString()).append('\n'); 318 }); 319 if (!builder.toString().isEmpty()) { 320 throw new RuntimeException("Lock files not cleaned:\n" 321 + builder.toString()); 322 } 323 } catch(RuntimeException | Error x) { 324 if (suppressed != null) x.addSuppressed(suppressed); 325 throw x; 326 } catch(Exception x) { 327 if (suppressed != null) x.addSuppressed(suppressed); 328 throw new RuntimeException(x); 329 } 330 }); 331 fooChild = null; 332 System.out.println("Setting fooChild to: " + fooChild); 333 while ((ref2 = queue.poll()) == null) { 334 System.gc(); 335 Thread.sleep(1000); 336 } 337 if (ref2 != fooRef) { 338 throw new RuntimeException("Unexpected reference: " 339 + ref2 +"\n\texpected: " + fooRef); 340 } 341 if (ref2.get() != null) { 342 throw new RuntimeException("Referent not cleared: " + ref2.get()); 343 } 344 System.out.println("Got fooRef after reset(), fooChild is " + fooChild); 345 346 } 347 if (failed != null) { 348 // should rarely happen... 349 throw new RuntimeException(failed); 350 } 351 352 } 353 354 public static void main(String... args) throws Exception { 355 356 357 if (args == null || args.length == 0) { 358 args = new String[] { 359 TestCase.UNSECURE.name(), 360 TestCase.SECURE.name(), 361 }; 362 } 363 364 try { 365 for (String testName : args) { 366 TestCase test = TestCase.valueOf(testName); 367 test.run(properties); 368 } 369 } finally { 370 if (userDirWritable) { 371 Configure.doPrivileged(() -> { 372 // cleanup - delete files that have been created 373 try { 374 Files.list(Paths.get(userDir)) 375 .filter((f) -> f.toString().contains(PREFIX)) 376 .forEach((f) -> { 377 try { 378 System.out.println("deleting " + f); 379 Files.delete(f); 380 } catch(Throwable t) { 381 System.err.println("Failed to delete " + f + ": " + t); 382 } 383 }); 384 } catch(Throwable t) { 385 System.err.println("Cleanup failed to list files: " + t); 386 t.printStackTrace(); 387 } 388 }); 389 } 390 } 391 } 392 393 static class Configure { 394 static Policy policy = null; 395 static final ThreadLocal<AtomicBoolean> allowAll = new ThreadLocal<AtomicBoolean>() { 396 @Override 397 protected AtomicBoolean initialValue() { 398 return new AtomicBoolean(false); 399 } 400 }; 401 static void setUp(TestCase test, Properties propertyFile) { 402 switch (test) { 403 case SECURE: 404 if (policy == null && System.getSecurityManager() != null) { 405 throw new IllegalStateException("SecurityManager already set"); 406 } else if (policy == null) { 407 policy = new SimplePolicy(TestCase.SECURE, allowAll); 408 Policy.setPolicy(policy); 409 System.setSecurityManager(new SecurityManager()); 410 } 411 if (System.getSecurityManager() == null) { 412 throw new IllegalStateException("No SecurityManager."); 413 } 414 if (policy == null) { 415 throw new IllegalStateException("policy not configured"); 416 } 417 break; 418 case UNSECURE: 419 if (System.getSecurityManager() != null) { 420 throw new IllegalStateException("SecurityManager already set"); 421 } 422 break; 423 default: 424 new InternalError("No such testcase: " + test); 425 } 426 doPrivileged(() -> { 427 updateConfigurationWith(propertyFile, false); 428 }); 429 } 430 431 static void updateConfigurationWith(Properties propertyFile, boolean append) { 432 try { 433 ByteArrayOutputStream bytes = new ByteArrayOutputStream(); 434 propertyFile.store(bytes, propertyFile.getProperty("test.name")); 435 ByteArrayInputStream bais = new ByteArrayInputStream(bytes.toByteArray()); 436 Function<String, BiFunction<String,String,String>> remapper = 437 append ? (x) -> ((o, n) -> n == null ? o : n) 438 : (x) -> ((o, n) -> n); 439 LogManager.getLogManager().updateConfiguration(bais, remapper); 440 } catch (IOException ex) { 441 throw new RuntimeException(ex); 442 } 443 } 444 445 static void doPrivileged(Runnable run) { 446 final boolean old = allowAll.get().getAndSet(true); 447 try { 448 run.run(); 449 } finally { 450 allowAll.get().set(old); 451 } 452 } 453 static <T> T callPrivileged(Callable<T> call) throws Exception { 454 final boolean old = allowAll.get().getAndSet(true); 455 try { 456 return call.call(); 457 } finally { 458 allowAll.get().set(old); 459 } 460 } 461 } 462 463 @FunctionalInterface 464 public static interface FileHandlerSupplier { 465 public FileHandler test() throws Exception; 466 } 467 468 static final class TestAssertException extends RuntimeException { 469 TestAssertException(String msg) { 470 super(msg); 471 } 472 } 473 474 private static void assertEquals(long expected, long received, String msg) { 475 if (expected != received) { 476 throw new TestAssertException("Unexpected result for " + msg 477 + ".\n\texpected: " + expected 478 + "\n\tactual: " + received); 479 } else { 480 System.out.println("Got expected " + msg + ": " + received); 481 } 482 } 483 484 final static class PermissionsBuilder { 485 final Permissions perms; 486 public PermissionsBuilder() { 487 this(new Permissions()); 488 } 489 public PermissionsBuilder(Permissions perms) { 490 this.perms = perms; 491 } 492 public PermissionsBuilder add(Permission p) { 493 perms.add(p); 494 return this; 495 } 496 public PermissionsBuilder addAll(PermissionCollection col) { 497 if (col != null) { 498 for (Enumeration<Permission> e = col.elements(); e.hasMoreElements(); ) { 499 perms.add(e.nextElement()); 500 } 501 } 502 return this; 503 } 504 public Permissions toPermissions() { 505 final PermissionsBuilder builder = new PermissionsBuilder(); 506 builder.addAll(perms); 507 return builder.perms; 508 } 509 } 510 511 public static class SimplePolicy extends Policy { 512 513 final Permissions permissions; 514 final Permissions allPermissions; 515 final ThreadLocal<AtomicBoolean> allowAll; // actually: this should be in a thread locale 516 public SimplePolicy(TestCase test, ThreadLocal<AtomicBoolean> allowAll) { 517 this.allowAll = allowAll; 518 permissions = new Permissions(); 519 permissions.add(new LoggingPermission("control", null)); 520 permissions.add(new FilePermission(PREFIX+".lck", "read,write,delete")); 521 permissions.add(new FilePermission(PREFIX, "read,write")); 522 523 // these are used for configuring the test itself... 524 allPermissions = new Permissions(); 525 allPermissions.add(new java.security.AllPermission()); 526 527 } 528 529 @Override 530 public boolean implies(ProtectionDomain domain, Permission permission) { 531 if (allowAll.get().get()) return allPermissions.implies(permission); 532 return permissions.implies(permission); 533 } 534 535 @Override 536 public PermissionCollection getPermissions(CodeSource codesource) { 537 return new PermissionsBuilder().addAll(allowAll.get().get() 538 ? allPermissions : permissions).toPermissions(); 539 } 540 541 @Override 542 public PermissionCollection getPermissions(ProtectionDomain domain) { 543 return new PermissionsBuilder().addAll(allowAll.get().get() 544 ? allPermissions : permissions).toPermissions(); 545 } 546 } 547 548 }