Add syscall count benchmark for 002_hello.ts (#820)

* Add syscall count tracking for benchmark

* Add fetch_deps thread benchmark

* Switch to `strace -c` for syscall parsing

* Spawn http_server during benchmark (for fetch)

* Rename `benchmarks` to `exec_time_benchmarks`

* Update app_test.js

tools/benchmark.py

@@ -12,11 +12,17 @@ import time
 import shutil
 from util import run, run_output, root_path, build_path
 import tempfile
+import http_server
+
+try:
+    http_server.spawn()
+except:
+    "Warning: another http_server instance is running"
 
 # The list of the tuples of the benchmark name and arguments
-benchmarks = [("hello", ["tests/002_hello.ts", "--reload"]),
-              ("relative_import", ["tests/003_relative_import.ts",
-                                   "--reload"])]
+exec_time_benchmarks = [("hello", ["tests/002_hello.ts", "--reload"]),
+                        ("relative_import",
+                         ["tests/003_relative_import.ts", "--reload"])]
 
 gh_pages_data_file = "gh-pages/data.json"
 data_file = "website/data.json"
@@ -45,23 +51,67 @@ def import_data_from_gh_pages():
         write_json(data_file, [])  # writes empty json data
 
 
-# run strace with test_args and record times a syscall record appears in out file
-# based on syscall_line_matcher. Should be reusable
-def count_strace_syscall(syscall_name, syscall_line_matcher, test_args):
+def get_strace_summary_text(test_args):
     f = tempfile.NamedTemporaryFile()
-    run(["strace", "-f", "-o", f.name, "-e", "trace=" + syscall_name] +
-        test_args)
-    return len(filter(syscall_line_matcher, f))
+    run(["strace", "-c", "-f", "-o", f.name] + test_args)
+    return f.read()
+
+
+def strace_parse(summary_text):
+    summary = {}
+    # clear empty lines
+    lines = list(filter(lambda x: x and x != "\n", summary_text.split("\n")))
+    if len(lines) < 4:
+        return {}  # malformed summary
+    lines, total_line = lines[2:-2], lines[-1]
+    # data to dict for each line
+    for line in lines:
+        syscall_fields = line.split()
+        syscall_name = syscall_fields[-1]
+        syscall_dict = {}
+        if 5 <= len(syscall_fields) <= 6:
+            syscall_dict = {
+                "% time": float(syscall_fields[0]),
+                "seconds": float(syscall_fields[1]),
+                "usecs/call": int(syscall_fields[2]),
+                "calls": int(syscall_fields[3])
+            }
+            syscall_dict["errors"] = 0 if len(syscall_fields) < 6 else int(
+                syscall_fields[4])
+        summary[syscall_name] = syscall_dict
+    # record overall (total) data
+    total_fields = total_line.split()
+    summary["total"] = {
+        "% time": float(total_fields[0]),
+        "seconds": float(total_fields[1]),
+        "calls": int(total_fields[2]),
+        "errors": int(total_fields[3])
+    }
+    return summary
+
+
+def get_strace_summary(test_args):
+    return strace_parse(get_strace_summary_text(test_args))
 
 
 def run_thread_count_benchmark(deno_path):
     thread_count_map = {}
-    thread_count_map["set_timeout"] = count_strace_syscall(
-        "clone", lambda line: "clone(" in line,
-        [deno_path, "tests/004_set_timeout.ts", "--reload"]) + 1
+    thread_count_map["set_timeout"] = get_strace_summary([
+        deno_path, "tests/004_set_timeout.ts", "--reload"
+    ])["clone"]["calls"] + 1
+    thread_count_map["fetch_deps"] = get_strace_summary([
+        deno_path, "tests/fetch_deps.ts", "--reload", "--allow-net"
+    ])["clone"]["calls"] + 1
     return thread_count_map
 
 
+def run_syscall_count_benchmark(deno_path):
+    syscall_count_map = {}
+    syscall_count_map["hello"] = get_strace_summary(
+        [deno_path, "tests/002_hello.ts", "--reload"])["total"]["calls"]
+    return syscall_count_map
+
+
 def main(argv):
     if len(argv) == 2:
         build_dir = sys.argv[1]
@@ -77,8 +127,9 @@ def main(argv):
     os.chdir(root_path)
     import_data_from_gh_pages()
     # TODO: Use hyperfine in //third_party
-    run(["hyperfine", "--export-json", benchmark_file, "--warmup", "3"] +
-        [deno_path + " " + " ".join(args) for [_, args] in benchmarks])
+    run(["hyperfine", "--export-json", benchmark_file, "--warmup", "3"] + [
+        deno_path + " " + " ".join(args) for [_, args] in exec_time_benchmarks
+    ])
     all_data = read_json(data_file)
     benchmark_data = read_json(benchmark_file)
     sha1 = run_output(["git", "rev-parse", "HEAD"]).strip()
@@ -87,9 +138,11 @@ def main(argv):
         "sha1": sha1,
         "binary_size": os.path.getsize(deno_path),
         "thread_count": {},
+        "syscall_count": {},
         "benchmark": {}
     }
