Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
153 changes: 153 additions & 0 deletions contrib/cf-profile/cf-profile.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,153 @@
from argparse import ArgumentParser
import sys
import json
import re
from collections import defaultdict

"""
This script parses profiling output from cf-agent and lists policy bundles, promises, and functions sorted by execution time.

Usage:
$ sudo /var/cfengine/cf-agent -Kp
$ python3 cf-profile.py profiling_output.json --bundles --promises --functions
"""


def parse_args():
parser = ArgumentParser()

# parser.add_argument("profiling_output")
parser.add_argument("--top", type=int, default=10)
parser.add_argument("--bundles", action="store_true")
parser.add_argument("--promises", action="store_true")
parser.add_argument("--functions", action="store_true")
parser.add_argument("--flamegraph", action="store_true")

return parser.parse_args()


def format_elapsed_time(elapsed_ns):
elapsed_ms = float(elapsed_ns) / 1e6

if elapsed_ms < 1000:
return "%.2f ms" % elapsed_ms
elif elapsed_ms < 60000:
elapsed_s = elapsed_ms / 1000.0
return "%.2fs" % elapsed_s
else:
elapsed_s = elapsed_ms / 1000.0
minutes = int(elapsed_s // 60)
seconds = int(elapsed_s % 60)
return "%dm%ds" % (minutes, seconds)


def format_label(event_type, name):
if event_type == "function":
return "%s() %s call" % (name, event_type)
elif name == "methods":
return "bundle invocation"
else:
return "%s %s" % (name, event_type)


def format_columns(events, top):

labels = []

for event in events[:top]:
label = format_label(event["type"], event["name"])
location = "%s:%s" % (event["filename"], event["offset"]["line"])
time = format_elapsed_time(event["elapsed"])

labels.append((label, location, time))

return labels


def get_max_column_lengths(lines, indent=4):

max_type, max_location, max_time = 0, 0, 0

for label, location, time_ms in lines:
max_type = max(max_type, len(label))
max_location = max(max_location, len(location))
max_time = max(max_time, len(time_ms))

return max_type + indent, max_location + indent, max_time + indent


def profile(data, args):

events = data["events"]
filter = defaultdict(list)

if args.bundles:
filter["type"].append("bundle")
filter["name"].append("methods")

if args.promises:
filter["name"] += list(
set(
event["name"]
for event in events
if event["type"] == "promise" and event["name"] != "methods"
)
)

if args.functions:
filter["type"].append("function")

# filter events
if filter is not None:
events = [
event
for field in filter.keys()
for event in events
if event[field] in filter[field]
]

# sort events
events = sorted(events, key=lambda x: x["elapsed"], reverse=True)

lines = format_columns(events, args.top)
line_format = "%-{}s %-{}s %{}s".format(*get_max_column_lengths(lines))

# print top k filtered events
print(line_format % ("Type", "Location", "Time"))
for label, location, time_ms in lines:
print(line_format % (label, location, time_ms))

def generate_callstacks(data):
events = data["events"]

# hashmap = {"policy" : 0}
# for event in events:
# hashmap[event["id"]] = event["elapsed"]
Comment on lines +124 to +125

Check notice

Code scanning / CodeQL

Commented-out code Note

This comment appears to contain commented-out code.
# print(json.dumps(hashmap, indent=4))

# for event in sorted(events, key=lambda x: x["id"].count(";"), reverse=True):
# parent = ";".join(event["id"].split(";")[:-1])
# hashmap[parent] -= event["elapsed"]
Comment on lines +128 to +130

Check notice

Code scanning / CodeQL

Commented-out code Note

This comment appears to contain commented-out code.


with open("stack.txt", "w") as f:
for event in events:
f.write("%s %d\n" % (event["callstack"], event["elapsed"]))

def main():
args = parse_args()
m = re.search(r"\{[.\s\S]*\}", sys.stdin.read())
# with open(args.profiling_output, "r") as f:
# data = json.load(f)
Comment on lines +140 to +141

Check notice

Code scanning / CodeQL

Commented-out code Note

This comment appears to contain commented-out code.
data = json.loads(m.group(0))


if args.flamegraph:
generate_callstacks(data)
else:
profile(data, args)



if __name__ == "__main__":
main()
94 changes: 82 additions & 12 deletions libpromises/eval_context.c
Original file line number Diff line number Diff line change
Expand Up @@ -127,8 +127,13 @@
static const char *EvalContextCurrentNamespace(const EvalContext *ctx);
static ClassRef IDRefQualify(const EvalContext *ctx, const char *id);

static EventFrame *EventFrameCreate(char *type, const char *name, const char *source, SourceOffset offset);
static EventFrame *EventFrameCreate(char *type, const char *name, const char *source, SourceOffset offset, char *id);
static void EventFrameDestroy(EventFrame *event);

static char *BundleGetCallStackID(const Bundle *bp);
static char *PromiseGetCallStackID(const Promise *pp);
static char *FunctionGetCallStackID(const FnCall *fp);

static EventFrame *BundleToEventFrame(const Bundle *bp);
static EventFrame *PromiseToEventFrame(const Promise *pp);
static EventFrame *FunctionToEventFrame(const FnCall *fp);
Expand Down Expand Up @@ -340,12 +345,26 @@
if (frame->type == type)
{
return frame;
}

Check notice

Code scanning / CodeQL

Pointer argument is dereferenced without checking for NULL Note

Parameter ctx in LastStackFrameByNonNullEvent() is dereferenced without an explicit null-check
}

