001/**
002 * Licensed to the Apache Software Foundation (ASF) under one
003 * or more contributor license agreements.  See the NOTICE file
004 * distributed with this work for additional information
005 * regarding copyright ownership.  The ASF licenses this file
006 * to you under the Apache License, Version 2.0 (the
007 * "License"); you may not use this file except in compliance
008 * with the License.  You may obtain a copy of the License at
009 *
010 *     http://www.apache.org/licenses/LICENSE-2.0
011 *
012 * Unless required by applicable law or agreed to in writing, software
013 * distributed under the License is distributed on an "AS IS" BASIS,
014 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
015 * See the License for the specific language governing permissions and
016 * limitations under the License.
017 */
018package org.apache.hadoop.hbase;
019
020import java.io.PrintWriter;
021import java.io.StringWriter;
022import java.lang.management.LockInfo;
023import java.lang.management.ManagementFactory;
024import java.lang.management.MonitorInfo;
025import java.lang.management.ThreadInfo;
026import java.lang.management.ThreadMXBean;
027import java.text.DateFormat;
028import java.text.SimpleDateFormat;
029import java.util.Date;
030import java.util.Locale;
031import java.util.Map;
032
033import org.junit.runner.notification.Failure;
034import org.junit.runner.notification.RunListener;
035
036/**
037 * JUnit run listener which prints full thread dump into System.err
038 * in case a test is failed due to timeout.
039 */
040public class TimedOutTestsListener extends RunListener {
041
042  static final String TEST_TIMED_OUT_PREFIX = "test timed out after";
043
044  private static String INDENT = "    ";
045
046  private final PrintWriter output;
047
048  public TimedOutTestsListener() {
049    this.output = new PrintWriter(System.err);
050  }
051
052  public TimedOutTestsListener(PrintWriter output) {
053    this.output = output;
054  }
055
056  @Override
057  public void testFailure(Failure failure) throws Exception {
058    if (failure != null && failure.getMessage() != null
059        && failure.getMessage().startsWith(TEST_TIMED_OUT_PREFIX)) {
060      output.println("====> TEST TIMED OUT. PRINTING THREAD DUMP. <====");
061      output.println();
062      output.print(buildThreadDiagnosticString());
063    }
064    output.flush();
065  }
066
067  public static String buildThreadDiagnosticString() {
068    StringWriter sw = new StringWriter();
069    PrintWriter output = new PrintWriter(sw);
070
071    DateFormat dateFormat = new SimpleDateFormat("yyyy-MM-dd hh:mm:ss,SSS");
072    output.println(String.format("Timestamp: %s", dateFormat.format(new Date())));
073    output.println();
074    output.println(buildThreadDump());
075
076    String deadlocksInfo = buildDeadlockInfo();
077    if (deadlocksInfo != null) {
078      output.println("====> DEADLOCKS DETECTED <====");
079      output.println();
080      output.println(deadlocksInfo);
081    }
082
083    return sw.toString();
084  }
085
086  static String buildThreadDump() {
087    StringBuilder dump = new StringBuilder();
088    Map<Thread, StackTraceElement[]> stackTraces = Thread.getAllStackTraces();
089    for (Map.Entry<Thread, StackTraceElement[]> e : stackTraces.entrySet()) {
090      Thread thread = e.getKey();
091      dump.append(String.format(
092          "\"%s\" %s prio=%d tid=%d %s\njava.lang.Thread.State: %s",
093          thread.getName(),
094          (thread.isDaemon() ? "daemon" : ""),
095          thread.getPriority(),
096          thread.getId(),
097          Thread.State.WAITING.equals(thread.getState()) ? 
098              "in Object.wait()" : thread.getState().name().toLowerCase(Locale.ROOT),
099          Thread.State.WAITING.equals(thread.getState()) ? 
100              "WAITING (on object monitor)" : thread.getState()));
101      for (StackTraceElement stackTraceElement : e.getValue()) {
102        dump.append("\n        at ");
103        dump.append(stackTraceElement);
104      }
105      dump.append("\n");
106    }
107    return dump.toString();
108  }
109
110  static String buildDeadlockInfo() {
111    ThreadMXBean threadBean = ManagementFactory.getThreadMXBean();
112    long[] threadIds = threadBean.findMonitorDeadlockedThreads();
113    if (threadIds != null && threadIds.length > 0) {
114      StringWriter stringWriter = new StringWriter();
115      PrintWriter out = new PrintWriter(stringWriter);
116
117      ThreadInfo[] infos = threadBean.getThreadInfo(threadIds, true, true);
118      for (ThreadInfo ti : infos) {
119        printThreadInfo(ti, out);
120        printLockInfo(ti.getLockedSynchronizers(), out);
121        out.println();
122      }
123
124      out.close();
125      return stringWriter.toString();
126    } else {
127      return null;
128    }
129  }
130
131  private static void printThreadInfo(ThreadInfo ti, PrintWriter out) {
132    // print thread information
133    printThread(ti, out);
134
135    // print stack trace with locks
136    StackTraceElement[] stacktrace = ti.getStackTrace();
137    MonitorInfo[] monitors = ti.getLockedMonitors();
138    for (int i = 0; i < stacktrace.length; i++) {
139      StackTraceElement ste = stacktrace[i];
140      out.println(INDENT + "at " + ste.toString());
141      for (MonitorInfo mi : monitors) {
142        if (mi.getLockedStackDepth() == i) {
143          out.println(INDENT + "  - locked " + mi);
144        }
145      }
146    }
147    out.println();
148  }
149
150  private static void printThread(ThreadInfo ti, PrintWriter out) {
151    out.print("\"" + ti.getThreadName() + "\"" + " Id="
152        + ti.getThreadId() + " in " + ti.getThreadState());
153    if (ti.getLockName() != null) {
154      out.print(" on lock=" + ti.getLockName());
155    }
156    if (ti.isSuspended()) {
157      out.print(" (suspended)");
158    }
159    if (ti.isInNative()) {
160      out.print(" (running in native)");
161    }
162    out.println();
163    if (ti.getLockOwnerName() != null) {
164      out.println(INDENT + " owned by " + ti.getLockOwnerName() + " Id="
165          + ti.getLockOwnerId());
166    }
167  }
168
169  private static void printLockInfo(LockInfo[] locks, PrintWriter out) {
170    out.println(INDENT + "Locked synchronizers: count = " + locks.length);
171    for (LockInfo li : locks) {
172      out.println(INDENT + "  - " + li);
173    }
174    out.println();
175  }
176
177}