Asyncify verbose option (#3022)

This logs out the decisions made about instrumenting functions, which
can help figure out why a function is instrumented, or to get a list of
what might need to be.

As the test shows, it can print things like this:

[asyncify] import is an import that can change the state
[asyncify] calls-import can change the state due to import
[asyncify] calls-calls-import can change the state due to calls-import
[asyncify] calls-calls-calls-import can change the state due to calls-calls-import

(the test has calls-calls-calls-import => calls-calls-import => calls-import -> import).

3 files changed, 58 insertions, 11 deletions

diff --git a/src/ir/module-utils.h b/src/ir/module-utils.h
index ab23649f7..8f89c780f 100644
--- a/src/ir/module-utils.h
+++ b/src/ir/module-utils.h
@@ -349,9 +349,14 @@ template<typename T> struct CallGraphPropertyAnalysis {
   enum IndirectCalls { IgnoreIndirectCalls, IndirectCallsHaveProperty };
 
   // Propagate a property from a function to those that call it.
+  //
+  // hasProperty() - Check if the property is present.
+  // canHaveProperty() - Check if the property could be present.
+  // addProperty() - Adds the property. This receives a second parameter which
+  //                 is the function due to which we are adding the property.
   void propagateBack(std::function<bool(const T&)> hasProperty,
                      std::function<bool(const T&)> canHaveProperty,
-                     std::function<void(T&)> addProperty,
+                     std::function<void(T&, Function*)> addProperty,
                      IndirectCalls indirectCalls) {
     // The work queue contains items we just learned can change the state.
     UniqueDeferredQueue<Function*> work;
@@ -359,7 +364,7 @@ template<typename T> struct CallGraphPropertyAnalysis {
       if (hasProperty(map[func.get()]) ||
           (indirectCalls == IndirectCallsHaveProperty &&
            map[func.get()].hasIndirectCall)) {
-        addProperty(map[func.get()]);
+        addProperty(map[func.get()], func.get());
         work.push(func.get());
       }
     }
@@ -369,7 +374,7 @@ template<typename T> struct CallGraphPropertyAnalysis {
         // If we don't already have the property, and we are not forbidden
         // from getting it, then it propagates back to us now.
         if (!hasProperty(map[caller]) && canHaveProperty(map[caller])) {
-          addProperty(map[caller]);
+          addProperty(map[caller], func);
           work.push(caller);
         }
       }
diff --git a/src/passes/Asyncify.cpp b/src/passes/Asyncify.cpp
index 61c1f0ff4..e5305317b 100644
--- a/src/passes/Asyncify.cpp
+++ b/src/passes/Asyncify.cpp
@@ -231,6 +231,11 @@
 //      an unwind/rewind in an invalid place (this can be helpful for manual
 //      tweaking of the only-list / remove-list, see later).
 //
+//   --pass-arg=asyncify-verbose
+//
+//      Logs out instrumentation decisions to the console. This can help figure
+//      out why a certain function was instrumented.
+//
 // For manual fine-tuning of the list of instrumented functions, there are lists
 // that you can set. These must be used carefully, as misuse can break your
 // application - for example, if a function is called that should be
@@ -486,6 +491,8 @@ class ModuleAnalyzer {
 
   struct Info
     : public ModuleUtils::CallGraphPropertyAnalysis<Info>::FunctionInfo {
+    // The function name.
+    Name name;
     // If this function can start an unwind/rewind.
     bool canChangeState = false;
     // If this function is part of the runtime that receives an unwinding
@@ -513,9 +520,10 @@ public:
                  const String::Split& removeListInput,
                  const String::Split& addListInput,
                  const String::Split& onlyListInput,
-                 bool asserts)
+                 bool asserts,
+                 bool verbose)
     : module(module), canIndirectChangeState(canIndirectChangeState),
-      fakeGlobals(module), asserts(asserts) {
+      fakeGlobals(module), asserts(asserts), verbose(verbose) {
 
     PatternMatcher removeList("remove", module, removeListInput);
     PatternMatcher addList("add", module, addListInput);
@@ -548,6 +556,7 @@ public:
     // name.
     ModuleUtils::CallGraphPropertyAnalysis<Info> scanner(
       module, [&](Function* func, Info& info) {
+        info.name = func->name;
         if (func->imported()) {
           // The relevant asyncify imports can definitely change the state.
           if (func->module == ASYNCIFY &&
@@ -556,6 +565,10 @@ public:
           } else {
             info.canChangeState =
               canImportChangeState(func->module, func->base);
+            if (verbose && info.canChangeState) {
+              std::cout << "[asyncify] " << func->name
+                        << " is an import that can change the state\n";
+            }
           }
           return;
         }
@@ -609,6 +622,10 @@ public:
           //       the bottom-most runtime also doing top-most runtime stuff
           //       like starting and unwinding.
         }
+        if (verbose && info.canChangeState) {
+          std::cout << "[asyncify] " << func->name
+                    << " can change the state due to initial scan\n";
+        }
       });
 
     // Functions in the remove-list are assumed to not change the state.
@@ -617,6 +634,10 @@ public:
       auto& info = pair.second;
       if (removeList.match(func->name)) {
         info.inRemoveList = true;
+        if (verbose && info.canChangeState) {
+          std::cout << "[asyncify] " << func->name
+                    << " is in the remove-list, ignore\n";
+        }
         info.canChangeState = false;
       }
     }
@@ -648,7 +669,14 @@ public:
                             return !info.isBottomMostRuntime &&
                                    !info.inRemoveList;
                           },
-                          [](Info& info) { info.canChangeState = true; },
+                          [verbose](Info& info, Function* reason) {
+                            if (verbose && !info.canChangeState) {
+                              std::cout << "[asyncify] " << info.name
+                                        << " can change the state due to "
+                                        << reason->name << "\n";
+                            }
+                            info.canChangeState = true;
+                          },
                           scanner.IgnoreIndirectCalls);
 
     map.swap(scanner.map);
@@ -663,6 +691,11 @@ public:
           if (matched) {
             info.addedFromList = true;
           }
+          if (verbose) {
+            std::cout << "[asyncify] " << func->name
+                      << "'s state is set based on the only-list to " << matched
+                      << '\n';
+          }
         }
       }
     }
