You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@pulsar.apache.org by mm...@apache.org on 2018/03/26 23:06:40 UTC

[incubator-pulsar] branch master updated: Enforce timeout on all TestNG tests, thread dump on timeout (#1347)

This is an automated email from the ASF dual-hosted git repository.

mmerli pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/incubator-pulsar.git


The following commit(s) were added to refs/heads/master by this push:
     new dafe123  Enforce timeout on all TestNG tests, thread dump on timeout (#1347)
dafe123 is described below

commit dafe123e2909ba138007d1dba3dc43c7852446b5
Author: Matteo Merli <mm...@apache.org>
AuthorDate: Mon Mar 26 16:06:38 2018 -0700

    Enforce timeout on all TestNG tests, thread dump on timeout (#1347)
    
    * Enforce timeout on all TestNG tests, thread dump on timeout
    
    * Increased default timeout to 120 seconds
    
    * Removed usage of log statement that were making the log4j appender test to fail
---
 .../apache/pulsar/tests/AnnotationListener.java    |  12 +-
 .../apache/pulsar/tests/PulsarTestListener.java    |  73 ++++++++++
 .../org/apache/pulsar/tests/ThreadDumpUtil.java    | 148 +++++++++++++++++++++
 managed-ledger/pom.xml                             |  12 --
 pom.xml                                            |   8 +-
 pulsar-broker/pom.xml                              |  12 --
 pulsar-discovery-service/pom.xml                   |  17 ---
 7 files changed, 239 insertions(+), 43 deletions(-)

diff --git a/buildtools/src/main/java/org/apache/pulsar/tests/AnnotationListener.java b/buildtools/src/main/java/org/apache/pulsar/tests/AnnotationListener.java
index 0682105..be03247 100644
--- a/buildtools/src/main/java/org/apache/pulsar/tests/AnnotationListener.java
+++ b/buildtools/src/main/java/org/apache/pulsar/tests/AnnotationListener.java
@@ -27,9 +27,19 @@ import org.testng.annotations.ITestAnnotation;
 @SuppressWarnings("rawtypes")
 public class AnnotationListener implements IAnnotationTransformer {
 
+    private static final int DEFAULT_TEST_TIMEOUT_MILLIS = 120000;
+
+    public AnnotationListener() {
+        System.out.println("Created annotation listener");
+    }
+
     @Override
     public void transform(ITestAnnotation annotation, Class testClass, Constructor testConstructor, Method testMethod) {
         annotation.setRetryAnalyzer(RetryAnalyzer.class);
-    }
 
+        // Enforce default test timeout
+        if (annotation.getTimeOut() == 0) {
+            annotation.setTimeOut(DEFAULT_TEST_TIMEOUT_MILLIS);
+        }
+    }
 }
diff --git a/buildtools/src/main/java/org/apache/pulsar/tests/PulsarTestListener.java b/buildtools/src/main/java/org/apache/pulsar/tests/PulsarTestListener.java
new file mode 100644
index 0000000..1b21a68
--- /dev/null
+++ b/buildtools/src/main/java/org/apache/pulsar/tests/PulsarTestListener.java
@@ -0,0 +1,73 @@
+/**
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements.  See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership.  The ASF licenses this file
+ * to you under the Apache License, Version 2.0 (the
+ * "License"); you may not use this file except in compliance
+ * with the License.  You may obtain a copy of the License at
+ *
+ *   http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing,
+ * software distributed under the License is distributed on an
+ * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+ * KIND, either express or implied.  See the License for the
+ * specific language governing permissions and limitations
+ * under the License.
+ */
+package org.apache.pulsar.tests;
+
+import java.util.Arrays;
+
+import org.testng.ITestContext;
+import org.testng.ITestListener;
+import org.testng.ITestResult;
+import org.testng.internal.thread.ThreadTimeoutException;
+
+public class PulsarTestListener implements ITestListener {
+
+    @Override
+    public void onTestStart(ITestResult result) {
+        System.out.format("------- Starting test %s.%s(%s)-------\n", result.getTestClass(), result.getTestName(),
+                Arrays.toString(result.getParameters()));
+    }
+
+    @Override
+    public void onTestSuccess(ITestResult result) {
+        System.out.format("------- SUCCESS -- %s.%s(%s)-------", result.getTestClass(), result.getTestName(),
+                Arrays.toString(result.getParameters()));
+    }
+
+    @Override
+    public void onTestFailure(ITestResult result) {
+        System.out.format("!!!!!!!!! FAILURE-- %s.%s(%s)-------\n", result.getTestClass(), result.getTestName(),
+                Arrays.toString(result.getParameters()));
+
+        if (result.getThrowable() instanceof ThreadTimeoutException) {
+            System.out.println("====== THREAD DUMPS ======");
+            System.out.println(ThreadDumpUtil.buildThreadDiagnosticString());
+        }
+    }
+
+    @Override
+    public void onTestSkipped(ITestResult result) {
+        System.out.format("~~~~~~~~~ SKIPPED -- %s.%s(%s)-------", result.getTestClass(), result.getTestName(),
+                Arrays.toString(result.getParameters()));
+    }
+
+    @Override
+    public void onTestFailedButWithinSuccessPercentage(ITestResult result) {
+
+    }
+
+    @Override
+    public void onStart(ITestContext context) {
+
+    }
+
+    @Override
+    public void onFinish(ITestContext context) {
+
+    }
+}
diff --git a/buildtools/src/main/java/org/apache/pulsar/tests/ThreadDumpUtil.java b/buildtools/src/main/java/org/apache/pulsar/tests/ThreadDumpUtil.java
new file mode 100644
index 0000000..e5156d0
--- /dev/null
+++ b/buildtools/src/main/java/org/apache/pulsar/tests/ThreadDumpUtil.java
@@ -0,0 +1,148 @@
+/**
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements.  See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership.  The ASF licenses this file
+ * to you under the Apache License, Version 2.0 (the
+ * "License"); you may not use this file except in compliance
+ * with the License.  You may obtain a copy of the License at
+ *
+ *   http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing,
+ * software distributed under the License is distributed on an
+ * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+ * KIND, either express or implied.  See the License for the
+ * specific language governing permissions and limitations
+ * under the License.
+ */
+package org.apache.pulsar.tests;
+
+import java.io.PrintWriter;
+import java.io.StringWriter;
+import java.lang.management.LockInfo;
+import java.lang.management.ManagementFactory;
+import java.lang.management.MonitorInfo;
+import java.lang.management.ThreadInfo;
+import java.lang.management.ThreadMXBean;
+import java.text.DateFormat;
+import java.text.SimpleDateFormat;
+import java.util.Date;
+import java.util.Map;
+
+/**
+ * Adapted from Hadoop TimedOutTestsListener
+ *
+ * https://raw.githubusercontent.com/apache/hadoop/master/hadoop-common-project/hadoop-common/src/test/java/org/apache/hadoop/test/TimedOutTestsListener.java
+ */
+public class ThreadDumpUtil {
+    static final String TEST_TIMED_OUT_PREFIX = "test timed out after";
+
+    private static String INDENT = "    ";
+
+    public static String buildThreadDiagnosticString() {
+        StringWriter sw = new StringWriter();
+        PrintWriter output = new PrintWriter(sw);
+
+        DateFormat dateFormat = new SimpleDateFormat("yyyy-MM-dd hh:mm:ss,SSS");
+        output.println(String.format("Timestamp: %s", dateFormat.format(new Date())));
+        output.println();
+        output.println(buildThreadDump());
+
+        String deadlocksInfo = buildDeadlockInfo();
+        if (deadlocksInfo != null) {
+            output.println("====> DEADLOCKS DETECTED <====");
+            output.println();
+            output.println(deadlocksInfo);
+        }
+
+        return sw.toString();
+    }
+
+    static String buildThreadDump() {
+        StringBuilder dump = new StringBuilder();
+        Map<Thread, StackTraceElement[]> stackTraces = Thread.getAllStackTraces();
+        for (Map.Entry<Thread, StackTraceElement[]> e : stackTraces.entrySet()) {
+            Thread thread = e.getKey();
+            dump.append('\n');
+            dump.append(String.format("\"%s\" %s prio=%d tid=%d %s\njava.lang.Thread.State: %s", thread.getName(),
+                    (thread.isDaemon() ? "daemon" : ""), thread.getPriority(), thread.getId(),
+                    Thread.State.WAITING.equals(thread.getState()) ? "in Object.wait()" : thread.getState().name(),
+                    Thread.State.WAITING.equals(thread.getState()) ? "WAITING (on object monitor)"
+                            : thread.getState()));
+            for (StackTraceElement stackTraceElement : e.getValue()) {
+                dump.append("\n        at ");
+                dump.append(stackTraceElement);
+            }
+            dump.append("\n");
+        }
+        return dump.toString();
+    }
+
+    static String buildDeadlockInfo() {
+        ThreadMXBean threadBean = ManagementFactory.getThreadMXBean();
+        long[] threadIds = threadBean.findMonitorDeadlockedThreads();
+        if (threadIds != null && threadIds.length > 0) {
+            StringWriter stringWriter = new StringWriter();
+            PrintWriter out = new PrintWriter(stringWriter);
+
+            ThreadInfo[] infos = threadBean.getThreadInfo(threadIds, true, true);
+            for (ThreadInfo ti : infos) {
+                printThreadInfo(ti, out);
+                printLockInfo(ti.getLockedSynchronizers(), out);
+                out.println();
+            }
+
+            out.close();
+            return stringWriter.toString();
+        } else {
+            return null;
+        }
+    }
+
+    private static void printThreadInfo(ThreadInfo ti, PrintWriter out) {
+        // print thread information
+        printThread(ti, out);
+
+        // print stack trace with locks
+        StackTraceElement[] stacktrace = ti.getStackTrace();
+        MonitorInfo[] monitors = ti.getLockedMonitors();
+        for (int i = 0; i < stacktrace.length; i++) {
+            StackTraceElement ste = stacktrace[i];
+            out.println(INDENT + "at " + ste.toString());
+            for (MonitorInfo mi : monitors) {
+                if (mi.getLockedStackDepth() == i) {
+                    out.println(INDENT + "  - locked " + mi);
+                }
+            }
+        }
+        out.println();
+    }
+
+    private static void printThread(ThreadInfo ti, PrintWriter out) {
+        out.println();
+        out.print("\"" + ti.getThreadName() + "\"" + " Id=" + ti.getThreadId() + " in " + ti.getThreadState());
+        if (ti.getLockName() != null) {
+            out.print(" on lock=" + ti.getLockName());
+        }
+        if (ti.isSuspended()) {
+            out.print(" (suspended)");
+        }
+        if (ti.isInNative()) {
+            out.print(" (running in native)");
+        }
+        out.println();
+        if (ti.getLockOwnerName() != null) {
+            out.println(INDENT + " owned by " + ti.getLockOwnerName() + " Id=" + ti.getLockOwnerId());
+        }
+    }
+
+    private static void printLockInfo(LockInfo[] locks, PrintWriter out) {
+        out.println(INDENT + "Locked synchronizers: count = " + locks.length);
+        for (LockInfo li : locks) {
+            out.println(INDENT + "  - " + li);
+        }
+        out.println();
+    }
+
+}
diff --git a/managed-ledger/pom.xml b/managed-ledger/pom.xml
index b4f0017..3ee7703 100644
--- a/managed-ledger/pom.xml
+++ b/managed-ledger/pom.xml
@@ -96,18 +96,6 @@
     <plugins>
       <plugin>
         <groupId>org.apache.maven.plugins</groupId>
-        <artifactId>maven-surefire-plugin</artifactId>
-        <configuration>
-          <properties>
-            <property>
-              <name>listener</name>
-              <value>org.apache.pulsar.tests.AnnotationListener</value>
-            </property>
-          </properties>
-        </configuration>
-      </plugin>
-      <plugin>
-        <groupId>org.apache.maven.plugins</groupId>
         <artifactId>maven-jar-plugin</artifactId>
         <executions>
           <execution>
diff --git a/pom.xml b/pom.xml
index 6ed567a..ef28966 100644
--- a/pom.xml
+++ b/pom.xml
@@ -809,6 +809,12 @@ flexible messaging model and an intuitive client API.</description>
           <forkCount>1</forkCount>
           <redirectTestOutputToFile>${redirectTestOutputToFile}</redirectTestOutputToFile>
           <trimStackTrace>false</trimStackTrace>
+          <properties>
+            <property>
+              <name>listener</name>
+              <value>org.apache.pulsar.tests.PulsarTestListener,org.apache.pulsar.tests.AnnotationListener</value>
+            </property>
+          </properties>
         </configuration>
       </plugin>
 
@@ -962,7 +968,7 @@ flexible messaging model and an intuitive client API.</description>
         <plugin>
           <groupId>org.apache.maven.plugins</groupId>
           <artifactId>maven-surefire-plugin</artifactId>
-          <version>2.20</version>
+          <version>2.21.0</version>
         </plugin>
         <plugin>
           <groupId>org.apache.maven.plugins</groupId>
diff --git a/pulsar-broker/pom.xml b/pulsar-broker/pom.xml
index 8681cad..2e1f220 100644
--- a/pulsar-broker/pom.xml
+++ b/pulsar-broker/pom.xml
@@ -269,18 +269,6 @@
   <build>
     <plugins>
       <plugin>
-        <groupId>org.apache.maven.plugins</groupId>
-        <artifactId>maven-surefire-plugin</artifactId>
-        <configuration>
-          <properties>
-            <property>
-              <name>listener</name>
-              <value>org.apache.pulsar.tests.AnnotationListener</value>
-            </property>
-          </properties>
-        </configuration>
-      </plugin>
-      <plugin>
         <groupId>org.codehaus.mojo</groupId>
         <artifactId>aspectj-maven-plugin</artifactId>
         <version>1.10</version>
diff --git a/pulsar-discovery-service/pom.xml b/pulsar-discovery-service/pom.xml
index 25dd53f..2c2c123 100644
--- a/pulsar-discovery-service/pom.xml
+++ b/pulsar-discovery-service/pom.xml
@@ -142,21 +142,4 @@
       <scope>test</scope>
     </dependency>
   </dependencies>
-
-  <build>
-    <plugins>
-      <plugin>
-        <groupId>org.apache.maven.plugins</groupId>
-        <artifactId>maven-surefire-plugin</artifactId>
-        <configuration>
-          <properties>
-            <property>
-              <name>listener</name>
-              <value>org.apache.pulsar.tests.AnnotationListener</value>
-            </property>
-          </properties>
-        </configuration>
-      </plugin>
-    </plugins>
-  </build>
 </project>

-- 
To stop receiving notification emails like this one, please contact
mmerli@apache.org.