Better logging

Summary:
Record the state of dexes and try to figure out new entries so that aborts are more actionable. This is likely not very cheap, but since it is not permanently on it should be OK.

NOTE: It is strange that for the test case `DexLimitsInfo` reports a field overflow when in fact the methods are overflowing. This should be investigated.

Reviewed By: thezhangwei

Differential Revision: D48634505

fbshipit-source-id: e104c37f340147c179cf1bb8030d0253aa4ed509

checkers/DexLimitsChecker.cpp

@@ -7,6 +7,8 @@
 
 #include "DexLimitsChecker.h"
 
+#include <iterator>
+#include <optional>
 #include <sstream>
 
 #include "ConfigFiles.h"
@@ -21,6 +23,159 @@
 
 namespace redex_properties {
 
+namespace {
+
+using dex_data_map_t =
+    std::unordered_map<std::string, std::vector<DexLimitsChecker::DexData>>;
+
+template <typename T>
+std::unordered_set<T> extract(const std::unordered_map<T, size_t>& input) {
+  // No insert iterator for unordered_set, have to go through vector.
+  std::vector<T> tmp{};
+  tmp.reserve(input.size());
+  std::transform(input.begin(),
+                 input.end(),
+                 std::back_inserter(tmp),
+                 [](auto& p) { return p.first; });
+  return std::unordered_set<T>(tmp.begin(), tmp.end());
+}
+
+dex_data_map_t create_data(
+    DexStoresVector& stores,
+    init_classes::InitClassesWithSideEffects* init_classes) {
+  dex_data_map_t tmp;
+
+  for (const auto& store : stores) {
+    std::vector<DexLimitsChecker::DexData> dexes_data;
+    dexes_data.reserve(store.num_dexes());
+
+    for (const auto& classes : store.get_dexen()) {
+      DexLimitsInfo dex_limits(init_classes);
+      for (const auto& cls : classes) {
+        dex_limits.update_refs_by_always_adding_class(cls);
+      }
+
+      auto& dex_struct = dex_limits.get_dex();
+
+      dexes_data.emplace_back(DexLimitsChecker::DexData{
+          extract(dex_struct.get_frefs()), extract(dex_struct.get_mrefs()),
+          extract(dex_struct.get_trefs())});
+    }
+    tmp.emplace(store.get_name(), std::move(dexes_data));
+  }
+
+  return tmp;
+}
+
+struct IssueIndex {
+  const DexStore* store{nullptr};
+  size_t dex_id{0};
+  bool field_overflow{false};
+  bool method_overflow{false};
+  bool type_overflow{false};
+};
+
+std::string print_new_entries(const dex_data_map_t& old_map,
+                              const dex_data_map_t& new_map,
+                              const std::vector<IssueIndex>& issues) {
+  std::ostringstream oss;
+
+  for (auto& i : issues) {
+    auto& store_name = i.store->get_name();
+    auto st_it = old_map.find(store_name);
+    if (st_it == old_map.end()) {
+      // Totally new store, log that.
+      oss << "\nStore " << store_name << " is newly created.\n";
+      continue;
+    }
+
+    // See whether we have the dex before. This may not match when dexes are
+    // deleted, best effort really.
+    auto& old_dexes = st_it->second;
+    if (old_dexes.size() <= i.dex_id) {
+      oss << "\nStore " << store_name << " dex " << i.dex_id
+          << " seems newly created.\n";
+      continue;
+    }
+
+    auto new_st_it = new_map.find(store_name);
+    redex_assert(new_st_it != new_map.end());
+
+    auto& new_dexes = new_st_it->second;
+    redex_assert(new_dexes.size() > i.dex_id);
+
+    auto print_differences =
+        [&](const auto& old_data, const auto& new_data, const char* prefix) {
+          // Won't be sorted, but sorting would be a template pain.
+          bool have_changes = false;
+          for (auto* entry : new_data) {
+            if (old_data.count(entry) != 0) {
+              continue;
+            }
+            if (!have_changes) {
+              have_changes = true;
+              oss << prefix << show(entry);
+            } else {
+              oss << ", " << show(entry);
+            }
+          }
+          if (have_changes) {
+            oss << "\n";
+          }
+          return have_changes;
+        };
+
+    bool had_fields{false};
+    if (i.field_overflow) {
+      had_fields = print_differences(
+          old_dexes[i.dex_id].fields, new_dexes[i.dex_id].fields, "Fields: ");
+      if (!had_fields) {
+        oss << "Failed detecting field changes for " << store_name << "@"
+            << i.dex_id << "\n";
+      }
+    }
+    bool had_methods{false};
+    if (i.method_overflow) {
+      had_methods = print_differences(old_dexes[i.dex_id].methods,
+                                      new_dexes[i.dex_id].methods,
+                                      "Methods: ");
+      if (!had_methods) {
+        oss << "Failed detecting method changes for " << store_name << "@"
+            << i.dex_id << "\n";
+      }
+    }
+    bool had_types{false};
+    if (i.type_overflow) {
+      had_types = print_differences(
+          old_dexes[i.dex_id].types, new_dexes[i.dex_id].types, "Types: ");
+      if (!had_types) {
+        oss << "Failed detecting type changes for " << store_name << "@"
+            << i.dex_id << "\n";
+      }
+    }
+    if (!had_fields && !had_methods && !had_types) {
+      // Run the other things, maybe there's a misdetection.
+      if (!i.field_overflow) {
+        print_differences(
+            old_dexes[i.dex_id].fields, new_dexes[i.dex_id].fields, "Fields: ");
+      }
+      if (!i.method_overflow) {
+        print_differences(old_dexes[i.dex_id].methods,
+                          new_dexes[i.dex_id].methods,
+                          "Methods: ");
+      }
+      if (!i.type_overflow) {
+        print_differences(
+            old_dexes[i.dex_id].types, new_dexes[i.dex_id].types, "Types: ");
+      }
+    }
+  }
+
+  return oss.str();
+}
+
+} // namespace
+
 void DexLimitsChecker::run_checker(DexStoresVector& stores,
                                    ConfigFiles& conf,
                                    PassManager& mgr,
@@ -45,35 +200,63 @@ void DexLimitsChecker::run_checker(DexStoresVector& stores,
             scope, conf.create_init_class_insns());
   }
 
-  auto check_ref_num =
-      [&init_classes_with_side_effects, &pass_name, &result](
-          const DexClasses& classes, const DexStore& store, size_t dex_id) {
-        DexLimitsInfo dex_limits(init_classes_with_side_effects.get());
-        for (const auto& cls : classes) {
-          if (!dex_limits.update_refs_by_adding_class(cls)) {
-            if (dex_limits.is_method_overflow()) {
-              result << pass_name << " adds too many method refs in dex "
-                     << dex_name(store, dex_id) << "\n";
-            }
-            if (dex_limits.is_field_overflow()) {
-              result << pass_name << " adds too many field refs in dex "
-                     << dex_name(store, dex_id) << "\n";
-            }
-            if (dex_limits.is_type_overflow()) {
-              result << pass_name << " adds too many type refs in dex "
-                     << dex_name(store, dex_id) << "\n";
-            }
-          }
-        }
-      };
+  auto check_ref_num = [&init_classes_with_side_effects, &pass_name, &result](
+                           const DexClasses& classes,
+                           const DexStore& store,
+                           size_t dex_id) -> std::optional<IssueIndex> {
+    DexLimitsInfo dex_limits(init_classes_with_side_effects.get());
+    bool field_overflow{false};
+    bool method_overflow{false};
+    bool type_overflow{false};
+    for (const auto& cls : classes) {
+      if (!dex_limits.update_refs_by_adding_class(cls)) {
+        method_overflow |= dex_limits.is_method_overflow();
+        field_overflow |= dex_limits.is_field_overflow();
+        type_overflow |= dex_limits.is_type_overflow();
+      }
+    }
+    auto add_overflow_msg = [&](bool check, const char* type_str) {
+      if (check) {
+        result << pass_name << " adds too many " << type_str << " refs in dex "
+               << dex_name(store, dex_id) << "\n";
+      }
+    };
+    add_overflow_msg(field_overflow, "field");
+    add_overflow_msg(method_overflow, "method");
+    add_overflow_msg(type_overflow, "type");
+
+    if (field_overflow || method_overflow || type_overflow) {
+      TRACE(PM,
+            0,
+            "Recording overflow %d / %d / %d",
+            field_overflow,
+            method_overflow,
+            type_overflow);
+      return IssueIndex{&store, dex_id, field_overflow, method_overflow,
+                        type_overflow};
+    }
+
+    return std::nullopt;
+  };
+
+  std::vector<IssueIndex> issues;
   for (const auto& store : stores) {
     size_t dex_id = 0;
     for (const auto& classes : store.get_dexen()) {
-      check_ref_num(classes, store, dex_id++);
+      auto maybe_issue = check_ref_num(classes, store, dex_id++);
+      if (maybe_issue) {
+        issues.emplace_back(*maybe_issue);
+      }
     }
   }
-  auto result_str = result.str();
-  always_assert_log(result_str.empty(), "%s", result_str.c_str());
+
+  auto old_data = std::move(m_data);
+  m_data = create_data(stores, init_classes_with_side_effects.get());
+  TRACE(PM, 0, "%s", result.str().c_str());
+  always_assert_log(issues.empty(),
+                    "%s\n%s",
+                    result.str().c_str(),
+                    print_new_entries(old_data, m_data, issues).c_str());
 }
 
 } // namespace redex_properties

