From 9a7649d4bfaff1a19aeffbbe28d11f9b73c2fb7c Mon Sep 17 00:00:00 2001 From: Yuxuan Jiang Date: Mon, 26 Oct 2026 19:09:29 +0800 Subject: [PATCH 1/5] Document tracing metadata and warning-management hotspots --- .../data/tracing-hotspot-audit-20261026.json | 1224 +++++++++++++++++ .../tracing-hotspot-audit-20261026.md | 134 ++ 2 files changed, 1358 insertions(+) create mode 100644 docs/measurements/data/tracing-hotspot-audit-20261026.json create mode 100644 docs/measurements/tracing-hotspot-audit-20261026.md diff --git a/docs/measurements/data/tracing-hotspot-audit-20261026.json b/docs/measurements/data/tracing-hotspot-audit-20261026.json new file mode 100644 index 00000000..b19790e9 --- /dev/null +++ b/docs/measurements/data/tracing-hotspot-audit-20261026.json @@ -0,0 +1,1224 @@ +{ + "artifacts": { + "adapter_sha256": "3a9723a7bc2c165493eb4e45b0dbe1f4e44e0f991b2e0bf64f5ef2b9c05d8ab5", + "archive_bytes": 80977920, + "archive_name": "remote-evidence.tar", + "archive_sha256": "31ad9746dc9b5318b3f49d9119c86606dce48194ac92701695960bb537a84036", + "audit_runner_sha256": "5ac3cb8f5a20bcdeefb2d6146a4060453f50d4d4d5a97e2c734ed93e410f4530", + "remote_directory": "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687", + "source_archive_sha256": "2574db44cdf2854160385dadef013968188f6688d2d70e57bf577a1bbfc20973" + }, + "configuration": { + "batch_size": 2, + "case_limits": { + "main_RSS_bytes": 4294967296, + "timeout_seconds": 90, + "trace_bytes": 268435456 + }, + "device": "cpu", + "dtype": "float32", + "hash_seed": 0, + "instrumentation": "Normal torch API coverage, unfiltered argument/return metadata, use_full_instr=False, descriptors disabled, no proxy/model tracking, no tensor-value dump, interval1,warmup0", + "instrumented_function_count": 20998, + "seed": 42, + "steps": 3, + "training_seed": 43 + }, + "hardware": { + "cpu": "Intel Core i9-13900K", + "cpu_affinity": false, + "exclusive_host": false, + "host_alias": "labmach", + "hostname": "yuxuan-Precision-3660", + "logical_cpus": 32, + "native_threads": 1, + "platform": "Linux-6.1.0-1027-oem-x86_64-with-glibc2.35", + "python": "3.11.4 (main, Jul 5 2023, 13:45:01) [GCC 11.2.0]" + }, + "limits": [ + "Two alternating unprofiled pairs and one distinct profile per workload; three steps including first-step effects; no steady-state or confidence claim", + "Tiny CPU training workloads; no GPU/distributed/online-checking overhead claim", + "cProfile slows Python-heavy paths; its percentages are profiled main-thread time and cannot be applied directly to unprofiled wall time", + "Profile excludes setup,start_step,loss extraction,state hashing,background writer and shutdown; unprofiled training wall includes start_step and wrapper-disable assignment", + "Raw traces across fresh processes contain different timestamps and identities; no normalization or trace-equivalence claim", + "Current full-API metadata collection, not selective checking mode or full tensor-value capture", + "No production optimization or speedup candidate was implemented" + ], + "production_source_modified": false, + "schema_version": 1, + "source_commit": "205a687eef30e498bd2d9a9951652b7cc05bec68", + "source_hashes_verified_after_download": true, + "source_python_file_count": 77, + "source_tree": "2177e2fa826bb4623c3c9cdbb3bdcb61fafbedab", + "verification": { + "all_downloaded_trace_digests_counts_and_pairs_verified": true, + "all_model_and_loss_parity_checks_passed": true, + "completed_cases": 10, + "verified_raw_trace_files": 6 + }, + "workloads": { + "mnist": { + "adaptation": { + "adapter_sha256": "3a9723a7bc2c165493eb4e45b0dbe1f4e44e0f991b2e0bf64f5ef2b9c05d8ab5", + "batch_size": 2, + "benchmark_source": "/home/yuxuan/experiments/codex-trace-impact-20261013/benchmarks/instr-overhead/overhead-e2e/mnist/main.py", + "benchmark_source_sha256": "4478c5de92610a1e03d61c356801d51ffca749f99dac00f234d6b6ea2bcb2aa7", + "data": { + "count": 6, + "files": [ + { + "path": "/home/yuxuan/gitrepos/data/MNIST/raw/train-images-idx3-ubyte", + "sha256": "ba891046e6505d7aadcbbe25680a0738ad16aec93bde7f9b65e87a2fc25776db" + }, + { + "path": "/home/yuxuan/gitrepos/data/MNIST/raw/train-labels-idx1-ubyte", + "sha256": "65a50cbbf4e906d70832878ad85ccda5333a97f0f4c3dd2ef09a8a9eef7101c5" + } + ], + "kind": "cached_mnist_training_prefix", + "normalization": "(uint8 / 255 - 0.1307) / 0.3081", + "ordering": "first samples in IDX order; no shuffle" + }, + "extracted_definitions_sha256": "f839142a57ce449054e05ffa79d746e5282e2599e101810e6ccf6e7a9dd33ce5", + "model_config": { + "architecture": "exact Net class" + }, + "parameter_count": 1199882, + "seed": 42, + "steps": 3, + "torch_version": "2.16.0.dev20261012+cpu", + "training_rng_seed": 43 + }, + "parity": { + "all_canonical_state_hashes_equal": true, + "all_state_shapes_equal": true, + "complete_loss_trajectories_equal": true, + "every_call_has_one_pre_and_one_post": true, + "final_state_sha256": "f20e5ffbd73ae70379e3a9360e4fe2cf78c4cae0168b259f8070a8d77fc2f097", + "initial_state_sha256": "877e9abeb783ae5ed703a9666a7276e921e0424b78bb2d50a41461221d90ddb0", + "raw_trace_equality_between_runs_claimed": false, + "trace_files_checked_by_raw_sha256": true + }, + "profile": { + "attribute_access_with_warning_context": { + "cumulative_percent": 54.53479215939012, + "cumulative_seconds": 0.497381218, + "file": "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/source/traincheck/instrumentor/dumper.py", + "function": "safe_getattr", + "line": 328, + "primitive_calls": 172768, + "self_percent": 16.20618712576155, + "self_seconds": 0.14780753300000002, + "total_calls": 172768 + }, + "context_getter": { + "cumulative_percent": 0.0024794860466412875, + "cumulative_seconds": 2.2614e-05, + "file": "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/source/traincheck/instrumentor/tracer.py", + "function": "get_meta_vars", + "line": 138, + "primitive_calls": 260, + "self_percent": 0.0024794860466412875, + "self_seconds": 2.2614e-05, + "total_calls": 260 + }, + "cumulative_rows_overlap_do_not_sum": true, + "denominator": "cProfile total time over the three training steps, main thread only", + "metadata_conversion": { + "cumulative_percent": 94.15436461744682, + "cumulative_seconds": 0.858729092, + "file": "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/source/traincheck/instrumentor/dumper.py", + "function": "convert_var_to_dict", + "line": 343, + "primitive_calls": 404, + "self_percent": 19.154807962358383, + "self_seconds": 0.174700248, + "total_calls": 404 + }, + "pid_tid_lookup": { + "cumulative_percent": 0.019916586247470443, + "cumulative_seconds": 0.00018164800000000002, + "file": "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/source/traincheck/instrumentor/tracer.py", + "function": "get_process_thread_id", + "line": 122, + "primitive_calls": 260, + "self_percent": 0.013997572594782584, + "self_seconds": 0.00012766400000000002, + "total_calls": 260 + }, + "profile_total_seconds": 0.9120438500000003, + "pstats_sha256": "8f4191c81b0b8e0dda4c405290ca2dd608787b591d29c6f2f2ba5f1cd1268514", + "stdlib_warning_functions_exclusive": { + "percent": 28.06110342172692, + "self_seconds": 0.255929568 + }, + "trace_json_serialization": { + "cumulative_percent": 0.4030543048999233, + "cumulative_seconds": 0.003676032, + "file": "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/source/traincheck/instrumentor/dumper.py", + "function": "serialize", + "line": 85, + "primitive_calls": 520, + "self_percent": 0.0383724971118439, + "self_seconds": 0.000349974, + "total_calls": 520 + } + }, + "runs": [ + { + "after_load_average": [ + 1.15771484375, + 1.1103515625, + 1.09326171875 + ], + "before_load_average": [ + 1.083984375, + 1.09521484375, + 1.087890625 + ], + "command": [ + "/home/yuxuan/experiments/codex-inference-runtime-20261025/venv/bin/python", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/audit_runner.py", + "--root", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687", + "--child", + "--workload", + "mnist", + "--mode", + "baseline", + "--output", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/runs/mnist-baseline-r1" + ], + "exit_code": 0, + "label": "mnist-baseline-r1", + "mode": "baseline", + "peak_main_RSS_bytes": 344936448, + "process_wall_seconds": 1.503827378153801, + "profiled": false, + "repetition": 1, + "steps": [ + { + "loss": 2.2311902046203613, + "seconds": 0.027345649898052216, + "step": 1 + }, + { + "loss": 3.296325445175171, + "seconds": 0.008510682731866837, + "step": 2 + }, + { + "loss": 2.6148438453674316, + "seconds": 0.007245682179927826, + "step": 3 + } + ], + "stop_reason": null, + "trace": { + "bytes": 0, + "call_count": 0, + "files": [], + "incomplete_or_exception_call_groups": {}, + "records": 0, + "records_by_api": {} + }, + "training_seconds": 0.04310201480984688 + }, + { + "after_load_average": [ + 1.14501953125, + 1.1083984375, + 1.09228515625 + ], + "before_load_average": [ + 1.15771484375, + 1.1103515625, + 1.09326171875 + ], + "command": [ + "/home/yuxuan/experiments/codex-inference-runtime-20261025/venv/bin/python", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/audit_runner.py", + "--root", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687", + "--child", + "--workload", + "mnist", + "--mode", + "instrumented", + "--output", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/runs/mnist-instrumented-r1" + ], + "exit_code": 0, + "label": "mnist-instrumented-r1", + "mode": "instrumented", + "peak_main_RSS_bytes": 572383232, + "process_wall_seconds": 6.21296213939786, + "profiled": false, + "repetition": 1, + "steps": [ + { + "loss": 2.2311902046203613, + "seconds": 0.14448309317231178, + "step": 1 + }, + { + "loss": 3.296325445175171, + "seconds": 0.09355559572577477, + "step": 2 + }, + { + "loss": 2.6148438453674316, + "seconds": 0.0937160812318325, + "step": 3 + } + ], + "stop_reason": null, + "trace": { + "bytes": 351073, + "call_count": 260, + "files": [ + { + "bytes": 351073, + "name": "trace_API_1673618_140358980621376.log", + "records": 520, + "sha256": "fd96459630c6d399e52280068c79dcb8b890002bd3f20934d7588b35fcf7c693" + } + ], + "incomplete_or_exception_call_groups": {}, + "records": 520, + "records_by_api": { + "torch._VariableFunctionsClass.conv2d": 12, + "torch._VariableFunctionsClass.flatten": 6, + "torch._VariableFunctionsClass.is_complex": 144, + "torch._VariableFunctionsClass.max_pool2d": 6, + "torch._VariableFunctionsClass.ones_like": 6, + "torch._VariableFunctionsClass.relu": 18, + "torch._VariableFunctionsClass.zeros": 16, + "torch._VariableFunctionsClass.zeros_like": 32, + "torch._ops.TorchBindOpOverload.__call__": 12, + "torch._ops._contains_fake_script_object": 12, + "torch._ops._must_dispatch_in_python": 12, + "torch._tensor.Tensor.backward": 6, + "torch.accelerator.current_accelerator": 6, + "torch.compiler.is_compiling": 24, + "torch.compiler.is_exporting": 6, + "torch.is_grad_enabled": 18, + "torch.nn._reduction.get_enum": 6, + "torch.nn.functional.boolean_dispatch..fn": 6, + "torch.nn.functional.dropout": 12, + "torch.nn.functional.log_softmax": 6, + "torch.nn.functional.nll_loss": 6, + "torch.nn.functional.relu": 18, + "torch.nn.modules.conv.Conv2d._conv_forward": 12, + "torch.nn.modules.conv.Conv2d.forward": 12, + "torch.nn.modules.dropout.Dropout.forward": 12, + "torch.nn.modules.linear.Linear.forward": 12, + "torch.optim.adadelta.Adadelta._init_group": 6, + "torch.optim.adadelta.Adadelta.step": 6, + "torch.optim.adadelta._single_tensor_adadelta": 6, + "torch.optim.adadelta.adadelta": 6, + "torch.optim.optimizer.Optimizer._accelerator_graph_capture_health_check": 6, + "torch.optim.optimizer.Optimizer._optimizer_step_code": 6, + "torch.optim.optimizer.Optimizer.zero_grad": 6, + "torch.optim.optimizer._default_to_fused_or_foreach": 6, + "torch.optim.optimizer._get_scalar_dtype": 16, + "torch.optim.optimizer._to_scalar": 6, + "torch.utils._foreach_utils._get_foreach_kernels_supported_devices": 6, + "torch.utils._foreach_utils._get_fused_kernels_supported_devices": 6 + } + }, + "training_seconds": 0.33175477012991905 + }, + { + "after_load_average": [ + 1.2939453125, + 1.14013671875, + 1.1025390625 + ], + "before_load_average": [ + 1.14501953125, + 1.1083984375, + 1.09228515625 + ], + "command": [ + "/home/yuxuan/experiments/codex-inference-runtime-20261025/venv/bin/python", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/audit_runner.py", + "--root", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687", + "--child", + "--workload", + "mnist", + "--mode", + "instrumented", + "--output", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/runs/mnist-instrumented-r2" + ], + "exit_code": 0, + "label": "mnist-instrumented-r2", + "mode": "instrumented", + "peak_main_RSS_bytes": 561512448, + "process_wall_seconds": 6.114231258630753, + "profiled": false, + "repetition": 2, + "steps": [ + { + "loss": 2.2311902046203613, + "seconds": 0.1442841961979866, + "step": 1 + }, + { + "loss": 3.296325445175171, + "seconds": 0.09362511709332466, + "step": 2 + }, + { + "loss": 2.6148438453674316, + "seconds": 0.09420855715870857, + "step": 3 + } + ], + "stop_reason": null, + "trace": { + "bytes": 351073, + "call_count": 260, + "files": [ + { + "bytes": 351073, + "name": "trace_API_1673639_140638032565312.log", + "records": 520, + "sha256": "f7128590cb337830d498663a62ccaa99dc0e2298ab5cc96a853ffeb8f7df0f01" + } + ], + "incomplete_or_exception_call_groups": {}, + "records": 520, + "records_by_api": { + "torch._VariableFunctionsClass.conv2d": 12, + "torch._VariableFunctionsClass.flatten": 6, + "torch._VariableFunctionsClass.is_complex": 144, + "torch._VariableFunctionsClass.max_pool2d": 6, + "torch._VariableFunctionsClass.ones_like": 6, + "torch._VariableFunctionsClass.relu": 18, + "torch._VariableFunctionsClass.zeros": 16, + "torch._VariableFunctionsClass.zeros_like": 32, + "torch._ops.TorchBindOpOverload.__call__": 12, + "torch._ops._contains_fake_script_object": 12, + "torch._ops._must_dispatch_in_python": 12, + "torch._tensor.Tensor.backward": 6, + "torch.accelerator.current_accelerator": 6, + "torch.compiler.is_compiling": 24, + "torch.compiler.is_exporting": 6, + "torch.is_grad_enabled": 18, + "torch.nn._reduction.get_enum": 6, + "torch.nn.functional.boolean_dispatch..fn": 6, + "torch.nn.functional.dropout": 12, + "torch.nn.functional.log_softmax": 6, + "torch.nn.functional.nll_loss": 6, + "torch.nn.functional.relu": 18, + "torch.nn.modules.conv.Conv2d._conv_forward": 12, + "torch.nn.modules.conv.Conv2d.forward": 12, + "torch.nn.modules.dropout.Dropout.forward": 12, + "torch.nn.modules.linear.Linear.forward": 12, + "torch.optim.adadelta.Adadelta._init_group": 6, + "torch.optim.adadelta.Adadelta.step": 6, + "torch.optim.adadelta._single_tensor_adadelta": 6, + "torch.optim.adadelta.adadelta": 6, + "torch.optim.optimizer.Optimizer._accelerator_graph_capture_health_check": 6, + "torch.optim.optimizer.Optimizer._optimizer_step_code": 6, + "torch.optim.optimizer.Optimizer.zero_grad": 6, + "torch.optim.optimizer._default_to_fused_or_foreach": 6, + "torch.optim.optimizer._get_scalar_dtype": 16, + "torch.optim.optimizer._to_scalar": 6, + "torch.utils._foreach_utils._get_foreach_kernels_supported_devices": 6, + "torch.utils._foreach_utils._get_fused_kernels_supported_devices": 6 + } + }, + "training_seconds": 0.33211787045001984 + }, + { + "after_load_average": [ + 1.2939453125, + 1.14013671875, + 1.1025390625 + ], + "before_load_average": [ + 1.2939453125, + 1.14013671875, + 1.1025390625 + ], + "command": [ + "/home/yuxuan/experiments/codex-inference-runtime-20261025/venv/bin/python", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/audit_runner.py", + "--root", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687", + "--child", + "--workload", + "mnist", + "--mode", + "baseline", + "--output", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/runs/mnist-baseline-r2" + ], + "exit_code": 0, + "label": "mnist-baseline-r2", + "mode": "baseline", + "peak_main_RSS_bytes": 345812992, + "process_wall_seconds": 1.403785590082407, + "profiled": false, + "repetition": 2, + "steps": [ + { + "loss": 2.2311902046203613, + "seconds": 0.015248574316501617, + "step": 1 + }, + { + "loss": 3.296325445175171, + "seconds": 0.007440429180860519, + "step": 2 + }, + { + "loss": 2.6148438453674316, + "seconds": 0.007134035229682922, + "step": 3 + } + ], + "stop_reason": null, + "trace": { + "bytes": 0, + "call_count": 0, + "files": [], + "incomplete_or_exception_call_groups": {}, + "records": 0, + "records_by_api": {} + }, + "training_seconds": 0.02982303872704506 + }, + { + "after_load_average": [ + 1.39599609375, + 1.16845703125, + 1.11181640625 + ], + "before_load_average": [ + 1.2939453125, + 1.14013671875, + 1.1025390625 + ], + "command": [ + "/home/yuxuan/experiments/codex-inference-runtime-20261025/venv/bin/python", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/audit_runner.py", + "--root", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687", + "--child", + "--workload", + "mnist", + "--mode", + "instrumented", + "--output", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/runs/mnist-instrumented-r1-profile", + "--profile" + ], + "exit_code": 0, + "label": "mnist-instrumented-r1-profile", + "mode": "instrumented", + "peak_main_RSS_bytes": 567246848, + "process_wall_seconds": 6.615078143775463, + "profiled": true, + "repetition": 1, + "steps": [ + { + "loss": 2.2311902046203613, + "seconds": 0.3891378231346607, + "step": 1 + }, + { + "loss": 3.296325445175171, + "seconds": 0.2634742856025696, + "step": 2 + }, + { + "loss": 2.6148438453674316, + "seconds": 0.2595182843506336, + "step": 3 + } + ], + "stop_reason": null, + "trace": { + "bytes": 351073, + "call_count": 260, + "files": [ + { + "bytes": 351073, + "name": "trace_API_1673690_140017730217024.log", + "records": 520, + "sha256": "09a7bfa5f591018ce027bfe5e72fdf6708a152964cc0981974f8cfa88a59c315" + } + ], + "incomplete_or_exception_call_groups": {}, + "records": 520, + "records_by_api": { + "torch._VariableFunctionsClass.conv2d": 12, + "torch._VariableFunctionsClass.flatten": 6, + "torch._VariableFunctionsClass.is_complex": 144, + "torch._VariableFunctionsClass.max_pool2d": 6, + "torch._VariableFunctionsClass.ones_like": 6, + "torch._VariableFunctionsClass.relu": 18, + "torch._VariableFunctionsClass.zeros": 16, + "torch._VariableFunctionsClass.zeros_like": 32, + "torch._ops.TorchBindOpOverload.__call__": 12, + "torch._ops._contains_fake_script_object": 12, + "torch._ops._must_dispatch_in_python": 12, + "torch._tensor.Tensor.backward": 6, + "torch.accelerator.current_accelerator": 6, + "torch.compiler.is_compiling": 24, + "torch.compiler.is_exporting": 6, + "torch.is_grad_enabled": 18, + "torch.nn._reduction.get_enum": 6, + "torch.nn.functional.boolean_dispatch..fn": 6, + "torch.nn.functional.dropout": 12, + "torch.nn.functional.log_softmax": 6, + "torch.nn.functional.nll_loss": 6, + "torch.nn.functional.relu": 18, + "torch.nn.modules.conv.Conv2d._conv_forward": 12, + "torch.nn.modules.conv.Conv2d.forward": 12, + "torch.nn.modules.dropout.Dropout.forward": 12, + "torch.nn.modules.linear.Linear.forward": 12, + "torch.optim.adadelta.Adadelta._init_group": 6, + "torch.optim.adadelta.Adadelta.step": 6, + "torch.optim.adadelta._single_tensor_adadelta": 6, + "torch.optim.adadelta.adadelta": 6, + "torch.optim.optimizer.Optimizer._accelerator_graph_capture_health_check": 6, + "torch.optim.optimizer.Optimizer._optimizer_step_code": 6, + "torch.optim.optimizer.Optimizer.zero_grad": 6, + "torch.optim.optimizer._default_to_fused_or_foreach": 6, + "torch.optim.optimizer._get_scalar_dtype": 16, + "torch.optim.optimizer._to_scalar": 6, + "torch.utils._foreach_utils._get_foreach_kernels_supported_devices": 6, + "torch.utils._foreach_utils._get_fused_kernels_supported_devices": 6 + } + }, + "training_seconds": 0.9121303930878639 + } + ], + "unprofiled": { + "baseline_median_seconds": 0.03646252676844597, + "baseline_three_step_seconds": [ + 0.04310201480984688, + 0.02982303872704506 + ], + "ratio_of_two_medians": 9.103491987758273, + "traced_median_seconds": 0.33193632028996944, + "traced_three_step_seconds": [ + 0.33175477012991905, + 0.33211787045001984 + ] + } + }, + "transformer": { + "adaptation": { + "adapter_sha256": "3a9723a7bc2c165493eb4e45b0dbe1f4e44e0f991b2e0bf64f5ef2b9c05d8ab5", + "batch_size": 2, + "benchmark_source": "/home/yuxuan/experiments/codex-trace-impact-20261013/benchmarks/false-positive/RNN/trainset/word_language_model-RNN_TANH-3epo/model.py", + "benchmark_source_sha256": "e4451a33e9b16953004bc639d736d14f42a2b21f2939ccabe4cff10d3c40b74c", + "data": { + "adaptation": "Whitespace tokenization plus ; vocabulary and tensors are bounded to the chosen prefix, unlike the full benchmark corpus.", + "kind": "wikitext2_training_prefix_with_prefix_only_vocabulary", + "path": "/home/yuxuan/experiments/codex-trace-impact-20261013/benchmarks/false-positive/RNN/trainset/word_language_model-RNN_TANH-3epo/data/wikitext-2/train.txt", + "prefix_sha256": "9b0b504c73ee103a9128f2072536e99b2696039399bd57669477f030db10eb35", + "sha256": "9e9fa1ad55b1c2c95b08e37dd8e653f638fac2c6de904b79e813611eefbc985f", + "token_count": 98, + "vocabulary_size": 60 + }, + "extracted_definitions_sha256": "1f2db95454690be6a91aaa141e3a5a246308f9abca11444c9113e4adfb78b95d", + "model_config": { + "clip": 0.25, + "dropout_argument": 0.2, + "lr": 1.0, + "nhead": 2, + "nhid": 64, + "ninp": 32, + "nlayers": 2, + "ntoken": 60, + "sequence_length": 16 + }, + "parameter_count": 21052, + "seed": 42, + "steps": 3, + "torch_version": "2.16.0.dev20261012+cpu", + "training_rng_seed": 43 + }, + "parity": { + "all_canonical_state_hashes_equal": true, + "all_state_shapes_equal": true, + "complete_loss_trajectories_equal": true, + "every_call_has_one_pre_and_one_post": true, + "final_state_sha256": "8f17d60efae8fc6f1fcdc3995f560af9a16a85a39c48074810f243f7946cdbc1", + "initial_state_sha256": "e197d3c2a3f351146bc265c5b3eb54dcd1d921499ce24d1cc61bdc5e6dce886d", + "raw_trace_equality_between_runs_claimed": false, + "trace_files_checked_by_raw_sha256": true + }, + "profile": { + "attribute_access_with_warning_context": { + "cumulative_percent": 56.290137875646614, + "cumulative_seconds": 1.3929320920000001, + "file": "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/source/traincheck/instrumentor/dumper.py", + "function": "safe_getattr", + "line": 328, + "primitive_calls": 477225, + "self_percent": 16.62318152653597, + "self_seconds": 0.41135026300000005, + "total_calls": 477225 + }, + "context_getter": { + "cumulative_percent": 0.002171862639509602, + "cumulative_seconds": 5.3744000000000006e-05, + "file": "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/source/traincheck/instrumentor/tracer.py", + "function": "get_meta_vars", + "line": 138, + "primitive_calls": 669, + "self_percent": 0.002171862639509602, + "self_seconds": 5.3744000000000006e-05, + "total_calls": 669 + }, + "cumulative_rows_overlap_do_not_sum": true, + "denominator": "cProfile total time over the three training steps, main thread only", + "metadata_conversion": { + "cumulative_percent": 97.54291716798443, + "cumulative_seconds": 2.413756029, + "file": "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/source/traincheck/instrumentor/dumper.py", + "function": "convert_var_to_dict", + "line": 343, + "primitive_calls": 1709, + "self_percent": 19.938888778539205, + "self_seconds": 0.49339936100000004, + "total_calls": 1709 + }, + "pid_tid_lookup": { + "cumulative_percent": 0.017974200069335363, + "cumulative_seconds": 0.000444782, + "file": "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/source/traincheck/instrumentor/tracer.py", + "function": "get_process_thread_id", + "line": 122, + "primitive_calls": 669, + "self_percent": 0.012582812931703359, + "self_seconds": 0.00031136900000000003, + "total_calls": 669 + }, + "profile_total_seconds": 2.4745579680000014, + "pstats_sha256": "899e7be474ac75cf3d9febe7ec7f6b4467f2b47cae2f0b936ccbe9ec95a0c7f9", + "stdlib_warning_functions_exclusive": { + "percent": 28.89372369716091, + "self_seconds": 0.7149919419999999 + }, + "trace_json_serialization": { + "cumulative_percent": 0.3973933982216574, + "cumulative_seconds": 0.00983373, + "file": "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/source/traincheck/instrumentor/dumper.py", + "function": "serialize", + "line": 85, + "primitive_calls": 1338, + "self_percent": 0.03603447611779687, + "self_seconds": 0.0008916940000000001, + "total_calls": 1338 + } + }, + "runs": [ + { + "after_load_average": [ + 1.39599609375, + 1.16845703125, + 1.11181640625 + ], + "before_load_average": [ + 1.39599609375, + 1.16845703125, + 1.11181640625 + ], + "command": [ + "/home/yuxuan/experiments/codex-inference-runtime-20261025/venv/bin/python", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/audit_runner.py", + "--root", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687", + "--child", + "--workload", + "transformer", + "--mode", + "baseline", + "--output", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/runs/transformer-baseline-r1" + ], + "exit_code": 0, + "label": "transformer-baseline-r1", + "mode": "baseline", + "peak_main_RSS_bytes": 336105472, + "process_wall_seconds": 1.4032803736627102, + "profiled": false, + "repetition": 1, + "steps": [ + { + "loss": 4.222344875335693, + "seconds": 0.005870260298252106, + "step": 1 + }, + { + "loss": 4.122839450836182, + "seconds": 0.0014097988605499268, + "step": 2 + }, + { + "loss": 4.136002063751221, + "seconds": 0.001257430762052536, + "step": 3 + } + ], + "stop_reason": null, + "trace": { + "bytes": 0, + "call_count": 0, + "files": [], + "incomplete_or_exception_call_groups": {}, + "records": 0, + "records_by_api": {} + }, + "training_seconds": 0.008537489920854568 + }, + { + "after_load_average": [ + 1.44482421875, + 1.1826171875, + 1.11669921875 + ], + "before_load_average": [ + 1.39599609375, + 1.16845703125, + 1.11181640625 + ], + "command": [ + "/home/yuxuan/experiments/codex-inference-runtime-20261025/venv/bin/python", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/audit_runner.py", + "--root", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687", + "--child", + "--workload", + "transformer", + "--mode", + "instrumented", + "--output", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/runs/transformer-instrumented-r1" + ], + "exit_code": 0, + "label": "transformer-instrumented-r1", + "mode": "instrumented", + "peak_main_RSS_bytes": 542380032, + "process_wall_seconds": 6.612125892192125, + "profiled": false, + "repetition": 1, + "steps": [ + { + "loss": 4.222344875335693, + "seconds": 0.28463035449385643, + "step": 1 + }, + { + "loss": 4.122839450836182, + "seconds": 0.2833110876381397, + "step": 2 + }, + { + "loss": 4.136002063751221, + "seconds": 0.3104921653866768, + "step": 3 + } + ], + "stop_reason": null, + "trace": { + "bytes": 1014134, + "call_count": 669, + "files": [ + { + "bytes": 1014134, + "name": "trace_API_1673711_139733505803328.log", + "records": 1338, + "sha256": "897ba9b25efe0db0ec305e732e476996c88fb0ab3c80528e962f5bbead9be043" + } + ], + "incomplete_or_exception_call_groups": {}, + "records": 1338, + "records_by_api": { + "torch._VariableFunctionsClass._foreach_mul_": 6, + "torch._VariableFunctionsClass._foreach_norm": 6, + "torch._VariableFunctionsClass.clamp": 6, + "torch._VariableFunctionsClass.embedding": 6, + "torch._VariableFunctionsClass.full": 6, + "torch._VariableFunctionsClass.is_floating_point": 42, + "torch._VariableFunctionsClass.layer_norm": 30, + "torch._VariableFunctionsClass.log": 2, + "torch._VariableFunctionsClass.ones": 2, + "torch._VariableFunctionsClass.ones_like": 6, + "torch._VariableFunctionsClass.relu": 12, + "torch._VariableFunctionsClass.stack": 6, + "torch._VariableFunctionsClass.tril": 2, + "torch._VariableFunctionsClass.triu": 6, + "torch._tensor.Tensor.backward": 6, + "torch._tensor.Tensor.unflatten": 12, + "torch.backends.mha.get_fastpath_enabled": 30, + "torch.is_grad_enabled": 90, + "torch.nn._reduction.get_enum": 6, + "torch.nn.functional._canonical_mask": 72, + "torch.nn.functional._in_projection_packed": 12, + "torch.nn.functional._mha_shape_check": 12, + "torch.nn.functional._none_or_dtype": 42, + "torch.nn.functional.dropout": 42, + "torch.nn.functional.embedding": 6, + "torch.nn.functional.layer_norm": 30, + "torch.nn.functional.log_softmax": 6, + "torch.nn.functional.multi_head_attention_forward": 12, + "torch.nn.functional.nll_loss": 6, + "torch.nn.modules.activation.MultiheadAttention.forward": 12, + "torch.nn.modules.container.ModuleList._get_abs_string_index": 6, + "torch.nn.modules.dropout.Dropout.forward": 42, + "torch.nn.modules.linear.Linear.forward": 30, + "torch.nn.modules.module.Module._named_members": 18, + "torch.nn.modules.module.Module.named_modules": 504, + "torch.nn.modules.module.Module.named_parameters": 18, + "torch.nn.modules.module.Module.parameters": 18, + "torch.nn.modules.module.Module.zero_grad": 6, + "torch.nn.modules.normalization.LayerNorm.forward": 30, + "torch.nn.modules.sparse.Embedding.forward": 6, + "torch.nn.modules.transformer.TransformerEncoder.forward": 6, + "torch.nn.modules.transformer.TransformerEncoderLayer._ff_block": 12, + "torch.nn.modules.transformer.TransformerEncoderLayer._sa_block": 12, + "torch.nn.modules.transformer.TransformerEncoderLayer.forward": 12, + "torch.nn.modules.transformer._detect_is_causal_mask": 6, + "torch.nn.modules.transformer._generate_square_subsequent_mask": 6, + "torch.nn.modules.transformer._get_seq_len": 6, + "torch.nn.utils.clip_grad._clip_grads_with_norm_": 6, + "torch.nn.utils.clip_grad._get_total_norm": 6, + "torch.nn.utils.clip_grad.clip_grad_norm_": 6, + "torch.utils._foreach_utils._device_has_foreach_support": 12, + "torch.utils._foreach_utils._get_foreach_kernels_supported_devices": 12, + "torch.utils._foreach_utils._group_tensors_by_device_and_dtype": 12, + "torch.utils._foreach_utils._has_foreach_support": 12 + } + }, + "training_seconds": 0.8784336075186729 + }, + { + "after_load_average": [ + 1.53076171875, + 1.2099609375, + 1.12646484375 + ], + "before_load_average": [ + 1.44482421875, + 1.1826171875, + 1.11669921875 + ], + "command": [ + "/home/yuxuan/experiments/codex-inference-runtime-20261025/venv/bin/python", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/audit_runner.py", + "--root", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687", + "--child", + "--workload", + "transformer", + "--mode", + "instrumented", + "--output", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/runs/transformer-instrumented-r2" + ], + "exit_code": 0, + "label": "transformer-instrumented-r2", + "mode": "instrumented", + "peak_main_RSS_bytes": 542195712, + "process_wall_seconds": 6.514302123337984, + "profiled": false, + "repetition": 2, + "steps": [ + { + "loss": 4.222344875335693, + "seconds": 0.2782718352973461, + "step": 1 + }, + { + "loss": 4.122839450836182, + "seconds": 0.2699402682483196, + "step": 2 + }, + { + "loss": 4.136002063751221, + "seconds": 0.27383317053318024, + "step": 3 + } + ], + "stop_reason": null, + "trace": { + "bytes": 1014134, + "call_count": 669, + "files": [ + { + "bytes": 1014134, + "name": "trace_API_1673771_140584477529152.log", + "records": 1338, + "sha256": "98e024c367f52bfde3bfd810bda836a08edb618eb98dc42a912233bfa1b7450b" + } + ], + "incomplete_or_exception_call_groups": {}, + "records": 1338, + "records_by_api": { + "torch._VariableFunctionsClass._foreach_mul_": 6, + "torch._VariableFunctionsClass._foreach_norm": 6, + "torch._VariableFunctionsClass.clamp": 6, + "torch._VariableFunctionsClass.embedding": 6, + "torch._VariableFunctionsClass.full": 6, + "torch._VariableFunctionsClass.is_floating_point": 42, + "torch._VariableFunctionsClass.layer_norm": 30, + "torch._VariableFunctionsClass.log": 2, + "torch._VariableFunctionsClass.ones": 2, + "torch._VariableFunctionsClass.ones_like": 6, + "torch._VariableFunctionsClass.relu": 12, + "torch._VariableFunctionsClass.stack": 6, + "torch._VariableFunctionsClass.tril": 2, + "torch._VariableFunctionsClass.triu": 6, + "torch._tensor.Tensor.backward": 6, + "torch._tensor.Tensor.unflatten": 12, + "torch.backends.mha.get_fastpath_enabled": 30, + "torch.is_grad_enabled": 90, + "torch.nn._reduction.get_enum": 6, + "torch.nn.functional._canonical_mask": 72, + "torch.nn.functional._in_projection_packed": 12, + "torch.nn.functional._mha_shape_check": 12, + "torch.nn.functional._none_or_dtype": 42, + "torch.nn.functional.dropout": 42, + "torch.nn.functional.embedding": 6, + "torch.nn.functional.layer_norm": 30, + "torch.nn.functional.log_softmax": 6, + "torch.nn.functional.multi_head_attention_forward": 12, + "torch.nn.functional.nll_loss": 6, + "torch.nn.modules.activation.MultiheadAttention.forward": 12, + "torch.nn.modules.container.ModuleList._get_abs_string_index": 6, + "torch.nn.modules.dropout.Dropout.forward": 42, + "torch.nn.modules.linear.Linear.forward": 30, + "torch.nn.modules.module.Module._named_members": 18, + "torch.nn.modules.module.Module.named_modules": 504, + "torch.nn.modules.module.Module.named_parameters": 18, + "torch.nn.modules.module.Module.parameters": 18, + "torch.nn.modules.module.Module.zero_grad": 6, + "torch.nn.modules.normalization.LayerNorm.forward": 30, + "torch.nn.modules.sparse.Embedding.forward": 6, + "torch.nn.modules.transformer.TransformerEncoder.forward": 6, + "torch.nn.modules.transformer.TransformerEncoderLayer._ff_block": 12, + "torch.nn.modules.transformer.TransformerEncoderLayer._sa_block": 12, + "torch.nn.modules.transformer.TransformerEncoderLayer.forward": 12, + "torch.nn.modules.transformer._detect_is_causal_mask": 6, + "torch.nn.modules.transformer._generate_square_subsequent_mask": 6, + "torch.nn.modules.transformer._get_seq_len": 6, + "torch.nn.utils.clip_grad._clip_grads_with_norm_": 6, + "torch.nn.utils.clip_grad._get_total_norm": 6, + "torch.nn.utils.clip_grad.clip_grad_norm_": 6, + "torch.utils._foreach_utils._device_has_foreach_support": 12, + "torch.utils._foreach_utils._get_foreach_kernels_supported_devices": 12, + "torch.utils._foreach_utils._group_tensors_by_device_and_dtype": 12, + "torch.utils._foreach_utils._has_foreach_support": 12 + } + }, + "training_seconds": 0.822045274078846 + }, + { + "after_load_average": [ + 1.53076171875, + 1.2099609375, + 1.12646484375 + ], + "before_load_average": [ + 1.53076171875, + 1.2099609375, + 1.12646484375 + ], + "command": [ + "/home/yuxuan/experiments/codex-inference-runtime-20261025/venv/bin/python", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/audit_runner.py", + "--root", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687", + "--child", + "--workload", + "transformer", + "--mode", + "baseline", + "--output", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/runs/transformer-baseline-r2" + ], + "exit_code": 0, + "label": "transformer-baseline-r2", + "mode": "baseline", + "peak_main_RSS_bytes": 336072704, + "process_wall_seconds": 1.4045208059251308, + "profiled": false, + "repetition": 2, + "steps": [ + { + "loss": 4.222344875335693, + "seconds": 0.002191394567489624, + "step": 1 + }, + { + "loss": 4.122839450836182, + "seconds": 0.0013248734176158905, + "step": 2 + }, + { + "loss": 4.136002063751221, + "seconds": 0.0012663193047046661, + "step": 3 + } + ], + "stop_reason": null, + "trace": { + "bytes": 0, + "call_count": 0, + "files": [], + "incomplete_or_exception_call_groups": {}, + "records": 0, + "records_by_api": {} + }, + "training_seconds": 0.004782587289810181 + }, + { + "after_load_average": [ + 1.568359375, + 1.22314453125, + 1.13134765625 + ], + "before_load_average": [ + 1.53076171875, + 1.2099609375, + 1.12646484375 + ], + "command": [ + "/home/yuxuan/experiments/codex-inference-runtime-20261025/venv/bin/python", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/audit_runner.py", + "--root", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687", + "--child", + "--workload", + "transformer", + "--mode", + "instrumented", + "--output", + "/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687/runs/transformer-instrumented-r1-profile", + "--profile" + ], + "exit_code": 0, + "label": "transformer-instrumented-r1-profile", + "mode": "instrumented", + "peak_main_RSS_bytes": 541638656, + "process_wall_seconds": 8.118554219603539, + "profiled": true, + "repetition": 1, + "steps": [ + { + "loss": 4.222344875335693, + "seconds": 0.8321634531021118, + "step": 1 + }, + { + "loss": 4.122839450836182, + "seconds": 0.8210002928972244, + "step": 2 + }, + { + "loss": 4.136002063751221, + "seconds": 0.8215112648904324, + "step": 3 + } + ], + "stop_reason": null, + "trace": { + "bytes": 1014134, + "call_count": 669, + "files": [ + { + "bytes": 1014134, + "name": "trace_API_1673827_140219656655936.log", + "records": 1338, + "sha256": "31caf36c9d5d45616f663f96b5f5d51615c842bacff67810aee61554c8b3a5cc" + } + ], + "incomplete_or_exception_call_groups": {}, + "records": 1338, + "records_by_api": { + "torch._VariableFunctionsClass._foreach_mul_": 6, + "torch._VariableFunctionsClass._foreach_norm": 6, + "torch._VariableFunctionsClass.clamp": 6, + "torch._VariableFunctionsClass.embedding": 6, + "torch._VariableFunctionsClass.full": 6, + "torch._VariableFunctionsClass.is_floating_point": 42, + "torch._VariableFunctionsClass.layer_norm": 30, + "torch._VariableFunctionsClass.log": 2, + "torch._VariableFunctionsClass.ones": 2, + "torch._VariableFunctionsClass.ones_like": 6, + "torch._VariableFunctionsClass.relu": 12, + "torch._VariableFunctionsClass.stack": 6, + "torch._VariableFunctionsClass.tril": 2, + "torch._VariableFunctionsClass.triu": 6, + "torch._tensor.Tensor.backward": 6, + "torch._tensor.Tensor.unflatten": 12, + "torch.backends.mha.get_fastpath_enabled": 30, + "torch.is_grad_enabled": 90, + "torch.nn._reduction.get_enum": 6, + "torch.nn.functional._canonical_mask": 72, + "torch.nn.functional._in_projection_packed": 12, + "torch.nn.functional._mha_shape_check": 12, + "torch.nn.functional._none_or_dtype": 42, + "torch.nn.functional.dropout": 42, + "torch.nn.functional.embedding": 6, + "torch.nn.functional.layer_norm": 30, + "torch.nn.functional.log_softmax": 6, + "torch.nn.functional.multi_head_attention_forward": 12, + "torch.nn.functional.nll_loss": 6, + "torch.nn.modules.activation.MultiheadAttention.forward": 12, + "torch.nn.modules.container.ModuleList._get_abs_string_index": 6, + "torch.nn.modules.dropout.Dropout.forward": 42, + "torch.nn.modules.linear.Linear.forward": 30, + "torch.nn.modules.module.Module._named_members": 18, + "torch.nn.modules.module.Module.named_modules": 504, + "torch.nn.modules.module.Module.named_parameters": 18, + "torch.nn.modules.module.Module.parameters": 18, + "torch.nn.modules.module.Module.zero_grad": 6, + "torch.nn.modules.normalization.LayerNorm.forward": 30, + "torch.nn.modules.sparse.Embedding.forward": 6, + "torch.nn.modules.transformer.TransformerEncoder.forward": 6, + "torch.nn.modules.transformer.TransformerEncoderLayer._ff_block": 12, + "torch.nn.modules.transformer.TransformerEncoderLayer._sa_block": 12, + "torch.nn.modules.transformer.TransformerEncoderLayer.forward": 12, + "torch.nn.modules.transformer._detect_is_causal_mask": 6, + "torch.nn.modules.transformer._generate_square_subsequent_mask": 6, + "torch.nn.modules.transformer._get_seq_len": 6, + "torch.nn.utils.clip_grad._clip_grads_with_norm_": 6, + "torch.nn.utils.clip_grad._get_total_norm": 6, + "torch.nn.utils.clip_grad.clip_grad_norm_": 6, + "torch.utils._foreach_utils._device_has_foreach_support": 12, + "torch.utils._foreach_utils._get_foreach_kernels_supported_devices": 12, + "torch.utils._foreach_utils._group_tensors_by_device_and_dtype": 12, + "torch.utils._foreach_utils._has_foreach_support": 12 + } + }, + "training_seconds": 2.4746750108897686 + } + ], + "unprofiled": { + "baseline_median_seconds": 0.006660038605332375, + "baseline_three_step_seconds": [ + 0.008537489920854568, + 0.004782587289810181 + ], + "ratio_of_two_medians": 127.66283968954976, + "traced_median_seconds": 0.8502394407987595, + "traced_three_step_seconds": [ + 0.8784336075186729, + 0.822045274078846 + ] + } + } + } +} diff --git a/docs/measurements/tracing-hotspot-audit-20261026.md b/docs/measurements/tracing-hotspot-audit-20261026.md new file mode 100644 index 00000000..a810e361 --- /dev/null +++ b/docs/measurements/tracing-hotspot-audit-20261026.md @@ -0,0 +1,134 @@ +# Bounded tracing hotspot audit + +The first optimization target is object-metadata conversion. Repeated process/thread +lookups and context retrieval are already cheap in these runs. This investigation +changed no production code and does not claim a tracing speedup. + +## Unprofiled observation + +Two alternating fresh-process pairs per workload ran three CPU training steps: +plain then traced, followed by traced then plain. Both modes use the same model, +data, training math, and RNG resets. A fifth, separately profiled traced run was +used only for attribution. All ten cases completed successfully. + +| Workload | Parameters | Plain three-step wall time, two runs | Traced three-step wall time, two runs | API records per traced run | Raw API bytes | +|---|---:|---:|---:|---:|---:| +| MNIST | 1,199,882 | 0.043102 / 0.029823 s | 0.331755 / 0.332118 s | 520 | 351,073 | +| Tiny Transformer | 21,052 | 0.008537 / 0.004783 s | 0.878434 / 0.822045 s | 1,338 | 1,014,134 | + +The ratios of the two medians are 9.10x and 127.66x. These very small denominators, +first-step effects, and two repeats make them bounded diagnostic observations, +not stable overhead estimates for longer training. The timer covers training +bodies, `start_step`, and the wrapper-disable assignment. It excludes imports, +instrumentation setup, data preparation, loss extraction, model hashing, and +process shutdown. No GPU or distributed workload ran. + +Tracing used normal torch API coverage (`use_full_instr=False`), unfiltered +argument/return metadata, interval 1, zero warmup, and descriptors disabled. +There were 20,998 installed wrappers, but only 260 and 669 recorded calls in the +two workloads. There was no proxy/model tracking or tensor-value collection. +These are trace-collection measurements, not selective invariant-checking overhead. + +## Separate profile + +Each cProfile run covered the main training thread during the three step bodies. +Its total recorded time was **0.912044 s for MNIST** and **2.474558 s for the +Transformer**, substantially above ordinary traced wall time. cProfile magnifies +Python-heavy paths; these shares must not be applied directly to unprofiled time. +Background file writing, setup, `start_step`, and process shutdown are outside +the profile. Cumulative rows overlap and must not be added. + +| Component | MNIST calls | MNIST share of profiled time | Transformer calls | Transformer share | +|---|---:|---:|---:|---:| +| `convert_var_to_dict`, cumulative | 404 | 94.15% | 1,709 | 97.54% | +| Dumper `safe_getattr`, cumulative and inside conversion | 172,768 | 54.53% | 477,225 | 56.29% | +| All `warnings.py` functions, summed exclusive time | — | 28.06% | — | 28.89% | +| `get_process_thread_id`, cumulative | 260 | 0.020% | 669 | 0.018% | +| `get_meta_vars`, cumulative | 260 | 0.0025% | 669 | 0.0022% | +| Final trace `serialize`, cumulative | 520 | 0.403% | 1,338 | 0.397% | + +`get_process_thread_id` caches identities in thread-local state. `get_meta_vars` +returns the existing metadata dictionary; it does not reconstruct context per +call. Conversely, metadata conversion repeatedly enumerates object attributes +and invokes `safe_getattr`, which enters/exits a warning context and installs an +ignore filter for every attribute. The warning-module shares above count its +exclusive function time once, avoiding nested cumulative double counting. + +Serialization and snapshot construction execute on the producer; file writes +already use a background queue consumer. The small JSON share here does not +measure file-writer cost, full tensor dumps, GPU synchronization, or larger traces. +It is evidence against prioritizing PID/TID caching or a JSON-library replacement +for this particular metadata-only CPU workload. + +## Correctness and evidence + +Every run's complete loss trajectory, canonical initial/final model-state hash, +and full state-shape map exactly match the plain reference. Canonical state hashes +cover sorted parameter/buffer names, dtypes, shapes, and tensor bytes. The two +profiled runs also pass these comparisons. + +All six downloaded API trace files were independently rehashed and parsed: +**5,574 records total**, with exactly one pre and one post for every recorded +call ID. Counts and byte sizes match the run manifests; there are no duplicate, +incomplete, or exception record groups. This does not prove universal API coverage. +Fresh-process raw traces contain different timestamps and identities; they were +not normalized, and byte equality between runs is not claimed. All 77 production +Python files and both harness files match their pre-run hashes after download; +each traced run's imported module digest matches the frozen source. + +Source: `205a687eef30e498bd2d9a9951652b7cc05bec68`, tree +`2177e2fa826bb4623c3c9cdbb3bdcb61fafbedab`. Runtime: labmach, Intel Core i9-13900K, +32 logical CPUs, Python 3.11.4, PyTorch `2.16.0.dev20261012+cpu`, float32, one +intra-op/inter-op/native thread, `PYTHONHASHSEED=0`, initialization seed 42, +training seed 43, batch size 2. The shared host had no affinity or exclusive +reservation. The other owned inference experiment started only after this audit +finished. Sampled main-process RSS was approximately 329 MiB plain / 536–546 MiB +traced for MNIST and 321 MiB / 517 MiB for Transformer; this includes imports and +setup and does not isolate trace-buffer memory. Per-case limits were 90 seconds, +4 GiB sampled main-process RSS, and 256 MiB API trace; none was reached. + +The existing adapter extracts exact benchmark model definitions without executing +their top-level scripts. MNIST uses the first six cached training images and +labels, NLL, and Adadelta. Transformer uses two 32-dimensional encoder layers, +64-dimensional feedforward, length-16 sequences, NLL, clipped manual SGD, and a +98-token WikiText prefix with a 60-token vocabulary. This is smaller than the +separate fresh-validation study's Transformer. Dataset, source, adapter, state, +and raw trace digests are in the [compact evidence](data/tracing-hotspot-audit-20261026.json). + +The complete 80,977,920-byte evidence archive has SHA-256 +`31ad9746dc9b5318b3f49d9119c86606dce48194ac92701695960bb537a84036`. +It retains exact source, adapters/controller, commands, per-step timings/losses, +raw traces, profiles, and logs. On labmach it is represented by the directory +`/home/yuxuan/experiments/codex-tracing-overhead-20261026-205a687`; the downloaded +archive and verifier are under the local project's +`outputs/release-20261026/tracing-audit/`. Raw traces are not committed. + +To repeat on that host, create a new experiment directory, copy the retained +`audit_runner.py` and `workload.py` there, extract `source.tar` into its `source/` +subdirectory, and run: + +```sh +/home/yuxuan/experiments/codex-inference-runtime-20261025/venv/bin/python \ + "$NEW_AUDIT/audit_runner.py" --root "$NEW_AUDIT" +``` + +The controller records exact child commands and refuses to overwrite individual +run directories. It reads the existing benchmark/data paths shown in the evidence. + +## Proposed follow-up, not an implemented fix + +First investigate batching warning-context setup and avoiding redundant metadata +classification. The measured hot loop is specific enough to justify a focused +prototype; there is no measured candidate speedup yet. + +Hoisting warning suppression is not automatically semantics-preserving: custom +attribute getters may change warning filters, warn or raise, and concurrent +conversions can interact with process-global warning state. Preserve the current +per-getter behavior for unsupported/dynamic objects unless equivalence is proven. +Likewise, caching attribute names must account for instance-specific `__dir__`, +properties, newly added attributes, tensor mutation, and tensor subclasses. +Do not cache mutable values or move snapshots after the application call. + +Any candidate needs exact conversion/trace contract comparisons, warning-state and +exception tests, concurrency checks, model/RNG parity, and new unprofiled paired +runs. No reduction in recorded APIs, fields, or snapshot timing is proposed. From faa40669721c56a91292dd511895946f2ee6d840 Mon Sep 17 00:00:00 2001 From: Yuxuan Jiang Date: Mon, 26 Oct 2026 19:34:02 +0800 Subject: [PATCH 2/5] Verify combined offline inference improvement with matched outputs --- .../offline-inference-combined-20261026.json | 324 ++++++++++++++++++ .../offline-inference-combined-20261026.md | 136 ++++++++ 2 files changed, 460 insertions(+) create mode 100644 docs/measurements/data/offline-inference-combined-20261026.json create mode 100644 docs/measurements/offline-inference-combined-20261026.md diff --git a/docs/measurements/data/offline-inference-combined-20261026.json b/docs/measurements/data/offline-inference-combined-20261026.json new file mode 100644 index 00000000..f4200cea --- /dev/null +++ b/docs/measurements/data/offline-inference-combined-20261026.json @@ -0,0 +1,324 @@ +{ + "measurement_date": "2026-10-26", + "scope": "One baseline-first sequential unprofiled pair of total offline inference on a fixed saved trace; not training, tracing, or checking time.", + "measurement_order": [ + "baseline", + "candidate" + ], + "workload": { + "training_run": "20261012T163111Z-88c4d357", + "model_parameters": 6163712, + "training_steps": 10, + "sequence_length": 256, + "batch_size": 1, + "training_seed": 42, + "events": 573494, + "raw_trace_bytes": 286335289, + "trace_files": { + "trace_API_1088885_23438542501568.log": { + "bytes": 82668375, + "sha256": "883d288d6955b12c49dc741c166bcca7d191c890d19565802dad60708979278d" + }, + "trace_API_1088885_23456244348224.log": { + "bytes": 203666914, + "sha256": "416b8ca45b4df361fc73052447573d7cb23d433d16c0947d74bbc18f7cc6c9a8" + } + }, + "model_config": "llama3_debugmodel", + "framework": "TorchTitan", + "torchtitan_revision": "2210414902d84d1219fd63ab8efeb24375a2a1a1", + "original_collection_manifest": { + "local_relative_path": "outputs/expanse/20261012T163111Z-88c4d357/manifest.json", + "sha256": "ead51e07800fa08178855aa0f724a7a2b3ded36fae53d0cb2b4c9cee7d0ad35e" + } + }, + "settings": { + "backend": "pandas", + "workers": 1, + "native_threads": 1, + "python_hash_seed": 0, + "gpu": false, + "disabled_relations": [ + "FunctionLeadRelation", + "FunctionCoverRelation" + ], + "enabled_relations": [ + "APIContainRelation", + "ConsistencyRelation", + "ConsistentOutputRelation", + "ConsistentInputOutputRelation", + "DistinctArgumentRelation", + "ThresholdRelation" + ], + "eligible_apis": 41, + "timeout_seconds_per_run": 2400, + "sampled_child_process_tree_pss_limit_gib": 12, + "memory_sampling_seconds": 1, + "profile_enabled": false, + "periodic_traceback_dumps": false + }, + "runtime": { + "host": "labmach", + "python": "3.11.4 (main, Jul 5 2023, 13:45:01) [GCC 11.2.0]", + "packages": { + "numpy": "2.1.0", + "pandas": "2.3.3", + "torch": "2.16.0.dev20261012+cpu" + }, + "platform": "Linux-6.1.0-1027-oem-x86_64-with-glibc2.35", + "cpu_count": 32, + "cpu_model": "13th Gen Intel(R) Core(TM) i9-13900K", + "torch_git_version": "8f9045d72f71e7aa9e16b6d7a055ec5bc1f720b5", + "controller_complete": true, + "baseline_and_candidate_runtime_identical": true + }, + "sources": { + "baseline_description": "Exact original PR144 frozen call-index-src snapshot plus only PR145 pruning-state correction; no single Git revision represents this pre-publication snapshot. Earlier sampling/reservoir/context/call indexes are already included.", + "candidate_revision": "205a687eef30e498bd2d9a9951652b7cc05bec68", + "candidate_tree": "2177e2fa826bb4623c3c9cdbb3bdcb61fafbedab", + "pruning_implementation_identical": true, + "baseline_original_provenance_sha256": "7e8e267085ece31844a820752004af6a1c5bb293a3a2733990b039d72fcd872a", + "source_manifest_sha256": "80167a03dffa6fe0f97e0f30ee928e5c1eca117fec0ddabc5d3bf819ae8b1c1f", + "baseline_pruning_fix_sha256": "38b40877f078483b34b8be72150884d7bc1d06fd8d90a188d9bd93715f7b1799", + "trace_pandas_sha256": { + "baseline": "8e4c3589371449b78430ed5039d0159d3d0435664b218f3a96c81935be0d75d5", + "candidate": "953d9cac029f83e015eb22e3bc9c8abc7b63919a0eef18b9794517392117ec24" + }, + "precondition_sha256": "c14c7580643780954eab5a4d955b0b5d6a6768a57cd8e5e48328ad0d8f2f8703", + "baseline_production_python_files": 76, + "candidate_production_python_files": 77, + "candidate_all_python_files": 118 + }, + "comparison": { + "scope": "One baseline-first sequential unprofiled pair of total offline inference on a fixed saved trace; not training, tracing, or checking time.", + "source_manifest": "source-manifest.json", + "baseline": { + "exit_code": 0, + "failed_hypotheses": { + "canonical_multiset_sha256": "5e4933736061977b60f01396ef03e14a7549faf67fda9b70743c116a62de0798", + "distinct_records": 104, + "records": 104 + }, + "invariants": { + "canonical_multiset_sha256": "955ecefffb96cc5f1acf3b95aaf82de2d808e13d86371c4aee27f5a811b07bdb", + "distinct_records": 836, + "records": 836 + }, + "sampled_peak_concurrent_memory": { + "pss_bytes": 2283449344, + "rss_bytes": 2292084736, + "uss_bytes": 2280603648 + }, + "source_unchanged": true, + "stage_times": { + "marker_durations": { + "cross_trace_collection_seconds": 0.0, + "generation_and_pruning_seconds": 641.082, + "precondition_and_output_sort_seconds": 782.884 + }, + "markers": { + "collection_start": "2026-10-26T07:09:22.516000", + "generation_start": "2026-10-26T06:58:41.434000", + "inference_end": "2026-10-26T07:22:25.400000", + "precondition_start": "2026-10-26T07:09:22.516000" + }, + "note": "Log marker intervals; missing endpoints mean incomplete phases, not zero duration.", + "reported": { + "inference_seconds": 1424.0316710472107, + "load_seconds": 10.776794910430908 + } + }, + "stop_reason": null, + "success": true, + "traces_unchanged": true, + "wall_seconds": 1439.5377350114286, + "monitor_exit_code": 0 + }, + "candidate": { + "exit_code": 0, + "failed_hypotheses": { + "canonical_multiset_sha256": "5e4933736061977b60f01396ef03e14a7549faf67fda9b70743c116a62de0798", + "distinct_records": 104, + "records": 104 + }, + "invariants": { + "canonical_multiset_sha256": "955ecefffb96cc5f1acf3b95aaf82de2d808e13d86371c4aee27f5a811b07bdb", + "distinct_records": 836, + "records": 836 + }, + "sampled_peak_concurrent_memory": { + "pss_bytes": 2325339136, + "rss_bytes": 2333978624, + "uss_bytes": 2322497536 + }, + "source_unchanged": true, + "stage_times": { + "marker_durations": { + "cross_trace_collection_seconds": 0.0, + "generation_and_pruning_seconds": 49.536, + "precondition_and_output_sort_seconds": 12.512 + }, + "markers": { + "collection_start": "2026-10-26T07:23:30.910000", + "generation_start": "2026-10-26T07:22:41.374000", + "inference_end": "2026-10-26T07:23:43.422000", + "precondition_start": "2026-10-26T07:23:30.910000" + }, + "note": "Log marker intervals; missing endpoints mean incomplete phases, not zero duration.", + "reported": { + "inference_seconds": 62.09680366516113, + "load_seconds": 10.745272397994995 + } + }, + "stop_reason": null, + "success": true, + "traces_unchanged": true, + "wall_seconds": 76.68627300858498, + "monitor_exit_code": 0 + }, + "raw_output_comparisons": [ + { + "file": "invariants.jsonl", + "baseline_sha256": "67ae805da54231ecfcfba060280ca8d5a0b2e98b44523f06b7c64490e9e3a8f0", + "candidate_sha256": "67ae805da54231ecfcfba060280ca8d5a0b2e98b44523f06b7c64490e9e3a8f0", + "raw_byte_equal": true, + "baseline_bytes": 530177, + "candidate_bytes": 530177, + "baseline_lines": 836, + "candidate_lines": 836 + }, + { + "file": "invariants.jsonl.failed", + "baseline_sha256": "173364b2792421ae048975cc5e7c6a89230f74223f166af046f7a7c9c95d11b2", + "candidate_sha256": "173364b2792421ae048975cc5e7c6a89230f74223f166af046f7a7c9c95d11b2", + "raw_byte_equal": true, + "baseline_bytes": 74805, + "candidate_bytes": 74805, + "baseline_lines": 104, + "candidate_lines": 104 + }, + { + "file": "contexts-0.json", + "baseline_sha256": "bea2a909d42bc621be2fea66ad7de4e7e871b7f40903f546934e3d7e4d9c1207", + "candidate_sha256": "bea2a909d42bc621be2fea66ad7de4e7e871b7f40903f546934e3d7e4d9c1207", + "raw_byte_equal": true, + "baseline_bytes": 250106, + "candidate_bytes": 250106, + "baseline_lines": 1, + "candidate_lines": 1 + }, + { + "file": "contexts-1.json", + "baseline_sha256": "bea2a909d42bc621be2fea66ad7de4e7e871b7f40903f546934e3d7e4d9c1207", + "candidate_sha256": "bea2a909d42bc621be2fea66ad7de4e7e871b7f40903f546934e3d7e4d9c1207", + "raw_byte_equal": true, + "baseline_bytes": 250106, + "candidate_bytes": 250106, + "baseline_lines": 1, + "candidate_lines": 1 + } + ], + "raw_outputs_and_contexts_identical": true, + "harness_sha256": { + "inference_replay_fatal_only.py": "2dd8d63a8bae80a944defee70be6bf33e9c9c8934e22e4b909ff222b4f7d6777", + "inference_scaling.py": "1fc8409ec68d23da26223424a41dcaeff252ede84723b4256fd7dc5797f8e994" + }, + "harness_unchanged": true, + "wall_speedup_baseline_over_candidate": 18.771778553513396, + "total_wall_time_reduction_percent": 94.67285426818101, + "limitations": [ + "One pair, no confidence interval", + "Baseline first; no order control", + "Shared host, no exclusive CPU reservation or affinity", + "Six enabled relations; FunctionLeadRelation and FunctionCoverRelation disabled", + "Fixed saved TorchTitan llama3_debugmodel trace; no distributed scaling or training-overhead claim" + ] + }, + "memory_delta": { + "sampled_peak_pss_bytes": 41889792, + "sampled_peak_pss_mib": 39.94921875, + "sampled_peak_pss_percent": 1.8344962243226348 + }, + "phase_percent_denominator": "Each variant complete wall_seconds; markers are not an exhaustive partition and are not cProfile attribution.", + "phase_percent_of_complete_wall": { + "baseline": { + "cross_trace_collection": 0.0, + "generation_and_pruning": 44.53387948145106, + "precondition_and_output_sort": 54.38440278147933, + "reported_load": 0.7486288583011929 + }, + "candidate": { + "cross_trace_collection": 0.0, + "generation_and_pruning": 64.59565455013635, + "precondition_and_output_sort": 16.31582747358095, + "reported_load": 14.01198933842054 + } + }, + "context_snapshots": { + "baseline": [ + { + "call": 0, + "contexts": 711, + "rows": 573494, + "seconds": 0.6209814846515656, + "states_sha256": "02a9f08ad19e890f92d26367b4a8c433c4953770d5359554bf496fc6f17e3b07" + }, + { + "call": 1, + "contexts": 711, + "rows": 573494, + "seconds": 0.5279750600457191, + "states_sha256": "02a9f08ad19e890f92d26367b4a8c433c4953770d5359554bf496fc6f17e3b07" + } + ], + "candidate": [ + { + "call": 0, + "contexts": 711, + "rows": 573494, + "seconds": 0.47907548025250435, + "states_sha256": "02a9f08ad19e890f92d26367b4a8c433c4953770d5359554bf496fc6f17e3b07" + }, + { + "call": 1, + "contexts": 711, + "rows": 573494, + "seconds": 0.4743414670228958, + "states_sha256": "02a9f08ad19e890f92d26367b4a8c433c4953770d5359554bf496fc6f17e3b07" + } + ] + }, + "validation": { + "pruning_regression_tests_per_source": 6, + "pruning_regression_tests_both_pass": true, + "archive_sha256": "776ee54a40fa883d167c3cccef3a40105a82f396f5235d8d566a93112c097823", + "archive_bytes": 5479198, + "verified_file_count": 330, + "all_file_hashes_match": true, + "candidate_python_files_verified_against_git": 118, + "baseline_original_python_files": 76, + "baseline_only_changed_file": "traincheck/invariant/precondition.py", + "pruning_implementation_identical": true, + "all_raw_outputs_and_contexts_byte_identical": true, + "per_run_source_manifest_matches_archived_source": true, + "both_trace_manifests_equal_original": true, + "per_run_source_and_input_hashes_unchanged": true + }, + "evidence": { + "archive_name": "codex-release-inference-20261026-205a687-evidence.tar.gz", + "archive_bytes": 5479198, + "archive_sha256": "776ee54a40fa883d167c3cccef3a40105a82f396f5235d8d566a93112c097823", + "remote_directory": "/home/yuxuan/experiments/codex-release-inference-20261026-205a687", + "local_relative_directory": "outputs/release-20261026/inference-pair/", + "controller_sha256": "9a446510b2f39a8c2bddfab27b81fadea791cbf2a0552a1030b66def9e898eb9", + "started_utc": "2026-10-26T10:58:29Z", + "timed_tracing_audit_completed_before_launch": true, + "background_workload": "One unrelated Python process approximately100%CPU in both pre-run snapshots; shared host, no affinity." + }, + "timing_boundary": { + "total_wall": "Child process lifetime including interpreter/imports, context snapshots, trace loading/preparation, inference, output writing, exit and monitor polling.", + "integrity_hashing": "Before/after input and source hashing excluded from wall timer.", + "context_snapshot_serialization": "Retained harness diagnostic overhead included in complete wall and relevant loading/inference timers.", + "polling_interval_seconds": 1 + } +} diff --git a/docs/measurements/offline-inference-combined-20261026.md b/docs/measurements/offline-inference-combined-20261026.md new file mode 100644 index 00000000..6e25a0a3 --- /dev/null +++ b/docs/measurements/offline-inference-combined-20261026.md @@ -0,0 +1,136 @@ +# Direct comparison of complete offline inference + +One matched, unprofiled pair on the retained TorchTitan Llama debug training +trace reduced complete offline-inference wall time from **1,439.538 s to 76.686 s**: **18.77x faster**, or +**94.67% less wall time**. This directly measures the combined result against the +pre-identity-cache baseline. It does not multiply the earlier PR speedups. + +The denominator is the entire offline-inference process: startup/imports, trace +loading and preparation, hypothesis generation, precondition inference, output +writing, and process exit. It excludes training, trace collection, and invariant +checking. The result supports an approximately 19x improvement for this saved +trace and configuration, not a general training-pipeline speedup. + +## Measured result + +| Measurement | Corrected baseline | Final main | Change | +|---|---:|---:|---:| +| Complete offline wall time | 1,439.538 s | 76.686 s | 18.77x; 94.67% reduction | +| Sampled peak process-tree PSS | 2.126628 GiB | 2.165641 GiB | +39.95 MiB; +1.83% | +| Invariants written | 836 | 836 | Full file byte-identical | +| Failed hypotheses written | 104 | 104 | Full file byte-identical | + +Both runs completed with exit code zero, without reaching the 2,400-second or +12-GiB sampled-PSS limit. Memory was sampled once per second; this is a sampled +peak rather than an exact allocation high-water mark. The monitor's own memory +is outside the measured child process tree. Its polling can add up to roughly +one second to the measured process lifetime. Source/input integrity hashing is +outside the wall timer. The retained harness serializes context snapshots inside +each child process; this shared diagnostic cost is included in complete wall +time and the relevant loading/inference timers. + +Unprofiled log timestamps show where the elapsed time moved: + +| Phase | Baseline time | Share of baseline total | Final-main time | Share of final-main total | +|---|---:|---:|---:|---:| +| Trace loading, reported timer | 10.777 s | 0.75% | 10.745 s | 14.01% | +| Hypothesis generation and pruning | 641.082 s | 44.53% | 49.536 s | 64.60% | +| Precondition inference and output sorting | 782.884 s | 54.38% | 12.512 s | 16.32% | + +Each percentage uses that column's complete wall time as its denominator. These +phase markers do not cover every startup, shutdown, and output operation and +should not be treated as an exhaustive partition or profiler attribution. The +trace-loading cost is nearly unchanged because both variants already contain +the context/call indexes from #141. + +## Sources and correctness + +The baseline is the exact frozen `call-index-src` snapshot used before #144's +identity-cache optimization, with only #145's two-hunk pruning-state correction +applied. This archived snapshot predates publication-only type/comment changes +and is identified by file hashes, not presented as a single Git revision. Its +original provenance manifest SHA-256 is +`7e8e267085ece31844a820752004af6a1c5bb293a3a2733990b039d72fcd872a`. +The baseline already contains the earlier deterministic sampling, reservoir, +and context/call-index work; their gains are not included in this comparison. + +The candidate is main commit `205a687eef30e498bd2d9a9951652b7cc05bec68`, tree +`2177e2fa826bb4623c3c9cdbb3bdcb61fafbedab`. The corrected `precondition.py` is +byte-identical in both variants, and all six pruning-state regressions pass on +each. This holds the independent correctness fix constant while comparing the +remaining inference optimizations and hardening against final main. + +All **836 invariants**, **104 failed hypotheses**, and both complete context +snapshots (**711 states each**) match byte for byte. No records, IDs, predicates, +array contents, duplicates, or output ordering were discarded to obtain parity. +The two input traces and all source hashes remain unchanged before/after each +run. The retained harness/helper hashes are identical to the earlier studies. + +Independent download verification rehashed all 330 archived evidence files, +matched all 118 candidate Python files against the specified Git revision, +and confirmed that the only change to the original 76-file baseline is the +pruning-state fix. Both run provenance manifests match their archived sources. +All raw-output comparisons were repeated locally on the downloaded files. +The [compact evidence](data/offline-inference-combined-20261026.json) records +the exact times, memory, digests, settings, and validation results. + +## Workload and controls + +The same two original traces contain **573,494 events / 286,335,289 raw bytes** +from ten training steps of TorchTitan `llama3_debugmodel` (6,163,712 parameters), +sequence length 256, batch size 1, seed 42, run `20261012T163111Z-88c4d357`. +This is TorchTitan's small Llama debug configuration, not the separately named +TinyLlama model/project. The original collection manifest identifies that +configuration and TorchTitan revision +`2210414902d84d1219fd63ab8efeb24375a2a1a1`; its SHA-256 is recorded in the +compact evidence. The trace files are read unchanged; no training is rerun here. + +Both fresh processes use pandas, one inference worker, native thread limits of +one, `PYTHONHASHSEED=0`, and CPU execution. Six relations are enabled: +`APIContainRelation`, `ConsistencyRelation`, `ConsistentOutputRelation`, +`ConsistentInputOutputRelation`, `DistinctArgumentRelation`, and +`ThresholdRelation`. `FunctionLeadRelation` and `FunctionCoverRelation` are +disabled, matching the earlier studies. Each run sees 41 eligible APIs. + +Runtime: labmach, Intel Core i9-13900K with 32 logical CPUs, Linux 6.1.0-1027-oem, +Python 3.11.4, PyTorch `2.16.0.dev20261012+cpu` at Torch revision +`8f9045d72f71e7aa9e16b6d7a055ec5bc1f720b5`, pandas 2.3.3, NumPy 2.1.0. +Original collection used Python 3.12.3 and a CUDA build at the same Torch source +revision. This comparison controls the replay environment between variants, +not between original collection and replay. + +This is **one baseline-first pair**, without repeats, randomized order, CPU +affinity, or an exclusive host reservation; no confidence interval is claimed. +One unrelated Python process was using approximately one CPU core at both +pre-run snapshots. The separate tracing audit finished before this pair began. +The result does not establish distributed scaling, GPU performance, portability +of these invariants to fresh runs, or overhead of selective checking. + +## Retained evidence and reproduction + +The complete evidence archive is 5,479,198 bytes, SHA-256 +`776ee54a40fa883d167c3cccef3a40105a82f396f5235d8d566a93112c097823`. +It contains both source snapshots, the pruning patch, exact commands, unchanged +replay harness/helper, controller, runtime/resource snapshots, per-second memory +samples, full output/context files, and logs. Raw input traces remain at their +existing paths and are identified by full digests in the evidence. + +Remote experiment directory: +`/home/yuxuan/experiments/codex-release-inference-20261026-205a687`. +The downloaded archive, independently checked results, and source manifest are +under the local project's `outputs/release-20261026/inference-pair/`. +No raw traces or machine-specific experiment files are committed. + +To repeat on labmach, create a new directory and copy the retained +`baseline-src/`, `candidate-src/`, `source-manifest.json`, `run_pair.py`, +`inference_replay_fatal_only.py`, and `inference_scaling.py` into it. Keep the +original trace paths from the manifest available, then run: + +```sh +/home/yuxuan/experiments/codex-inference-runtime-20261025/venv/bin/python \ + "$NEW_STUDY/run_pair.py" +``` + +The controller runs baseline then candidate with the same limits and refuses +to overwrite measurement directories. `comparison.json` records direct raw +byte equality in addition to the inherited harness's structural summaries. From 53ff6c712c5586f1f30bf7e81a7dbe5abe1e3bfc Mon Sep 17 00:00:00 2001 From: Yuxuan Jiang Date: Mon, 26 Oct 2026 21:22:53 +0800 Subject: [PATCH 3/5] Explain tracing invocation costs and unmeasured hashing coverage --- .../tracing-hotspot-breakdown-20261026.json | 397 ++++++++++++++++++ .../tracing-hotspot-audit-20261026.md | 108 +++++ 2 files changed, 505 insertions(+) create mode 100644 docs/measurements/data/tracing-hotspot-breakdown-20261026.json diff --git a/docs/measurements/data/tracing-hotspot-breakdown-20261026.json b/docs/measurements/data/tracing-hotspot-breakdown-20261026.json new file mode 100644 index 00000000..9452d218 --- /dev/null +++ b/docs/measurements/data/tracing-hotspot-breakdown-20261026.json @@ -0,0 +1,397 @@ +{ + "source_commit": "205a687eef30e498bd2d9a9951652b7cc05bec68", + "hardware": { + "cpu": "Intel Core i9-13900K", + "cpu_affinity": false, + "exclusive_host": false, + "host_alias": "labmach", + "hostname": "yuxuan-Precision-3660", + "logical_cpus": 32, + "native_threads": 1, + "platform": "Linux-6.1.0-1027-oem-x86_64-with-glibc2.35", + "python": "3.11.4 (main, Jul 5 2023, 13:45:01) [GCC 11.2.0]" + }, + "configuration": { + "batch_size": 2, + "case_limits": { + "main_RSS_bytes": 4294967296, + "timeout_seconds": 90, + "trace_bytes": 268435456 + }, + "device": "cpu", + "dtype": "float32", + "hash_seed": 0, + "instrumentation": "Normal torch API coverage, unfiltered argument/return metadata, use_full_instr=False, descriptors disabled, no proxy/model tracking, no tensor-value dump, interval1,warmup0", + "instrumented_function_count": 20998, + "seed": 42, + "steps": 3, + "training_seed": 43 + }, + "methods": { + "profile_categories": "Disjoint self-time partition of every pstats function. All warnings.py self time plus immediate callees self time on pstats caller edges assigned to warnings; subtract those edges before classifying remaining function self time. Conversion bucket is dumper convert_var_to_dict, safe_getattr, and attribute-name listcomp own self time. Type-check bucket is isinstance, issubclass, and __instancecheck__ remaining self time. Attribute bucket is dir/getattr/startswith remaining self time. JSON bucket is json module functions, orjson.dumps, dumper serialize/_json_default remaining self time, including serializability probes. Everything else is residual. Sum checked against pstats total. This is a profiled CPU main-thread partition, not a measured partition of ordinary-run added overhead.", + "trace_counts": "Every raw pre record counted once; records kept in original order, grouped using exact step metadata and exact call IDs. Serialized variables counted by original singleton type-tag dictionaries in args, kwargs and return_values. Snapshot counts count repeated observations, not unique objects.", + "regions": "Regions only label call counts, not timings. For each step, zero-grad region extends through matching zero_grad post. Forward extends until nll_loss pre. Loss extends until Tensor.backward pre. Backward extends through matching backward post. Everything after is update/gradient processing. Nested call counts are included. These regions do not measure device kernels." + }, + "workloads": { + "mnist": { + "profile_sha256": "8f4191c81b0b8e0dda4c405290ca2dd608787b591d29c6f2f2ba5f1cd1268514", + "trace_sha256": "09a7bfa5f591018ce027bfe5e72fdf6708a152964cc0981974f8cfa88a59c315", + "profile_total_seconds": 0.9120438500000003, + "profile_disjoint_self_time": { + "everything_else": { + "seconds": 0.05084355899999998, + "percent_of_profile_total": 5.57468360759189 + }, + "dir_getattr_startswith_all_callers": { + "seconds": 0.059819945000000006, + "percent_of_profile_total": 6.558889136744904 + }, + "warning_machinery": { + "seconds": 0.3325780160000001, + "percent_of_profile_total": 36.465134434051606 + }, + "type_checks_all_callers": { + "seconds": 0.12640411000000001, + "percent_of_profile_total": 13.859433403339102 + }, + "json_encode_and_probe_self_all_callers": { + "seconds": 0.005528244, + "percent_of_profile_total": 0.6061379614587608 + }, + "conversion_loop_and_safe_getattr_self": { + "seconds": 0.336869976, + "percent_of_profile_total": 36.93572145681371 + } + }, + "unprofiled_medians": { + "baseline_seconds": 0.03646252676844597, + "traced_seconds": 0.33193632028996944, + "added_seconds": 0.2954737935215235, + "traced_divided_by_baseline": 9.103491987758273, + "percent_increase": 810.3491987758273, + "added_ms_per_step": 98.49126450717449, + "added_us_per_recorded_python_call": 1136.4376673904749 + }, + "recorded_python_calls": 260, + "calls_by_region": { + "zero_grad": 15, + "forward": 66, + "loss": 6, + "backward": 6, + "post_backward_gradient_processing_and_update": 167 + }, + "calls_by_step": { + "1": 108, + "2": 76, + "3": 76 + }, + "calls_by_api": { + "torch._VariableFunctionsClass.is_complex": 72, + "torch._VariableFunctionsClass.zeros_like": 16, + "torch.compiler.is_compiling": 12, + "torch.nn.functional.relu": 9, + "torch._VariableFunctionsClass.relu": 9, + "torch.is_grad_enabled": 9, + "torch.optim.optimizer._get_scalar_dtype": 8, + "torch._VariableFunctionsClass.zeros": 8, + "torch._ops.TorchBindOpOverload.__call__": 6, + "torch._ops._must_dispatch_in_python": 6, + "torch._ops._contains_fake_script_object": 6, + "torch.nn.modules.conv.Conv2d.forward": 6, + "torch.nn.modules.conv.Conv2d._conv_forward": 6, + "torch._VariableFunctionsClass.conv2d": 6, + "torch.nn.modules.dropout.Dropout.forward": 6, + "torch.nn.functional.dropout": 6, + "torch.nn.modules.linear.Linear.forward": 6, + "torch.optim.optimizer.Optimizer.zero_grad": 3, + "torch.compiler.is_exporting": 3, + "torch.nn.functional.boolean_dispatch..fn": 3, + "torch._VariableFunctionsClass.max_pool2d": 3, + "torch._VariableFunctionsClass.flatten": 3, + "torch.nn.functional.log_softmax": 3, + "torch.nn.functional.nll_loss": 3, + "torch.nn._reduction.get_enum": 3, + "torch._tensor.Tensor.backward": 3, + "torch._VariableFunctionsClass.ones_like": 3, + "torch.optim.adadelta.Adadelta.step": 3, + "torch.optim.optimizer.Optimizer._accelerator_graph_capture_health_check": 3, + "torch.accelerator.current_accelerator": 3, + "torch.optim.adadelta.Adadelta._init_group": 3, + "torch.optim.adadelta.adadelta": 3, + "torch.optim.optimizer._default_to_fused_or_foreach": 3, + "torch.utils._foreach_utils._get_fused_kernels_supported_devices": 3, + "torch.utils._foreach_utils._get_foreach_kernels_supported_devices": 3, + "torch.optim.adadelta._single_tensor_adadelta": 3, + "torch.optim.optimizer._to_scalar": 3, + "torch.optim.optimizer.Optimizer._optimizer_step_code": 3 + }, + "serialized_variable_type_counts": { + "torch.FloatTensor": 171, + "bool": 165, + "torch.nn.Parameter": 112, + "list": 57, + "NoneType": 33, + "int": 33, + "tuple": 32, + "float": 30, + "memory_format": 19, + "torch.dtype": 16, + "torch.optim.adadelta.Adadelta": 15, + "torch._RecordFunction": 12, + "torch.nn.modules.conv.Conv2d": 12, + "dict": 9, + "torch._ops.profiler.profiler::_record_function_exit._RecordFunction": 6, + "torch.nn.modules.dropout.Dropout": 6, + "torch.nn.modules.linear.Linear": 6, + "torch.LongTensor": 3, + "str": 3 + }, + "dictionary_payload_counts": { + "torch.FloatTensor": 171, + "torch.nn.Parameter": 112, + "list": 33, + "memory_format": 19, + "torch.optim.adadelta.Adadelta": 15, + "torch._RecordFunction": 12, + "torch.nn.modules.conv.Conv2d": 12, + "dict": 9, + "torch._ops.profiler.profiler::_record_function_exit._RecordFunction": 6, + "tuple": 6, + "torch.nn.modules.dropout.Dropout": 6, + "torch.nn.modules.linear.Linear": 6, + "torch.LongTensor": 3 + }, + "saved_metadata_fields_by_type": { + "torch.FloatTensor": 4653, + "torch.nn.Parameter": 3136, + "torch.nn.modules.conv.Conv2d": 120, + "torch.LongTensor": 84, + "torch.nn.modules.linear.Linear": 42, + "torch.nn.modules.dropout.Dropout": 30, + "dict": 24, + "torch._ops.profiler.profiler::_record_function_exit._RecordFunction": 12, + "torch.optim.adadelta.Adadelta": 0, + "torch._RecordFunction": 0, + "tuple": 0, + "memory_format": 0, + "list": 0 + }, + "saved_dictionary_payload_fields_total": 8101, + "tensor_content_hash_stats_full_dump_profiled_calls_observed": false, + "tensor_content_hash_stats_full_dump_interpretation": "Not exercised in this metadata-only audit; costs remain unmeasured, not zero in full-value collection.", + "final_json_encoding": { + "total_calls": 520, + "cumulative_seconds": 0.003676032, + "percent_of_profile_total": 0.4030543048999233, + "stdlib_fallback_calls": 219, + "stdlib_fallback_cumulative_seconds": 0.002728555, + "fallback_reason": "Not observed by retained profile; exception reason unrecorded." + } + }, + "transformer": { + "profile_sha256": "899e7be474ac75cf3d9febe7ec7f6b4467f2b47cae2f0b936ccbe9ec95a0c7f9", + "trace_sha256": "31caf36c9d5d45616f663f96b5f5d51615c842bacff67810aee61554c8b3a5cc", + "profile_total_seconds": 2.4745579680000014, + "profile_disjoint_self_time": { + "everything_else": { + "seconds": 0.05606722100000001, + "percent_of_profile_total": 2.265746922280221 + }, + "dir_getattr_startswith_all_callers": { + "seconds": 0.172234026, + "percent_of_profile_total": 6.960193627599833 + }, + "warning_machinery": { + "seconds": 0.928045153, + "percent_of_profile_total": 37.50347193321436 + }, + "type_checks_all_callers": { + "seconds": 0.3556693530000001, + "percent_of_profile_total": 14.373045917669925 + }, + "json_encode_and_probe_self_all_callers": { + "seconds": 0.016580772, + "percent_of_profile_total": 0.6700498519095509 + }, + "conversion_loop_and_safe_getattr_self": { + "seconds": 0.9459614430000002, + "percent_of_profile_total": 38.22749174732607 + } + }, + "unprofiled_medians": { + "baseline_seconds": 0.006660038605332375, + "traced_seconds": 0.8502394407987595, + "added_seconds": 0.8435794021934271, + "traced_divided_by_baseline": 127.66283968954976, + "percent_increase": 12666.283968954975, + "added_ms_per_step": 281.1931340644757, + "added_us_per_recorded_python_call": 1260.9557581366623 + }, + "recorded_python_calls": 669, + "calls_by_region": { + "zero_grad": 96, + "forward": 285, + "loss": 6, + "backward": 6, + "post_backward_gradient_processing_and_update": 276 + }, + "calls_by_step": { + "1": 225, + "2": 222, + "3": 222 + }, + "calls_by_api": { + "torch.nn.modules.module.Module.named_modules": 252, + "torch.is_grad_enabled": 45, + "torch.nn.functional._canonical_mask": 36, + "torch.nn.modules.dropout.Dropout.forward": 21, + "torch.nn.functional.dropout": 21, + "torch.nn.functional._none_or_dtype": 21, + "torch._VariableFunctionsClass.is_floating_point": 21, + "torch.backends.mha.get_fastpath_enabled": 15, + "torch.nn.modules.normalization.LayerNorm.forward": 15, + "torch.nn.functional.layer_norm": 15, + "torch._VariableFunctionsClass.layer_norm": 15, + "torch.nn.modules.linear.Linear.forward": 15, + "torch.nn.modules.module.Module.parameters": 9, + "torch.nn.modules.module.Module.named_parameters": 9, + "torch.nn.modules.module.Module._named_members": 9, + "torch.nn.modules.transformer.TransformerEncoderLayer.forward": 6, + "torch.nn.modules.transformer.TransformerEncoderLayer._sa_block": 6, + "torch.nn.modules.activation.MultiheadAttention.forward": 6, + "torch.nn.functional.multi_head_attention_forward": 6, + "torch.nn.functional._mha_shape_check": 6, + "torch.nn.functional._in_projection_packed": 6, + "torch._tensor.Tensor.unflatten": 6, + "torch.nn.modules.transformer.TransformerEncoderLayer._ff_block": 6, + "torch._VariableFunctionsClass.relu": 6, + "torch.utils._foreach_utils._group_tensors_by_device_and_dtype": 6, + "torch.utils._foreach_utils._has_foreach_support": 6, + "torch.utils._foreach_utils._device_has_foreach_support": 6, + "torch.utils._foreach_utils._get_foreach_kernels_supported_devices": 6, + "torch.nn.modules.module.Module.zero_grad": 3, + "torch.nn.modules.sparse.Embedding.forward": 3, + "torch.nn.functional.embedding": 3, + "torch._VariableFunctionsClass.embedding": 3, + "torch.nn.modules.transformer.TransformerEncoder.forward": 3, + "torch.nn.modules.container.ModuleList._get_abs_string_index": 3, + "torch.nn.modules.transformer._get_seq_len": 3, + "torch.nn.modules.transformer._detect_is_causal_mask": 3, + "torch.nn.modules.transformer._generate_square_subsequent_mask": 3, + "torch._VariableFunctionsClass.full": 3, + "torch._VariableFunctionsClass.triu": 3, + "torch.nn.functional.log_softmax": 3, + "torch.nn.functional.nll_loss": 3, + "torch.nn._reduction.get_enum": 3, + "torch._tensor.Tensor.backward": 3, + "torch._VariableFunctionsClass.ones_like": 3, + "torch.nn.utils.clip_grad.clip_grad_norm_": 3, + "torch.nn.utils.clip_grad._get_total_norm": 3, + "torch._VariableFunctionsClass._foreach_norm": 3, + "torch._VariableFunctionsClass.stack": 3, + "torch.nn.utils.clip_grad._clip_grads_with_norm_": 3, + "torch._VariableFunctionsClass.clamp": 3, + "torch._VariableFunctionsClass._foreach_mul_": 3, + "torch._VariableFunctionsClass.ones": 1, + "torch._VariableFunctionsClass.tril": 1, + "torch._VariableFunctionsClass.log": 1 + }, + "serialized_variable_type_counts": { + "torch.FloatTensor": 638, + "bool": 525, + "str": 339, + "Module.named_modules": 252, + "set": 243, + "NoneType": 138, + "torch.nn.Parameter": 102, + "torch.nn.modules.dropout.Dropout": 84, + "torch.dtype": 84, + "float": 78, + "torch.nn.modules.linear.Linear": 60, + "torch.nn.modules.normalization.LayerNorm": 60, + "int": 50, + "trace_impact_benchmark.TransformerModel": 39, + "tuple": 39, + "torch.nn.modules.transformer.TransformerEncoderLayer": 36, + "list": 36, + "torch.nn.modules.activation.MultiheadAttention": 24, + "torch.nn.modules.linear.NonDynamicallyQuantizableLinear": 18, + "device": 18, + "Module.parameters": 12, + "torch.nn.modules.transformer.TransformerEncoder": 12, + "torch.nn.modules.container.ModuleList": 12, + "torch.nn.modules.sparse.Embedding": 12, + "torch.LongTensor": 12, + "Module.named_parameters": 9, + "torch.nn.modules.module.Module.named_parameters..": 9, + "Module._named_members": 9, + "trace_impact_benchmark.PositionalEncoding": 9, + "dict": 6, + "memory_format": 3 + }, + "dictionary_payload_counts": { + "torch.FloatTensor": 638, + "Module.named_modules": 252, + "set": 243, + "torch.nn.Parameter": 102, + "torch.nn.modules.dropout.Dropout": 84, + "torch.nn.modules.linear.Linear": 60, + "torch.nn.modules.normalization.LayerNorm": 60, + "trace_impact_benchmark.TransformerModel": 39, + "torch.nn.modules.transformer.TransformerEncoderLayer": 36, + "list": 30, + "torch.nn.modules.activation.MultiheadAttention": 24, + "torch.nn.modules.linear.NonDynamicallyQuantizableLinear": 18, + "device": 18, + "Module.parameters": 12, + "torch.nn.modules.transformer.TransformerEncoder": 12, + "torch.nn.modules.container.ModuleList": 12, + "torch.nn.modules.sparse.Embedding": 12, + "torch.LongTensor": 12, + "Module.named_parameters": 9, + "torch.nn.modules.module.Module.named_parameters..": 9, + "Module._named_members": 9, + "trace_impact_benchmark.PositionalEncoding": 9, + "dict": 6, + "memory_format": 3 + }, + "saved_metadata_fields_by_type": { + "torch.FloatTensor": 17462, + "torch.nn.Parameter": 2856, + "Module.named_modules": 756, + "torch.nn.modules.activation.MultiheadAttention": 432, + "torch.nn.modules.linear.Linear": 420, + "torch.nn.modules.dropout.Dropout": 420, + "torch.nn.modules.normalization.LayerNorm": 420, + "trace_impact_benchmark.TransformerModel": 351, + "torch.LongTensor": 336, + "torch.nn.modules.transformer.TransformerEncoderLayer": 180, + "torch.nn.modules.sparse.Embedding": 132, + "torch.nn.modules.linear.NonDynamicallyQuantizableLinear": 126, + "torch.nn.modules.transformer.TransformerEncoder": 84, + "Module.parameters": 36, + "torch.nn.modules.container.ModuleList": 36, + "trace_impact_benchmark.PositionalEncoding": 36, + "device": 36, + "Module.named_parameters": 27, + "Module._named_members": 27, + "torch.nn.modules.module.Module.named_parameters..": 0, + "set": 0, + "memory_format": 0, + "list": 0, + "dict": 0 + }, + "saved_dictionary_payload_fields_total": 24173, + "tensor_content_hash_stats_full_dump_profiled_calls_observed": false, + "tensor_content_hash_stats_full_dump_interpretation": "Not exercised in this metadata-only audit; costs remain unmeasured, not zero in full-value collection.", + "final_json_encoding": { + "total_calls": 1338, + "cumulative_seconds": 0.00983373, + "percent_of_profile_total": 0.3973933982216575, + "stdlib_fallback_calls": 567, + "stdlib_fallback_cumulative_seconds": 0.0073618830000000005, + "fallback_reason": "Not observed by retained profile; exception reason unrecorded." + } + } + } +} diff --git a/docs/measurements/tracing-hotspot-audit-20261026.md b/docs/measurements/tracing-hotspot-audit-20261026.md index a810e361..cbc72065 100644 --- a/docs/measurements/tracing-hotspot-audit-20261026.md +++ b/docs/measurements/tracing-hotspot-audit-20261026.md @@ -60,6 +60,114 @@ measure file-writer cost, full tensor dumps, GPU synchronization, or larger trac It is evidence against prioritizing PID/TID caching or a JSON-library replacement for this particular metadata-only CPU workload. +## Invocation counts explain the workload difference + +The unprofiled medians below cover three CPU training steps and only two runs per +mode. Added time is median traced time minus median plain time; dividing it by +recorded calls is an aggregate normalization, not a measured latency for each API. +Invocation/attribute counts come from the separate profile and its trace; timing +rows use ordinary-run medians. + +| Metric | MNIST | Transformer | +|---|---:|---:| +| Plain training | 36.463 ms | 6.660 ms | +| Traced training | 331.936 ms | 850.239 ms | +| Added tracing time | 295.474 ms | 843.579 ms | +| Added time per step | 98.491 ms | 281.193 ms | +| Recorded Python calls | 260 | 669 | +| Calls during the forward region | 66 | 285 | +| Attribute reads via `safe_getattr` (separate profile) | 172,768 | 477,225 | +| Added time divided by recorded calls | 1.136 ms | 1.261 ms | + +Transformer has 2.57x the recorded calls, 2.76x the attribute reads, and 2.85x the +absolute added time. Its plain computation is also 5.47x faster in this particular +small configuration. Both numerator and denominator explain the much larger +slowdown ratio; this is not evidence of an order-of-magnitude increase in cost per +intercepted call. Slower computation can dilute percentage overhead without +reducing absolute tracing time. This relationship is conditional: changing device +or execution path can also change tracing costs and the set of calls. + +The raw trace contains nested Python API calls, including framework bookkeeping. +`Module.named_modules` accounts for 252/669 Transformer calls (37.7%), reflecting +repeated parameter/module traversal. The forward region has more intercepted +calls, but not all additional events are mathematical operations. Region counts +use exact pre/post call IDs and step metadata; forward is after zero-grad and +before NLL. They are not additive timings or counts of device kernels. + +Repeated serialized tensor/Parameter observations number 286 versus 752; module +observations number 24 versus 366. Transformer additionally serializes 282 +generator observations and 243 sets. The sets produce empty metadata dictionaries, +yet still traverse the generic inspection path. These are repeated snapshots, +not unique objects. Avoiding redundant work on known types is a candidate; +dropping these records or fields would be a separate coverage change. + +## Disjoint profile breakdown and meaning of serialization + +The following partition assigns every function's exclusive time exactly once. +Its denominator is the separate profiled main-thread training time, not ordinary +training wall time or measured added overhead. Each column sums to 100% before +rounding. See the [detailed evidence](data/tracing-hotspot-breakdown-20261026.json) +for source profile/trace hashes, counts, methods, and exact values. + +| Exclusive-time category | MNIST | Transformer | +|---|---:|---:| +| Conversion loop and attribute helper's own Python code | 36.94% | 38.23% | +| Warning filters and their direct helper calls | 36.47% | 37.50% | +| Type checks across callers, excluding warning-owned time | 13.86% | 14.37% | +| Attribute lookup/name filtering across callers, excluding warning-owned time | 6.56% | 6.96% | +| JSON encoding and JSON-compatibility probes | 0.61% | 0.67% | +| Everything else in the profiled thread | 5.57% | 2.27% | + +The broader warning category includes `warnings.py` exclusive time plus direct +helper time assigned by pstats caller edges, such as list/filter operations. The +earlier 28.06%/28.89% figures include only functions defined in `warnings.py`. +Warning-to-warning edges are not added again. Other categories subtract the +warning-owned helper portion before assigning remaining exclusive time. Generic +type/attribute operations can have non-conversion callers, so these are an +explicit code-cost partition rather than exact semantic stage measurements. + +Here, metadata conversion means constructing a snapshot dictionary from a live +object. A tensor snapshot records dtype, shape, gradient/device flags and object +identities, with no tensor elements. The implementation enumerates public +attributes with `dir`, reads them with `getattr`, and classifies the returned +values; many inspected methods are subsequently discarded. This is part of +serialization in the broader sense. The earlier ~0.4% row covers only encoding an +already constructed record with `serialize`, not this snapshot construction. +There is also an earlier `json.dumps` compatibility probe for each value; the +partition above includes its JSON-function time. + +Warning management does not mean printing warnings. Every `safe_getattr` enters +`warnings.catch_warnings`, installs `simplefilter("ignore")`, reads one attribute, +and restores warning state. This is repeated even when no warning is raised. +Hoisting or bypassing this work needs the getter/warning/concurrency contract +checks described below. + +## Hashing is an unmeasured path in this audit + +Both profiles contain no calls to `dump_tensor`, `tensor_hash`, or `tensor_stats`. +API metadata conversion passes `include_tensor_data=False`, and model/proxy +tracking is disabled. The harness's initial/final model SHA-256 checks run outside +timed training for correctness. Hashing is also not universally one hash per API: +value/proxy tracking hashes eligible tensor-valued attributes according to its +tracking configuration. Therefore this audit does not estimate the cost +of tensor hashing, full tensor dumps, or statistics during training. + +The frozen production code also has an important routing detail: +`dumper.dump_tensor` passes `with_cuda=False` to `tensor_hash` for both CPU and CUDA +tensors. The selected hash path converts floating values to int64, uses +`.cpu().numpy().astype(np.int64)`, and performs a column loop in Python/NumPy. +CUDA training alone consequently does not select the CUDA hash implementation; +on CUDA tensors this path also includes a device-to-host transfer. This is a +source finding, not a measured time allocation. MPS hashing has an explicit +unsupported-fast-path TODO in the dumper. + +A hash-enabled follow-up must measure the actual tensor-tracking path separately: +number and bytes of hashed snapshots, input conversion, transfer/synchronization, +hash arithmetic, metadata construction, JSON encoding, and writer drain. CPU versus +CUDA hash choices must preserve hash results and mutation/snapshot behavior; no +backend or algorithm change was made here. The original metadata-only profile +cannot establish that hashing or full serialization is cheap. + ## Correctness and evidence Every run's complete loss trajectory, canonical initial/final model-state hash, From 44235bc9fc0bf902f1cdd86febdb59d7e2b72695 Mon Sep 17 00:00:00 2001 From: Yuxuan Jiang Date: Mon, 26 Oct 2026 21:44:52 +0800 Subject: [PATCH 4/5] Measure API and model tracing costs and audit CUDA hash safety --- .../data/tensor-hash-backends-20261026.json | 1154 +++++++++++++++++ .../data/tracer-components-20261026.json | 795 ++++++++++++ .../tensor-hash-backends-20261026.md | 104 ++ .../tracer-components-20261026.md | 161 +++ .../tracing-hotspot-audit-20261026.md | 10 + 5 files changed, 2224 insertions(+) create mode 100644 docs/measurements/data/tensor-hash-backends-20261026.json create mode 100644 docs/measurements/data/tracer-components-20261026.json create mode 100644 docs/measurements/tensor-hash-backends-20261026.md create mode 100644 docs/measurements/tracer-components-20261026.md diff --git a/docs/measurements/data/tensor-hash-backends-20261026.json b/docs/measurements/data/tensor-hash-backends-20261026.json new file mode 100644 index 00000000..01d20da1 --- /dev/null +++ b/docs/measurements/data/tensor-hash-backends-20261026.json @@ -0,0 +1,1154 @@ +{ + "schema_version": 1, + "date": "2026-10-26", + "source_commit": "9ba90ac84a1b4efd7e9f65b48b36bbbebf958253", + "source_sha256": "e917bec817df1981c682d8b8645307432c6badb220b9f7c424b4089d9bf97bd7", + "production_changes": false, + "historical_disable_commit": { + "sha": "fec69179f6fbfd906789ffa6278c61a627229179", + "author": "danielryckman", + "date": "2026-06-08", + "message": "temp fixes", + "change": "CUDA inputs switch from with_cuda=True to with_cuda=False; the same commit adds DTensor.to_local handling", + "rationale_documented": false + }, + "environment": { + "host": "labmach", + "python": "3.10.16", + "torch": "2.2.2+cu121", + "numba": "0.61.2", + "numpy": "1.26.4", + "gpu": "NVIDIA RTX A2000 12GB", + "driver": "545.23.08", + "platform": "Linux-6.1.0-1027-oem-x86_64-with-glibc2.35", + "native_threads": 1, + "host_exclusive": false, + "gpu_idle_at_recorded_pre_audit_and_extra_timing_checks": true + }, + "method": { + "warmups_per_backend": 2, + "timed_calls_per_backend_per_shape": 7, + "order": "CPU/CUDA then CUDA/CPU alternating by repetition", + "input_device": "cuda:0", + "dtype_for_timings": "torch.float32", + "timing_stream": "default", + "timing_scope": "Complete tensor_hash call plus CUDA synchronization; includes input integer conversion and CPU copy/hash or CUDA launch/result copy. Excludes tracing metadata, training, import/initialization.", + "nondefault_stream_delay_cycles": 10000000, + "stream_control_scope": "Producer delay/fill and hash invocation are inside same current Torch stream; CUDA-after-sync waits for producer before call; all methods synchronize after returned value.", + "shared_hash_semantics": "Both return only first-row accumulator; this audit preserves rather than repairs that algorithm." + }, + "correctness_summary": { + "cases": 17, + "both_success_equal": 15, + "all_inputs_unchanged": true, + "scalar_cpu_success_cuda_failure": true, + "empty_rows_both_fail_differently": true + }, + "correctness_cases": [ + { + "case": "scalar-f32", + "shape": [], + "dtype": "torch.float32", + "stride": [], + "cpu_backend": { + "success": true, + "value": 250000001, + "error_type": null, + "error_message": null + }, + "cuda_backend": { + "success": false, + "value": null, + "error_type": "ValueError", + "error_message": "not enough values to unpack (expected 2, got 0)" + }, + "both_succeeded": false, + "equal_values": false, + "input_unchanged": true + }, + { + "case": "empty-vector", + "shape": [ + 0 + ], + "dtype": "torch.float32", + "stride": [ + 1 + ], + "cpu_backend": { + "success": true, + "value": 0, + "error_type": null, + "error_message": null + }, + "cuda_backend": { + "success": true, + "value": 0, + "error_type": null, + "error_message": null + }, + "both_succeeded": true, + "equal_values": true, + "input_unchanged": true + }, + { + "case": "empty-rows", + "shape": [ + 0, + 3 + ], + "dtype": "torch.float32", + "stride": [ + 3, + 1 + ], + "cpu_backend": { + "success": false, + "value": null, + "error_type": "IndexError", + "error_message": "index 0 is out of bounds for axis 0 with size 0" + }, + "cuda_backend": { + "success": false, + "value": null, + "error_type": "CudaAPIError", + "error_message": "[1] Call to cuLaunchKernel results in CUDA_ERROR_INVALID_VALUE" + }, + "both_succeeded": false, + "equal_values": false, + "input_unchanged": true + }, + { + "case": "empty-columns", + "shape": [ + 3, + 0 + ], + "dtype": "torch.float32", + "stride": [ + 1, + 1 + ], + "cpu_backend": { + "success": true, + "value": 0, + "error_type": null, + "error_message": null + }, + "cuda_backend": { + "success": true, + "value": 0, + "error_type": null, + "error_message": null + }, + "both_succeeded": true, + "equal_values": true, + "input_unchanged": true + }, + { + "case": "vector", + "shape": [ + 17 + ], + "dtype": "torch.float32", + "stride": [ + 1 + ], + "cpu_backend": { + "success": true, + "value": -8252389398833339663, + "error_type": null, + "error_message": null + }, + "cuda_backend": { + "success": true, + "value": -8252389398833339663, + "error_type": null, + "error_message": null + }, + "both_succeeded": true, + "equal_values": true, + "input_unchanged": true + }, + { + "case": "matrix", + "shape": [ + 3, + 4 + ], + "dtype": "torch.float32", + "stride": [ + 4, + 1 + ], + "cpu_backend": { + "success": true, + "value": 4672964312098266124, + "error_type": null, + "error_message": null + }, + "cuda_backend": { + "success": true, + "value": 4672964312098266124, + "error_type": null, + "error_message": null + }, + "both_succeeded": true, + "equal_values": true, + "input_unchanged": true + }, + { + "case": "rank3", + "shape": [ + 2, + 3, + 4 + ], + "dtype": "torch.float32", + "stride": [ + 12, + 4, + 1 + ], + "cpu_backend": { + "success": true, + "value": 4672964312098266124, + "error_type": null, + "error_message": null + }, + "cuda_backend": { + "success": true, + "value": 4672964312098266124, + "error_type": null, + "error_message": null + }, + "both_succeeded": true, + "equal_values": true, + "input_unchanged": true + }, + { + "case": "transpose", + "shape": [ + 4, + 3 + ], + "dtype": "torch.float32", + "stride": [ + 1, + 4 + ], + "cpu_backend": { + "success": true, + "value": 2775809770071943447, + "error_type": null, + "error_message": null + }, + "cuda_backend": { + "success": true, + "value": 2775809770071943447, + "error_type": null, + "error_message": null + }, + "both_succeeded": true, + "equal_values": true, + "input_unchanged": true + }, + { + "case": "strided", + "shape": [ + 16 + ], + "dtype": "torch.float32", + "stride": [ + 2 + ], + "cpu_backend": { + "success": true, + "value": 1876072234410241200, + "error_type": null, + "error_message": null + }, + "cuda_backend": { + "success": true, + "value": 1876072234410241200, + "error_type": null, + "error_message": null + }, + "both_succeeded": true, + "equal_values": true, + "input_unchanged": true + }, + { + "case": "torch.float16", + "shape": [ + 3, + 4 + ], + "dtype": "torch.float16", + "stride": [ + 4, + 1 + ], + "cpu_backend": { + "success": true, + "value": -8429496642941146891, + "error_type": null, + "error_message": null + }, + "cuda_backend": { + "success": true, + "value": -8429496642941146891, + "error_type": null, + "error_message": null + }, + "both_succeeded": true, + "equal_values": true, + "input_unchanged": true + }, + { + "case": "torch.bfloat16", + "shape": [ + 3, + 4 + ], + "dtype": "torch.bfloat16", + "stride": [ + 4, + 1 + ], + "cpu_backend": { + "success": true, + "value": -5804717181047253492, + "error_type": null, + "error_message": null + }, + "cuda_backend": { + "success": true, + "value": -5804717181047253492, + "error_type": null, + "error_message": null + }, + "both_succeeded": true, + "equal_values": true, + "input_unchanged": true + }, + { + "case": "torch.float64", + "shape": [ + 3, + 4 + ], + "dtype": "torch.float64", + "stride": [ + 4, + 1 + ], + "cpu_backend": { + "success": true, + "value": 4672964312098266124, + "error_type": null, + "error_message": null + }, + "cuda_backend": { + "success": true, + "value": 4672964312098266124, + "error_type": null, + "error_message": null + }, + "both_succeeded": true, + "equal_values": true, + "input_unchanged": true + }, + { + "case": "torch.int8", + "shape": [ + 3, + 4 + ], + "dtype": "torch.int8", + "stride": [ + 4, + 1 + ], + "cpu_backend": { + "success": true, + "value": -1965408633344425390, + "error_type": null, + "error_message": null + }, + "cuda_backend": { + "success": true, + "value": -1965408633344425390, + "error_type": null, + "error_message": null + }, + "both_succeeded": true, + "equal_values": true, + "input_unchanged": true + }, + { + "case": "torch.uint8", + "shape": [ + 3, + 4 + ], + "dtype": "torch.uint8", + "stride": [ + 4, + 1 + ], + "cpu_backend": { + "success": true, + "value": -1965408633344425390, + "error_type": null, + "error_message": null + }, + "cuda_backend": { + "success": true, + "value": -1965408633344425390, + "error_type": null, + "error_message": null + }, + "both_succeeded": true, + "equal_values": true, + "input_unchanged": true + }, + { + "case": "torch.int16", + "shape": [ + 3, + 4 + ], + "dtype": "torch.int16", + "stride": [ + 4, + 1 + ], + "cpu_backend": { + "success": true, + "value": -1965408633344425390, + "error_type": null, + "error_message": null + }, + "cuda_backend": { + "success": true, + "value": -1965408633344425390, + "error_type": null, + "error_message": null + }, + "both_succeeded": true, + "equal_values": true, + "input_unchanged": true + }, + { + "case": "torch.int32", + "shape": [ + 3, + 4 + ], + "dtype": "torch.int32", + "stride": [ + 4, + 1 + ], + "cpu_backend": { + "success": true, + "value": -1965408633344425390, + "error_type": null, + "error_message": null + }, + "cuda_backend": { + "success": true, + "value": -1965408633344425390, + "error_type": null, + "error_message": null + }, + "both_succeeded": true, + "equal_values": true, + "input_unchanged": true + }, + { + "case": "torch.int64", + "shape": [ + 3, + 4 + ], + "dtype": "torch.int64", + "stride": [ + 4, + 1 + ], + "cpu_backend": { + "success": true, + "value": -1965408633344425390, + "error_type": null, + "error_message": null + }, + "cuda_backend": { + "success": true, + "value": -1965408633344425390, + "error_type": null, + "error_message": null + }, + "both_succeeded": true, + "equal_values": true, + "input_unchanged": true + } + ], + "stream_controls": [ + { + "dtype": "torch.int64", + "iteration": 0, + "variant": "cuda-current-stream", + "expected": -5810646643502623232, + "actual": -5338016848865215808, + "actual_success": true, + "actual_error_type": null, + "actual_error_message": null, + "cpu_after_sync": -5810646643502623232, + "matches_expected": false + }, + { + "dtype": "torch.int64", + "iteration": 0, + "variant": "cuda-after-sync", + "expected": -5810646643502623232, + "actual": -5810646643502623232, + "actual_success": true, + "actual_error_type": null, + "actual_error_message": null, + "cpu_after_sync": -5810646643502623232, + "matches_expected": true + }, + { + "dtype": "torch.int64", + "iteration": 0, + "variant": "cpu-current-stream", + "expected": -5810646643502623232, + "actual": -5810646643502623232, + "actual_success": true, + "actual_error_type": null, + "actual_error_message": null, + "cpu_after_sync": -5810646643502623232, + "matches_expected": true + }, + { + "dtype": "torch.int64", + "iteration": 1, + "variant": "cuda-current-stream", + "expected": 7298080581341712576, + "actual": -5338016848865215808, + "actual_success": true, + "actual_error_type": null, + "actual_error_message": null, + "cpu_after_sync": 7298080581341712576, + "matches_expected": false + }, + { + "dtype": "torch.int64", + "iteration": 1, + "variant": "cuda-after-sync", + "expected": 7298080581341712576, + "actual": 7298080581341712576, + "actual_success": true, + "actual_error_type": null, + "actual_error_message": null, + "cpu_after_sync": 7298080581341712576, + "matches_expected": true + }, + { + "dtype": "torch.int64", + "iteration": 1, + "variant": "cpu-current-stream", + "expected": 7298080581341712576, + "actual": 7298080581341712576, + "actual_success": true, + "actual_error_type": null, + "actual_error_message": null, + "cpu_after_sync": 7298080581341712576, + "matches_expected": true + }, + { + "dtype": "torch.int64", + "iteration": 2, + "variant": "cuda-current-stream", + "expected": 1960063732476496768, + "actual": -5338016848865215808, + "actual_success": true, + "actual_error_type": null, + "actual_error_message": null, + "cpu_after_sync": 1960063732476496768, + "matches_expected": false + }, + { + "dtype": "torch.int64", + "iteration": 2, + "variant": "cuda-after-sync", + "expected": 1960063732476496768, + "actual": 1960063732476496768, + "actual_success": true, + "actual_error_type": null, + "actual_error_message": null, + "cpu_after_sync": 1960063732476496768, + "matches_expected": true + }, + { + "dtype": "torch.int64", + "iteration": 2, + "variant": "cpu-current-stream", + "expected": 1960063732476496768, + "actual": 1960063732476496768, + "actual_success": true, + "actual_error_type": null, + "actual_error_message": null, + "cpu_after_sync": 1960063732476496768, + "matches_expected": true + }, + { + "dtype": "torch.float32", + "iteration": 0, + "variant": "cuda-current-stream", + "expected": 8485304009635789504, + "actual": -5338016848865215808, + "actual_success": true, + "actual_error_type": null, + "actual_error_message": null, + "cpu_after_sync": 8485304009635789504, + "matches_expected": false + }, + { + "dtype": "torch.float32", + "iteration": 0, + "variant": "cuda-after-sync", + "expected": 8485304009635789504, + "actual": 8485304009635789504, + "actual_success": true, + "actual_error_type": null, + "actual_error_message": null, + "cpu_after_sync": 8485304009635789504, + "matches_expected": true + }, + { + "dtype": "torch.float32", + "iteration": 0, + "variant": "cpu-current-stream", + "expected": 8485304009635789504, + "actual": 8485304009635789504, + "actual_success": true, + "actual_error_type": null, + "actual_error_message": null, + "cpu_after_sync": 8485304009635789504, + "matches_expected": true + }, + { + "dtype": "torch.float32", + "iteration": 1, + "variant": "cuda-current-stream", + "expected": 2554316672117553856, + "actual": -5338016848865215808, + "actual_success": true, + "actual_error_type": null, + "actual_error_message": null, + "cpu_after_sync": 2554316672117553856, + "matches_expected": false + }, + { + "dtype": "torch.float32", + "iteration": 1, + "variant": "cuda-after-sync", + "expected": 2554316672117553856, + "actual": 2554316672117553856, + "actual_success": true, + "actual_error_type": null, + "actual_error_message": null, + "cpu_after_sync": 2554316672117553856, + "matches_expected": true + }, + { + "dtype": "torch.float32", + "iteration": 1, + "variant": "cpu-current-stream", + "expected": 2554316672117553856, + "actual": 2554316672117553856, + "actual_success": true, + "actual_error_type": null, + "actual_error_message": null, + "cpu_after_sync": 2554316672117553856, + "matches_expected": true + }, + { + "dtype": "torch.float32", + "iteration": 2, + "variant": "cuda-current-stream", + "expected": -3376670665400681792, + "actual": -5338016848865215808, + "actual_success": true, + "actual_error_type": null, + "actual_error_message": null, + "cpu_after_sync": -3376670665400681792, + "matches_expected": false + }, + { + "dtype": "torch.float32", + "iteration": 2, + "variant": "cuda-after-sync", + "expected": -3376670665400681792, + "actual": -3376670665400681792, + "actual_success": true, + "actual_error_type": null, + "actual_error_message": null, + "cpu_after_sync": -3376670665400681792, + "matches_expected": true + }, + { + "dtype": "torch.float32", + "iteration": 2, + "variant": "cpu-current-stream", + "expected": -3376670665400681792, + "actual": -3376670665400681792, + "actual_success": true, + "actual_error_type": null, + "actual_error_message": null, + "cpu_after_sync": -3376670665400681792, + "matches_expected": true + } + ], + "stream_control_summary": { + "cases": 18, + "cuda_current_stream_correct": 0, + "cuda_after_sync_correct": 6, + "cpu_current_stream_correct": 6, + "cases_per_variant": 6 + }, + "mutation_observation": { + "original": { + "cpu": { + "success": true, + "value": 4672964312098266124, + "error_type": null, + "error_message": null + }, + "cuda": { + "success": true, + "value": 4672964312098266124, + "error_type": null, + "error_message": null + } + }, + "nonfirst_row_changed": { + "cpu": { + "success": true, + "value": 4672964312098266124, + "error_type": null, + "error_message": null + }, + "cuda": { + "success": true, + "value": 4672964312098266124, + "error_type": null, + "error_message": null + } + }, + "first_row_changed": { + "cpu": { + "success": true, + "value": 7141502261496787212, + "error_type": null, + "error_message": null + }, + "cuda": { + "success": true, + "value": 7141502261496787212, + "error_type": null, + "error_message": null + } + } + }, + "timings": [ + { + "shape": [ + 16 + ], + "dtype": "torch.float32", + "input_bytes": 64, + "cpu_median_seconds": 4.952773451805115e-05, + "cuda_median_seconds": 0.00012518838047981262, + "cpu_divided_by_cuda": 0.3956256509447999, + "samples_seconds": { + "cpu": [ + 6.622076034545898e-05, + 5.0224363803863525e-05, + 4.2010098695755005e-05, + 5.261227488517761e-05, + 4.2729079723358154e-05, + 4.952773451805115e-05, + 4.1406601667404175e-05 + ], + "cuda": [ + 0.00013249367475509644, + 0.00012518838047981262, + 0.00012725964188575745, + 0.0001330748200416565, + 0.00011906027793884277, + 0.00011687353253364563, + 0.0001161135733127594 + ] + } + }, + { + "shape": [ + 64, + 64 + ], + "dtype": "torch.float32", + "input_bytes": 16384, + "cpu_median_seconds": 0.00010630860924720764, + "cuda_median_seconds": 0.00011986866593360901, + "cpu_divided_by_cuda": 0.8868757186810454, + "samples_seconds": { + "cpu": [ + 0.00011799484491348267, + 0.00011884793639183044, + 9.90740954875946e-05, + 0.00011590495705604553, + 0.00010630860924720764, + 0.00010573118925094604, + 9.775161743164062e-05 + ], + "cuda": [ + 0.00013583898544311523, + 0.00012421980500221252, + 0.000123538076877594, + 0.00011800974607467651, + 0.00011986866593360901, + 0.00011301413178443909, + 0.00011808797717094421 + ] + } + }, + { + "shape": [ + 1024, + 1024 + ], + "dtype": "torch.float32", + "input_bytes": 4194304, + "cpu_median_seconds": 0.011968977749347687, + "cuda_median_seconds": 0.00030375272035598755, + "cpu_divided_by_cuda": 39.403689077485346, + "samples_seconds": { + "cpu": [ + 0.01245785504579544, + 0.01018982008099556, + 0.01201363280415535, + 0.010214142501354218, + 0.011646285653114319, + 0.011968977749347687, + 0.01430797204375267 + ], + "cuda": [ + 0.00039573386311531067, + 0.00029542669653892517, + 0.0003079622983932495, + 0.0002805367112159729, + 0.0003190450370311737, + 0.0002852119505405426, + 0.00030375272035598755 + ] + } + }, + { + "shape": [ + 1024 + ], + "dtype": "torch.float32", + "input_bytes": 4096, + "cpu_median_seconds": 0.0010499395430088043, + "cuda_median_seconds": 0.00020195543766021729, + "cpu_divided_by_cuda": 5.1988674094296465, + "samples_seconds": { + "cpu": [ + 0.0010948777198791504, + 0.001168135553598404, + 0.0010659284889698029, + 0.0010499395430088043, + 0.001040138304233551, + 0.001040775328874588, + 0.0010373108088970184 + ], + "cuda": [ + 0.00020319223403930664, + 0.00019872933626174927, + 0.0002453327178955078, + 0.00020195543766021729, + 0.00020509213209152222, + 0.00019384920597076416, + 0.00018447265028953552 + ] + } + }, + { + "shape": [ + 4096 + ], + "dtype": "torch.float32", + "input_bytes": 16384, + "cpu_median_seconds": 0.0040616244077682495, + "cuda_median_seconds": 0.00041097402572631836, + "cpu_divided_by_cuda": 9.882922407541697, + "samples_seconds": { + "cpu": [ + 0.004065990447998047, + 0.00405396893620491, + 0.004031617194414139, + 0.004064466804265976, + 0.0040616244077682495, + 0.004073053598403931, + 0.004030473530292511 + ], + "cuda": [ + 0.0004185512661933899, + 0.000406607985496521, + 0.0004246942698955536, + 0.00041097402572631836, + 0.00041143596172332764, + 0.0004088655114173889, + 0.0004093572497367859 + ] + } + }, + { + "shape": [ + 256, + 256 + ], + "dtype": "torch.float32", + "input_bytes": 262144, + "cpu_median_seconds": 0.00046943873167037964, + "cuda_median_seconds": 0.00015348196029663086, + "cpu_divided_by_cuda": 3.058592233009709, + "samples_seconds": { + "cpu": [ + 0.0004907324910163879, + 0.0004807673394680023, + 0.00046698376536369324, + 0.0004808157682418823, + 0.0004634670913219452, + 0.00046943873167037964, + 0.00046386197209358215 + ], + "cuda": [ + 0.00015043094754219055, + 0.00013437122106552124, + 0.00026668235659599304, + 0.00016199424862861633, + 0.00016066059470176697, + 0.00014073774218559265, + 0.00015348196029663086 + ] + } + }, + { + "shape": [ + 4096, + 16 + ], + "dtype": "torch.float32", + "input_bytes": 262144, + "cpu_median_seconds": 0.00021225959062576294, + "cuda_median_seconds": 0.00013484060764312744, + "cpu_divided_by_cuda": 1.5741518399823184, + "samples_seconds": { + "cpu": [ + 0.00022611767053604126, + 0.00021656975150108337, + 0.0002048984169960022, + 0.00021633505821228027, + 0.00020454823970794678, + 0.00021195784211158752, + 0.00021225959062576294 + ], + "cuda": [ + 0.0002016797661781311, + 0.00013020634651184082, + 0.0001468472182750702, + 0.0001270100474357605, + 0.00014220550656318665, + 0.00012057647109031677, + 0.00013484060764312744 + ] + } + }, + { + "shape": [ + 1, + 1024 + ], + "dtype": "torch.float32", + "input_bytes": 4096, + "cpu_median_seconds": 0.00103827565908432, + "cuda_median_seconds": 0.0001866072416305542, + "cpu_divided_by_cuda": 5.563962309350795, + "samples_seconds": { + "cpu": [ + 0.001045726239681244, + 0.0011187456548213959, + 0.00103827565908432, + 0.0010272487998008728, + 0.00103059783577919, + 0.001041904091835022, + 0.0010345764458179474 + ], + "cuda": [ + 0.0002496987581253052, + 0.0002479180693626404, + 0.00019634515047073364, + 0.00018278881907463074, + 0.00018258020281791687, + 0.0001782625913619995, + 0.0001866072416305542 + ] + } + }, + { + "shape": [ + 1024, + 1 + ], + "dtype": "torch.float32", + "input_bytes": 4096, + "cpu_median_seconds": 3.3993273973464966e-05, + "cuda_median_seconds": 0.00012517720460891724, + "cpu_divided_by_cuda": 0.27156121659425037, + "samples_seconds": { + "cpu": [ + 3.674626350402832e-05, + 4.293397068977356e-05, + 2.830103039741516e-05, + 3.913417458534241e-05, + 2.831965684890747e-05, + 3.3993273973464966e-05, + 2.8524547815322876e-05 + ], + "cuda": [ + 0.0001200549304485321, + 0.00018195435404777527, + 0.00019641220569610596, + 0.00012517720460891724, + 0.0001265890896320343, + 0.00011945515871047974, + 0.00011345371603965759 + ] + } + } + ], + "artifacts": { + "remote_directory": "/home/yuxuan/experiments/codex-hash-backend-audit-20261026-v020", + "local_directory": "/Users/matt/gitrepos/traincheck/outputs/tracing-components-20261026/hash", + "verified_files": [ + { + "filename": "audit_hash.py", + "sha256": "a80a6ab65f0f3af203a6b358f330c88965d4d9e37ac3b552188fe5f3be54a713", + "bytes": 9276 + }, + { + "filename": "audit_hash_more_shapes.py", + "sha256": "d9d8c79bf72e915b098c7b9ba223cb81a0f535526245ca2cad2cb8c60d4b8565", + "bytes": 3075 + }, + { + "filename": "audit_hash_stream_controls.py", + "sha256": "6ac71fc295a9e5e6346136686c606900d2f8151d17de3db9b58cc4e28cf5f414", + "bytes": 2645 + }, + { + "filename": "audit_hash_streams.py", + "sha256": "dc6c3746579e6f453045c7b3fbf7bb51a7954894cfe9c8a6c644a24e31dbb83c", + "bytes": 2022 + }, + { + "filename": "hash_source.py", + "sha256": "e917bec817df1981c682d8b8645307432c6badb220b9f7c424b4089d9bf97bd7", + "bytes": 4602 + }, + { + "filename": "hash-results.json", + "sha256": "5112894bf5c7e9e22dbcd3d277745f33f01a4ddd857abd8c2728fa8169f94898", + "bytes": 15016 + }, + { + "filename": "more-shapes-results.json", + "sha256": "e8775f4bbeeb7b8b7f4f33f93d9c6e5c6d0c4bd3e6e202308c6a83ab9a40291f", + "bytes": 5180 + }, + { + "filename": "stream-controls-results.json", + "sha256": "9747a1d6b289c56eca07adb2af6a2eede4d87006c121d55ab00cf7d75ea3844e", + "bytes": 10684 + }, + { + "filename": "stream-results.json", + "sha256": "b4668c0dd605ad1f3719f1e281d1578f314b3217ffa5928d2788e903427d703a", + "bytes": 3484 + }, + { + "filename": "audit.log", + "sha256": "67bac1c7d27ed0558a6aedfa1984add1a1e80a5f936f2e8d49ce1327acd6d559", + "bytes": 1046 + }, + { + "filename": "more-shapes.log", + "sha256": "5f83f7704f33453241515e5974b99e585cc78cad382c8663636c7584fd62b082", + "bytes": 800 + }, + { + "filename": "stream-controls.log", + "sha256": "68adee85d1818c7edff9419aa9ef5352206a9cfed3e762b2be8bbb28eb95265a", + "bytes": 278 + }, + { + "filename": "stream.log", + "sha256": "119688bb48d6e261896b5cf8be552538647b9ae4b1b77daa1bb5ddfa8a04c4b8", + "bytes": 280 + } + ], + "reproduce_commands": [ + "cd /home/yuxuan/experiments/codex-hash-backend-audit-20261026-v020 && OMP_NUM_THREADS=1 MKL_NUM_THREADS=1 OPENBLAS_NUM_THREADS=1 PYTHONDONTWRITEBYTECODE=1 timeout 90 /home/yuxuan/miniconda3/envs/traincheck/bin/python audit_hash.py --source hash_source.py --output hash-results.json", + "cd /home/yuxuan/experiments/codex-hash-backend-audit-20261026-v020 && OMP_NUM_THREADS=1 MKL_NUM_THREADS=1 OPENBLAS_NUM_THREADS=1 PYTHONDONTWRITEBYTECODE=1 timeout 30 /home/yuxuan/miniconda3/envs/traincheck/bin/python audit_hash_streams.py", + "cd /home/yuxuan/experiments/codex-hash-backend-audit-20261026-v020 && OMP_NUM_THREADS=1 MKL_NUM_THREADS=1 OPENBLAS_NUM_THREADS=1 PYTHONDONTWRITEBYTECODE=1 timeout 30 /home/yuxuan/miniconda3/envs/traincheck/bin/python audit_hash_stream_controls.py", + "cd /home/yuxuan/experiments/codex-hash-backend-audit-20261026-v020 && OMP_NUM_THREADS=1 MKL_NUM_THREADS=1 OPENBLAS_NUM_THREADS=1 PYTHONDONTWRITEBYTECODE=1 timeout 60 /home/yuxuan/miniconda3/envs/traincheck/bin/python audit_hash_more_shapes.py" + ] + }, + "validation": { + "strict_mypy": { + "passed": true, + "files": 4, + "options": [ + "--check-untyped-defs", + "--disallow-untyped-defs", + "--disallow-any-generics", + "--follow-imports=skip" + ] + }, + "black": { + "passed": true, + "files": 4, + "target_version": "py310" + }, + "isort": { + "passed": true, + "files": 4, + "profile": "black" + }, + "downloaded_hashes_verified": 13, + "unchanged_released_source_verified": true + }, + "limits": [ + "Hash-only microbenchmark; no percentage of total tracing or training inferred.", + "Default-stream timings do not include a proposed stream-safety repair.", + "One warmed process per timing batch, seven alternating measurements per backend, no exclusive host or confidence interval.", + "No production backend default or algorithm changed.", + "Scalar/empty errors and stream observations must be handled before enabling CUDA generally.", + "First-row-only behavior is shared existing hash semantics, separate from backend parity." + ] +} diff --git a/docs/measurements/data/tracer-components-20261026.json b/docs/measurements/data/tracer-components-20261026.json new file mode 100644 index 00000000..1039e9b4 --- /dev/null +++ b/docs/measurements/data/tracer-components-20261026.json @@ -0,0 +1,795 @@ +{ + "source_commit": "9ba90ac84a1b4efd7e9f65b48b36bbbebf958253", + "source_tree": "6fbebbeae8f1c4327d39452361325b9c716a4068", + "source_files_verified_against_release_archive": 77, + "mode": "subclass model tracing, CPU hash format, 3 cold CPU steps, batch2, fp32", + "workload": "Exact benchmark MNIST Net, 1,199,882 parameters; first six cached training images; Adadelta; seeds42/43; one native thread", + "tracer_topology": "VAR modes install normal depth3 static observers and scan_proxy_in_args=True; API-only omits both; VAR-only uses production no-dump API wrapper fast path", + "timing_denominator": "Three training steps including start_step and wrapper-disable; excludes imports/setup/loss extraction/state hashes/background-writer drain", + "ordinary_runs": { + "plain": { + "seconds": [ + 0.02966778352856636, + 0.029060598462820053, + 0.03131105750799179 + ], + "median_seconds": 0.02966778352856636, + "min_seconds": 0.029060598462820053, + "max_seconds": 0.03131105750799179 + }, + "api": { + "seconds": [ + 0.34370866417884827, + 0.3386892266571522, + 0.3355434164404869 + ], + "median_seconds": 0.3386892266571522, + "min_seconds": 0.3355434164404869, + "max_seconds": 0.34370866417884827 + }, + "var": { + "seconds": [ + 0.37231897935271263, + 0.4145994558930397, + 0.4741646386682987 + ], + "median_seconds": 0.4145994558930397, + "min_seconds": 0.37231897935271263, + "max_seconds": 0.4741646386682987 + }, + "combined": { + "seconds": [ + 0.7073203325271606, + 0.7271270304918289, + 0.7525023780763149 + ], + "median_seconds": 0.7271270304918289, + "min_seconds": 0.7073203325271606, + "max_seconds": 0.7525023780763149 + } + }, + "ablation_decomposition": { + "added_combined_seconds": 0.6974592469632626, + "api_increment_seconds": 0.3090214431285858, + "var_increment_seconds": 0.38493167236447334, + "interaction_seconds": 0.0035061314702033997, + "api_percent_of_added_combined": 44.306738275256244, + "var_percent_of_added_combined": 55.190561174787746, + "interaction_percent_of_added_combined": 0.5027005499560147, + "marginal_var_on_top_of_api_seconds": 0.38843780383467674, + "interpretation": "Differences of ordinary-run medians, not a physically exclusive stage timer. Interaction includes shared work, topology differences, and timing noise; it may be negative." + }, + "combined_profile": { + "total_seconds": 1.4951598140000004, + "sha256": "59e728e23bd2538eb0ffbdc1c0821c85231e5d7fac931f4a40d36fa5571544e3", + "rows": [ + { + "file": "/home/yuxuan/experiments/codex-tracing-components-20261026-v020/source/traincheck/instrumentor/tracer.py", + "line": 160, + "function": "to_dict_args_kwargs", + "calls": 260, + "self_seconds": 0.00033124200000000004, + "cumulative_seconds": 0.59092002, + "percent_of_profile_total": 39.52219785917814 + }, + { + "file": "/home/yuxuan/experiments/codex-tracing-components-20261026-v020/source/traincheck/instrumentor/proxy_wrapper/hash.py", + "line": 47, + "function": "hash_tensor_cpu", + "calls": 112, + "self_seconds": 0.170946004, + "cumulative_seconds": 0.32131208, + "percent_of_profile_total": 21.490149547317884 + }, + { + "file": "/home/yuxuan/experiments/codex-tracing-components-20261026-v020/source/traincheck/instrumentor/proxy_wrapper/hash.py", + "line": 95, + "function": "tensor_hash", + "calls": 112, + "self_seconds": 0.010262915000000001, + "cumulative_seconds": 0.36295976, + "percent_of_profile_total": 24.275649773449565 + }, + { + "file": "/home/yuxuan/experiments/codex-tracing-components-20261026-v020/source/traincheck/instrumentor/dumper.py", + "line": 302, + "function": "dump_tensor", + "calls": 112, + "self_seconds": 0.004399142, + "cumulative_seconds": 0.36736353800000004, + "percent_of_profile_total": 24.57018537818994 + }, + { + "file": "/home/yuxuan/experiments/codex-tracing-components-20261026-v020/source/traincheck/instrumentor/proxy_wrapper/subclass.py", + "line": 181, + "function": "dump_trace", + "calls": 64, + "self_seconds": 0.000179428, + "cumulative_seconds": 0.568882218, + "percent_of_profile_total": 38.04825495396841 + }, + { + "file": "/home/yuxuan/experiments/codex-tracing-components-20261026-v020/source/traincheck/instrumentor/dumper.py", + "line": 241, + "function": "dump_trace_API", + "calls": 520, + "self_seconds": 0.000411052, + "cumulative_seconds": 0.005945879, + "percent_of_profile_total": 0.39767514778858276 + }, + { + "file": "/home/yuxuan/experiments/codex-tracing-components-20261026-v020/source/traincheck/instrumentor/dumper.py", + "line": 250, + "function": "dump_trace_VAR", + "calls": 64, + "self_seconds": 5.6548e-05, + "cumulative_seconds": 0.0013427760000000002, + "percent_of_profile_total": 0.08980819223649893 + }, + { + "file": "/home/yuxuan/experiments/codex-tracing-components-20261026-v020/source/traincheck/instrumentor/dumper.py", + "line": 85, + "function": "serialize", + "calls": 584, + "self_seconds": 0.000740237, + "cumulative_seconds": 0.004557091, + "percent_of_profile_total": 0.30478955877020375 + }, + { + "file": "/home/yuxuan/experiments/codex-tracing-components-20261026-v020/source/traincheck/instrumentor/tracer.py", + "line": 184, + "function": "to_dict_return_value", + "calls": 260, + "self_seconds": 0.000122889, + "cumulative_seconds": 0.28594894600000004, + "percent_of_profile_total": 19.1249753586542 + } + ], + "limits": "Separate instrumented profile; cumulative rows overlap; hash is nested in variable snapshots. Do not apply these percentages to ordinary-run timings." + }, + "validation": { + "full_loss_and_initial_final_state_parity": true, + "all_raw_trace_digests_counts_and_pairs_verified": true, + "cases": [ + { + "label": "mnist-plain-r1", + "records": { + "API": 0, + "VAR": 0 + }, + "tensor_data_and_gradient_hash_fields": 0, + "logical_input_bytes_of_hashed_tensors": 0, + "logical_hash_input_bytes_by_variable": {} + }, + { + "label": "mnist-api-r1", + "records": { + "API": 520, + "VAR": 0 + }, + "tensor_data_and_gradient_hash_fields": 0, + "logical_input_bytes_of_hashed_tensors": 0, + "logical_hash_input_bytes_by_variable": {} + }, + { + "label": "mnist-var-r1", + "records": { + "API": 0, + "VAR": 64 + }, + "tensor_data_and_gradient_hash_fields": 112, + "logical_input_bytes_of_hashed_tensors": 67193392, + "logical_hash_input_bytes_by_variable": { + "model.conv1.weight": 16128, + "model.conv1.bias": 1792, + "model.conv2.weight": 1032192, + "model.conv2.bias": 3584, + "model.fc1.weight": 66060288, + "model.fc1.bias": 7168, + "model.fc2.weight": 71680, + "model.fc2.bias": 560 + } + }, + { + "label": "mnist-combined-r1", + "records": { + "API": 520, + "VAR": 64 + }, + "tensor_data_and_gradient_hash_fields": 112, + "logical_input_bytes_of_hashed_tensors": 67193392, + "logical_hash_input_bytes_by_variable": { + "model.conv1.weight": 16128, + "model.conv1.bias": 1792, + "model.conv2.weight": 1032192, + "model.conv2.bias": 3584, + "model.fc1.weight": 66060288, + "model.fc1.bias": 7168, + "model.fc2.weight": 71680, + "model.fc2.bias": 560 + } + }, + { + "label": "mnist-combined-r2", + "records": { + "API": 520, + "VAR": 64 + }, + "tensor_data_and_gradient_hash_fields": 112, + "logical_input_bytes_of_hashed_tensors": 67193392, + "logical_hash_input_bytes_by_variable": { + "model.conv1.weight": 16128, + "model.conv1.bias": 1792, + "model.conv2.weight": 1032192, + "model.conv2.bias": 3584, + "model.fc1.weight": 66060288, + "model.fc1.bias": 7168, + "model.fc2.weight": 71680, + "model.fc2.bias": 560 + } + }, + { + "label": "mnist-var-r2", + "records": { + "API": 0, + "VAR": 64 + }, + "tensor_data_and_gradient_hash_fields": 112, + "logical_input_bytes_of_hashed_tensors": 67193392, + "logical_hash_input_bytes_by_variable": { + "model.conv1.weight": 16128, + "model.conv1.bias": 1792, + "model.conv2.weight": 1032192, + "model.conv2.bias": 3584, + "model.fc1.weight": 66060288, + "model.fc1.bias": 7168, + "model.fc2.weight": 71680, + "model.fc2.bias": 560 + } + }, + { + "label": "mnist-api-r2", + "records": { + "API": 520, + "VAR": 0 + }, + "tensor_data_and_gradient_hash_fields": 0, + "logical_input_bytes_of_hashed_tensors": 0, + "logical_hash_input_bytes_by_variable": {} + }, + { + "label": "mnist-plain-r2", + "records": { + "API": 0, + "VAR": 0 + }, + "tensor_data_and_gradient_hash_fields": 0, + "logical_input_bytes_of_hashed_tensors": 0, + "logical_hash_input_bytes_by_variable": {} + }, + { + "label": "mnist-var-r3", + "records": { + "API": 0, + "VAR": 64 + }, + "tensor_data_and_gradient_hash_fields": 112, + "logical_input_bytes_of_hashed_tensors": 67193392, + "logical_hash_input_bytes_by_variable": { + "model.conv1.weight": 16128, + "model.conv1.bias": 1792, + "model.conv2.weight": 1032192, + "model.conv2.bias": 3584, + "model.fc1.weight": 66060288, + "model.fc1.bias": 7168, + "model.fc2.weight": 71680, + "model.fc2.bias": 560 + } + }, + { + "label": "mnist-plain-r3", + "records": { + "API": 0, + "VAR": 0 + }, + "tensor_data_and_gradient_hash_fields": 0, + "logical_input_bytes_of_hashed_tensors": 0, + "logical_hash_input_bytes_by_variable": {} + }, + { + "label": "mnist-combined-r3", + "records": { + "API": 520, + "VAR": 64 + }, + "tensor_data_and_gradient_hash_fields": 112, + "logical_input_bytes_of_hashed_tensors": 67193392, + "logical_hash_input_bytes_by_variable": { + "model.conv1.weight": 16128, + "model.conv1.bias": 1792, + "model.conv2.weight": 1032192, + "model.conv2.bias": 3584, + "model.fc1.weight": 66060288, + "model.fc1.bias": 7168, + "model.fc2.weight": 71680, + "model.fc2.bias": 560 + } + }, + { + "label": "mnist-api-r3", + "records": { + "API": 520, + "VAR": 0 + }, + "tensor_data_and_gradient_hash_fields": 0, + "logical_input_bytes_of_hashed_tensors": 0, + "logical_hash_input_bytes_by_variable": {} + }, + { + "label": "mnist-combined-r1-profile", + "records": { + "API": 520, + "VAR": 64 + }, + "tensor_data_and_gradient_hash_fields": 112, + "logical_input_bytes_of_hashed_tensors": 67193392, + "logical_hash_input_bytes_by_variable": { + "model.conv1.weight": 16128, + "model.conv1.bias": 1792, + "model.conv2.weight": 1032192, + "model.conv2.bias": 3584, + "model.fc1.weight": 66060288, + "model.fc1.bias": 7168, + "model.fc2.weight": 71680, + "model.fc2.bias": 560 + } + } + ] + }, + "transformer": { + "status": "failed before completing first training step", + "failure": { + "command": [ + "/home/yuxuan/experiments/codex-inference-runtime-20261025/venv/bin/python", + "/home/yuxuan/experiments/codex-tracing-components-20261026-v020/component_runner.py", + "--root", + "/home/yuxuan/experiments/codex-tracing-components-20261026-v020", + "--child", + "--workload", + "transformer", + "--mode", + "var", + "--output", + "/home/yuxuan/experiments/codex-tracing-components-20261026-v020/runs/transformer-var-r1", + "--steps", + "3" + ], + "exit_code": 1, + "label": "transformer-var-r1", + "metrics": { + "error": { + "message": "'Tensor' object has no attribute 'named_parameters'", + "type": "AttributeError" + }, + "final_shapes": { + "model.decoder.bias": { + "dtype": "torch.float32", + "shape": [ + 60 + ] + }, + "model.decoder.weight": { + "dtype": "torch.float32", + "shape": [ + 60, + 32 + ] + }, + "model.encoder.layers.0.linear1.bias": { + "dtype": "torch.float32", + "shape": [ + 64 + ] + }, + "model.encoder.layers.0.linear1.weight": { + "dtype": "torch.float32", + "shape": [ + 64, + 32 + ] + }, + "model.encoder.layers.0.linear2.bias": { + "dtype": "torch.float32", + "shape": [ + 32 + ] + }, + "model.encoder.layers.0.linear2.weight": { + "dtype": "torch.float32", + "shape": [ + 32, + 64 + ] + }, + "model.encoder.layers.0.norm1.bias": { + "dtype": "torch.float32", + "shape": [ + 32 + ] + }, + "model.encoder.layers.0.norm1.weight": { + "dtype": "torch.float32", + "shape": [ + 32 + ] + }, + "model.encoder.layers.0.norm2.bias": { + "dtype": "torch.float32", + "shape": [ + 32 + ] + }, + "model.encoder.layers.0.norm2.weight": { + "dtype": "torch.float32", + "shape": [ + 32 + ] + }, + "model.encoder.layers.0.self_attn.in_proj_bias": { + "dtype": "torch.float32", + "shape": [ + 96 + ] + }, + "model.encoder.layers.0.self_attn.in_proj_weight": { + "dtype": "torch.float32", + "shape": [ + 96, + 32 + ] + }, + "model.encoder.layers.0.self_attn.out_proj.bias": { + "dtype": "torch.float32", + "shape": [ + 32 + ] + }, + "model.encoder.layers.0.self_attn.out_proj.weight": { + "dtype": "torch.float32", + "shape": [ + 32, + 32 + ] + }, + "model.encoder.layers.1.linear1.bias": { + "dtype": "torch.float32", + "shape": [ + 64 + ] + }, + "model.encoder.layers.1.linear1.weight": { + "dtype": "torch.float32", + "shape": [ + 64, + 32 + ] + }, + "model.encoder.layers.1.linear2.bias": { + "dtype": "torch.float32", + "shape": [ + 32 + ] + }, + "model.encoder.layers.1.linear2.weight": { + "dtype": "torch.float32", + "shape": [ + 32, + 64 + ] + }, + "model.encoder.layers.1.norm1.bias": { + "dtype": "torch.float32", + "shape": [ + 32 + ] + }, + "model.encoder.layers.1.norm1.weight": { + "dtype": "torch.float32", + "shape": [ + 32 + ] + }, + "model.encoder.layers.1.norm2.bias": { + "dtype": "torch.float32", + "shape": [ + 32 + ] + }, + "model.encoder.layers.1.norm2.weight": { + "dtype": "torch.float32", + "shape": [ + 32 + ] + }, + "model.encoder.layers.1.self_attn.in_proj_bias": { + "dtype": "torch.float32", + "shape": [ + 96 + ] + }, + "model.encoder.layers.1.self_attn.in_proj_weight": { + "dtype": "torch.float32", + "shape": [ + 96, + 32 + ] + }, + "model.encoder.layers.1.self_attn.out_proj.bias": { + "dtype": "torch.float32", + "shape": [ + 32 + ] + }, + "model.encoder.layers.1.self_attn.out_proj.weight": { + "dtype": "torch.float32", + "shape": [ + 32, + 32 + ] + }, + "model.encoder.norm.bias": { + "dtype": "torch.float32", + "shape": [ + 32 + ] + }, + "model.encoder.norm.weight": { + "dtype": "torch.float32", + "shape": [ + 32 + ] + }, + "model.input_emb.weight": { + "dtype": "torch.float32", + "shape": [ + 60, + 32 + ] + }, + "model.pos_encoder.pe": { + "dtype": "torch.float32", + "shape": [ + 5000, + 1, + 32 + ] + } + }, + "final_state_hash": "e197d3c2a3f351146bc265c5b3eb54dcd1d921499ce24d1cc61bdc5e6dce886d", + "initial_shapes": { + "model.decoder.bias": { + "dtype": "torch.float32", + "shape": [ + 60 + ] + }, + "model.decoder.weight": { + "dtype": "torch.float32", + "shape": [ + 60, + 32 + ] + }, + "model.encoder.layers.0.linear1.bias": { + "dtype": "torch.float32", + "shape": [ + 64 + ] + }, + "model.encoder.layers.0.linear1.weight": { + "dtype": "torch.float32", + "shape": [ + 64, + 32 + ] + }, + "model.encoder.layers.0.linear2.bias": { + "dtype": "torch.float32", + "shape": [ + 32 + ] + }, + "model.encoder.layers.0.linear2.weight": { + "dtype": "torch.float32", + "shape": [ + 32, + 64 + ] + }, + "model.encoder.layers.0.norm1.bias": { + "dtype": "torch.float32", + "shape": [ + 32 + ] + }, + "model.encoder.layers.0.norm1.weight": { + "dtype": "torch.float32", + "shape": [ + 32 + ] + }, + "model.encoder.layers.0.norm2.bias": { + "dtype": "torch.float32", + "shape": [ + 32 + ] + }, + "model.encoder.layers.0.norm2.weight": { + "dtype": "torch.float32", + "shape": [ + 32 + ] + }, + "model.encoder.layers.0.self_attn.in_proj_bias": { + "dtype": "torch.float32", + "shape": [ + 96 + ] + }, + "model.encoder.layers.0.self_attn.in_proj_weight": { + "dtype": "torch.float32", + "shape": [ + 96, + 32 + ] + }, + "model.encoder.layers.0.self_attn.out_proj.bias": { + "dtype": "torch.float32", + "shape": [ + 32 + ] + }, + "model.encoder.layers.0.self_attn.out_proj.weight": { + "dtype": "torch.float32", + "shape": [ + 32, + 32 + ] + }, + "model.encoder.layers.1.linear1.bias": { + "dtype": "torch.float32", + "shape": [ + 64 + ] + }, + "model.encoder.layers.1.linear1.weight": { + "dtype": "torch.float32", + "shape": [ + 64, + 32 + ] + }, + "model.encoder.layers.1.linear2.bias": { + "dtype": "torch.float32", + "shape": [ + 32 + ] + }, + "model.encoder.layers.1.linear2.weight": { + "dtype": "torch.float32", + "shape": [ + 32, + 64 + ] + }, + "model.encoder.layers.1.norm1.bias": { + "dtype": "torch.float32", + "shape": [ + 32 + ] + }, + "model.encoder.layers.1.norm1.weight": { + "dtype": "torch.float32", + "shape": [ + 32 + ] + }, + "model.encoder.layers.1.norm2.bias": { + "dtype": "torch.float32", + "shape": [ + 32 + ] + }, + "model.encoder.layers.1.norm2.weight": { + "dtype": "torch.float32", + "shape": [ + 32 + ] + }, + "model.encoder.layers.1.self_attn.in_proj_bias": { + "dtype": "torch.float32", + "shape": [ + 96 + ] + }, + "model.encoder.layers.1.self_attn.in_proj_weight": { + "dtype": "torch.float32", + "shape": [ + 96, + 32 + ] + }, + "model.encoder.layers.1.self_attn.out_proj.bias": { + "dtype": "torch.float32", + "shape": [ + 32 + ] + }, + "model.encoder.layers.1.self_attn.out_proj.weight": { + "dtype": "torch.float32", + "shape": [ + 32, + 32 + ] + }, + "model.encoder.norm.bias": { + "dtype": "torch.float32", + "shape": [ + 32 + ] + }, + "model.encoder.norm.weight": { + "dtype": "torch.float32", + "shape": [ + 32 + ] + }, + "model.input_emb.weight": { + "dtype": "torch.float32", + "shape": [ + 60, + 32 + ] + }, + "model.pos_encoder.pe": { + "dtype": "torch.float32", + "shape": [ + 5000, + 1, + 32 + ] + } + }, + "initial_state_hash": "e197d3c2a3f351146bc265c5b3eb54dcd1d921499ce24d1cc61bdc5e6dce886d", + "setup_seconds": 2.199223518371582, + "steps": [], + "success": false, + "training_seconds": 0 + }, + "mode": "var", + "peak_RSS_bytes": 519995392, + "process_seconds": 4.208818104118109, + "profiled": false, + "repetition": 1, + "stop_reason": null, + "trace_status": "Not parsed: process failed or was stopped; partial files retained", + "workload": "transformer" + }, + "cause": "Existing subclass_setattr_hook sends a plain Tensor (src_mask) into proxy_parameter, which assumes nn.Module.named_parameters; AttributeError", + "overhead_status": "Not measured for VAR/combined; stopped matrix at failure without changing production behavior" + }, + "artifact": { + "archive": "evidence.tar.gz", + "bytes": 12483879, + "sha256": "d9dad870e9b26d2b076d09d6f56f6037cdb4948d4af0e58f26e7aa2105f594ff", + "remote": "/home/yuxuan/experiments/codex-tracing-components-20261026-v020" + }, + "limitations": [ + "Only three repeats and three cold steps, shared host without affinity or exclusive reservation", + "VAR-only timing variation is material; tiny interaction estimate is not statistically resolved", + "Subclass mode only, not general Proxy or VarSampler mode", + "Plain mode imports TrainCheck's global Module setattr hook but has no API wrappers or model proxies", + "Background writer/drain and setup are outside the training time denominator", + "Transformer model tracing failed; successful MNIST numbers do not establish Transformer compatibility" + ] +} diff --git a/docs/measurements/tensor-hash-backends-20261026.md b/docs/measurements/tensor-hash-backends-20261026.md new file mode 100644 index 00000000..f2aae827 --- /dev/null +++ b/docs/measurements/tensor-hash-backends-20261026.md @@ -0,0 +1,104 @@ +# Released CPU/CUDA tensor-hash audit + +This is a bounded audit of unchanged TrainCheck v0.2.0 source, not a production +change or an end-to-end training benchmark. The source commit is +`9ba90ac84a1b4efd7e9f65b48b36bbbebf958253`; the retained hash source has SHA-256 +`e917bec817df1981c682d8b8645307432c6badb220b9f7c424b4089d9bf97bd7`. + +The CUDA dumper flag was changed from true to false by Daniel in commit +`fec69179f6fbfd906789ffa6278c61a627229179` (2026-06-08), whose message is only +`temp fixes`. The same commit adds `to_local()` handling. The commit does not +document why the CUDA backend was disabled; the failures below do not establish +the original motivation. + +## Correctness findings + +- Of 17 shape/dtype cases, 15 succeed with identical CPU/CUDA hash values and + unchanged inputs. Tested cases include floating/integer dtypes, rank-three + tensors, noncontiguous transpose/strided inputs, and empty vectors/columns. +- Scalar float32 is accepted by CPU hashing but CUDA hashing raises `ValueError: + not enough values to unpack (expected 2, got 0)`. A blanket flag flip changes + an accepted input into a failure. +- Empty shape `(0, 3)` already fails with CPU `IndexError`; CUDA produces a + different launch error. Empty-input semantics are an existing limitation, + not evidence of a successful CUDA fallback. +- Six deliberately delayed nondefault-stream cases return incorrect CUDA hash + values. The producer write and hash call both execute inside the same + `with torch.cuda.stream(producer)` context. CUDA returns the old zero-tensor + hash while CPU hashing on that same current stream returns the expected hash. + Adding `producer.synchronize()` before the CUDA hash also produces the correct + result. The explicit control matrix has CUDA-current-stream 0/6 correct, + CUDA-after-sync 6/6 correct, and CPU-current-stream 6/6 correct. Both int64 and + float32 are covered; no consumer-outside-producer-stream misuse is involved. +- Both implementations return only the first row's accumulator. Changing a + nonfirst row does not change either result; changing the first row does. This + is a separate, pre-existing hash semantics limitation shared by both paths. + Backend parity is not proof that the hash detects arbitrary tensor mutation. + +## Timing results + +All inputs below already reside on CUDA. Timings include the entire `tensor_hash` +call (float-to-int conversion, CPU transfer/hash or CUDA launch/result transfer) +and CUDA synchronization. They exclude tracer metadata, training computation, +imports and CUDA/Numba initialization. Two warmups/backend precede seven timed +calls/backend in alternating CPU/CUDA then CUDA/CPU order. These are medians from +one warmed process on a shared host; no confidence interval or end-to-end speedup +is claimed. The explicit synchronization controls are not included in these +default-stream timing cases. + +| Float32 input shape | CPU backend | CUDA backend | CPU / CUDA | +|---|---:|---:|---:| +| 16 | 49.53 us | 125.19 us | 0.40x | +| 64 x 64 | 106.31 us | 119.87 us | 0.89x | +| 1024 x 1024 | 11.969 ms | 0.304 ms | 39.40x | +| 1024 | 1.050 ms | 0.202 ms | 5.20x | +| 4096 | 4.062 ms | 0.411 ms | 9.88x | +| 256 x 256 | 0.469 ms | 0.153 ms | 3.06x | +| 4096 x 16 | 0.212 ms | 0.135 ms | 1.57x | +| 1 x 1024 | 1.038 ms | 0.187 ms | 5.56x | +| 1024 x 1 | 33.99 us | 125.18 us | 0.27x | + +The last two shapes contain the same number of elements but have different +preferred backends. Input element count alone is insufficient to choose a +threshold. A guarded CUDA path may be useful after stream/shape contracts are +fixed and workload-specific hash-size distributions are measured. Do not enable +CUDA globally on the basis of the large-matrix result. + +The [compact evidence](data/tensor-hash-backends-20261026.json) retains all +shape outcomes, timing samples, stream controls, and artifact identities. + +## Environment and evidence + +labmach: RTX A2000 12GB, driver 545.23.08, Python 3.10.16, PyTorch 2.2.2+cu121, +Numba 0.61.2. One native CPU thread; GPU was inspected idle before the audit and the additional +timing batch. +`environment.txt` records exact versions and post-run GPU status. The isolated +remote directory is `/home/yuxuan/experiments/codex-hash-backend-audit-20261026-v020`. +No shared environment or production source changed. Local evidence is retained +at `/Users/matt/gitrepos/traincheck/outputs/tracing-components-20261026/hash/`. + +`hash-results.json`, `more-shapes-results.json`, and `stream-controls-results.json` +retain exact outcomes and all timing samples. The initial stream stress is in +`stream-results.json`. `verified-artifacts.json` verifies all 13 downloaded +scripts/result/log files against remote hashes. All four audit harnesses passed +strict mypy (`--check-untyped-defs --disallow-untyped-defs +--disallow-any-generics --follow-imports=skip`), Black and isort checks. The +released legacy hash module was not rewritten or type-checked as new code. + +To reproduce in a new directory, retain the same released `hash_source.py` and +four audit scripts. Run with the existing environment and these settings: + +```sh +OMP_NUM_THREADS=1 MKL_NUM_THREADS=1 OPENBLAS_NUM_THREADS=1 PYTHONDONTWRITEBYTECODE=1 \ + /home/yuxuan/miniconda3/envs/traincheck/bin/python audit_hash.py \ + --source hash_source.py --output hash-results.json +``` + +Use the same environment variables for `audit_hash_streams.py`, +`audit_hash_stream_controls.py`, and `audit_hash_more_shapes.py`. Each script +refuses to overwrite prior results. The controller bounded the original runs at +90, 30, 30 and 60 seconds, respectively; all Python runs completed. The first +launch's shell wrapper attempted to assign zsh's read-only `status` variable +after Python completed; the complete saved JSON/log and subsequent checks +confirm the Python audit itself succeeded. Later wrappers use a dedicated exit +code variable. diff --git a/docs/measurements/tracer-components-20261026.md b/docs/measurements/tracer-components-20261026.md new file mode 100644 index 00000000..4bf3d5a0 --- /dev/null +++ b/docs/measurements/tracer-components-20261026.md @@ -0,0 +1,161 @@ +# API and model-tracer overhead: bounded CPU measurements + +The previous tracing audit had **API tracing only**. This follow-up activates the +`subclass` model tracer and default tensor-hash dumping, and separates four real +configurations. It changes no production code. MNIST completes with exact training +state/loss parity; Transformer model tracing exposes a pre-existing failure, so no +Transformer model-tracing overhead is reported. + +## Ordinary training timings + +Each fresh process trains the exact benchmark MNIST `Net` (1,199,882 parameters) +for three CPU steps on the first six cached MNIST images, batch 2, fp32, Adadelta, +initialization/training seeds 42/43, and one native thread. Three repeats use orders +plain/API/VAR/both, both/VAR/API/plain, and VAR/plain/both/API. These are cold +three-step diagnostics, not steady-state or large-scale training estimates. + +| Mode | Run 1 | Run 2 | Run 3 | Median | +|---|---:|---:|---:|---:| +| Plain | 29.668 ms | 29.061 ms | 31.311 ms | 29.668 ms | +| API only | 343.709 ms | 338.689 ms | 335.543 ms | 338.689 ms | +| Model/VAR only, hash enabled | 372.319 ms | 414.599 ms | 474.165 ms | 414.599 ms | +| API + model/VAR, hash enabled | 707.320 ms | 727.127 ms | 752.502 ms | 727.127 ms | + +The timer includes the training body, `start_step`, and wrapper-disable assignment. +It excludes imports, instrumentation/model setup, loss extraction, full model-state +verification, and final background-writer drain. The plain process imports +TrainCheck, including its global Module `__setattr__` hook, but installs neither +API wrappers nor proxied parameters; this shared import is a stated baseline limit. + +Subtracting medians gives **697.459 ms added time** with both tracers. The ablation +accounting is: + +| Term | Added time | Share of 697.459 ms added time | +|---|---:|---:| +| API only minus plain | 309.021 ms | 44.31% | +| VAR only minus plain | 384.932 ms | 55.19% | +| Interaction: both - API - VAR + plain | 3.506 ms | 0.50% | + +The marginal cost of adding model tracking to API tracing is **388.438 ms**. +These are differences between measured configuration medians, **not an exclusive +physical stage timer**. The interaction includes shared work, configuration +differences, and timing noise. The VAR-only range is material; three repeats do +not resolve a 3.5 ms interaction reliably, and interaction may be negative in +another matched run. Percentages above use added time, not total 727.127 ms. + +Sampled peak main-process RSS, including imports/setup rather than isolated +trace-buffer memory: plain: 442.8–464.9 MiB; api: 536.1–549.1 MiB; var: 548.5–552.2 MiB; combined: 563.6–563.8 MiB. + +## What actually activated + +Model parameters are converted to `ProxyParameter` **before optimizer creation**. +The normal static observer lookup tables are installed at depth 3, with hidden +functions/modules excluded and `observe_then_unproxy=False`. Every VAR-enabled +run registers all eight model parameters and emits **64 VAR records**, each with +a tensor-data hash; 48 also contain a gradient hash. All eight parameters have +pre/post-Adadelta observations with changed data hashes, so this is active model +tracing rather than configuration-only registration. There are **112 tensor hash +fields** over three steps, representing 67,193,392 logical input bytes (64.081 MiB). +That is logical tensor size, not allocated memory or transfer volume. +The large `fc1.weight` tensor (128 x 9,216) accounts for 66,060,288 bytes, or +98.31% of that logical volume. This identifies a concrete hash workload; it does +not mean that tensor accounts for 98.31% of hash time. The CPU implementation's +column loop also makes the last dimension relevant, not only the total bytes. + +API-enabled runs emit **520 API records** (260 complete pre/post pairs). Plain and +VAR-only emit no API records; plain and API-only emit no VAR records. Counts and +complete raw call pairs are independently checked after downloading the traces. + +These numbers apply to `subclass` mode. The CLI defaults to `proxy`, whose +`json_dumper` writes synchronously; that distinct mode has not been measured here. +The subclass mode uses the buffered VAR writer. + +The modes are real activation ablations, not identical wrapper topology: + +- VAR modes install static observers and enable `scan_proxy_in_args`; API-only + omits them, matching normal collection configuration. +- VAR-only passes `funcs_to_instr=[]` to `Instrumentor`, retaining production + no-dump wrappers that take a faster path than API record construction. +- The original model dump and observer paths remain untouched; no new suppression, + sampling, field omission, or hash-backend change is applied for this measurement. + +## Separate combined profile + +A separate three-step combined cProfile run totals **1.495160 s**, versus the +ordinary combined median 0.727127 s. It preserves the complete loss trajectory and +initial/final model state. These cumulative rows overlap and must not be added; +their percentages are of **profiled main-thread time**, not ordinary added time. + +| Entry point | Calls | Cumulative time | Share of profile | +|---|---:|---:|---:| +| API argument conversion | 260 | 590.920 ms | 39.52% | +| API return conversion | 260 | 285.949 ms | 19.12% | +| `ProxyParameter.dump_trace` | 64 | 568.882 ms | 38.05% | +| `tensor_hash` (nested inside variable snapshots) | 112 | 362.960 ms | 24.28% | +| `hash_tensor_cpu` (nested inside `tensor_hash`) | 112 | 321.312 ms | 21.49% | +| Final record JSON `serialize`, API + VAR | 584 | 4.557 ms | 0.305% | + +The caller graph identifies all 112 hash calls beneath `dump_tensor`. The variable +entry has 48 observer-triggered calls plus 16 attribute-update-triggered calls. +Hashing is a substantial part of the now-active variable path. API argument/return +conversion together accounts for 58.65% cumulative profiled time, but this sum and +the variable entry are presented as diagnostic entry points; the aggregated +profile is not used to claim a disjoint semantic stage partition. + +## Transformer failure instead of an overhead number + +Plain and API-only Transformer runs complete. The first VAR-only run fails before +finishing its first step when `TransformerModel.forward` assigns `self.src_mask = +mask`. The model tracer's `subclass_setattr_hook` accepts either a Tensor or Module +and forwards the value to `proxy_parameter`; that helper assumes an `nn.Module` +and calls `named_parameters` on the plain Tensor: + +```text +subclass.py:286 wrapped_setattr -> subclass_setattr_hook +subclass.py:263 subclass_setattr_hook -> proxy_parameter(value, ...) +subclass.py:231 proxy_parameter -> module.named_parameters(recurse=False) +AttributeError: 'Tensor' object has no attribute 'named_parameters' +``` + +The matrix stops at this failure; it does not silently change tracker style, omit +the mask assignment, or claim a successful Transformer VAR/combined measurement. +The failed case retains its log, manifest, partial state and explicit error. + +The [compact evidence](data/tracer-components-20261026.json) retains all +per-run timings, activation checks, profile rows, and the explicit failed case. + +## Provenance and validation + +- Frozen source: release commit `9ba90ac84a1b4efd7e9f65b48b36bbbebf958253`, tree + `6fbebbeae8f1c4327d39452361325b9c716a4068` (`v0.2.0`). All 77 production + Python files byte-match the release archive. Only the isolated workload adapter + receives a typed model-registration callback immediately after construction. +- Host/runtime: labmach, Intel Core i9-13900K, Python 3.11.4, PyTorch + `2.16.0.dev20261012+cpu`, one native thread, no CPU affinity/exclusive reservation. +- All 12 ordinary MNIST cases and the separate profile have exactly matching full + loss trajectories, canonical initial/final model hashes, names, dtypes and + shapes. Raw trace digests/counts/pre-post multiplicity and active hash fields + were rechecked locally. No IDs or trace contents were normalized to claim raw + trace equality across processes. +- Each case is capped at 90 s, 4 GiB main-process RSS and 256 MiB raw trace. No + successful MNIST case hits a cap. No GPU experiment runs in this matrix. +- `component_runner.py`, `run_matrix.py`, and `analyze_components.py` pass mypy + with `--check-untyped-defs --disallow-untyped-defs --disallow-any-generics` + (`--follow-imports=skip --ignore-missing-imports` limits dependency coverage). +- Retained data: `component-summary.json` / `evidence.json`; exact scripts, + commands, manifests, profiles and raw traces under local + `outputs/tracing-components-20261026/components/` and remote + `/home/yuxuan/experiments/codex-tracing-components-20261026-v020`. +- Archive `evidence.tar.gz`: 12,483,879 bytes; SHA-256 + `d9dad870e9b26d2b076d09d6f56f6037cdb4948d4af0e58f26e7aa2105f594ff`. + +Recompute the validated summary locally with: + +```sh +python analyze_components.py --root /path/to/retained/components +``` + +The matrix commands and changed adapter are retained for exact reproduction. +Existing run directories are never overwritten. A new run should use a fresh +experiment root. The Transformer failure should be reproduced/fixed separately +before extending its overhead claims. diff --git a/docs/measurements/tracing-hotspot-audit-20261026.md b/docs/measurements/tracing-hotspot-audit-20261026.md index cbc72065..44115846 100644 --- a/docs/measurements/tracing-hotspot-audit-20261026.md +++ b/docs/measurements/tracing-hotspot-audit-20261026.md @@ -144,6 +144,16 @@ checks described below. ## Hashing is an unmeasured path in this audit +A subsequent [four-mode API/model tracing study](tracer-components-20261026.md) +activates subclass model tracking and tensor hashing. It measures the added +model-tracing cost on MNIST and preserves a Transformer compatibility failure. +Those results are distinct from this initial API-only audit. + +A subsequent [CPU/CUDA hash-backend study](tensor-hash-backends-20261026.md) +measures the hash function directly and finds shape/stream correctness blockers +to blanket CUDA enablement. It does not assign hashing a share of this earlier +metadata-only training profile. + Both profiles contain no calls to `dump_tensor`, `tensor_hash`, or `tensor_stats`. API metadata conversion passes `include_tensor_data=False`, and model/proxy tracking is disabled. The harness's initial/final model SHA-256 checks run outside From b8e74752c163d03442a556b5588036e8db15a72b Mon Sep 17 00:00:00 2001 From: Yuxuan Jiang Date: Mon, 26 Oct 2026 21:46:53 +0800 Subject: [PATCH 5/5] Measure CUDA hashing for the dominant traced MNIST weight --- .../data/tensor-hash-backends-20261026.json | 60 ++++++++++++++++++- .../tensor-hash-backends-20261026.md | 12 ++++ 2 files changed, 71 insertions(+), 1 deletion(-) diff --git a/docs/measurements/data/tensor-hash-backends-20261026.json b/docs/measurements/data/tensor-hash-backends-20261026.json index 01d20da1..4d627029 100644 --- a/docs/measurements/data/tensor-hash-backends-20261026.json +++ b/docs/measurements/data/tensor-hash-backends-20261026.json @@ -1150,5 +1150,63 @@ "No production backend default or algorithm changed.", "Scalar/empty errors and stream observations must be handled before enabling CUDA generally.", "First-row-only behavior is shared existing hash semantics, separate from backend parity." - ] + ], + "mnist_dominant_shape_followup": { + "timings": [ + { + "shape": [ + 128, + 9216 + ], + "dtype": "torch.float32", + "input_bytes": 4718592, + "samples_seconds": { + "cpu": [ + 0.01494477316737175, + 0.014594506472349167, + 0.01264377310872078, + 0.012647747993469238, + 0.014576397836208344, + 0.01462256908416748, + 0.01264270395040512 + ], + "cuda": [ + 0.0015219561755657196, + 0.0014661811292171478, + 0.0015172585844993591, + 0.0014633052051067352, + 0.0015113502740859985, + 0.001466561108827591, + 0.001525983214378357 + ] + }, + "median_seconds": { + "cpu": 0.014576397836208344, + "cuda": 0.0015113502740859985 + }, + "hash_backends_equal": true + } + ], + "warmups_per_backend": 2, + "repeats_per_backend": 7, + "order": "CPU/CUDA alternating then CUDA/CPU alternating", + "scope": "Complete tensor_hash plus CUDA synchronization, CUDA float32 input, no tracer or metadata operations", + "artifacts": [ + { + "filename": "audit_hash_mnist_fc1.py", + "sha256": "093827aa0bccfda1bf30778c70ce65fdf799b071af72d591792e8e491ba1ebe0" + }, + { + "filename": "mnist-fc1-results.json", + "sha256": "6db80ff91e7a4eca77f4da72894e2de8b9b0df7c87e366c6def516ccfe3c6470" + }, + { + "filename": "mnist-fc1.log", + "sha256": "d9bc00296b30e66e50ab01bd8f8817db7c50b2762661d8f1a62ef3937cb65056" + } + ], + "runtime_same_as_original_hash_audit": true, + "stream": "default", + "limits": "Exact shape of dominant logical hash volume in the CPU model-tracer study, moved to CUDA for this isolated backend comparison; not a combined-training speedup and no stream-safety repair included." + } } diff --git a/docs/measurements/tensor-hash-backends-20261026.md b/docs/measurements/tensor-hash-backends-20261026.md index f2aae827..e5903b15 100644 --- a/docs/measurements/tensor-hash-backends-20261026.md +++ b/docs/measurements/tensor-hash-backends-20261026.md @@ -67,6 +67,18 @@ CUDA globally on the basis of the large-matrix result. The [compact evidence](data/tensor-hash-backends-20261026.json) retains all shape outcomes, timing samples, stream controls, and artifact identities. +## Follow-up on the measured MNIST weight shape + +The [API/model-tracer study](tracer-components-20261026.md) identifies `fc1.weight`, +shape `(128, 9216)`, as 98.31% of logical hashed input bytes. A separate matched +microbenchmark of that exact shape, with input already on CUDA, measures +**14.576 ms CPU hashing versus 1.511 ms CUDA hashing (9.64x)** with identical hash +values. The same two warmups and seven alternating timed calls/backend are used; +all raw samples and three verified follow-up artifact hashes are in the compact +evidence. This confirms a relevant optimization opportunity after the scalar and +stream contracts are fixed. It is not a measured speedup for CPU training, model +tracing, or the complete training run. The future stream repair is not timed. + ## Environment and evidence labmach: RTX A2000 12GB, driver 545.23.08, Python 3.10.16, PyTorch 2.2.2+cu121,