Adding MIGRAPHX_TIME_MATCHERS

docs/dev/env_vars.rst

@@ -192,6 +192,11 @@ Prints the compile pass and the program after the pass.
 Set to "1", "enable", "enabled", "yes", or "true" to use.
 Times the compile passes.
 
+.. envvar:: MIGRAPHX_TIME_MATCHERS
+
+Set to "1", "enable", "enabled", "yes", or "true" to use.
+Times the matchers.
+
 .. envvar:: MIGRAPHX_DISABLE_PASSES
 
 Set to the name of the pass you want to skip.  Comma separated list is supported

src/include/migraphx/matcher.hpp

@@ -34,6 +34,8 @@
 #include <migraphx/type_name.hpp>
 #include <migraphx/source_location.hpp>
 #include <migraphx/config.hpp>
+#include <migraphx/time.hpp>
+
 #include <array>
 #include <unordered_map>
 #include <unordered_set>
@@ -402,6 +404,7 @@
 MIGRAPHX_DECLARE_ENV_VAR(MIGRAPHX_TRACE_MATCHES)
 MIGRAPHX_DECLARE_ENV_VAR(MIGRAPHX_TRACE_MATCHES_FOR)
 MIGRAPHX_DECLARE_ENV_VAR(MIGRAPHX_VALIDATE_MATCHES)
+MIGRAPHX_DECLARE_ENV_VAR(MIGRAPHX_TIME_MATCHERS)
 
 /// Find matches for an instruction in the module for per section of matchers
 template <class Mod, class... Ms>
@@ -410,7 +413,8 @@
     const int trace         = value_of(MIGRAPHX_TRACE_MATCHES{});
     const bool validate     = enabled(MIGRAPHX_VALIDATE_MATCHES{});
     const auto trace_filter = string_value_of(MIGRAPHX_TRACE_MATCHES_FOR{});
-    bool match              = false;
+    const bool time_matchers = enabled(MIGRAPHX_TIME_MATCHERS{});
+    bool match               = false;
     each_args(
         [&](auto&& m) {
             const auto& matcher_name = get_type_name(m);
@@ -420,19 +424,44 @@
                                     contains(matcher_name, trace_filter));
             if(match)
                 return;
+            // print running matcher even if it doesn't match anything
             if(trace > 1 and trace_for)
-                std::cout << "Match: " << matcher_name << std::endl;
-            auto r = match_instruction(get_module(mod), ins, m.matcher());
+                std::cout << "Running matcher: " << matcher_name << std::endl;
+
+            matcher_result r;
+            if(time_matchers or trace_for)
+            {
+                timer match_timer{};
+                r = match_instruction(get_module(mod), ins, m.matcher());
+                const auto match_time =
+                    match_timer.record<std::chrono::duration<double, std::micro>>();
+                std::cout << "Matcher time for " << matcher_name << ": " << match_time << "us"
+                          << std::endl;
+            }
+            else
+            {
+                r = match_instruction(get_module(mod), ins, m.matcher());
+            }
+
+            // did not match any instruction
             if(r.result == get_module(mod).end())
                 return;
+
             if(trace > 0 or trace_for)
             {
-                std::cout << "Matched by " << matcher_name << std::endl;
+                std::cout << "Matched by: " << matcher_name << std::endl;
                 get_module(mod).debug_print(ins);
             }
             // If its already invalid dont validate it again
             bool invalidated = validate and get_module(mod).validate() != get_module(mod).end();
-            m.apply(mod, r);
+            auto apply_time =
+                time<std::chrono::duration<double, std::micro>>([&] { m.apply(mod, r); });
+            if(time_matchers or trace_for)
+            {
+                std::cout << "Apply time for " << matcher_name << ": " << apply_time << "us"
+                          << std::endl;
+            }
+
             if(validate and not invalidated)
             {
                 auto invalid = get_module(mod).validate();