diff --git a/CHANGELOG.md b/CHANGELOG.md index d9a32923..072b0a70 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -14,6 +14,11 @@ ## Unreleased +- Changed (runtime, no promise changes): on Apple platforms the clock that + measures a yielding kernel's slices reads `mach_absolute_time` instead of + the ERTS monotonic clock. A yielding kernel's call cost about 20 ns less + (a tiny call 37 -> 21 ns); the slice length, the yields and the resume + paths are the same. Other platforms keep the ERTS clock. - Added (unstable, the fast-path report's facts): the `:check` topic. Each i64 `+`, `-` and `*` notes whether its overflow check was dropped or kept, and each store into an element type narrower than the value's diff --git a/README.md b/README.md index 380b5edc..e72b4d64 100644 --- a/README.md +++ b/README.md @@ -29,7 +29,7 @@ measurement rules are in [`examples/README.md`](https://github.com/DanielLuning/ what is planned and what stays out by design. -Speedups over an optimised Elixir baseline, measured end to end on Apple M4 Pro from 2026-10-19 to 2026-10-20 (one machine, so measure your own job). โœ… defk helps; ๐ŸŸก and โŒ use Elixir. +Speedups over an optimised Elixir baseline, measured end to end on Apple M4 Pro from 2026-10-19 to 2026-10-21 (one machine, so measure your own job). โœ… defk helps; ๐ŸŸก and โŒ use Elixir. | | The job | defk vs best Elixir | |---|---|---| @@ -47,9 +47,9 @@ Speedups over an optimised Elixir baseline, measured end to end on Apple M4 Pro | โœ… | an early-exit loop (the first packet past a byte budget), where Nx with EXLA pays ~40 ยตs a call and recompiles per shape | 2.5ร— | | โœ… | a fuzzy-search web service, Myers bit-parallel on both sides: `/health` latency stays at Elixir's while a blocking NIF raises it | [its own measurement](https://github.com/DanielLuning/defk/blob/main/examples/fuzzy_search/README.md) | | ๐ŸŸก | a dictionary-wide Levenshtein batch over all schedulers: Myers bit-parallel in Elixir is close | 1.5ร— | -| ๐ŸŸก | small WebSocket frames, UTF-8 validation, substring search: the BIFs are native already | 1.0โ€“1.5ร— | +| ๐ŸŸก | small WebSocket frames, UTF-8 validation, substring search: the BIFs are native already | 1.1โ€“1.5ร— | | โŒ | anything `:crypto` does (a SHA-256 chain) and memory-hard password hashing (Argon2: the C runs its lanes on threads) | 0.27โ€“0.57ร— | -| โŒ | one kernel call per element | 0.28ร— | +| โŒ | one kernel call per element | 0.29ร— | | โŒ | data that arrives as lists: packing costs more than the whole `Enum.sum` | 0.07ร— | | โ›” | maps and string building | not expressible (a string literal is a read-only `[u8]`) | diff --git a/bench/call_cost.exs b/bench/call_cost.exs new file mode 100644 index 00000000..04fd0698 --- /dev/null +++ b/bench/call_cost.exs @@ -0,0 +1,278 @@ +# The base cost of a kernel call, broken down by stage: the BEAM's NIF call +# (a bare NIF), argument decoding and result encoding, defk's entry (the +# sigsetjmp, the thread-local store pair, the frame fields, the slice init), +# a yielding kernel's clock read, and the generated Elixir function with its +# run-queue hint. The stages are measured on the generated C itself: the +# bench module's C is varied with string replacements, each variant built +# and loaded as its own library. docs/performance.md 5.1. +# +# mix run bench/call_cost.exs [rounds] +# +# Each row is the median over the rounds of (ns per call over n calls) minus +# the empty loop, rounds interleaved. Other processes' CPU is printed before +# each block (Defk.Bench.other_cpu/0): at most one core counts as quiet. +rounds = String.to_integer(List.first(System.argv()) || "9") +n = 1_000_000 + +defmodule CallCost.Kernels do + use Defk + + # the snapshot's kernel: two i64 in, one out, no loop: the NIF is the function + defk add(a :: i64, b :: i64) :: i64 do + a + b + end + + # poor_tiny_calls' kernel: three f64 in, one out + defk clamp(x :: f64, lo :: f64, hi :: f64) :: f64 do + min(max(x, lo), hi) + end + + # one array argument: the bind (inspect, alignment check) + defk len(p :: [i64]) :: i64 do + length(p) + end + + # one loop, one trip: a yielding kernel, so its function reads the + # run-queue hint and the entry reads the clock + defk loop1(n :: i64) :: i64 do + for i <- 0..(n - 1)//1, reduce: 0 do + acc -> acc + i + end + end +end + +defmodule CallCost.NoAdaptive do + use Defk, adaptive_slice: false + + # the same loop without the hint: the NIF is the function, the clock stays + defk loop1(n :: i64) :: i64 do + for i <- 0..(n - 1)//1, reduce: 0 do + acc -> acc + i + end + end +end + +defmodule CallCost.NoYield do + use Defk + + # the same loop with no safepoints: no clock, no resume preamble + defk loop1(n :: i64) :: i64, yield: false do + for i <- 0..(n - 1)//1, reduce: 0 do + acc -> acc + i + end + end +end + +defmodule CallCost.Elixir do + def add(a, b), do: a + b +end + +# ---- the floor: plain NIFs ------------------------------------------------- + +defmodule CallCost.Floor do + @so Path.join(System.tmp_dir!(), "defk_call_cost_floor") + @on_load :load + def load do + args = + ~w(-O3 -std=gnu11 -fPIC -shared -I) ++ + [Defk.Build.erts_include(), "-o", @so <> ".so", "bench/call_cost_nif.c"] ++ + if(match?({:unix, :darwin}, :os.type()), do: ~w(-undefined dynamic_lookup), else: []) + + {_, 0} = System.cmd("cc", args) + :erlang.load_nif(String.to_charlist(@so), 0) + end + + def bare(_), do: :erlang.nif_error(:not_loaded) + def add2(_, _), do: :erlang.nif_error(:not_loaded) + def add2_jmp(_, _), do: :erlang.nif_error(:not_loaded) + def add2_clock(_, _), do: :erlang.nif_error(:not_loaded) + def clock_enif(_), do: :erlang.nif_error(:not_loaded) + def clock_posix(_), do: :erlang.nif_error(:not_loaded) + def clock_fast(_), do: :erlang.nif_error(:not_loaded) +end + +# ---- variants of the generated C -------------------------------------------- + +defmodule CallCost.Variant do + @moduledoc false + # `edits` is a list of {from, to} applied to CallCost.Kernels' C; every + # `from` must occur, so a change in the generated text fails loudly. + def build(name, edits) do + mod = Module.concat(CallCost, name) + src = CallCost.Kernels.__defk_c_source__() + + src = + Enum.reduce([{"Elixir.CallCost.Kernels", Atom.to_string(mod)} | edits], src, fn {from, to}, + s -> + unless String.contains?(s, from), + do: raise("variant #{name}: #{inspect(from)} not in the C") + + String.replace(s, from, to) + end) + + {:ok, base} = Defk.Build.library(mod, src, __ENV__.file) + + Module.create( + mod, + quote do + @on_load :load + def load, do: :erlang.load_nif(String.to_charlist(unquote(base)), 0) + def add(_, _), do: :erlang.nif_error(:not_loaded) + def clamp(_, _, _), do: :erlang.nif_error(:not_loaded) + def len(_), do: :erlang.nif_error(:not_loaded) + def __defk_native_loop1__(_, _), do: :erlang.nif_error(:not_loaded) + def __defk_stats__, do: :erlang.nif_error(:not_loaded) + def __defk_force_yields__(_), do: :erlang.nif_error(:not_loaded) + end, + Macro.Env.location(__ENV__) + ) + + mod + end +end + +# the guard's sigsetjmp (an error would then longjmp into garbage: no call here raises) +nojmp = [{"if (sigsetjmp(F->ctx.jb, 0)) { *defk_slot = NULL; return DEFK_ERR; }\n", ""}] +# the thread-local store pair of fault containment (ADR-0009) +notls = [ + {"defk_ctx **defk_slot = &defk_cur_ctx; /* one thread-local lookup per call */\n", ""}, + {"*defk_slot = &F->ctx;\n", ""}, + {"{ *defk_slot = NULL; return DEFK_ERR; }", "{ return DEFK_ERR; }"}, + {"*defk_slot = NULL;\n", ""} +] + +# the clock read at a yielding kernel's entry (one trip never reaches a tick) +noclock = [ + {"defk_clock_init(&defk_clk, ctx);", + "defk_clk.last = 0; defk_clk.unreported = 0; defk_clk.ctx = ctx;"} +] + +# the slice init (the hint's decode) of loop1's entry +noslice = [ + {"defk_slice_init(env, &local.ctx, argc > 1 ? &argv[1] : NULL);", + "local.ctx.slice_us = DEFK_SLICE_US; local.ctx.short_left = 0;"} +] + +_ = CallCost.Variant.build(:NoJmp, nojmp) +_ = CallCost.Variant.build(:NoTls, notls) +_ = CallCost.Variant.build(:NoClock, noclock) +_ = CallCost.Variant.build(:NoSlice, noslice) +# the stores go first: the sigsetjmp line then reads `{ return DEFK_ERR; }` +_ = + CallCost.Variant.build( + :None, + notls ++ [{"if (sigsetjmp(F->ctx.jb, 0)) { return DEFK_ERR; }\n", ""}] ++ noclock ++ noslice + ) + +# ---- the measurement --------------------------------------------------------- + +defmodule CallCost.Time do + def loop(_f, 0), do: :ok + + def loop(f, k) do + f.() + loop(f, k - 1) + end + + def ns(f, n) do + {us, _} = :timer.tc(fn -> loop(f, n) end) + us * 1000 / n + end + + def median(l), do: Enum.at(Enum.sort(l), div(length(l), 2)) + + # interleaved: each round runs every row once; the empty loop is subtracted + def block(title, rows, n, rounds) do + IO.puts("\n#{title} (other CPU: #{Float.round(Defk.Bench.other_cpu() * 1.0, 2)} cores)") + rows = rows ++ [{"empty loop", fn -> :ok end}] + + res = + for _ <- 1..rounds, {name, f} <- rows, reduce: %{} do + acc -> Map.update(acc, name, [ns(f, n)], &[ns(f, n) | &1]) + end + + empty = median(res["empty loop"]) + + for {name, _} <- rows, name != "empty loop" do + IO.puts( + " #{String.pad_trailing(name, 58)} #{Float.round(median(res[name]) - empty, 1) |> :erlang.float_to_binary(decimals: 1) |> String.pad_leading(6)} ns" + ) + end + end +end + +alias CallCost.{Kernels, NoAdaptive, NoYield, Floor} +p = <<1::64-native>> + +# every row gives the same answer as its kernel +3 = Kernels.add(1, 2) +3 = Floor.add2(1, 2) +3 = CallCost.None.add(1, 2) +0 = Kernels.loop1(1) +0 = NoAdaptive.loop1(1) +0 = NoYield.loop1(1) +0 = CallCost.None.__defk_native_loop1__(1, 0) +1 = Kernels.len(p) +5.0 = Kernels.clamp(5.0, -10.0, 90.0) + +IO.puts( + "call cost: n = #{n} calls per row, median of #{rounds} interleaved rounds, minus the empty loop" +) + +IO.puts( + "#{:erlang.system_info(:system_architecture)}, OTP #{:erlang.system_info(:otp_release)}, Elixir #{System.version()}, #{System.schedulers_online()} schedulers" +) + +CallCost.Time.block( + "1. the floor and the non-yielding kernels", + [ + {"Elixir remote call add/2", fn -> CallCost.Elixir.add(1, 2) end}, + {"bare NIF (returns its argument)", fn -> Floor.bare(1) end}, + {"plain NIF add2 (decode two i64, encode one)", fn -> Floor.add2(1, 2) end}, + {"plain NIF add2 + sigsetjmp", fn -> Floor.add2_jmp(1, 2) end}, + {"defk add/2 (the kernel as generated)", fn -> Kernels.add(1, 2) end}, + {"defk add/2 without the sigsetjmp", fn -> CallCost.NoJmp.add(1, 2) end}, + {"defk add/2 without the thread-local stores", fn -> CallCost.NoTls.add(1, 2) end}, + {"defk add/2 without both", fn -> CallCost.None.add(1, 2) end}, + {"defk clamp/3 (three f64 in, f64 out)", fn -> Kernels.clamp(5.0, -10.0, 90.0) end}, + {"defk len/1 (one [i64] argument)", fn -> Kernels.len(p) end} + ], + n, + rounds +) + +CallCost.Time.block( + "2. a yielding kernel with one loop trip", + [ + {"defk add/2 (no loop, for reference)", fn -> Kernels.add(1, 2) end}, + {"loop1 with yield: false (no safepoints)", fn -> NoYield.loop1(1) end}, + {"loop1 with adaptive_slice: false (NIF direct, clock read)", fn -> NoAdaptive.loop1(1) end}, + {"loop1 (default: function + hint BIF + NIF + clock read)", fn -> Kernels.loop1(1) end}, + {"loop1's NIF called directly with hint 0", fn -> Kernels.__defk_native_loop1__(1, 0) end}, + {"loop1's NIF called directly with hint 5 (short slice)", + fn -> Kernels.__defk_native_loop1__(1, 5) end}, + {"loop1's NIF without the clock read", + fn -> CallCost.NoClock.__defk_native_loop1__(1, 0) end}, + {"loop1's NIF without the slice init", + fn -> CallCost.NoSlice.__defk_native_loop1__(1, 0) end}, + {"loop1's NIF without clock, slice init, sigsetjmp, TLS", + fn -> CallCost.None.__defk_native_loop1__(1, 0) end}, + {"the hint BIF alone: statistics(:total_run_queue_lengths)", + fn -> :erlang.statistics(:total_run_queue_lengths) end} + ], + n, + rounds +) + +CallCost.Time.block( + "3. clock reads, each on top of the bare NIF", + [ + {"bare NIF", fn -> Floor.bare(1) end}, + {"enif_monotonic_time(ERL_NIF_USEC)", fn -> Floor.clock_enif(1) end}, + {"clock_gettime(CLOCK_MONOTONIC)", fn -> Floor.clock_posix(1) end}, + {"mach_absolute_time / cntvct_el0 / rdtsc", fn -> Floor.clock_fast(1) end}, + {"plain NIF add2 + enif_monotonic_time", fn -> Floor.add2_clock(1, 2) end} + ], + n, + rounds +) diff --git a/bench/call_cost_nif.c b/bench/call_cost_nif.c new file mode 100644 index 00000000..3f736402 --- /dev/null +++ b/bench/call_cost_nif.c @@ -0,0 +1,89 @@ +/* The floor under a kernel call, as plain NIFs: what the BEAM charges for a + * NIF call before defk's entry code runs, and what each clock read costs. + * Built and loaded by bench/call_cost.exs; docs/performance.md 5.1. */ +#include +#include +#include +#include +#include +#if defined(__APPLE__) +#include +#endif + +/* the bare NIF call: the term goes straight back */ +static ERL_NIF_TERM bare(ErlNifEnv *env, int argc, const ERL_NIF_TERM argv[]) { + (void)env; + (void)argc; + return argv[0]; +} + +/* decode two i64 arguments, encode one: the terms of add/2 */ +static ERL_NIF_TERM add2(ErlNifEnv *env, int argc, const ERL_NIF_TERM argv[]) { + (void)argc; + ErlNifSInt64 a, b; + if (!enif_get_int64(env, argv[0], &a) || !enif_get_int64(env, argv[1], &b)) + return enif_make_badarg(env); + return enif_make_int64(env, a + b); +} + +/* add2 plus a sigsetjmp(jb, 0) on the stack, as the generated guard does */ +static ERL_NIF_TERM add2_jmp(ErlNifEnv *env, int argc, const ERL_NIF_TERM argv[]) { + sigjmp_buf jb; + if (sigsetjmp(jb, 0)) return enif_make_badarg(env); + return add2(env, argc, argv); +} + +/* add2 plus one monotonic clock read, as a yielding kernel's entry does */ +static ERL_NIF_TERM add2_clock(ErlNifEnv *env, int argc, const ERL_NIF_TERM argv[]) { + volatile ErlNifTime t = enif_monotonic_time(ERL_NIF_USEC); + (void)t; + return add2(env, argc, argv); +} + +/* the clock primitives alone, each on top of the bare call */ +static ERL_NIF_TERM clock_enif(ErlNifEnv *env, int argc, const ERL_NIF_TERM argv[]) { + (void)argc; + volatile ErlNifTime t = enif_monotonic_time(ERL_NIF_USEC); + (void)t; + return argv[0]; +} + +static ERL_NIF_TERM clock_posix(ErlNifEnv *env, int argc, const ERL_NIF_TERM argv[]) { + (void)env; + (void)argc; + struct timespec ts; + clock_gettime(CLOCK_MONOTONIC, &ts); + volatile long t = ts.tv_nsec; + (void)t; + return argv[0]; +} + +static ERL_NIF_TERM clock_fast(ErlNifEnv *env, int argc, const ERL_NIF_TERM argv[]) { + (void)env; + (void)argc; +#if defined(__APPLE__) + volatile uint64_t t = mach_absolute_time(); +#elif defined(__aarch64__) + uint64_t v; + __asm__ volatile("mrs %0, cntvct_el0" : "=r"(v)); + volatile uint64_t t = v; +#elif defined(__x86_64__) + volatile uint64_t t = __builtin_ia32_rdtsc(); +#else + volatile uint64_t t = 0; +#endif + (void)t; + return argv[0]; +} + +static ErlNifFunc funcs[] = { + {"bare", 1, bare, 0}, + {"add2", 2, add2, 0}, + {"add2_jmp", 2, add2_jmp, 0}, + {"add2_clock", 2, add2_clock, 0}, + {"clock_enif", 1, clock_enif, 0}, + {"clock_posix", 1, clock_posix, 0}, + {"clock_fast", 1, clock_fast, 0}, +}; + +ERL_NIF_INIT(Elixir.CallCost.Floor, funcs, NULL, NULL, NULL, NULL) diff --git a/docs/beam-nifs.md b/docs/beam-nifs.md index 022f3a5a..230b7764 100644 --- a/docs/beam-nifs.md +++ b/docs/beam-nifs.md @@ -65,7 +65,9 @@ documentation calls yielding "always preferred over the other alternatives". would still block its scheduler for the whole loop. defk therefore decides *to* yield from its own wall-clock safepoints and uses `enif_consume_timeslice` to *charge* the time: every loop back-edge counts - against a budget, `defk_tick` reads `enif_monotonic_time` and adapts that + against a budget, `defk_tick` reads the slice clock (`defk_now_us`: + `mach_absolute_time` on Apple platforms, `enif_monotonic_time` elsewhere; + the ERTS clock cost ~27 ns a read on macOS arm64) and adapts that budget so the clock is read every `DEFK_SLICE_US/10` โ€ฆ `/4` (around `defk_tick` in priv/defk_runtime.h), and a spent budget returns `0`, which makes the loop return `DEFK_YIELD`. `DEFK_SLICE_US` is 250 ยตs diff --git a/docs/performance.md b/docs/performance.md index 9c216ea3..85598b55 100644 --- a/docs/performance.md +++ b/docs/performance.md @@ -1066,7 +1066,8 @@ call keeps 250 us. `use Defk, adaptive_slice: false` turns it off. (the caller's own queue) 60 / 81; `statistics(:run_queue)` 43 / 1954 (it locks every queue); `system_info(:scheduler_id)` alone 3. A tiny yielding call (`count_primes(10)`) goes from 40-43 to 49-58 ns with the total check - and to 102-132 ns with the own-queue check. The NIF API has no run-queue + and to 102-132 ns with the own-queue check (before the cheaper slice clock + of 5.13, which took ~20 ns off every yielding call). The NIF API has no run-queue length, so the check is a BIF call in Elixir. 9 ns is 0.0014% of a 0.65 ms call. - **Lone calls** (`count_primes`, median of 15 interleaved rounds, vs the 250 us slice): 0.65 ms call -0.6 to +0.1% on 12 schedulers, -0.2 to -0.1% @@ -1137,7 +1138,10 @@ def spin(n), do: __defk_native_spin__(n, :erlang.statistics(:total_run_queue_len disagree (see 8.2, open questions). - **Conditions:** results snapshot "noisy, single runs"; ws_masking under load. - **Source:** [results snapshot](https://github.com/DanielLuning/defk/blob/main/docs/project.md#results-snapshot), [`poor_tiny_calls.exs`](https://github.com/DanielLuning/defk/blob/main/examples/poor_tiny_calls.exs), [`ws_masking.exs`](https://github.com/DanielLuning/defk/blob/main/examples/ws_masking.exs), [`hashes.exs`](https://github.com/DanielLuning/defk/blob/main/examples/hashes.exs). -- **Status:** measured; ws_masking provisional. +- **Status:** measured; ws_masking provisional. The per-call figure is + superseded by 5.13: 11-13 ns for a kernel without a loop, 37 ns for a + yielding one before the cheaper slice clock and 21 ns after; the rule + (never call per element) stands. ```elixir @@ -1424,6 +1428,79 @@ question makes several solves, batch it. - **Source:** `defk-oed`, [`bench/tick_gap.exs`](https://github.com/DanielLuning/defk/blob/main/bench/tick_gap.exs), `test/strip_copies_test.exs`. - **Status:** measured, provisional (loaded machine). +### 5.13 Where a call's nanoseconds go: the BEAM's NIF call first, then the clock read of a yielding kernel + +A kernel call stage by stage, measured on the generated C itself: +`bench/call_cost.exs` takes the bench module's C, removes one piece per +variant (the `sigsetjmp`, the fault-containment stores, the entry clock +read, the slice init) and loads each variant as its own library. Each +number is the median of 9 interleaved rounds of 1M calls, minus the empty +loop. The non-yielding figure settles 8.2's per-call question: 11-13 ns, of +which the BEAM's own NIF call and the term decoding are 6. + +- **The floor** (ns): an Elixir remote call 0.2 (inside the loop's noise); a + bare NIF that returns its argument 3.7; a plain NIF that decodes two i64 + and encodes one 6.2; the same with a `sigsetjmp(jb, 0)` 7.7. +- **A non-yielding kernel** (`add/2`, no loop, so the NIF is the function): + 11.5. The `sigsetjmp` is 2.5 of it (9.0 without), the fault-containment + store pair 1.2 (10.3 without), and the frame's field stores, the slice + init, the two `noinline` calls and `defk_finish` about 1.6 (8.2 with + neither). Three f64 in and one out (`clamp/3`, `poor_tiny_calls`' kernel) + 13.0; one `[i64]` argument 11.7. +- **A yielding kernel with one loop trip** (`loop1/1`), before the change: + its NIF alone 33.4; without the entry clock read 11.8, so + `enif_monotonic_time` cost 21.6 per call; the slice init (the hint's + decode) 0; the kernel's function (the hint BIF + `statistics(:total_run_queue_lengths)` and one more call) 3.9 on top, + 37.3 in all; the BIF alone 7.8. The same loop with `yield: false` 10.4. +- **Clock reads** on top of the bare NIF: `enif_monotonic_time(ERL_NIF_USEC)` + 26.7; `clock_gettime(CLOCK_MONOTONIC)` 15.6; `mach_absolute_time` 4.5. +- **The change:** the slice clock is `defk_now_us` in the runtime header. + On Apple platforms it reads `mach_absolute_time`, converted with the + timebase read once per library at load; elsewhere it is still + `enif_monotonic_time` (Linux is not measured; its clock is a vDSO + `clock_gettime`). After (two runs, the second on the final header): the + yielding NIF alone 12.4-12.6 (the clock read 1.2-1.5 over the variant + without it), through its function 21.2-21.6; `add/2` 10.7-11.0, + unchanged within noise. A tiny yielding call went from 37 to 21 ns. What + remains over a non-yielding call is the hint BIF and its function, about + 9 ns, which cannot be skipped without knowing the call is short. +- **Not changed, and why:** the `sigsetjmp` is where an argument error and + a contained fault land; the store pair is fault containment (6.29); the + hint is what spreads short calls (4.9); a kernel with no loop already has + no hint and no clock. The function does nothing but the BIF, so there is + nothing to thin in it. +- **The small-input crossovers, re-measured and stored** (`mix defk.examples + --bench --snapshot`, quiet, the stored rows of 2026-10-19 -> this run): + `ws_masking`, 10,000 frames of 125 B: defk 1.231 -> 1.129 ms (123 -> 113 + ns a frame), the ratio 1.46x -> 1.47x only because the Elixir side also + measured faster this session (1.79 -> 1.66 ms); over bandit_native 1.2x -> + 1.21x; the crossover stays 1024 B. `geohash_crc` one point per call: defk + 1.953 -> 1.657 ms, 1.29x -> 1.58x (pre-registered poor, measured + marginal, accepted by the script's boundary rule: pack two floats and + call, for a 50-bit loop). `poor_tiny_calls` 53 -> 45 ns a call, 0.28x -> + 0.29x: its kernel has no loop, so no clock, and nothing on its path + changed; that is the session-to-session spread. `utf8_valid` 1.04x -> + 1.06x: 16 MB of work per call. An earlier run of the same four, before the + commit, gave ws_masking 1.77x and geohash 1.62x: the ratios move with the + Elixir side's run, the defk times less. +- **Found on the way:** an ERTS clock read is not free of side effects. + `erts_get_monotonic_time` stores the time in the scheduler's data and + resets its reduction counter, and the scheduler bumps its timer wheel from + that stored time. Forced yields (`__defk_force_yields__/1`, the test mode) + charge no reductions, so with the cheap clock nothing advanced the + scheduler's time during a forced-yield kernel, and a test process that + slept 1 ms on the same scheduler woke only when the kernel ended + (`bitstring_test`, "a process killed mid-build"). The forced path now + reads the ERTS clock once per forced yield, as the old slice clock did at + every re-entry; a normal yield charges reductions through + `enif_consume_timeslice`, so the scheduler reads its own clock there. +- **Conditions:** M-series Mac, 12 schedulers, OTP 29, Elixir 1.20.2, Apple + clang, on battery; other processes at 0.1-0.8 cores (the ps quiet test) + before each block; before and after are two runs of the same script. +- **Source:** `defk-25s`, [`bench/call_cost.exs`](https://github.com/DanielLuning/defk/blob/main/bench/call_cost.exs), [`bench/call_cost_nif.c`](https://github.com/DanielLuning/defk/blob/main/bench/call_cost_nif.c); `defk_now_us` in [`priv/defk_runtime.h`](https://github.com/DanielLuning/defk/blob/main/priv/defk_runtime.h). +- **Status:** measured. + --- ## 6. Making a defk kernel fast @@ -2996,11 +3073,14 @@ costs as much as the splits. ### 8.2 Open questions -- **Per-call cost.** Sources give ~10 ns (`poor_tiny_calls`), 12 ns (results snapshot +- **Per-call cost** (settled by 5.13). Sources gave ~10 ns (`poor_tiny_calls`), 12 ns (results snapshot micro-benchmark), ~35 ns more than a NIF call (`hashes`), ~0.1-0.2 us (`per_pair_distance`) and ~0.12-0.13 us (`ws_masking`, under load), and a - bitstring result adds ~0.1 us (`defk-cao`). No source says which costs are - included in each. A single micro-benchmark on a quiet machine would settle it. + bitstring result adds ~0.1 us (`defk-cao`). The quiet breakdown: a kernel + without a loop 11-13 ns (6 of it the BEAM's NIF call and the terms); a + yielding kernel 37 ns, 21 after the cheaper slice clock, the rest the + run-queue hint; a one-buffer result adds ~45 ns (5.2). `hashes`' 35 ns + over siphash's NIF was a yielding kernel's clock read and hint. - **Geohash batch break-even.** The `geohash_crc.exs` header says the encode crossover is about 100 points (1 point 0.5x); its report reason and the catalog row say a batch of 10 breaks even. @@ -3055,4 +3135,5 @@ example or close a workload ticket, add its entries and its line here. `defk-sve`, `defk-sve.1` ([`state-copy-cost.md`](https://github.com/DanielLuning/defk/blob/main/docs/research/state-copy-cost.md)), `defk-ulk`, `defk-ulk.1` ([`simd.md`](https://github.com/DanielLuning/defk/blob/main/docs/research/simd.md)), `defk-33b`, `defk-ulk.4`, `defk-52v.15` ([`cdcl_sat.exs`](https://github.com/DanielLuning/defk/blob/main/examples/cdcl_sat.exs)), `defk-tif`, `defk-gqk`, `defk-6ag`, `defk-7dm` ([`bench/port_roundtrip.exs`](https://github.com/DanielLuning/defk/blob/main/bench/port_roundtrip.exs)), `defk-1ub`, - `defk-o08.2`, `defk-o08.3`, `defk-o08.4`, `defk-o08.5`, `defk-o08.6`. + `defk-o08.2`, `defk-o08.3`, `defk-o08.4`, `defk-o08.5`, `defk-o08.6`, + `defk-w8r.2`, `defk-25s` ([`bench/call_cost.exs`](https://github.com/DanielLuning/defk/blob/main/bench/call_cost.exs)). diff --git a/docs/project.md b/docs/project.md index 2b79da4c..a5cb0d49 100644 --- a/docs/project.md +++ b/docs/project.md @@ -94,6 +94,7 @@ Apple M4 Pro, OTP 29.0.3, Elixir 1.20.2, commit f064e33, 2026-10-13: `bench/demo | call overhead (ns/call) | 1.8 | 13.1 (11.3 ns over the Elixir call; one thread-local store pair of it is fault containment, ADR-0009) | โ€” | | worst 1 ms-ticker gap on one scheduler (ms) | 2.0โ€“2.5 (busy Elixir process; idle 2.0โ€“2.4) | 2.25โ€“2.3 (yielding), 2.3 (loop in a called kernel), 2.3 (early exit), 554 (`yield: false`) | โ€” | +- Call overhead, broken down on 2026-10-21 (`bench/call_cost.exs`, docs/performance.md 5.13): the row above is a kernel without a loop, whose NIF is the function; a plain NIF that decodes the same terms costs 6 ns, so defk adds about 5. A yielding kernel's call cost 37 ns, 22 of it the ERTS clock read at entry; since then the slice clock reads `mach_absolute_time` on Apple platforms and a tiny yielding call is 21 ns, the rest being the run-queue hint. - Safepoint overhead: 2.4-2.7% on `count_primes` (2,065 yields per run, 6.5 ยตs per yield, `bench/yield_cost.exs` on the idle machine), ~0% on branchy nested loops such as the fuzzy_search Levenshtein kernel (20 ms yielding vs 20 ms `yield: false`). - A kernel yields after 250 ยตs of wall time (`DEFK_SLICE_US`). At 1 ms, the limit ERTS allows a NIF, the ticker's worst gap was 3.5 ms. A busy Elixir process yields every few ยตs. Each yield costs a few ยตs of scheduler work (mostly its I/O poll): 2โ€“3% on `count_primes`, which yields ~3,300 times a second, and nothing measurable on fuzzy_search. `bench/tick_gap.exs` and `bench/yield_cost.exs` measure both sides. - Kernel calls are inlined, so a loop in a callee yields too: `count_primes_via_call` (all its work two calls deep) has the yielding kernel's worst tick gap (2.3 ms). Inlining costs `count_primes` nothing measurable: `prime?`'s trial division (up to 1000 trips at 1M) is a flat loop, and since `DEFK_STRIP` went from 512 to 2048 it runs as one plain loop (at 512 it ran in two strips, 6% slower than `yield: false`). diff --git a/examples/README.md b/examples/README.md index 1ab3c0d0..754e69c1 100644 --- a/examples/README.md +++ b/examples/README.md @@ -43,7 +43,7 @@ script tried and what to take from it; the numbers behind them are in each script's header. -Measured on Apple M4 Pro (12 logical cores) in 5 runs, from 2026-10-19 to 2026-10-20. The newest at commit `3602f17d`, OTP 29.0.3, Elixir 1.20.2: `mix defk.examples --bench --only threshold_cross --snapshot --fresh`. A quiet measurement: other processes used at most 1.0 cores before and after it. A row from an earlier run says when it was measured, and at which commit. +Measured on Apple M4 Pro (12 logical cores) in 6 runs, from 2026-10-19 to 2026-10-21. The newest at commit `03771114`, OTP 29.0.3, Elixir 1.20.2: `mix defk.examples --bench --only ws_masking,geohash_crc,poor_tiny_calls,utf8_valid --snapshot`. A quiet measurement: other processes used at most 1.0 cores before and after it. A row from an earlier run says when it was measured, and at which commit. | | Example | The job | defk vs best Elixir | vs the package's NIF | In one line | |---|---|---|---|---|---| @@ -52,8 +52,8 @@ Measured on Apple M4 Pro (12 logical cores) in 5 runs, from 2026-10-19 to 2026-1 | โœ… | [`blake`](blake.exs) (measured 2026-10-19 at `8fa900b7`) | BLAKE2b-512 of 64 KB | **32ร—** | 1.0ร— blake2_elixir (reference C) | BLAKE3 9.9ร— Elixir and 0.61ร— the NEON NIF; against `:crypto`'s BLAKE2b only 1.2ร— | | โœ… | [`matmul`](matmul.exs) (measured 2026-10-19 at `8fa900b7`) | 256ร—256 f64 | **31ร—** | 0.21ร— Nx + EXLA (CPU, from binaries) | Nx with EXLA is 6ร— faster at 256ร—256 and 108ร— at 1024ร—1024; defk wins only at 64ร—64, where EXLA's dispatch and copies cost more than the product | | โœ… | [`image_ops`](image_ops.exs) (measured 2026-10-19 at `8fa900b7`) | bilinear resize 1080p โ†’ 480ร—270 | **14ร—** | โ€“ | YUV420 19ร— and Floyd-Steinberg dither 21ร—; libvips not compared | +| โœ… | [`geohash_crc`](geohash_crc.exs) | geohash encode of 100k points | **14ร—** | โ€“ | decode 18ร—; CRC-16 1.6ร— and CRC-64 2.3ร—; one point per call 1.6ร— | | โœ… | [`cosine_topk`](cosine_topk.exs) (measured 2026-10-19 at `8fa900b7`) | top-10 of 100k ร— 384 f32 embeddings | **13ร—** | 3.2ร— vettore | Nx + EXLA is faster than defk: use it for a plain dot-product top-k | -| โœ… | [`geohash_crc`](geohash_crc.exs) (measured 2026-10-19 at `8fa900b7`) | geohash encode of 100k points | **12ร—** | โ€“ | decode 19ร—; CRC-16 2.2ร— and CRC-64 2.5ร—; one point per call 1.3ร— | | โœ… | [`cdcl_sat`](cdcl_sat.exs) (measured 2026-10-19 at `8fa900b7`) | Crux's whole scenario enumeration, 109 vars | **11ร—** | 3.6ร— Crux on picosat | picosat's search is stronger on hard random 3-SAT, and blocks a scheduler for the whole solve there | | โœ… | [`hll_update_many`](hll_update_many.exs) (measured 2026-10-19 at `8fa900b7`) | 100k hashes into a p = 14 sketch | **10ร—** | 7.5ร— the Rust NIF | the NIF's time is its own packing; fed packed input it is level | | โœ… | [`pcm_mix`](pcm_mix.exs) (measured 2026-10-19 at `8fa900b7`) | 4 PCM streams with clip prevention, 10 ms chunks | **9.7ร—** | 2.7ร— Membrane's NativeAdder | back-to-back NativeAdder calls are never preempted | @@ -69,16 +69,16 @@ Measured on Apple M4 Pro (12 logical cores) in 5 runs, from 2026-10-19 to 2026-1 | โœ… | [`geo_nearest`](geo_nearest.exs) (measured 2026-10-19 at `8fa900b7`) | 10 nearest of 500k locations | **3.2ร—** | โ€“ | 14ร— in one process; a grid prefilter helps both sides | | โœ… | [`numeric_loader`](numeric_loader.exs) (measured 2026-10-20 at `0d6e7c78`) | numeric CSV of 26 MB into packed f64s | **2.7ร—** | โ€“ | a JSON array of numbers 4.0ร—; a fixed number grammar, and NimbleCSV or Jason for anything else | | โœ… | [`cdcl_sat_per_call`](cdcl_sat_per_call.exs) (measured 2026-10-19 at `8fa900b7`) | one SAT solve per call, 26โ€“28 vars | **2.6ร—** | 1.6ร— picosat | โ‰ˆ1ร— on tiny formulas; batch the solves when one question makes several | -| โœ… | [`threshold_cross`](threshold_cross.exs) | first packet past a byte budget, 64k packets | **2.5ร—** | 13ร— Nx + EXLA `while` | EXLA costs ~40 ยตs a call and scales 1.9ร— over 48 callers; Elixir beats it up to ~1M packets | +| โœ… | [`threshold_cross`](threshold_cross.exs) (measured 2026-10-20 at `3602f17d`) | first packet past a byte budget, 64k packets | **2.5ร—** | 13ร— Nx + EXLA `while` | EXLA costs ~40 ยตs a call and scales 1.9ร— over 48 callers; Elixir beats it up to ~1M packets | | โœ… | [`gorilla_encode`](gorilla_encode.exs) (measured 2026-10-19 at `684a3592`) | Gorilla encoding of 100-point blocks | **2.4ร—** | 4.2ร— gorilla_stream's NIF | close to the bar at this size; 4.1ร— at 1M points | | โœ… | [`tape_csv`](tape_csv.exs) (measured 2026-10-20 at `71e29777`) | CSV of 20 MB to NimbleCSV's rows, a fresh process per parse | **2.1ร—** | 0.38ร— rusty_csv | in a long-lived process 0.8โ€“2.1ร— run to run; an [i64] tape of field events is slower than the cleaned copy | | โœ… | [`fuzzy_search/`](fuzzy_search) | a search service over 234k words behind Bandit | its own measurement, see its README | โ€“ | Myers on both sides; `/health` latency stays at Elixir's while a blocking NIF raises it | | ๐ŸŸก | [`batched_levenshtein`](batched_levenshtein.exs) (measured 2026-10-19 at `8fa900b7`) | one query against 234k words, 12 chunks each side | 1.5ร— | 13ร— ex_strsim per pair | Myers bit-parallel in plain Elixir is close; use it | -| ๐ŸŸก | [`ws_masking`](ws_masking.exs) (measured 2026-10-19 at `8fa900b7`) | mask 125-byte WebSocket frames | 1.5ร— | 1.2ร— bandit_native | the call is the cost; 3.4ร— at 1 MiB, crossover 1024 B | +| ๐ŸŸก | [`ws_masking`](ws_masking.exs) | mask 125-byte WebSocket frames | 1.5ร— | 1.2ร— bandit_native | the call is the cost; 3.7ร— at 1 MiB, crossover 1024 B | | ๐ŸŸก | [`poor_substring_search`](poor_substring_search.exs) (measured 2026-10-19 at `8fa900b7`) | a 64-byte needle in 16 MB | 1.1ร— | โ€“ | `:binary.match` is Boyer-Moore in C already | -| ๐ŸŸก | [`utf8_valid`](utf8_valid.exs) (measured 2026-10-19 at `8fa900b7`) | validate 16 MB of UTF-8 | 1.0ร— | โ€“ | `String.valid?` is C already | +| ๐ŸŸก | [`utf8_valid`](utf8_valid.exs) | validate 16 MB of UTF-8 | 1.1ร— | โ€“ | `String.valid?` is C already | | โŒ | [`hash_chain`](hash_chain.exs) (measured 2026-10-19 at `8fa900b7`) | a 10M-step SHA-256 chain | 0.57ร— | โ€“ | `:crypto` runs on the SHA instructions; HMAC rounds 1.5ร— | -| โŒ | [`poor_tiny_calls`](poor_tiny_calls.exs) (measured 2026-10-19 at `8fa900b7`) | one kernel call per element | 0.28ร— | โ€“ | 13 ns per call against 2 ns for an Elixir call | +| โŒ | [`poor_tiny_calls`](poor_tiny_calls.exs) | one kernel call per element | 0.29ร— | โ€“ | 13 ns per call against 2 ns for an Elixir call | | โŒ | [`argon2`](argon2.exs) (measured 2026-10-19 at `8fa900b7`) | Argon2id at argon2_elixir's defaults | 0.27ร— | lane for lane 0.94ร— of the reference C | the C runs its four lanes on threads; the kernel runs them in sequence | | โŒ | [`poor_list_data`](poor_list_data.exs) (measured 2026-10-19 at `8fa900b7`) | the data arrives as a list | 0.07ร— | โ€“ | packing the list costs more than the whole `Enum.sum` | | โ›” | [`out_of_scope_word_count`](out_of_scope_word_count.exs) (measured 2026-10-19 at `8fa900b7`) | strings in, a map out | โ€“ | โ€“ | not expressible: the compiler refuses, as it should | diff --git a/examples/scoreboard.json b/examples/scoreboard.json index 947d52f2..29d637d4 100644 --- a/examples/scoreboard.json +++ b/examples/scoreboard.json @@ -13,7 +13,7 @@ {"name":"cosine_topk","quiet":true,"results":[{"baseline":"optimized","cache":"stored","correct":true,"crossover":1000,"defk_gap_ms":{"max":2.245,"p99":2.245},"defk_ms":3.9,"defk_spread_ms":{"max":4.064,"median":3.965,"runs":5},"elixir_gap_ms":{"max":2.113,"p99":2.094},"elixir_ms":49.83,"elixir_spread_ms":{"max":53.089,"median":51.511,"runs":5},"example":"cosine_topk","expected":"good","native_gap_ms":{"max":2.001,"p99":2.001},"native_label":"vettore 0.3.5 flat, inner product on unit vectors","native_ms":12.511,"native_speedup":3.21,"native_spread_ms":{"max":13.242,"median":12.522,"runs":5},"realistic_size":"100k x 384 f32, k = 10","reason":"f32 widen-multiply-add over a resident packed index, 5-7x the best Elixir and 1.7x vettore's single-threaded NIF, but Nx with EXLA (multithreaded SIMD) is 6-8x faster than defk: for a plain dot-product top-k use Nx+EXLA","speedup":12.78,"stamp":{"c":{"Cosine.Kernels":"075c25c9c93447b5b81b72232208bdfe"},"commit":"8fa900b7","defk":"0.1.0","measured_at":"2026-10-19T11:31:36Z","quiet":{"limit":1.0,"other_cpu":[0.91,0.33],"quiet":true,"waited_s":0}},"sweep":[{"defk_ms":0.219,"elixir_ms":2.384,"size":1000,"speedup":10.89},{"defk_ms":0.543,"elixir_ms":4.492,"size":2500,"speedup":8.27},{"defk_ms":1.385,"elixir_ms":7.786,"size":6300,"speedup":5.62},{"defk_ms":3.427,"elixir_ms":13.506,"size":16000,"speedup":3.94},{"defk_ms":3.012,"elixir_ms":24.953,"size":40000,"speedup":8.28},{"defk_ms":3.811,"elixir_ms":50.438,"size":100000,"speedup":13.23}],"verdict":"good"}],"run":{"command":"mix defk.examples --bench --all --snapshot","commit":"8fa900b7","elixir":"1.20.2","measured_at":"2026-10-19T11:41:41Z","otp":"29.0.3","quiet_limit":1.0},"status":"ok"}, {"name":"fft","quiet":true,"results":[{"baseline":"optimized","cache":"stored","correct":true,"crossover":4096,"defk_gap_ms":{"max":2.516,"p99":2.516},"defk_ms":0.05,"defk_spread_ms":{"max":0.067,"median":0.051,"runs":20},"elixir_gap_ms":{"max":51.611,"p99":5.818},"elixir_ms":4.096,"elixir_spread_ms":{"max":6.978,"median":4.178,"runs":20},"example":"fft","expected":"good","realistic_size":"n = 4096","reason":"butterflies over packed floats in place, where Elixir allocates a tuple or cons cell per value and rebuilds the signal every stage","speedup":81.92,"stamp":{"c":{"FFT.Kernels":"ca48b43c0ecfe5330e7ad85fd546b322"},"commit":"8fa900b7","defk":"0.1.0","measured_at":"2026-10-19T11:32:35Z","quiet":{"limit":1.0,"other_cpu":[0.87,0.53],"quiet":true,"waited_s":33}},"sweep":[{"defk_ms":0.056,"elixir_ms":4.371,"size":4096,"speedup":78.05},{"defk_ms":0.246,"elixir_ms":17.955,"size":16384,"speedup":72.99},{"defk_ms":1.494,"elixir_ms":114.248,"size":65536,"speedup":76.47},{"defk_ms":7.109,"elixir_ms":596.935,"size":262144,"speedup":83.97},{"defk_ms":33.758,"elixir_ms":2126.6,"size":1048576,"speedup":63.0}],"verdict":"good"}],"run":{"command":"mix defk.examples --bench --all --snapshot","commit":"8fa900b7","elixir":"1.20.2","measured_at":"2026-10-19T11:41:41Z","otp":"29.0.3","quiet_limit":1.0},"status":"ok"}, {"name":"geo_nearest","quiet":true,"results":[{"baseline":"optimized","cache":"stored","correct":true,"defk_ms":1.061,"defk_spread_ms":{"max":1.224,"median":1.079,"runs":5},"elixir_ms":3.368,"elixir_spread_ms":{"max":3.765,"median":3.484,"runs":5},"example":"geo_nearest","expected":"good","reason":"float math per candidate over a packed index reused by every query","speedup":3.17,"stamp":{"c":{"Geo.Kernels":"b2124a3692b9bde0b904d21fedfbc2d2"},"commit":"8fa900b7","defk":"0.1.0","measured_at":"2026-10-19T11:32:36Z","quiet":{"limit":1.0,"other_cpu":[0.26,0.26],"quiet":true,"waited_s":0}},"verdict":"good"}],"run":{"command":"mix defk.examples --bench --all --snapshot","commit":"8fa900b7","elixir":"1.20.2","measured_at":"2026-10-19T11:41:41Z","otp":"29.0.3","quiet_limit":1.0},"status":"ok"}, - {"name":"geohash_crc","quiet":true,"results":[{"baseline":"optimized","cache":"stored","correct":true,"crossover":100,"defk_ms":1.615,"defk_spread_ms":{"max":1.638,"median":1.63,"runs":5},"elixir_ms":18.704,"elixir_spread_ms":{"max":19.927,"median":19.211,"runs":5},"example":"geohash_encode","expected":"good","realistic_size":"100k points","reason":"a branch-light integer loop over packed f64 columns: quantise, interleave by bit spreading, write bytes; Elixir is held back by building 100k binaries and boxed floats","speedup":11.58,"stamp":{"c":{"GeoCrc.Kernels":"7c23ba5f0f6d5984d69aaec42f383b3c","GeoCrc.KernelsEM":"a4cc8677626de10c1253b902f9bb5968"},"commit":"8fa900b7","defk":"0.1.0","measured_at":"2026-10-19T11:32:48Z","quiet":{"limit":1.0,"other_cpu":[0.66,0.51],"quiet":true,"waited_s":0}},"sweep":[{"defk_ms":0.002,"elixir_ms":0.0,"size":1,"speedup":0.0},{"defk_ms":0.003,"elixir_ms":0.003,"size":10,"speedup":1.0},{"defk_ms":0.004,"elixir_ms":0.016,"size":100,"speedup":4.0},{"defk_ms":0.019,"elixir_ms":0.127,"size":1000,"speedup":6.68},{"defk_ms":0.164,"elixir_ms":1.244,"size":10000,"speedup":7.59},{"defk_ms":1.58,"elixir_ms":20.76,"size":100000,"speedup":13.14}],"verdict":"good"},{"baseline":"optimized","cache":"stored","correct":true,"crossover":100,"defk_ms":0.63,"defk_spread_ms":{"max":0.706,"median":0.686,"runs":5},"elixir_ms":11.994,"elixir_spread_ms":{"max":28.551,"median":27.829,"runs":5},"example":"geohash_decode","expected":"good","realistic_size":"100k hashes","reason":"the inverse of the encoder: hashes to two cell indices to packed f64 centres; no BEAM terms are built on the kernel side","speedup":19.04,"stamp":{"c":{"GeoCrc.Kernels":"7c23ba5f0f6d5984d69aaec42f383b3c","GeoCrc.KernelsEM":"a4cc8677626de10c1253b902f9bb5968"},"commit":"8fa900b7","defk":"0.1.0","measured_at":"2026-10-19T11:32:49Z","quiet":{"limit":1.0,"other_cpu":[0.72,0.34],"quiet":true,"waited_s":0}},"sweep":[{"defk_ms":0.0,"elixir_ms":0.0,"size":1,"speedup":0.0},{"defk_ms":0.0,"elixir_ms":0.001,"size":10,"speedup":1.0},{"defk_ms":0.001,"elixir_ms":0.013,"size":100,"speedup":13.0},{"defk_ms":0.008,"elixir_ms":0.118,"size":1000,"speedup":14.75},{"defk_ms":0.068,"elixir_ms":1.162,"size":10000,"speedup":17.09},{"defk_ms":0.66,"elixir_ms":11.795,"size":100000,"speedup":17.87}],"verdict":"good"},{"baseline":"optimized","cache":"stored","correct":true,"crossover":65536,"defk_ms":2.013,"defk_spread_ms":{"max":2.131,"median":2.095,"runs":5},"elixir_ms":4.445,"elixir_spread_ms":{"max":4.576,"median":4.539,"runs":5},"example":"crc16","expected":"marginal","native_label":"crc 0.11.0","native_ms":2.745,"native_speedup":1.36,"native_spread_ms":{"max":2.964,"median":2.811,"runs":5},"realistic_size":"1 MB","reason":"a byte-serial table lookup (one dependent load per byte) is about 2 ns per byte natively and the Elixir binary loop is already about 3.6 ns, so the gain is under 2x; :erlang.crc32 (zlib, another polynomial) is 100x faster than both and the crc NIF is no faster than the kernel","speedup":2.21,"stamp":{"c":{"GeoCrc.Kernels":"7c23ba5f0f6d5984d69aaec42f383b3c","GeoCrc.KernelsEM":"a4cc8677626de10c1253b902f9bb5968"},"commit":"8fa900b7","defk":"0.1.0","measured_at":"2026-10-19T11:32:50Z","quiet":{"limit":1.0,"other_cpu":[0.28,0.33],"quiet":true,"waited_s":0}},"sweep":[{"defk_ms":0.002,"elixir_ms":0.0,"size":64,"speedup":0.0},{"defk_ms":0.004,"elixir_ms":0.004,"size":1024,"speedup":1.0},{"defk_ms":0.128,"elixir_ms":0.282,"size":65536,"speedup":2.2},{"defk_ms":2.015,"elixir_ms":4.528,"size":1048576,"speedup":2.25},{"defk_ms":32.603,"elixir_ms":74.219,"size":16777216,"speedup":2.28}],"verdict":"good"},{"baseline":"optimized","cache":"stored","correct":true,"crossover":null,"defk_ms":1.754,"defk_spread_ms":{"max":1.806,"median":1.781,"runs":5},"elixir_ms":4.324,"elixir_spread_ms":{"max":4.439,"median":4.347,"runs":5},"example":"crc64","expected":"marginal","native_label":"crc 0.11.0","native_ms":1.991,"native_speedup":1.14,"native_spread_ms":{"max":2.014,"median":2.0,"runs":5},"realistic_size":"1 MB","reason":"same shape as crc16: the reflected table loop is 1.7-1.9x the best Elixir (two 32-bit halves, since one integer goes bignum and costs 10x), and the crc package NIF is within 1.1-1.4x of the kernel","speedup":2.47,"stamp":{"c":{"GeoCrc.Kernels":"7c23ba5f0f6d5984d69aaec42f383b3c","GeoCrc.KernelsEM":"a4cc8677626de10c1253b902f9bb5968"},"commit":"8fa900b7","defk":"0.1.0","measured_at":"2026-10-19T11:32:51Z","quiet":{"limit":1.0,"other_cpu":[0.33,0.3],"quiet":true,"waited_s":0}},"sweep":[{"defk_ms":0.002,"elixir_ms":0.0,"size":64,"speedup":0.0},{"defk_ms":0.004,"elixir_ms":0.004,"size":1024,"speedup":1.0},{"defk_ms":0.114,"elixir_ms":0.19,"size":65536,"speedup":1.67},{"defk_ms":1.768,"elixir_ms":3.211,"size":1048576,"speedup":1.82},{"defk_ms":28.034,"elixir_ms":51.148,"size":16777216,"speedup":1.82}],"verdict":"good"},{"baseline":"optimized","cache":"stored","correct":true,"defk_ms":1.953,"defk_spread_ms":{"max":2.05,"median":1.97,"runs":5},"elixir_ms":2.527,"elixir_spread_ms":{"max":3.05,"median":2.712,"runs":5},"example":"geohash_encode_single","expected":"poor","realistic_size":"10k calls of 1 point","reason":"one point per call: packing two floats and the call cost more than the 50-bit loop saves; batch the points (a batch of 10 already breaks even)","speedup":1.29,"stamp":{"c":{"GeoCrc.Kernels":"7c23ba5f0f6d5984d69aaec42f383b3c","GeoCrc.KernelsEM":"a4cc8677626de10c1253b902f9bb5968"},"commit":"8fa900b7","defk":"0.1.0","measured_at":"2026-10-19T11:32:51Z","quiet":{"limit":1.0,"other_cpu":[0.38,0.38],"quiet":true,"waited_s":0}},"verdict":"marginal"}],"run":{"command":"mix defk.examples --bench --all --snapshot","commit":"8fa900b7","elixir":"1.20.2","measured_at":"2026-10-19T11:41:41Z","otp":"29.0.3","quiet_limit":1.0},"status":"ok"}, + {"name":"geohash_crc","quiet":true,"results":[{"baseline":"optimized","cache":"stored","correct":true,"crossover":10,"defk_ms":1.523,"defk_spread_ms":{"max":1.552,"median":1.547,"runs":5},"elixir_ms":20.716,"elixir_spread_ms":{"max":21.811,"median":21.469,"runs":5},"example":"geohash_encode","expected":"good","realistic_size":"100k points","reason":"a branch-light integer loop over packed f64 columns: quantise, interleave by bit spreading, write bytes; Elixir is held back by building 100k binaries and boxed floats","speedup":13.6,"stamp":{"c":{"GeoCrc.Kernels":"dfea9ece6c04ddc0c876e33b61dab1ef","GeoCrc.KernelsEM":"ff5f1a0c13f267b14f76c94136c48d8f"},"commit":"03771114","defk":"0.1.0","measured_at":"2026-10-21T19:58:23Z","quiet":{"limit":1.0,"other_cpu":[0.23,0.37],"quiet":true,"waited_s":0}},"sweep":[{"defk_ms":0.0,"elixir_ms":0.0,"size":1,"speedup":0.0},{"defk_ms":0.001,"elixir_ms":0.002,"size":10,"speedup":2.0},{"defk_ms":0.002,"elixir_ms":0.014,"size":100,"speedup":7.0},{"defk_ms":0.019,"elixir_ms":0.129,"size":1000,"speedup":6.79},{"defk_ms":0.152,"elixir_ms":1.412,"size":10000,"speedup":9.29},{"defk_ms":1.533,"elixir_ms":19.658,"size":100000,"speedup":12.82}],"verdict":"good"},{"baseline":"optimized","cache":"stored","correct":true,"crossover":100,"defk_ms":0.639,"defk_spread_ms":{"max":0.695,"median":0.657,"runs":5},"elixir_ms":11.181,"elixir_spread_ms":{"max":27.14,"median":27.013,"runs":5},"example":"geohash_decode","expected":"good","realistic_size":"100k hashes","reason":"the inverse of the encoder: hashes to two cell indices to packed f64 centres; no BEAM terms are built on the kernel side","speedup":17.5,"stamp":{"c":{"GeoCrc.Kernels":"dfea9ece6c04ddc0c876e33b61dab1ef","GeoCrc.KernelsEM":"ff5f1a0c13f267b14f76c94136c48d8f"},"commit":"03771114","defk":"0.1.0","measured_at":"2026-10-21T19:58:24Z","quiet":{"limit":1.0,"other_cpu":[0.37,0.22],"quiet":true,"waited_s":0}},"sweep":[{"defk_ms":0.0,"elixir_ms":0.0,"size":1,"speedup":0.0},{"defk_ms":0.0,"elixir_ms":0.001,"size":10,"speedup":1.0},{"defk_ms":0.001,"elixir_ms":0.013,"size":100,"speedup":13.0},{"defk_ms":0.008,"elixir_ms":0.119,"size":1000,"speedup":14.87},{"defk_ms":0.067,"elixir_ms":1.142,"size":10000,"speedup":17.04},{"defk_ms":0.638,"elixir_ms":11.244,"size":100000,"speedup":17.62}],"verdict":"good"},{"baseline":"optimized","cache":"stored","correct":true,"crossover":null,"defk_ms":2.012,"defk_spread_ms":{"max":2.208,"median":2.151,"runs":5},"elixir_ms":3.319,"elixir_spread_ms":{"max":4.415,"median":3.346,"runs":5},"example":"crc16","expected":"marginal","native_label":"crc 0.11.0","native_ms":2.695,"native_speedup":1.34,"native_spread_ms":{"max":3.089,"median":3.021,"runs":5},"realistic_size":"1 MB","reason":"a byte-serial table lookup (one dependent load per byte) is about 2 ns per byte natively and the Elixir binary loop is already about 3.6 ns, so the gain is under 2x; :erlang.crc32 (zlib, another polynomial) is 100x faster than both and the crc NIF is no faster than the kernel","speedup":1.65,"stamp":{"c":{"GeoCrc.Kernels":"dfea9ece6c04ddc0c876e33b61dab1ef","GeoCrc.KernelsEM":"ff5f1a0c13f267b14f76c94136c48d8f"},"commit":"03771114","defk":"0.1.0","measured_at":"2026-10-21T19:58:25Z","quiet":{"limit":1.0,"other_cpu":[0.22,0.27],"quiet":true,"waited_s":0}},"sweep":[{"defk_ms":0.005,"elixir_ms":0.0,"size":64,"speedup":0.0},{"defk_ms":0.004,"elixir_ms":0.004,"size":1024,"speedup":1.0},{"defk_ms":0.128,"elixir_ms":0.21,"size":65536,"speedup":1.64},{"defk_ms":1.993,"elixir_ms":3.339,"size":1048576,"speedup":1.68},{"defk_ms":32.038,"elixir_ms":54.332,"size":16777216,"speedup":1.7}],"verdict":"marginal"},{"baseline":"optimized","cache":"stored","correct":true,"crossover":65536,"defk_ms":1.782,"defk_spread_ms":{"max":1.807,"median":1.786,"runs":5},"elixir_ms":4.068,"elixir_spread_ms":{"max":4.284,"median":4.178,"runs":5},"example":"crc64","expected":"marginal","native_label":"crc 0.11.0","native_ms":1.997,"native_speedup":1.12,"native_spread_ms":{"max":2.023,"median":2.008,"runs":5},"realistic_size":"1 MB","reason":"same shape as crc16: the reflected table loop is 1.7-1.9x the best Elixir (two 32-bit halves, since one integer goes bignum and costs 10x), and the crc package NIF is within 1.1-1.4x of the kernel","speedup":2.28,"stamp":{"c":{"GeoCrc.Kernels":"dfea9ece6c04ddc0c876e33b61dab1ef","GeoCrc.KernelsEM":"ff5f1a0c13f267b14f76c94136c48d8f"},"commit":"03771114","defk":"0.1.0","measured_at":"2026-10-21T19:58:26Z","quiet":{"limit":1.0,"other_cpu":[0.27,0.18],"quiet":true,"waited_s":0}},"sweep":[{"defk_ms":0.002,"elixir_ms":0.0,"size":64,"speedup":0.0},{"defk_ms":0.004,"elixir_ms":0.004,"size":1024,"speedup":1.0},{"defk_ms":0.113,"elixir_ms":0.252,"size":65536,"speedup":2.23},{"defk_ms":1.782,"elixir_ms":4.168,"size":1048576,"speedup":2.34},{"defk_ms":28.611,"elixir_ms":66.226,"size":16777216,"speedup":2.31}],"verdict":"good"},{"baseline":"optimized","cache":"stored","correct":true,"defk_ms":1.657,"defk_spread_ms":{"max":1.745,"median":1.719,"runs":5},"elixir_ms":2.618,"elixir_spread_ms":{"max":2.862,"median":2.754,"runs":5},"example":"geohash_encode_single","expected":"poor","realistic_size":"10k calls of 1 point","reason":"one point per call: packing two floats and the call cost more than the 50-bit loop saves; batch the points (a batch of 10 already breaks even)","speedup":1.58,"stamp":{"c":{"GeoCrc.Kernels":"dfea9ece6c04ddc0c876e33b61dab1ef","GeoCrc.KernelsEM":"ff5f1a0c13f267b14f76c94136c48d8f"},"commit":"03771114","defk":"0.1.0","measured_at":"2026-10-21T19:58:26Z","quiet":{"limit":1.0,"other_cpu":[0.19,0.19],"quiet":true,"waited_s":0}},"verdict":"marginal"}],"run":{"command":"mix defk.examples --bench --only ws_masking,geohash_crc,poor_tiny_calls,utf8_valid --snapshot","commit":"03771114","elixir":"1.20.2","measured_at":"2026-10-21T19:58:40Z","otp":"29.0.3","quiet_limit":1.0},"status":"ok"}, {"name":"gorilla_encode","quiet":true,"results":[{"baseline":"optimized","cache":"stored","correct":true,"crossover":"100 pts","defk_gap_ms":{"max":2.253,"p99":2.253},"defk_ms":2.481,"defk_spread_ms":{"max":2.593,"median":2.535,"runs":15},"elixir_gap_ms":{"max":2.036,"p99":2.036},"elixir_ms":5.932,"elixir_spread_ms":{"max":6.146,"median":6.029,"runs":15},"example":"gorilla_encode","expected":"good","native_gap_ms":{"max":2.004,"p99":2.004},"native_label":"gorilla_stream 3.0.3 NIF.nif_gorilla_encode","native_ms":10.48,"native_speedup":4.22,"native_spread_ms":{"max":11.49,"median":10.664,"runs":15},"realistic_size":"100-point blocks (a Gorilla/Prometheus chunk), 1,000 series per timed run, one call each","reason":"both bit streams are built by one kernel with the bitstring accumulator; pure Elixir pays per point for bitstring appends and boxed floats","speedup":2.39,"stamp":{"c":{"Gorilla.Kernels":"250e6ef3117c36c63af132804ec1ec20"},"commit":"684a3592","defk":"0.1.0","measured_at":"2026-10-19T11:58:40Z","quiet":{"limit":1.0,"other_cpu":[0.19,0.03],"quiet":true,"waited_s":0}},"sweep":[{"defk_ms":19.865,"elixir_ms":55.624,"size":"100 pts","speedup":2.8},{"defk_ms":12.198,"elixir_ms":60.068,"size":"630 pts","speedup":4.92},{"defk_ms":10.611,"elixir_ms":55.939,"size":"4000 pts","speedup":5.27},{"defk_ms":13.571,"elixir_ms":56.792,"size":"25000 pts","speedup":4.18},{"defk_ms":12.918,"elixir_ms":55.293,"size":"160000 pts","speedup":4.28},{"defk_ms":12.988,"elixir_ms":58.345,"size":"1000000 pts","speedup":4.49}],"verdict":"good"},{"baseline":"optimized","cache":"reused","correct":true,"defk_ms":13.396,"defk_spread_ms":{"max":18.756,"median":14.102,"runs":15},"elixir_ms":54.903,"elixir_spread_ms":{"max":59.886,"median":55.797,"runs":15},"example":"gorilla_encode_1m","expected":"good","measured_at":"2026-10-19T11:35:56Z","native_label":"gorilla_stream 3.0.3 NIF.nif_gorilla_encode","native_ms":33.096,"native_speedup":2.47,"native_spread_ms":{"max":36.79,"median":34.273,"runs":15},"realistic_size":"1M points, one call","reason":"the same job on one 1M-point series; packing the list is ~half of defk's time","speedup":4.1,"stamp":{"c":{"Gorilla.Kernels":"250e6ef3117c36c63af132804ec1ec20"},"commit":"8fa900b7","defk":"0.1.0","measured_at":"2026-10-19T11:35:56Z","quiet":{"limit":1.0,"other_cpu":[0.63,0.53],"quiet":true,"waited_s":2}},"verdict":"good"}],"run":{"command":"mix defk.examples --bench --only codecs,gorilla_encode,monte_carlo_rtp,sort_u64_keys --snapshot","commit":"684a3592","elixir":"1.20.2","measured_at":"2026-10-19T11:59:29Z","otp":"29.0.3","quiet_limit":1.0},"status":"ok"}, {"name":"hash_chain","quiet":true,"results":[{"baseline":"optimized","cache":"stored","correct":true,"crossover":null,"defk_ms":1649.914,"defk_spread_ms":{"max":1661.685,"median":1654.775,"runs":5},"elixir_ms":937.81,"elixir_spread_ms":{"max":1142.52,"median":1137.494,"runs":5},"example":"hash_chain","expected":"poor","realistic_size":"10000000 steps","reason":":crypto.hash/2 is OpenSSL using the CPU's SHA-256 instructions, about 100 ns per step including the call; the kernel is portable C with no intrinsics (about 170 ns per compression), and the call overhead it removes is smaller than the instructions it lacks: use :crypto","speedup":0.57,"stamp":{"c":{"HashChain.Kernels":"461d8bb565bb47045f4e6d1d9463bb02","HashChain.KernelsEM":"5c93cf8120a242870b22acd5e606c253"},"commit":"8fa900b7","defk":"0.1.0","measured_at":"2026-10-19T11:37:06Z","quiet":{"limit":1.0,"other_cpu":[0.08,0.32],"quiet":true,"waited_s":0}},"sweep":[{"defk_ms":0.156,"elixir_ms":0.098,"size":1000,"speedup":0.63},{"defk_ms":16.289,"elixir_ms":9.803,"size":100000,"speedup":0.6},{"defk_ms":164.422,"elixir_ms":96.229,"size":1000000,"speedup":0.59},{"defk_ms":1631.439,"elixir_ms":946.548,"size":10000000,"speedup":0.58}],"verdict":"poor"},{"baseline":"optimized","cache":"stored","correct":true,"crossover":null,"defk_ms":381.839,"defk_spread_ms":{"max":398.667,"median":382.578,"runs":5},"elixir_ms":556.357,"elixir_spread_ms":{"max":626.538,"median":607.226,"runs":5},"example":"hmac_rounds","expected":"marginal","realistic_size":"1000000 nonces","reason":"two compressions per round in portable C against four on the SHA instructions plus two calls: the kernel saves the calls, the message building and the key-pad compressions, 1.3-1.5x; :crypto.mac per round is 1.7-1.9x slower than that RFC 2104 by hand, from its per-call key setup","speedup":1.46,"stamp":{"c":{"HashChain.Kernels":"461d8bb565bb47045f4e6d1d9463bb02","HashChain.KernelsEM":"5c93cf8120a242870b22acd5e606c253"},"commit":"8fa900b7","defk":"0.1.0","measured_at":"2026-10-19T11:37:18Z","quiet":{"limit":1.0,"other_cpu":[0.32,0.07],"quiet":true,"waited_s":0}},"sweep":[{"defk_ms":0.001,"elixir_ms":0.001,"size":1,"speedup":1.0},{"defk_ms":0.041,"elixir_ms":0.034,"size":100,"speedup":0.83},{"defk_ms":3.83,"elixir_ms":4.347,"size":10000,"speedup":1.13},{"defk_ms":382.988,"elixir_ms":533.277,"size":1000000,"speedup":1.39}],"verdict":"marginal"}],"run":{"command":"mix defk.examples --bench --all --snapshot","commit":"8fa900b7","elixir":"1.20.2","measured_at":"2026-10-19T11:41:41Z","otp":"29.0.3","quiet_limit":1.0},"status":"ok"}, {"name":"hashes","quiet":true,"results":[{"baseline":"optimized","cache":"stored","correct":true,"crossover":"1k x 32 B","defk_ms":0.176,"defk_spread_ms":{"max":0.181,"median":0.18,"runs":5},"elixir_ms":35.738,"elixir_spread_ms":{"max":37.559,"median":36.616,"runs":5},"example":"hashes_xxh64","expected":"good","realistic_size":"one 4 MB message","reason":"64-bit multiplies and rotates are bignum work in Elixir; the kernel does them in registers at 10 GB/s","speedup":203.06,"stamp":{"c":{"Hashes.CRC32CPortable":"1829cdec005522c668ddfaf0af6091a0","Hashes.Kernels":"2e2008f5ccf46304f6a5b4c1645ab99f"},"commit":"8fa900b7","defk":"0.1.0","measured_at":"2026-10-19T11:37:25Z","quiet":{"limit":1.0,"other_cpu":[0.11,0.42],"quiet":true,"waited_s":0}},"sweep":[{"defk_ms":0.055,"elixir_ms":1.118,"size":"1k x 32 B","speedup":20.33},{"defk_ms":0.002,"elixir_ms":0.571,"size":"64 KB","speedup":285.5},{"defk_ms":0.179,"elixir_ms":35.878,"size":"4 MB","speedup":200.44}],"verdict":"good"},{"baseline":"optimized","cache":"stored","correct":true,"crossover":"1k x 32 B","defk_ms":0.503,"defk_spread_ms":{"max":0.521,"median":0.506,"runs":5},"elixir_ms":69.011,"elixir_spread_ms":{"max":73.644,"median":73.305,"runs":5},"example":"hashes_murmur3","expected":"good","realistic_size":"one 4 MB message","reason":"the same bignum-versus-register gap as xxHash64; murmur is already a well-written pure version","speedup":137.2,"stamp":{"c":{"Hashes.CRC32CPortable":"1829cdec005522c668ddfaf0af6091a0","Hashes.Kernels":"2e2008f5ccf46304f6a5b4c1645ab99f"},"commit":"8fa900b7","defk":"0.1.0","measured_at":"2026-10-19T11:37:26Z","quiet":{"limit":1.0,"other_cpu":[0.42,0.15],"quiet":true,"waited_s":0}},"sweep":[{"defk_ms":0.071,"elixir_ms":0.803,"size":"1k x 32 B","speedup":11.31},{"defk_ms":0.007,"elixir_ms":1.09,"size":"64 KB","speedup":155.71},{"defk_ms":0.527,"elixir_ms":72.924,"size":"4 MB","speedup":138.38}],"verdict":"good"},{"baseline":"optimized","cache":"stored","correct":true,"crossover":"1k x 32 B","defk_ms":0.074,"defk_spread_ms":{"max":0.105,"median":0.074,"runs":5},"elixir_ms":4.249,"elixir_spread_ms":{"max":7.16,"median":4.387,"runs":5},"example":"hashes_siphash24","expected":"good","native_label":"siphash 3.2.0 C NIF, a call per key","native_ms":0.089,"native_speedup":1.2,"native_spread_ms":{"max":0.121,"median":0.089,"runs":5},"realistic_size":"1k 32-byte keys","reason":"bignum SipRounds in Elixir; the kernel batch is level with siphash's C NIF, so the C buys nothing","speedup":57.42,"stamp":{"c":{"Hashes.CRC32CPortable":"1829cdec005522c668ddfaf0af6091a0","Hashes.Kernels":"2e2008f5ccf46304f6a5b4c1645ab99f"},"commit":"8fa900b7","defk":"0.1.0","measured_at":"2026-10-19T11:37:27Z","quiet":{"limit":1.0,"other_cpu":[0.15,0.11],"quiet":true,"waited_s":0}},"sweep":[{"defk_ms":0.075,"elixir_ms":4.399,"size":"1k x 32 B","speedup":58.65},{"defk_ms":0.02,"elixir_ms":4.61,"size":"64 KB","speedup":230.5},{"defk_ms":1.302,"elixir_ms":302.65,"size":"4 MB","speedup":232.45}],"verdict":"good"},{"baseline":"optimized","cache":"stored","correct":true,"crossover":"64 KB","defk_ms":0.147,"defk_spread_ms":{"max":0.163,"median":0.147,"runs":5},"elixir_ms":2.995,"elixir_spread_ms":{"max":3.131,"median":3.099,"runs":5},"example":"hashes_crc32c","expected":"good","native_label":"crc32cer 1.1.4 (Google crc32c, ARM64 CRC32C instructions)","native_ms":0.12,"native_speedup":0.82,"native_spread_ms":{"max":0.134,"median":0.126,"runs":5},"realistic_size":"one 4 MB message","reason":"the crc32c/3 builtin runs the CRC32C instruction in three streams, level with crc32cer; Elixir slicing-by-8 stays in small integers but does eight lookups per word","speedup":20.37,"stamp":{"c":{"Hashes.CRC32CPortable":"1829cdec005522c668ddfaf0af6091a0","Hashes.Kernels":"2e2008f5ccf46304f6a5b4c1645ab99f"},"commit":"8fa900b7","defk":"0.1.0","measured_at":"2026-10-19T11:37:27Z","quiet":{"limit":1.0,"other_cpu":[0.11,0.06],"quiet":true,"waited_s":0}},"sweep":[{"defk_ms":0.046,"elixir_ms":0.046,"size":"1k x 32 B","speedup":1.0},{"defk_ms":0.002,"elixir_ms":0.036,"size":"64 KB","speedup":18.0},{"defk_ms":0.147,"elixir_ms":3.181,"size":"4 MB","speedup":21.64}],"verdict":"good"}],"run":{"command":"mix defk.examples --bench --all --snapshot","commit":"8fa900b7","elixir":"1.20.2","measured_at":"2026-10-19T11:41:41Z","otp":"29.0.3","quiet_limit":1.0},"status":"ok"}, @@ -30,12 +30,12 @@ {"name":"per_pair_distance","quiet":true,"results":[{"baseline":"optimized","cache":"stored","correct":true,"defk_ms":11.429,"defk_spread_ms":{"max":11.687,"median":11.436,"runs":5},"elixir_ms":41.271,"elixir_spread_ms":{"max":42.276,"median":41.466,"runs":5},"example":"per_pair_distance","expected":"good","reason":"one NIF call per pair: the call overhead eats most of the kernel's advantage on 8-16 byte strings","speedup":3.61,"stamp":{"c":{"Pairs.Kernels":"67c9f0fe5b68fb00c708e66d6521fe44"},"commit":"8fa900b7","defk":"0.1.0","measured_at":"2026-10-19T11:40:38Z","quiet":{"limit":1.0,"other_cpu":[0.06,0.16],"quiet":true,"waited_s":0}},"verdict":"good"}],"run":{"command":"mix defk.examples --bench --all --snapshot","commit":"8fa900b7","elixir":"1.20.2","measured_at":"2026-10-19T11:41:41Z","otp":"29.0.3","quiet_limit":1.0},"status":"ok"}, {"name":"poor_list_data","quiet":true,"results":[{"baseline":"optimized","cache":"stored","correct":true,"defk_ms":72.646,"defk_spread_ms":{"max":78.339,"median":74.052,"runs":5},"elixir_ms":5.272,"elixir_spread_ms":{"max":12.544,"median":5.429,"runs":5},"example":"poor_list_data","expected":"poor","reason":"packing a list into a binary costs more than summing it in Elixir","speedup":0.07,"stamp":{"c":{"Orders.Kernels":"bea4612e55227d1bbe8c4ef8f51922f4"},"commit":"8fa900b7","defk":"0.1.0","measured_at":"2026-10-19T11:40:39Z","quiet":{"limit":1.0,"other_cpu":[0.04,0.04],"quiet":true,"waited_s":0}},"verdict":"poor"}],"run":{"command":"mix defk.examples --bench --all --snapshot","commit":"8fa900b7","elixir":"1.20.2","measured_at":"2026-10-19T11:41:41Z","otp":"29.0.3","quiet_limit":1.0},"status":"ok"}, {"name":"poor_substring_search","quiet":true,"results":[{"baseline":"optimized","cache":"stored","correct":true,"defk_ms":4.35,"defk_spread_ms":{"max":4.605,"median":4.485,"runs":15},"elixir_ms":4.973,"elixir_spread_ms":{"max":5.009,"median":4.991,"runs":15},"example":"poor_substring_search","expected":"marginal","reason":":binary.match is already native Boyer-Moore; the Horspool kernel is only about 1.1-1.2x ahead, not worth native code","speedup":1.14,"stamp":{"c":{"Search.Kernels":"ce74605200a0f85da8b7773ed0bf4b61"},"commit":"8fa900b7","defk":"0.1.0","measured_at":"2026-10-19T11:40:40Z","quiet":{"limit":1.0,"other_cpu":[0.05,0.06],"quiet":true,"waited_s":0}},"verdict":"marginal"}],"run":{"command":"mix defk.examples --bench --all --snapshot","commit":"8fa900b7","elixir":"1.20.2","measured_at":"2026-10-19T11:41:41Z","otp":"29.0.3","quiet_limit":1.0},"status":"ok"}, - {"name":"poor_tiny_calls","quiet":true,"results":[{"baseline":"optimized","cache":"stored","correct":true,"defk_ms":53.406,"defk_spread_ms":{"max":87.449,"median":80.758,"runs":5},"elixir_ms":14.797,"elixir_spread_ms":{"max":22.138,"median":15.554,"runs":5},"example":"poor_tiny_calls","expected":"poor","reason":"one NIF call per element: the call overhead is larger than the work","speedup":0.28,"stamp":{"c":{"Clamp.Kernels":"ccc3a59eb65b3080b5b00482aca8813c"},"commit":"8fa900b7","defk":"0.1.0","measured_at":"2026-10-19T11:40:42Z","quiet":{"limit":1.0,"other_cpu":[0.06,0.07],"quiet":true,"waited_s":0}},"verdict":"poor"}],"run":{"command":"mix defk.examples --bench --all --snapshot","commit":"8fa900b7","elixir":"1.20.2","measured_at":"2026-10-19T11:41:41Z","otp":"29.0.3","quiet_limit":1.0},"status":"ok"}, + {"name":"poor_tiny_calls","quiet":true,"results":[{"baseline":"optimized","cache":"stored","correct":true,"defk_ms":45.476,"defk_spread_ms":{"max":85.522,"median":81.457,"runs":5},"elixir_ms":13.311,"elixir_spread_ms":{"max":19.65,"median":14.37,"runs":5},"example":"poor_tiny_calls","expected":"poor","reason":"one NIF call per element: the call overhead is larger than the work","speedup":0.29,"stamp":{"c":{"Clamp.Kernels":"b6d4433c8084d615d46c7c60d5446a1a"},"commit":"03771114","defk":"0.1.0","measured_at":"2026-10-21T19:58:28Z","quiet":{"limit":1.0,"other_cpu":[0.65,0.2],"quiet":true,"waited_s":0}},"verdict":"poor"}],"run":{"command":"mix defk.examples --bench --only ws_masking,geohash_crc,poor_tiny_calls,utf8_valid --snapshot","commit":"03771114","elixir":"1.20.2","measured_at":"2026-10-21T19:58:40Z","otp":"29.0.3","quiet_limit":1.0},"status":"ok"}, {"name":"rolling_stats","quiet":true,"results":[{"baseline":"optimized","cache":"stored","correct":true,"defk_ms":1.089,"defk_spread_ms":{"max":1.88,"median":1.701,"runs":5},"elixir_ms":10.252,"elixir_spread_ms":{"max":11.131,"median":10.366,"runs":5},"example":"rolling_stats","expected":"good","reason":"one pass over packed floats, no allocation per sample","speedup":9.41,"stamp":{"c":{"Rolling.Kernels":"741787c6de035e89fde5d5b14392c9f2"},"commit":"8fa900b7","defk":"0.1.0","measured_at":"2026-10-19T11:40:43Z","quiet":{"limit":1.0,"other_cpu":[0.34,0.07],"quiet":true,"waited_s":0}},"verdict":"good"}],"run":{"command":"mix defk.examples --bench --all --snapshot","commit":"8fa900b7","elixir":"1.20.2","measured_at":"2026-10-19T11:41:41Z","otp":"29.0.3","quiet_limit":1.0},"status":"ok"}, {"name":"sort_u64_keys","quiet":true,"results":[{"baseline":"optimized","cache":"stored","correct":true,"defk_ms":59.478,"defk_spread_ms":{"max":60.181,"median":60.172,"runs":5},"elixir_ms":355.392,"elixir_spread_ms":{"max":418.879,"median":369.938,"runs":5},"example":"sort_packed","expected":"good","reason":"packed in, packed out: no list is ever built on the defk side","speedup":5.98,"stamp":{"c":{"Keys.Kernels":"a49c2e57190d29d9d5d46c60ecd6535f"},"commit":"684a3592","defk":"0.1.0","measured_at":"2026-10-19T11:59:29Z","quiet":{"limit":1.0,"other_cpu":[0.12,0.04],"quiet":true,"waited_s":0}},"verdict":"good"},{"baseline":"optimized","cache":"reused","correct":true,"defk_ms":94.191,"defk_spread_ms":{"max":118.427,"median":96.442,"runs":5},"elixir_ms":362.119,"elixir_spread_ms":{"max":396.991,"median":371.298,"runs":5},"example":"sort_to_list","expected":"good","measured_at":"2026-10-19T11:41:02Z","reason":"decoding the sorted result to a list costs 40 ms, the margin shrinks to about 2.5x but holds","speedup":3.84,"stamp":{"c":{"Keys.Kernels":"a49c2e57190d29d9d5d46c60ecd6535f"},"commit":"8fa900b7","defk":"0.1.0","measured_at":"2026-10-19T11:41:02Z","quiet":{"limit":1.0,"other_cpu":[0.54,0.22],"quiet":true,"waited_s":6}},"verdict":"good"}],"run":{"command":"mix defk.examples --bench --only codecs,gorilla_encode,monte_carlo_rtp,sort_u64_keys --snapshot","commit":"684a3592","elixir":"1.20.2","measured_at":"2026-10-19T11:59:29Z","otp":"29.0.3","quiet_limit":1.0},"status":"ok"}, {"name":"tape_csv","quiet":true,"results":[{"baseline":"optimized","cache":"stored","correct":true,"crossover":"1000000 rows","defk_ms":131.174,"defk_spread_ms":{"max":133.365,"median":132.849,"runs":15},"elixir_ms":274.473,"elixir_spread_ms":{"max":279.982,"median":277.864,"runs":15},"example":"tape_csv","expected":"good","native_label":"rusty_csv 0.4.6","native_ms":49.459,"native_speedup":0.38,"native_spread_ms":{"max":52.635,"median":50.216,"runs":15},"realistic_size":"20 MB: a 200k-row customer export","reason":"the kernel cleans 20 MB in 36 ms and two :binary.split passes build the rows, with less garbage than a parser in Elixir; rusty_csv builds them in C, 2.7x faster still","speedup":2.09,"stamp":{"c":{"Tape.Kernels":"9a6a5466f9da258adf6f944d858351d0"},"commit":"71e29777","defk":"0.1.0","measured_at":"2026-10-20T13:41:22Z","quiet":{"limit":1.0,"other_cpu":[0.29,0.82],"quiet":true,"waited_s":0}},"sweep":[{"defk_ms":1.082,"elixir_ms":1.71,"size":"2000 rows","speedup":1.58},{"defk_ms":10.814,"elixir_ms":17.611,"size":"20000 rows","speedup":1.63},{"defk_ms":646.619,"elixir_ms":1524.704,"size":"1000000 rows","speedup":2.36}],"verdict":"good"}],"run":{"command":"mix defk.examples --bench --only tape_csv --snapshot --fresh","commit":"71e29777","elixir":"1.20.2","measured_at":"2026-10-20T13:41:22Z","otp":"29.0.3","quiet_limit":1.0},"status":"ok"}, {"name":"threshold_cross","quiet":true,"results":[{"baseline":"optimized","cache":"stored","correct":true,"crossover":16384,"defk_gap_ms":{"max":2.018,"p99":2.018},"defk_ms":0.006,"defk_spread_ms":{"max":0.008,"median":0.006,"runs":15},"elixir_gap_ms":{"max":2.018,"p99":2.018},"elixir_ms":0.015,"elixir_spread_ms":{"max":0.021,"median":0.015,"runs":15},"example":"threshold_cross","expected":"good","native_gap_ms":{"max":2.003,"p99":2.003},"native_label":"Nx 0.13.1 + EXLA 0.13.1, while","native_ms":0.076,"native_speedup":12.67,"native_spread_ms":{"max":0.137,"median":0.09,"runs":15},"realistic_size":"64k packets, the budget passed at 25%","reason":"a sequential loop that stops early: the kernel runs it at C speed with a call cost of tens of ns; EXLA pays about 40 us per call and its while loop is several times slower per step","speedup":2.5,"stamp":{"c":{"Cross.Kernels":"a9b05d807cb008926d11bd6381803e21"},"commit":"3602f17d","defk":"0.1.0","measured_at":"2026-10-20T17:59:00Z","quiet":{"limit":1.0,"other_cpu":[0.98,0.95],"quiet":true,"waited_s":0}},"sweep":[{"defk_ms":0.001,"elixir_ms":0.003,"size":16384,"speedup":3.0},{"defk_ms":0.006,"elixir_ms":0.016,"size":65536,"speedup":2.67},{"defk_ms":0.102,"elixir_ms":0.262,"size":1048576,"speedup":2.57}],"verdict":"good"}],"run":{"command":"mix defk.examples --bench --only threshold_cross --snapshot --fresh","commit":"3602f17d","elixir":"1.20.2","measured_at":"2026-10-20T17:59:00Z","otp":"29.0.3","quiet_limit":1.0},"status":"ok"}, - {"name":"utf8_valid","quiet":true,"results":[{"baseline":"optimized","cache":"stored","correct":true,"crossover":null,"defk_ms":26.992,"defk_spread_ms":{"max":27.922,"median":27.5,"runs":15},"elixir_ms":28.037,"elixir_spread_ms":{"max":29.813,"median":29.156,"runs":15},"example":"utf8_valid","expected":"marginal","realistic_size":"16 MB","reason":"a scalar byte DFA competes with a C BIF; :unicode.characters_to_binary is already C and the DFA is only about 1.07x ahead, so use String.valid? (a SIMD validator is a wrapper job)","speedup":1.04,"stamp":{"c":{"Utf8.Kernels":"5439915fa11707ea174a3f68e6e8af0b"},"commit":"8fa900b7","defk":"0.1.0","measured_at":"2026-10-19T11:41:05Z","quiet":{"limit":1.0,"other_cpu":[0.14,0.38],"quiet":true,"waited_s":0}},"sweep":[{"defk_ms":0.002,"elixir_ms":0.0,"size":1024,"speedup":0.0},{"defk_ms":0.102,"elixir_ms":0.057,"size":65536,"speedup":0.56},{"defk_ms":1.718,"elixir_ms":1.812,"size":1048576,"speedup":1.05},{"defk_ms":27.234,"elixir_ms":29.351,"size":16777216,"speedup":1.08}],"verdict":"marginal"}],"run":{"command":"mix defk.examples --bench --all --snapshot","commit":"8fa900b7","elixir":"1.20.2","measured_at":"2026-10-19T11:41:41Z","otp":"29.0.3","quiet_limit":1.0},"status":"ok"}, - {"name":"ws_masking","quiet":true,"results":[{"baseline":"optimized","cache":"stored","correct":true,"crossover":"1024 B","defk_gap_ms":{"max":1.751,"p99":1.751},"defk_ms":1.231,"defk_spread_ms":{"max":1.369,"median":1.287,"runs":15},"elixir_gap_ms":{"max":2.008,"p99":2.008},"elixir_ms":1.793,"elixir_spread_ms":{"max":2.786,"median":2.397,"runs":15},"example":"ws_masking","expected":"marginal","native_gap_ms":{"max":8.345,"p99":8.345},"native_label":"bandit_native 0.1.2 Bandit.Native.mask/2 (Rust, byte at a time, normal scheduler)","native_ms":1.424,"native_speedup":1.16,"native_spread_ms":{"max":1.556,"median":1.461,"runs":15},"realistic_size":"125 B frames (the largest 7-bit length), 10,000 frames per timed run","reason":"a 125 B frame is ~0.13 us of kernel call against the BEAM's already-compiled 32-bit loop; use Bandit's own ws_mask/2 for small frames","speedup":1.46,"stamp":{"c":{"Ws.Defk":"aa97b7005e38e3435e015619bd5af1e8"},"commit":"8fa900b7","defk":"0.1.0","measured_at":"2026-10-19T11:41:21Z","quiet":{"limit":1.0,"other_cpu":[0.34,0.11],"quiet":true,"waited_s":8}},"sweep":[{"defk_ms":1.226,"elixir_ms":1.626,"size":"125 B","speedup":1.33},{"defk_ms":2.176,"elixir_ms":5.996,"size":"1024 B","speedup":2.76},{"defk_ms":1.35,"elixir_ms":4.582,"size":"8192 B","speedup":3.39},{"defk_ms":1.222,"elixir_ms":3.95,"size":"65536 B","speedup":3.23},{"defk_ms":1.203,"elixir_ms":4.109,"size":"1048576 B","speedup":3.42},{"defk_ms":2.547,"elixir_ms":9.134,"size":"16777216 B","speedup":3.59}],"verdict":"marginal"},{"baseline":"optimized","cache":"stored","correct":true,"defk_ms":1.2,"defk_spread_ms":{"max":1.23,"median":1.209,"runs":15},"elixir_ms":4.103,"elixir_spread_ms":{"max":7.095,"median":4.194,"runs":15},"example":"ws_masking_1mib","expected":"good","native_label":"bandit_native 0.1.2 Bandit.Native.mask/2 (Rust, byte at a time, normal scheduler)","native_ms":4.215,"native_speedup":3.51,"native_spread_ms":{"max":4.418,"median":4.38,"runs":15},"realistic_size":"1 MiB frames, 8 per timed run","reason":"the vectorised kernel runs at memory bandwidth (~38 GB/s) while the best Elixir (:crypto.exor/2) and bandit_native's byte-at-a-time loop run at 2 GB/s","speedup":3.42,"stamp":{"c":{"Ws.Defk":"aa97b7005e38e3435e015619bd5af1e8"},"commit":"8fa900b7","defk":"0.1.0","measured_at":"2026-10-19T11:41:21Z","quiet":{"limit":1.0,"other_cpu":[0.11,0.06],"quiet":true,"waited_s":0}},"verdict":"good"}],"run":{"command":"mix defk.examples --bench --all --snapshot","commit":"8fa900b7","elixir":"1.20.2","measured_at":"2026-10-19T11:41:41Z","otp":"29.0.3","quiet_limit":1.0},"status":"ok"} + {"name":"utf8_valid","quiet":true,"results":[{"baseline":"optimized","cache":"stored","correct":true,"crossover":null,"defk_ms":26.26,"defk_spread_ms":{"max":26.668,"median":26.453,"runs":15},"elixir_ms":27.731,"elixir_spread_ms":{"max":29.465,"median":28.211,"runs":15},"example":"utf8_valid","expected":"marginal","realistic_size":"16 MB","reason":"a scalar byte DFA competes with a C BIF; :unicode.characters_to_binary is already C and the DFA is only about 1.07x ahead, so use String.valid? (a SIMD validator is a wrapper job)","speedup":1.06,"stamp":{"c":{"Utf8.Kernels":"6d71015bdd7f0e2b7af934f0fc22cbf0"},"commit":"03771114","defk":"0.1.0","measured_at":"2026-10-21T19:58:32Z","quiet":{"limit":1.0,"other_cpu":[0.41,0.16],"quiet":true,"waited_s":0}},"sweep":[{"defk_ms":0.002,"elixir_ms":0.0,"size":1024,"speedup":0.0},{"defk_ms":0.102,"elixir_ms":0.051,"size":65536,"speedup":0.5},{"defk_ms":1.631,"elixir_ms":1.712,"size":1048576,"speedup":1.05},{"defk_ms":26.247,"elixir_ms":27.825,"size":16777216,"speedup":1.06}],"verdict":"marginal"}],"run":{"command":"mix defk.examples --bench --only ws_masking,geohash_crc,poor_tiny_calls,utf8_valid --snapshot","commit":"03771114","elixir":"1.20.2","measured_at":"2026-10-21T19:58:40Z","otp":"29.0.3","quiet_limit":1.0},"status":"ok"}, + {"name":"ws_masking","quiet":true,"results":[{"baseline":"optimized","cache":"stored","correct":true,"crossover":"1024 B","defk_gap_ms":{"max":1.69,"p99":1.69},"defk_ms":1.129,"defk_spread_ms":{"max":1.204,"median":1.168,"runs":15},"elixir_gap_ms":{"max":2.006,"p99":2.006},"elixir_ms":1.66,"elixir_spread_ms":{"max":1.687,"median":1.675,"runs":15},"example":"ws_masking","expected":"marginal","native_gap_ms":{"max":8.418,"p99":8.418},"native_label":"bandit_native 0.1.2 Bandit.Native.mask/2 (Rust, byte at a time, normal scheduler)","native_ms":1.361,"native_speedup":1.21,"native_spread_ms":{"max":1.6,"median":1.44,"runs":15},"realistic_size":"125 B frames (the largest 7-bit length), 10,000 frames per timed run","reason":"a 125 B frame is ~0.13 us of kernel call against the BEAM's already-compiled 32-bit loop; use Bandit's own ws_mask/2 for small frames","speedup":1.47,"stamp":{"c":{"Ws.Defk":"48e22dcdc7e30d6fadd1d7b456e1cede"},"commit":"03771114","defk":"0.1.0","measured_at":"2026-10-21T19:58:40Z","quiet":{"limit":1.0,"other_cpu":[0.33,0.23],"quiet":true,"waited_s":0}},"sweep":[{"defk_ms":1.149,"elixir_ms":1.644,"size":"125 B","speedup":1.43},{"defk_ms":1.855,"elixir_ms":6.661,"size":"1024 B","speedup":3.59},{"defk_ms":1.257,"elixir_ms":4.131,"size":"8192 B","speedup":3.29},{"defk_ms":1.206,"elixir_ms":4.002,"size":"65536 B","speedup":3.32},{"defk_ms":1.187,"elixir_ms":4.122,"size":"1048576 B","speedup":3.47},{"defk_ms":2.515,"elixir_ms":9.393,"size":"16777216 B","speedup":3.73}],"verdict":"marginal"},{"baseline":"optimized","cache":"stored","correct":true,"defk_ms":1.086,"defk_spread_ms":{"max":1.251,"median":1.163,"runs":15},"elixir_ms":4.04,"elixir_spread_ms":{"max":4.348,"median":4.166,"runs":15},"example":"ws_masking_1mib","expected":"good","native_label":"bandit_native 0.1.2 Bandit.Native.mask/2 (Rust, byte at a time, normal scheduler)","native_ms":4.031,"native_speedup":3.71,"native_spread_ms":{"max":4.357,"median":4.22,"runs":15},"realistic_size":"1 MiB frames, 8 per timed run","reason":"the vectorised kernel runs at memory bandwidth (~38 GB/s) while the best Elixir (:crypto.exor/2) and bandit_native's byte-at-a-time loop run at 2 GB/s","speedup":3.72,"stamp":{"c":{"Ws.Defk":"48e22dcdc7e30d6fadd1d7b456e1cede"},"commit":"03771114","defk":"0.1.0","measured_at":"2026-10-21T19:58:40Z","quiet":{"limit":1.0,"other_cpu":[0.23,0.2],"quiet":true,"waited_s":0}},"verdict":"good"}],"run":{"command":"mix defk.examples --bench --only ws_masking,geohash_crc,poor_tiny_calls,utf8_valid --snapshot","commit":"03771114","elixir":"1.20.2","measured_at":"2026-10-21T19:58:40Z","otp":"29.0.3","quiet_limit":1.0},"status":"ok"} ] } diff --git a/priv/defk_runtime.h b/priv/defk_runtime.h index c8bcdc63..857d4734 100644 --- a/priv/defk_runtime.h +++ b/priv/defk_runtime.h @@ -1892,6 +1892,34 @@ __attribute__((unused)) static ERL_NIF_TERM defk_make_bits(ErlNifEnv *env, defk_ /* ---- scheduling ---------------------------------------------------------- */ +/* + * The clock the slices are measured with, in microseconds. A yielding kernel + * reads it once at entry and once per tick. enif_monotonic_time costs ~27 ns + * a read on macOS arm64, and that entry read was more than half of a tiny + * yielding call (37 ns; docs/performance.md 5.1). On Apple platforms + * mach_absolute_time is a counter read (~5 ns), converted with the timebase + * read once per library at load. Elsewhere the ERTS clock stays. + */ +#if defined(__APPLE__) +#include +static uint64_t defk_tb_numer = 1, defk_tb_denom = 1000; /* ticks -> us */ +static void defk_clock_setup(void) { + mach_timebase_info_data_t tb; + if (mach_timebase_info(&tb) == KERN_SUCCESS && tb.numer && tb.denom) { + defk_tb_numer = tb.numer; + defk_tb_denom = (uint64_t)tb.denom * 1000; + } +} +static inline int64_t defk_now_us(void) { + return (int64_t)(mach_absolute_time() * defk_tb_numer / defk_tb_denom); +} +#else +static void defk_clock_setup(void) {} +static inline int64_t defk_now_us(void) { + return (int64_t)enif_monotonic_time(ERL_NIF_USEC); +} +#endif + /* * Safepoint clock. Loops count back-edges against an adaptive budget so the * clock is read every DEFK_SLICE_US/10 .. /4 no matter how expensive one @@ -1970,7 +1998,7 @@ __attribute__((unused)) static void defk_slice_init(ErlNifEnv *env, defk_ctx *ct } static void defk_clock_init(defk_clock *c, defk_ctx *ctx) { - c->last = enif_monotonic_time(ERL_NIF_USEC); + c->last = defk_now_us(); c->unreported = 0; c->ctx = ctx; } @@ -1991,8 +2019,19 @@ __attribute__((noinline)) static int64_t defk_tick(ErlNifEnv *env, defk_clock *c else defk_inject_fault_now(inj); } #endif - if (atomic_load_explicit(&defk_force_yields, memory_order_relaxed)) return 0; - ErlNifTime now = enif_monotonic_time(ERL_NIF_USEC); + if (DEFK_UNLIKELY(atomic_load_explicit(&defk_force_yields, memory_order_relaxed))) { + /* Forced yields charge no reductions, so the scheduler never reads its + clock between them, and a process that sleeps on this scheduler + (Process.sleep in a test watching the kernel) waits until the kernel + ends: the timer wheel is bumped from the scheduler's last_monotonic_time, + which only an ERTS clock read advances (erts_get_monotonic_time stores + it and resets check_time_reds). With the ERTS slice clock every + re-entry read it (defk_clock_init); the cheap clock does not, so the + forced path reads it here. */ + (void)enif_monotonic_time(ERL_NIF_USEC); + return 0; + } + ErlNifTime now = defk_now_us(); ErlNifTime dt = now - c->last; defk_ctx *ctx = c->ctx; int64_t slice = ctx->slice_us; @@ -2458,6 +2497,7 @@ static int defk_open_rt(ErlNifEnv *env, ErlNifResourceFlags flags) { } static int defk_load(ErlNifEnv *env, void **priv, ERL_NIF_TERM info) { (void)info; + defk_clock_setup(); defk_max_owned_init(); defk_fault_install(); *priv = &defk_fault; @@ -2465,6 +2505,7 @@ static int defk_load(ErlNifEnv *env, void **priv, ERL_NIF_TERM info) { } static int defk_upgrade(ErlNifEnv *env, void **priv, void **old, ERL_NIF_TERM info) { (void)info; + defk_clock_setup(); defk_max_owned_init(); defk_fault_pin_old(old ? *old : NULL); defk_fault_install();