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.OutputStreamWriter;
021import java.io.PrintWriter;
022import java.io.StringWriter;
023import java.lang.management.LockInfo;
024import java.lang.management.ManagementFactory;
025import java.lang.management.MonitorInfo;
026import java.lang.management.ThreadInfo;
027import java.lang.management.ThreadMXBean;
028import java.nio.charset.StandardCharsets;
029import java.time.Instant;
030import java.time.ZoneId;
031import java.time.format.DateTimeFormatter;
032import java.util.Locale;
033import java.util.Map;
034import org.junit.runner.notification.Failure;
035import org.junit.runner.notification.RunListener;
036
037/**
038 * JUnit run listener which prints full thread dump into System.err in case a test is failed due to
039 * timeout.
040 */
041public class TimedOutTestsListener extends RunListener {
042
043  private static final String TEST_TIMED_OUT_PREFIX = "test timed out after";
044
045  private static final DateTimeFormatter TIMESTAMP_FORMATTER =
046    DateTimeFormatter.ofPattern("yyyy-MM-dd HH:mm:ss,SSS Z").withZone(ZoneId.systemDefault());
047
048  private static String INDENT = "    ";
049
050  private final PrintWriter output;
051
052  public TimedOutTestsListener() {
053    this.output = new PrintWriter(new OutputStreamWriter(System.err, StandardCharsets.UTF_8));
054  }
055
056  public TimedOutTestsListener(PrintWriter output) {
057    this.output = output;
058  }
059
060  @Override
061  public void testFailure(Failure failure) throws Exception {
062    if (
063      failure != null && failure.getMessage() != null
064        && failure.getMessage().startsWith(TEST_TIMED_OUT_PREFIX)
065    ) {
066      output.println("====> TEST TIMED OUT. PRINTING THREAD DUMP. <====");
067      output.println();
068      output.print(buildThreadDiagnosticString());
069    }
070    output.flush();
071  }
072
073  public static String buildThreadDiagnosticString() {
074    StringWriter sw = new StringWriter();
075    PrintWriter output = new PrintWriter(sw);
076
077    output.println(String.format("Timestamp: %s", TIMESTAMP_FORMATTER.format(Instant.now())));
078    output.println();
079    output.println(buildThreadDump());
080
081    String deadlocksInfo = buildDeadlockInfo();
082    if (deadlocksInfo != null) {
083      output.println("====> DEADLOCKS DETECTED <====");
084      output.println();
085      output.println(deadlocksInfo);
086    }
087
088    return sw.toString();
089  }
090
091  private static String buildThreadDump() {
092    StringBuilder dump = new StringBuilder();
093    Map<Thread, StackTraceElement[]> stackTraces = Thread.getAllStackTraces();
094    for (Map.Entry<Thread, StackTraceElement[]> e : stackTraces.entrySet()) {
095      Thread thread = e.getKey();
096      dump.append(String.format("\"%s\" %s prio=%d tid=%d %s\njava.lang.Thread.State: %s",
097        thread.getName(), (thread.isDaemon() ? "daemon" : ""), thread.getPriority(), thread.getId(),
098        Thread.State.WAITING.equals(thread.getState())
099          ? "in Object.wait()"
100          : thread.getState().name().toLowerCase(Locale.ROOT),
101        Thread.State.WAITING.equals(thread.getState())
102          ? "WAITING (on object monitor)"
103          : thread.getState()));
104      for (StackTraceElement stackTraceElement : e.getValue()) {
105        dump.append("\n        at ");
106        dump.append(stackTraceElement);
107      }
108      dump.append("\n");
109    }
110    return dump.toString();
111  }
112
113  private static String buildDeadlockInfo() {
114    ThreadMXBean threadBean = ManagementFactory.getThreadMXBean();
115    long[] threadIds = threadBean.findMonitorDeadlockedThreads();
116    if (threadIds != null && threadIds.length > 0) {
117      StringWriter stringWriter = new StringWriter();
118      PrintWriter out = new PrintWriter(stringWriter);
119
120      ThreadInfo[] infos = threadBean.getThreadInfo(threadIds, true, true);
121      for (ThreadInfo ti : infos) {
122        printThreadInfo(ti, out);
123        printLockInfo(ti.getLockedSynchronizers(), out);
124        out.println();
125      }
126
127      out.close();
128      return stringWriter.toString();
129    } else {
130      return null;
131    }
132  }
133
134  private static void printThreadInfo(ThreadInfo ti, PrintWriter out) {
135    // print thread information
136    printThread(ti, out);
137
138    // print stack trace with locks
139    StackTraceElement[] stacktrace = ti.getStackTrace();
140    MonitorInfo[] monitors = ti.getLockedMonitors();
141    for (int i = 0; i < stacktrace.length; i++) {
142      StackTraceElement ste = stacktrace[i];
143      out.println(INDENT + "at " + ste.toString());
144      for (MonitorInfo mi : monitors) {
145        if (mi.getLockedStackDepth() == i) {
146          out.println(INDENT + "  - locked " + mi);
147        }
148      }
149    }
150    out.println();
151  }
152
153  private static void printThread(ThreadInfo ti, PrintWriter out) {
154    out.print(
155      "\"" + ti.getThreadName() + "\"" + " Id=" + ti.getThreadId() + " in " + ti.getThreadState());
156    if (ti.getLockName() != null) {
157      out.print(" on lock=" + ti.getLockName());
158    }
159    if (ti.isSuspended()) {
160      out.print(" (suspended)");
161    }
162    if (ti.isInNative()) {
163      out.print(" (running in native)");
164    }
165    out.println();
166    if (ti.getLockOwnerName() != null) {
167      out.println(INDENT + " owned by " + ti.getLockOwnerName() + " Id=" + ti.getLockOwnerId());
168    }
169  }
170
171  private static void printLockInfo(LockInfo[] locks, PrintWriter out) {
172    out.println(INDENT + "Locked synchronizers: count = " + locks.length);
173    for (LockInfo li : locks) {
174      out.println(INDENT + "  - " + li);
175    }
176    out.println();
177  }
178
179}