diff --git a/.devcontainer/devcontainer.json b/.devcontainer/devcontainer.json index eb17a4d..7700f8d 100644 --- a/.devcontainer/devcontainer.json +++ b/.devcontainer/devcontainer.json @@ -15,6 +15,8 @@ "ms-azuretools.vscode-docker", "ms-vscode.cpptools-extension-pack", "eamodio.gitlens", + "ms-python.python", + "MS-vsliveshare.vsliveshare", ], // allow access to the toradex board diff --git a/.vscode/tasks.json b/.vscode/tasks.json index 2be3374..f92d424 100644 --- a/.vscode/tasks.json +++ b/.vscode/tasks.json @@ -31,7 +31,7 @@ { "label": "Build and Run Toradex", "type": "shell", - "command": "cd ${BFBUILD} && make -j7 imx8x && make usbboot_imx8x | tee ${BFBUILD}/full_output.log", + "command": "cd ${BFBUILD} && make -j7 imx8x && make usbboot_imx8x", "group": { "kind": "build", "isDefault": true @@ -40,7 +40,7 @@ { "label": "Toradex Console", "type": "shell", - "command": "if ! picocom -b 115200 -f n /dev/ttyUSB0; then echo; echo !!!Make sure you installed the toradex udev rules to allow user access!!!; fi", + "command": "if ! picocom -b 115200 -f n /dev/ttyUSB0 | tee ${BFBUILD}/full_output.log; then echo; echo !!!Make sure you installed the toradex udev rules to allow user access!!!; fi", "group": { "kind": "build", "isDefault": true diff --git a/include/aos/performance.h b/include/aos/performance.h new file mode 100644 index 0000000..b093fa3 --- /dev/null +++ b/include/aos/performance.h @@ -0,0 +1,27 @@ +#ifndef LIBBARRELFISH_PERFORMANCE_H +#define LIBBARRELFISH_PERFORMANCE_H + +#include + +#define PERFORMANCE_MEASUREMENT_COUNT_MAX 10 + +// uncomment to enable performance measurements +// #define PERFORMANCE_ENABLED + +struct measurement { + char *tag; + systime_t timestamp; +}; + +struct performance_context { + size_t count; + char *name; + struct measurement measurements[PERFORMANCE_MEASUREMENT_COUNT_MAX]; +}; + +void perf_init(struct performance_context *c, char *name); +void perf_add_measurement(struct performance_context *c, char *tag, systime_t timestamp); +void perf_add_now(struct performance_context *c, char *tag); +void perf_print(struct performance_context *c); + +#endif // LIBBARRELFISH_PERFORMANCE_H diff --git a/lib/aos/Hakefile b/lib/aos/Hakefile index b7e5305..0f9e870 100644 --- a/lib/aos/Hakefile +++ b/lib/aos/Hakefile @@ -25,6 +25,7 @@ "slot_alloc/twolevel_slot_alloc.c", "aos_rpc.c", "aos_urpc.c", + "performance.c", "capabilities.c", "coreset.c", "coreboot.c", diff --git a/lib/aos/aos_urpc.c b/lib/aos/aos_urpc.c index 3f4827d..5bb47a0 100644 --- a/lib/aos/aos_urpc.c +++ b/lib/aos/aos_urpc.c @@ -18,6 +18,7 @@ #include #include #include +#include extern coreid_t my_core_id; extern rpc_handler_t rpc_handlers[RPC_MTYPE_COUNT]; @@ -167,7 +168,7 @@ errval_t aos_urpc_get_bootinfo(struct aos_urpc * rpc, struct bootinfo_serialized return SYS_ERR_OK; } - +struct performance_context p; int urpc_server(void *arg) { struct aos_urpc_server *urpc = arg; struct waitset *default_ws = get_default_waitset(); @@ -180,7 +181,8 @@ int urpc_server(void *arg) { // wait until an rpc call arrives while(urpc->meta->call_in_progress == false) { // sleep for a bit while there is nothing to do - barrelfish_usleep(100); + // barrelfish_usleep(100); + thread_yield(); } // memory barrier @@ -188,10 +190,29 @@ int urpc_server(void *arg) { "dmb sy\n" ); +#ifdef PERFORMANCE_ENABLED + bool type_nop = urpc->meta->a0 == RPC_MTYPE_NOP; + if(type_nop) { + perf_init(&p, "aos_urpc_server"); + perf_add_now(&p, "start"); + } +#endif + // handle the URPC on the same thread that handles regular RPCs, to avoid concurrency for the handlers waitset_chan_trigger_closure(default_ws, &chan, MKCLOSURE(urpc_server_handler, urpc)); +#ifdef PERFORMANCE_ENABLED + perf_add_now(&p, "triggered_closure"); +#endif + // wait until the rpc is handled thread_sem_wait(&urpc->sem); + +#ifdef PERFORMANCE_ENABLED + if(type_nop) { + perf_add_now(&p, "done"); + perf_print(&p); + } +#endif } } diff --git a/lib/aos/performance.c b/lib/aos/performance.c new file mode 100644 index 0000000..5a030de --- /dev/null +++ b/lib/aos/performance.c @@ -0,0 +1,33 @@ +#include +#include +#include +#include + +void perf_init(struct performance_context *c, char *name) { + c->count = 0; + c->name = name; + memset(c->measurements, 0, sizeof(c->measurements)); +} + +inline void perf_add_measurement(struct performance_context *c, char *tag, systime_t timestamp) +{ + c->measurements[c->count].tag = tag; + c->measurements[c->count].timestamp = timestamp; + c->count++; + __asm volatile ( + "dmb sy\n" + ); +} + +inline void perf_add_now(struct performance_context *c, char *tag) +{ + systime_t now = systime_now(); + perf_add_measurement(c, tag, now); +} + +void perf_print(struct performance_context *c) +{ + for (size_t i = 0; i < c->count; i++) { + debug_printf("MEASUREMENT %s:%s %lu\n", c->name, c->measurements[i].tag, c->measurements[i].timestamp); + } +} diff --git a/performance/.gitignore b/performance/.gitignore new file mode 100644 index 0000000..5ceb386 --- /dev/null +++ b/performance/.gitignore @@ -0,0 +1 @@ +venv diff --git a/performance/performance_evaluation.py b/performance/performance_evaluation.py new file mode 100644 index 0000000..169ed3a --- /dev/null +++ b/performance/performance_evaluation.py @@ -0,0 +1,109 @@ +#/bin/env python3 +from distutils.log import error +from statistics import mean, median +import sys +from matplotlib import pyplot as p +from mailbox import linesep +import os +import re + +from numpy import std + +MEASUREMENT_TAG = "MEASUREMENT" +# searches for a measurement with #1 name, #2 tag, #3 time +MEASUREMENT_REGEX = r"^.* " + MEASUREMENT_TAG + r" ([a-zA-Z_:-]*) ([0-9]*)$" + +# TODO change this for the actual measurement +# data_basedir = os.environ.get("BFBUILD_QEMU") +data_basedir = os.environ.get("BFBUILD") +data_file = os.path.join(data_basedir, "full_output.log") +out_dir = os.path.join(os.path.dirname(sys.argv[0]), "plots") + +def extract_measurement(line): + match = re.match(MEASUREMENT_REGEX, line) + if not match: + print(f"[ERROR] Malformed measurement: '{line}'") + exit(1) + return { + "tag": match.group(1), + "timestamp": int(match.group(2)), + } + +def extract_measurements(lines): + filtered = filter(lambda l: MEASUREMENT_TAG in l, lines) + return list(map(extract_measurement, filtered)) + +def read_data(file): + with open(file) as f: + return f.readlines() + +def build_dataseries(measurements, start_tag, end_tag): + datapoints = [] + + started_at = None + for m in measurements: + if started_at is None: + if m["tag"] == start_tag: + started_at = m["timestamp"] + else: + if m["tag"] == end_tag: + datapoints.append(m["timestamp"] - started_at) + started_at = None + elif m["tag"] == start_tag: + print("[ERROR] Invalid sequence, ignoring last start tag") + started_at = m["timestamp"] + + return datapoints + + +def main(): + raw_log = read_data(data_file) + + measurements = extract_measurements(raw_log) + measurements.sort(key=lambda m: m["timestamp"]) + + dataset = {} + + dataset["performance"] = build_dataseries(measurements, "aos_performance:start", "aos_performance:done") + + dataset["client_to_server"] = build_dataseries(measurements, "aos_urpc_nop:start", "aos_urpc_server:start") + dataset["server_schedule_task"] = build_dataseries(measurements, "aos_urpc_server:start", "aos_urpc_server:triggered_closure") + dataset["server_completed_task"] = build_dataseries(measurements, "aos_urpc_server:triggered_closure", "aos_urpc_server:done") + dataset["server_to_client"] = build_dataseries(measurements, "aos_urpc_server:done", "aos_urpc_nop:done") + + # calculate stats for each data series + metrics = {} + for key in dataset: + # d_mean = mean(dataset[key]) + d_std = std(dataset[key]) + d_median = median(dataset[key]) + metrics[key] = (d_median, d_std) + + # create output directory + os.makedirs(out_dir, exist_ok=True) + + # create plots for data series + for key in dataset: + d = dataset[key] + d.sort() + p.clf() + p.title(key) + p.xlabel("datapoint index") + p.ylabel("duration (cycles)") + p.scatter(range(len(d)), d) + p.savefig(os.path.join(out_dir, f"{key}.jpg")) + + p.clf() + fig, ax = p.subplots(figsize=(12,5)) + p.title("Metrics") + p.ylabel("median duration (cycles)") + p.bar( + metrics.keys(), + [x[0] for x in metrics.values()], + yerr=[x[1] for x in metrics.values()], + ) + ax.set_ylim(0) + p.savefig(os.path.join(out_dir, "metrics.jpg")) + +if __name__ == "__main__": + main() diff --git a/performance/requirements.txt b/performance/requirements.txt new file mode 100644 index 0000000..4b43f7e --- /dev/null +++ b/performance/requirements.txt @@ -0,0 +1 @@ +matplotlib \ No newline at end of file diff --git a/usr/init/main.c b/usr/init/main.c index 730b3c2..76b7f62 100644 --- a/usr/init/main.c +++ b/usr/init/main.c @@ -30,7 +30,8 @@ #include #include - +#include +#include struct bootinfo *bi; @@ -247,6 +248,28 @@ app_main(int argc, char *argv[]) { ram_alloc_set(ram_alloc_remote_core); +#ifdef PERFORMANCE_ENABLED + barrelfish_usleep(2000000); + + struct performance_context p; + // measure performance measurement performance + for(size_t i = 0; i < 1000; ++i) { + perf_init(&p, "aos_performance"); + perf_add_now(&p, "start"); + perf_add_now(&p, "done"); + perf_print(&p); + } + + // measure URPC performance + for(size_t i = 0; i < 1000; ++i) { + perf_init(&p, "aos_urpc_nop"); + perf_add_now(&p, "start"); + do_aos_urpc(&urpc_to_bsp, RPC_MTYPE_NOP, NULL_CAP, 0, 0, 0, NULL, NULL, NULL, NULL); + perf_add_now(&p, "done"); + perf_print(&p); + } +#endif + // Allocate all pages of the thread stack now. // We can't have page faults while the thread is running, // because URPC calls may only be done from the main thread.