return NULL;
}

static StackFrame *LastStackFrameByEvent(const EvalContext *ctx)
{
for (size_t i = 0; i < SeqLength(ctx->stack); i++)
{
StackFrame *frame = LastStackFrame(ctx, i);
if (frame->event != NULL)
{
return frame;
}
}

return NULL;
}

static LogLevel AdjustLogLevel(LogLevel base, LogLevel adjust)
{
if (adjust == -1)
Expand Down Expand Up @@ -1436,7 +1455,22 @@
assert(ctx != NULL);
assert(!LastStackFrame(ctx, 0) || LastStackFrame(ctx, 0)->type == STACK_FRAME_TYPE_PROMISE_ITERATION);

EvalContextStackPushFrame(ctx, StackFrameNewBundle(owner, inherits_previous, ctx->profiling));
StackFrame *prev_frame = LastStackFrameByEvent(ctx);
StackFrame *frame = StackFrameNewBundle(owner, inherits_previous, ctx->profiling);

EventFrame *pushed_event = frame->event;
EvalContextStackPushFrame(ctx, frame);
if (pushed_event != NULL)
{
if (prev_frame == NULL || prev_frame->event == NULL)
{
pushed_event->stacktrace = SafeStringDuplicate(pushed_event->id);
}
else
{
pushed_event->stacktrace = StringFormat("%s;%s", prev_frame->event->stacktrace, pushed_event->id);
}
}

if (RlistLen(args) > 0)
{
Expand Down Expand Up @@ -1516,9 +1550,22 @@

EvalContextVariableClearMatch(ctx);

StackFrame *prev_frame = LastStackFrameByEvent(ctx);
StackFrame *frame = StackFrameNewPromise(owner, ctx->profiling);

EvalContextStackPushFrame(ctx, frame);
EventFrame *pushed_event = frame->event;
if (pushed_event != NULL)
{
if (prev_frame == NULL || prev_frame->event == NULL)
{
pushed_event->stacktrace = SafeStringDuplicate(pushed_event->id);
}
else
{
pushed_event->stacktrace = StringFormat("%s;%s", prev_frame->event->stacktrace, pushed_event->id);
}
}

// create an empty table
frame->data.promise.vars = VariableTableNew();
Expand Down Expand Up @@ -3891,7 +3938,7 @@
ctx->profiling = profiling;
}

static EventFrame *EventFrameCreate(char *type, const char *name, const char *source, SourceOffset offset)
static EventFrame *EventFrameCreate(char *type, const char *name, const char *source, SourceOffset offset, char *id)
{
EventFrame *event = (EventFrame *) xmalloc(sizeof(EventFrame));

Expand All @@ -3900,7 +3947,8 @@
event->filename = GetAbsolutePath(source);
event->elapsed = 0;
event->offset = offset;
event->id = StringFormat("%s_%s_%s_%ld_%ld", type, name, source, offset.start, offset.line);
event->id = id;
event->stacktrace = "";

return event;
}
Expand All @@ -3926,6 +3974,7 @@
JsonObjectAppendString(json_event, "filename", event->filename);
JsonObjectAppendString(json_event, "id", event->id);
JsonObjectAppendInteger64(json_event, "elapsed", event->elapsed);
JsonObjectAppendString(json_event, "callstack", event->stacktrace);

JsonElement *offset = JsonObjectCreate(4);
JsonObjectAppendInteger(offset, "start", event->offset.start);
Expand All @@ -3941,19 +3990,19 @@
static EventFrame *BundleToEventFrame(const Bundle *bp)
{
assert(bp != NULL);
return EventFrameCreate("bundle", bp->name, bp->source_path, bp->offset);
return EventFrameCreate("bundle", bp->name, bp->source_path, bp->offset, BundleGetCallStackID(bp));
}

static EventFrame *PromiseToEventFrame(const Promise *pp)
{
assert(pp != NULL);
return EventFrameCreate("promise", PromiseGetPromiseType(pp), PromiseGetBundle(pp)->source_path, pp->offset);
return EventFrameCreate("promise", PromiseGetPromiseType(pp), PromiseGetBundle(pp)->source_path, pp->offset, PromiseGetCallStackID(pp));
}

static EventFrame *FunctionToEventFrame(const FnCall *fp)
{
assert(fp != NULL);
return EventFrameCreate("function", fp->name, PromiseGetBundle(fp->caller)->source_path, fp->caller->offset);
return EventFrameCreate("function", fp->name, PromiseGetBundle(fp->caller)->source_path, fp->caller->offset, FunctionGetCallStackID(fp));
}

void EvalContextAddFunctionEvent(EvalContext *ctx, const FnCall *fp, int64_t start)
Expand Down Expand Up @@ -4022,21 +4071,26 @@

ctx->profiler.elapsed = end - start;

HashMap *map = SumEventFrames(ctx->profiler.events);
// HashMap *map = SumEventFrames(ctx->profiler.events);
JsonElement *profiling = JsonObjectCreate(2);

JsonElement *json_policy = PolicyToJson(policy);
JsonObjectAppendObject(profiling, "policy", json_policy);

JsonElement *events = JsonArrayCreate(10);
{
HashMapIterator iter = HashMapIteratorInit(map);
MapKeyValue *mkv;
while ((mkv = HashMapIteratorNext(&iter)) != NULL)
// HashMapIterator iter = HashMapIteratorInit(map);
// MapKeyValue *mkv;
// while ((mkv = HashMapIteratorNext(&iter)) != NULL)
// {
// EventFrame *event = mkv->value;
// JsonArrayAppendObject(events, EventToJson(event));
// }
for (size_t i = 0; i < SeqLength(ctx->profiler.events); i++)
{
EventFrame *event = mkv->value;
EventFrame *event = SeqAt(ctx->profiler.events, i);
JsonArrayAppendObject(events, EventToJson(event));
}

Check notice

Code scanning / CodeQL

Commented-out code Note

This comment appears to contain commented-out code.
}
JsonObjectAppendArray(profiling, "events", events);

Expand All @@ -4047,3 +4101,19 @@

JsonDestroy(profiling);
}


