diff --git a/models/experimental/MODEL_TIMING.ja.md b/models/experimental/MODEL_TIMING.ja.md index c823e3d..174fe9a 100644 --- a/models/experimental/MODEL_TIMING.ja.md +++ b/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、 diff --git a/models/experimental/model_timing.py b/models/experimental/model_timing.py index caed9f4..f36d816 100644 --- a/models/experimental/model_timing.py +++ b/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" diff --git a/models/experimental/sequence-probe.cpp b/models/experimental/sequence-probe.cpp index f1b0350..f5fe25e 100644 --- a/models/experimental/sequence-probe.cpp +++ b/models/experimental/sequence-probe.cpp @@ -11,6 +11,9 @@ #include #include #include +#ifdef __linux__ +#include +#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::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(value.tv_sec) * 1000000000 + + static_cast(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; diff --git a/models/experimental/sequence_probe.py b/models/experimental/sequence_probe.py index 647deec..755fff5 100644 --- a/models/experimental/sequence_probe.py +++ b/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 diff --git a/models/experimental/test_sequence_probe.py b/models/experimental/test_sequence_probe.py index e930c73..477cad6 100644 --- a/models/experimental/test_sequence_probe.py +++ b/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) )