blob: 4d4d1ea7c657f69427cf50d42d561fd6c2186a49 [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 Juravlec90bc922016-02-24 10:13:09 +000019#include <sys/types.h>
20#include <sys/stat.h>
21#include <fcntl.h>
22
Calin Juravle4d77b6a2015-12-01 18:38:09 +000023#include "art_method-inl.h"
Mathieu Chartier32ce2ad2016-03-04 14:58:03 -080024#include "base/systrace.h"
Calin Juravle050fb1b2016-03-25 17:17:09 +000025#include "base/time_utils.h"
26#include "compiler_filter.h"
Calin Juravle4d77b6a2015-12-01 18:38:09 +000027#include "oat_file_manager.h"
Calin Juravle050fb1b2016-03-25 17:17:09 +000028#include "scoped_thread_state_change.h"
29
Calin Juravle4d77b6a2015-12-01 18:38:09 +000030
31namespace art {
32
Calin Juravle4d77b6a2015-12-01 18:38:09 +000033ProfileSaver* ProfileSaver::instance_ = nullptr;
34pthread_t ProfileSaver::profiler_pthread_ = 0U;
35
Calin Juravle138dbff2016-06-28 19:36:58 +010036ProfileSaver::ProfileSaver(const ProfileSaverOptions& options,
37 const std::string& output_filename,
Calin Juravle4d77b6a2015-12-01 18:38:09 +000038 jit::JitCodeCache* jit_code_cache,
Calin Juravlec90bc922016-02-24 10:13:09 +000039 const std::vector<std::string>& code_paths,
40 const std::string& foreign_dex_profile_path,
41 const std::string& app_data_dir)
Calin Juravleb4eddd22016-01-13 15:52:33 -080042 : jit_code_cache_(jit_code_cache),
Calin Juravlec90bc922016-02-24 10:13:09 +000043 foreign_dex_profile_path_(foreign_dex_profile_path),
Calin Juravle4d77b6a2015-12-01 18:38:09 +000044 shutting_down_(false),
Calin Juravle67265462016-03-18 16:23:40 +000045 last_save_number_of_methods_(0),
Calin Juravle698f4d12016-03-30 18:18:58 +010046 last_save_number_of_classes_(0),
Calin Juravlea2638922016-04-29 16:44:11 +010047 last_time_ns_saver_woke_up_(0),
48 jit_activity_notifications_(0),
Calin Juravle4d77b6a2015-12-01 18:38:09 +000049 wait_lock_("ProfileSaver wait lock"),
Calin Juravleb8e69992016-03-09 15:37:48 +000050 period_condition_("ProfileSaver period condition", wait_lock_),
51 total_bytes_written_(0),
52 total_number_of_writes_(0),
53 total_number_of_code_cache_queries_(0),
54 total_number_of_skipped_writes_(0),
55 total_number_of_failed_writes_(0),
Calin Juravle67265462016-03-18 16:23:40 +000056 total_ms_of_sleep_(0),
Calin Juravleb8e69992016-03-09 15:37:48 +000057 total_ns_of_work_(0),
Calin Juravle67265462016-03-18 16:23:40 +000058 total_number_of_foreign_dex_marks_(0),
Calin Juravlea2638922016-04-29 16:44:11 +010059 max_number_of_profile_entries_cached_(0),
60 total_number_of_hot_spikes_(0),
Calin Juravle138dbff2016-06-28 19:36:58 +010061 total_number_of_wake_ups_(0),
62 options_(options) {
63 DCHECK(options_.IsEnabled());
Calin Juravle20b7e3b2016-04-18 18:59:22 +010064 AddTrackedLocations(output_filename, app_data_dir, code_paths);
Calin Juravlec90bc922016-02-24 10:13:09 +000065 if (!app_data_dir.empty()) {
66 // The application directory is used to determine which dex files are owned by app.
67 // Since it could be a symlink (e.g. /data/data instead of /data/user/0), and we
68 // don't have control over how the dex files are actually loaded (symlink or canonical path),
69 // store it's canonical form to be sure we use the same base when comparing.
70 UniqueCPtr<const char[]> app_data_dir_real_path(realpath(app_data_dir.c_str(), nullptr));
71 if (app_data_dir_real_path != nullptr) {
Calin Juravle20b7e3b2016-04-18 18:59:22 +010072 app_data_dirs_.emplace(app_data_dir_real_path.get());
Calin Juravlec90bc922016-02-24 10:13:09 +000073 } else {
Calin Juravle20b7e3b2016-04-18 18:59:22 +010074 LOG(WARNING) << "Failed to get the real path for app dir: " << app_data_dir
Calin Juravlec90bc922016-02-24 10:13:09 +000075 << ". The app dir will not be used to determine which dex files belong to the app";
76 }
77 }
Calin Juravle4d77b6a2015-12-01 18:38:09 +000078}
79
80void ProfileSaver::Run() {
Calin Juravle4d77b6a2015-12-01 18:38:09 +000081 Thread* self = Thread::Current();
82
Calin Juravlea2638922016-04-29 16:44:11 +010083 // Fetch the resolved classes for the app images after sleeping for
Calin Juravle138dbff2016-06-28 19:36:58 +010084 // options_.GetSaveResolvedClassesDelayMs().
Calin Juravlea2638922016-04-29 16:44:11 +010085 // TODO(calin) This only considers the case of the primary profile file.
86 // Anything that gets loaded in the same VM will not have their resolved
87 // classes save (unless they started before the initial saving was done).
88 {
89 MutexLock mu(self, wait_lock_);
Calin Juravle138dbff2016-06-28 19:36:58 +010090 const uint64_t end_time = NanoTime() + MsToNs(options_.GetSaveResolvedClassesDelayMs());
Mathieu Chartiera57305e2016-05-18 19:51:23 -070091 while (true) {
92 const uint64_t current_time = NanoTime();
93 if (current_time >= end_time) {
94 break;
95 }
96 period_condition_.TimedWait(self, NsToMs(end_time - current_time), 0);
97 }
Calin Juravle138dbff2016-06-28 19:36:58 +010098 total_ms_of_sleep_ += options_.GetSaveResolvedClassesDelayMs();
Calin Juravlea2638922016-04-29 16:44:11 +010099 }
Mathieu Chartier27ed3a42016-05-18 08:51:52 -0700100 FetchAndCacheResolvedClassesAndMethods();
Calin Juravlea2638922016-04-29 16:44:11 +0100101
102 // Loop for the profiled methods.
Mathieu Chartierc5dd3192015-12-09 16:38:30 -0800103 while (!ShuttingDown(self)) {
Calin Juravlea2638922016-04-29 16:44:11 +0100104 uint64_t sleep_start = NanoTime();
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000105 {
Calin Juravle8fbea8e2016-05-18 15:49:36 -0700106 uint64_t sleep_time = 0;
107 {
108 MutexLock mu(self, wait_lock_);
109 period_condition_.Wait(self);
Calin Juravle5d04eb62016-05-25 18:09:53 +0100110 sleep_time = NanoTime() - sleep_start;
Calin Juravle8fbea8e2016-05-18 15:49:36 -0700111 }
112 // Check if the thread was woken up for shutdown.
113 if (ShuttingDown(self)) {
114 break;
115 }
Calin Juravlea2638922016-04-29 16:44:11 +0100116 total_number_of_wake_ups_++;
117 // We might have been woken up by a huge number of notifications to guarantee saving.
118 // If we didn't meet the minimum saving period go back to sleep (only if missed by
119 // a reasonable margin).
Calin Juravle138dbff2016-06-28 19:36:58 +0100120 uint64_t min_save_period_ns = MsToNs(options_.GetMinSavePeriodMs());
121 while (min_save_period_ns * 0.9 > sleep_time) {
Calin Juravle8fbea8e2016-05-18 15:49:36 -0700122 {
123 MutexLock mu(self, wait_lock_);
Calin Juravle138dbff2016-06-28 19:36:58 +0100124 period_condition_.TimedWait(self, NsToMs(min_save_period_ns - sleep_time), 0);
Calin Juravle5d04eb62016-05-25 18:09:53 +0100125 sleep_time = NanoTime() - sleep_start;
Calin Juravle8fbea8e2016-05-18 15:49:36 -0700126 }
127 // Check if the thread was woken up for shutdown.
128 if (ShuttingDown(self)) {
129 break;
130 }
Calin Juravlea2638922016-04-29 16:44:11 +0100131 total_number_of_wake_ups_++;
Calin Juravlea2638922016-04-29 16:44:11 +0100132 }
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000133 }
Calin Juravlea2638922016-04-29 16:44:11 +0100134 total_ms_of_sleep_ += NsToMs(NanoTime() - sleep_start);
135
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000136 if (ShuttingDown(self)) {
137 break;
138 }
139
Calin Juravlea2638922016-04-29 16:44:11 +0100140 uint16_t new_methods = 0;
141 uint64_t start_work = NanoTime();
142 bool profile_saved_to_disk = ProcessProfilingInfo(&new_methods);
143 // Update the notification counter based on result. Note that there might be contention on this
144 // but we don't care about to be 100% precise.
145 if (!profile_saved_to_disk) {
146 // If we didn't save to disk it may be because we didn't have enough new methods.
147 // Set the jit activity notifications to new_methods so we can wake up earlier if needed.
148 jit_activity_notifications_ = new_methods;
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000149 }
Calin Juravlea2638922016-04-29 16:44:11 +0100150 total_ns_of_work_ += NanoTime() - start_work;
151 }
152}
Calin Juravleb8e69992016-03-09 15:37:48 +0000153
Calin Juravlea2638922016-04-29 16:44:11 +0100154void ProfileSaver::NotifyJitActivity() {
155 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
156 if (instance_ == nullptr || instance_->shutting_down_) {
157 return;
158 }
159 instance_->NotifyJitActivityInternal();
160}
161
162void ProfileSaver::WakeUpSaver() {
163 jit_activity_notifications_ = 0;
164 last_time_ns_saver_woke_up_ = NanoTime();
165 period_condition_.Signal(Thread::Current());
166}
167
168void ProfileSaver::NotifyJitActivityInternal() {
169 // Unlikely to overflow but if it happens,
170 // we would have waken up the saver long before that.
171 jit_activity_notifications_++;
172 // Note that we are not as precise as we could be here but we don't want to wake the saver
173 // every time we see a hot method.
Calin Juravle138dbff2016-06-28 19:36:58 +0100174 if (jit_activity_notifications_ > options_.GetMinNotificationBeforeWake()) {
Calin Juravlea2638922016-04-29 16:44:11 +0100175 MutexLock wait_mutex(Thread::Current(), wait_lock_);
Calin Juravle138dbff2016-06-28 19:36:58 +0100176 if ((NanoTime() - last_time_ns_saver_woke_up_) > MsToNs(options_.GetMinSavePeriodMs())) {
Calin Juravlea2638922016-04-29 16:44:11 +0100177 WakeUpSaver();
178 }
Calin Juravle138dbff2016-06-28 19:36:58 +0100179 } else if (jit_activity_notifications_ > options_.GetMaxNotificationBeforeWake()) {
Calin Juravlea2638922016-04-29 16:44:11 +0100180 // Make sure to wake up the saver if we see a spike in the number of notifications.
181 // This is a precaution to avoid "loosing" a big number of methods in case
182 // this is a spike with no jit after.
183 total_number_of_hot_spikes_++;
184 MutexLock wait_mutex(Thread::Current(), wait_lock_);
185 WakeUpSaver();
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000186 }
187}
188
Calin Juravle67265462016-03-18 16:23:40 +0000189ProfileCompilationInfo* ProfileSaver::GetCachedProfiledInfo(const std::string& filename) {
190 auto info_it = profile_cache_.find(filename);
191 if (info_it == profile_cache_.end()) {
192 info_it = profile_cache_.Put(filename, ProfileCompilationInfo());
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000193 }
Calin Juravle67265462016-03-18 16:23:40 +0000194 return &info_it->second;
195}
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000196
Mathieu Chartier27ed3a42016-05-18 08:51:52 -0700197// Get resolved methods that have a profile info or more than kStartupMethodSamples samples.
198// Excludes native methods and classes in the boot image.
199class GetMethodsVisitor : public ClassVisitor {
200 public:
Calin Juravle138dbff2016-06-28 19:36:58 +0100201 GetMethodsVisitor(std::vector<MethodReference>* methods, uint32_t startup_method_samples)
202 : methods_(methods),
203 startup_method_samples_(startup_method_samples) {}
Mathieu Chartier27ed3a42016-05-18 08:51:52 -0700204
205 virtual bool operator()(mirror::Class* klass) SHARED_REQUIRES(Locks::mutator_lock_) {
206 if (Runtime::Current()->GetHeap()->ObjectIsInBootImageSpace(klass)) {
207 return true;
208 }
209 for (ArtMethod& method : klass->GetMethods(sizeof(void*))) {
210 if (!method.IsNative()) {
Calin Juravle138dbff2016-06-28 19:36:58 +0100211 if (method.GetCounter() >= startup_method_samples_ ||
Mathieu Chartier27ed3a42016-05-18 08:51:52 -0700212 method.GetProfilingInfo(sizeof(void*)) != nullptr) {
213 // Have samples, add to profile.
214 const DexFile* dex_file = method.GetInterfaceMethodIfProxy(sizeof(void*))->GetDexFile();
215 methods_->push_back(MethodReference(dex_file, method.GetDexMethodIndex()));
216 }
217 }
218 }
219 return true;
220 }
221
222 private:
223 std::vector<MethodReference>* const methods_;
Calin Juravle138dbff2016-06-28 19:36:58 +0100224 uint32_t startup_method_samples_;
Mathieu Chartier27ed3a42016-05-18 08:51:52 -0700225};
226
227void ProfileSaver::FetchAndCacheResolvedClassesAndMethods() {
Calin Juravle67265462016-03-18 16:23:40 +0000228 ScopedTrace trace(__PRETTY_FUNCTION__);
Calin Juravle67265462016-03-18 16:23:40 +0000229 ClassLinker* const class_linker = Runtime::Current()->GetClassLinker();
230 std::set<DexCacheResolvedClasses> resolved_classes =
231 class_linker->GetResolvedClasses(/*ignore boot classes*/ true);
Mathieu Chartier27ed3a42016-05-18 08:51:52 -0700232
233 std::vector<MethodReference> methods;
234 {
235 ScopedTrace trace2("Get hot methods");
Calin Juravle138dbff2016-06-28 19:36:58 +0100236 GetMethodsVisitor visitor(&methods, options_.GetStartupMethodSamples());
Mathieu Chartier27ed3a42016-05-18 08:51:52 -0700237 ScopedObjectAccess soa(Thread::Current());
238 class_linker->VisitClasses(&visitor);
239 VLOG(profiler) << "Methods with samples greater than "
Calin Juravle138dbff2016-06-28 19:36:58 +0100240 << options_.GetStartupMethodSamples() << " = " << methods.size();
Mathieu Chartier27ed3a42016-05-18 08:51:52 -0700241 }
Calin Juravle67265462016-03-18 16:23:40 +0000242 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
243 uint64_t total_number_of_profile_entries_cached = 0;
Mathieu Chartierb384e5e2016-04-29 12:03:56 -0700244
Calin Juravle67265462016-03-18 16:23:40 +0000245 for (const auto& it : tracked_dex_base_locations_) {
Mathieu Chartierb384e5e2016-04-29 12:03:56 -0700246 std::set<DexCacheResolvedClasses> resolved_classes_for_location;
Calin Juravle67265462016-03-18 16:23:40 +0000247 const std::string& filename = it.first;
248 const std::set<std::string>& locations = it.second;
Mathieu Chartier27ed3a42016-05-18 08:51:52 -0700249 std::vector<MethodReference> methods_for_location;
250 for (const MethodReference& ref : methods) {
251 if (locations.find(ref.dex_file->GetBaseLocation()) != locations.end()) {
252 methods_for_location.push_back(ref);
253 }
254 }
Calin Juravle67265462016-03-18 16:23:40 +0000255 for (const DexCacheResolvedClasses& classes : resolved_classes) {
Mathieu Chartierb384e5e2016-04-29 12:03:56 -0700256 if (locations.find(classes.GetBaseLocation()) != locations.end()) {
Mathieu Chartier27ed3a42016-05-18 08:51:52 -0700257 VLOG(profiler) << "Added " << classes.GetClasses().size() << " classes for location "
258 << classes.GetBaseLocation() << " (" << classes.GetDexLocation() << ")";
Calin Juravle67265462016-03-18 16:23:40 +0000259 resolved_classes_for_location.insert(classes);
Mathieu Chartierb384e5e2016-04-29 12:03:56 -0700260 } else {
261 VLOG(profiler) << "Location not found " << classes.GetBaseLocation()
262 << " (" << classes.GetDexLocation() << ")";
Calin Juravle67265462016-03-18 16:23:40 +0000263 }
264 }
265 ProfileCompilationInfo* info = GetCachedProfiledInfo(filename);
Mathieu Chartier27ed3a42016-05-18 08:51:52 -0700266 info->AddMethodsAndClasses(methods_for_location, resolved_classes_for_location);
Calin Juravle67265462016-03-18 16:23:40 +0000267 total_number_of_profile_entries_cached += resolved_classes_for_location.size();
268 }
269 max_number_of_profile_entries_cached_ = std::max(
270 max_number_of_profile_entries_cached_,
271 total_number_of_profile_entries_cached);
272}
273
Calin Juravlea2638922016-04-29 16:44:11 +0100274bool ProfileSaver::ProcessProfilingInfo(uint16_t* new_methods) {
Calin Juravle67265462016-03-18 16:23:40 +0000275 ScopedTrace trace(__PRETTY_FUNCTION__);
Calin Juravleb4eddd22016-01-13 15:52:33 -0800276 SafeMap<std::string, std::set<std::string>> tracked_locations;
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000277 {
Calin Juravleb4eddd22016-01-13 15:52:33 -0800278 // Make a copy so that we don't hold the lock while doing I/O.
279 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
280 tracked_locations = tracked_dex_base_locations_;
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000281 }
Calin Juravleb9c1b9b2016-03-17 17:07:52 +0000282
Calin Juravle67265462016-03-18 16:23:40 +0000283 bool profile_file_saved = false;
284 uint64_t total_number_of_profile_entries_cached = 0;
Calin Juravlea2638922016-04-29 16:44:11 +0100285 *new_methods = 0;
286
Calin Juravleb4eddd22016-01-13 15:52:33 -0800287 for (const auto& it : tracked_locations) {
288 if (ShuttingDown(Thread::Current())) {
289 return true;
290 }
291 const std::string& filename = it.first;
292 const std::set<std::string>& locations = it.second;
Calin Juravle99629622016-04-19 16:33:46 +0100293 std::vector<MethodReference> methods;
Calin Juravleb4eddd22016-01-13 15:52:33 -0800294 {
295 ScopedObjectAccess soa(Thread::Current());
Calin Juravle99629622016-04-19 16:33:46 +0100296 jit_code_cache_->GetProfiledMethods(locations, methods);
Calin Juravleb8e69992016-03-09 15:37:48 +0000297 total_number_of_code_cache_queries_++;
Calin Juravleb4eddd22016-01-13 15:52:33 -0800298 }
Calin Juravleb9c1b9b2016-03-17 17:07:52 +0000299
Calin Juravle67265462016-03-18 16:23:40 +0000300 ProfileCompilationInfo* cached_info = GetCachedProfiledInfo(filename);
301 cached_info->AddMethodsAndClasses(methods, std::set<DexCacheResolvedClasses>());
Calin Juravle698f4d12016-03-30 18:18:58 +0100302 int64_t delta_number_of_methods =
303 cached_info->GetNumberOfMethods() -
304 static_cast<int64_t>(last_save_number_of_methods_);
305 int64_t delta_number_of_classes =
306 cached_info->GetNumberOfResolvedClasses() -
307 static_cast<int64_t>(last_save_number_of_classes_);
Calin Juravle67265462016-03-18 16:23:40 +0000308
Calin Juravle138dbff2016-06-28 19:36:58 +0100309 if (delta_number_of_methods < options_.GetMinMethodsToSave() &&
310 delta_number_of_classes < options_.GetMinClassesToSave()) {
Calin Juravle698f4d12016-03-30 18:18:58 +0100311 VLOG(profiler) << "Not enough information to save to: " << filename
Calin Juravle138dbff2016-06-28 19:36:58 +0100312 << " Number of methods: " << delta_number_of_methods
313 << " Number of classes: " << delta_number_of_classes;
Calin Juravleb8e69992016-03-09 15:37:48 +0000314 total_number_of_skipped_writes_++;
Calin Juravle67265462016-03-18 16:23:40 +0000315 continue;
Calin Juravleb4eddd22016-01-13 15:52:33 -0800316 }
Calin Juravlea2638922016-04-29 16:44:11 +0100317 *new_methods = std::max(static_cast<uint16_t>(delta_number_of_methods), *new_methods);
Calin Juravleb8e69992016-03-09 15:37:48 +0000318 uint64_t bytes_written;
Calin Juravle5d1bd0a2016-03-24 20:33:22 +0000319 // Force the save. In case the profile data is corrupted or the the profile
320 // has the wrong version this will "fix" the file to the correct format.
321 if (cached_info->MergeAndSave(filename, &bytes_written, /*force*/ true)) {
Calin Juravle67265462016-03-18 16:23:40 +0000322 last_save_number_of_methods_ = cached_info->GetNumberOfMethods();
Calin Juravle698f4d12016-03-30 18:18:58 +0100323 last_save_number_of_classes_ = cached_info->GetNumberOfResolvedClasses();
Calin Juravle67265462016-03-18 16:23:40 +0000324 // Clear resolved classes. No need to store them around as
325 // they don't change after the first write.
326 cached_info->ClearResolvedClasses();
Calin Juravleb8e69992016-03-09 15:37:48 +0000327 if (bytes_written > 0) {
328 total_number_of_writes_++;
329 total_bytes_written_ += bytes_written;
Calin Juravle698f4d12016-03-30 18:18:58 +0100330 profile_file_saved = true;
Calin Juravle67265462016-03-18 16:23:40 +0000331 } else {
332 // At this point we could still have avoided the write.
333 // We load and merge the data from the file lazily at its first ever
334 // save attempt. So, whatever we are trying to save could already be
335 // in the file.
336 total_number_of_skipped_writes_++;
Calin Juravleb8e69992016-03-09 15:37:48 +0000337 }
Calin Juravle67265462016-03-18 16:23:40 +0000338 } else {
339 LOG(WARNING) << "Could not save profiling info to " << filename;
340 total_number_of_failed_writes_++;
Calin Juravleb4eddd22016-01-13 15:52:33 -0800341 }
Calin Juravle67265462016-03-18 16:23:40 +0000342 total_number_of_profile_entries_cached +=
343 cached_info->GetNumberOfMethods() +
344 cached_info->GetNumberOfResolvedClasses();
Calin Juravleb4eddd22016-01-13 15:52:33 -0800345 }
Calin Juravle67265462016-03-18 16:23:40 +0000346 max_number_of_profile_entries_cached_ = std::max(
347 max_number_of_profile_entries_cached_,
348 total_number_of_profile_entries_cached);
349 return profile_file_saved;
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000350}
351
352void* ProfileSaver::RunProfileSaverThread(void* arg) {
353 Runtime* runtime = Runtime::Current();
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000354
Calin Juravlef39f0092016-04-28 12:59:33 +0100355 bool attached = runtime->AttachCurrentThread("Profile Saver",
356 /*as_daemon*/true,
357 runtime->GetSystemThreadGroup(),
358 /*create_peer*/true);
359 if (!attached) {
360 CHECK(runtime->IsShuttingDown(Thread::Current()));
361 return nullptr;
362 }
363
364 ProfileSaver* profile_saver = reinterpret_cast<ProfileSaver*>(arg);
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000365 profile_saver->Run();
366
367 runtime->DetachCurrentThread();
368 VLOG(profiler) << "Profile saver shutdown";
369 return nullptr;
370}
371
Calin Juravle050fb1b2016-03-25 17:17:09 +0000372static bool ShouldProfileLocation(const std::string& location) {
Calin Juravle0b791272016-04-18 16:38:27 +0100373 OatFileManager& oat_manager = Runtime::Current()->GetOatFileManager();
374 const OatFile* oat_file = oat_manager.FindOpenedOatFileFromDexLocation(location);
Calin Juravle050fb1b2016-03-25 17:17:09 +0000375 if (oat_file == nullptr) {
376 // This can happen if we fallback to run code directly from the APK.
377 // Profile it with the hope that the background dexopt will get us back into
378 // a good state.
Calin Juravle0b791272016-04-18 16:38:27 +0100379 VLOG(profiler) << "Asked to profile a location without an oat file:" << location;
Calin Juravle050fb1b2016-03-25 17:17:09 +0000380 return true;
381 }
382 CompilerFilter::Filter filter = oat_file->GetCompilerFilter();
Calin Juravle65439332016-04-19 18:17:41 +0100383 if ((filter == CompilerFilter::kSpeed) || (filter == CompilerFilter::kEverything)) {
Calin Juravle0b791272016-04-18 16:38:27 +0100384 VLOG(profiler)
Calin Juravle65439332016-04-19 18:17:41 +0100385 << "Skip profiling oat file because it's already speed|everything compiled: "
386 << location << " oat location: " << oat_file->GetLocation();
Calin Juravle050fb1b2016-03-25 17:17:09 +0000387 return false;
388 }
389 return true;
390}
391
Calin Juravle138dbff2016-06-28 19:36:58 +0100392void ProfileSaver::Start(const ProfileSaverOptions& options,
393 const std::string& output_filename,
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000394 jit::JitCodeCache* jit_code_cache,
Calin Juravlec90bc922016-02-24 10:13:09 +0000395 const std::vector<std::string>& code_paths,
396 const std::string& foreign_dex_profile_path,
397 const std::string& app_data_dir) {
Calin Juravle138dbff2016-06-28 19:36:58 +0100398 DCHECK(options.IsEnabled());
399 DCHECK(Runtime::Current()->GetJit() != nullptr);
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000400 DCHECK(!output_filename.empty());
401 DCHECK(jit_code_cache != nullptr);
402
Calin Juravle050fb1b2016-03-25 17:17:09 +0000403 std::vector<std::string> code_paths_to_profile;
404
405 for (const std::string& location : code_paths) {
406 if (ShouldProfileLocation(location)) {
407 code_paths_to_profile.push_back(location);
Calin Juravle050fb1b2016-03-25 17:17:09 +0000408 }
409 }
410 if (code_paths_to_profile.empty()) {
Calin Juravle0b791272016-04-18 16:38:27 +0100411 VLOG(profiler) << "No code paths should be profiled.";
Calin Juravle050fb1b2016-03-25 17:17:09 +0000412 return;
413 }
414
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000415 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000416 if (instance_ != nullptr) {
Calin Juravleb4eddd22016-01-13 15:52:33 -0800417 // If we already have an instance, make sure it uses the same jit_code_cache.
418 // This may be called multiple times via Runtime::registerAppInfo (e.g. for
419 // apps which share the same runtime).
420 DCHECK_EQ(instance_->jit_code_cache_, jit_code_cache);
421 // Add the code_paths to the tracked locations.
Calin Juravle20b7e3b2016-04-18 18:59:22 +0100422 instance_->AddTrackedLocations(output_filename, app_data_dir, code_paths_to_profile);
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000423 return;
424 }
425
426 VLOG(profiler) << "Starting profile saver using output file: " << output_filename
Calin Juravle0b791272016-04-18 16:38:27 +0100427 << ". Tracking: " << Join(code_paths_to_profile, ':');
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000428
Calin Juravle138dbff2016-06-28 19:36:58 +0100429 instance_ = new ProfileSaver(options,
430 output_filename,
Calin Juravlec90bc922016-02-24 10:13:09 +0000431 jit_code_cache,
Calin Juravle0b791272016-04-18 16:38:27 +0100432 code_paths_to_profile,
Calin Juravlec90bc922016-02-24 10:13:09 +0000433 foreign_dex_profile_path,
434 app_data_dir);
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000435
436 // Create a new thread which does the saving.
437 CHECK_PTHREAD_CALL(
438 pthread_create,
439 (&profiler_pthread_, nullptr, &RunProfileSaverThread, reinterpret_cast<void*>(instance_)),
440 "Profile saver thread");
441}
442
Calin Juravleb8e69992016-03-09 15:37:48 +0000443void ProfileSaver::Stop(bool dump_info) {
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000444 ProfileSaver* profile_saver = nullptr;
445 pthread_t profiler_pthread = 0U;
446
447 {
448 MutexLock profiler_mutex(Thread::Current(), *Locks::profiler_lock_);
Calin Juravleb4eddd22016-01-13 15:52:33 -0800449 VLOG(profiler) << "Stopping profile saver thread";
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000450 profile_saver = instance_;
451 profiler_pthread = profiler_pthread_;
452 if (instance_ == nullptr) {
453 DCHECK(false) << "Tried to stop a profile saver which was not started";
454 return;
455 }
456 if (instance_->shutting_down_) {
457 DCHECK(false) << "Tried to stop the profile saver twice";
458 return;
459 }
460 instance_->shutting_down_ = true;
Calin Juravleb8e69992016-03-09 15:37:48 +0000461 if (dump_info) {
462 instance_->DumpInfo(LOG(INFO));
463 }
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000464 }
465
466 {
467 // Wake up the saver thread if it is sleeping to allow for a clean exit.
468 MutexLock wait_mutex(Thread::Current(), profile_saver->wait_lock_);
469 profile_saver->period_condition_.Signal(Thread::Current());
470 }
471
472 // Wait for the saver thread to stop.
473 CHECK_PTHREAD_CALL(pthread_join, (profiler_pthread, nullptr), "profile saver thread shutdown");
474
475 {
476 MutexLock profiler_mutex(Thread::Current(), *Locks::profiler_lock_);
477 instance_ = nullptr;
478 profiler_pthread_ = 0U;
479 }
480 delete profile_saver;
481}
482
483bool ProfileSaver::ShuttingDown(Thread* self) {
484 MutexLock mu(self, *Locks::profiler_lock_);
485 return shutting_down_;
486}
487
488bool ProfileSaver::IsStarted() {
489 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
490 return instance_ != nullptr;
491}
492
Calin Juravleb4eddd22016-01-13 15:52:33 -0800493void ProfileSaver::AddTrackedLocations(const std::string& output_filename,
Calin Juravle20b7e3b2016-04-18 18:59:22 +0100494 const std::string& app_data_dir,
Calin Juravleb4eddd22016-01-13 15:52:33 -0800495 const std::vector<std::string>& code_paths) {
496 auto it = tracked_dex_base_locations_.find(output_filename);
497 if (it == tracked_dex_base_locations_.end()) {
498 tracked_dex_base_locations_.Put(output_filename,
499 std::set<std::string>(code_paths.begin(), code_paths.end()));
Calin Juravle20b7e3b2016-04-18 18:59:22 +0100500 app_data_dirs_.insert(app_data_dir);
Calin Juravleb4eddd22016-01-13 15:52:33 -0800501 } else {
502 it->second.insert(code_paths.begin(), code_paths.end());
503 }
504}
505
Calin Juravlec90bc922016-02-24 10:13:09 +0000506void ProfileSaver::NotifyDexUse(const std::string& dex_location) {
Calin Juravle050fb1b2016-03-25 17:17:09 +0000507 if (!ShouldProfileLocation(dex_location)) {
508 return;
509 }
Calin Juravlec90bc922016-02-24 10:13:09 +0000510 std::set<std::string> app_code_paths;
511 std::string foreign_dex_profile_path;
Calin Juravle20b7e3b2016-04-18 18:59:22 +0100512 std::set<std::string> app_data_dirs;
Calin Juravlec90bc922016-02-24 10:13:09 +0000513 {
514 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
Calin Juravleb8e69992016-03-09 15:37:48 +0000515 if (instance_ == nullptr) {
516 return;
517 }
Calin Juravlec90bc922016-02-24 10:13:09 +0000518 // Make a copy so that we don't hold the lock while doing I/O.
519 for (const auto& it : instance_->tracked_dex_base_locations_) {
520 app_code_paths.insert(it.second.begin(), it.second.end());
521 }
522 foreign_dex_profile_path = instance_->foreign_dex_profile_path_;
Calin Juravle20b7e3b2016-04-18 18:59:22 +0100523 app_data_dirs.insert(instance_->app_data_dirs_.begin(), instance_->app_data_dirs_.end());
Calin Juravlec90bc922016-02-24 10:13:09 +0000524 }
525
Calin Juravleb8e69992016-03-09 15:37:48 +0000526 bool mark_created = MaybeRecordDexUseInternal(dex_location,
527 app_code_paths,
528 foreign_dex_profile_path,
Calin Juravle20b7e3b2016-04-18 18:59:22 +0100529 app_data_dirs);
Calin Juravleb8e69992016-03-09 15:37:48 +0000530 if (mark_created) {
531 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
532 if (instance_ != nullptr) {
533 instance_->total_number_of_foreign_dex_marks_++;
534 }
535 }
Calin Juravlec90bc922016-02-24 10:13:09 +0000536}
537
Calin Juravleb8e69992016-03-09 15:37:48 +0000538bool ProfileSaver::MaybeRecordDexUseInternal(
Calin Juravlec90bc922016-02-24 10:13:09 +0000539 const std::string& dex_location,
540 const std::set<std::string>& app_code_paths,
541 const std::string& foreign_dex_profile_path,
Calin Juravle20b7e3b2016-04-18 18:59:22 +0100542 const std::set<std::string>& app_data_dirs) {
Calin Juravlef529e9b2016-03-08 12:52:52 +0000543 if (dex_location.empty()) {
544 LOG(WARNING) << "Asked to record foreign dex use with an empty dex location.";
Calin Juravleb8e69992016-03-09 15:37:48 +0000545 return false;
Calin Juravlef529e9b2016-03-08 12:52:52 +0000546 }
Calin Juravlec90bc922016-02-24 10:13:09 +0000547 if (foreign_dex_profile_path.empty()) {
548 LOG(WARNING) << "Asked to record foreign dex use without a valid profile path ";
Calin Juravleb8e69992016-03-09 15:37:48 +0000549 return false;
Calin Juravlec90bc922016-02-24 10:13:09 +0000550 }
551
552 UniqueCPtr<const char[]> dex_location_real_path(realpath(dex_location.c_str(), nullptr));
Calin Juravlef529e9b2016-03-08 12:52:52 +0000553 if (dex_location_real_path == nullptr) {
554 PLOG(WARNING) << "Could not get realpath for " << dex_location;
555 }
556 std::string dex_location_real_path_str((dex_location_real_path == nullptr)
557 ? dex_location.c_str()
558 : dex_location_real_path.get());
Calin Juravlec90bc922016-02-24 10:13:09 +0000559
Calin Juravle20b7e3b2016-04-18 18:59:22 +0100560 if (app_data_dirs.find(dex_location_real_path_str) != app_data_dirs.end()) {
Calin Juravlec90bc922016-02-24 10:13:09 +0000561 // The dex location is under the application folder. Nothing to record.
Calin Juravleb8e69992016-03-09 15:37:48 +0000562 return false;
Calin Juravlec90bc922016-02-24 10:13:09 +0000563 }
564
565 if (app_code_paths.find(dex_location) != app_code_paths.end()) {
566 // The dex location belongs to the application code paths. Nothing to record.
Calin Juravleb8e69992016-03-09 15:37:48 +0000567 return false;
Calin Juravlec90bc922016-02-24 10:13:09 +0000568 }
569 // Do another round of checks with the real paths.
570 // Note that we could cache all the real locations in the saver (since it's an expensive
571 // operation). However we expect that app_code_paths is small (usually 1 element), and
572 // NotifyDexUse is called just a few times in the app lifetime. So we make the compromise
573 // to save some bytes of memory usage.
574 for (const auto& app_code_location : app_code_paths) {
575 UniqueCPtr<const char[]> real_app_code_location(realpath(app_code_location.c_str(), nullptr));
Calin Juravlef529e9b2016-03-08 12:52:52 +0000576 if (real_app_code_location == nullptr) {
577 PLOG(WARNING) << "Could not get realpath for " << app_code_location;
578 }
579 std::string real_app_code_location_str((real_app_code_location == nullptr)
580 ? app_code_location.c_str()
581 : real_app_code_location.get());
Calin Juravlec90bc922016-02-24 10:13:09 +0000582 if (real_app_code_location_str == dex_location_real_path_str) {
583 // The dex location belongs to the application code paths. Nothing to record.
Calin Juravleb8e69992016-03-09 15:37:48 +0000584 return false;
Calin Juravlec90bc922016-02-24 10:13:09 +0000585 }
586 }
587
588 // For foreign dex files we record a flag on disk. PackageManager will (potentially) take this
589 // into account when deciding how to optimize the loaded dex file.
590 // The expected flag name is the canonical path of the apk where '/' is substituted to '@'.
591 // (it needs to be kept in sync with
592 // frameworks/base/services/core/java/com/android/server/pm/PackageDexOptimizer.java)
593 std::replace(dex_location_real_path_str.begin(), dex_location_real_path_str.end(), '/', '@');
594 std::string flag_path = foreign_dex_profile_path + "/" + dex_location_real_path_str;
Richard Uhlere18d6192016-05-10 14:01:18 -0700595 // We use O_RDONLY as the access mode because we must supply some access
596 // mode, and there is no access mode that means 'create but do not read' the
597 // file. We will not not actually read from the file.
598 int fd = TEMP_FAILURE_RETRY(open(flag_path.c_str(),
599 O_CREAT | O_RDONLY | O_EXCL | O_CLOEXEC | O_NOFOLLOW, 0));
Calin Juravlec90bc922016-02-24 10:13:09 +0000600 if (fd != -1) {
601 if (close(fd) != 0) {
602 PLOG(WARNING) << "Could not close file after flagging foreign dex use " << flag_path;
603 }
Calin Juravleb8e69992016-03-09 15:37:48 +0000604 return true;
Calin Juravlec90bc922016-02-24 10:13:09 +0000605 } else {
Richard Uhlere18d6192016-05-10 14:01:18 -0700606 if (errno != EEXIST && errno != EACCES) {
607 // Another app could have already created the file, and selinux may not
608 // allow the read access to the file implied by the call to open.
Calin Juravlec90bc922016-02-24 10:13:09 +0000609 PLOG(WARNING) << "Could not create foreign dex use mark " << flag_path;
Calin Juravleb8e69992016-03-09 15:37:48 +0000610 return false;
Calin Juravlec90bc922016-02-24 10:13:09 +0000611 }
Calin Juravleb8e69992016-03-09 15:37:48 +0000612 return true;
Calin Juravlec90bc922016-02-24 10:13:09 +0000613 }
614}
615
Calin Juravleb8e69992016-03-09 15:37:48 +0000616void ProfileSaver::DumpInstanceInfo(std::ostream& os) {
617 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
618 if (instance_ != nullptr) {
619 instance_->DumpInfo(os);
620 }
621}
622
623void ProfileSaver::DumpInfo(std::ostream& os) {
624 os << "ProfileSaver total_bytes_written=" << total_bytes_written_ << '\n'
625 << "ProfileSaver total_number_of_writes=" << total_number_of_writes_ << '\n'
Calin Juravle67265462016-03-18 16:23:40 +0000626 << "ProfileSaver total_number_of_code_cache_queries="
627 << total_number_of_code_cache_queries_ << '\n'
Calin Juravleb8e69992016-03-09 15:37:48 +0000628 << "ProfileSaver total_number_of_skipped_writes=" << total_number_of_skipped_writes_ << '\n'
629 << "ProfileSaver total_number_of_failed_writes=" << total_number_of_failed_writes_ << '\n'
Calin Juravle67265462016-03-18 16:23:40 +0000630 << "ProfileSaver total_ms_of_sleep=" << total_ms_of_sleep_ << '\n'
Calin Juravle050fb1b2016-03-25 17:17:09 +0000631 << "ProfileSaver total_ms_of_work=" << NsToMs(total_ns_of_work_) << '\n'
Calin Juravle67265462016-03-18 16:23:40 +0000632 << "ProfileSaver total_number_of_foreign_dex_marks="
633 << total_number_of_foreign_dex_marks_ << '\n'
634 << "ProfileSaver max_number_profile_entries_cached="
Calin Juravlea2638922016-04-29 16:44:11 +0100635 << max_number_of_profile_entries_cached_ << '\n'
636 << "ProfileSaver total_number_of_hot_spikes=" << total_number_of_hot_spikes_ << '\n'
637 << "ProfileSaver total_number_of_wake_ups=" << total_number_of_wake_ups_ << '\n';
Calin Juravleb8e69992016-03-09 15:37:48 +0000638}
639
Calin Juravleffc87072016-04-20 14:22:09 +0100640
641void ProfileSaver::ForceProcessProfiles() {
642 ProfileSaver* saver = nullptr;
643 {
644 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
645 saver = instance_;
646 }
647 // TODO(calin): this is not actually thread safe as the instance_ may have been deleted,
648 // but we only use this in testing when we now this won't happen.
649 // Refactor the way we handle the instance so that we don't end up in this situation.
650 if (saver != nullptr) {
Calin Juravlea2638922016-04-29 16:44:11 +0100651 uint16_t new_methods;
652 saver->ProcessProfilingInfo(&new_methods);
Calin Juravleffc87072016-04-20 14:22:09 +0100653 }
654}
655
656bool ProfileSaver::HasSeenMethod(const std::string& profile,
657 const DexFile* dex_file,
658 uint16_t method_idx) {
659 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
660 if (instance_ != nullptr) {
661 ProfileCompilationInfo* info = instance_->GetCachedProfiledInfo(profile);
662 if (info != nullptr) {
663 return info->ContainsMethod(MethodReference(dex_file, method_idx));
664 }
665 }
666 return false;
667}
668
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000669} // namespace art