#!/usr/sbin/dtrace -Zs
/*
 * py_functime.d - measure Python function times using DTrace.
 * Based on Brendan Greg's Javascript js_functime.d
 *
 * py_function-entry	(filename, classname, funcname)
 *
 * Usage: pfexec  dtrace -s py_functime3.d function
*
*/
#pragma ident   "@(#)js_functime.d      1.3     07/03/26 SMI"

#pragma D option quiet

this string str;

dtrace:::BEGIN
{
        printf("Tracing... Hit Ctrl-C to end.\n");
        depth = 0;
	self->count = 0;
	self->monitor = 0;
}

python*:::function-entry
/basename(copyinstr(arg0)) == $$1 && copyinstr(arg1) == $$2 /
{
	self->monitor = timestamp;
}

python*:::function-entry
/self->monitor/
{
        self->depth++;
        self->start[copyinstr(arg1), self->depth] = timestamp;
}

python*:::function-return
/self->monitor && (this->str = copyinstr(arg1)) != NULL && self->start[this->str, self->depth]/
{
        this->file = basename(copyinstr(arg0));
        this->elapsed = timestamp - self->start[this->str, self->depth];
        @num[this->file, this->str] = count();
        @eavg[this->file, this->str] = avg(this->elapsed);
        @esum[this->file, this->str] = sum(this->elapsed);
        @edist[this->str] = quantize(this->elapsed);
        self->start[this->file, self->depth] = 0;
        self->depth--;
}

python*:::function-entry
/basename(copyinstr(arg0)) == $$3 && copyinstr(arg1) == $$4 /
{
	printf("TOTAL: %d\n", timestamp - self->monitor);
	self->monitor = 0;
	exit(0);
}

dtrace:::END
{
        normalize(@eavg, 1000000);
        normalize(@esum, 1000000);
        printf("ELAPSED TIME DISTRIBUTION,\n");
        printa(@edist);
        setopt("aggsortpos", "2");
        printf("%-33s %45s\n", "___ OVERLAP TIMES: ___",
            "______ ELAPSED _____");
        printf("%-24s %-23s %6s %10s %12s\n", "FILE", "FUNCTION",
            "COUNT", "AVG(ms)", "SUM(ms)");
        printa("%-24.24s %-23.23s %@6d %@10d %@12d\n", @num, @eavg, @esum);
}