blob: 025d10ccc0e03d0ad5585e6a48723df0bf39dc7c [file] [log] [blame]
Calin Juravle4d77b6a2015-12-01 18:38:09 +00001/*
2 * Copyright (C) 2015 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 * http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16
17#include "profile_saver.h"
18
Calin Juravle86a9ebe2016-02-24 10:13:09 +000019#include <sys/types.h>
20#include <sys/stat.h>
21#include <fcntl.h>
22
Andreas Gampe9186ced2016-12-12 14:28:21 -080023#include "android-base/strings.h"
24
Calin Juravle4d77b6a2015-12-01 18:38:09 +000025#include "art_method-inl.h"
Andreas Gampe542451c2016-07-26 09:02:02 -070026#include "base/enums.h"
Mathieu Chartierdabdc0f2016-03-04 14:58:03 -080027#include "base/systrace.h"
Calin Juravle6044fa72016-03-25 17:17:09 +000028#include "base/time_utils.h"
29#include "compiler_filter.h"
Calin Juravle4d77b6a2015-12-01 18:38:09 +000030#include "oat_file_manager.h"
Mathieu Chartier0795f232016-09-27 18:43:30 -070031#include "scoped_thread_state_change-inl.h"
Calin Juravle6044fa72016-03-25 17:17:09 +000032
Calin Juravle4d77b6a2015-12-01 18:38:09 +000033
34namespace art {
35
Calin Juravle4d77b6a2015-12-01 18:38:09 +000036ProfileSaver* ProfileSaver::instance_ = nullptr;
37pthread_t ProfileSaver::profiler_pthread_ = 0U;
38
Calin Juravle138dbff2016-06-28 19:36:58 +010039ProfileSaver::ProfileSaver(const ProfileSaverOptions& options,
40 const std::string& output_filename,
Calin Juravle4d77b6a2015-12-01 18:38:09 +000041 jit::JitCodeCache* jit_code_cache,
Calin Juravle86a9ebe2016-02-24 10:13:09 +000042 const std::vector<std::string>& code_paths,
43 const std::string& foreign_dex_profile_path,
44 const std::string& app_data_dir)
Calin Juravleb4eddd22016-01-13 15:52:33 -080045 : jit_code_cache_(jit_code_cache),
Calin Juravle86a9ebe2016-02-24 10:13:09 +000046 foreign_dex_profile_path_(foreign_dex_profile_path),
Calin Juravle4d77b6a2015-12-01 18:38:09 +000047 shutting_down_(false),
Calin Juravle85f7bf32016-03-18 16:23:40 +000048 last_save_number_of_methods_(0),
Calin Juravle0cdaa6c2016-03-30 18:18:58 +010049 last_save_number_of_classes_(0),
Calin Juravle5fbb0fe2016-04-29 16:44:11 +010050 last_time_ns_saver_woke_up_(0),
51 jit_activity_notifications_(0),
Calin Juravle4d77b6a2015-12-01 18:38:09 +000052 wait_lock_("ProfileSaver wait lock"),
Calin Juravlec19c1c22016-03-09 15:37:48 +000053 period_condition_("ProfileSaver period condition", wait_lock_),
54 total_bytes_written_(0),
55 total_number_of_writes_(0),
56 total_number_of_code_cache_queries_(0),
57 total_number_of_skipped_writes_(0),
58 total_number_of_failed_writes_(0),
Calin Juravle85f7bf32016-03-18 16:23:40 +000059 total_ms_of_sleep_(0),
Calin Juravlec19c1c22016-03-09 15:37:48 +000060 total_ns_of_work_(0),
Calin Juravle85f7bf32016-03-18 16:23:40 +000061 total_number_of_foreign_dex_marks_(0),
Calin Juravle5fbb0fe2016-04-29 16:44:11 +010062 max_number_of_profile_entries_cached_(0),
63 total_number_of_hot_spikes_(0),
Calin Juravle138dbff2016-06-28 19:36:58 +010064 total_number_of_wake_ups_(0),
65 options_(options) {
66 DCHECK(options_.IsEnabled());
Calin Juravle20ae7932016-04-18 18:59:22 +010067 AddTrackedLocations(output_filename, app_data_dir, code_paths);
Calin Juravle4d77b6a2015-12-01 18:38:09 +000068}
69
70void ProfileSaver::Run() {
Calin Juravle4d77b6a2015-12-01 18:38:09 +000071 Thread* self = Thread::Current();
72
Calin Juravle5fbb0fe2016-04-29 16:44:11 +010073 // Fetch the resolved classes for the app images after sleeping for
Calin Juravle138dbff2016-06-28 19:36:58 +010074 // options_.GetSaveResolvedClassesDelayMs().
Calin Juravle5fbb0fe2016-04-29 16:44:11 +010075 // TODO(calin) This only considers the case of the primary profile file.
76 // Anything that gets loaded in the same VM will not have their resolved
77 // classes save (unless they started before the initial saving was done).
78 {
79 MutexLock mu(self, wait_lock_);
Calin Juravle138dbff2016-06-28 19:36:58 +010080 const uint64_t end_time = NanoTime() + MsToNs(options_.GetSaveResolvedClassesDelayMs());
Mathieu Chartier0ec065d2016-05-18 19:51:23 -070081 while (true) {
82 const uint64_t current_time = NanoTime();
83 if (current_time >= end_time) {
84 break;
85 }
86 period_condition_.TimedWait(self, NsToMs(end_time - current_time), 0);
87 }
Calin Juravle138dbff2016-06-28 19:36:58 +010088 total_ms_of_sleep_ += options_.GetSaveResolvedClassesDelayMs();
Calin Juravle5fbb0fe2016-04-29 16:44:11 +010089 }
Mathieu Chartierc600eaa2016-05-18 08:51:52 -070090 FetchAndCacheResolvedClassesAndMethods();
Calin Juravle5fbb0fe2016-04-29 16:44:11 +010091
92 // Loop for the profiled methods.
Mathieu Chartier8913fc12015-12-09 16:38:30 -080093 while (!ShuttingDown(self)) {
Calin Juravle5fbb0fe2016-04-29 16:44:11 +010094 uint64_t sleep_start = NanoTime();
Calin Juravle4d77b6a2015-12-01 18:38:09 +000095 {
Calin Juravle0233a412016-05-18 15:49:36 -070096 uint64_t sleep_time = 0;
97 {
98 MutexLock mu(self, wait_lock_);
99 period_condition_.Wait(self);
Calin Juravledc85bd72016-05-25 18:09:53 +0100100 sleep_time = NanoTime() - sleep_start;
Calin Juravle0233a412016-05-18 15:49:36 -0700101 }
102 // Check if the thread was woken up for shutdown.
103 if (ShuttingDown(self)) {
104 break;
105 }
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100106 total_number_of_wake_ups_++;
107 // We might have been woken up by a huge number of notifications to guarantee saving.
108 // If we didn't meet the minimum saving period go back to sleep (only if missed by
109 // a reasonable margin).
Calin Juravle138dbff2016-06-28 19:36:58 +0100110 uint64_t min_save_period_ns = MsToNs(options_.GetMinSavePeriodMs());
111 while (min_save_period_ns * 0.9 > sleep_time) {
Calin Juravle0233a412016-05-18 15:49:36 -0700112 {
113 MutexLock mu(self, wait_lock_);
Calin Juravle138dbff2016-06-28 19:36:58 +0100114 period_condition_.TimedWait(self, NsToMs(min_save_period_ns - sleep_time), 0);
Calin Juravledc85bd72016-05-25 18:09:53 +0100115 sleep_time = NanoTime() - sleep_start;
Calin Juravle0233a412016-05-18 15:49:36 -0700116 }
117 // Check if the thread was woken up for shutdown.
118 if (ShuttingDown(self)) {
119 break;
120 }
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100121 total_number_of_wake_ups_++;
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100122 }
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000123 }
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100124 total_ms_of_sleep_ += NsToMs(NanoTime() - sleep_start);
125
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000126 if (ShuttingDown(self)) {
127 break;
128 }
129
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100130 uint16_t new_methods = 0;
131 uint64_t start_work = NanoTime();
132 bool profile_saved_to_disk = ProcessProfilingInfo(&new_methods);
133 // Update the notification counter based on result. Note that there might be contention on this
134 // but we don't care about to be 100% precise.
135 if (!profile_saved_to_disk) {
136 // If we didn't save to disk it may be because we didn't have enough new methods.
137 // Set the jit activity notifications to new_methods so we can wake up earlier if needed.
138 jit_activity_notifications_ = new_methods;
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000139 }
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100140 total_ns_of_work_ += NanoTime() - start_work;
141 }
142}
Calin Juravlec19c1c22016-03-09 15:37:48 +0000143
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100144void ProfileSaver::NotifyJitActivity() {
145 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
146 if (instance_ == nullptr || instance_->shutting_down_) {
147 return;
148 }
149 instance_->NotifyJitActivityInternal();
150}
151
152void ProfileSaver::WakeUpSaver() {
153 jit_activity_notifications_ = 0;
154 last_time_ns_saver_woke_up_ = NanoTime();
155 period_condition_.Signal(Thread::Current());
156}
157
158void ProfileSaver::NotifyJitActivityInternal() {
159 // Unlikely to overflow but if it happens,
160 // we would have waken up the saver long before that.
161 jit_activity_notifications_++;
162 // Note that we are not as precise as we could be here but we don't want to wake the saver
163 // every time we see a hot method.
Calin Juravle138dbff2016-06-28 19:36:58 +0100164 if (jit_activity_notifications_ > options_.GetMinNotificationBeforeWake()) {
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100165 MutexLock wait_mutex(Thread::Current(), wait_lock_);
Calin Juravle138dbff2016-06-28 19:36:58 +0100166 if ((NanoTime() - last_time_ns_saver_woke_up_) > MsToNs(options_.GetMinSavePeriodMs())) {
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100167 WakeUpSaver();
Serguei Katkov87de9cf2016-08-01 17:47:04 +0700168 } else if (jit_activity_notifications_ > options_.GetMaxNotificationBeforeWake()) {
169 // Make sure to wake up the saver if we see a spike in the number of notifications.
170 // This is a precaution to avoid losing a big number of methods in case
171 // this is a spike with no jit after.
172 total_number_of_hot_spikes_++;
173 WakeUpSaver();
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100174 }
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000175 }
176}
177
Calin Juravle85f7bf32016-03-18 16:23:40 +0000178ProfileCompilationInfo* ProfileSaver::GetCachedProfiledInfo(const std::string& filename) {
179 auto info_it = profile_cache_.find(filename);
180 if (info_it == profile_cache_.end()) {
181 info_it = profile_cache_.Put(filename, ProfileCompilationInfo());
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000182 }
Calin Juravle85f7bf32016-03-18 16:23:40 +0000183 return &info_it->second;
184}
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000185
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700186// Get resolved methods that have a profile info or more than kStartupMethodSamples samples.
187// Excludes native methods and classes in the boot image.
188class GetMethodsVisitor : public ClassVisitor {
189 public:
Calin Juravle138dbff2016-06-28 19:36:58 +0100190 GetMethodsVisitor(std::vector<MethodReference>* methods, uint32_t startup_method_samples)
191 : methods_(methods),
192 startup_method_samples_(startup_method_samples) {}
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700193
Mathieu Chartier28357fa2016-10-18 16:27:40 -0700194 virtual bool operator()(ObjPtr<mirror::Class> klass) REQUIRES_SHARED(Locks::mutator_lock_) {
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700195 if (Runtime::Current()->GetHeap()->ObjectIsInBootImageSpace(klass)) {
196 return true;
197 }
Andreas Gampe542451c2016-07-26 09:02:02 -0700198 for (ArtMethod& method : klass->GetMethods(kRuntimePointerSize)) {
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700199 if (!method.IsNative()) {
Calin Juravle138dbff2016-06-28 19:36:58 +0100200 if (method.GetCounter() >= startup_method_samples_ ||
Andreas Gampe542451c2016-07-26 09:02:02 -0700201 method.GetProfilingInfo(kRuntimePointerSize) != nullptr) {
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700202 // Have samples, add to profile.
Andreas Gampe542451c2016-07-26 09:02:02 -0700203 const DexFile* dex_file =
204 method.GetInterfaceMethodIfProxy(kRuntimePointerSize)->GetDexFile();
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700205 methods_->push_back(MethodReference(dex_file, method.GetDexMethodIndex()));
206 }
207 }
208 }
209 return true;
210 }
211
212 private:
213 std::vector<MethodReference>* const methods_;
Calin Juravle138dbff2016-06-28 19:36:58 +0100214 uint32_t startup_method_samples_;
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700215};
216
217void ProfileSaver::FetchAndCacheResolvedClassesAndMethods() {
Calin Juravle85f7bf32016-03-18 16:23:40 +0000218 ScopedTrace trace(__PRETTY_FUNCTION__);
Calin Juravle85f7bf32016-03-18 16:23:40 +0000219 ClassLinker* const class_linker = Runtime::Current()->GetClassLinker();
220 std::set<DexCacheResolvedClasses> resolved_classes =
221 class_linker->GetResolvedClasses(/*ignore boot classes*/ true);
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700222
223 std::vector<MethodReference> methods;
224 {
225 ScopedTrace trace2("Get hot methods");
Calin Juravle138dbff2016-06-28 19:36:58 +0100226 GetMethodsVisitor visitor(&methods, options_.GetStartupMethodSamples());
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700227 ScopedObjectAccess soa(Thread::Current());
228 class_linker->VisitClasses(&visitor);
229 VLOG(profiler) << "Methods with samples greater than "
Calin Juravle138dbff2016-06-28 19:36:58 +0100230 << options_.GetStartupMethodSamples() << " = " << methods.size();
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700231 }
Calin Juravle85f7bf32016-03-18 16:23:40 +0000232 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
233 uint64_t total_number_of_profile_entries_cached = 0;
Mathieu Chartier9275af62016-04-29 12:03:56 -0700234
Calin Juravle85f7bf32016-03-18 16:23:40 +0000235 for (const auto& it : tracked_dex_base_locations_) {
Mathieu Chartier9275af62016-04-29 12:03:56 -0700236 std::set<DexCacheResolvedClasses> resolved_classes_for_location;
Calin Juravle85f7bf32016-03-18 16:23:40 +0000237 const std::string& filename = it.first;
238 const std::set<std::string>& locations = it.second;
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700239 std::vector<MethodReference> methods_for_location;
240 for (const MethodReference& ref : methods) {
241 if (locations.find(ref.dex_file->GetBaseLocation()) != locations.end()) {
242 methods_for_location.push_back(ref);
243 }
244 }
Calin Juravle85f7bf32016-03-18 16:23:40 +0000245 for (const DexCacheResolvedClasses& classes : resolved_classes) {
Mathieu Chartier9275af62016-04-29 12:03:56 -0700246 if (locations.find(classes.GetBaseLocation()) != locations.end()) {
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700247 VLOG(profiler) << "Added " << classes.GetClasses().size() << " classes for location "
248 << classes.GetBaseLocation() << " (" << classes.GetDexLocation() << ")";
Calin Juravle85f7bf32016-03-18 16:23:40 +0000249 resolved_classes_for_location.insert(classes);
Mathieu Chartier9275af62016-04-29 12:03:56 -0700250 } else {
251 VLOG(profiler) << "Location not found " << classes.GetBaseLocation()
252 << " (" << classes.GetDexLocation() << ")";
Calin Juravle85f7bf32016-03-18 16:23:40 +0000253 }
254 }
255 ProfileCompilationInfo* info = GetCachedProfiledInfo(filename);
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700256 info->AddMethodsAndClasses(methods_for_location, resolved_classes_for_location);
Calin Juravle85f7bf32016-03-18 16:23:40 +0000257 total_number_of_profile_entries_cached += resolved_classes_for_location.size();
258 }
259 max_number_of_profile_entries_cached_ = std::max(
260 max_number_of_profile_entries_cached_,
261 total_number_of_profile_entries_cached);
262}
263
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100264bool ProfileSaver::ProcessProfilingInfo(uint16_t* new_methods) {
Calin Juravle85f7bf32016-03-18 16:23:40 +0000265 ScopedTrace trace(__PRETTY_FUNCTION__);
Calin Juravleb4eddd22016-01-13 15:52:33 -0800266 SafeMap<std::string, std::set<std::string>> tracked_locations;
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000267 {
Calin Juravleb4eddd22016-01-13 15:52:33 -0800268 // Make a copy so that we don't hold the lock while doing I/O.
269 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
270 tracked_locations = tracked_dex_base_locations_;
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000271 }
Calin Juravlec15e5662016-03-17 17:07:52 +0000272
Calin Juravle85f7bf32016-03-18 16:23:40 +0000273 bool profile_file_saved = false;
274 uint64_t total_number_of_profile_entries_cached = 0;
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100275 *new_methods = 0;
276
Calin Juravleb4eddd22016-01-13 15:52:33 -0800277 for (const auto& it : tracked_locations) {
278 if (ShuttingDown(Thread::Current())) {
279 return true;
280 }
281 const std::string& filename = it.first;
282 const std::set<std::string>& locations = it.second;
Calin Juravlee2d066d2016-04-19 16:33:46 +0100283 std::vector<MethodReference> methods;
Calin Juravleb4eddd22016-01-13 15:52:33 -0800284 {
285 ScopedObjectAccess soa(Thread::Current());
Calin Juravlee2d066d2016-04-19 16:33:46 +0100286 jit_code_cache_->GetProfiledMethods(locations, methods);
Calin Juravlec19c1c22016-03-09 15:37:48 +0000287 total_number_of_code_cache_queries_++;
Calin Juravleb4eddd22016-01-13 15:52:33 -0800288 }
Calin Juravlec15e5662016-03-17 17:07:52 +0000289
Calin Juravle85f7bf32016-03-18 16:23:40 +0000290 ProfileCompilationInfo* cached_info = GetCachedProfiledInfo(filename);
291 cached_info->AddMethodsAndClasses(methods, std::set<DexCacheResolvedClasses>());
Calin Juravle0cdaa6c2016-03-30 18:18:58 +0100292 int64_t delta_number_of_methods =
293 cached_info->GetNumberOfMethods() -
294 static_cast<int64_t>(last_save_number_of_methods_);
295 int64_t delta_number_of_classes =
296 cached_info->GetNumberOfResolvedClasses() -
297 static_cast<int64_t>(last_save_number_of_classes_);
Calin Juravle85f7bf32016-03-18 16:23:40 +0000298
Calin Juravle138dbff2016-06-28 19:36:58 +0100299 if (delta_number_of_methods < options_.GetMinMethodsToSave() &&
300 delta_number_of_classes < options_.GetMinClassesToSave()) {
Calin Juravle0cdaa6c2016-03-30 18:18:58 +0100301 VLOG(profiler) << "Not enough information to save to: " << filename
Calin Juravle138dbff2016-06-28 19:36:58 +0100302 << " Number of methods: " << delta_number_of_methods
303 << " Number of classes: " << delta_number_of_classes;
Calin Juravlec19c1c22016-03-09 15:37:48 +0000304 total_number_of_skipped_writes_++;
Calin Juravle85f7bf32016-03-18 16:23:40 +0000305 continue;
Calin Juravleb4eddd22016-01-13 15:52:33 -0800306 }
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100307 *new_methods = std::max(static_cast<uint16_t>(delta_number_of_methods), *new_methods);
Calin Juravlec19c1c22016-03-09 15:37:48 +0000308 uint64_t bytes_written;
Calin Juravlefe297a92016-03-24 20:33:22 +0000309 // Force the save. In case the profile data is corrupted or the the profile
310 // has the wrong version this will "fix" the file to the correct format.
311 if (cached_info->MergeAndSave(filename, &bytes_written, /*force*/ true)) {
Calin Juravle85f7bf32016-03-18 16:23:40 +0000312 last_save_number_of_methods_ = cached_info->GetNumberOfMethods();
Calin Juravle0cdaa6c2016-03-30 18:18:58 +0100313 last_save_number_of_classes_ = cached_info->GetNumberOfResolvedClasses();
Calin Juravle85f7bf32016-03-18 16:23:40 +0000314 // Clear resolved classes. No need to store them around as
315 // they don't change after the first write.
316 cached_info->ClearResolvedClasses();
Calin Juravlec19c1c22016-03-09 15:37:48 +0000317 if (bytes_written > 0) {
318 total_number_of_writes_++;
319 total_bytes_written_ += bytes_written;
Calin Juravle0cdaa6c2016-03-30 18:18:58 +0100320 profile_file_saved = true;
Calin Juravle85f7bf32016-03-18 16:23:40 +0000321 } else {
322 // At this point we could still have avoided the write.
323 // We load and merge the data from the file lazily at its first ever
324 // save attempt. So, whatever we are trying to save could already be
325 // in the file.
326 total_number_of_skipped_writes_++;
Calin Juravlec19c1c22016-03-09 15:37:48 +0000327 }
Calin Juravle85f7bf32016-03-18 16:23:40 +0000328 } else {
329 LOG(WARNING) << "Could not save profiling info to " << filename;
330 total_number_of_failed_writes_++;
Calin Juravleb4eddd22016-01-13 15:52:33 -0800331 }
Calin Juravle85f7bf32016-03-18 16:23:40 +0000332 total_number_of_profile_entries_cached +=
333 cached_info->GetNumberOfMethods() +
334 cached_info->GetNumberOfResolvedClasses();
Calin Juravleb4eddd22016-01-13 15:52:33 -0800335 }
Calin Juravle85f7bf32016-03-18 16:23:40 +0000336 max_number_of_profile_entries_cached_ = std::max(
337 max_number_of_profile_entries_cached_,
338 total_number_of_profile_entries_cached);
339 return profile_file_saved;
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000340}
341
342void* ProfileSaver::RunProfileSaverThread(void* arg) {
343 Runtime* runtime = Runtime::Current();
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000344
Calin Juravlee55fda12016-04-28 12:59:33 +0100345 bool attached = runtime->AttachCurrentThread("Profile Saver",
346 /*as_daemon*/true,
347 runtime->GetSystemThreadGroup(),
348 /*create_peer*/true);
349 if (!attached) {
350 CHECK(runtime->IsShuttingDown(Thread::Current()));
351 return nullptr;
352 }
353
354 ProfileSaver* profile_saver = reinterpret_cast<ProfileSaver*>(arg);
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000355 profile_saver->Run();
356
357 runtime->DetachCurrentThread();
358 VLOG(profiler) << "Profile saver shutdown";
359 return nullptr;
360}
361
Calin Juravle6044fa72016-03-25 17:17:09 +0000362static bool ShouldProfileLocation(const std::string& location) {
Calin Juravle75064232016-04-18 16:38:27 +0100363 OatFileManager& oat_manager = Runtime::Current()->GetOatFileManager();
364 const OatFile* oat_file = oat_manager.FindOpenedOatFileFromDexLocation(location);
Calin Juravle6044fa72016-03-25 17:17:09 +0000365 if (oat_file == nullptr) {
366 // This can happen if we fallback to run code directly from the APK.
367 // Profile it with the hope that the background dexopt will get us back into
368 // a good state.
Calin Juravle75064232016-04-18 16:38:27 +0100369 VLOG(profiler) << "Asked to profile a location without an oat file:" << location;
Calin Juravle6044fa72016-03-25 17:17:09 +0000370 return true;
371 }
372 CompilerFilter::Filter filter = oat_file->GetCompilerFilter();
Calin Juravled19dc462016-04-19 18:17:41 +0100373 if ((filter == CompilerFilter::kSpeed) || (filter == CompilerFilter::kEverything)) {
Calin Juravle75064232016-04-18 16:38:27 +0100374 VLOG(profiler)
Calin Juravled19dc462016-04-19 18:17:41 +0100375 << "Skip profiling oat file because it's already speed|everything compiled: "
376 << location << " oat location: " << oat_file->GetLocation();
Calin Juravle6044fa72016-03-25 17:17:09 +0000377 return false;
378 }
379 return true;
380}
381
Calin Juravle138dbff2016-06-28 19:36:58 +0100382void ProfileSaver::Start(const ProfileSaverOptions& options,
383 const std::string& output_filename,
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000384 jit::JitCodeCache* jit_code_cache,
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000385 const std::vector<std::string>& code_paths,
386 const std::string& foreign_dex_profile_path,
387 const std::string& app_data_dir) {
Calin Juravle138dbff2016-06-28 19:36:58 +0100388 DCHECK(options.IsEnabled());
389 DCHECK(Runtime::Current()->GetJit() != nullptr);
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000390 DCHECK(!output_filename.empty());
391 DCHECK(jit_code_cache != nullptr);
392
Calin Juravle6044fa72016-03-25 17:17:09 +0000393 std::vector<std::string> code_paths_to_profile;
394
395 for (const std::string& location : code_paths) {
396 if (ShouldProfileLocation(location)) {
397 code_paths_to_profile.push_back(location);
Calin Juravle6044fa72016-03-25 17:17:09 +0000398 }
399 }
400 if (code_paths_to_profile.empty()) {
Calin Juravle75064232016-04-18 16:38:27 +0100401 VLOG(profiler) << "No code paths should be profiled.";
Calin Juravle6044fa72016-03-25 17:17:09 +0000402 return;
403 }
404
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000405 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000406 if (instance_ != nullptr) {
Calin Juravleb4eddd22016-01-13 15:52:33 -0800407 // If we already have an instance, make sure it uses the same jit_code_cache.
408 // This may be called multiple times via Runtime::registerAppInfo (e.g. for
409 // apps which share the same runtime).
410 DCHECK_EQ(instance_->jit_code_cache_, jit_code_cache);
411 // Add the code_paths to the tracked locations.
Calin Juravle20ae7932016-04-18 18:59:22 +0100412 instance_->AddTrackedLocations(output_filename, app_data_dir, code_paths_to_profile);
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000413 return;
414 }
415
416 VLOG(profiler) << "Starting profile saver using output file: " << output_filename
Andreas Gampe9186ced2016-12-12 14:28:21 -0800417 << ". Tracking: " << android::base::Join(code_paths_to_profile, ':');
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000418
Calin Juravle138dbff2016-06-28 19:36:58 +0100419 instance_ = new ProfileSaver(options,
420 output_filename,
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000421 jit_code_cache,
Calin Juravle75064232016-04-18 16:38:27 +0100422 code_paths_to_profile,
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000423 foreign_dex_profile_path,
424 app_data_dir);
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000425
426 // Create a new thread which does the saving.
427 CHECK_PTHREAD_CALL(
428 pthread_create,
429 (&profiler_pthread_, nullptr, &RunProfileSaverThread, reinterpret_cast<void*>(instance_)),
430 "Profile saver thread");
431}
432
Calin Juravlec19c1c22016-03-09 15:37:48 +0000433void ProfileSaver::Stop(bool dump_info) {
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000434 ProfileSaver* profile_saver = nullptr;
435 pthread_t profiler_pthread = 0U;
436
437 {
438 MutexLock profiler_mutex(Thread::Current(), *Locks::profiler_lock_);
Calin Juravleb4eddd22016-01-13 15:52:33 -0800439 VLOG(profiler) << "Stopping profile saver thread";
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000440 profile_saver = instance_;
441 profiler_pthread = profiler_pthread_;
442 if (instance_ == nullptr) {
443 DCHECK(false) << "Tried to stop a profile saver which was not started";
444 return;
445 }
446 if (instance_->shutting_down_) {
447 DCHECK(false) << "Tried to stop the profile saver twice";
448 return;
449 }
450 instance_->shutting_down_ = true;
Calin Juravlec19c1c22016-03-09 15:37:48 +0000451 if (dump_info) {
Andreas Gampe3fec9ac2016-09-13 10:47:28 -0700452 instance_->DumpInfo(LOG_STREAM(INFO));
Calin Juravlec19c1c22016-03-09 15:37:48 +0000453 }
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000454 }
455
456 {
457 // Wake up the saver thread if it is sleeping to allow for a clean exit.
458 MutexLock wait_mutex(Thread::Current(), profile_saver->wait_lock_);
459 profile_saver->period_condition_.Signal(Thread::Current());
460 }
461
462 // Wait for the saver thread to stop.
463 CHECK_PTHREAD_CALL(pthread_join, (profiler_pthread, nullptr), "profile saver thread shutdown");
464
465 {
466 MutexLock profiler_mutex(Thread::Current(), *Locks::profiler_lock_);
467 instance_ = nullptr;
468 profiler_pthread_ = 0U;
469 }
470 delete profile_saver;
471}
472
473bool ProfileSaver::ShuttingDown(Thread* self) {
474 MutexLock mu(self, *Locks::profiler_lock_);
475 return shutting_down_;
476}
477
478bool ProfileSaver::IsStarted() {
479 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
480 return instance_ != nullptr;
481}
482
Calin Juravleb4eddd22016-01-13 15:52:33 -0800483void ProfileSaver::AddTrackedLocations(const std::string& output_filename,
Calin Juravle20ae7932016-04-18 18:59:22 +0100484 const std::string& app_data_dir,
Calin Juravleb4eddd22016-01-13 15:52:33 -0800485 const std::vector<std::string>& code_paths) {
486 auto it = tracked_dex_base_locations_.find(output_filename);
487 if (it == tracked_dex_base_locations_.end()) {
488 tracked_dex_base_locations_.Put(output_filename,
489 std::set<std::string>(code_paths.begin(), code_paths.end()));
Calin Juravle655c3c32016-05-25 16:45:16 +0100490 if (!app_data_dir.empty()) {
491 app_data_dirs_.insert(app_data_dir);
492 }
Calin Juravleb4eddd22016-01-13 15:52:33 -0800493 } else {
494 it->second.insert(code_paths.begin(), code_paths.end());
495 }
496}
497
Calin Juravle655c3c32016-05-25 16:45:16 +0100498// TODO(calin): This may lead to several calls to realpath.
499// Consider moving the logic to the saver thread (i.e. when notified,
500// only cache the location, and then wake up the saver thread to do the
501// comparisons with the real file paths and to create the markers).
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000502void ProfileSaver::NotifyDexUse(const std::string& dex_location) {
Calin Juravle6044fa72016-03-25 17:17:09 +0000503 if (!ShouldProfileLocation(dex_location)) {
504 return;
505 }
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000506 std::set<std::string> app_code_paths;
507 std::string foreign_dex_profile_path;
Calin Juravle20ae7932016-04-18 18:59:22 +0100508 std::set<std::string> app_data_dirs;
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000509 {
510 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
Calin Juravlec19c1c22016-03-09 15:37:48 +0000511 if (instance_ == nullptr) {
512 return;
513 }
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000514 // Make a copy so that we don't hold the lock while doing I/O.
515 for (const auto& it : instance_->tracked_dex_base_locations_) {
516 app_code_paths.insert(it.second.begin(), it.second.end());
517 }
518 foreign_dex_profile_path = instance_->foreign_dex_profile_path_;
Calin Juravle20ae7932016-04-18 18:59:22 +0100519 app_data_dirs.insert(instance_->app_data_dirs_.begin(), instance_->app_data_dirs_.end());
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000520 }
521
Calin Juravlec19c1c22016-03-09 15:37:48 +0000522 bool mark_created = MaybeRecordDexUseInternal(dex_location,
523 app_code_paths,
524 foreign_dex_profile_path,
Calin Juravle20ae7932016-04-18 18:59:22 +0100525 app_data_dirs);
Calin Juravlec19c1c22016-03-09 15:37:48 +0000526 if (mark_created) {
527 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
528 if (instance_ != nullptr) {
529 instance_->total_number_of_foreign_dex_marks_++;
530 }
531 }
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000532}
533
Calin Juravle655c3c32016-05-25 16:45:16 +0100534static bool CheckContainsWithRealPath(const std::set<std::string>& paths_set,
535 const std::string& path_to_check) {
536 for (const auto& path : paths_set) {
537 UniqueCPtr<const char[]> real_path(realpath(path.c_str(), nullptr));
538 if (real_path == nullptr) {
539 PLOG(WARNING) << "Could not get realpath for " << path;
540 continue;
Calin Juravle1fae45f2016-03-08 12:52:52 +0000541 }
Calin Juravle655c3c32016-05-25 16:45:16 +0100542 std::string real_path_str(real_path.get());
543 if (real_path_str == path_to_check) {
544 return true;
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000545 }
546 }
Calin Juravle655c3c32016-05-25 16:45:16 +0100547 return false;
548}
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000549
Calin Juravle655c3c32016-05-25 16:45:16 +0100550// After the call, dex_location_real_path will contain the marker's name.
551static bool CreateForeignDexMarker(const std::string& foreign_dex_profile_path,
552 /*in-out*/ std::string* dex_location_real_path) {
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000553 // For foreign dex files we record a flag on disk. PackageManager will (potentially) take this
554 // into account when deciding how to optimize the loaded dex file.
555 // The expected flag name is the canonical path of the apk where '/' is substituted to '@'.
556 // (it needs to be kept in sync with
557 // frameworks/base/services/core/java/com/android/server/pm/PackageDexOptimizer.java)
Calin Juravle655c3c32016-05-25 16:45:16 +0100558 std::replace(dex_location_real_path->begin(), dex_location_real_path->end(), '/', '@');
559 std::string flag_path = foreign_dex_profile_path + "/" + *dex_location_real_path;
Richard Uhler12e41572016-05-10 14:01:18 -0700560 // We use O_RDONLY as the access mode because we must supply some access
561 // mode, and there is no access mode that means 'create but do not read' the
562 // file. We will not not actually read from the file.
563 int fd = TEMP_FAILURE_RETRY(open(flag_path.c_str(),
564 O_CREAT | O_RDONLY | O_EXCL | O_CLOEXEC | O_NOFOLLOW, 0));
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000565 if (fd != -1) {
566 if (close(fd) != 0) {
567 PLOG(WARNING) << "Could not close file after flagging foreign dex use " << flag_path;
568 }
Calin Juravlec19c1c22016-03-09 15:37:48 +0000569 return true;
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000570 } else {
Richard Uhler12e41572016-05-10 14:01:18 -0700571 if (errno != EEXIST && errno != EACCES) {
572 // Another app could have already created the file, and selinux may not
573 // allow the read access to the file implied by the call to open.
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000574 PLOG(WARNING) << "Could not create foreign dex use mark " << flag_path;
Calin Juravlec19c1c22016-03-09 15:37:48 +0000575 return false;
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000576 }
Calin Juravlec19c1c22016-03-09 15:37:48 +0000577 return true;
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000578 }
579}
580
Calin Juravle655c3c32016-05-25 16:45:16 +0100581bool ProfileSaver::MaybeRecordDexUseInternal(
582 const std::string& dex_location,
583 const std::set<std::string>& app_code_paths,
584 const std::string& foreign_dex_profile_path,
585 const std::set<std::string>& app_data_dirs) {
586 if (dex_location.empty()) {
587 LOG(WARNING) << "Asked to record foreign dex use with an empty dex location.";
588 return false;
589 }
590 if (foreign_dex_profile_path.empty()) {
591 LOG(WARNING) << "Asked to record foreign dex use without a valid profile path ";
592 return false;
593 }
594
595 if (app_code_paths.find(dex_location) != app_code_paths.end()) {
596 // The dex location belongs to the application code paths. Nothing to record.
597 return false;
598 }
599
600 if (app_data_dirs.find(dex_location) != app_data_dirs.end()) {
601 // The dex location is under the application folder. Nothing to record.
602 return false;
603 }
604
605 // Do another round of checks with the real paths.
606 // Application directory could be a symlink (e.g. /data/data instead of /data/user/0), and we
607 // don't have control over how the dex files are actually loaded (symlink or canonical path),
608
609 // Note that we could cache all the real locations in the saver (since it's an expensive
610 // operation). However we expect that app_code_paths is small (usually 1 element), and
611 // NotifyDexUse is called just a few times in the app lifetime. So we make the compromise
612 // to save some bytes of memory usage.
613
614 UniqueCPtr<const char[]> dex_location_real_path(realpath(dex_location.c_str(), nullptr));
615 if (dex_location_real_path == nullptr) {
616 PLOG(WARNING) << "Could not get realpath for " << dex_location;
617 return false;
618 }
619 std::string dex_location_real_path_str(dex_location_real_path.get());
620
621 if (CheckContainsWithRealPath(app_code_paths, dex_location_real_path_str)) {
622 return false;
623 }
624
625 if (CheckContainsWithRealPath(app_data_dirs, dex_location_real_path_str)) {
626 return false;
627 }
628
629 return CreateForeignDexMarker(foreign_dex_profile_path, &dex_location_real_path_str);
630}
631
Calin Juravlec19c1c22016-03-09 15:37:48 +0000632void ProfileSaver::DumpInstanceInfo(std::ostream& os) {
633 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
634 if (instance_ != nullptr) {
635 instance_->DumpInfo(os);
636 }
637}
638
639void ProfileSaver::DumpInfo(std::ostream& os) {
640 os << "ProfileSaver total_bytes_written=" << total_bytes_written_ << '\n'
641 << "ProfileSaver total_number_of_writes=" << total_number_of_writes_ << '\n'
Calin Juravle85f7bf32016-03-18 16:23:40 +0000642 << "ProfileSaver total_number_of_code_cache_queries="
643 << total_number_of_code_cache_queries_ << '\n'
Calin Juravlec19c1c22016-03-09 15:37:48 +0000644 << "ProfileSaver total_number_of_skipped_writes=" << total_number_of_skipped_writes_ << '\n'
645 << "ProfileSaver total_number_of_failed_writes=" << total_number_of_failed_writes_ << '\n'
Calin Juravle85f7bf32016-03-18 16:23:40 +0000646 << "ProfileSaver total_ms_of_sleep=" << total_ms_of_sleep_ << '\n'
Calin Juravle6044fa72016-03-25 17:17:09 +0000647 << "ProfileSaver total_ms_of_work=" << NsToMs(total_ns_of_work_) << '\n'
Calin Juravle85f7bf32016-03-18 16:23:40 +0000648 << "ProfileSaver total_number_of_foreign_dex_marks="
649 << total_number_of_foreign_dex_marks_ << '\n'
650 << "ProfileSaver max_number_profile_entries_cached="
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100651 << max_number_of_profile_entries_cached_ << '\n'
652 << "ProfileSaver total_number_of_hot_spikes=" << total_number_of_hot_spikes_ << '\n'
653 << "ProfileSaver total_number_of_wake_ups=" << total_number_of_wake_ups_ << '\n';
Calin Juravlec19c1c22016-03-09 15:37:48 +0000654}
655
Calin Juravlee5de54c2016-04-20 14:22:09 +0100656
657void ProfileSaver::ForceProcessProfiles() {
658 ProfileSaver* saver = nullptr;
659 {
660 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
661 saver = instance_;
662 }
663 // TODO(calin): this is not actually thread safe as the instance_ may have been deleted,
664 // but we only use this in testing when we now this won't happen.
665 // Refactor the way we handle the instance so that we don't end up in this situation.
666 if (saver != nullptr) {
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100667 uint16_t new_methods;
668 saver->ProcessProfilingInfo(&new_methods);
Calin Juravlee5de54c2016-04-20 14:22:09 +0100669 }
670}
671
672bool ProfileSaver::HasSeenMethod(const std::string& profile,
673 const DexFile* dex_file,
674 uint16_t method_idx) {
675 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
676 if (instance_ != nullptr) {
677 ProfileCompilationInfo* info = instance_->GetCachedProfiledInfo(profile);
678 if (info != nullptr) {
679 return info->ContainsMethod(MethodReference(dex_file, method_idx));
680 }
681 }
682 return false;
683}
684
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000685} // namespace art