Skip to content

Commit

Permalink
[improve][ci] Detect test thread leaks in CI builds and add tooling f…
Browse files Browse the repository at this point in the history
…or resource leak investigation
  • Loading branch information
lhotari committed Oct 18, 2023
1 parent b1bca56 commit 3162692
Show file tree
Hide file tree
Showing 8 changed files with 353 additions and 16 deletions.
39 changes: 37 additions & 2 deletions .github/workflows/pulsar-ci.yaml
Original file line number Diff line number Diff line change
Expand Up @@ -29,7 +29,22 @@ on:
collect_coverage:
description: 'Collect test coverage and upload to Codecov'
required: true
default: 'true'
type: boolean
default: true
trace_test_resource_cleanup:
description: 'Collect thread & heap information before exiting a test JVM. When set to "on", thread dump and heap histogram will be collected. When set to "full", a heap dump will also be collected.'
required: true
type: choice
options:
- 'off'
- 'on'
- 'full'
default: 'off'
thread_leak_detector_wait_millis:
description: 'Duration in ms to wait for threads to exit in thread leak detection between test classes. It is necessary to wait for threads to complete before they are determined to be leaked threads.'
required: true
type: number
default: 10000

concurrency:
group: ${{ github.workflow }}-${{ github.ref }}
Expand Down Expand Up @@ -172,6 +187,10 @@ jobs:
JOB_NAME: CI - Unit - ${{ matrix.name }}
COLLECT_COVERAGE: "${{ needs.preconditions.outputs.collect_coverage }}"
GRADLE_ENTERPRISE_ACCESS_KEY: ${{ secrets.GE_ACCESS_TOKEN }}
TRACE_TEST_RESOURCE_CLEANUP: ${{ github.event_name == 'workflow_dispatch' && github.event.inputs.trace_test_resource_cleanup || 'off' }}
TRACE_TEST_RESOURCE_CLEANUP_DIR: ${{ github.workspace }}/target/trace-test-resource-cleanup
THREAD_LEAK_DETECTOR_WAIT_MILLIS: ${{ github.event_name == 'workflow_dispatch' && github.event.inputs.thread_leak_detector_wait_millis || 10000 }}
THREAD_LEAK_DETECTOR_DIR: ${{ github.workspace }}/target/thread-leak-dumps
runs-on: ubuntu-22.04
timeout-minutes: ${{ matrix.timeout || 60 }}
needs: ['preconditions', 'build-and-license-check']
Expand Down Expand Up @@ -212,6 +231,10 @@ jobs:
- name: Tune Runner VM
uses: ./.github/actions/tune-runner-vm

- name: Clean Disk when tracing test resource cleanup
if: ${{ env.TRACE_TEST_RESOURCE_CLEANUP != 'off' }}
uses: ./.github/actions/clean-disk

- name: Setup ssh access to build runner VM
# ssh access is enabled for builds in own forks
if: ${{ github.repository != 'apache/pulsar' && github.event_name == 'pull_request' }}
Expand Down Expand Up @@ -273,9 +296,19 @@ jobs:
report_paths: 'test-reports/TEST-*.xml'
annotate_only: 'true'

