Add basic benchmarking suite (#106)

pipermerriam · web-flow · commit 2bd66b93c443 · 2019-03-01T16:11:10.000-07:00
diff --git a/.circleci/config.yml b/.circleci/config.yml
@@ -72,6 +72,18 @@ jobs:
       - image: circleci/python:3.7
         environment:
           TOXENV: py37-spec
+  py36-benchmark:
+    <<: *common
+    docker:
+      - image: circleci/python:3.6
+        environment:
+          TOXENV: py36-benchmark
+  py37-benchmark:
+    <<: *common
+    docker:
+      - image: circleci/python:3.7
+        environment:
+          TOXENV: py37-benchmark
 workflows:
   version: 2
   test:
@@ -82,3 +94,5 @@ workflows:
       - py37-core
       - py36-spec
       - py37-spec
+      - py36-benchmark
+      - py37-benchmark
diff --git a/scripts/benchmark/bench.wasm b/scripts/benchmark/bench.wasm
diff --git a/scripts/benchmark/bench.wast b/scripts/benchmark/bench.wast
@@ -0,0 +1,49 @@
+(module
+  (export "thunk" (func $thunk))
+  (export "call_thunk" (func $call_thunk))
+  (export "add" (func $add))
+  (export "call_add" (func $call_add))
+
+  (func $call_thunk (param i32)
+    block
+      get_local 0
+      i32.eqz
+      br_if 0
+      loop
+        call $thunk
+        get_local 0
+        i32.const 1
+        i32.sub
+        tee_local 0
+        br_if 0
+      end
+    end
+  )
+
+  (func $call_add (param i32) (param i32) (param i32)
+    block
+      get_local 0
+      i32.eqz
+      br_if 0
+      loop
+        get_local 2
+        get_local 1
+        call $add
+        drop
+        get_local 0
+        i32.const 1
+        i32.sub
+        tee_local 0
+        br_if 0
+      end
+    end
+  )
+
+  (func $thunk)
+
+  (func $add (param i32) (param i32) (result i32)
+    get_local 0
+    get_local 1
+    i32.add
+  )
+)
diff --git a/scripts/benchmark/run.py b/scripts/benchmark/run.py
@@ -0,0 +1,62 @@
+from pathlib import Path
+import time
+
+import numpy
+
+from wasm import (
+    Runtime,
+)
+
+
+# From https://github.com/alexcrichton/rust-wasm-benchmark/blob/master/raw-wasm/raw.wast
+BASE_DIR = Path(__file__).parent
+WASM_BENCH = BASE_DIR / 'bench.wasm'
+
+
+def _get_fn_address(runtime, module, function_name):
+    for export in module.exports:
+        if export.is_function and export.name == function_name:
+            return export.function_address
+    else:
+        raise Exception(f"No function found by name: {function_name}")
+
+
+def bench():
+    runtime = Runtime()
+    module, _ = runtime.instantiate_module(runtime.load_module(WASM_BENCH))
+    runtime.register_module('bench', module)
+
+    thunk_delta = bench_fn(runtime, module, 'thunk', (), 10000)
+    add_delta = bench_fn(runtime, module, 'add', (numpy.uint32(1), numpy.uint32(2)), 10000)
+    call_thunk_delta = bench_fn(runtime, module, 'call_thunk', (numpy.uint32(10000),), 1)
+    call_add_delta = bench_fn(
+        runtime,
+        module,
+        'call_add',
+        (numpy.uint32(10000), numpy.uint32(1), numpy.uint32(2)),
+        1,
+    )
+
+    print(f"wrapped thunk: {call_thunk_delta / 10000:.8f} per call")
+    print(f"wrapped add  : {call_add_delta / 10000:.8f} per call")
+
+    thunk_overhead = (call_thunk_delta - thunk_delta)
+    add_overhead = call_add_delta - add_delta
+    print(f"call overhead for thunk: {thunk_overhead:.4f} ({100 * thunk_overhead / thunk_delta:.2f}%)  |   {thunk_overhead / 10000:.8f} per call")  # noqa: E501
+    print(f"call overhead for add  : {add_overhead:.4f} ({100 * add_overhead / add_delta:.2f}%)  |   {add_overhead / 10000:.8f} per call")  # noqa: E501
+
+
+def bench_fn(runtime, module, fn_name, fn_args, times):
+    func_addr = _get_fn_address(runtime, module, fn_name)
+    start_at = time.perf_counter()
+    for _ in range(times):
+        runtime.invoke_function(func_addr, fn_args)
+    end_at = time.perf_counter()
+    delta = end_at - start_at
+    signature = f"{fn_name}{fn_args}"
+    print(f"{signature.ljust(22)} x {str(times).rjust(10)}: {delta:.4f}  |  {delta / times:.4f} per-call")  # noqa: E501
+    return delta
+
+
+if __name__ == '__main__':
+    bench()
diff --git a/tox.ini b/tox.ini
@@ -1,6 +1,6 @@
 [tox]
 envlist=
-    py{36,37,py3}-{core,spec}
+    py{36,37,py3}-{core,spec,benchmark}
     lint
     doctest
 
@@ -24,6 +24,7 @@ usedevelop=True
 commands=
     core: pytest {posargs:tests/core}
     spec: pytest {posargs:tests/spec}
+    benchmark: python scripts/benchmark/run.py
     doctest: make -C {toxinidir}/docs doctest
 basepython =
     doctest: python
diff --git a/wasm/tools/fixtures/runner.py b/wasm/tools/fixtures/runner.py
@@ -4,6 +4,7 @@
 from pathlib import (
     Path,
 )
+import time
 from typing import (
     Any,
     Callable,
@@ -386,22 +387,29 @@ def run_fixture_test(fixture_path: Path,
 
     module = None
 
-    logger.info("Finished test fixture: %s", fixture.file_path.name)
+    logger.info("Test fixture: %s", fixture.file_path.name)
 
     all_modules = copy.copy(runtime.modules)
 
     for idx, command in enumerate(fixture.commands):
-        logger.debug("running command: line=%d  type=%s", command.line, str(type(command)))
+        logger.info("command: line=%d  type=%s", command.line, str(type(command)))
 
         command_fn = get_command_fn(command)
 
+        start_at = time.perf_counter()
         result = command_fn(command, module, all_modules, runtime)
+        end_at = time.perf_counter()
 
         if result:
             module = result
-        logger.debug("Finished command: line=%d  type=%s", command.line, str(type(command)))
+        logger.info(
+            "finished command: line=%d  type=%s  took=%f",
+            command.line,
+            str(type(command)),
+            end_at - start_at,
+        )
 
         if stop_after is not None and command.line >= stop_after:
             break
 
-    logger.debug("Finished test fixture: %s", fixture.file_path.name)
+    logger.info("Finished test fixture: %s", fixture.file_path.name)