@@ -671,6 +704,10 @@ public:
       for (auto& func : module.functions) {
         if (!func->imported() && addList.match(func->name)) {
           auto& info = map[func.get()];
+          if (verbose && !info.canChangeState) {
+            std::cout << "[asyncify] " << func->name
+                      << " is in the add-list, add\n";
+          }
           info.canChangeState = true;
           info.addedFromList = true;
         }
@@ -741,6 +778,7 @@ public:
 
   FakeGlobalHelper fakeGlobals;
   bool asserts;
+  bool verbose;
 };
 
 // Checks if something performs a call: either a direct or indirect call,
@@ -1397,6 +1435,8 @@ struct Asyncify : public Pass {
       String::trim(read_possible_response_file(onlyListInput)), ",");
     auto asserts =
       runner->options.getArgumentOrDefault("asyncify-asserts", "") != "";
+    auto verbose =
+      runner->options.getArgumentOrDefault("asyncify-verbose", "") != "";
 
     removeList = handleBracketingOperators(removeList);
     addList = handleBracketingOperators(addList);
@@ -1427,7 +1467,8 @@ struct Asyncify : public Pass {
                             removeList,
                             addList,
                             onlyList,
-                            asserts);
+                            asserts,
+                            verbose);
 
     // Add necessary globals before we emit code to use them.
     addGlobals(module);
diff --git a/src/passes/PostEmscripten.cpp b/src/passes/PostEmscripten.cpp
index 00fb30b51..2397284c3 100644
--- a/src/passes/PostEmscripten.cpp
+++ b/src/passes/PostEmscripten.cpp
@@ -175,10 +175,11 @@ struct PostEmscripten : public Pass {
       });
 
     // Assume an indirect call might throw.
-    analyzer.propagateBack([](const Info& info) { return info.canThrow; },
-                           [](const Info& info) { return true; },
-                           [](Info& info) { info.canThrow = true; },
-                           analyzer.IndirectCallsHaveProperty);
+    analyzer.propagateBack(
+      [](const Info& info) { return info.canThrow; },
+      [](const Info& info) { return true; },
+      [](Info& info, Function* reason) { info.canThrow = true; },
+      analyzer.IndirectCallsHaveProperty);
 
     // Apply the information.
     struct OptimizeInvokes : public WalkerPass<PostWalker<OptimizeInvokes>> {