1 module profdump; 2 3 import std.algorithm : canFind; 4 import std.stdio : File; 5 import std..string : indexOfAny, indexOfNeither; 6 import std.conv : to; 7 import std.regex : regex, matchFirst, replaceAll; 8 import std.json : JSONValue; 9 import std.exception : enforce; 10 11 alias HASH = ubyte[4]; 12 13 private char[] demangle(const(char)[] buf, bool verbose = false) { 14 static import core.demangle; 15 if(buf == "_Dmain".dup) { 16 return "void main()".dup; 17 } else { 18 if(verbose) { 19 return core.demangle.demangle(buf); 20 } else { 21 return core.demangle.demangle(buf) 22 .replaceAll(regex(r"(?:@\w+\s|pure\s|nothrow\s)", "g"), "") 23 .replaceAll(regex(r"\([ ,*A-Za-z0-9\(\)!\[\]@]+\)", "g"), "(..)"); 24 } 25 } 26 } 27 28 struct Profile { 29 Function[HASH] Functions; 30 ulong TicksPerSecond; 31 float TimeOfMain; 32 33 this(ref File f, bool verbose = false) { 34 import std.digest.crc : crc32Of; 35 36 Function temp; 37 bool newEntry = false; 38 foreach(ref line; f.byLine) { 39 if(line.length == 0) { 40 continue; 41 } else if(line[0] == '-') { 42 newEntry = true; 43 if(temp.Name.length != 0) { 44 this.Functions[temp.Mangled.crc32Of] = temp; 45 temp = Function(); 46 } 47 } else if(line[0] == '=') { 48 if(temp.Name.length != 0) 49 this.Functions[temp.Mangled.crc32Of] = temp; 50 auto i = line.indexOfAny("0123456789"); 51 if (i == -1 && line.canFind("Megaticks")) { 52 // timing is in Megaticks. See: druntime/rt/trace.d 53 this.TicksPerSecond = 1_000_000; 54 } else { 55 enforce(i > 0, 56 "Your trace.log file is invalid"); 57 auto s = line[i..$].indexOfNeither("0123456789"); 58 this.TicksPerSecond = line[i..i + s].to!ulong; 59 } 60 break; 61 } else if(line[0] == '\t') { 62 auto cap = line.matchFirst( 63 regex(r"\t\s*(\d+)\t\s*(\w+)")); 64 enforce(!cap.empty, 65 "Your trace.log file is invalid"); 66 if(newEntry) { 67 temp.calledBy(FunctionElement( 68 cap[2].demangle(verbose).dup, 69 cap[2].dup, 70 cap[1].to!ulong)); 71 } else { 72 temp.callsTo(FunctionElement( 73 cap[2].demangle(verbose).dup, 74 cap[2].dup, 75 cap[1].to!ulong)); 76 } 77 } else { 78 auto cap = line.matchFirst( 79 regex(r"(\w+)\t\s*-?(\d+)\t\s*-?(\d+)\t\s*-?(\d+)")); 80 assert(!cap.empty); 81 newEntry = false; 82 temp.Name = cap[1].demangle(verbose).dup; 83 temp.Mangled = cap[1].dup; 84 temp.Calls = cap[2].to!ulong; 85 temp.FunctionTime = cap[4].to!ulong; 86 temp.Time = cap[3].to!ulong; 87 } 88 } 89 90 const HASH main = "_Dmain".crc32Of; 91 enforce(main in this.Functions, 92 "Your trace.log file is invalid"); 93 94 this.TimeOfMain = this.timeOf(main); 95 } 96 97 const void writeString(ref File f, in float threshold = 0) { 98 foreach(k, ref v; this.Functions) { 99 if(threshold != 0 && this.percOf(k) < threshold) 100 continue; 101 f.writefln("Function '%s':\n"~ 102 "\tMangled name: '%s'", 103 v.Name, 104 v.Mangled); 105 106 if(v.CallsTo) { 107 f.writeln("\tCalls:"); 108 foreach(ke, va; v.CallsTo) 109 f.writefln("\t\t%s\t%d %s", va.Name, va.Calls, 110 va.Calls == 1 ? "time" : "times"); 111 } 112 if(v.CalledBy) { 113 f.writeln("\tCalled by:"); 114 foreach(ke, va; v.CalledBy) 115 f.writefln("\t\t%s\t%d %s", va.Name, va.Calls, 116 va.Calls == 1 ? "time" : "times"); 117 } 118 f.writefln("\tTook: %f seconds (%f%%)\n"~ 119 "\tFinished in: %f seconds (%f%%)", 120 this.functionTimeOf(k), 121 this.functionPercOf(k), 122 this.timeOf(k), 123 this.percOf(k)); 124 } 125 } 126 127 deprecated const void toString(scope void delegate(const(char)[]) s, in float threshold = 0) { 128 import std.format : format; 129 foreach(k, ref v; this.Functions) { 130 if(threshold != 0 && this.percOf(k) < threshold) 131 continue; 132 s("Function '%s':\n".format(v.Name)); 133 s("\tMangled name: '%s'\n".format(v.Mangled)); 134 if(v.CallsTo) { 135 s("\tCalls:\n"); 136 foreach(ke, va; v.CallsTo) 137 s("\t\t%s\t%d times\n".format(va.Name, va.Calls)); 138 } 139 if(v.CalledBy) { 140 s("\tCalled by:\n"); 141 foreach(ke, va; v.CalledBy) 142 s("\t\t%s\t%d times\n".format(va.Name, va.Calls)); 143 } 144 s("\tTook: %f seconds (%f%%)\n" 145 .format(this.functionTimeOf(k), this.functionPercOf(k))); 146 s("\tFinished in: %f seconds (%f%%)\n" 147 .format(this.timeOf(k), this.percOf(k))); 148 } 149 } 150 151 deprecated const void toJSONString(scope void delegate(const(char)[]) s, 152 in float threshold = 0, 153 in bool pretty = false) { 154 if(pretty) { 155 s(this.toJSON(threshold).toPrettyString); 156 s("\n"); 157 } else { 158 s(this.toJSON(threshold).toString); 159 } 160 } 161 162 const void writeJSON(ref File f, in float threshold = 0, in bool pretty = false) { 163 (pretty) 164 ? f.writeln(this.toJSON(threshold).toPrettyString) 165 : f.write(this.toJSON(threshold).toString); 166 } 167 168 const JSONValue toJSON(in float threshold = 0) { 169 JSONValue[] ret; 170 foreach(k, ref v; this.Functions) { 171 if(threshold != 0 && this.percOf(k) < threshold) 172 continue; 173 174 JSONValue func = JSONValue([ 175 "name": v.Name, 176 "mangled": v.Mangled 177 ]); 178 if(v.CallsTo) { 179 JSONValue[] temp; 180 foreach(kk, vv; v.CallsTo) { 181 temp ~= JSONValue([ 182 "name": JSONValue(vv.Name), 183 "mangled": JSONValue(vv.Mangled), 184 "calls": JSONValue(vv.Calls) 185 ]); 186 } 187 func["callsTo"] = JSONValue(temp); 188 } 189 if(v.CalledBy) { 190 JSONValue[] temp; 191 foreach(k, vv; v.CalledBy) { 192 temp ~= JSONValue([ 193 "name": JSONValue(vv.Name), 194 "mangled": JSONValue(vv.Mangled), 195 "calls": JSONValue(vv.Calls) 196 ]); 197 } 198 func["calledBy"] = JSONValue(temp); 199 } 200 func["functionTimeSec"] = JSONValue(this.functionTimeOf(k)); 201 func["timeSec"] = JSONValue(this.timeOf(k)); 202 func["functionTime"] = JSONValue(v.FunctionTime); 203 func["time"] = JSONValue(v.Time); 204 func["functionPerc"] = JSONValue(this.functionPercOf(k)); 205 func["perc"] = JSONValue(this.percOf(k)); 206 207 ret ~= func; 208 } 209 210 return JSONValue([ 211 "tps" : JSONValue(this.TicksPerSecond), 212 "functions" : JSONValue(ret)]); 213 } 214 215 @safe pure nothrow const float timeOf(HASH f) 216 in { 217 assert(f in this.Functions); 218 } body { 219 return cast(float) this.Functions[f].Time / 220 cast(float) this.TicksPerSecond; 221 } 222 223 @safe pure nothrow const float percOf(HASH f) 224 in { 225 assert(f in this.Functions); 226 } body { 227 return (cast(float) this.Functions[f].Time / 228 cast(float) this.TicksPerSecond) / TimeOfMain * 100; 229 } 230 231 @safe pure nothrow const float functionTimeOf(HASH f) 232 in { 233 assert(f in this.Functions); 234 } body { 235 return cast(float) this.Functions[f].FunctionTime / 236 cast(float) this.TicksPerSecond; 237 } 238 239 @safe pure nothrow const float functionPercOf(HASH f) 240 in { 241 assert(f in this.Functions); 242 } body { 243 return (cast(float) this.Functions[f].FunctionTime / 244 cast(float) this.TicksPerSecond) / TimeOfMain * 100; 245 } 246 247 const void writeDOT(ref File f, 248 in float threshold = 0, 249 in string[float] colours = [ 250 0: "limegreen", 251 10: "slateblue", 252 25: "steelblue", 253 50: "royalblue", 254 75: "navy", 255 95: "red" 256 ] 257 ) { 258 import std..string : tr, wrap; 259 import std.digest.crc : crc32Of; 260 261 auto clr = (float f) { 262 import std.algorithm : sort; 263 foreach(k; sort!("a>b")(colours.keys)) 264 if(k <= f) 265 return colours[k]; 266 return "gray"; 267 }; 268 269 HASH[][HASH] func; 270 enum fmt = "\"%s\" [label=\"%s\\n%.2f%%(%.2f%%)\", shape=\"box\"," ~ 271 " style=filled, fillcolor=\"%s\"];"; 272 273 foreach(k, ref v; this.Functions) { 274 if(threshold == 0 || this.percOf(k) > threshold) { 275 func[k] = []; 276 foreach(key, unused; v.CallsTo) { 277 if(threshold != 0 && this.percOf(key) <= threshold) 278 continue; 279 if(key !in func) 280 func[key] = []; 281 func[k] ~= key; 282 } 283 } else { 284 continue; 285 } 286 } 287 288 f.writeln("digraph {"); 289 foreach(k, ref v; func) { 290 f.writefln(fmt, 291 this.Functions[k].Mangled.tr("\"", "\\\""), 292 this.Functions[k].Name.tr("\"", "\\\"").wrap(40), 293 this.percOf(k), 294 this.functionPercOf(k), 295 clr(this.percOf(k))); 296 foreach(i; v) { 297 if(i !in func) { 298 f.writefln(fmt, 299 this.Functions[i].Mangled.tr("\"", "\\\""), 300 this.Functions[i].Name.tr("\"", "\\\"").wrap(40), 301 this.percOf(i), 302 this.functionPercOf(i), 303 clr(this.percOf(i))); 304 } 305 f.writefln("\"%s\" -> \"%s\" [label=\"%dx\"];", 306 this.Functions[k].Mangled.tr("\"", "\\\""), 307 this.Functions[i].Mangled.tr("\"", "\\\""), 308 this.Functions[k].CallsTo[i].Calls); 309 } 310 } 311 f.writeln("}"); 312 } 313 314 deprecated const void toDOT(scope void delegate(const(char)[]) s, 315 float threshold = 0, 316 string[float] colours = [ 317 0: "limegreen", 318 10: "slateblue", 319 25: "steelblue", 320 50: "royalblue", 321 75: "navy", 322 95: "red" 323 ] 324 ) { 325 import std.format : format; 326 import std..string : tr, wrap; 327 import std.digest.crc : crc32Of; 328 329 string clr(float f) { 330 import std.algorithm : sort; 331 foreach(k; sort!("a>b")(colours.keys)) { 332 if(k <= f) { 333 return colours[k]; 334 } 335 } 336 return "gray"; 337 } 338 339 HASH[][HASH] func; 340 enum fmt = "\"%s\" [label=\"%s\\n%.2f%%(%.2f%%)\", shape=\"box\"," ~ 341 " style=filled, fillcolor=\"%s\"];\n"; 342 343 foreach(k, ref v; this.Functions) { 344 if(threshold == 0 || this.percOf(k) > threshold) { 345 func[k] = []; 346 foreach(key, unused; v.CallsTo) { 347 if(threshold != 0 && this.percOf(key) <= threshold) 348 continue; 349 if(key !in func) 350 func[key] = []; 351 func[k] ~= key; 352 } 353 } else { 354 continue; 355 } 356 } 357 358 s("digraph {\n"); 359 foreach(k, ref v; func) { 360 s(fmt.format( 361 this.Functions[k].Mangled.tr("\"", "\\\""), 362 this.Functions[k].Name.tr("\"", "\\\"").wrap(40), 363 this.percOf(k), 364 this.functionPercOf(k), 365 clr(this.percOf(k)))); 366 foreach(i; v) { 367 if(i !in func) { 368 s(fmt.format( 369 this.Functions[i].Mangled.tr("\"", "\\\""), 370 this.Functions[i].Name.tr("\"", "\\\"").wrap(40), 371 this.percOf(i), 372 this.functionPercOf(i), 373 clr(this.percOf(i)))); 374 } 375 s("\"%s\" -> \"%s\" [label=\"%dx\"];\n".format( 376 this.Functions[k].Mangled.tr("\"", "\\\""), 377 this.Functions[i].Mangled.tr("\"", "\\\""), 378 this.Functions[k].CallsTo[i].Calls)); 379 } 380 } 381 s("}\n"); 382 } 383 } 384 385 private struct FunctionElement { 386 char[] Name; 387 char[] Mangled; 388 ulong Calls; 389 } 390 391 private struct Function { 392 char[] Name; 393 char[] Mangled; 394 ulong Calls; 395 FunctionElement[HASH] CallsTo; 396 FunctionElement[HASH] CalledBy; 397 ulong FunctionTime; 398 ulong Time; 399 400 void callsTo(FunctionElement func) { 401 import std.digest.crc : crc32Of; 402 HASH h = func.Mangled.crc32Of; 403 this.CallsTo[h] = func; 404 } 405 406 void calledBy(FunctionElement func) { 407 import std.digest.crc : crc32Of; 408 HASH h = func.Mangled.crc32Of; 409 this.CalledBy[h] = func; 410 } 411 }