Add per-trial CPU and scheduling evidence to model timing

models/experimental/MODEL_TIMING.ja.md

@@ -48,6 +48,24 @@ checksumはconfidence bits × iteration数とも照合する。
 計時値は再実行で変動する。JSON全byteの一致を性能の再現性と扱わず、独立runの分布を比較する。
 保存先はrunごとに変える。異なる既存reportを上書きしない。
 
+## v2: 試行ごとのresource観測
+
+Linuxでは[`getrusage(RUSAGE_SELF)`](https://man7.org/linux/man-pages/man2/getrusage.2.html)
+をwall計測の直前・直後に呼び、user/system CPU時間、voluntary/involuntary context switch、
+minor/major page faultの差を保存する。単一thread processの観測で、他processや子processは含めない。
+counter読取りはwall区間外だが、resource差分の区間はclock読取り等を含むため厳密には異なる。
+CPU時間はmicrosecond精度のtimevalをnsへ換算した値で、ns分解能を意味しない。
+短い試行では0もあり得る。CPU時間がwall時間以下であることをassertしない。
+
+report schemaは`native-model-timing-v2`。各sourceの`trial_resources`配列は`elapsed_ns`と
+同じ試行順・件数で、全試行を除外せず保存する。Linuxのresource取得失敗は計測失敗とする。
+non-Linuxの低レベルprobeは`resources: null`とし、未観測値を0と偽らない。
+Linux affinity必須の上位runnerはresourceが欠けた場合にreport生成を拒否する。
+
+CPUとwallの差やcontext switchの増加は原因調査の材料であって、個々の停止時間や
+周波数・cache missの計測ではない。相関だけでOSやmodelを原因と断定しない。
+新しいcounterを理由に試行を自動削除したり、過去reportを補完したりしない。
+
 ## 採用判断とは別
 
 このtoolは単一モデルのreuse処理コストだけを測る。allocation数、ピークmemory、

models/experimental/model_timing.py

@@ -93,6 +93,7 @@ def run(
                         sample_sha256=sample["sha256"],
                         byte_length=len(data),
                         elapsed_ns=[],
+                        trial_resources=[],
                     )
                     for source, sample, data in records
                 },