-    for [[name, _], data] in zip(benchmarks, benchmark_data["results"]):
+    for [[name, _], data] in zip(exec_time_benchmarks,
+                                 benchmark_data["results"]):
         new_data["benchmark"][name] = {
             "mean": data["mean"],
             "stddev": data["stddev"],
@@ -102,6 +155,7 @@ def main(argv):
     if "linux" in sys.platform:
         # Thread count test, only on linux
         new_data["thread_count"] = run_thread_count_benchmark(deno_path)
+        new_data["syscall_count"] = run_syscall_count_benchmark(deno_path)
 
     all_data.append(new_data)
     write_json(data_file, all_data)

tools/benchmark_test.py

 import sys
 import os
-from benchmark import run_thread_count_benchmark
+import benchmark
+
+
+def strace_parse_test():
+    with open(os.path.join(sys.path[0], "testdata/strace_summary.out"),
+              "r") as f:
+        summary = benchmark.strace_parse(f.read())
+        # first syscall line
+        assert summary["munmap"]["calls"] == 60
+        assert summary["munmap"]["errors"] == 0
+        # line with errors
+        assert summary["mkdir"]["errors"] == 2
+        # last syscall line
+        assert summary["prlimit64"]["calls"] == 2
+        assert summary["prlimit64"]["% time"] == 0
+        # summary line
+        assert summary["total"]["calls"] == 704
+
+
+def thread_count_test(deno_path):
+    thread_count_dict = benchmark.run_thread_count_benchmark(deno_path)
+    assert "set_timeout" in thread_count_dict
+    assert thread_count_dict["set_timeout"] > 1
+
+
+def syscall_count_test(deno_path):
+    syscall_count_dict = benchmark.run_syscall_count_benchmark(deno_path)
+    assert "hello" in syscall_count_dict
+    assert syscall_count_dict["hello"] > 1
 
 
 def benchmark_test(deno_path):
+    strace_parse_test()
     if "linux" in sys.platform:
-        thread_count_dict = run_thread_count_benchmark(deno_path)
-        assert "set_timeout" in thread_count_dict
-        assert thread_count_dict["set_timeout"] > 1
+        thread_count_test(deno_path)
+        syscall_count_test(deno_path)

tools/testdata/strace_summary.out

+% time     seconds  usecs/call     calls    errors syscall
+------ ----------- ----------- --------- --------- ----------------
+ 65.76    0.005881          98        60           munmap
+ 13.79    0.001233           2       462           mprotect
+  7.13    0.000638          11        56           mmap
+  3.57    0.000319          22        14           openat
+  1.65    0.000148          10        14           fstat
+  1.58    0.000141           7        20           read
+  1.53    0.000137           7        18           close
+  1.49    0.000133          16         8           madvise
+  1.10    0.000098          98         1           execve
+  0.30    0.000027           9         3           prctl
+  0.29    0.000026          26         1         1 access
+  0.25    0.000022          11         2         2 mkdir
+  0.23    0.000021           7         3           write
+  0.18    0.000016           4         4           set_robust_list
+  0.16    0.000014           7         2           brk
+  0.15    0.000013          13         1           pipe2
+  0.11    0.000010           3         3           clone
+  0.11    0.000010           3         3           sigaltstack
+  0.10    0.000009           4         2           stat
+  0.10    0.000009           9         1           arch_prctl
+  0.10    0.000009           9         1           epoll_create1
+  0.09    0.000008           8         1           epoll_ctl
+  0.08    0.000007           3         2           getrandom
+  0.04    0.000004           4         1           getcwd
+  0.04    0.000004           2         2           sched_getaffinity
+  0.03    0.000003           3         1         1 ioctl
+  0.03    0.000003           1         3           futex
+  0.00    0.000000           0         1           open
+  0.00    0.000000           0         5           rt_sigaction
+  0.00    0.000000           0         1           rt_sigprocmask
+  0.00    0.000000           0         1           fcntl
+  0.00    0.000000           0         1         1 readlink
+  0.00    0.000000           0         1           set_tid_address
+  0.00    0.000000           0         3           epoll_wait
+  0.00    0.000000           0         2           prlimit64
+------ ----------- ----------- --------- --------- ----------------
+100.00    0.008943                   704         5 total

website/app.js

@@ -20,7 +20,7 @@ export function createBinarySizeColumns(data) {
   return [["binary_size", ...data.map(d => d.binary_size || 0)]];
 }
 
-const threadCountNames = ["set_timeout"];
+const threadCountNames = ["set_timeout", "fetch_deps"];
 export function createThreadCountColumns(data) {
   return threadCountNames.map(name => [
     name,
@@ -34,6 +34,20 @@ export function createThreadCountColumns(data) {
   ]);
 }
 
+const syscallCountNames = ["hello"];
+export function createSyscallCountColumns(data) {
+  return syscallCountNames.map(name => [
+    name,
+    ...data.map(d => {
+      const syscallCountData = d["syscall_count"];
+      if (!syscallCountData) {
+        return 0;
+      }
+      return syscallCountData[name] || 0;
+    })
+  ]);
+}
+
 export function createSha1List(data) {
   return data.map(d => d.sha1);
 }
@@ -55,6 +69,7 @@ export async function main() {
   const execTimeColumns = createExecTimeColumns(data);
   const binarySizeColumns = createBinarySizeColumns(data);
   const threadCountColumns = createThreadCountColumns(data);
+  const syscallCountColumns = createSyscallCountColumns(data);
   const sha1List = createSha1List(data);
 
   c3.generate({
@@ -94,4 +109,15 @@ export async function main() {
       }
     }
   });
+
+  c3.generate({
+    bindto: "#syscall-count-chart",
+    data: { columns: syscallCountColumns },
+    axis: {
+      x: {
+        type: "category",
+        categories: sha1List
+      }
+    }
+  });
 }

website/app_test.js

@@ -5,6 +5,7 @@ import {
   createBinarySizeColumns,
   createExecTimeColumns,
   createThreadCountColumns,
+  createSyscallCountColumns,
   createSha1List,
   formatBytes
 } from "./app.js";
@@ -23,7 +24,11 @@ const regularData = [
       }
     },
     thread_count: {
-      set_timeout: 4
+      set_timeout: 4,
+      fetch_deps: 6
+    },
+    syscall_count: {
+      hello: 600
     }
   },
   {
@@ -39,7 +44,11 @@ const regularData = [
       }
     },
     thread_count: {
-      set_timeout: 5
+      set_timeout: 5,
+      fetch_deps: 7
+    },
+    syscall_count: {
+      hello: 700
     }
   }
 ];
