perf: log instruction metrics

4 files changed, 112 insertions, 3 deletions

diff --git a/examples/php-on-wasm/php-wasm.php b/examples/php-on-wasm/php-wasm.php
index 75e9c3f..b5a9fed 100644
--- a/examples/php-on-wasm/php-wasm.php
+++ b/examples/php-on-wasm/php-wasm.php
@@ -153,6 +153,10 @@ $exitCode = $result->inner->value;
 
 fprintf(STDERR, "Exit code: $exitCode\n");
 fprintf(STDERR, "Memory peak usage: %s\n", memory_get_peak_usage());
+fprintf(STDERR, "\n\n");
+foreach ($runtime->getInstrMetrics() as $instr => $count) {
+    fprintf(STDERR, "%s: %d\n", $instr, $count);
+}
 
 function allocateStringOnWasmMemory(Runtime $runtime, string $str): int {
     // Plus 1 for the null terminator in C.
diff --git a/prof.sh b/prof.sh
index 0361100..2d456e7 100644
--- a/prof.sh
+++ b/prof.sh
@@ -1,3 +1,5 @@
 timestamp="$(date '+%Y%m%d-%H%M')"
-php -d 'error_reporting=E_ALL & ~E_DEPRECATED & ~E_USER_DEPRECATED' vendor/bin/reli inspector:trace -o traces/"$timestamp".log -- php -d memory_limit=256M -d opcache.enable_cli=on -d opcache.jit=on -d opcache.jit_buffer_size=1G examples/php-on-wasm/php-wasm.php 2> traces/"$timestamp".stderr.log
-vendor/bin/reli converter:flamegraph < traces/"$timestamp".log > traces/"$timestamp".svg
+# php -d 'error_reporting=E_ALL & ~E_DEPRECATED & ~E_USER_DEPRECATED' vendor/bin/reli inspector:trace -o traces/"$timestamp".log -- php -d memory_limit=256M -d opcache.enable_cli=on -d opcache.jit=on -d opcache.jit_buffer_size=1G examples/php-on-wasm/php-wasm.php 2> traces/"$timestamp".stderr.log
+# vendor/bin/reli converter:flamegraph < traces/"$timestamp".log > traces/"$timestamp".svg
+
+php -d memory_limit=256M -d opcache.enable_cli=on -d opcache.jit=on -d opcache.jit_buffer_size=1G examples/php-on-wasm/php-wasm.php 2> traces/"$timestamp".stderr.log
diff --git a/src/Execution/Runtime.php b/src/Execution/Runtime.php
index 40d7703..3617de2 100644
--- a/src/Execution/Runtime.php
+++ b/src/Execution/Runtime.php
@@ -21,8 +21,13 @@ use Nsfisis\Waddiwasi\Structure\Types\TableIdx;
 use Nsfisis\Waddiwasi\Structure\Types\ValType;
 use Nsfisis\Waddiwasi\Structure\Types\ValTypes;
 
-final readonly class Runtime
+final class Runtime
 {
+    /**
+     * @var array<string, int>
+     */
+    private array $instrMetrics = [];
+
     private function __construct(
         public readonly Store $store,
         public readonly Stack $stack,
@@ -152,6 +157,15 @@ final readonly class Runtime
     }
 
     /**
+     * @return array<string, int>
+     */
+    public function getInstrMetrics(): array
+    {
+        ksort($this->instrMetrics);
+        return $this->instrMetrics;
+    }
+
+    /**
      * @param list<Val> $vals
      * @return list<Val>
      */
@@ -314,6 +328,9 @@ final readonly class Runtime
         static $debug = 0;
         // if ($debug >= 3) echo "Exec: " . $instr::opName() . "\n";
 
+        // $this->instrMetrics[$instr::opName()] ??= 0;
+        // $this->instrMetrics[$instr::opName()]++;
+
         return match ($instr::class) {
             Instrs\Numeric\F32Abs::class => $this->execInstrNumericF32Abs($instr),
             Instrs\Numeric\F32Add::class => $this->execInstrNumericF32Add($instr),
diff --git a/traces/20240313-2203.stderr.log b/traces/20240313-2203.stderr.log
new file mode 100644
index 0000000..70fc92e
--- /dev/null
+++ b/traces/20240313-2203.stderr.log
@@ -0,0 +1,86 @@
+Decoding...
+Instantiating...
+Executing...
+
+Exit code: 0
+Memory peak usage: 251930488
+
+
+local.get: 3135728
+i32.const: 1589717
+i32.add: 812466
+local.tee: 758661
+br_if: 732305
+block: 723450
+i32.load: 564315
+br: 491022
+local.set: 439632
+i32.store: 362806
+i64.store: 306534
+i32.and: 249884
+i32.eqz: 198278
+i32.load8_u: 159431
+i32.gt_u: 117828
+i32.lt_u: 101169
+i32.ne: 92660
+i32.shl: 86408
+i32.or: 71541
+call: 70579
+i32.mul: 68122
+i32.eq: 66100
+i32.sub: 64081
+i32.load8_s: 54242
+i32.shr_u: 51699
+global.set: 51161
+loop: 44110
+i32.store8: 42849
+i32.ge_u: 33468
+select: 29114
+global.get: 25951
+i32.le_u: 25404
+return: 19633
+i32.xor: 18826
+drop: 15033
+i64.load: 12927
+call_indirect: 12643
+i64.const: 9965
+br_table: 6061
+i32.clz: 5130
+i32.rot_l: 2203
+i32.lt_s: 2161
+i32.store16: 1998
+i64.mul: 842
+i32.gt_s: 613
+i64.extend_i32_u: 592
+i32.load16_u: 426
+i64.add: 323
+i32.div_u: 284
+i32.extend16_s: 256
+i64.shr_u: 239
+i64.and: 226
+i32.ctz: 155
+i32.ge_s: 134
+memory.size: 130
+i32.load16_s: 81
+i32.extend8_s: 78
+i64.ne: 70
+i64.xor: 62
+i32.le_s: 49
+i64.shl: 47
+i64.or: 46
+i64.gt_u: 46
+i64.eqz: 42
+i32.wrap_i64: 32
+f64.const: 26
+f64.store: 24
+i64.lt_u: 17
+i64.sub: 16
+i64.extend_i32_s: 16
+f64.convert_i32_s: 4
+f64.add: 4
+i64.eq: 2
+f64.mul: 2
+f64.load: 2
+f64.gt: 2
+i64.rot_l: 1
+i32.rem_u: 1