Skip to content

Commit 5fed051

Browse files
committed
Add vm-counters feature: per-run instruction, allocation, and RC counts
A cargo feature on the VM (off by default, passed through by the compiler) counts dispatched instructions, heap allocations, and incref/decref per run and prints them on exit. The increments are cfg-gated no-op methods, so the normal build is unchanged and pays nothing. The counts are deterministic, so they read from the feature build while wall-clock reads from the plain build, and the counter cost never contaminates a timing. First finding, the hello-world HTTP request (two-point measurement, per request): about 3,865 instructions, 94 allocations, and 274 reference-count operations. The allocation and RC traffic, not raw dispatch, is the larger interpreter lever and the concrete target for reference-count elision. Recorded in PROFILING.md.
1 parent c6e74dd commit 5fed051

6 files changed

Lines changed: 131 additions & 7 deletions

File tree

plans/PROFILING.md

Lines changed: 27 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -18,9 +18,14 @@ Three tools, since heavyweight profilers are often unavailable in a sandbox:
1818
- **`strace -f -c`** on the server gives the syscall histogram, which is where the connection-lifecycle
1919
cost shows up. It roughly triples the runtime, so read the counts and the distribution, not the
2020
absolute times.
21-
- **VM instrumentation counters** (planned, not yet built): dispatched instructions, allocations, and
22-
incref/decref per request. These are deterministic, so they double as a regression gate, and they
23-
are what sizes the interpreter-internal levers (RC elision, fusion) that strace cannot see.
21+
- **VM instrumentation counters** (built, behind the `vm-counters` cargo feature, off by default):
22+
dispatched instructions, heap allocations, and incref/decref per run, printed to stderr on exit.
23+
The increments compile out of the normal build, so it pays nothing by default. Build with
24+
`cargo build --release -p solid-snake-compiler --features vm-counters`, run a bounded program, and
25+
divide the totals by the request count. The counts are deterministic, so they double as a
26+
regression gate, and they size the interpreter-internal levers (RC elision, fusion) that strace
27+
cannot see. Read counts from this build and wall-clock from the plain build, so the counters' own
28+
cost never contaminates a timing.
2429

2530
Two server shapes bracket the cost. The full `std.http` library server measures the realistic path
2631
(request parsing included). A raw server (`srv_perreq.ss`, `srv_ka.ss`) that reads a request and
@@ -54,16 +59,31 @@ requests). Reference counting reclaims each request's allocations immediately, s
5459
bounded with no per-request growth. This is lean, well under a typical Node idle footprint and in
5560
Go's range.
5661

62+
Interpreter internals per request, from the `vm-counters` build (two-point measurement subtracting a
63+
1000-request run from a 4000-request run, so fixed setup cancels, and the counts are perfectly
64+
linear):
65+
66+
- dispatched instructions: about 3,865
67+
- heap allocations: about 94
68+
- incref: about 102, decref: about 172, so about 274 reference-count operations
69+
70+
That is a large amount of allocation and reference-count traffic for a fixed-response hello-world.
71+
Most of it is request-parsing temporaries that are uniquely owned and short-lived, which is exactly
72+
what reference-count elision targets. So of the roughly 24 us of interpreter parsing, a large share
73+
is the allocation and reference-count work these counts expose, not raw dispatch.
74+
5775
## The levers, sized
5876

5977
- **Keep-alive is the syscall lever.** It removes a hard 27 us per request. On the raw path that is a
6078
3.3x jump (25k to 83k). On the full library the ratio is smaller, because once the connection
6179
syscalls are gone the parse cost dominates, so the estimate is roughly 15.8k to 28k. The server is
6280
`Connection: close` today (`std.http` defers keep-alive deliberately), so this is unbuilt.
63-
- **The interpreter is the next lever.** The roughly 24 us of parsing is where RC elision (skip the
64-
retain and release where a value is provably uniquely owned and does not escape, which is most
65-
temporaries) and instruction fusion (cut dispatch and register traffic on hot runs) pay off. The
66-
VM counters will break this down into how much is RC traffic versus raw dispatch.
81+
- **The interpreter is the next lever, and it is allocation and reference counting more than raw
82+
dispatch.** The counters show about 94 allocations and about 274 reference-count operations per
83+
request. RC elision (skip the retain and release where a value is provably uniquely owned and does
84+
not escape, which is most temporaries) removes RC operations and the allocations tied to them, and
85+
instruction fusion cuts dispatch on the roughly 3,865 instructions. The allocation and RC traffic
86+
is the larger, more concrete target of the two.
6787

