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