Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Implement new stand dump tool for virtual threads #43369

Merged
merged 7 commits into from
Sep 20, 2024
Merged
Show file tree
Hide file tree
Changes from 2 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
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";
ravinperera00 marked this conversation as resolved.
Show resolved Hide resolved
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);
ravinperera00 marked this conversation as resolved.
Show resolved Hide resolved
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);
ravinperera00 marked this conversation as resolved.
Show resolved Hide resolved
}
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")) {
ravinperera00 marked this conversation as resolved.
Show resolved Hide resolved
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) {
ravinperera00 marked this conversation as resolved.
Show resolved Hide resolved
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
Loading