Fix and tune ProfileSaver
- the statement to mark the profile saved was not guarded by the right
condition.
- increase the backoff to 2x and maximum period time to 10 minutes.
As part of this change also
- fix typos
- remove uneeded warning
- add more VLOGs for easier debuging in the future
Bug: 27914456
(cherry picked from commit 0cdaa6cdbeadceaee3a1acc641e7cc2548e125d9)
Change-Id: I76ddc6ced897bb91cfbd2a0cb6614bdeeafb9ee9
diff --git a/runtime/jit/profile_saver.cc b/runtime/jit/profile_saver.cc
index bb31746..70ea617 100644
--- a/runtime/jit/profile_saver.cc
+++ b/runtime/jit/profile_saver.cc
@@ -34,10 +34,10 @@
// Add a random delay each time we go to sleep so that we don't hammer the CPU
// with all profile savers running at the same time.
static constexpr const uint64_t kRandomDelayMaxMs = 30 * 1000; // 30 seconds
-static constexpr const uint64_t kMaxBackoffMs = 5 * 60 * 1000; // 5 minutes
+static constexpr const uint64_t kMaxBackoffMs = 10 * 60 * 1000; // 10 minutes
static constexpr const uint64_t kSavePeriodMs = 20 * 1000; // 20 seconds
static constexpr const uint64_t kSaveResolvedClassesDelayMs = 2 * 1000; // 2 seconds
-static constexpr const double kBackoffCoef = 1.5;
+static constexpr const double kBackoffCoef = 2.0;
static constexpr const uint32_t kMinimumNumberOfMethodsToSave = 10;
static constexpr const uint32_t kMinimumNumberOfClassesToSave = 10;
@@ -54,7 +54,7 @@
foreign_dex_profile_path_(foreign_dex_profile_path),
shutting_down_(false),
last_save_number_of_methods_(0),
- last_save_number_of_classes__(0),
+ last_save_number_of_classes_(0),
wait_lock_("ProfileSaver wait lock"),
period_condition_("ProfileSaver period condition", wait_lock_),
total_bytes_written_(0),
@@ -125,9 +125,11 @@
// so in the future. Increase the time between saves according to the
// kBackoffCoef, but make it no larger than kMaxBackoffMs.
save_period_ms = static_cast<uint64_t>(kBackoffCoef * save_period_ms);
+ VLOG(profiler) << "Profile saver: nothing to save, delaying period to: " << save_period_ms;
} else {
// Reset the period to the initial value as it's highly likely to JIT again.
save_period_ms = kSavePeriodMs;
+ VLOG(profiler) << "Profile saver: saved something, period reset to: " << save_period_ms;
}
}
cache_resolved_classes = false;
@@ -197,14 +199,16 @@
ProfileCompilationInfo* cached_info = GetCachedProfiledInfo(filename);
cached_info->AddMethodsAndClasses(methods, std::set<DexCacheResolvedClasses>());
- uint32_t delta_number_of_methods =
- cached_info->GetNumberOfMethods() - last_save_number_of_methods_;
- uint32_t delta_number_of_classes =
- cached_info->GetNumberOfResolvedClasses() - last_save_number_of_classes__;
+ int64_t delta_number_of_methods =
+ cached_info->GetNumberOfMethods() -
+ static_cast<int64_t>(last_save_number_of_methods_);
+ int64_t delta_number_of_classes =
+ cached_info->GetNumberOfResolvedClasses() -
+ static_cast<int64_t>(last_save_number_of_classes_);
if (delta_number_of_methods < kMinimumNumberOfMethodsToSave &&
delta_number_of_classes < kMinimumNumberOfClassesToSave) {
- VLOG(profiler) << "Not enough information to save to: " << filename
+ VLOG(profiler) << "Not enough information to save to: " << filename
<< " Nr of methods: " << delta_number_of_methods
<< " Nr of classes: " << delta_number_of_classes;
total_number_of_skipped_writes_++;
@@ -215,13 +219,14 @@
// has the wrong version this will "fix" the file to the correct format.
if (cached_info->MergeAndSave(filename, &bytes_written, /*force*/ true)) {
last_save_number_of_methods_ = cached_info->GetNumberOfMethods();
- last_save_number_of_classes__ = cached_info->GetNumberOfResolvedClasses();
+ last_save_number_of_classes_ = cached_info->GetNumberOfResolvedClasses();
// Clear resolved classes. No need to store them around as
// they don't change after the first write.
cached_info->ClearResolvedClasses();
if (bytes_written > 0) {
total_number_of_writes_++;
total_bytes_written_ += bytes_written;
+ profile_file_saved = true;
} else {
// At this point we could still have avoided the write.
// We load and merge the data from the file lazily at its first ever
@@ -229,12 +234,9 @@
// in the file.
total_number_of_skipped_writes_++;
}
- profile_file_saved = true;
} else {
LOG(WARNING) << "Could not save profiling info to " << filename;
total_number_of_failed_writes_++;
- // TODO: (calin): if we failed because of bad profiling data or parsing
- // errors we should clear the profile file.
}
total_number_of_profile_entries_cached +=
cached_info->GetNumberOfMethods() +
@@ -268,7 +270,6 @@
// This can happen if we fallback to run code directly from the APK.
// Profile it with the hope that the background dexopt will get us back into
// a good state.
- LOG(WARNING) << "Accepting to profile an un-opened oat file " << location;
return true;
}
CompilerFilter::Filter filter = oat_file->GetCompilerFilter();
diff --git a/runtime/jit/profile_saver.h b/runtime/jit/profile_saver.h
index 91390fe..5cfbc22 100644
--- a/runtime/jit/profile_saver.h
+++ b/runtime/jit/profile_saver.h
@@ -101,7 +101,7 @@
std::string app_data_dir_;
bool shutting_down_ GUARDED_BY(Locks::profiler_lock_);
uint32_t last_save_number_of_methods_;
- uint32_t last_save_number_of_classes__;
+ uint32_t last_save_number_of_classes_;
// A local cache for the profile information. Maps each tracked file to its
// profile information. The size of this cache is usually very small and tops