Asyncify: Fix nondeterminism in verbose logging

src/ir/module-utils.h

@@ -393,6 +393,13 @@ template<typename T> struct CallGraphPropertyAnalysis {
   // addProperty() - Adds the property.
   // logVisit() - Log each visit of the propagation. This is called before
   //              we check if the function already has the property.
+  //
+  // Note that the order of propagation here is *not* deterministic, for
+  // efficiency reasons (specifically, |calledBy| is unordered and also is
+  // generated by |callsTo| which is likewise unordered). If the order matters
+  // we could add an ordered variant of this. For now, users that care about
+  // ordering in the middle need to handle this (e.g. Asyncify - if we add such
+  // an ordered variant, we could use it there).
   void propagateBack(std::function<bool(const T&)> hasProperty,
                      std::function<bool(const T&)> canHaveProperty,
                      std::function<void(T&)> addProperty,

src/passes/Asyncify.cpp

@@ -711,21 +711,34 @@ class ModuleAnalyzer {
       handleAddList(scanner.map);
     }
 
+    // The order of propagation in |propagateBack| is non-deterministic, so sort
+    // the loggings we intend to do.
+    std::vector<std::string> loggings;
+
     scanner.propagateBack([](const Info& info) { return info.canChangeState; },
                           [](const Info& info) {
                             return !info.isBottomMostRuntime &&
                                    !info.inRemoveList;
                           },
                           [](Info& info) { info.canChangeState = true; },
-                          [verbose](const Info& info, Function* reason) {
+                          [&](const Info& info, Function* reason) {
                             if (verbose) {
-                              std::cout << "[asyncify] " << info.name
-                                        << " can change the state due to "
-                                        << reason->name << "\n";
+                              std::stringstream str;
+                              str << "[asyncify] " << info.name
+                                  << " can change the state due to "
+                                  << reason->name << "\n";
+                              loggings.push_back(str.str());
                             }
                           },
                           scanner.IgnoreNonDirectCalls);
 
+    if (!loggings.empty()) {
+      std::sort(loggings.begin(), loggings.end());
+      for (auto& logging : loggings) {
+        std::cout << logging;
+      }
+    }
+
     map.swap(scanner.map);
 
     if (!onlyListInput.empty()) {

test/lit/passes/asyncify_verbose.wast

@@ -1,40 +1,36 @@
 ;; RUN: foreach %s %t wasm-opt --asyncify --pass-arg=asyncify-verbose -q | filecheck %s
 
-;; The import is reported as changing the state, as all imports can.
+;; The import is reported as changing the state, as all imports can. The
+;; function that calls it, consequently, is also reported as such, and so on
+;; further up the chain.
 ;;
-;; CHECK: [asyncify] import is an import that can change the state
-
-;; The function that calls the import can change the state too.
-;;
-;; CHECK: [asyncify] calls-import can change the state due to import
-
-;; Likewise, further up the call chain as well.
-;;
-;; CHECK: [asyncify] calls-calls-import can change the state due to calls-import
-;; CHECK: [asyncify] calls-calls-import-b can change the state due to calls-import
-;; CHECK: [asyncify] calls-calls-calls-import can change the state due to calls-calls-import
-;; CHECK: [asyncify] calls-calls-calls-import can change the state due to calls-calls-import-b
+;; CHECK: [asyncify] a-import is an import that can change the state
+;; CHECK: [asyncify] calls-a-import can change the state due to a-import
+;; CHECK: [asyncify] calls-calls-a-import can change the state due to calls-a-import
+;; CHECK: [asyncify] calls-calls-a-import-b can change the state due to calls-a-import
+;; CHECK: [asyncify] calls-calls-calls-a-import can change the state due to calls-calls-a-import
+;; CHECK: [asyncify] calls-calls-calls-a-import can change the state due to calls-calls-a-import-b
 
 (module
-  (import "env" "import" (func $import))
+  (import "env" "import" (func $a-import))
 
   (memory 1 2)
 
-  (func $calls-import
-    (call $import)
+  (func $calls-a-import
+    (call $a-import)
   )
 
-  (func $calls-calls-import
-    (call $calls-import)
+  (func $calls-calls-a-import
+    (call $calls-a-import)
   )
 
-  (func $calls-calls-import-b
-    (call $calls-import)
+  (func $calls-calls-a-import-b
+    (call $calls-a-import)
   )
 
-  (func $calls-calls-calls-import
-    (call $calls-calls-import)
-    (call $calls-calls-import-b)
+  (func $calls-calls-calls-a-import
+    (call $calls-calls-a-import)
+    (call $calls-calls-a-import-b)
   )
 
   (func $nothing