File: LoggingDeadlock2.java

package info (click to toggle)
openjdk-11 11.0.4%2B11-1
  • links: PTS, VCS
  • area: main
  • in suites: sid
  • size: 757,028 kB
  • sloc: java: 5,016,041; xml: 1,191,974; cpp: 934,731; ansic: 555,697; sh: 24,299; objc: 12,703; python: 3,602; asm: 3,415; makefile: 2,772; awk: 351; sed: 172; perl: 114; jsp: 24; csh: 3
file content (336 lines) | stat: -rw-r--r-- 12,543 bytes parent folder | download | duplicates (7)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
/*
 * Copyright (c) 2006, 2017, 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.
 */

/*
 * @test
 * @bug     6467152 6716076 6829503 8132550
 * @summary deadlock occurs in LogManager initialization and JVM termination
 * @author  Serguei Spitsyn / Hitachi / Martin Buchholz
 *
 * @build    LoggingDeadlock2
 * @run  main LoggingDeadlock2
 * @key randomness
 */

/*
 *
 * There is a clear deadlock between LogManager.<clinit> and
 * Cleaner.run() methods.
 * T1 thread:
 *   The LogManager.<clinit> creates LogManager.manager object,
 *   sets shutdown hook with the Cleaner class and then waits
 *   to lock the LogManager.manager monitor.
 * T2 thread:
 *   It is started by the System.exit() as shutdown hook thread.
 *   It locks the LogManager.manager monitor and then calls the
 *   static methods of the LogManager class (in this particular
 *   case it is a trick of the inner classes implementation).
 *   It is waits when the LogManager.<clinit> is completed.
 *
 * This is a regression test for this bug.
 */

import java.util.Arrays;
import java.util.List;
import java.util.Random;
import java.util.concurrent.CyclicBarrier;
import java.util.concurrent.atomic.AtomicInteger;
import java.util.logging.LogManager;
import java.io.File;
import java.io.IOException;
import java.io.InputStream;
import java.io.InputStreamReader;
import java.io.Reader;
import java.util.concurrent.TimeUnit;

public class LoggingDeadlock2 {

    // ask child process to dumpstack after 60secs
    public static final long DUMP_STACK_FREQUENCY_MS = 60000;

    // A marker that allows to validate the subprocess output.
    public static final String MARKER = "$";

    public static void realMain(String arg[]) throws Throwable {
        try {
            System.out.println(javaChildArgs);
            ProcessBuilder pb = new ProcessBuilder(javaChildArgs);
            ProcessResults r = run(pb.start());
            equal(r.exitValue(), 99);

            // output of subprocess should end with "$"
            final String out = r.out();
            final String trailingOutput = out.indexOf(MARKER) > -1
                    ? out.substring(out.indexOf(MARKER)+MARKER.length())
                    : out;
            equal(trailingOutput, "");
            equal(r.err(), "");
            equal(out.startsWith("JavaChild started"), true);
            equal(out.endsWith("$"), true);
        } catch (Throwable t) { unexpected(t); }
    }

    public static class JavaChild {
        public static void main(String args[]) throws Throwable {
            System.out.println("JavaChild started");

            final CyclicBarrier startingGate = new CyclicBarrier(2);
            final Throwable[] thrown = new Throwable[1];

            // Some random variation, to help tickle races.
            final Random rnd = new Random();
            final long seed = rnd.nextLong();
            rnd.setSeed(seed);
            System.out.println("seed=" + seed);
            final boolean dojoin = rnd.nextBoolean();
            final int JITTER = 1024;
            final int iters1 = rnd.nextInt(JITTER);
            final int iters2 = JITTER - iters1;
            final AtomicInteger counter = new AtomicInteger(0);
            System.out.println("dojoin=" + dojoin);
            System.out.println("iters1=" + iters1);
            System.out.println("iters2=" + iters2);

            Thread exiter = new Thread() {
                public void run() {
                    try {
                        startingGate.await();
                        for (int i = 0; i < iters1; i++)
                            counter.getAndIncrement();
                        System.exit(99);
                    } catch (Throwable t) {
                        t.printStackTrace();
                        System.exit(86);
                    }
                }};
            exiter.start();

            System.out.println("exiter started");

            // signal end of verbose output
            System.out.print(MARKER);
            System.out.flush();

            startingGate.await();
            for (int i = 0; i < iters2; i++)
                counter.getAndIncrement();
            // This may or may not result in a first call to
            // Runtime.addShutdownHook after shutdown has already
            // commenced.
            LogManager.getLogManager();

            if (dojoin) {
                exiter.join();
                if (thrown[0] != null)
                    throw new Error(thrown[0]);
                check(counter.get() == JITTER);
            }
        }
    }

    //----------------------------------------------------------------
    // The rest of this test is copied from ProcessBuilder/Basic.java
    //----------------------------------------------------------------
    private static final String javaExe =
        System.getProperty("java.home") +
        File.separator + "bin" + File.separator + "java";
    private static final String jstackExe =
        System.getProperty("java.home") +
        File.separator + "bin" + File.separator + "jstack";

    private static final String classpath =
        System.getProperty("java.class.path");

