1 /* 2 * Copyright (c) 2014, 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.HashSet; 42 import java.util.List; 43 import java.util.Properties; 44 import java.util.Set; 45 import java.util.UUID; 46 import java.util.concurrent.Callable; 47 import java.util.concurrent.atomic.AtomicBoolean; 48 import java.util.logging.FileHandler; 49 import java.util.logging.Handler; 50 import java.util.logging.LogManager; 51 import java.util.logging.Logger; 52 import java.util.logging.LoggingPermission; 53 54 /** 55 * @test 56 * @bug 8060132 57 * @summary tests that FileHandlers configured on abstract nodes in logging.properties 58 * will be closed by reset(). 59 * @run main/othervm ParentLoggerWithHandlerGC UNSECURE 60 * @run main/othervm ParentLoggerWithHandlerGC SECURE 61 * @author danielfuchs 62 */ 63 public class ParentLoggerWithHandlerGC { 64 65 /** 66 * We will test the handling of abstract logger nodes with file handlers in 67 * two configurations: 68 * UNSECURE: No security manager. 69 * SECURE: With the security manager present - and the required 70 * permissions granted. 71 */ 72 public static enum TestCase { 73 UNSECURE, SECURE; 74 public void run(Properties propertyFile) throws Exception { 75 System.out.println("Running test case: " + name()); 76 Configure.setUp(this, propertyFile); 77 test(this.name() + " " + propertyFile.getProperty("test.name"), propertyFile); 78 } 79 } 80 81 82 private static final String PREFIX = 83 "FileHandler-" + UUID.randomUUID() + ".log"; 84 private static final String userDir = System.getProperty("user.dir", "."); 85 private static final boolean userDirWritable = Files.isWritable(Paths.get(userDir)); 86 87 static enum ConfigMode { DEFAULT, ENSURE_CLOSE_ON_RESET_TRUE, ENSURE_CLOSE_ON_RESET_FALSE } 88 89 private static final List<Properties> properties; 90 static { 91 Properties props1 = new Properties(); 92 props1.setProperty("test.name", "parent logger with handler"); 93 props1.setProperty("test.config.mode", ConfigMode.DEFAULT.name()); 94 props1.setProperty(FileHandler.class.getName() + ".pattern", PREFIX); 95 props1.setProperty(FileHandler.class.getName() + ".limit", String.valueOf(Integer.MAX_VALUE)); 96 props1.setProperty(FileHandler.class.getName() + ".level", "ALL"); 97 props1.setProperty(FileHandler.class.getName() + ".formatter", "java.util.logging.SimpleFormatter"); 98 props1.setProperty("com.foo.handlers", FileHandler.class.getName()); 99 props1.setProperty("com.bar.level", "FINEST"); 100 101 Properties props2 = new Properties(); 102 props2.setProperty("test.name", "parent logger with handler"); 103 props2.setProperty("test.config.mode", ConfigMode.ENSURE_CLOSE_ON_RESET_TRUE.name()); 104 props2.setProperty(FileHandler.class.getName() + ".pattern", PREFIX); 105 props2.setProperty(FileHandler.class.getName() + ".limit", String.valueOf(Integer.MAX_VALUE)); 106 props2.setProperty(FileHandler.class.getName() + ".level", "ALL"); 107 props2.setProperty(FileHandler.class.getName() + ".formatter", "java.util.logging.SimpleFormatter"); 108 props2.setProperty("com.foo.handlers", FileHandler.class.getName()); 109 props2.setProperty("com.foo.handlers.ensureCloseOnReset", "true"); 110 props2.setProperty("com.bar.level", "FINEST"); 111 112 Properties props3 = new Properties(); 113 props3.setProperty("test.name", "parent logger with handler"); 114 props3.setProperty("test.config.mode", ConfigMode.ENSURE_CLOSE_ON_RESET_FALSE.name()); 115 props3.setProperty(FileHandler.class.getName() + ".pattern", PREFIX); 116 props3.setProperty(FileHandler.class.getName() + ".limit", String.valueOf(Integer.MAX_VALUE)); 117 props3.setProperty(FileHandler.class.getName() + ".level", "ALL"); 118 props3.setProperty(FileHandler.class.getName() + ".formatter", "java.util.logging.SimpleFormatter"); 119 props3.setProperty("com.foo.handlers", FileHandler.class.getName()); 120 props3.setProperty("com.foo.handlers.ensureCloseOnReset", "false"); 121 props3.setProperty("com.bar.level", "FINEST"); 122 123 properties = Collections.unmodifiableList(Arrays.asList( 124 props1, props2, props3)); 125 } 126 127 public static void main(String... args) throws Exception { 128 129 130 if (args == null || args.length == 0) { 131 args = new String[] { 132 TestCase.UNSECURE.name(), 133 TestCase.SECURE.name(), 134 }; 135 } 136 137 try { 138 for (String testName : args) { 139 for (Properties propertyFile : properties) { 140 TestCase test = TestCase.valueOf(testName); 141 test.run(propertyFile); 142 } 143 } 144 } finally { 145 if (userDirWritable) { 146 Configure.doPrivileged(() -> { 147 // cleanup - delete files that have been created 148 try { 149 Files.list(Paths.get(userDir)) 150 .filter((f) -> f.toString().contains(PREFIX)) 151 .forEach((f) -> { 152 try { 153 System.out.println("deleting " + f); 154 Files.delete(f); 155 } catch(Throwable t) { 156 System.err.println("Failed to delete " + f + ": " + t); 157 } 158 }); 159 } catch(Throwable t) { 160 System.err.println("Cleanup failed to list files: " + t); 161 t.printStackTrace(); 162 } 163 }); 164 } 165 } 166 } 167 168 static class Configure { 169 static Policy policy = null; 170 static final AtomicBoolean allowAll = new AtomicBoolean(false); 171 static void setUp(TestCase test, Properties propertyFile) { 172 switch (test) { 173 case SECURE: 174 if (policy == null && System.getSecurityManager() != null) { 175 throw new IllegalStateException("SecurityManager already set"); 176 } else if (policy == null) { 177 policy = new SimplePolicy(TestCase.SECURE, allowAll); 178 Policy.setPolicy(policy); 179 System.setSecurityManager(new SecurityManager()); 180 } 181 if (System.getSecurityManager() == null) { 182 throw new IllegalStateException("No SecurityManager."); 183 } 184 if (policy == null) { 185 throw new IllegalStateException("policy not configured"); 186 } 187 break; 188 case UNSECURE: 189 if (System.getSecurityManager() != null) { 190 throw new IllegalStateException("SecurityManager already set"); 191 } 192 break; 193 default: 194 new InternalError("No such testcase: " + test); 195 } 196 doPrivileged(() -> { 197 try { 198 ByteArrayOutputStream bytes = new ByteArrayOutputStream(); 199 propertyFile.store(bytes, propertyFile.getProperty("test.name")); 200 ByteArrayInputStream bais = new ByteArrayInputStream(bytes.toByteArray()); 201 LogManager.getLogManager().readConfiguration(bais); 202 } catch (IOException ex) { 203 throw new RuntimeException(ex); 204 } 205 }); 206 } 207 static void doPrivileged(Runnable run) { 208 allowAll.set(true); 209 try { 210 run.run(); 211 } finally { 212 allowAll.set(false); 213 } 214 } 215 static <T> T callPrivileged(Callable<T> call) throws Exception { 216 allowAll.set(true); 217 try { 218 return call.call(); 219 } finally { 220 allowAll.set(false); 221 } 222 } 223 } 224 225 @FunctionalInterface 226 public static interface FileHandlerSupplier { 227 public FileHandler test() throws Exception; 228 } 229 230 static final class TestAssertException extends RuntimeException { 231 TestAssertException(String msg) { 232 super(msg); 233 } 234 } 235 236 private static void assertEquals(long expected, long received, String msg) { 237 if (expected != received) { 238 throw new TestAssertException("Unexpected result for " + msg 239 + ".\n\texpected: " + expected 240 + "\n\tactual: " + received); 241 } else { 242 System.out.println("Got expected " + msg + ": " + received); 243 } 244 } 245 246 247 public static void test(String name, Properties props) throws Exception { 248 ConfigMode configMode = ConfigMode.valueOf(props.getProperty("test.config.mode")); 249 System.out.println("\nTesting: " + name + " mode=" + configMode); 250 if (!userDirWritable) { 251 throw new RuntimeException("Not writable: "+userDir); 252 } 253 switch(configMode) { 254 case DEFAULT: 255 case ENSURE_CLOSE_ON_RESET_TRUE: 256 testCloseOnResetTrue(name, props); break; 257 case ENSURE_CLOSE_ON_RESET_FALSE: 258 testCloseOnResetFalse(name, props); break; 259 default: 260 throw new RuntimeException("Unknwown mode: " + configMode); 261 } 262 } 263 264 265 // Test a configuration which has either 266 // com.foo.handlers.ensureCloseOnReset=true, or where 267 // com.foo.handlers.ensureCloseOnReset is not specified. 268 public static void testCloseOnResetTrue(String name, Properties props) 269 throws Exception { 270 Logger fooChild = Logger.getLogger("com.foo.child"); 271 fooChild.info("hello world"); 272 Logger barChild = Logger.getLogger("com.bar.child"); 273 barChild.info("hello world"); 274 275 ReferenceQueue<Logger> queue = new ReferenceQueue(); 276 WeakReference<Logger> fooRef = new WeakReference<>(Logger.getLogger("com.foo"), queue); 277 if (fooRef.get() != fooChild.getParent()) { 278 throw new RuntimeException("Unexpected parent logger: " 279 + fooChild.getParent() +"\n\texpected: " + fooRef.get()); 280 } 281 WeakReference<Logger> barRef = new WeakReference<>(Logger.getLogger("com.bar"), queue); 282 if (barRef.get() != barChild.getParent()) { 283 throw new RuntimeException("Unexpected parent logger: " 284 + barChild.getParent() +"\n\texpected: " + barRef.get()); 285 } 286 fooChild = barChild = null; 287 Reference<? extends Logger> ref2 = null; 288 while ((ref2 = queue.poll()) == null) { 289 System.gc(); 290 Thread.sleep(1000); 291 } 292 Throwable failed = null; 293 try { 294 do { 295 if (ref2 != barRef) { 296 throw new RuntimeException("Unexpected reference: " 297 + ref2 +"\n\texpected: " + barRef); 298 } 299 if (ref2.get() != null) { 300 throw new RuntimeException("Referent not cleared: " 301 + ref2.get()); 302 } 303 System.out.println("Got barRef"); 304 System.gc(); 305 Thread.sleep(1000); 306 } while( (ref2 = queue.poll()) != null); 307 System.out.println("Parent logger GCed"); 308 } catch(Throwable t) { 309 failed = t; 310 } finally { 311 final Throwable suppressed = failed; 312 Configure.doPrivileged(() -> LogManager.getLogManager().reset()); 313 Configure.doPrivileged(() -> { 314 try { 315 StringBuilder builder = new StringBuilder(); 316 Files.list(Paths.get(userDir)) 317 .filter((f) -> f.toString().contains(PREFIX)) 318 .filter((f) -> f.toString().endsWith(".lck")) 319 .forEach((f) -> { 320 builder.append(f.toString()).append('\n'); 321 }); 322 if (!builder.toString().isEmpty()) { 323 throw new RuntimeException("Lock files not cleaned:\n" 324 + builder.toString()); 325 } 326 } catch(RuntimeException | Error x) { 327 if (suppressed != null) x.addSuppressed(suppressed); 328 throw x; 329 } catch(Exception x) { 330 if (suppressed != null) x.addSuppressed(suppressed); 331 throw new RuntimeException(x); 332 } 333 }); 334 while ((ref2 = queue.poll()) == null) { 335 System.gc(); 336 Thread.sleep(1000); 337 } 338 if (ref2 != fooRef) { 339 throw new RuntimeException("Unexpected reference: " 340 + ref2 +"\n\texpected: " + fooRef); 341 } 342 if (ref2.get() != null) { 343 throw new RuntimeException("Referent not cleared: " + ref2.get()); 344 } 345 System.out.println("Got fooRef after reset()"); 346 347 } 348 if (failed != null) { 349 // should rarely happen... 350 throw new RuntimeException(failed); 351 } 352 353 } 354 355 private static Handler getHandlerToClose() throws Exception { 356 return Configure.callPrivileged( 357 () -> Logger.getLogger("com.foo.child").getParent().getHandlers()[0]); 358 } 359 360 // Test a configuration which has com.foo.handlers.ensureCloseOnReset=false 361 public static void testCloseOnResetFalse(String name, Properties props) 362 throws Exception { 363 Logger fooChild = Logger.getLogger("com.foo.child"); 364 fooChild.info("hello world"); 365 Logger barChild = Logger.getLogger("com.bar.child"); 366 barChild.info("hello world"); 367 368 Handler toClose = getHandlerToClose(); 369 370 ReferenceQueue<Logger> queue = new ReferenceQueue(); 371 WeakReference<Logger> fooRef = new WeakReference<>(Logger.getLogger("com.foo"), queue); 372 if (fooRef.get() != fooChild.getParent()) { 373 throw new RuntimeException("Unexpected parent logger: " 374 + fooChild.getParent() +"\n\texpected: " + fooRef.get()); 375 } 376 WeakReference<Logger> barRef = new WeakReference<>(Logger.getLogger("com.bar"), queue); 377 if (barRef.get() != barChild.getParent()) { 378 throw new RuntimeException("Unexpected parent logger: " 379 + barChild.getParent() +"\n\texpected: " + barRef.get()); 380 } 381 fooChild = barChild = null; 382 Reference<? extends Logger> ref2 = null; 383 Set<WeakReference<Logger>> expectedRefs = new HashSet<>(Arrays.asList(fooRef, barRef)); 384 Throwable failed = null; 385 try { 386 int l=0; 387 while (failed == null && !expectedRefs.isEmpty()) { 388 int max = 60; 389 while ((ref2 = queue.poll()) == null) { 390 if (l > 0 && max-- <= 0) { 391 throw new RuntimeException("Logger #2 not GC'ed!" 392 + " max too short (max=60) or " 393 + "com.foo.handlers.ensureCloseOnReset=false" 394 + " does not work"); 395 } 396 System.gc(); 397 Thread.sleep(1000); 398 } 399 do { 400 if (!expectedRefs.contains(ref2)) { 401 throw new RuntimeException("Unexpected reference: " 402 + ref2 +"\n\texpected: " + expectedRefs); 403 } 404 if (ref2.get() != null) { 405 throw new RuntimeException("Referent not cleared: " 406 + ref2.get()); 407 } 408 expectedRefs.remove(ref2); 409 System.out.println("Got "+ 410 (ref2 == barRef ? "barRef" 411 : (ref2 == fooRef ? "fooRef" 412 : ref2.toString()))); 413 System.gc(); 414 Thread.sleep(1000); 415 System.out.println("Logger #" + (++l) + " GCed"); 416 } while( (ref2 = queue.poll()) != null); 417 } 418 } catch(Throwable t) { 419 failed = t; 420 } finally { 421 final Throwable suppressed = failed; 422 Configure.doPrivileged(() -> LogManager.getLogManager().reset()); 423 Configure.doPrivileged(() -> { 424 try { 425 toClose.close(); 426 StringBuilder builder = new StringBuilder(); 427 Files.list(Paths.get(userDir)) 428 .filter((f) -> f.toString().contains(PREFIX)) 429 .filter((f) -> f.toString().endsWith(".lck")) 430 .forEach((f) -> { 431 builder.append(f.toString()).append('\n'); 432 }); 433 if (!builder.toString().isEmpty()) { 434 throw new RuntimeException("Lock files not cleaned:\n" + builder.toString()); 435 } 436 } catch(RuntimeException | Error x) { 437 if (suppressed != null) x.addSuppressed(suppressed); 438 throw x; 439 } catch(Exception x) { 440 if (suppressed != null) x.addSuppressed(suppressed); 441 throw new RuntimeException(x); 442 } 443 }); 444 } 445 if (failed != null) { 446 // should rarely happen... 447 throw new RuntimeException(failed); 448 } 449 450 } 451 452 453 final static class PermissionsBuilder { 454 final Permissions perms; 455 public PermissionsBuilder() { 456 this(new Permissions()); 457 } 458 public PermissionsBuilder(Permissions perms) { 459 this.perms = perms; 460 } 461 public PermissionsBuilder add(Permission p) { 462 perms.add(p); 463 return this; 464 } 465 public PermissionsBuilder addAll(PermissionCollection col) { 466 if (col != null) { 467 for (Enumeration<Permission> e = col.elements(); e.hasMoreElements(); ) { 468 perms.add(e.nextElement()); 469 } 470 } 471 return this; 472 } 473 public Permissions toPermissions() { 474 final PermissionsBuilder builder = new PermissionsBuilder(); 475 builder.addAll(perms); 476 return builder.perms; 477 } 478 } 479 480 public static class SimplePolicy extends Policy { 481 482 final Permissions permissions; 483 final Permissions allPermissions; 484 final AtomicBoolean allowAll; 485 public SimplePolicy(TestCase test, AtomicBoolean allowAll) { 486 this.allowAll = allowAll; 487 permissions = new Permissions(); 488 permissions.add(new LoggingPermission("control", null)); 489 permissions.add(new FilePermission(PREFIX+".lck", "read,write,delete")); 490 permissions.add(new FilePermission(PREFIX, "read,write")); 491 492 // these are used for configuring the test itself... 493 allPermissions = new Permissions(); 494 allPermissions.add(new java.security.AllPermission()); 495 496 } 497 498 @Override 499 public boolean implies(ProtectionDomain domain, Permission permission) { 500 if (allowAll.get()) return allPermissions.implies(permission); 501 return permissions.implies(permission); 502 } 503 504 @Override 505 public PermissionCollection getPermissions(CodeSource codesource) { 506 return new PermissionsBuilder().addAll(allowAll.get() 507 ? allPermissions : permissions).toPermissions(); 508 } 509 510 @Override 511 public PermissionCollection getPermissions(ProtectionDomain domain) { 512 return new PermissionsBuilder().addAll(allowAll.get() 513 ? allPermissions : permissions).toPermissions(); 514 } 515 } 516 517 }