6888
## Where this sits
6989

solid-snake-compiler/Cargo.toml

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,11 @@ name = "solid-snake-compiler"
33
version = "0.1.0"
44
edition = "2024"
55

6+
[features]
7+
# Pass through the VM's per-run profiling counters, so `--features vm-counters` on the CLI enables
8+
# them end to end. Off by default. See plans/PROFILING.md.
9+
vm-counters = ["solid-snake-vm/vm-counters"]
10+
611
[dependencies]
712
solid-snake-vm = { path = "../solid-snake-vm" }
813
ariadne = "0.5.1"

solid-snake-vm/Cargo.toml

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,12 @@ name = "solid-snake-vm"
33
version = "0.1.0"
44
edition = "2024"
55

6+
[features]
7+
# Count dispatched instructions, heap allocations, and incref/decref per run, printed on exit. Off
8+
# by default so the increments compile out entirely and the normal build pays nothing. See
9+
# plans/PROFILING.md. Build with `--features vm-counters` to read the per-run tallies.
10+
vm-counters = []
11+
612
[dependencies]
713
solid-snake-vm-macros = { path = "../solid-snake-vm-macros" }
814
env_logger = "0.11.8"

solid-snake-vm/src/executor/interpreted/implimentation.rs

Lines changed: 77 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -136,13 +136,20 @@ pub trait VmHeapExt {
136136
pub struct VmHeap {
137137
memory_sections: Vec<VmMemorySection>,
138138
freed_sections: Vec<usize>,
139+
/// Total allocations over the run, only under `vm-counters`. Unlike `section_count`, this counts
140+
/// every `alloc` including those that reuse a freed slot, so it measures allocation traffic (what
141+
/// reference-count elision would reduce), not live sections.
142+
#[cfg(feature = "vm-counters")]
143+
alloc_count: u64,
139144
}
140145

141146
impl VmHeap {
142147
pub fn new() -> Self {
143148
Self {
144149
freed_sections: Vec::new(),
145150
memory_sections: Vec::new(),
151+
#[cfg(feature = "vm-counters")]
152+
alloc_count: 0,
146153
}
147154
}
148155

@@ -151,10 +158,20 @@ impl VmHeap {
151158
pub fn section_count(&self) -> usize {
152159
self.memory_sections.len()
153160
}
161+
162+
/// Total allocations over the run (only meaningful under `vm-counters`).
163+
#[cfg(feature = "vm-counters")]
164+
pub fn alloc_count(&self) -> u64 {
165+
self.alloc_count
166+
}
154167
}
155168

156169
impl VmHeapExt for VmHeap {
157170
fn alloc(&mut self, n: usize) -> Result<usize, VmExecutionError> {
171+
#[cfg(feature = "vm-counters")]
172+
{
173+
self.alloc_count += 1;
174+
}
158175
let memory_block: Vec<u8> = vec![0; n];
159176
let new_section = VmMemorySection::new_with_bytes(memory_block);
160177
if let Some(idx) = self.freed_sections.pop() {
@@ -464,6 +481,18 @@ impl InputSource {
464481
}
465482
}
466483

484+
/// Per-run profiling counters, populated only under the `vm-counters` feature. The counts are
485+
/// deterministic (a program does the same work every run), so they measure the interpreter workload
486+
/// shape without depending on wall-clock, and the increments compile out of the normal build. See
487+
/// plans/PROFILING.md.
488+
#[cfg(feature = "vm-counters")]
489+
#[derive(Default, Debug, Clone, Copy)]
490+
pub struct PerfCounters {
491+
pub instructions: u64,
492+
pub incref: u64,
493+
pub decref: u64,
494+
}
495+
467496
pub struct VmInterpretedExecutor {
468497
pub frame_stack: Vec<CallFrame>,
469498
pub stack_top: usize,
@@ -521,6 +550,10 @@ pub struct VmInterpretedExecutor {
521550
/// add or override handlers through `register_builtin`, so the VM core does not hardcode which
522551
/// builtins exist. See `plans/BUILTIN_REGISTRY.md`.
523552
builtins: BuiltinRegistry,
553+
/// Per-run profiling counters, only under the `vm-counters` feature so the increments compile
554+
/// out of the normal build.
555+
#[cfg(feature = "vm-counters")]
556+
perf: PerfCounters,
524557
}
525558

526559
impl VmInterpretedExecutor {
@@ -552,9 +585,50 @@ impl VmInterpretedExecutor {
552585
handles: HandleTable::default(),
553586
program: Vec::new(),
554587
builtins: BuiltinRegistry::with_defaults(),
588+
#[cfg(feature = "vm-counters")]
589+
perf: PerfCounters::default(),
555590
}
556591
}
557592

593+
// The counter methods are no-ops without `vm-counters`, so call sites stay unconditional.
594+
#[cfg(feature = "vm-counters")]
595+
#[inline(always)]
596+
pub fn perf_instr(&mut self) {
597+
self.perf.instructions += 1;
598+
}
599+
#[cfg(not(feature = "vm-counters"))]
600+
#[inline(always)]
601+
pub fn perf_instr(&mut self) {}
602+
603+
#[cfg(feature = "vm-counters")]
604+
#[inline(always)]
605+
pub fn perf_incref(&mut self) {
606+
self.perf.incref += 1;
607+
}
608+
#[cfg(not(feature = "vm-counters"))]
609+
#[inline(always)]
610+
pub fn perf_incref(&mut self) {}
611+
612+
#[cfg(feature = "vm-counters")]
613+
#[inline(always)]
614+
pub fn perf_decref(&mut self) {
615+
self.perf.decref += 1;
616+
}
617+
#[cfg(not(feature = "vm-counters"))]
618+
#[inline(always)]
619+
pub fn perf_decref(&mut self) {}
620+
621+
#[cfg(feature = "vm-counters")]
622+
pub fn perf_report(&self) -> String {
623+
format!(
624+
"vm-counters: instructions={} allocations={} incref={} decref={}",
625+
self.perf.instructions,
626+
self.heap.alloc_count(),
627+
self.perf.incref,
628+
self.perf.decref,
629+
)
630+
}
631+
558632
/// The builtin handler at an index, if one is installed. Read out before dispatch so the call
559633
/// holds no borrow into the executor it mutates (handlers are `Copy` function pointers).
560634
#[inline(always)]
@@ -959,11 +1033,14 @@ impl VmExecutorExt for VmInterpretedExecutor {
9591033
let decoded = self.program[self.program_counter];
9601034

9611035
if let DecodedInstruction::Halt((exit_code,)) = decoded {
1036+
#[cfg(feature = "vm-counters")]
1037+
eprintln!("{}", self.perf_report());
9621038
return Ok(exit_code);
9631039
}
9641040
self.prev_error_code = self.error_code;
9651041
self.error_code = 0; // TODO: examine if any instruction will need it kept set between multiple instructions.
9661042
self.program_counter += 1;
1043+
self.perf_instr();
9671044
decoded.exec(self)?;
9681045
}
9691046
}

solid-snake-vm/src/executor/interpreted/opcode_impl/memory.rs

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -245,6 +245,7 @@ pub fn incref_handler(
245245
args: IncRefArgs,
246246
) -> Result<(), VmExecutionError> {
247247
let (reg_target,) = args;
248+
executor.perf_incref();
248249
let section_idx: u64 = executor.registers().get_value(reg_target)?;
249250
adjust_refcount(executor, section_idx as usize, 1)?;
250251
Ok(())
@@ -255,6 +256,7 @@ pub fn decref_handler(
255256
args: DecRefArgs,
256257
) -> Result<(), VmExecutionError> {
257258
let (reg_target,) = args;
259+
executor.perf_decref();
258260
let root: u64 = executor.registers().get_value(reg_target)?;
259261
release_cascade(executor, root as usize)
260262
}

tools/profiling/README.md

Lines changed: 14 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -41,3 +41,17 @@ grep -E 'VmRSS|VmHWM' /proc/<pid>/status # resident and peak memory
4141

4242
The `srv_ka.ss` and `srv_perreq.ss` servers serve a bounded number of connections and then exit, so
4343
the accept count in each file must be at least the number of client connections used.
44+
45+
## Interpreter counters
46+
47+
Build with the `vm-counters` feature to print dispatched instructions, heap allocations, and
48+
incref/decref on exit, then divide by the request count (or subtract two run sizes to cancel fixed
49+
setup). Off by default, so the normal build pays nothing.
50+
51+
```
52+
cargo build --release -p solid-snake-compiler --features vm-counters
53+
./target/release/solid-snake-compiler tools/profiling/hello_server.ss & # serves a bounded count
54+
python3 tools/profiling/load.py 3000 8
55+
# the server prints: vm-counters: instructions=... allocations=... incref=... decref=...
56+
```
57+

0 commit comments

Comments
 (0)