    private static final List<String> javaChildArgs =
        Arrays.asList(new String[]
            { javaExe, "-classpath", classpath,
              "LoggingDeadlock2$JavaChild"});

    private static class ProcessResults {
        private final String out;
        private final String err;
        private final int exitValue;
        private final Throwable throwable;

        public ProcessResults(String out,
                              String err,
                              int exitValue,
                              Throwable throwable) {
            this.out = out;
            this.err = err;
            this.exitValue = exitValue;
            this.throwable = throwable;
        }

        public String out()          { return out; }
        public String err()          { return err; }
        public int exitValue()       { return exitValue; }

        public String toString() {
            StringBuilder sb = new StringBuilder();
            sb.append("<STDOUT>\n" + out() + "</STDOUT>\n")
                .append("<STDERR>\n" + err() + "</STDERR>\n")
                .append("exitValue = " + exitValue + "\n");
            if (throwable != null)
                sb.append(throwable.getStackTrace());
            return sb.toString();
        }
    }

    private static class StreamAccumulator extends Thread {
        private final InputStream is;
        private final StringBuilder sb = new StringBuilder();
        private Throwable throwable = null;

        public String result () throws Throwable {
            if (throwable != null)
                throw throwable;
            return sb.toString();
        }

        StreamAccumulator (InputStream is) {
            this.is = is;
        }

        public void run() {
            try {
                Reader r = new InputStreamReader(is);
                int n;
                while ((n = r.read()) > 0) {
                    sb.append((char)n);

                    // prints everything immediately to System.out so that we can
                    // see the traces even in the event of a test timeout
                    System.out.write((char)n);
                    System.out.flush();

                }
            } catch (Throwable t) {
                throwable = t;
            } finally {
                try { is.close(); }
                catch (Throwable t) { throwable = t; }
            }
        }
    }

    /**
     * If the child process deadlocks, then the parent may fail in timeout.
     * In that case, we won't have any interesting traces, unless we manage
     * to get a thread dump from the child.
     * It is unsure whether obtaining a thread dump from a deadlocked child
     * will work - but maybe we could see something if the timeout is a false
     * positive (the child has not deadlocked but hasn't managed to fully start
     * yet, for instance).
     * The idea here is to periodically try to obtain a thread dump from the
     * child, every 60sec - which should be always less than the jtreg timeout.
     */
    private static class TimeoutThread extends Thread {
        final long ms;
        final Process process;
        TimeoutThread(long ms, Process p) {
            super("TimeoutThread");
            setDaemon(true);
            this.ms = ms;
            this.process = p;
        }

        @Override
        public void run() {
            long start = System.nanoTime();
            try {
                while (true) {
                    sleep(ms);
                    System.err.println("Timeout reached: " + ms);
                    if (process.isAlive()) {
                        long pid = process.pid();
                        ProcessBuilder jstack = new ProcessBuilder(jstackExe, String.valueOf(pid));
                        System.err.println("Dumping subprocess stack: " + pid);
                        Process p = jstack.inheritIO().start();
                        p.waitFor(ms, TimeUnit.MILLISECONDS);
                    } else {
                        System.err.println("Process is not alive!");
                        break;
                    }
                }
            } catch (InterruptedException ex) {
                System.err.println("Interrupted: " + ex);
            } catch (IOException io) {
                System.err.println("Failed to get stack from subprocess");
                io.printStackTrace();
            }
        }


    }

    private static ProcessResults run(Process p) {
        Throwable throwable = null;
        int exitValue = -1;
        String out = "";
        String err = "";

        StreamAccumulator outAccumulator =
            new StreamAccumulator(p.getInputStream());
        StreamAccumulator errAccumulator =
            new StreamAccumulator(p.getErrorStream());

        try {
            System.out.println("Waiting for child process to exit");
            outAccumulator.start();
            errAccumulator.start();

            // ask subprocess to dump stack every 60 secs.
            new TimeoutThread(DUMP_STACK_FREQUENCY_MS, p).start();

            exitValue = p.waitFor();
            System.out.println("\nChild exited with status: " + exitValue);

            outAccumulator.join();
            errAccumulator.join();

            out = outAccumulator.result();
            err = errAccumulator.result();
        } catch (Throwable t) {
            throwable = t;
        }

        return new ProcessResults(out, err, exitValue, throwable);
    }

    //--------------------- Infrastructure ---------------------------
    static volatile int passed = 0, failed = 0;
    static void pass() {passed++;}
    static void fail() {failed++; Thread.dumpStack();}
    static void fail(String msg) {System.out.println(msg); fail();}
    static void unexpected(Throwable t) {failed++; t.printStackTrace();}
    static void check(boolean cond) {if (cond) pass(); else fail();}
    static void check(boolean cond, String m) {if (cond) pass(); else fail(m);}
    static void equal(Object x, Object y) {
        if (x == null ? y == null : x.equals(y)) pass();
        else fail(x + " not equal to " + y);}
    public static void main(String[] args) throws Throwable {
        try {realMain(args);} catch (Throwable t) {unexpected(t);}
        System.out.printf("%nPassed = %d, failed = %d%n%n", passed, failed);
        if (failed > 0) throw new AssertionError("Some tests failed");}
}