Skip to content

Commit

Permalink
Implement strand dump tool for virtual threads
Browse files Browse the repository at this point in the history
  • Loading branch information
ravinperera00 committed Sep 9, 2024
1 parent 1fe53c1 commit 1f4f7fe
Show file tree
Hide file tree
Showing 5 changed files with 298 additions and 197 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -18,59 +18,114 @@

package io.ballerina.runtime.internal.troubleshoot;

import io.ballerina.runtime.internal.scheduling.Strand;
import com.sun.management.HotSpotDiagnosticMXBean;

import javax.management.MBeanServer;
import java.io.File;
import java.io.IOException;
import java.lang.management.ManagementFactory;
import java.nio.file.Files;
import java.nio.file.Paths;
import java.time.LocalDateTime;
import java.time.format.DateTimeFormatter;
import java.util.HashMap;
import java.util.List;
import java.util.Map;
import java.util.ArrayList;
import java.util.HashSet;
import java.util.Set;

/**
* Used to get the status of current Ballerina strands.
*
* @since 2201.2.0
*/
public class StrandDump {
private static final String hotSpotBeanName = "com.sun.management:type=HotSpotDiagnostic";
private static volatile HotSpotDiagnosticMXBean hotSpotDiagnosticMXBean;

public static String getStrandDump() {
Map<Integer, Strand> availableStrands = new HashMap<>();
int createdStrandGroupCount = 0;
int createdStrandCount = 0;
int availableStrandCount = 0;
Map<Integer, List<String>> availableStrandGroups = new HashMap<>();

String strandDumpOutput = generateOutput(availableStrandGroups, availableStrandCount, createdStrandGroupCount,
createdStrandCount);
cleanUp(availableStrands, availableStrandGroups);
return strandDumpOutput;
String filename = "thread_dump" + LocalDateTime.now();
String dump;
try {
getStrandDump(System.getProperty("user.dir") + "/" + filename);
dump = new String(Files.readAllBytes(Paths.get(filename)));
File fileObj = new File(filename);
fileObj.delete();
} catch (Exception e) {
return "Error occurred during strand dump generation";
}
return generateOutput(dump);
}

private static String generateOutput(Map<Integer, List<String>> availableStrandGroups, int availableStrandCount,
int createdStrandGroupCount, int createdStrandCount) {
private static String generateOutput(String dump) {
String[] dump_items = dump.split("\\n\\n");
int id = 0;
Set<Integer> isolatedWorkerList = new HashSet<>();
Set<Integer> nonIsolatedWorkerList = new HashSet<>();
ArrayList<ArrayList<String>> balTraces = new ArrayList<>();
for(String item : dump_items) {
String[] lines = item.split("\\n");
String[] subitems = lines[0].split("\" ");
ArrayList<String> balTraceItems = new ArrayList<>();
boolean bal_strand = false;
if(subitems.length > 1 && subitems[1].equals("virtual")) {
balTraceItems.add("\tStrand " + lines[0].replace("virtual", ":") + "\n\t\tat");
String prefix = " ";
for(String line : lines) {
if(line.contains("Scheduler.lambda$startIsolatedWorker")) {
isolatedWorkerList.add(id);
}
if(line.contains("Scheduler.lambda$startNonIsolatedWorker")) {
nonIsolatedWorkerList.add(id);
}
if(!line.contains("java") && !line.contains("\" virtual")){
balTraceItems.add(prefix + line + "\n");
prefix = "\t\t ";
}
if(line.contains(".bal")) {
bal_strand = true;
}
}
if(bal_strand) {
balTraces.add(balTraceItems);
}else {
isolatedWorkerList.remove(id);
nonIsolatedWorkerList.remove(id);
}
id++;
}
}
StringBuilder outputStr = new StringBuilder("Ballerina Strand Dump [");
DateTimeFormatter dateTimeFormatter = DateTimeFormatter.ofPattern("yyyy/MM/dd HH:mm:ss");
LocalDateTime localDateTime = LocalDateTime.now();
outputStr.append(dateTimeFormatter.format(localDateTime));
outputStr.append("]\n===========================================\n\n");
outputStr.append("Total strand group count \t:\t").append(createdStrandGroupCount).append("\n");
outputStr.append("Total strand count \t:\t").append(createdStrandCount).append("\n");
outputStr.append("Active strand group count\t:\t").append(availableStrandGroups.size()).append("\n");
outputStr.append("Active strand count \t:\t").append(availableStrandCount).append("\n\n");
availableStrandGroups.forEach((strandGroupId, strandList) -> {
outputStr.append("group ").append(strandGroupId).append(" [").append(strandList.get(0)).append("]: [")
.append(strandList.size() - 1).append("]\n");
strandList.subList(1, strandList.size()).forEach(outputStr::append);
});
outputStr.append("===========================================\n");
outputStr.append("]\n===============================================================\n\n");
outputStr.append("Total Strand count \t\t\t:\t").append(balTraces.size()).append("\n\n");
outputStr.append("Total Isolated Worker count \t\t:\t").append(isolatedWorkerList.size()).append("\n\n");
outputStr.append("Total Non Isolated Worker count \t\t:\t").append(nonIsolatedWorkerList.size()).append("\n\n");
outputStr.append("================================================================\n");
outputStr.append("\nIsolated Workers:\n\n");
for(int strandId: isolatedWorkerList){
balTraces.get(strandId).forEach(outputStr::append);
outputStr.append("\n");
}
outputStr.append("Non Isolated Workers:\n\n");
for(int strandId: nonIsolatedWorkerList){
balTraces.get(strandId).forEach(outputStr::append);
outputStr.append("\n");
}
return outputStr.toString();
}

private static void cleanUp(Map<Integer, Strand> availableStrands,
Map<Integer, List<String>> availableStrandGroups) {
availableStrands.clear();
availableStrandGroups.clear();
private static void getStrandDump(String fileName) throws IOException {
if (hotSpotDiagnosticMXBean == null) {
synchronized (StrandDump.class) {
hotSpotDiagnosticMXBean = getHotSpotDiagnosticMXBean();
}
}
hotSpotDiagnosticMXBean.dumpThreads(fileName, HotSpotDiagnosticMXBean.ThreadDumpFormat.TEXT_PLAIN);
}

private StrandDump() {}
private static HotSpotDiagnosticMXBean getHotSpotDiagnosticMXBean() throws IOException {
MBeanServer mBeanServer = ManagementFactory.getPlatformMBeanServer();
return ManagementFactory.newPlatformMXBeanProxy(mBeanServer, hotSpotBeanName, HotSpotDiagnosticMXBean.class);
}
}
1 change: 1 addition & 0 deletions bvm/ballerina-runtime/src/main/java/module-info.java
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,7 @@
requires java.naming;
requires io.ballerina.identifier;
requires jdk.unsupported;
requires jdk.management;

// API exports
exports io.ballerina.runtime.api;
Expand Down
Original file line number Diff line number Diff line change
@@ -1,43 +1,56 @@
Ballerina Strand Dump \[\d*/\d*/\d* \d*:\d*:\d*\]
===========================================
===============================================================

Total strand group count \t:\t5
Total strand count \t:\t9
Active strand group count\t:\t3
Active strand count \t:\t9
Total Strand count \t\t\t:\t9

group \d* \[QUEUED\]: \[7\]
\tstrand \d* "main" \[\$anon...0:main\] \[BLOCKED\]:
\t\tat\tballerina.lang.runtime.\d*.\d*.\d*:sleep\(runtime.bal:\d*\)
\t\t \t\$anon...0.0.0:bar\(balProgram1.bal:86\)
\t\t \t\$anon...0.0.0:foo\(balProgram1.bal:27\)
\t\t \t\$anon...0.0.0:main\(balProgram1.bal:23\)
Total Isolated Worker count \t\t:\t2

\tstrand \d* "w3" \[\$anon...0:bar\]\[\d*\] \[BLOCKED ON WORKER MESSAGE SEND\]:
\t\tat\t\$anon...0.0.0:\$lambda\$_2\(balProgram1.bal:53\)
Total Non Isolated Worker count \t\t:\t7

\tstrand \d* "w4" \[\$anon...0:bar\]\[\d*\] \[BLOCKED\]:
\t\tat\tballerina.lang.runtime.\d*.\d*.\d*:sleep\(runtime.bal:\d*\)
\t\t \t\$anon...0.0.0:\$lambda\$_3\(balProgram1.bal:58\)
================================================================

\tstrand \d* "w5" \[\$anon...0:bar\]\[\d*\] \[BLOCKED ON WORKER MESSAGE FLUSH\]:
\t\tat\t\$anon...0.0.0:\$lambda\$_4\(balProgram1.bal:65\)
Isolated Workers:

\tstrand \d* "w6" \[\$anon...0:bar\]\[\d*\] \[BLOCKED\]:
\t\tat\tballerina.lang.runtime.\d*.\d*.\d*:sleep\(runtime.bal:\d*\)
\t\t \t\$anon...0.0.0:\$lambda\$_5\(balProgram1.bal:70\)
\tStrand #\d* \"\d*\" :
\t\tat balProgram1.\$lambda\$_0\(balProgram1.bal:\d*\)
\t\t lambdas.\$_generated1balProgram1.\$lambda\$_0\$lambda0\$\(balProgram1.bal:\d*\)

\tstrand \d* \[\$anon...0:bar\]\[\d*\] \[BLOCKED ON WORKER MESSAGE RECEIVE\]:
\t\tat\t\$anon...0.0.0:\$lambda\$_6\(balProgram1.bal:76\)
\tStrand #\d* \"\d*\" :
\t\tat balProgram1.\$lambda\$_1\(balProgram1.bal:\d*\)
\t\t lambdas.\$_generated1balProgram1.\$lambda\$_1\$lambda1\$\(balProgram1.bal:\d*\)

\tstrand \d* "w8" \[\$anon...0:bar\]\[\d*\] \[WAITING\]:
\t\tat\t\$anon...0.0.0:\$lambda\$_7\(balProgram1.bal:82\)
Non Isolated Workers:

group \d* \[RUNNABLE\]: \[1\]
\tstrand \d* "w1" \[\$anon...0:bar\]\[\d*\] \[RUNNABLE\]
\tStrand #\d* \"\d*\" :
\t\tat balProgram1.\$lambda\$_2\(balProgram1.bal:\d*\)
\t\t lambdas.\$_generated1balProgram1.\$lambda\$_2\$lambda2\$\(balProgram1.bal:\d*\)

group \d* \[QUEUED\]: \[1\]
\tstrand \d* "w2" \[\$anon...0:bar\]\[\d*\] \[WAITING FOR LOCK\]:
\t\tat\t\$anon...0.0.0:\$lambda\$_1\(balProgram1.bal:46\)
\tStrand #\d* \"\d*\" :
\t\tat ballerina.lang&0046runtime.0.runtime.sleep\(runtime.bal:\d*\)
\t\t balProgram1.\$lambda\$_3\(balProgram1.bal:\d*\)
\t\t lambdas.\$_generated1balProgram1.\$lambda\$_3\$lambda3\$\(balProgram1.bal:\d*\)

===========================================
\tStrand #\d* \"\d*\" :
\t\tat balProgram1.\$lambda\$_4\(balProgram1.bal:\d*\)
\t\t lambdas.\$_generated1balProgram1.\$lambda\$_4\$lambda4\$\(balProgram1.bal:\d*\)

\tStrand #\d* \"\d*\" :
\t\tat ballerina.lang&0046runtime.0.runtime.sleep\(runtime.bal:\d*\)
\t\t balProgram1.\$lambda\$_5\(balProgram1.bal:\d*\)
\t\t lambdas.\$_generated1balProgram1.\$lambda\$_5\$lambda5\$\(balProgram1.bal:\d*\)

\tStrand #\d* \"\d*\" :
\t\tat ballerina.lang&0046runtime.0.runtime.sleep\(runtime.bal:\d*\)
\t\t balProgram1.bar\(balProgram1.bal:\d*\)
\t\t balProgram1.foo\(balProgram1.bal:\d*\)
\t\t balProgram1.main\(balProgram1.bal:\d*\)
\t\t \$_init.\$moduleExecute\(.\)
\t\t \$_init.\$lambda\$\$moduleExecute\$\(.\)

\tStrand #\d* \"\d*\" :
\t\tat balProgram1.\$lambda\$_6\(balProgram1.bal:\d*\)
\t\t lambdas.\$_generated1balProgram1.\$lambda\$_6\$lambda6\$\(balProgram1.bal:\d*\)

\tStrand #\d* \"\d*\" :
\t\tat balProgram1.\$lambda\$_7\(balProgram1.bal:\d*\)
\t\t lambdas.\$_generated1balProgram1.\$lambda\$_7\$lambda7\$\(balProgram1.bal:\d*\)
Original file line number Diff line number Diff line change
@@ -1,53 +1,66 @@
Ballerina Strand Dump \[\d*/\d*/\d* \d*:\d*:\d*\]
===========================================

Total strand group count \t:\t3
Total strand count \t:\t8
Active strand group count\t:\t1
Active strand count \t:\t8

group \d* \[QUEUED\]: \[8\]
\tstrand \d* "main" \[testOrg.testPackageWithModules.0:main\] \[BLOCKED\]:
\t\tat\tballerina.lang.function.\d*.\d*.\d*:call\(function.bal:\d*\)
\t\t \tballerina.test.\d*.\d*.\d*:executeTestFunction\(serialExecuter.bal:\d*\)
\t\t \tballerina.test.\d*.\d*.\d*:executeNonDataDrivenTest\(serialExecuter.bal:\d*\)
\t\t \tballerina.test.\d*.\d*.\d*:executeTest\(serialExecuter.bal:\d*\)
\t\t \tballerina.test.\d*.\d*.\d*:executeTests\(execute.bal:\d*\)
\t\t \tballerina.test.\d*.\d*.\d*:startSuite\(execute.bal:\d*\)
\t\t \ttestOrg.testPackageWithModules.0.1.0:__execute__\(tests/test_execute-generated_1.bal:\d*\)
\t\t \t\$moduleExecute

\tstrand \d* \[ballerina.lang.function.\d*.\d*.\d*:call\]\[\d*\] \[WAITING\]:
\t\tat\ttestOrg.testPackageWithModules.0.1.0:bar\(main.bal:52\)
\t\t \ttestOrg.testPackageWithModules.0.1.0:foo\(main.bal:37\)
\t\t \ttestOrg.testPackageWithModules.0.1.0:foobar\(main.bal:33\)
\t\t \ttestOrg.testPackageWithModules.0.1.0:testStrandDump\(tests/main_test.bal:35\)

\tstrand \d* "w11" \[testOrg.testPackageWithModules.0:testStrandDump\]\[\d*\] \[WAITING\]:
\t\tat\ttestOrg.testPackageWithModules.anotherutils.0.1.0:func3\(anotherutils.bal:46\)
\t\t \ttestOrg.testPackageWithModules.anotherutils.0.1.0:func2\(anotherutils.bal:29\)
\t\t \ttestOrg.testPackageWithModules.anotherutils.0.1.0:func1\(anotherutils.bal:25\)
\t\t \ttestOrg.testPackageWithModules.anotherutils.0.1.0:entryfunc\(anotherutils.bal:21\)
\t\t \ttestOrg.testPackageWithModules.0.1.0:\$lambda\$_10\(tests/main_test.bal:26\)

\tstrand \d* "w22" \[testOrg.testPackageWithModules.0:testStrandDump\]\[\d*\] \[BLOCKED\]:
\t\tat\tballerina.lang.runtime.\d*.\d*.\d*:sleep\(runtime.bal:\d*\)
\t\t \ttestOrg.testPackageWithModules.0.1.0:\$lambda\$_11\(tests/main_test.bal:31\)

\tstrand \d* "w1" \[testOrg.testPackageWithModules.0:bar\]\[\d*\] \[BLOCKED\]:
\t\tat\tballerina.lang.runtime.\d*.\d*.\d*:sleep\(runtime.bal:\d*\)
\t\t \ttestOrg.testPackageWithModules.0.1.0:sleep_and_wait_nested\(main.bal:61\)
\t\t \ttestOrg.testPackageWithModules.0.1.0:sleep_and_wait\(main.bal:56\)
\t\t \ttestOrg.testPackageWithModules.0.1.0:\$lambda\$_0\(main.bal:42\)

\tstrand \d* "w2" \[testOrg.testPackageWithModules.0:bar\]\[\d*\] \[BLOCKED ON WORKER MESSAGE RECEIVE\]:
\t\tat\ttestOrg.testPackageWithModules.0.1.0:\$lambda\$_1\(main.bal:48\)

\tstrand \d* "w1" \[testOrg.testPackageWithModules.anotherutils.0:func3\]\[\d*\] \[BLOCKED\]:
\t\tat\tballerina.lang.runtime.\d*.\d*.\d*:sleep\(runtime.bal:\d*\)
\t\t \ttestOrg.testPackageWithModules.anotherutils.0.1.0:sleep_and_wait_nested\(anotherutils.bal:55\)
\t\t \ttestOrg.testPackageWithModules.anotherutils.0.1.0:sleep_and_wait\(anotherutils.bal:50\)
\t\t \ttestOrg.testPackageWithModules.anotherutils.0.1.0:\$lambda\$_0\(anotherutils.bal:34\)

\tstrand \d* "w2" \[testOrg.testPackageWithModules.anotherutils.0:func3\]\[\d*\] \[BLOCKED ON WORKER MESSAGE RECEIVE\]:
\t\tat\ttestOrg.testPackageWithModules.anotherutils.0.1.0:\$lambda\$_1\(anotherutils.bal:42\)
===============================================================

Total Strand count \t\t\t:\t7

Total Isolated Worker count \t\t:\t0

Total Non Isolated Worker count \t\t:\t7

================================================================

Isolated Workers:

Non Isolated Workers:

\tStrand #\d* \"\d*\" :
\t\tat testOrg.testPackageWithModules.0.main.bar\(main.bal:\d*\)
\t\t testOrg.testPackageWithModules.0.main.foo\(main.bal:\d*\)
\t\t testOrg.testPackageWithModules.0.main.foobar\(main.bal:\d*\)
\t\t testOrg.testPackageWithModules\$test.0.tests.main_test.testStrandDump\(tests/main_test.bal:\d*\)
\t\t testOrg.testPackageWithModules\$test.0.lambdas.\$_generated1tests.test_execute-generated_1.testStrandDump\$lambda0\$\(tests/test_execute-generated_1.bal:\d*\)
\t\t ballerina.lang&0046function.0.function.call\(function.bal:\d*\)
\t\t ballerina.test.0.serialExecuter.executeTestFunction\(serialExecuter.bal:\d*\)
\t\t ballerina.test.0.serialExecuter.executeNonDataDrivenTest\(serialExecuter.bal:\d*\)
\t\t ballerina.test.0.serialExecuter.executeTest\(serialExecuter.bal:\d*\)
\t\t ballerina.test.0.execute.executeTests\(execute.bal:\d*\)
\t\t ballerina.test.0.execute.startSuite\(execute.bal:\d*\)
\t\t testOrg.testPackageWithModules\$test.0.tests.test_execute-generated_1.__execute__\(tests/test_execute-generated_1.bal:\d*\)
\t\t testOrg.testPackageWithModules\$test.0.\$_init.\$moduleExecute\(testPackageWithModules\)
\t\t testOrg.testPackageWithModules\$test.0.\$_init.\$lambda\$\$moduleExecute\$\(testPackageWithModules\)

\tStrand #\d* \"\d*\" :
\t\tat ballerina.lang&0046runtime.0.runtime.sleep\(runtime.bal:\d*\)
\t\t testOrg.testPackageWithModules.0.main.sleep_and_wait_nested\(main.bal:\d*\)
\t\t testOrg.testPackageWithModules.0.main.sleep_and_wait\(main.bal:\d*\)
\t\t testOrg.testPackageWithModules.0.main.\$lambda\$_0\(main.bal:\d*\)
\t\t testOrg.testPackageWithModules.0.lambdas.\$_generated1main.\$lambda\$_0\$lambda3\$\(main.bal:\d*\)

\tStrand #\d* \"\d*\" :
\t\tat testOrg.testPackageWithModules.0.main.\$lambda\$_1\(main.bal:\d*\)
\t\t testOrg.testPackageWithModules.0.lambdas.\$_generated1main.\$lambda\$_1\$lambda4\$\(main.bal:\d*\)

\tStrand #\d* \"\d*\" :
\t\tat ballerina.lang&0046runtime.0.runtime.sleep\(runtime.bal:\d*\)
\t\t testOrg.testPackageWithModules&0046anotherutils.0.anotherutils.sleep_and_wait_nested\(anotherutils.bal:\d*\)
\t\t testOrg.testPackageWithModules&0046anotherutils.0.anotherutils.sleep_and_wait\(anotherutils.bal:\d*\)
\t\t testOrg.testPackageWithModules&0046anotherutils.0.anotherutils.\$lambda\$_0\(anotherutils.bal:\d*\)
\t\t testOrg.testPackageWithModules&0046anotherutils.0.lambdas.\$_generated1anotherutils.\$lambda\$_0\$lambda0\$\(anotherutils.bal:\d*\)

\tStrand #\d* \"\d*\" :
\t\tat testOrg.testPackageWithModules&0046anotherutils.0.anotherutils.\$lambda\$_1\(anotherutils.bal:\d*\)
\t\t testOrg.testPackageWithModules&0046anotherutils.0.lambdas.\$_generated1anotherutils.\$lambda\$_1\$lambda1\$\(anotherutils.bal:\d*\)

\tStrand #\d* \"\d*\" :
\t\tat testOrg.testPackageWithModules&0046anotherutils.0.anotherutils.func3\(anotherutils.bal:\d*\)
\t\t testOrg.testPackageWithModules&0046anotherutils.0.anotherutils.func2\(anotherutils.bal:\d*\)
\t\t testOrg.testPackageWithModules&0046anotherutils.0.anotherutils.func1\(anotherutils.bal:\d*\)
\t\t testOrg.testPackageWithModules&0046anotherutils.0.anotherutils.entryfunc\(anotherutils.bal:\d*\)
\t\t testOrg.testPackageWithModules\$test.0.tests.main_test.\$lambda\$_10\(tests/main_test.bal:\d*\)
\t\t testOrg.testPackageWithModules\$test.0.lambdas.\$_generated2tests.main_test.\$lambda\$_10\$lambda0\$\(tests/main_test.bal:\d*\)

\tStrand #\d* \"\d*\" :
\t\tat ballerina.lang&0046runtime.0.runtime.sleep\(runtime.bal:\d*\)
\t\t testOrg.testPackageWithModules\$test.0.tests.main_test.\$lambda\$_11\(tests/main_test.bal:\d*\)
\t\t testOrg.testPackageWithModules\$test.0.lambdas.\$_generated2tests.main_test.\$lambda\$_11\$lambda1\$\(tests/main_test.bal:\d*\)

Loading

0 comments on commit 1f4f7fe

Please sign in to comment.