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 import java.lang.management.ManagementFactory;
24 import java.lang.management.ThreadInfo;
25 import java.security.Permission;
26 import java.security.Policy;
27 import java.security.ProtectionDomain;
28 import java.util.ArrayList;
29 import java.util.List;
30 import java.util.concurrent.atomic.AtomicLong;
31 import java.util.logging.LogManager;
32 import java.util.logging.Logger;
33
34
35 /**
36 * @test
37 * @bug 8029281 8027670
38 * @summary Synchronization issues in Logger and LogManager. This test
39 * focusses more particularly on potential deadlock in
40 * drainLoggerRefQueueBounded / readConfiguration
41 * @run main/othervm TestLogConfigurationDeadLock
42 * @author danielfuchs
43 */
44 // This test is a best effort to try & detect issues. The test itself will run
45 // for 8secs. This is usually unsufficient to detect issues.
46 // To get a greater confidence it is recommended to run this test in a loop:
47 // e.g. use something like:
48 // $ while jtreg -jdk:$JDK -verbose:all \
49 // test/java/util/logging/TestLogConfigurationDeadLock.java ; \
50 // do echo Running test again ; done
51 // and let it run for a few hours...
52 //
53 public class TestLogConfigurationDeadLock {
54
55 static volatile Exception thrown = null;
56 static volatile boolean goOn = true;
57
58 static final int READERS = 2;
59 static final int LOGGERS = 2;
60 static final long TIME = 4 * 1000; // 4 sec.
61 static final long STEP = 1 * 1000; // message every 1 sec.
62 static final int LCOUNT = 50; // 50 loggers created in a row...
63 static final AtomicLong nextLogger = new AtomicLong(0);
64 static final AtomicLong readCount = new AtomicLong(0);
65 static final AtomicLong checkCount = new AtomicLong(0);
66
67 /**
68 * This test will run both with and without a security manager.
69 *
70 * The test starts a number of threads that will call
71 * LogManager.readConfiguration() concurrently (ReadConf), then starts
72 * a number of threads that will create new loggers concurrently
73 * (AddLogger), and then two additional threads: one (Stopper) that
74 * will stop the test after 4secs (TIME ms), and one DeadlockDetector
75 * that will attempt to detect deadlocks.
76 * If after 4secs no deadlock was detected and no exception was thrown
77 * then the test is considered a success and passes.
78 *
79 * This procedure is done twice: once without a security manager and once
80 * again with a security manager - which means the test takes ~8secs to
81 * run.
82 *
83 * Note that 8sec may not be enough to detect issues if there are some.
84 * This is a best effort test.
85 *
86 * @param args the command line arguments
87 */
88 public static void main(String[] args) throws Exception {
89
90 // test without security
91 System.out.println("No security");
92 test();
93
94 // test with security
95 System.out.println("\nWith security");
96 Policy.setPolicy(new Policy() {
97 @Override
98 public boolean implies(ProtectionDomain domain, Permission permission) {
99 if (super.implies(domain, permission)) return true;
100 // System.out.println("Granting " + permission);
101 return true; // all permissions
102 }
103 });
104 System.setSecurityManager(new SecurityManager());
105 test();
106 }
107
108 /**
109 * Starts all threads, wait 4secs, then stops all threads.
110 * @throws Exception if a deadlock was detected or an error occurred.
111 */
112 public static void test() throws Exception {
113 goOn = true;
114 thrown = null;
115 long sNextLogger = nextLogger.get();
116 long sReadCount = readCount.get();
117 long sCheckCount = checkCount.get();
118 List<Thread> threads = new ArrayList<>();
119 for (int i = 0; i<READERS; i++) {
120 threads.add(new ReadConf());
121 }
122 for (int i = 0; i<LOGGERS; i++) {
123 threads.add(new AddLogger());
124 }
125 threads.add(new DeadlockDetector());
126 threads.add(0, new Stopper(TIME));
127 for (Thread t : threads) {
128 t.start();
129 }
130 for (Thread t : threads) {
131 try {
132 t.join();
133 } catch (Exception x) {
134 fail(x);
135 }
136 }
137 if (thrown != null) {
138 throw thrown;
139 }
140 System.out.println("Passed: " + (nextLogger.get() - sNextLogger)
141 + " loggers created by " + LOGGERS + " Thread(s),");
142 System.out.println("\t LogManager.readConfiguration() called "
143 + (readCount.get() - sReadCount) + " times by " + READERS
144 + " Thread(s).");
145 System.out.println("\t ThreadMXBean.findDeadlockedThreads called "
146 + (checkCount.get() -sCheckCount) + " times by 1 Thread.");
147
148 }
149
150
151 final static class ReadConf extends Thread {
152 @Override
153 public void run() {
154 while (goOn) {
155 try {
156 LogManager.getLogManager().readConfiguration();
157 readCount.incrementAndGet();
158 Thread.sleep(1);
159 } catch (Exception x) {
160 fail(x);
161 }
162 }
163 }
164 }
165
166 final static class AddLogger extends Thread {
167 @Override
168 public void run() {
169 try {
170 while (goOn) {
171 Logger l;
172 Logger foo = Logger.getLogger("foo");
173 Logger bar = Logger.getLogger("foo.bar");
174 for (int i=0; i < LCOUNT ; i++) {
175 l = Logger.getLogger("foo.bar.l"+nextLogger.incrementAndGet());
176 l.fine("I'm fine");
177 if (!goOn) break;
178 Thread.sleep(1);
179 }
180 }
181 } catch (InterruptedException | RuntimeException x ) {
182 fail(x);
183 }
184 }
185 }
186
187 final static class DeadlockDetector extends Thread {
188
189 @Override
190 public void run() {
191 while(goOn) {
192 try {
193 long[] ids = ManagementFactory.getThreadMXBean().findDeadlockedThreads();
194 checkCount.incrementAndGet();
195 ids = ids == null ? new long[0] : ids;
196 if (ids.length == 1) {
197 throw new RuntimeException("Found 1 deadlocked thread: "+ids[0]);
198 } else if (ids.length > 0) {
199 ThreadInfo[] infos = ManagementFactory.getThreadMXBean().getThreadInfo(ids);
200 System.err.println("Found "+ids.length+" deadlocked threads: ");
201 for (ThreadInfo inf : infos) {
202 System.err.println(inf.toString());
203 }
204 throw new RuntimeException("Found "+ids.length+" deadlocked threads");
205 }
206 Thread.sleep(100);
207 } catch(InterruptedException | RuntimeException x) {
208 fail(x);
209 }
210 }
211 }
212
213 }
214
215 static final class Stopper extends Thread {
216 long start;
217 long time;
218
219 Stopper(long time) {
220 start = System.currentTimeMillis();
221 this.time = time;
222 }
223
224 @Override
225 public void run() {
226 try {
227 long rest, previous;
228 previous = time;
229 while (goOn && (rest = start - System.currentTimeMillis() + time) > 0) {
230 if (previous == time || previous - rest >= STEP) {
231 Logger.getLogger("remaining").info(String.valueOf(rest)+"ms remaining...");
232 previous = rest == time ? rest -1 : rest;
233 System.gc();
234 }
235 if (goOn == false) break;
236 Thread.sleep(Math.min(rest, 100));
237 }
238 System.out.println(System.currentTimeMillis() - start
239 + " ms elapsed ("+time+ " requested)");
240 goOn = false;
241 } catch(InterruptedException | RuntimeException x) {
242 fail(x);
243 }
244 }
245
246 }
247
248 static void fail(Exception x) {
249 x.printStackTrace();
250 if (thrown == null) {
251 thrown = x;
252 }
253 goOn = false;
254 }
255 }