 | Posted by Richard (Rikki) Andrew Cattermole
in reply to Johan |  Permalink Reply |
|
Richard (Rikki) Andrew Cattermole 
| So there is a problem with time trace handling, it doesn't escape Windows paths so you end up with an exception on \T tather than \\T.
I've gone ahead and modified the tool, did some cleaning up, added a second output file that allows for consumption in a spreadsheet application, sorted by duration automatically.
I'd love to see the time trace switch upstreamed into dmd. We can then distribute this tool for an out of the box visualization experience that doesn't require a web browser. And of course globals need work, not just Windows path escaping ;)
It is an absolutely lovely tool that will ease a lot of peoples concerns over debugging compile times. Gonna be worth a blog article!
I'll put my version here also:
// Run using: rdmd timeTraceTree.d <your .time-trace file>
// Outputs timetrace.txt in current dir
module timeTraceTree;
import std.stdio;
import std.file;
import std.json;
import std.range;
import std.conv;
import std.algorithm;
File outputTextFile, outputTSVFile;
static string duration_format_string = "%13.3f ";
JSONValue sourceFile;
JSONValue[] metadata; // "M"
JSONValue[] counterdata; // "C"
JSONValue[] processes; // "X"
ulong lineNumberCounter = 1;
int main(string[] args)
{
if (args.length < 1)
return 1;
auto input_json = read(args[1]).to!string;
outputTextFile = File("timetrace.txt", "w");
outputTSVFile = File("timetrace.tsv", "w");
{
sourceFile = parseJSON(input_json);
readMetaData;
constructTree;
constructList;
}
{
outputTextFile.writeln("Timetrace: ", args[1]);
lineNumberCounter++;
outputTextFile.writeln("Metadata:");
lineNumberCounter++;
foreach (node; metadata)
{
outputTextFile.write(" ");
outputTextFile.writeln(node);
lineNumberCounter++;
}
outputTextFile.writeln("Duration (ms)");
lineNumberCounter++;
}
foreach (i, ref child; Node.root.children)
child.print(0, false);
outputTSVFile.writeln("Duration\tText Line Number\tName\tLocation\tDetail");
foreach (node; Node.all)
outputTSVFile.writeln(node.duration, "\t", node.lineNumber, "\t",
node.name, "\t", node.location, "\t", node.detail);
return 0;
}
void readMetaData()
{
auto beginningOfTime = sourceFile["beginningOfTime"].get!ulong;
auto traceEvents = sourceFile["traceEvents"].get!(JSONValue[]);
// Read meta data
foreach (value; traceEvents)
{
switch (value["ph"].get!string)
{
case "M":
metadata ~= value;
break;
case "C":
counterdata ~= value;
break;
case "X":
processes ~= value;
break;
default: //drop
}
}
// process node = {"ph":"X","name": "Sema1: Module object","ts":26825,"dur":1477,"loc":"<no file>","args":{"detail": "","loc":"<no file>"},"pid":101,"tid":101},
// Sort time processes
multiSort!(q{a["ts"].get!ulong < b["ts"].get!ulong}, q{a["dur"].get!ulong > b["dur"].get!ulong})(
processes);
}
void constructTree()
{
// Build tree (to get nicer looking structure lines)
Node*[] parent_stack = [&Node.root]; // each stack item represents the first uncompleted note of that level in the tree
foreach (ref process; processes)
{
auto last_ts = process["ts"].get!ulong + process["dur"].get!ulong;
size_t parent_idx = 0; // index in parent_stack to which this item should be added.
foreach (i; 0 .. parent_stack.length)
{
if (last_ts > parent_stack[i].last_ts)
{
// The current process outlasts stack item i. Stop traversing, parent is i-1;
parent_idx = i - 1;
parent_stack.length = i;
break;
}
parent_idx = i;
}
parent_stack[parent_idx].children ~= Node(&process, last_ts);
parent_stack ~= &parent_stack[parent_idx].children[$ - 1];
Node.count++;
}
}
void constructList()
{
size_t offset;
Node.all.length = Node.count - 1;
void handle(Node* root)
{
Node.all[offset++] = root;
foreach (ref child; root.children)
handle(&child);
}
foreach (ref child; Node.root.children)
handle(&child);
Node.all.sort!((a, b) => a.duration > b.duration);
}
struct Node
{
Node[] children;
JSONValue* json;
ulong last_ts; // represents the last timestamp of this node (i.e. ts + dur)
ulong lineNumber;
string name;
ulong duration;
string location;
string detail;
this(JSONValue* json, ulong last_ts)
{
this.json = json;
this.last_ts = last_ts;
if ((*json).type == JSONType.object && "dur" in (*json))
{
this.duration = (*json)["dur"].get!ulong;
this.name = (*json)["name"].get!string;
this.location = (*json)["args"]["loc"].get!string;
this.detail = (*json)["args"]["detail"].get!string;
}
}
void print(uint indentLevel, bool last_child)
{
char[] identPrefix = getIdentPrefix(indentLevel, last_child);
import std.stdio;
if (last_child)
{
identPrefix[$ - 4] = ' ';
identPrefix[$ - 3 .. $] = "\u2514";
}
else
identPrefix[$ - 2 .. $] = " |";
outputTextFile.writef(duration_format_string,
cast(double)(*this.json)["dur"].get!ulong / 1000);
outputTextFile.write(identPrefix);
outputTextFile.write("- ", this.name);
outputTextFile.write(", ", this.detail);
outputTextFile.writeln(", ", this.location);
this.lineNumber = lineNumberCounter;
lineNumberCounter++;
if (last_child)
identPrefix[$ - 4 .. $] = ' ';
foreach (i, ref child; this.children)
child.print(indentLevel + 1, i == this.children.length - 1);
}
static Node root = Node(new JSONValue("Tree root"), ulong.max);
static Node*[] all;
static size_t count = 1;
}
char[] getIdentPrefix(uint indentLevel, bool last_child)
{
static char[] buffer;
size_t needed = ((indentLevel + 1) * 2) + (last_child * 2);
if (buffer.length < needed)
buffer.length = needed;
return buffer;
}
|