@@ -106,9 +107,14 @@ def run(
                     timing = observed.pop("benchmark")
                     if observed != baselines[name][source["id"]]:
                         raise ValueError("timed run differs from untimed observation")
+                    if timing.get("resources") is None:
+                        raise ValueError("Linux timing requires native resource observation")
                     profiles[name]["sources"][source["id"]]["elapsed_ns"].append(
                         timing["elapsed_ns"]
                     )
+                    profiles[name]["sources"][source["id"]]["trial_resources"].append(
+                        timing["resources"]
+                    )
     if affinity() != cpus or digest(library.read_bytes()) != library_hash:
         raise ValueError("affinity/library changed during timing")
     for profile in profiles.values():
@@ -121,7 +127,7 @@ def run(
         ]
         profile["summed_document_trial_summary"] = summary(totals, iterations)
     report = dict(
-        schema="native-model-timing-v1",
+        schema="native-model-timing-v2",
         corpus_content_hash=manifest["content_hash"],
         split=split,
         scope="reused single prober: reset + filter + feed + confidence + checksum",
@@ -130,6 +136,8 @@ def run(
         repeats=repeats,
         warmup_iterations=128,
         clock="C++ steady_clock; nanoseconds",
+        resource_scope="Linux RUSAGE_SELF deltas around wall interval; single-thread process",
+        resource_precision="CPU timeval microseconds converted to ns; not nanosecond resolution",
         cpu_affinity=cpus,
         aggregate_policy=(
             "sum of independent warmed same-document trial means; not interleaved corpus"

models/experimental/sequence-probe.cpp

@@ -11,6 +11,9 @@
 #include <stdexcept>
 #include <string>
 #include <vector>
+#ifdef __linux__
+#include <sys/resource.h>
+#endif
 #ifdef UCHARDET_ALLOCATION_PROBE
 #include "allocation-hooks.hpp"
 #endif
@@ -95,13 +98,24 @@ int main(int argc, char** argv) {
     std::int64_t elapsed_ns = 0;
     volatile std::uint64_t checksum = 0;
     const unsigned warmup = 128;
+#ifdef __linux__
+    struct rusage usage_before = {}, usage_after = {};
+#endif
     if (iterations) {
       for (unsigned i = 0; i < warmup; ++i) checksum += run();
       checksum = 0;
+#ifdef __linux__
+      if (getrusage(RUSAGE_SELF, &usage_before) != 0)
+        throw std::runtime_error("cannot read resource usage before timing");
+#endif
       const auto start = std::chrono::steady_clock::now();
       for (std::uint64_t i = 0; i < iterations; ++i) checksum += run();
       elapsed_ns = std::chrono::duration_cast<std::chrono::nanoseconds>(
           std::chrono::steady_clock::now() - start).count();
+#ifdef __linux__
+      if (getrusage(RUSAGE_SELF, &usage_after) != 0)
+        throw std::runtime_error("cannot read resource usage after timing");
+#endif
     }
     std::cout << "{\"schema\":\"sequence-native-probe-v1\",\"raw_bytes\":" << data.size()
               << ",\"filtered_bytes\":" << retained
@@ -126,7 +140,22 @@ int main(int argc, char** argv) {
       std::cout << ",\"benchmark\":{\"iterations\":" << iterations
                 << ",\"warmup_iterations\":" << warmup
                 << ",\"elapsed_ns\":" << elapsed_ns
-                << ",\"checksum\":" << checksum << '}';
+                << ",\"checksum\":" << checksum << ",\"resources\":";
+#ifdef __linux__
+      const auto cpu_ns = [](const struct timeval& value) -> std::int64_t {
+        return static_cast<std::int64_t>(value.tv_sec) * 1000000000 +
+               static_cast<std::int64_t>(value.tv_usec) * 1000;
+      };
+      std::cout << "{\"user_cpu_ns\":" << cpu_ns(usage_after.ru_utime) - cpu_ns(usage_before.ru_utime)
+                << ",\"system_cpu_ns\":" << cpu_ns(usage_after.ru_stime) - cpu_ns(usage_before.ru_stime)
+                << ",\"voluntary_switches\":" << usage_after.ru_nvcsw - usage_before.ru_nvcsw
+                << ",\"involuntary_switches\":" << usage_after.ru_nivcsw - usage_before.ru_nivcsw
+                << ",\"minor_faults\":" << usage_after.ru_minflt - usage_before.ru_minflt
+                << ",\"major_faults\":" << usage_after.ru_majflt - usage_before.ru_majflt << '}';
+#else
+      std::cout << "null";
+#endif
+      std::cout << '}';
     }
     std::cout << "}\n";
     return std::cout ? 0 : 1;

models/experimental/sequence_probe.py

@@ -143,6 +143,18 @@ def _build(header, model_metadata, library, directory, compiler, *, allocations=
     return binary, provenance
 
 
+def validate_resources(resources):
+    if resources is None:
+        return
+    fields = {
+        "user_cpu_ns", "system_cpu_ns", "voluntary_switches", "involuntary_switches",
+        "minor_faults", "major_faults",
+    }
+    if (not isinstance(resources, dict) or set(resources) != fields or
+            any(type(v) is not int or not 0 <= v < 2**63 for v in resources.values())):
+        raise ValueError("invalid native resource counters")
+
+
 def observe(binary, data, iterations=None):
     if len(data) > 65536:
         raise ValueError("probe input exceeds 65536 bytes")
@@ -172,6 +184,7 @@ def observe(binary, data, iterations=None):
         expected = int(observation["snapshot"]["confidence_bits"], 16) * iterations
         if benchmark["elapsed_ns"] <= 0 or benchmark["checksum"] != expected:
             raise ValueError("invalid native elapsed time/checksum")
+        validate_resources(benchmark.get("resources"))
     return observation
 
 

models/experimental/test_sequence_probe.py

@@ -1,6 +1,7 @@
 # SPDX-License-Identifier: MIT
 import os
 import struct
+import sys
 import subprocess
 import tempfile
 import unittest
@@ -13,6 +14,18 @@
 
 
 class SequenceProbeGuards(unittest.TestCase):
+    def test_resource_counter_validation(self):
+        valid = dict(user_cpu_ns=0, system_cpu_ns=1000, voluntary_switches=0,
+                     involuntary_switches=2, minor_faults=0, major_faults=0)
+        sequence_probe.validate_resources(valid)
+        sequence_probe.validate_resources(None)
+        for value in (-1, True, 1.5, 2**63):
+            with self.assertRaisesRegex(ValueError, "resource"):
+                sequence_probe.validate_resources(valid | {"user_cpu_ns": value})
+        for invalid in ({}, [], valid | {"unknown": 1}):
+            with self.assertRaisesRegex(ValueError, "resource"):
+                sequence_probe.validate_resources(invalid)
+
     def test_iteration_limits_before_execution(self):
         for iterations in (0, -1, 1000001, True, 1.5):
             with patch.object(sequence_probe.subprocess, "run") as run:
@@ -125,6 +138,9 @@ def test_timing_preserves_observation_and_checksum(self):
             self.assertEqual(benchmark["iterations"], 3)
             self.assertEqual(benchmark["warmup_iterations"], 128)
             self.assertGreater(benchmark["elapsed_ns"], 0)
+            sequence_probe.validate_resources(benchmark["resources"])
+            if sys.platform == "linux":
+                self.assertIsInstance(benchmark["resources"], dict)
             self.assertEqual(
                 benchmark["checksum"], 3 * int(baseline["snapshot"]["confidence_bits"], 16)
             )