static char *BundleGetCallStackID(const Bundle *bp)
{
return StringFormat("bundle_%s_%s:%s_%s:%ld_%ld-%ld", bp->type, bp->ns, bp->name, bp->source_path, bp->offset.line, bp->offset.start, bp->offset.end);
}

static char *PromiseGetCallStackID(const Promise *pp)
{
return StringFormat("promise_%s_%ld_%ld-%ld", PromiseGetPromiseType(pp), pp->offset.line, pp->offset.start, pp->offset.end);

Check notice

Code scanning / CodeQL

Pointer argument is dereferenced without checking for NULL Note

Parameter bp in BundleGetCallStackID() is dereferenced without an explicit null-check

Check notice

Code scanning / CodeQL

Pointer argument is dereferenced without checking for NULL Note

Parameter bp in BundleGetCallStackID() is dereferenced without an explicit null-check

Check notice

Code scanning / CodeQL

Pointer argument is dereferenced without checking for NULL Note

Parameter bp in BundleGetCallStackID() is dereferenced without an explicit null-check

Check notice

Code scanning / CodeQL

Pointer argument is dereferenced without checking for NULL Note

Parameter bp in BundleGetCallStackID() is dereferenced without an explicit null-check

Check notice

Code scanning / CodeQL

Pointer argument is dereferenced without checking for NULL Note

Parameter bp in BundleGetCallStackID() is dereferenced without an explicit null-check

Check notice

Code scanning / CodeQL

Pointer argument is dereferenced without checking for NULL Note

Parameter bp in BundleGetCallStackID() is dereferenced without an explicit null-check

Check notice

Code scanning / CodeQL

Pointer argument is dereferenced without checking for NULL Note

Parameter bp in BundleGetCallStackID() is dereferenced without an explicit null-check
}

static char *FunctionGetCallStackID(const FnCall *fp)
{
return StringFormat("function_%s_%ld_%ld-%ld", fp->name, fp->caller->offset.line, fp->caller->offset.start, fp->caller->offset.end);

Check notice

Code scanning / CodeQL

Pointer argument is dereferenced without checking for NULL Note

Parameter pp in PromiseGetCallStackID() is dereferenced without an explicit null-check

Check notice

Code scanning / CodeQL

Pointer argument is dereferenced without checking for NULL Note

Parameter pp in PromiseGetCallStackID() is dereferenced without an explicit null-check

Check notice

Code scanning / CodeQL

Pointer argument is dereferenced without checking for NULL Note

Parameter pp in PromiseGetCallStackID() is dereferenced without an explicit null-check
}
1 change: 1 addition & 0 deletions libpromises/eval_context.h
Original file line number Diff line number Diff line change
Expand Up @@ -47,6 +47,7 @@ typedef struct {
char *filename;
SourceOffset offset;
int64_t elapsed;
char *stacktrace;
} EventFrame;

typedef enum
Expand Down
Loading