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 }