checkers/DexLimitsChecker.h

@@ -9,13 +9,28 @@
 
 #include "RedexPropertyChecker.h"
 
+#include <string>
+#include <vector>
+
+class DexFieldRef;
+class DexMethodRef;
+class DexType;
+
 namespace redex_properties {
 
 class DexLimitsChecker : public PropertyChecker {
  public:
   DexLimitsChecker() : PropertyChecker(names::DexLimitsObeyed) {}
 
   void run_checker(DexStoresVector&, ConfigFiles&, PassManager&, bool) override;
+
+  struct DexData {
+    std::unordered_set<DexFieldRef*> fields;
+    std::unordered_set<DexMethodRef*> methods;
+    std::unordered_set<DexType*> types;
+  };
+
+  std::unordered_map<std::string, std::vector<DexData>> m_data;
 };
 
 } // namespace redex_properties

libredex/DexLimitsInfo.cpp

@@ -52,6 +52,36 @@ bool DexLimitsInfo::update_refs_by_adding_class(DexClass* cls) {
                                  cls);
 }
 
+void DexLimitsInfo::update_refs_by_always_adding_class(DexClass* cls) {
+  MethodRefs method_refs;
+  FieldRefs field_refs;
+  TypeRefs type_refs;
+  TypeRefs init_refs;
+  std::vector<DexType*> itrefs;
+  TypeRefs pending_init_class_fields;
+  TypeRefs pending_init_class_types;
+
+  if (m_init_classes_with_side_effects) {
+    cls->gather_init_classes(itrefs);
+    init_refs.insert(itrefs.begin(), itrefs.end());
+  }
+  cls->gather_methods(method_refs);
+  cls->gather_fields(field_refs);
+  cls->gather_types(type_refs);
+
+  m_dex.resolve_init_classes(m_init_classes_with_side_effects, field_refs,
+                             type_refs, init_refs, &pending_init_class_fields,
+                             &pending_init_class_types);
+
+  return m_dex.add_class_no_checks(method_refs,
+                                   field_refs,
+                                   type_refs,
+                                   pending_init_class_fields,
+                                   pending_init_class_types,
+                                   /*laclazz=*/0,
+                                   cls);
+}
+
 void DexLimitsInfo::update_refs_by_erasing_class(DexClass* cls) {
   MethodRefs method_refs;
   FieldRefs field_refs;

libredex/DexLimitsInfo.h

@@ -47,7 +47,10 @@ class DexLimitsInfo {
   // Calculate the refs after adding \p cls to current dex. If the dex is still
   // valid, update the refs and return true. Otherwise, return false.
   bool update_refs_by_adding_class(DexClass* cls);
+  void update_refs_by_always_adding_class(DexClass* cls);
 
   // Update the the refs when cls is removed from current dex.
   void update_refs_by_erasing_class(DexClass* cls);
+
+  const DexStructure& get_dex() const { return m_dex; }
 };

libredex/DexStructure.h

@@ -170,9 +170,20 @@ also reject some legal cases.
 
   size_t get_num_classes() const { return m_classes.size(); }
 
+  size_t get_num_trefs() const { return m_trefs.size(); }
+  const std::unordered_map<DexType*, size_t>& get_trefs() const {
+    return m_trefs;
+  }
+
   size_t get_num_mrefs() const { return m_mrefs.size(); }
+  const std::unordered_map<DexMethodRef*, size_t>& get_mrefs() const {
+    return m_mrefs;
+  }
 
   size_t get_num_frefs() const { return m_frefs.size(); }
+  const std::unordered_map<DexFieldRef*, size_t>& get_frefs() const {
+    return m_frefs;
+  }
 
   const OverflowStats& get_overflow_stats() const { return m_overflow_stats; }