mirror of
https://github.com/dart-lang/sdk
synced 2024-10-06 16:31:07 +00:00
[CFE] Instrumenter can also count constructors; first run uses less ram because of trimming
For instance running like this:
out/ReleaseX64/dart pkg/front_end/tool/flame/instrumenter.dart pkg/front_end/tool/_fasta/compile.dart --count
out/ReleaseX64/dart pkg/front_end/tool/_fasta/compile.dart.dill.instrumented.dill --omit-platform pkg/front_end/tool/_fasta/compile.dart
will now also print how often Constructors are executed, e.g. it contains
stuff like thid:
529,397: ast.dart|DartType.constructor:
715,197: ast.dart|Expression.constructor:
1,177,700: ast.dart|TreeNode.constructor:
2,001,460: ast.dart|Node.constructor:
Change-Id: I26ff69f8ad8a1453d6004e97952ce3b39bfff687
Reviewed-on: https://dart-review.googlesource.com/c/sdk/+/298540
Reviewed-by: Johnni Winther <johnniwinther@google.com>
Commit-Queue: Jens Johansen <jensj@google.com>
This commit is contained in:
Jens Johansen
Commit Queue
parent
2a82ba0f48
commit
6f1b754a2f
|
|
@ -290,6 +290,7 @@ filters
|
|||
fisk
|
||||
five
|
||||
fl
|
||||
flame
|
||||
floor
|
||||
fluctuate
|
||||
foo'bar'baz
|
||||
|
|
@ -554,6 +555,7 @@ quit
|
|||
quot
|
||||
quux
|
||||
quuz
|
||||
ram
|
||||
reality
|
||||
recompilation
|
||||
recompiles
|
||||
|
|
|
|||
|
|
@ -71,33 +71,49 @@ Future<void> _main(List<String> inputArguments, Directory tmpDir) async {
|
|||
new BinaryBuilder(bytes).readComponent(component);
|
||||
|
||||
List<Procedure> procedures = [];
|
||||
List<Constructor> constructors = [];
|
||||
for (Library lib in component.libraries) {
|
||||
if (lib.importUri.scheme == "dart") continue;
|
||||
for (Class c in lib.classes) {
|
||||
addIfWanted(procedures, c.procedures, includeAll: reportCandidates);
|
||||
addIfWantedProcedures(procedures, c.procedures,
|
||||
includeAll: reportCandidates);
|
||||
if (!reportCandidates || doCount) {
|
||||
addIfWantedConstructors(constructors, c.constructors,
|
||||
includeAll: reportCandidates);
|
||||
}
|
||||
}
|
||||
addIfWanted(procedures, lib.procedures, includeAll: reportCandidates);
|
||||
addIfWantedProcedures(procedures, lib.procedures,
|
||||
includeAll: reportCandidates);
|
||||
}
|
||||
print("Procedures: ${procedures.length}");
|
||||
print("Constructors: ${constructors.length}");
|
||||
|
||||
bytes = File.fromUri(instrumentationLibDill).readAsBytesSync();
|
||||
new BinaryBuilder(bytes).readComponent(component);
|
||||
|
||||
// TODO: Check that this is true.
|
||||
Library instrumenterLib = component.libraries.last;
|
||||
Procedure instrumenterInitialize = instrumenterLib.procedures[0];
|
||||
Procedure instrumenterEnter = instrumenterLib.procedures[1];
|
||||
Procedure instrumenterExit = instrumenterLib.procedures[2];
|
||||
Procedure instrumenterReport = instrumenterLib.procedures[3];
|
||||
Procedure instrumenterInitialize =
|
||||
instrumenterLib.procedures.firstWhere((p) => p.name.text == "initialize");
|
||||
Procedure instrumenterEnter =
|
||||
instrumenterLib.procedures.firstWhere((p) => p.name.text == "enter");
|
||||
Procedure instrumenterExit =
|
||||
instrumenterLib.procedures.firstWhere((p) => p.name.text == "exit");
|
||||
Procedure instrumenterReport =
|
||||
instrumenterLib.procedures.firstWhere((p) => p.name.text == "report");
|
||||
|
||||
int id = 0;
|
||||
for (Procedure p in procedures) {
|
||||
int thisId = id++;
|
||||
wrapProcedure(p, thisId, instrumenterEnter, instrumenterExit);
|
||||
}
|
||||
for (Constructor c in constructors) {
|
||||
int thisId = id++;
|
||||
wrapConstructor(c, thisId, instrumenterEnter, instrumenterExit);
|
||||
}
|
||||
|
||||
initializeAndReport(component.mainMethod!, instrumenterInitialize, procedures,
|
||||
instrumenterReport, reportCandidates);
|
||||
constructors, instrumenterReport, reportCandidates);
|
||||
|
||||
print("Writing output.");
|
||||
String outString = output.toFilePath() + ".instrumented.dill";
|
||||
|
|
@ -105,7 +121,7 @@ Future<void> _main(List<String> inputArguments, Directory tmpDir) async {
|
|||
print("Wrote to $outString");
|
||||
}
|
||||
|
||||
void addIfWanted(List<Procedure> output, List<Procedure> input,
|
||||
void addIfWantedProcedures(List<Procedure> output, List<Procedure> input,
|
||||
{required bool includeAll}) {
|
||||
for (Procedure p in input) {
|
||||
if (p.function.body == null) continue;
|
||||
|
|
@ -113,7 +129,7 @@ void addIfWanted(List<Procedure> output, List<Procedure> input,
|
|||
if (p.function.dartAsyncMarker == AsyncMarker.SyncStar) continue;
|
||||
if (p.function.dartAsyncMarker == AsyncMarker.AsyncStar) continue;
|
||||
if (!includeAll) {
|
||||
String name = getName(p);
|
||||
String name = getProcedureName(p);
|
||||
Set<String> procedureNamesWantedInFile =
|
||||
wanted[p.fileUri.pathSegments.last] ?? const {};
|
||||
if (!procedureNamesWantedInFile.contains(name)) {
|
||||
|
|
@ -124,9 +140,25 @@ void addIfWanted(List<Procedure> output, List<Procedure> input,
|
|||
}
|
||||
}
|
||||
|
||||
String getName(Procedure p, {bool renameSetter = false}) {
|
||||
void addIfWantedConstructors(List<Constructor> output, List<Constructor> input,
|
||||
{required bool includeAll}) {
|
||||
for (Constructor c in input) {
|
||||
if (c.isExternal) continue;
|
||||
if (!includeAll) {
|
||||
String name = getConstructorName(c);
|
||||
Set<String> constructorNamesWantedInFile =
|
||||
wanted[c.fileUri.pathSegments.last] ?? const {};
|
||||
if (!constructorNamesWantedInFile.contains(name)) {
|
||||
continue;
|
||||
}
|
||||
}
|
||||
output.add(c);
|
||||
}
|
||||
}
|
||||
|
||||
String getProcedureName(Procedure p) {
|
||||
String name = p.name.text;
|
||||
if (renameSetter && p.isSetter) {
|
||||
if (p.isSetter) {
|
||||
name = "set:$name";
|
||||
}
|
||||
if (p.parent is Class) {
|
||||
|
|
@ -136,6 +168,12 @@ String getName(Procedure p, {bool renameSetter = false}) {
|
|||
}
|
||||
}
|
||||
|
||||
String getConstructorName(Constructor c) {
|
||||
String name = "constructor:${c.name.text}";
|
||||
Class parent = c.parent as Class;
|
||||
return "${parent.name}.$name";
|
||||
}
|
||||
|
||||
void setupWantedMap(List<String> candidates) {
|
||||
for (String filename in candidates) {
|
||||
File f = new File(filename);
|
||||
|
|
@ -155,6 +193,7 @@ void initializeAndReport(
|
|||
Procedure mainProcedure,
|
||||
Procedure initializeProcedure,
|
||||
List<Procedure> procedures,
|
||||
List<Constructor> constructors,
|
||||
Procedure instrumenterReport,
|
||||
bool reportCandidates) {
|
||||
ChildReplacer childReplacer;
|
||||
|
|
@ -165,19 +204,25 @@ void initializeAndReport(
|
|||
}
|
||||
|
||||
Block block = new Block([
|
||||
new ExpressionStatement(new StaticInvocation(initializeProcedure,
|
||||
new Arguments([new IntLiteral(procedures.length)]))),
|
||||
new ExpressionStatement(new StaticInvocation(
|
||||
initializeProcedure,
|
||||
new Arguments([
|
||||
new IntLiteral(procedures.length + constructors.length),
|
||||
new BoolLiteral(reportCandidates),
|
||||
]))),
|
||||
new TryFinally(
|
||||
childReplacer.originalChild as Statement,
|
||||
new ExpressionStatement(new StaticInvocation(
|
||||
instrumenterReport,
|
||||
new Arguments([
|
||||
new ListLiteral(procedures
|
||||
.map(
|
||||
(p) => new StringLiteral("${p.fileUri.pathSegments.last}|"
|
||||
"${getName(p, renameSetter: true)}"))
|
||||
.toList()),
|
||||
new BoolLiteral(reportCandidates),
|
||||
new ListLiteral([
|
||||
...procedures.map(
|
||||
(p) => new StringLiteral("${p.fileUri.pathSegments.last}|"
|
||||
"${getProcedureName(p)}")),
|
||||
...constructors.map(
|
||||
(c) => new StringLiteral("${c.fileUri.pathSegments.last}|"
|
||||
"${getConstructorName(c)}")),
|
||||
]),
|
||||
])))),
|
||||
]);
|
||||
childReplacer.replacer(block);
|
||||
|
|
@ -258,3 +303,32 @@ void wrapProcedure(Procedure p, int id, Procedure instrumenterEnter,
|
|||
instrumenterExit, new Arguments([new IntLiteral(id)]))));
|
||||
childReplacer.replacer(tryFinally);
|
||||
}
|
||||
|
||||
void wrapConstructor(Constructor c, int id, Procedure instrumenterEnter,
|
||||
Procedure instrumenterExit) {
|
||||
if (c.function.body == null || c.function.body is EmptyStatement) {
|
||||
// We just completely replace the body.
|
||||
Block block = new Block([
|
||||
new ExpressionStatement(new StaticInvocation(
|
||||
instrumenterEnter, new Arguments([new IntLiteral(id)]))),
|
||||
new ExpressionStatement(new StaticInvocation(
|
||||
instrumenterExit, new Arguments([new IntLiteral(id)]))),
|
||||
]);
|
||||
c.function.body = block;
|
||||
block.parent = c.function;
|
||||
return;
|
||||
}
|
||||
|
||||
// We retain the original body as with procedures.
|
||||
Block block = new Block([
|
||||
new ExpressionStatement(new StaticInvocation(
|
||||
instrumenterEnter, new Arguments([new IntLiteral(id)]))),
|
||||
c.function.body as Statement,
|
||||
]);
|
||||
TryFinally tryFinally = new TryFinally(
|
||||
block,
|
||||
new ExpressionStatement(new StaticInvocation(
|
||||
instrumenterExit, new Arguments([new IntLiteral(id)]))));
|
||||
c.function.body = tryFinally;
|
||||
tryFinally.parent = c.function;
|
||||
}
|
||||
|
|
|
|||
|
|
@ -5,11 +5,16 @@
|
|||
import "dart:io";
|
||||
|
||||
Stopwatch stopwatch = new Stopwatch();
|
||||
|
||||
List<int> data = [];
|
||||
bool _doReportCandidates = false;
|
||||
late List<Sum> _sum;
|
||||
List<int> _activeStack = [];
|
||||
List<DelayedReportData> delayedReportData = [];
|
||||
|
||||
void initialize(int count) {
|
||||
void initialize(int count, bool reportCandidates) {
|
||||
_sum = new List.generate(count, (_) => new Sum(), growable: false);
|
||||
stopwatch.start();
|
||||
_doReportCandidates = reportCandidates;
|
||||
}
|
||||
|
||||
@pragma("vm:prefer-inline")
|
||||
|
|
@ -24,48 +29,93 @@ void exit(int i) {
|
|||
data.add(0); // exit
|
||||
data.add(i); // what
|
||||
data.add(stopwatch.elapsedTicks); // time
|
||||
|
||||
if (_doReportCandidates && data.length > 100000000) {
|
||||
// We're reporting everything which can use a lot of ram. Try to trim it.
|
||||
_trim();
|
||||
}
|
||||
}
|
||||
|
||||
void report(List<String> names, bool reportCandidates) {
|
||||
Map<String, Sum>? sum = {};
|
||||
void _trim() {
|
||||
stopwatch.stop();
|
||||
print("Trimming...");
|
||||
int factorForMicroSeconds = stopwatch.frequency ~/ 1000000;
|
||||
_processData(null, factorForMicroSeconds);
|
||||
stopwatch.start();
|
||||
}
|
||||
|
||||
void report(List<String> names) {
|
||||
int factorForMicroSeconds = stopwatch.frequency ~/ 1000000;
|
||||
|
||||
File f = new File("cfe_compile_trace.txt");
|
||||
RandomAccessFile randomAccessFile = f.openSync(mode: FileMode.writeOnly);
|
||||
StringBuffer sb = new StringBuffer();
|
||||
sb.write("[");
|
||||
List<int> activeStack = [];
|
||||
|
||||
WithOutputInfo withOutputInfo =
|
||||
new WithOutputInfo(names, sb, randomAccessFile);
|
||||
|
||||
// Report previously delayed data.
|
||||
for (DelayedReportData data in delayedReportData) {
|
||||
_writeFlameOutputToBuffer(withOutputInfo, data.procedureNumber,
|
||||
data.enterMicroseconds, data.duration);
|
||||
}
|
||||
|
||||
// Report "new" data.
|
||||
_processData(withOutputInfo, factorForMicroSeconds);
|
||||
sb.write("\n]");
|
||||
randomAccessFile.writeStringSync(sb.toString());
|
||||
sb.clear();
|
||||
randomAccessFile.closeSync();
|
||||
print("Write to $f");
|
||||
|
||||
_reportCandidates(factorForMicroSeconds, names);
|
||||
}
|
||||
|
||||
class WithOutputInfo {
|
||||
final List<String> names;
|
||||
final StringBuffer sb;
|
||||
String separator = "\n";
|
||||
final RandomAccessFile randomAccessFile;
|
||||
|
||||
WithOutputInfo(this.names, this.sb, this.randomAccessFile);
|
||||
}
|
||||
|
||||
void _processData(WithOutputInfo? withOutputInfo, int factorForMicroSeconds) {
|
||||
for (int i = 0; i < data.length; i += 3) {
|
||||
int enterOrExit = data[i];
|
||||
int procedureNumber = data[i + 1];
|
||||
int ticks = data[i + 2];
|
||||
if (enterOrExit == 1) {
|
||||
// Enter.
|
||||
activeStack.add(procedureNumber);
|
||||
activeStack.add(ticks);
|
||||
_activeStack.add(procedureNumber);
|
||||
_activeStack.add(ticks);
|
||||
} else if (enterOrExit == 0) {
|
||||
// Exit
|
||||
int enterTicks = activeStack.removeLast();
|
||||
int enterProcedureNumber = activeStack.removeLast();
|
||||
int enterTicks = _activeStack.removeLast();
|
||||
int enterProcedureNumber = _activeStack.removeLast();
|
||||
if (enterProcedureNumber != procedureNumber) {
|
||||
print("DEBUG: Now exiting ${names[procedureNumber]}.");
|
||||
print("DEBUG: Latest entering ${names[enterProcedureNumber]}.");
|
||||
if (withOutputInfo != null) {
|
||||
print("DEBUG: Now exiting "
|
||||
"${withOutputInfo.names[procedureNumber]}.");
|
||||
print("DEBUG: Latest entering "
|
||||
"${withOutputInfo.names[enterProcedureNumber]}.");
|
||||
}
|
||||
bool foundMatch = false;
|
||||
int steps = 1;
|
||||
for (int i = activeStack.length - 2; i >= 0; i -= 2) {
|
||||
for (int i = _activeStack.length - 2; i >= 0; i -= 2) {
|
||||
steps++;
|
||||
if (activeStack[i] == procedureNumber) {
|
||||
if (_activeStack[i] == procedureNumber) {
|
||||
foundMatch = true;
|
||||
break;
|
||||
}
|
||||
}
|
||||
if (foundMatch) {
|
||||
activeStack.add(enterProcedureNumber);
|
||||
activeStack.add(enterTicks);
|
||||
_activeStack.add(enterProcedureNumber);
|
||||
_activeStack.add(enterTicks);
|
||||
enterProcedureNumber =
|
||||
activeStack.removeAt(activeStack.length - steps * 2);
|
||||
enterTicks = activeStack.removeAt(activeStack.length - steps * 2);
|
||||
_activeStack.removeAt(_activeStack.length - steps * 2);
|
||||
enterTicks = _activeStack.removeAt(_activeStack.length - steps * 2);
|
||||
assert(enterProcedureNumber != procedureNumber);
|
||||
} else {
|
||||
throw "Mismatching enter/exit with no matching "
|
||||
|
|
@ -74,58 +124,66 @@ void report(List<String> names, bool reportCandidates) {
|
|||
}
|
||||
|
||||
double enterMicroseconds = enterTicks / factorForMicroSeconds;
|
||||
String name = names[procedureNumber];
|
||||
double duration = (ticks - enterTicks) / factorForMicroSeconds;
|
||||
Sum s = sum[name] ??= new Sum();
|
||||
s.addTick(ticks - enterTicks);
|
||||
_sum[procedureNumber].addTick(ticks - enterTicks);
|
||||
|
||||
// Avoid outputting too much data.
|
||||
if (reportCandidates) {
|
||||
if (_doReportCandidates) {
|
||||
// If collecting all, don't output everything as that will simply be
|
||||
// too much data.
|
||||
if (duration < 1000) continue;
|
||||
}
|
||||
sb.write(separator);
|
||||
separator = ",\n";
|
||||
|
||||
String displayName = name.substring(name.indexOf("|") + 1);
|
||||
String file = name.substring(0, name.indexOf("|"));
|
||||
sb.write('{"ph": "X", "ts": $enterMicroseconds, "dur": $duration, '
|
||||
'"name": "$displayName", "cat": "$file", "pid": 1, "tid": 1}');
|
||||
if (withOutputInfo != null) {
|
||||
_writeFlameOutputToBuffer(
|
||||
withOutputInfo, procedureNumber, enterMicroseconds, duration);
|
||||
} else {
|
||||
// Save for later output.
|
||||
delayedReportData.add(new DelayedReportData(
|
||||
procedureNumber, enterMicroseconds, duration));
|
||||
}
|
||||
} else {
|
||||
throw "Error: $enterOrExit expected to be 0 or 1.";
|
||||
}
|
||||
if (sb.length > 1024 * 1024) {
|
||||
randomAccessFile.writeStringSync(sb.toString());
|
||||
sb.clear();
|
||||
if (withOutputInfo != null && withOutputInfo.sb.length > 1024 * 1024) {
|
||||
withOutputInfo.randomAccessFile
|
||||
.writeStringSync(withOutputInfo.sb.toString());
|
||||
withOutputInfo.sb.clear();
|
||||
}
|
||||
}
|
||||
sb.write("\n]");
|
||||
randomAccessFile.writeStringSync(sb.toString());
|
||||
sb.clear();
|
||||
randomAccessFile.closeSync();
|
||||
print("Write to $f");
|
||||
|
||||
_reportCandidates(sum, factorForMicroSeconds, reportCandidates);
|
||||
data.clear();
|
||||
}
|
||||
|
||||
void _reportCandidates(
|
||||
Map<String, Sum> sum, int factorForMicroSeconds, bool reportCandidates) {
|
||||
void _writeFlameOutputToBuffer(WithOutputInfo withOutputInfo,
|
||||
int procedureNumber, double enterMicroseconds, double duration) {
|
||||
withOutputInfo.sb.write(withOutputInfo.separator);
|
||||
withOutputInfo.separator = ",\n";
|
||||
String name = withOutputInfo.names[procedureNumber];
|
||||
|
||||
String displayName = name.substring(name.indexOf("|") + 1);
|
||||
String file = name.substring(0, name.indexOf("|"));
|
||||
withOutputInfo.sb
|
||||
.write('{"ph": "X", "ts": $enterMicroseconds, "dur": $duration, '
|
||||
'"name": "$displayName", "cat": "$file", "pid": 1, "tid": 1}');
|
||||
}
|
||||
|
||||
void _reportCandidates(int factorForMicroSeconds, List<String> names) {
|
||||
StringBuffer sb = new StringBuffer();
|
||||
StringBuffer sbDebug = new StringBuffer();
|
||||
final int leastRuntime = reportCandidates ? 500 : 50;
|
||||
for (MapEntry<String, Sum> entry in sum.entries) {
|
||||
double averageMicroseconds = entry.value.average / factorForMicroSeconds;
|
||||
final int leastRuntime = _doReportCandidates ? 500 : 50;
|
||||
for (int i = 0; i < _sum.length; i++) {
|
||||
Sum sum = _sum[i];
|
||||
double averageMicroseconds = sum.average / factorForMicroSeconds;
|
||||
if (averageMicroseconds >= leastRuntime) {
|
||||
// Average call time is >= 0.5 or 0.05 ms.
|
||||
sb.writeln(entry.key);
|
||||
sbDebug.writeln(entry.key);
|
||||
sbDebug.writeln(" => ${entry.value.count}, ${entry.value.totalTicks}, "
|
||||
"${entry.value.average}, $averageMicroseconds");
|
||||
String name = names[i];
|
||||
sb.writeln(name);
|
||||
sbDebug.writeln(name);
|
||||
sbDebug.writeln(" => ${sum.count}, ${sum.totalTicks}, "
|
||||
"${sum.average}, $averageMicroseconds");
|
||||
}
|
||||
}
|
||||
if (sb.length > 0) {
|
||||
String extra = reportCandidates ? "" : "_subsequent";
|
||||
String extra = _doReportCandidates ? "" : "_subsequent";
|
||||
File f = new File("cfe_compile_trace_candidates$extra.txt");
|
||||
f.writeAsStringSync(sb.toString());
|
||||
print("Wrote candidates to $f");
|
||||
|
|
@ -144,3 +202,12 @@ class Sum {
|
|||
totalTicks += tick;
|
||||
}
|
||||
}
|
||||
|
||||
class DelayedReportData {
|
||||
final int procedureNumber;
|
||||
final double enterMicroseconds;
|
||||
final double duration;
|
||||
|
||||
DelayedReportData(
|
||||
this.procedureNumber, this.enterMicroseconds, this.duration);
|
||||
}
|
||||
|
|
|
|||
|
|
@ -8,7 +8,7 @@ Stopwatch stopwatch = new Stopwatch();
|
|||
|
||||
Uint32List counts = new Uint32List(0);
|
||||
|
||||
void initialize(int count) {
|
||||
void initialize(int count, bool reportCandidates) {
|
||||
counts = new Uint32List(count);
|
||||
stopwatch.start();
|
||||
}
|
||||
|
|
@ -21,7 +21,7 @@ void enter(int i) {
|
|||
@pragma("vm:prefer-inline")
|
||||
void exit(int i) {}
|
||||
|
||||
void report(List<String> names, bool reportCandidates) {
|
||||
void report(List<String> names) {
|
||||
List<NameWithCount> data = [];
|
||||
for (int i = 0; i < counts.length; i++) {
|
||||
int count = counts[i];
|
||||
|
|
|
|||
Loading…
Reference in a new issue