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