Last active
April 6, 2020 23:11
-
-
Save hamaluik/412e2109a5f5fbcf12e1 to your computer and use it in GitHub Desktop.
Simple Haxe Profiler
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
package ; | |
import haxe.ds.StringMap; | |
import haxe.macro.Context; | |
import haxe.macro.Expr; | |
import haxe.macro.Printer; | |
import haxe.macro.Type.ClassType; | |
import neko.Lib; | |
using haxe.macro.ExprTools; | |
typedef MethodProfile = { | |
var calls:Int; | |
var startTime:Float; | |
var elapsedTime:Float; | |
} | |
class Profiler | |
{ | |
/** | |
* An internal tool for determining the fully-qualified-name of a class | |
* @param cls a macro classtype | |
* @return the fully-qualified-name of the class | |
*/ | |
private static function getFullClassName(cls:ClassType):String | |
{ | |
return (cls.pack.length > 0 ? cls.pack.join(".") + "." : "") + cls.name; | |
} | |
private static var lastWasReturn:Bool = false; | |
private static var clsName:String = ""; | |
private static var methodName:String = ""; | |
/** | |
* This is a recursive function which will tunnel into a function's expressions and replace any | |
* occurrances of a return expression with a custom profiling return expressions | |
* @param expr the expression to recursively search through | |
* @return the transformed expression | |
*/ | |
private static function remapReturn(expr:Expr):Expr | |
{ | |
lastWasReturn = false; | |
switch(expr.expr) | |
{ | |
case EReturn(retExpr): | |
{ | |
lastWasReturn = true; | |
if (retExpr == null) | |
{ | |
return macro { | |
Profiler.endProfile($v { clsName }, $v { methodName } ); | |
return; | |
}; | |
} | |
else | |
{ | |
return macro { | |
var ___tempProfilingReturnValue = ${retExpr}; | |
Profiler.endProfile($v { clsName }, $v { methodName } ); | |
return ___tempProfilingReturnValue; | |
}; | |
} | |
} | |
case _: | |
return ExprTools.map(expr, remapReturn); | |
} | |
} | |
/** | |
* This function, when used in a build macro, will inject profiling code at the beginning | |
* and ending of each function. Call using a build macro such as: | |
* @:build(Profiler.profile()) | |
* class SomeClass { | |
* ... | |
* } | |
*/ | |
macro public static function profile():Array<Field> | |
{ | |
// get the fields of the class | |
var fields:Array<Field> = Context.getBuildFields(); | |
var printer:Printer = new Printer(); | |
// and the fully qualified class name | |
clsName = getFullClassName(Context.getLocalClass().get()); | |
// loop through each field to find the methods | |
for (field in fields) | |
{ | |
switch(field.kind) | |
{ | |
// yay, found a method! | |
case FFun(func): | |
{ | |
// get the name of the method | |
methodName = field.name; | |
// prepend the start code to the function | |
func.expr = macro { | |
Profiler.startProfile($v { clsName }, $v { methodName } ); | |
$ { func.expr }; | |
}; | |
// start the recursive expression transformation | |
lastWasReturn = false; | |
func.expr = remapReturn(func.expr); | |
if (!lastWasReturn) | |
{ | |
func.expr = macro { | |
$ { func.expr }; | |
Profiler.endProfile($v { clsName }, $v { methodName } ); | |
return; | |
} | |
} | |
} | |
// skip properties and variables | |
default: { }; | |
} | |
} | |
return fields; | |
} | |
private static var profiles:StringMap<StringMap<MethodProfile>> = new StringMap<StringMap<MethodProfile>>(); | |
/** | |
* Reset all the profiling information. Doing this before reading / printing the information will | |
* cause all the data collected since the beginning (or last reset) to be lost | |
*/ | |
public static function reset() | |
{ | |
profiles = new StringMap<StringMap<MethodProfile>>(); | |
} | |
/** | |
* Called at the start of a function to record when in time the method was called. This must always | |
* be called BEFORE an endProfile() call is made | |
* @param className the fully-qualified class name of the method's class | |
* @param methodName the name of the method being profiled | |
*/ | |
public static function startProfile(className:String, methodName:String) | |
{ | |
// make sure the profiles exist | |
if (!profiles.exists(className)) | |
profiles.set(className, new StringMap<MethodProfile>()); | |
if (!profiles.get(className).exists(methodName)) | |
profiles.get(className).set(methodName, { calls: 0, startTime: 0, elapsedTime: 0 } ); | |
profiles.get(className).get(methodName).startTime = Sys.cpuTime(); | |
profiles.get(className).get(methodName).calls++; | |
Lib.println("> Starting " + className + "." + methodName); | |
} | |
/** | |
* Called at the end of a function to calculate the method's execution time. This must always | |
* be called AFTER a startProfile() call | |
* @param className the fully-qualified class name of the method's class | |
* @param methodName the name of the method being profiled | |
*/ | |
public static function endProfile(className:String, methodName:String) | |
{ | |
var t:Float = Sys.cpuTime(); | |
if (!profiles.exists(className) || !profiles.get(className).exists(methodName)) | |
throw "EndProfile was called on a function that was never started!"; | |
profiles.get(className).get(methodName).elapsedTime += t - profiles.get(className).get(methodName).startTime; | |
Lib.println("< Ending " + className + "." + methodName); | |
} | |
/** | |
* Just a utility function to print the profiling data, separated by class. | |
*/ | |
public static function printProfiles():Void | |
{ | |
var totalTime:Float = 0; | |
for (className in profiles.keys()) | |
{ | |
var classTime:Float = 0; | |
Lib.println(className + ":"); | |
for (methodName in profiles.get(className).keys()) | |
{ | |
Lib.println(" ." + methodName + ": " + profiles.get(className).get(methodName).elapsedTime + "s (" + profiles.get(className).get(methodName).calls + " calls)"); | |
classTime += profiles.get(className).get(methodName).elapsedTime; | |
} | |
Lib.println(" ---"); | |
Lib.println(" " + classTime + "s"); | |
totalTime += classTime; | |
} | |
Lib.println(""); | |
Lib.println("Total time: " + totalTime + "s"); | |
} | |
} |
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
package ; | |
import haxe.macro.Printer; | |
import neko.Lib; | |
class Main | |
{ | |
static function main() | |
{ | |
var worker:Worker = new Worker(); | |
worker.doSomething(); | |
Lib.println(worker.derp()); | |
Lib.println("w/ 0: " + worker.doSomethingElse(0)); | |
Lib.println("w/ 1: " + worker.doSomethingElse(1)); | |
Lib.println("w/ 2: " + worker.doSomethingElse(2)); | |
Lib.println("w/ 3: " + worker.doSomethingElse(3)); | |
Lib.println("w/ 4: " + worker.doSomethingElse(4)); | |
Lib.println("w/ 5: " + worker.doSomethingElse(5)); | |
Profiler.printProfiles(); | |
} | |
} |
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
> Starting Worker.new | |
< Ending Worker.new | |
> Starting Worker.doSomething | |
< Ending Worker.doSomething | |
> Starting Worker.derp | |
< Ending Worker.derp | |
herp | |
> Starting Worker.doSomethingElse | |
< Ending Worker.doSomethingElse | |
w/ 0: 0 | |
> Starting Worker.doSomethingElse | |
< Ending Worker.doSomethingElse | |
w/ 1: 1 | |
> Starting Worker.doSomethingElse | |
< Ending Worker.doSomethingElse | |
w/ 2: 2 | |
> Starting Worker.doSomethingElse | |
< Ending Worker.doSomethingElse | |
w/ 3: 3 | |
> Starting Worker.doSomethingElse | |
< Ending Worker.doSomethingElse | |
w/ 4: 4 | |
> Starting Worker.doSomethingElse | |
< Ending Worker.doSomethingElse | |
w/ 5: 4 | |
Worker: | |
.new: 0s (1 calls) | |
.doSomething: 0.046875s (1 calls) | |
.derp: 0s (1 calls) | |
.doSomethingElse: 0s (6 calls) | |
--- | |
0.046875s |
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
package ; | |
import neko.Lib; | |
@:build(Profiler.profile()) | |
@:autoBuild(Profiler.profile()) | |
class Worker | |
{ | |
public function new() | |
{ | |
} | |
public function doSomething():Void | |
{ | |
var q:Float = 0; | |
for (i in 0...1000000) | |
{ | |
q += 3.14159; | |
} | |
} | |
public function doSomethingElse(x:Int):Float | |
{ | |
try | |
{ | |
if (x == 0) | |
return 0; | |
else if (x == 1) | |
throw "derp"; | |
} | |
catch (exc:String) { return 1; } | |
switch(x) | |
{ | |
case 2: | |
return 2; | |
case 3: | |
return 3; | |
} | |
return 4; | |
} | |
public function derp():String return "herp"; | |
} |
Great recommendation @pshtif!
I tried this on a php project and I found two issues:
- remapReturn should also have a case for EThrow expressions to make it handle exits via exceptions
- remapReturn should be inside a
#if macro … #end
condition, to make sure haxe does not try to compile it to target (you get anClass<haxe.macro.Context> has no field makeExpr
error for every $v)
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Thanks @pshtif, you're totally right! I didn't know about the
ExprTools
(specifically themap
capability). I've updated the gist to reflect your changes.