- name: Report detected thread leaks
if: ${{ always() }}
run: |
if [ -d "$THREAD_LEAK_DETECTOR_DIR" ]; then
cd "$THREAD_LEAK_DETECTOR_DIR"
for file in threadleak*.txt; do
cat "$file" | awk '{ if($0 != "") { print "::warning::"$0 }}'
done
fi
- name: Upload Surefire reports
uses: actions/upload-artifact@v3
if: ${{ !success() }}
if: ${{ !success() || env.TRACE_TEST_RESOURCE_CLEANUP != 'off' }}
with:
name: Unit-${{ matrix.group }}-surefire-reports
path: surefire-reports
Expand All @@ -290,6 +323,8 @@ jobs:
/tmp/*.hprof
**/hs_err_*.log
**/core.*
${{ env.TRACE_TEST_RESOURCE_CLEANUP_DIR }}/*
${{ env.THREAD_LEAK_DETECTOR_DIR }}/*
retention-days: 7
if-no-files-found: ignore

Expand Down
53 changes: 53 additions & 0 deletions buildtools/src/main/java/org/apache/pulsar/tests/HeapDumpUtil.java
Original file line number Diff line number Diff line change
@@ -0,0 +1,53 @@
/*
* 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 com.sun.management.HotSpotDiagnosticMXBean;
import java.io.File;
import java.lang.management.ManagementFactory;
import javax.management.MBeanServer;

public class HeapDumpUtil {
private static final String HOTSPOT_BEAN_NAME = "com.sun.management:type=HotSpotDiagnostic";

// Utility method to get the HotSpotDiagnosticMXBean
private static HotSpotDiagnosticMXBean getHotSpotDiagnosticMXBean() {
try {
MBeanServer server = ManagementFactory.getPlatformMBeanServer();
return ManagementFactory.newPlatformMXBeanProxy(server, HOTSPOT_BEAN_NAME, HotSpotDiagnosticMXBean.class);
} catch (Exception e) {
throw new RuntimeException(e);
}
}

/**
* Dump the heap of the JVM.
*
* @param file the system-dependent filename
* @param liveObjects if true dump only live objects i.e. objects that are reachable from others
*/
public static void dumpHeap(File file, boolean liveObjects) {
try {
HotSpotDiagnosticMXBean hotspotMBean = getHotSpotDiagnosticMXBean();
hotspotMBean.dumpHeap(file.getAbsolutePath(), liveObjects);
} catch (Exception e) {
throw new RuntimeException("Error generating heap dump", e);
}
}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,62 @@
/*
* 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.lang.management.ManagementFactory;
import java.time.ZonedDateTime;
import java.time.format.DateTimeFormatter;
import javax.management.JMException;
import javax.management.ObjectName;

public class HeapHistogramUtil {
public static String buildHeapHistogram() {
StringBuilder dump = new StringBuilder();
dump.append(String.format("Timestamp: %s", DateTimeFormatter.ISO_OFFSET_DATE_TIME.format(ZonedDateTime.now())));
dump.append("\n\n");
try {
dump.append(callDiagnosticCommand("gcHeapInfo"));
} catch (Exception e) {
e.printStackTrace();
return null;
}
dump.append("\n");
try {
dump.append(callDiagnosticCommand("gcClassHistogram"));
} catch (Exception e) {
e.printStackTrace();
return null;
}
return dump.toString();
}

/**
* Calls a diagnostic commands.
* The available operations are similar to what the jcmd commandline tool has,
* however the naming of the operations are different. The "help" operation can be used
* to find out the available operations. For example, the jcmd command "Thread.print" maps
* to "threadPrint" operation name.
*/
static String callDiagnosticCommand(String operationName, String... args)
throws JMException {
return (String) ManagementFactory.getPlatformMBeanServer()
.invoke(new ObjectName("com.sun.management:type=DiagnosticCommand"),
operationName, new Object[] {args}, new String[] {String[].class.getName()});
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -25,7 +25,7 @@
import java.lang.management.MonitorInfo;
import java.lang.management.ThreadInfo;
import java.lang.management.ThreadMXBean;
import java.time.LocalDateTime;
import java.time.ZonedDateTime;
import java.time.format.DateTimeFormatter;
import java.util.Map;
import javax.management.JMException;
Expand Down Expand Up @@ -65,7 +65,7 @@ static String buildThreadDump() {
// fallback to using JMX for creating the thread dump
StringBuilder dump = new StringBuilder();

dump.append(String.format("Timestamp: %s", DateTimeFormatter.ISO_OFFSET_DATE_TIME.format(LocalDateTime.now())));
dump.append(String.format("Timestamp: %s", DateTimeFormatter.ISO_OFFSET_DATE_TIME.format(ZonedDateTime.now())));
dump.append("\n\n");

Map<Thread, StackTraceElement[]> stackTraces = Thread.getAllStackTraces();
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -16,49 +16,140 @@
* specific language governing permissions and limitations
* under the License.
*/

package org.apache.pulsar.tests;

import com.google.common.base.Charsets;
import com.google.common.io.Files;
import java.io.File;
import java.io.IOException;
import java.io.PrintWriter;
import java.time.ZonedDateTime;
import java.time.format.DateTimeFormatter;
import java.util.Collections;
import java.util.LinkedHashSet;
import java.util.Objects;
import java.util.Set;
import java.util.stream.Collectors;
import org.apache.commons.lang3.ThreadUtils;
import org.apache.commons.lang3.mutable.MutableBoolean;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

/**
* Detects new threads that have been created during the test execution.
* Detects new threads that have been created during the test execution. This is useful to detect thread leaks.
* Will create files to the configured directory if new threads are detected and THREAD_LEAK_DETECTOR_WAIT_MILLIS
* is set to a positive value. A recommended value is 10000 for THREAD_LEAK_DETECTOR_WAIT_MILLIS. This will ensure
* that any asynchronous operations should have completed before the detector determines that it has found a leak.
*/
public class ThreadLeakDetectorListener extends BetweenTestClassesListenerAdapter {
private static final Logger LOG = LoggerFactory.getLogger(ThreadLeakDetectorListener.class);
private static final long WAIT_FOR_THREAD_TERMINATION_MILLIS =
Long.parseLong(System.getenv().getOrDefault("THREAD_LEAK_DETECTOR_WAIT_MILLIS", "0"));
private static final File DUMP_DIR =
new File(System.getenv().getOrDefault("THREAD_LEAK_DETECTOR_DIR", "target/thread-leak-dumps"));
private static final long THREAD_TERMINATION_POLL_INTERVAL =
Long.parseLong(System.getenv().getOrDefault("THREAD_LEAK_DETECTOR_POLL_INTERVAL", "250"));
private static final boolean COLLECT_THREADDUMP =
Boolean.parseBoolean(System.getenv().getOrDefault("THREAD_LEAK_DETECTOR_COLLECT_THREADDUMP", "true"));

private Set<ThreadKey> capturedThreadKeys;


@Override
protected void onBetweenTestClasses(Class<?> endedTestClass, Class<?> startedTestClass) {
LOG.info("Capturing identifiers of running threads.");
capturedThreadKeys = compareThreads(capturedThreadKeys, endedTestClass);
MutableBoolean differenceDetected = new MutableBoolean();
Set<ThreadKey> currentThreadKeys =
compareThreads(capturedThreadKeys, endedTestClass, WAIT_FOR_THREAD_TERMINATION_MILLIS <= 0,
differenceDetected, null);
if (WAIT_FOR_THREAD_TERMINATION_MILLIS > 0 && endedTestClass != null && differenceDetected.booleanValue()) {
LOG.info("Difference detected in active threads. Waiting up to {} ms for threads to terminate.",
WAIT_FOR_THREAD_TERMINATION_MILLIS);
long endTime = System.currentTimeMillis() + WAIT_FOR_THREAD_TERMINATION_MILLIS;
while (System.currentTimeMillis() < endTime) {
try {
Thread.sleep(THREAD_TERMINATION_POLL_INTERVAL);
} catch (InterruptedException e) {
Thread.currentThread().interrupt();
}
differenceDetected.setFalse();
currentThreadKeys = compareThreads(capturedThreadKeys, endedTestClass, false, differenceDetected, null);
if (!differenceDetected.booleanValue()) {
break;
}
}
if (differenceDetected.booleanValue()) {
String datetimePart =
DateTimeFormatter.ofPattern("yyyyMMdd-HHmmss.SSS").format(ZonedDateTime.now());
PrintWriter out = null;
try {
if (!DUMP_DIR.exists()) {
DUMP_DIR.mkdirs();
}
File threadleakdumpFile =
new File(DUMP_DIR, "threadleak" + datetimePart + endedTestClass.getName() + ".txt");
out = new PrintWriter(threadleakdumpFile);
} catch (IOException e) {
LOG.error("Cannot write thread leak dump", e);
}
currentThreadKeys = compareThreads(capturedThreadKeys, endedTestClass, true, null, out);
if (out != null) {
out.close();
}
if (COLLECT_THREADDUMP) {
File threaddumpFile =
new File(DUMP_DIR, "threaddump" + datetimePart + endedTestClass.getName() + ".txt");
try {
Files.asCharSink(threaddumpFile, Charsets.UTF_8)
.write(ThreadDumpUtil.buildThreadDiagnosticString());
} catch (IOException e) {
LOG.error("Cannot write thread dump", e);
}
}
}
}
capturedThreadKeys = currentThreadKeys;
}

private static Set<ThreadKey> compareThreads(Set<ThreadKey> previousThreadKeys, Class<?> endedTestClass) {
private static Set<ThreadKey> compareThreads(Set<ThreadKey> previousThreadKeys, Class<?> endedTestClass,
boolean logDifference, MutableBoolean differenceDetected,
PrintWriter out) {
Set<ThreadKey> threadKeys = Collections.unmodifiableSet(ThreadUtils.getAllThreads().stream()
.map(ThreadKey::of)
.collect(Collectors.<ThreadKey, Set<ThreadKey>>toCollection(LinkedHashSet::new)));

if (endedTestClass != null && previousThreadKeys != null) {
int newThreadsCounter = 0;
LOG.info("Checking for new threads created by {}.", endedTestClass.getName());
for (ThreadKey threadKey : threadKeys) {
if (!previousThreadKeys.contains(threadKey)) {
newThreadsCounter++;
LOG.warn("Tests in class {} created thread id {} with name '{}'", endedTestClass.getSimpleName(),
threadKey.getThreadId(), threadKey.getThreadName());
if (differenceDetected != null) {
differenceDetected.setTrue();
}
if (logDifference || out != null) {
String message = String.format("Tests in class %s created thread id %d with name '%s'",
endedTestClass.getSimpleName(),
threadKey.getThreadId(), threadKey.getThreadName());
if (logDifference) {
LOG.warn(message);
}
if (out != null) {
out.println(message);
}
}
}
}
if (newThreadsCounter > 0) {
LOG.warn("Summary: Tests in class {} created {} new threads", endedTestClass.getName(),
newThreadsCounter);
if (newThreadsCounter > 0 && (logDifference || out != null)) {
String message = String.format(
"Summary: Tests in class %s created %d new threads. There are now %d threads in total.",
endedTestClass.getName(), newThreadsCounter, threadKeys.size());
if (logDifference) {
LOG.warn(message);
}
if (out != null) {
out.println(message);
}
}
}

Expand Down
Loading

0 comments on commit 3162692

Please sign in to comment.