1 /* 2 * Copyright (c) 2013, 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 24 import java.lang.management.ManagementFactory; 25 import java.lang.management.ThreadInfo; 26 import java.security.Permission; 27 import java.security.Policy; 28 import java.security.ProtectionDomain; 29 import java.util.ArrayList; 30 import java.util.List; 31 import java.util.ListResourceBundle; 32 import java.util.Objects; 33 import java.util.ResourceBundle; 34 import java.util.concurrent.Callable; 35 import java.util.concurrent.ExecutorService; 36 import java.util.concurrent.Executors; 37 import java.util.concurrent.FutureTask; 38 import java.util.concurrent.atomic.AtomicLong; 39 import java.util.logging.Handler; 40 import java.util.logging.Level; 41 import java.util.logging.LogRecord; 42 import java.util.logging.Logger; 43 44 /** 45 * @test 46 * @bug 8029281 8028763 47 * @summary Attempts to detect synchronization issues with getResourceBundle() 48 * and getResourceBundleName(). It might also detect issues in the way 49 * that the logger tree is cleaned up after a logger has been garbage 50 * collected. This test helped find the root cause of 8029092, so if 51 * this test fails one might also expect failures in 52 * java/util/logging/Logger/logrb/TestLogrbResourceBundle.java and 53 * java/util/logging/Logger/setResourceBundle/TestSetResourceBundle.java. 54 * Note that this is a best effort test. Running it in a loop to 55 * reproduce intermittent issues can be a good idea. 56 * @run main/othervm TestLoggerBundleSync 57 * @author danielfuchs 58 */ 59 public class TestLoggerBundleSync { 60 61 static volatile Exception thrown = null; 62 static volatile boolean goOn = true; 63 64 static final int READERS = 3; 65 static final long TIME = 4 * 1000; // 4 sec. 66 static final long STEP = 1 * 1000; // message every 1 sec. 67 static final int LCOUNT = 50; // change bundle 50 times... 68 static final AtomicLong setRBcount = new AtomicLong(0); 69 static final AtomicLong setRBNameCount = new AtomicLong(0); 70 static final AtomicLong getRBcount = new AtomicLong(0); 71 static final AtomicLong checkCount = new AtomicLong(0); 72 static final AtomicLong nextLong = new AtomicLong(0); 73 74 public static class MyBundle extends ListResourceBundle { 75 @Override 76 protected Object[][] getContents() { 77 return new Object[][] { 78 {"dummy", "foo"} 79 }; 80 } 81 } 82 83 public static final class MyBundle1 extends MyBundle { }; 84 public static final class MyBundle2 extends MyBundle { }; 85 public static final class MyBundle3 extends MyBundle { }; 86 87 88 public static final class LoggerRB { 89 public final String resourceBundleName; 90 public final ResourceBundle userBundle; 91 public LoggerRB(String name, ResourceBundle bundle) { 92 resourceBundleName = name; 93 userBundle = bundle; 94 } 95 } 96 97 static final List<Class<? extends ResourceBundle>> classes = new ArrayList<>(); 98 static { 99 classes.add(MyBundle1.class); 100 classes.add(MyBundle2.class); 101 classes.add(MyBundle3.class); 102 } 103 104 105 /** 106 * This test will run both with and without a security manager. 107 * 108 * The test starts a number of threads that will attempt to concurrently 109 * set resource bundles on Logger, and verifies the consistency of the 110 * obtained results. 111 * 112 * This is a best effort test. 113 * 114 * @param args the command line arguments 115 */ 116 public static void main(String[] args) throws Exception { 117 118 try { 119 // test without security 120 System.out.println("No security"); 121 test(); 122 123 // test with security 124 System.out.println("\nWith security"); 125 Policy.setPolicy(new Policy() { 126 @Override 127 public boolean implies(ProtectionDomain domain, Permission permission) { 128 if (super.implies(domain, permission)) return true; 129 // System.out.println("Granting " + permission); 130 return true; // all permissions 131 } 132 }); 133 System.setSecurityManager(new SecurityManager()); 134 test(); 135 } finally { 136 SetRB.executor.shutdownNow(); 137 SetRBName.executor.shutdownNow(); 138 } 139 } 140 141 /** 142 * Starts all threads, wait 15secs, then stops all threads. 143 * @throws Exception if a deadlock was detected or an error occurred. 144 */ 145 public static void test() throws Exception { 146 goOn = true; 147 thrown = null; 148 long sGetRBCount = getRBcount.get(); 149 long sSetRBCount = setRBcount.get(); 150 long sSetRBNameCount = setRBNameCount.get(); 151 long sCheckCount = checkCount.get(); 152 long sNextLong = nextLong.get(); 153 List<Thread> threads = new ArrayList<>(); 154 for (Class<? extends ResourceBundle> type : classes) { 155 threads.add(new SetRB(type)); 156 threads.add(new SetRBName(type)); 157 } 158 for (int i =0 ; i < READERS ; i++) { 159 threads.add(new GetRB()); 160 } 161 threads.add(new DeadlockDetector()); 162 threads.add(0, new Stopper(TIME)); 163 for (Thread t : threads) { 164 t.start(); 165 } 166 for (Thread t : threads) { 167 try { 168 t.join(); 169 } catch (Exception x) { 170 fail(x); 171 } 172 } 173 if (thrown != null) { 174 throw thrown; 175 } 176 System.out.println("Passed: " + (nextLong.longValue() - sNextLong) 177 + " unique loggers created"); 178 System.out.println("\t " +(getRBcount.get() - sGetRBCount) 179 + " loggers tested by " + READERS + " Thread(s),"); 180 System.out.println("\t " + (setRBcount.get() - sSetRBCount) 181 + " resource bundles set by " + classes.size() + " Thread(s),"); 182 System.out.println("\t " + (setRBNameCount.get() - sSetRBNameCount) 183 + " resource bundle names set by " + classes.size() + " Thread(s),"); 184 System.out.println("\t ThreadMXBean.findDeadlockedThreads called " 185 + (checkCount.get() -sCheckCount) + " times by 1 Thread."); 186 187 } 188 189 final static class GetRB extends Thread { 190 final static class MyHandler extends Handler { 191 volatile ResourceBundle rb; 192 volatile String rbName; 193 @Override 194 public synchronized void publish(LogRecord record) { 195 rb = record.getResourceBundle(); 196 rbName = record.getResourceBundleName(); 197 } 198 199 @Override 200 public void flush() { 201 } 202 203 @Override 204 public void close() throws SecurityException { 205 } 206 }; 207 final MyHandler handler = new MyHandler(); 208 @Override 209 public void run() { 210 try { 211 handler.setLevel(Level.FINEST); 212 while (goOn) { 213 Logger l; 214 Logger foo = Logger.getLogger("foo"); 215 Logger bar = Logger.getLogger("foo.bar"); 216 for (long i=0; i < nextLong.longValue() + 100 ; i++) { 217 if (!goOn) break; 218 l = Logger.getLogger("foo.bar.l"+i); 219 final ResourceBundle b = l.getResourceBundle(); 220 final String name = l.getResourceBundleName(); 221 if (b != null) { 222 if (!name.equals(b.getBaseBundleName())) { 223 throw new RuntimeException("Unexpected bundle name: " 224 +b.getBaseBundleName()); 225 } 226 } 227 Logger ll = Logger.getLogger(l.getName()+".bie.bye"); 228 ResourceBundle hrb; 229 String hrbName; 230 ll.setLevel(Level.FINEST); 231 ll.addHandler(handler); 232 ll.fine("dummy"); 233 ll.removeHandler(handler); 234 hrb = handler.rb; 235 hrbName = handler.rbName; 236 if (name != null) { 237 if (!name.equals(hrbName)) { 238 throw new RuntimeException("Unexpected bundle name: " 239 +hrb.getBaseBundleName()); 240 } 241 if (!name.equals(hrb.getBaseBundleName())) { 242 throw new RuntimeException("Unexpected bundle name: " 243 +hrb.getBaseBundleName()); 244 } 245 } 246 247 getRBcount.incrementAndGet(); 248 if (!goOn) break; 249 Thread.sleep(1); 250 } 251 } 252 } catch (Exception x) { 253 fail(x); 254 } 255 } 256 } 257 258 final static class SetRB extends Thread { 259 final Class<? extends ResourceBundle> type; 260 final static ExecutorService executor = Executors.newSingleThreadExecutor(); 261 final static class CheckRBTask implements Callable<Exception> { 262 final Logger logger; 263 volatile String rbName; 264 volatile ResourceBundle rb; 265 266 public CheckRBTask(Logger logger) { 267 this.logger = logger; 268 } 269 270 @Override 271 public Exception call() throws Exception { 272 try { 273 final String name = logger.getResourceBundleName(); 274 if (!Objects.equals(name, rbName)) { 275 throw new RuntimeException("Unexpected rbname for " 276 + logger.getName() + ": " + name); 277 } 278 final ResourceBundle b = logger.getResourceBundle(); 279 if (b != rb) { 280 throw new RuntimeException("Unexpected rb for " 281 + logger.getName() + ": " + b); 282 } 283 } catch(Exception x) { 284 return x; 285 } 286 return null; 287 } 288 289 public void check() throws Exception { 290 final FutureTask<Exception> futureTask = new FutureTask<>(this); 291 executor.submit(futureTask); 292 Exception x = futureTask.get(); 293 if ( x != null) { 294 throw new RuntimeException("Check failed: "+x,x); 295 } 296 } 297 } 298 SetRB(Class<? extends ResourceBundle> type) { 299 super("SetRB["+type.getSimpleName()+"]"); 300 this.type = type; 301 } 302 @Override 303 public void run() { 304 try { 305 while (goOn) { 306 Logger l; 307 Logger foo = Logger.getLogger("foo"); 308 Logger bar = Logger.getLogger("foo.bar"); 309 l = Logger.getLogger("foo.bar.l"+nextLong.incrementAndGet()); 310 final CheckRBTask checkTask = new CheckRBTask(l); 311 checkTask.check(); 312 313 for (int i=0; i < LCOUNT ; i++) { 314 if (!goOn) break; 315 316 ResourceBundle b = ResourceBundle.getBundle(type.getName()); 317 try { 318 l.setResourceBundle(b); 319 checkTask.rb = b; 320 checkTask.rbName = type.getName(); 321 checkTask.check(); 322 if (!goOn) break; 323 324 String name = l.getResourceBundleName(); 325 ResourceBundle bb = l.getResourceBundle(); 326 if (!type.getName().equals(name)) { 327 throw new RuntimeException(this.getName() 328 + ": Unexpected name: "+name); 329 } 330 if (!b.getBaseBundleName().equals(name)) { 331 throw new RuntimeException(this.getName() 332 + ": Unexpected base name: " + 333 b.getBaseBundleName()); 334 } 335 if (b != bb) { 336 throw new RuntimeException(this.getName() 337 + ": Unexpected bundle: "+bb); 338 } 339 setRBcount.incrementAndGet(); 340 } catch (IllegalArgumentException x) { 341 final String name = l.getResourceBundleName(); 342 if (!name.startsWith(MyBundle.class.getName())) { 343 throw new RuntimeException(this.getName() 344 + ": Unexpected name: "+name, x); 345 } else if (type.getName().equals(name)) { 346 throw new RuntimeException(this.getName() 347 + ": Unexpected exception for "+name, x); 348 } 349 throw x; 350 } 351 l.fine("I'm fine"); 352 if (!goOn) break; 353 Thread.sleep(1); 354 } 355 } 356 } catch (Exception x) { 357 fail(x); 358 } 359 } 360 } 361 362 final static class SetRBName extends Thread { 363 int nexti = 0; 364 final Class<? extends ResourceBundle> type; 365 final static ExecutorService executor = Executors.newSingleThreadExecutor(); 366 final static class CheckRBNameTask implements Callable<Exception> { 367 final Logger logger; 368 volatile String rbName; 369 370 public CheckRBNameTask(Logger logger) { 371 this.logger = logger; 372 } 373 374 @Override 375 public Exception call() throws Exception { 376 try { 377 final String name = logger.getResourceBundleName(); 378 if (!Objects.equals(name, rbName)) { 379 throw new RuntimeException("Unexpected rbname for " 380 + logger.getName() + ": " + name); 381 } 382 final ResourceBundle b = logger.getResourceBundle(); 383 if (!Objects.equals(b == null ? null : b.getBaseBundleName(), rbName)) { 384 throw new RuntimeException("Unexpected base name for " 385 + logger.getName() + ": " + b.getBaseBundleName()); 386 } 387 } catch(Exception x) { 388 return x; 389 } 390 return null; 391 } 392 393 public void check() throws Exception { 394 final FutureTask<Exception> futureTask = new FutureTask<>(this); 395 executor.submit(futureTask); 396 Exception x = futureTask.get(); 397 if ( x != null) { 398 throw new RuntimeException("Check failed: "+x,x); 399 } 400 } 401 402 } 403 SetRBName(Class<? extends ResourceBundle> type) { 404 super("SetRB["+type.getSimpleName()+"]"); 405 this.type = type; 406 } 407 @Override 408 public void run() { 409 try { 410 while (goOn) { 411 Logger foo = Logger.getLogger("foo"); 412 Logger bar = Logger.getLogger("foo.bar"); 413 Logger l = Logger.getLogger("foo.bar.l"+nextLong.incrementAndGet()); 414 final CheckRBNameTask checkTask = new CheckRBNameTask(l); 415 checkTask.check(); 416 417 for (int i=0; i < LCOUNT ; i++) { 418 if (!goOn) break; 419 420 try { 421 Logger l2 = Logger.getLogger(l.getName(), type.getName()); 422 if (l2 != l) { 423 System.err.println("**** ERROR WITH "+l.getName()); 424 throw new RuntimeException("l2 != l [" 425 + l2 + "(" + l2.getName() + ") != " 426 + l + "(" + l.getName() + ")]"); 427 } 428 checkTask.rbName = type.getName(); 429 checkTask.check(); 430 if (!goOn) break; 431 432 String name = l.getResourceBundleName(); 433 ResourceBundle bb = l.getResourceBundle(); 434 if (!type.getName().equals(name)) { 435 throw new RuntimeException(this.getName() 436 + ": Unexpected name: "+name); 437 } 438 if (!bb.getBaseBundleName().equals(name)) { 439 throw new RuntimeException(this.getName() 440 + ": Unexpected base name: " 441 + bb.getBaseBundleName()); 442 } 443 setRBNameCount.incrementAndGet(); 444 } catch (IllegalArgumentException x) { 445 final String name = l.getResourceBundleName(); 446 if (!name.startsWith(MyBundle.class.getName())) { 447 throw new RuntimeException(this.getName() 448 + ": Unexpected name: "+name, x); 449 } else if (type.getName().equals(name)) { 450 throw new RuntimeException(this.getName() 451 + ": Unexpected exception for "+name, x); 452 } 453 throw x; 454 } 455 l.fine("I'm fine"); 456 if (!goOn) break; 457 Thread.sleep(1); 458 } 459 } 460 } catch (Exception x) { 461 fail(x); 462 } 463 } 464 } 465 466 final static class DeadlockDetector extends Thread { 467 468 @Override 469 public void run() { 470 while(goOn) { 471 try { 472 long[] ids = ManagementFactory.getThreadMXBean().findDeadlockedThreads(); 473 checkCount.incrementAndGet(); 474 ids = ids == null ? new long[0] : ids; 475 if (ids.length == 1) { 476 throw new RuntimeException("Found 1 deadlocked thread: "+ids[0]); 477 } else if (ids.length > 0) { 478 ThreadInfo[] infos = ManagementFactory.getThreadMXBean().getThreadInfo(ids); 479 System.err.println("Found "+ids.length+" deadlocked threads: "); 480 for (ThreadInfo inf : infos) { 481 System.err.println(inf.toString()); 482 } 483 throw new RuntimeException("Found "+ids.length+" deadlocked threads"); 484 } 485 Thread.sleep(100); 486 } catch(InterruptedException | RuntimeException x) { 487 fail(x); 488 } 489 } 490 } 491 492 } 493 494 static final class Stopper extends Thread { 495 long start; 496 long time; 497 498 Stopper(long time) { 499 start = System.currentTimeMillis(); 500 this.time = time; 501 } 502 503 @Override 504 public void run() { 505 try { 506 long rest, previous; 507 previous = time; 508 while (goOn && (rest = start - System.currentTimeMillis() + time) > 0) { 509 if (previous == time || previous - rest >= STEP) { 510 Logger.getLogger("remaining").info(String.valueOf(rest)+"ms remaining..."); 511 previous = rest == time ? rest -1 : rest; 512 System.gc(); 513 } 514 if (goOn == false) break; 515 Thread.sleep(Math.min(rest, 100)); 516 } 517 System.out.println(System.currentTimeMillis() - start 518 + " ms elapsed ("+time+ " requested)"); 519 goOn = false; 520 } catch(InterruptedException | RuntimeException x) { 521 fail(x); 522 } 523 } 524 525 } 526 527 static void fail(Exception x) { 528 x.printStackTrace(); 529 if (thrown == null) { 530 thrown = x; 531 } 532 goOn = false; 533 } 534 }