@@ -52,7 +61,8 @@ const irregularData = [
       hello: {},
       relative_import: {}
     },
-    thread_count: {}
+    thread_count: {},
+    syscall_count: {}
   },
   {
     created_at: "2018-02-01T01:00:00Z",
@@ -86,12 +96,22 @@ test(function createBinarySizeColumnsIrregularData() {
 
 test(function createThreadCountColumnsRegularData() {
   const columns = createThreadCountColumns(regularData);
-  assertEqual(columns, [["set_timeout", 4, 5]]);
+  assertEqual(columns, [["set_timeout", 4, 5], ["fetch_deps", 6, 7]]);
 });
 
 test(function createThreadCountColumnsIrregularData() {
   const columns = createThreadCountColumns(irregularData);
-  assertEqual(columns, [["set_timeout", 0, 0]]);
+  assertEqual(columns, [["set_timeout", 0, 0], ["fetch_deps", 0, 0]]);
+});
+
+test(function createSyscallCountColumnsRegularData() {
+  const columns = createSyscallCountColumns(regularData);
+  assertEqual(columns, [["hello", 600, 700]]);
+});
+
+test(function createSyscallCountColumnsIrregularData() {
+  const columns = createSyscallCountColumns(irregularData);
+  assertEqual(columns, [["hello", 0, 0]]);
 });
 
 test(function createSha1ListRegularData() {

website/index.html

@@ -11,6 +11,8 @@
   <div id="binary-size-chart"></div>
   <h2>Thread count chart</h2>
   <div id="thread-count-chart"></div>
+  <h2>Syscall count chart</h2>
+  <div id="syscall-count-chart"></div>
   <script src="https://unpkg.com/d3@5.7.0/dist/d3.min.js"></script>
   <script src="https://unpkg.com/c3@0.6.7/c3.min.js"></script>
   <script type="module">