From 5a7cd0cb2693818a0e5056f338e6b287c18e5a65 Mon Sep 17 00:00:00 2001 From: James Wu Date: Wed, 3 Apr 2024 15:13:45 -0400 Subject: [PATCH] Add compilation metrics parsing --- Cargo.lock | 164 ++++++++++++++++++++++++++++++++++ Cargo.toml | 1 + src/lib.rs | 2 + src/parsers.rs | 29 ++++++ src/templates.rs | 59 ++++++++++++ src/types.rs | 28 ++++++ tests/inputs/comp_metrics.log | 65 ++++++++++++++ tests/integration_test.rs | 31 +++++++ 8 files changed, 379 insertions(+) create mode 100644 tests/inputs/comp_metrics.log diff --git a/Cargo.lock b/Cargo.lock index a49392f..45b3c26 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -11,6 +11,21 @@ dependencies = [ "memchr", ] +[[package]] +name = "android-tzdata" +version = "0.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e999941b234f3131b00bc13c22d06e8c5ff726d1b6318ac7eb276997bbb4fef0" + +[[package]] +name = "android_system_properties" +version = "0.1.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "819e7219dbd41043ac279b19830f2efc897156490d7fd6ea916720117ee66311" +dependencies = [ + "libc", +] + [[package]] name = "anstream" version = "0.6.13" @@ -65,6 +80,12 @@ version = "1.0.81" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "0952808a6c2afd1aa8947271f3a60f1a6763c7b912d210184c5149b5cf147247" +[[package]] +name = "autocfg" +version = "1.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f1fdabc7756949593fe60f30ec81974b613357de856987752631dea1e3394c80" + [[package]] name = "base16ct" version = "0.2.0" @@ -91,18 +112,44 @@ dependencies = [ "serde", ] +[[package]] +name = "bumpalo" +version = "3.15.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7ff69b9dd49fd426c69a0db9fc04dd934cdb6645ff000864d98f7e2af8830eaa" + [[package]] name = "byteorder" version = "1.5.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "1fd0f2584146f6f2ef48085050886acf353beff7305ebd1ae69500e27c67f64b" +[[package]] +name = "cc" +version = "1.0.90" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8cd6604a82acf3039f1144f54b8eb34e91ffba622051189e71b781822d5ee1f5" + [[package]] name = "cfg-if" version = "1.0.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "baf1de4339761588bc0619e3cbc0120ee582ebb74b53b4efbf79117bd2da40fd" +[[package]] +name = "chrono" +version = "0.4.37" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8a0d04d43504c61aa6c7531f1871dd0d418d91130162063b789da00fd7057a5e" +dependencies = [ + "android-tzdata", + "iana-time-zone", + "js-sys", + "num-traits", + "wasm-bindgen", + "windows-targets", +] + [[package]] name = "clap" version = "4.5.4" @@ -162,6 +209,12 @@ dependencies = [ "windows-sys", ] +[[package]] +name = "core-foundation-sys" +version = "0.8.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "06ea2b9bc92be3c2baa9334a323ebca2d6f074ff852cd1d7b11064035cd3868f" + [[package]] name = "crypto-common" version = "0.1.6" @@ -234,6 +287,29 @@ dependencies = [ "utf8-width", ] +[[package]] +name = "iana-time-zone" +version = "0.1.60" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e7ffbb5a1b541ea2561f8c41c087286cc091e21e556a4f09a8f6cbf17b69b141" +dependencies = [ + "android_system_properties", + "core-foundation-sys", + "iana-time-zone-haiku", + "js-sys", + "wasm-bindgen", + "windows-core", +] + +[[package]] +name = "iana-time-zone-haiku" +version = "0.1.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f31827a206f56af32e590ba56d5d2d085f558508192593743f16b2306495269f" +dependencies = [ + "cc", +] + [[package]] name = "indexmap" version = "2.2.6" @@ -272,6 +348,15 @@ version = "1.0.11" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "49f1f14873335454500d59611f1cf4a4b0f786f9ac11f4312a78e4cf2566695b" +[[package]] +name = "js-sys" +version = "0.3.69" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "29c15563dc2726973df627357ce0c9ddddbea194836909d655df6a75d2cf296d" +dependencies = [ + "wasm-bindgen", +] + [[package]] name = "lazy_static" version = "1.4.0" @@ -284,6 +369,12 @@ version = "0.2.153" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "9c198f91728a82281a64e1f4f9eeb25d82cb32a5de251c6bd1b5154d63a8e7bd" +[[package]] +name = "log" +version = "0.4.21" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "90ed8c1e510134f979dbc4f070f87d4313098b704861a105fe34231c70a3901c" + [[package]] name = "md-5" version = "0.10.6" @@ -309,6 +400,15 @@ dependencies = [ "windows-sys", ] +[[package]] +name = "num-traits" +version = "0.2.18" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "da0df0e5185db44f69b44f26786fe401b6c293d1907744beaa7fa62b2e5a517a" +dependencies = [ + "autocfg", +] + [[package]] name = "number_prefix" version = "0.4.0" @@ -455,6 +555,7 @@ version = "0.3.12" dependencies = [ "anyhow", "base16ct", + "chrono", "clap", "fxhash", "html-escape", @@ -505,6 +606,60 @@ version = "0.9.4" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "49874b5167b65d7193b8aba1567f5c7d93d001cafc34600cee003eda787e483f" +[[package]] +name = "wasm-bindgen" +version = "0.2.92" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "4be2531df63900aeb2bca0daaaddec08491ee64ceecbee5076636a3b026795a8" +dependencies = [ + "cfg-if", + "wasm-bindgen-macro", +] + +[[package]] +name = "wasm-bindgen-backend" +version = "0.2.92" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "614d787b966d3989fa7bb98a654e369c762374fd3213d212cfc0251257e747da" +dependencies = [ + "bumpalo", + "log", + "once_cell", + "proc-macro2", + "quote", + "syn", + "wasm-bindgen-shared", +] + +[[package]] +name = "wasm-bindgen-macro" +version = "0.2.92" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a1f8823de937b71b9460c0c34e25f3da88250760bec0ebac694b49997550d726" +dependencies = [ + "quote", + "wasm-bindgen-macro-support", +] + +[[package]] +name = "wasm-bindgen-macro-support" +version = "0.2.92" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e94f17b526d0a461a191c78ea52bbce64071ed5c04c9ffe424dcb38f74171bb7" +dependencies = [ + "proc-macro2", + "quote", + "syn", + "wasm-bindgen-backend", + "wasm-bindgen-shared", +] + +[[package]] +name = "wasm-bindgen-shared" +version = "0.2.92" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "af190c94f2773fdb3729c55b007a722abb5384da03bc0986df4c289bf5567e96" + [[package]] name = "winapi" version = "0.3.9" @@ -527,6 +682,15 @@ version = "0.4.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "712e227841d057c1ee1cd2fb22fa7e5a5461ae8e48fa2ca79ec42cfc1931183f" +[[package]] +name = "windows-core" +version = "0.52.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "33ab640c8d7e35bf8ba19b884ba838ceb4fba93a4e8c65a9059d08afcfc683d9" +dependencies = [ + "windows-targets", +] + [[package]] name = "windows-sys" version = "0.52.0" diff --git a/Cargo.toml b/Cargo.toml index 98f56a2..cbff941 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -18,6 +18,7 @@ path = "src/cli.rs" [dependencies] anyhow = "1.0.75" base16ct = "0.2.0" +chrono = "0.4" clap = { version = "4.5.2", features = ["derive"] } fxhash = "0.2.1" html-escape = "0.2.5" diff --git a/src/lib.rs b/src/lib.rs index 75ca48f..030c5ba 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -71,6 +71,8 @@ pub fn parse_path(path: &PathBuf, config: ParseConfig) -> anyhow::Result { + tt: &'t TinyTemplate<'t>, +} +impl StructuredLogParser for CompilationMetricsParser<'_> { + fn name(&self) -> &'static str { + "compilation_metrics" + } + fn get_metadata<'e>(&self, e: &'e Envelope) -> Option> { + e.compilation_metrics.as_ref().map(|m| Metadata::CompilationMetrics(m)) + } + fn parse<'e>(&self, + lineno: usize, + metrics: Metadata<'e>, + _rank: Option, + compile_id: &Option, + _payload: &str + ) -> anyhow::Result { + let filename = format!("{}.html", self.name()); + if let Metadata::CompilationMetrics(m) = metrics { + let output = self.tt.render(&filename, &m)?; + simple_file_output(&filename, lineno, compile_id, &output) + } else { + Err(anyhow::anyhow!("Expected CompilationMetrics metadata")) + } + + } +} + // Register your parser here pub fn default_parsers<'t>(tt: &'t TinyTemplate<'t>) -> Vec> { // We need to use Box wrappers here because vecs in Rust need to have known size @@ -202,6 +230,7 @@ pub fn default_parsers<'t>(tt: &'t TinyTemplate<'t>) -> Vec "#; + +pub static TEMPLATE_COMPILATION_METRICS : &str = r#" + + + Compilation Metrics + + +

