/* * Copyright (c) 2013, Oracle and/or its affiliates. All rights reserved. * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. * * This code is free software; you can redistribute it and/or modify it * under the terms of the GNU General Public License version 2 only, as * published by the Free Software Foundation. * * This code is distributed in the hope that it will be useful, but WITHOUT * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License * version 2 for more details (a copy is included in the LICENSE file that * accompanied this code). * * You should have received a copy of the GNU General Public License version * 2 along with this work; if not, write to the Free Software Foundation, * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA. * * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA * or visit www.oracle.com if you need additional information or have any * questions. */ import java.lang.management.ManagementFactory; import java.lang.management.ThreadInfo; import java.security.Permission; import java.security.Policy; import java.security.ProtectionDomain; import java.util.ArrayList; import java.util.List; import java.util.ListResourceBundle; import java.util.Objects; import java.util.ResourceBundle; import java.util.concurrent.Callable; import java.util.concurrent.ExecutorService; import java.util.concurrent.Executors; import java.util.concurrent.FutureTask; import java.util.concurrent.atomic.AtomicLong; import java.util.logging.Handler; import java.util.logging.Level; import java.util.logging.LogRecord; import java.util.logging.Logger; /** * @test * @bug 8029281 8028763 * @summary Attempts to detect synchronization issues with getResourceBundle() * and getResourceBundleName(). It might also detect issues in the way * that the logger tree is cleaned up after a logger has been garbage * collected. This test helped find the root cause of 8029092, so if * this test fails one might also expect failures in * java/util/logging/Logger/logrb/TestLogrbResourceBundle.java and * java/util/logging/Logger/setResourceBundle/TestSetResourceBundle.java. * Note that this is a best effort test. Running it in a loop to * reproduce intermittent issues can be a good idea. * @run main/othervm TestLoggerBundleSync * @author danielfuchs */ public class TestLoggerBundleSync { static volatile Exception thrown = null; static volatile boolean goOn = true; static final int READERS = 3; static final long TIME = 4 * 1000; // 4 sec. static final long STEP = 1 * 1000; // message every 1 sec. static final int LCOUNT = 50; // change bundle 50 times... static final AtomicLong setRBcount = new AtomicLong(0); static final AtomicLong setRBNameCount = new AtomicLong(0); static final AtomicLong getRBcount = new AtomicLong(0); static final AtomicLong checkCount = new AtomicLong(0); static final AtomicLong nextLong = new AtomicLong(0); public static class MyBundle extends ListResourceBundle { @Override protected Object[][] getContents() { return new Object[][] { {"dummy", "foo"} }; } } public static final class MyBundle1 extends MyBundle { }; public static final class MyBundle2 extends MyBundle { }; public static final class MyBundle3 extends MyBundle { }; public static final class LoggerRB { public final String resourceBundleName; public final ResourceBundle userBundle; public LoggerRB(String name, ResourceBundle bundle) { resourceBundleName = name; userBundle = bundle; } } static final List> classes = new ArrayList<>(); static { classes.add(MyBundle1.class); classes.add(MyBundle2.class); classes.add(MyBundle3.class); } /** * This test will run both with and without a security manager. * * The test starts a number of threads that will attempt to concurrently * set resource bundles on Logger, and verifies the consistency of the * obtained results. * * This is a best effort test. * * @param args the command line arguments */ public static void main(String[] args) throws Exception { try { // test without security System.out.println("No security"); test(); // test with security System.out.println("\nWith security"); Policy.setPolicy(new Policy() { @Override public boolean implies(ProtectionDomain domain, Permission permission) { if (super.implies(domain, permission)) return true; // System.out.println("Granting " + permission); return true; // all permissions } }); System.setSecurityManager(new SecurityManager()); test(); } finally { SetRB.executor.shutdownNow(); SetRBName.executor.shutdownNow(); } } /** * Starts all threads, wait 15secs, then stops all threads. * @throws Exception if a deadlock was detected or an error occurred. */ public static void test() throws Exception { goOn = true; thrown = null; long sGetRBCount = getRBcount.get(); long sSetRBCount = setRBcount.get(); long sSetRBNameCount = setRBNameCount.get(); long sCheckCount = checkCount.get(); long sNextLong = nextLong.get(); List threads = new ArrayList<>(); for (Class type : classes) { threads.add(new SetRB(type)); threads.add(new SetRBName(type)); } for (int i =0 ; i < READERS ; i++) { threads.add(new GetRB()); } threads.add(new DeadlockDetector()); threads.add(0, new Stopper(TIME)); for (Thread t : threads) { t.start(); } for (Thread t : threads) { try { t.join(); } catch (Exception x) { fail(x); } } if (thrown != null) { throw thrown; } System.out.println("Passed: " + (nextLong.longValue() - sNextLong) + " unique loggers created"); System.out.println("\t " +(getRBcount.get() - sGetRBCount) + " loggers tested by " + READERS + " Thread(s),"); System.out.println("\t " + (setRBcount.get() - sSetRBCount) + " resource bundles set by " + classes.size() + " Thread(s),"); System.out.println("\t " + (setRBNameCount.get() - sSetRBNameCount) + " resource bundle names set by " + classes.size() + " Thread(s),"); System.out.println("\t ThreadMXBean.findDeadlockedThreads called " + (checkCount.get() -sCheckCount) + " times by 1 Thread."); } final static class GetRB extends Thread { final static class MyHandler extends Handler { volatile ResourceBundle rb; volatile String rbName; @Override public synchronized void publish(LogRecord record) { rb = record.getResourceBundle(); rbName = record.getResourceBundleName(); } @Override public void flush() { } @Override public void close() throws SecurityException { } }; final MyHandler handler = new MyHandler(); @Override public void run() { try { handler.setLevel(Level.FINEST); while (goOn) { Logger l; Logger foo = Logger.getLogger("foo"); Logger bar = Logger.getLogger("foo.bar"); for (long i=0; i < nextLong.longValue() + 100 ; i++) { if (!goOn) break; l = Logger.getLogger("foo.bar.l"+i); final ResourceBundle b = l.getResourceBundle(); final String name = l.getResourceBundleName(); if (b != null) { if (!name.equals(b.getBaseBundleName())) { throw new RuntimeException("Unexpected bundle name: " +b.getBaseBundleName()); } } Logger ll = Logger.getLogger(l.getName()+".bie.bye"); ResourceBundle hrb; String hrbName; ll.setLevel(Level.FINEST); ll.addHandler(handler); ll.fine("dummy"); ll.removeHandler(handler); hrb = handler.rb; hrbName = handler.rbName; if (name != null) { if (!name.equals(hrbName)) { throw new RuntimeException("Unexpected bundle name: " +hrb.getBaseBundleName()); } if (!name.equals(hrb.getBaseBundleName())) { throw new RuntimeException("Unexpected bundle name: " +hrb.getBaseBundleName()); } } getRBcount.incrementAndGet(); if (!goOn) break; Thread.sleep(1); } } } catch (Exception x) { fail(x); } } } final static class SetRB extends Thread { final Class type; final static ExecutorService executor = Executors.newSingleThreadExecutor(); final static class CheckRBTask implements Callable { final Logger logger; volatile String rbName; volatile ResourceBundle rb; public CheckRBTask(Logger logger) { this.logger = logger; } @Override public Exception call() throws Exception { try { final String name = logger.getResourceBundleName(); if (!Objects.equals(name, rbName)) { throw new RuntimeException("Unexpected rbname for " + logger.getName() + ": " + name); } final ResourceBundle b = logger.getResourceBundle(); if (b != rb) { throw new RuntimeException("Unexpected rb for " + logger.getName() + ": " + b); } } catch(Exception x) { return x; } return null; } public void check() throws Exception { final FutureTask futureTask = new FutureTask<>(this); executor.submit(futureTask); Exception x = futureTask.get(); if ( x != null) { throw new RuntimeException("Check failed: "+x,x); } } } SetRB(Class type) { super("SetRB["+type.getSimpleName()+"]"); this.type = type; } @Override public void run() { try { while (goOn) { Logger l; Logger foo = Logger.getLogger("foo"); Logger bar = Logger.getLogger("foo.bar"); l = Logger.getLogger("foo.bar.l"+nextLong.incrementAndGet()); final CheckRBTask checkTask = new CheckRBTask(l); checkTask.check(); for (int i=0; i < LCOUNT ; i++) { if (!goOn) break; ResourceBundle b = ResourceBundle.getBundle(type.getName()); try { l.setResourceBundle(b); checkTask.rb = b; checkTask.rbName = type.getName(); checkTask.check(); if (!goOn) break; String name = l.getResourceBundleName(); ResourceBundle bb = l.getResourceBundle(); if (!type.getName().equals(name)) { throw new RuntimeException(this.getName() + ": Unexpected name: "+name); } if (!b.getBaseBundleName().equals(name)) { throw new RuntimeException(this.getName() + ": Unexpected base name: " + b.getBaseBundleName()); } if (b != bb) { throw new RuntimeException(this.getName() + ": Unexpected bundle: "+bb); } setRBcount.incrementAndGet(); } catch (IllegalArgumentException x) { final String name = l.getResourceBundleName(); if (!name.startsWith(MyBundle.class.getName())) { throw new RuntimeException(this.getName() + ": Unexpected name: "+name, x); } else if (type.getName().equals(name)) { throw new RuntimeException(this.getName() + ": Unexpected exception for "+name, x); } throw x; } l.fine("I'm fine"); if (!goOn) break; Thread.sleep(1); } } } catch (Exception x) { fail(x); } } } final static class SetRBName extends Thread { int nexti = 0; final Class type; final static ExecutorService executor = Executors.newSingleThreadExecutor(); final static class CheckRBNameTask implements Callable { final Logger logger; volatile String rbName; public CheckRBNameTask(Logger logger) { this.logger = logger; } @Override public Exception call() throws Exception { try { final String name = logger.getResourceBundleName(); if (!Objects.equals(name, rbName)) { throw new RuntimeException("Unexpected rbname for " + logger.getName() + ": " + name); } final ResourceBundle b = logger.getResourceBundle(); if (!Objects.equals(b == null ? null : b.getBaseBundleName(), rbName)) { throw new RuntimeException("Unexpected base name for " + logger.getName() + ": " + b.getBaseBundleName()); } } catch(Exception x) { return x; } return null; } public void check() throws Exception { final FutureTask futureTask = new FutureTask<>(this); executor.submit(futureTask); Exception x = futureTask.get(); if ( x != null) { throw new RuntimeException("Check failed: "+x,x); } } } SetRBName(Class type) { super("SetRB["+type.getSimpleName()+"]"); this.type = type; } @Override public void run() { try { while (goOn) { Logger foo = Logger.getLogger("foo"); Logger bar = Logger.getLogger("foo.bar"); Logger l = Logger.getLogger("foo.bar.l"+nextLong.incrementAndGet()); final CheckRBNameTask checkTask = new CheckRBNameTask(l); checkTask.check(); for (int i=0; i < LCOUNT ; i++) { if (!goOn) break; try { Logger l2 = Logger.getLogger(l.getName(), type.getName()); if (l2 != l) { System.err.println("**** ERROR WITH "+l.getName()); throw new RuntimeException("l2 != l [" + l2 + "(" + l2.getName() + ") != " + l + "(" + l.getName() + ")]"); } checkTask.rbName = type.getName(); checkTask.check(); if (!goOn) break; String name = l.getResourceBundleName(); ResourceBundle bb = l.getResourceBundle(); if (!type.getName().equals(name)) { throw new RuntimeException(this.getName() + ": Unexpected name: "+name); } if (!bb.getBaseBundleName().equals(name)) { throw new RuntimeException(this.getName() + ": Unexpected base name: " + bb.getBaseBundleName()); } setRBNameCount.incrementAndGet(); } catch (IllegalArgumentException x) { final String name = l.getResourceBundleName(); if (!name.startsWith(MyBundle.class.getName())) { throw new RuntimeException(this.getName() + ": Unexpected name: "+name, x); } else if (type.getName().equals(name)) { throw new RuntimeException(this.getName() + ": Unexpected exception for "+name, x); } throw x; } l.fine("I'm fine"); if (!goOn) break; Thread.sleep(1); } } } catch (Exception x) { fail(x); } } } final static class DeadlockDetector extends Thread { @Override public void run() { while(goOn) { try { long[] ids = ManagementFactory.getThreadMXBean().findDeadlockedThreads(); checkCount.incrementAndGet(); ids = ids == null ? new long[0] : ids; if (ids.length == 1) { throw new RuntimeException("Found 1 deadlocked thread: "+ids[0]); } else if (ids.length > 0) { ThreadInfo[] infos = ManagementFactory.getThreadMXBean().getThreadInfo(ids); System.err.println("Found "+ids.length+" deadlocked threads: "); for (ThreadInfo inf : infos) { System.err.println(inf.toString()); } throw new RuntimeException("Found "+ids.length+" deadlocked threads"); } Thread.sleep(100); } catch(InterruptedException | RuntimeException x) { fail(x); } } } } static final class Stopper extends Thread { long start; long time; Stopper(long time) { start = System.currentTimeMillis(); this.time = time; } @Override public void run() { try { long rest, previous; previous = time; while (goOn && (rest = start - System.currentTimeMillis() + time) > 0) { if (previous == time || previous - rest >= STEP) { Logger.getLogger("remaining").info(String.valueOf(rest)+"ms remaining..."); previous = rest == time ? rest -1 : rest; System.gc(); } if (goOn == false) break; Thread.sleep(Math.min(rest, 100)); } System.out.println(System.currentTimeMillis() - start + " ms elapsed ("+time+ " requested)"); goOn = false; } catch(InterruptedException | RuntimeException x) { fail(x); } } } static void fail(Exception x) { x.printStackTrace(); if (thrown == null) { thrown = x; } goOn = false; } }