Repository: bytecodealliance/wasmtime
Pull request #8013 (2024-02-28 14:28:18)

Cranelift: Tweak egraph mid-end logging
This logs the resulting values of a call into ISLE's `simplify` constructor, not just the input value, so we can better debug in the future by tracing how a value was produced and which value it is a rewrite of.

New output:

    Calling into ISLE with original value v2
    -> returned from ISLE: v2 -> [v3, v4, v5]

Old output:

    Calling into ISLE with original value v2
    -> returned from ISLE, generated 3 optimized values

<!--
Please make sure you include the following information:

- If this work has been discussed elsewhere, please include a link to that
  conversation. If it was discussed in an issue, just mention "issue #...".

- Explain why this change is needed. If the details are in an issue already,
  this can be brief.

Our development process is documented in the Wasmtime book:
https://docs.wasmtime.dev/contributing-development-process.html

Please ensure all communication follows the code of conduct:
https://github.com/bytecodealliance/wasmtime/blob/main/CODE_OF_CONDUCT.md
-->



Patch:
diff --git a/cranelift/codegen/src/egraph.rs b/cranelift/codegen/src/egraph.rs
index cd9adcba8..2b5db33b3 100644
--- a/cranelift/codegen/src/egraph.rs
+++ b/cranelift/codegen/src/egraph.rs
@@ -250,19 +250,21 @@ where
             orig_value,
             &mut optimized_values,
         );
-        trace!(
-            "  -> returned from ISLE, generated {} optimized values",
-            optimized_values.len()
-        );
 
         // It's not supposed to matter what order `simplify` returns values in.
         self.ctrl_plane.shuffle(&mut optimized_values);
 
-        if optimized_values.len() > MATCHES_LIMIT {
-            trace!("Reached maximum matches limit; too many optimized values, ignoring rest.");
+        let num_matches = optimized_values.len();
+        if num_matches > MATCHES_LIMIT {
+            trace!(
+                "Reached maximum matches limit; too many optimized values \
+                 ({num_matches} > {MATCHES_LIMIT}); ignoring rest.",
+            );
             optimized_values.truncate(MATCHES_LIMIT);
         }
 
+        trace!("  -> returned from ISLE: {orig_value} -> {optimized_values:?}");
+
         // Create a union of all new values with the original (or
         // maybe just one new value marked as "subsuming" the
         // original, if present.)
@@ -298,6 +300,7 @@ where
         }
 
         self.rewrite_depth -= 1;
+        trace!("Decrementing rewrite depth; now {}", self.rewrite_depth);
 
         debug_assert!(self.optimized_values.is_empty());
         self.optimized_values = optimized_values;


Test patch:
diff --git a/cranelift/filetests/filetests/egraph/issue-7999.clif b/cranelift/filetests/filetests/egraph/issue-7999.clif
new file mode 100644
index 000000000..7cacb533f
--- /dev/null
+++ b/cranelift/filetests/filetests/egraph/issue-7999.clif
@@ -0,0 +1,12 @@
+test optimize
+set opt_level=speed
+target x86_64
+
+function u0:11(i8) -> i8 system_v {
+block0(v0: i8):
+    v1 = uextend.i64 v0
+    v2 = imul_imm v1, 256
+    v3 = ireduce.i8 v2
+    return v3
+    ; return v10  ; v10 = 0
+}