Compilation Info

+

Dynamo Output:

+ + dynamo_output_graph.txt + +

Compile Time(seconds)

+

Entire Frame [?]: {entire_frame_compile_time_s} +

Backend [?]: {backend_compile_time_s} + {{ if inductor_compile_time_s }} +

Inductor [?]: {inductor_compile_time_s} + {{ endif }} + {{ if code_gen_time_s }} +

Code Gen Time: {code_gen_time_s}

+ {{ endif}} +
Dynamo Time Before Restart [?]: {dynamo_time_before_restart_s}
+

Restarts and Failures

+ {{ if fail_type }} +

Failure Exception: {fail_type}

+

Failure Reason: {fail_reason}

+

In file {fail_user_frame_filename}, line {fail_user_frame_lineno}

+ {{ else }} +

No failures!

+ {{ endif }} + {{ if restart_reasons }} +

Restart Reasons:

+ {{ for restart_reason in restart_reasons }} +

  • {restart_reason }
    • + {{ endfor }} + {{ else }} +

    No restarts!

    + {{ endif }} +

    Cache Metrics

    +

    Cache Size: {cache_size}

    +

    Accumulated Cache Size: {accumulated_cache_size}

    +

    Graph Metrics

    +

    Guard Count: {guard_count}

    +

    Shape Env Guards: {shape_env_guard_count}

    +

    Graph Ops: {graph_op_count}

    +

    Graph Nodes: {graph_node_count}

    +

    Graph Inputs: {graph_input_count}

    +

    Custom Ops

    +

    Compliant Custom Ops:

    + {{ for op in compliant_custom_ops }} +
  • {op}
    • + {{ endfor }} +

    Non-Compliant Custom Ops:

    + {{ for op in non_compliant_ops }} +
  • {op}
    • + {{ endfor }} + + +"#; diff --git a/src/types.rs b/src/types.rs index 3536db0..b51de15 100644 --- a/src/types.rs +++ b/src/types.rs @@ -172,6 +172,31 @@ pub struct InductorOutputCodeMetadata { pub filename: Option, } +#[derive(Debug, Deserialize, Serialize)] +pub struct CompilationMetricsMetadata { + // Other information like frame_key, co_name, etc. are already in envelope + cache_size: Option, + accumulated_cache_size: Option, + guard_count: Option, + shape_env_guard_count: Option, + graph_op_count: Option, + graph_node_count: Option, + graph_input_count: Option, + start_time: Option, + entire_frame_compile_time_s: Option, + backend_compile_time_s: Option, + inductor_compile_time_s: Option, + code_gen_time_s: Option, + fail_type: Option, + fail_reason: Option, + fail_user_frame_filename: Option, + fail_user_frame_lineno: Option, + non_compliant_ops: Option>, + compliant_custom_ops: Option>, + restart_reasons: Option>, + dynamo_time_before_restart_s: Option, +} + #[derive(Debug)] pub enum Metadata<'e> { Empty(&'e EmptyMetadata), @@ -180,8 +205,10 @@ pub enum Metadata<'e> { DynamoStart(&'e DynamoStartMetadata), InductorOutputCode(&'e InductorOutputCodeMetadata), OptimizeDdpSplitChild(&'e OptimizeDdpSplitChildMetadata), + CompilationMetrics(&'e CompilationMetricsMetadata), } + #[derive(Debug, Deserialize)] pub struct Envelope { pub rank: Option, @@ -202,6 +229,7 @@ pub struct Envelope { pub aot_joint_graph: Option, pub inductor_post_grad_graph: Option, pub inductor_output_code: Option, + pub compilation_metrics: Option, } #[derive(Debug, Deserialize, Serialize)] diff --git a/tests/inputs/comp_metrics.log b/tests/inputs/comp_metrics.log new file mode 100644 index 0000000..0498e91 --- /dev/null +++ b/tests/inputs/comp_metrics.log @@ -0,0 +1,65 @@ +V0403 07:28:48.051000 139877824898048 torch/_logging/structured.py:19] {"str": ["/data/users/jjwu/a/pytorch/test/dynamo/test_misc.py", 0]} +V0403 07:28:48.052000 139877824898048 torch/_logging/structured.py:19] {"str": ["/data/users/jjwu/a/pytorch/torch/_dynamo/test_case.py", 1]} +V0403 07:28:48.052000 139877824898048 torch/_logging/structured.py:19] {"str": ["/data/users/jjwu/a/pytorch/torch/testing/_internal/common_utils.py", 2]} +V0403 07:28:48.052000 139877824898048 torch/_logging/structured.py:19] {"str": ["/data/users/jjwu/a/pytorch-env/lib/python3.10/unittest/main.py", 3]} +V0403 07:28:48.052000 139877824898048 torch/_logging/structured.py:19] {"str": ["/data/users/jjwu/a/pytorch-env/lib/python3.10/unittest/runner.py", 4]} +V0403 07:28:48.052000 139877824898048 torch/_logging/structured.py:19] {"str": ["/data/users/jjwu/a/pytorch-env/lib/python3.10/unittest/suite.py", 5]} +V0403 07:28:48.052000 139877824898048 torch/_logging/structured.py:19] {"str": ["/data/users/jjwu/a/pytorch-env/lib/python3.10/unittest/case.py", 6]} +V0403 07:28:48.052000 139877824898048 torch/_logging/structured.py:19] {"str": ["/data/users/jjwu/a/pytorch/torch/_dynamo/eval_frame.py", 7]} +V0403 07:28:48.052000 139877824898048 torch/_dynamo/convert_frame.py:672] {"dynamo_start": {"stack": [{"line": 10079, "name": "", "filename": 0}, {"line": 41, "name": "run_tests", "filename": 1}, {"line": 1167, "name": "run_tests", "filename": 2}, {"line": 101, "name": "__init__", "filename": 3}, {"line": 271, "name": "runTests", "filename": 3}, {"line": 184, "name": "run", "filename": 4}, {"line": 84, "name": "__call__", "filename": 5}, {"line": 122, "name": "run", "filename": 5}, {"line": 84, "name": "__call__", "filename": 5}, {"line": 122, "name": "run", "filename": 5}, {"line": 650, "name": "__call__", "filename": 6}, {"line": 2868, "name": "run", "filename": 2}, {"line": 2840, "name": "_run_custom", "filename": 2}, {"line": 591, "name": "run", "filename": 6}, {"line": 549, "name": "_callTestMethod", "filename": 6}, {"line": 2741, "name": "wrapper", "filename": 2}, {"line": 9559, "name": "test_graph_break_compilation_metrics", "filename": 0}, {"line": 410, "name": "_fn", "filename": 7}]}, "frame_id": 0, "frame_compile_id": 0, "attempt": 0} +V0403 07:28:48.061000 139877824898048 torch/_dynamo/output_graph.py:1139] {"dynamo_output_graph": {"sizes": {"l_x_": [4, 4], "cos": [4, 4]}}, "frame_id": 0, "frame_compile_id": 0, "attempt": 1, "has_payload": "b02b7e74ec144d0daf4087e58131a444"} + class GraphModule(torch.nn.Module): + def forward(self, L_x_ : torch.Tensor): + l_x_ = L_x_ + + # File: /data/users/jjwu/a/pytorch/test/dynamo/test_misc.py:9550 in fn, code: x.cos() + cos = l_x_.cos(); l_x_ = None + return () + +V0403 07:28:48.063000 139877824898048 torch/_logging/structured.py:19] {"str": ["/data/users/jjwu/a/pytorch/torch/_dynamo/convert_frame.py", 8]} +V0403 07:28:48.063000 139877824898048 torch/_logging/structured.py:19] {"str": ["/data/users/jjwu/a/pytorch-env/lib/python3.10/contextlib.py", 9]} +V0403 07:28:48.064000 139877824898048 torch/_logging/structured.py:19] {"str": ["/data/users/jjwu/a/pytorch/torch/_dynamo/utils.py", 10]} +V0403 07:28:48.064000 139877824898048 torch/_logging/structured.py:19] {"str": ["/data/users/jjwu/a/pytorch/torch/_dynamo/bytecode_transformation.py", 11]} +V0403 07:28:48.064000 139877824898048 torch/_logging/structured.py:19] {"str": ["/data/users/jjwu/a/pytorch/torch/_dynamo/symbolic_convert.py", 12]} +V0403 07:28:48.064000 139877824898048 torch/_logging/structured.py:19] {"str": ["/data/users/jjwu/a/pytorch/torch/_dynamo/output_graph.py", 13]} +V0403 07:28:48.064000 139877824898048 torch/_dynamo/guards.py:1894] {"dynamo_guards": {}, "frame_id": 0, "frame_compile_id": 0, "attempt": 1, "has_payload": "29e35548d59d0e446f0c8a3f3010cc72"} + [ + {"code": "hasattr(L['x'], '_dynamo_dynamic_indices') == False", "stack": null, "user_stack": null}, + {"code": "utils_device.CURRENT_DEVICE == None", "stack": [{"line": 10079, "name": "", "filename": 0}, {"line": 41, "name": "run_tests", "filename": 1}, {"line": 1167, "name": "run_tests", "filename": 2}, {"line": 101, "name": "__init__", "filename": 3}, {"line": 271, "name": "runTests", "filename": 3}, {"line": 184, "name": "run", "filename": 4}, {"line": 84, "name": "__call__", "filename": 5}, {"line": 122, "name": "run", "filename": 5}, {"line": 84, "name": "__call__", "filename": 5}, {"line": 122, "name": "run", "filename": 5}, {"line": 650, "name": "__call__", "filename": 6}, {"line": 2868, "name": "run", "filename": 2}, {"line": 2840, "name": "_run_custom", "filename": 2}, {"line": 591, "name": "run", "filename": 6}, {"line": 549, "name": "_callTestMethod", "filename": 6}, {"line": 2741, "name": "wrapper", "filename": 2}, {"line": 9559, "name": "test_graph_break_compilation_metrics", "filename": 0}, {"line": 410, "name": "_fn", "filename": 7}, {"line": 939, "name": "catch_errors", "filename": 8}, {"line": 802, "name": "_convert_frame", "filename": 8}, {"line": 400, "name": "_convert_frame_assert", "filename": 8}, {"line": 79, "name": "inner", "filename": 9}, {"line": 686, "name": "_compile", "filename": 8}, {"line": 265, "name": "time_wrapper", "filename": 10}, {"line": 541, "name": "compile_inner", "filename": 8}, {"line": 1078, "name": "transform_code_object", "filename": 11}, {"line": 165, "name": "_fn", "filename": 8}, {"line": 485, "name": "transform", "filename": 8}, {"line": 2102, "name": "__init__", "filename": 12}, {"line": 302, "name": "__init__", "filename": 13}, {"line": 425, "name": "init_ambient_guards", "filename": 13}], "user_stack": null}, + {"code": "check_tensor(L['x'], Tensor, DispatchKeySet(CPU, BackendSelect, ADInplaceOrView, AutogradCPU), torch.float32, device=None, requires_grad=False, size=[4, 4], stride=[4, 1])", "stack": null, "user_stack": null} + ] +V0403 07:28:48.065000 139877824898048 torch/_dynamo/utils.py:685] {"compilation_metrics": {"frame_key": "1", "co_name": "fn", "co_filename": "/data/users/jjwu/a/pytorch/test/dynamo/test_misc.py", "co_firstlineno": 9549, "cache_size": 0, "accumulated_cache_size": 0, "guard_count": 9, "shape_env_guard_count": 0, "graph_op_count": 1, "graph_node_count": 3, "graph_input_count": 1, "start_time": 1712154528.0523684, "entire_frame_compile_time_s": 0.012439489364624023, "backend_compile_time_s": 3.910064697265625e-05, "inductor_compile_time_s": null, "code_gen_time_s": null, "fail_type": null, "fail_reason": null, "fail_user_frame_filename": null, "fail_user_frame_lineno": null, "non_compliant_ops": [], "compliant_custom_ops": [], "restart_reasons": ["'skip function graph_break in file /data/users/jjwu/a/pytorch/torch/_dynamo/decorators.py'"], "dynamo_time_before_restart_s": 0.006658077239990234}, "frame_id": 0, "frame_compile_id": 0, "attempt": 1} +V0403 07:28:48.066000 139877824898048 torch/_dynamo/convert_frame.py:672] {"dynamo_start": {"stack": [{"line": 10079, "name": "", "filename": 0}, {"line": 41, "name": "run_tests", "filename": 1}, {"line": 1167, "name": "run_tests", "filename": 2}, {"line": 101, "name": "__init__", "filename": 3}, {"line": 271, "name": "runTests", "filename": 3}, {"line": 184, "name": "run", "filename": 4}, {"line": 84, "name": "__call__", "filename": 5}, {"line": 122, "name": "run", "filename": 5}, {"line": 84, "name": "__call__", "filename": 5}, {"line": 122, "name": "run", "filename": 5}, {"line": 650, "name": "__call__", "filename": 6}, {"line": 2868, "name": "run", "filename": 2}, {"line": 2840, "name": "_run_custom", "filename": 2}, {"line": 591, "name": "run", "filename": 6}, {"line": 549, "name": "_callTestMethod", "filename": 6}, {"line": 2741, "name": "wrapper", "filename": 2}, {"line": 9559, "name": "test_graph_break_compilation_metrics", "filename": 0}, {"line": 410, "name": "_fn", "filename": 7}, {"line": 9551, "name": "fn", "filename": 0}]}, "frame_id": 1, "frame_compile_id": 0, "attempt": 0} +V0403 07:28:48.071000 139877824898048 torch/_dynamo/output_graph.py:1139] {"dynamo_output_graph": {"sizes": {"l_x_": [4, 4], "sin": [4, 4]}}, "frame_id": 1, "frame_compile_id": 0, "attempt": 1, "has_payload": "2a35823c4e6ce78bcc3a8557f11f8a52"} + class GraphModule(torch.nn.Module): + def forward(self, L_x_ : torch.Tensor): + l_x_ = L_x_ + + # File: /data/users/jjwu/a/pytorch/test/dynamo/test_misc.py:9552 in torch_dynamo_resume_in_fn_at_9551, code: x.sin() + sin = l_x_.sin(); l_x_ = None + return () + +V0403 07:28:48.073000 139877824898048 torch/_dynamo/guards.py:1894] {"dynamo_guards": {}, "frame_id": 1, "frame_compile_id": 0, "attempt": 1, "has_payload": "e18e1bcb67140c0a67427a6119556f7a"} + [ + {"code": "hasattr(L['x'], '_dynamo_dynamic_indices') == False", "stack": null, "user_stack": null}, + {"code": "utils_device.CURRENT_DEVICE == None", "stack": [{"line": 10079, "name": "", "filename": 0}, {"line": 41, "name": "run_tests", "filename": 1}, {"line": 1167, "name": "run_tests", "filename": 2}, {"line": 101, "name": "__init__", "filename": 3}, {"line": 271, "name": "runTests", "filename": 3}, {"line": 184, "name": "run", "filename": 4}, {"line": 84, "name": "__call__", "filename": 5}, {"line": 122, "name": "run", "filename": 5}, {"line": 84, "name": "__call__", "filename": 5}, {"line": 122, "name": "run", "filename": 5}, {"line": 650, "name": "__call__", "filename": 6}, {"line": 2868, "name": "run", "filename": 2}, {"line": 2840, "name": "_run_custom", "filename": 2}, {"line": 591, "name": "run", "filename": 6}, {"line": 549, "name": "_callTestMethod", "filename": 6}, {"line": 2741, "name": "wrapper", "filename": 2}, {"line": 9559, "name": "test_graph_break_compilation_metrics", "filename": 0}, {"line": 410, "name": "_fn", "filename": 7}, {"line": 9551, "name": "fn", "filename": 0}, {"line": 939, "name": "catch_errors", "filename": 8}, {"line": 802, "name": "_convert_frame", "filename": 8}, {"line": 400, "name": "_convert_frame_assert", "filename": 8}, {"line": 79, "name": "inner", "filename": 9}, {"line": 686, "name": "_compile", "filename": 8}, {"line": 265, "name": "time_wrapper", "filename": 10}, {"line": 541, "name": "compile_inner", "filename": 8}, {"line": 1078, "name": "transform_code_object", "filename": 11}, {"line": 165, "name": "_fn", "filename": 8}, {"line": 485, "name": "transform", "filename": 8}, {"line": 2102, "name": "__init__", "filename": 12}, {"line": 302, "name": "__init__", "filename": 13}, {"line": 425, "name": "init_ambient_guards", "filename": 13}], "user_stack": null}, + {"code": "check_tensor(L['x'], Tensor, DispatchKeySet(CPU, BackendSelect, ADInplaceOrView, AutogradCPU), torch.float32, device=None, requires_grad=False, size=[4, 4], stride=[4, 1])", "stack": null, "user_stack": null} + ] +V0403 07:28:48.074000 139877824898048 torch/_dynamo/utils.py:685] {"compilation_metrics": {"frame_key": "2", "co_name": "torch_dynamo_resume_in_fn_at_9551", "co_filename": "/data/users/jjwu/a/pytorch/test/dynamo/test_misc.py", "co_firstlineno": 9551, "cache_size": 0, "accumulated_cache_size": 0, "guard_count": 9, "shape_env_guard_count": 0, "graph_op_count": 1, "graph_node_count": 3, "graph_input_count": 1, "start_time": 1712154528.0669525, "entire_frame_compile_time_s": 0.0071980953216552734, "backend_compile_time_s": 2.7894973754882812e-05, "inductor_compile_time_s": null, "code_gen_time_s": null, "fail_type": null, "fail_reason": null, "fail_user_frame_filename": null, "fail_user_frame_lineno": null, "non_compliant_ops": [], "compliant_custom_ops": [], "restart_reasons": ["'skip function graph_break in file /data/users/jjwu/a/pytorch/torch/_dynamo/decorators.py'"], "dynamo_time_before_restart_s": 0.002626180648803711}, "frame_id": 1, "frame_compile_id": 0, "attempt": 1} +V0403 07:28:48.074000 139877824898048 torch/_dynamo/convert_frame.py:672] {"dynamo_start": {"stack": [{"line": 10079, "name": "", "filename": 0}, {"line": 41, "name": "run_tests", "filename": 1}, {"line": 1167, "name": "run_tests", "filename": 2}, {"line": 101, "name": "__init__", "filename": 3}, {"line": 271, "name": "runTests", "filename": 3}, {"line": 184, "name": "run", "filename": 4}, {"line": 84, "name": "__call__", "filename": 5}, {"line": 122, "name": "run", "filename": 5}, {"line": 84, "name": "__call__", "filename": 5}, {"line": 122, "name": "run", "filename": 5}, {"line": 650, "name": "__call__", "filename": 6}, {"line": 2868, "name": "run", "filename": 2}, {"line": 2840, "name": "_run_custom", "filename": 2}, {"line": 591, "name": "run", "filename": 6}, {"line": 549, "name": "_callTestMethod", "filename": 6}, {"line": 2741, "name": "wrapper", "filename": 2}, {"line": 9559, "name": "test_graph_break_compilation_metrics", "filename": 0}, {"line": 410, "name": "_fn", "filename": 7}, {"line": 9551, "name": "fn", "filename": 0}, {"line": 9553, "name": "torch_dynamo_resume_in_fn_at_9551", "filename": 0}]}, "frame_id": 2, "frame_compile_id": 0, "attempt": 0} +V0403 07:28:48.076000 139877824898048 torch/_dynamo/output_graph.py:1139] {"dynamo_output_graph": {"sizes": {"l_x_": [4, 4], "cos": [4, 4]}}, "frame_id": 2, "frame_compile_id": 0, "attempt": 0, "has_payload": "2cbc38baafc04c3a903e8d659e78c854"} + class GraphModule(torch.nn.Module): + def forward(self, L_x_ : torch.Tensor): + l_x_ = L_x_ + + # File: /data/users/jjwu/a/pytorch/test/dynamo/test_misc.py:9554 in torch_dynamo_resume_in_fn_at_9553, code: return x.cos() + cos = l_x_.cos(); l_x_ = None + return (cos,) + +V0403 07:28:48.077000 139877824898048 torch/_dynamo/guards.py:1894] {"dynamo_guards": {}, "frame_id": 2, "frame_compile_id": 0, "attempt": 0, "has_payload": "11726d08889974e57b12edee2812504e"} + [ + {"code": "hasattr(L['x'], '_dynamo_dynamic_indices') == False", "stack": null, "user_stack": null}, + {"code": "utils_device.CURRENT_DEVICE == None", "stack": [{"line": 10079, "name": "", "filename": 0}, {"line": 41, "name": "run_tests", "filename": 1}, {"line": 1167, "name": "run_tests", "filename": 2}, {"line": 101, "name": "__init__", "filename": 3}, {"line": 271, "name": "runTests", "filename": 3}, {"line": 184, "name": "run", "filename": 4}, {"line": 84, "name": "__call__", "filename": 5}, {"line": 122, "name": "run", "filename": 5}, {"line": 84, "name": "__call__", "filename": 5}, {"line": 122, "name": "run", "filename": 5}, {"line": 650, "name": "__call__", "filename": 6}, {"line": 2868, "name": "run", "filename": 2}, {"line": 2840, "name": "_run_custom", "filename": 2}, {"line": 591, "name": "run", "filename": 6}, {"line": 549, "name": "_callTestMethod", "filename": 6}, {"line": 2741, "name": "wrapper", "filename": 2}, {"line": 9559, "name": "test_graph_break_compilation_metrics", "filename": 0}, {"line": 410, "name": "_fn", "filename": 7}, {"line": 9551, "name": "fn", "filename": 0}, {"line": 9553, "name": "torch_dynamo_resume_in_fn_at_9551", "filename": 0}, {"line": 939, "name": "catch_errors", "filename": 8}, {"line": 802, "name": "_convert_frame", "filename": 8}, {"line": 400, "name": "_convert_frame_assert", "filename": 8}, {"line": 79, "name": "inner", "filename": 9}, {"line": 686, "name": "_compile", "filename": 8}, {"line": 265, "name": "time_wrapper", "filename": 10}, {"line": 541, "name": "compile_inner", "filename": 8}, {"line": 1078, "name": "transform_code_object", "filename": 11}, {"line": 165, "name": "_fn", "filename": 8}, {"line": 485, "name": "transform", "filename": 8}, {"line": 2102, "name": "__init__", "filename": 12}, {"line": 302, "name": "__init__", "filename": 13}, {"line": 425, "name": "init_ambient_guards", "filename": 13}], "user_stack": null}, + {"code": "check_tensor(L['x'], Tensor, DispatchKeySet(CPU, BackendSelect, ADInplaceOrView, AutogradCPU), torch.float32, device=None, requires_grad=False, size=[4, 4], stride=[4, 1])", "stack": null, "user_stack": null} + ] +V0403 07:28:48.078000 139877824898048 torch/_dynamo/utils.py:685] {"compilation_metrics": {"frame_key": "3", "co_name": "torch_dynamo_resume_in_fn_at_9553", "co_filename": "/data/users/jjwu/a/pytorch/test/dynamo/test_misc.py", "co_firstlineno": 9553, "cache_size": 0, "accumulated_cache_size": 0, "guard_count": 6, "shape_env_guard_count": 0, "graph_op_count": 1, "graph_node_count": 3, "graph_input_count": 1, "start_time": 1712154528.074718, "entire_frame_compile_time_s": 0.003393888473510742, "backend_compile_time_s": 2.6226043701171875e-05, "inductor_compile_time_s": null, "code_gen_time_s": null, "fail_type": null, "fail_reason": null, "fail_user_frame_filename": null, "fail_user_frame_lineno": null, "non_compliant_ops": [], "compliant_custom_ops": [], "restart_reasons": [], "dynamo_time_before_restart_s": 0.0}, "frame_id": 2, "frame_compile_id": 0, "attempt": 0} diff --git a/tests/integration_test.rs b/tests/integration_test.rs index 8fa66e0..f8bf081 100644 --- a/tests/integration_test.rs +++ b/tests/integration_test.rs @@ -34,3 +34,34 @@ fn test_parse_simple() { assert!(prefix_exists(&map, prefix), "{} not found in output", prefix); } } + +#[test] +fn test_parse_compilation_metrics() { + let expected_files = [ + "0_0_1/dynamo_output_graph.txt", + "0_0_1/dynamo_guards.html", + "0_0_1/compilation_metrics.html", + "1_0_1/dynamo_output_graph.txt", + "1_0_1/dynamo_guards.html", + "1_0_1/compilation_metrics.html", + "2_0_0/dynamo_output_graph.txt", + "2_0_0/dynamo_guards.html", + "2_0_0/compilation_metrics.html", + "index.html", + ]; + // Read the test file + // simple.log was generated from the following: + // TORCH_TRACE=~/trace_logs/test python test/inductor/test_torchinductor.py -k test_custom_op_fixed_layout_channels_last_cpu + let path = Path::new("tests/inputs/comp_metrics.log").to_path_buf(); + let config = tlparse::ParseConfig { + strict: true, + custom_parsers: vec![], + }; + let output = tlparse::parse_path(&path, config); + assert!(output.is_ok()); + let map: HashMap = output.unwrap().into_iter().collect(); + // Check all files are present + for prefix in expected_files { + assert!(prefix_exists(&map, prefix), "{} not found in output", prefix); + } +}