blob: 794ea278242ad2cb172b28e843b9319cce21f16c [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
Calin Juravle4d77b6a2015-12-01 18:38:09 +000023#include "art_method-inl.h"
Mathieu Chartierdabdc0f2016-03-04 14:58:03 -080024#include "base/systrace.h"
Calin Juravle6044fa72016-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 Juravle6044fa72016-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 +000033// TODO: read the constants from ProfileOptions,
34// Add a random delay each time we go to sleep so that we don't hammer the CPU
35// with all profile savers running at the same time.
Calin Juravle5fbb0fe2016-04-29 16:44:11 +010036static constexpr const uint64_t kMinSavePeriodNs = MsToNs(20 * 1000); // 20 seconds
Calin Juravlec15e5662016-03-17 17:07:52 +000037static constexpr const uint64_t kSaveResolvedClassesDelayMs = 2 * 1000; // 2 seconds
Mathieu Chartierc600eaa2016-05-18 08:51:52 -070038// Minimum number of JIT samples during launch to include a method into the profile.
39static constexpr const size_t kStartupMethodSamples = 1;
Calin Juravle4d77b6a2015-12-01 18:38:09 +000040
Calin Juravle85f7bf32016-03-18 16:23:40 +000041static constexpr const uint32_t kMinimumNumberOfMethodsToSave = 10;
42static constexpr const uint32_t kMinimumNumberOfClassesToSave = 10;
Calin Juravle5fbb0fe2016-04-29 16:44:11 +010043static constexpr const uint32_t kMinimumNumberOfNotificationBeforeWake =
44 kMinimumNumberOfMethodsToSave;
45static constexpr const uint32_t kMaximumNumberOfNotificationBeforeWake = 50;
46
Calin Juravle4d77b6a2015-12-01 18:38:09 +000047
48ProfileSaver* ProfileSaver::instance_ = nullptr;
49pthread_t ProfileSaver::profiler_pthread_ = 0U;
50
51ProfileSaver::ProfileSaver(const std::string& output_filename,
52 jit::JitCodeCache* jit_code_cache,
Calin Juravle86a9ebe2016-02-24 10:13:09 +000053 const std::vector<std::string>& code_paths,
54 const std::string& foreign_dex_profile_path,
55 const std::string& app_data_dir)
Calin Juravleb4eddd22016-01-13 15:52:33 -080056 : jit_code_cache_(jit_code_cache),
Calin Juravle86a9ebe2016-02-24 10:13:09 +000057 foreign_dex_profile_path_(foreign_dex_profile_path),
Calin Juravle4d77b6a2015-12-01 18:38:09 +000058 shutting_down_(false),
Calin Juravle85f7bf32016-03-18 16:23:40 +000059 last_save_number_of_methods_(0),
Calin Juravle0cdaa6c2016-03-30 18:18:58 +010060 last_save_number_of_classes_(0),
Calin Juravle5fbb0fe2016-04-29 16:44:11 +010061 last_time_ns_saver_woke_up_(0),
62 jit_activity_notifications_(0),
Calin Juravle4d77b6a2015-12-01 18:38:09 +000063 wait_lock_("ProfileSaver wait lock"),
Calin Juravlec19c1c22016-03-09 15:37:48 +000064 period_condition_("ProfileSaver period condition", wait_lock_),
65 total_bytes_written_(0),
66 total_number_of_writes_(0),
67 total_number_of_code_cache_queries_(0),
68 total_number_of_skipped_writes_(0),
69 total_number_of_failed_writes_(0),
Calin Juravle85f7bf32016-03-18 16:23:40 +000070 total_ms_of_sleep_(0),
Calin Juravlec19c1c22016-03-09 15:37:48 +000071 total_ns_of_work_(0),
Calin Juravle85f7bf32016-03-18 16:23:40 +000072 total_number_of_foreign_dex_marks_(0),
Calin Juravle5fbb0fe2016-04-29 16:44:11 +010073 max_number_of_profile_entries_cached_(0),
74 total_number_of_hot_spikes_(0),
75 total_number_of_wake_ups_(0) {
Calin Juravle20ae7932016-04-18 18:59:22 +010076 AddTrackedLocations(output_filename, app_data_dir, code_paths);
Calin Juravle4d77b6a2015-12-01 18:38:09 +000077}
78
79void ProfileSaver::Run() {
Calin Juravle4d77b6a2015-12-01 18:38:09 +000080 Thread* self = Thread::Current();
81
Calin Juravle5fbb0fe2016-04-29 16:44:11 +010082 // Fetch the resolved classes for the app images after sleeping for
83 // kSaveResolvedClassesDelayMs.
84 // TODO(calin) This only considers the case of the primary profile file.
85 // Anything that gets loaded in the same VM will not have their resolved
86 // classes save (unless they started before the initial saving was done).
87 {
88 MutexLock mu(self, wait_lock_);
Mathieu Chartier0ec065d2016-05-18 19:51:23 -070089 constexpr uint64_t kSleepTime = kSaveResolvedClassesDelayMs;
90 const uint64_t end_time = NanoTime() + MsToNs(kSleepTime);
91 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 Juravle5fbb0fe2016-04-29 16:44:11 +010098 total_ms_of_sleep_ += kSaveResolvedClassesDelayMs;
99 }
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700100 FetchAndCacheResolvedClassesAndMethods();
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100101
102 // Loop for the profiled methods.
Mathieu Chartier8913fc12015-12-09 16:38:30 -0800103 while (!ShuttingDown(self)) {
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100104 uint64_t sleep_start = NanoTime();
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000105 {
Calin Juravle0233a412016-05-18 15:49:36 -0700106 uint64_t sleep_time = 0;
107 {
108 MutexLock mu(self, wait_lock_);
109 period_condition_.Wait(self);
Calin Juravledc85bd72016-05-25 18:09:53 +0100110 sleep_time = NanoTime() - sleep_start;
Calin Juravle0233a412016-05-18 15:49:36 -0700111 }
112 // Check if the thread was woken up for shutdown.
113 if (ShuttingDown(self)) {
114 break;
115 }
Calin Juravle5fbb0fe2016-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).
Brian Carlstrom8f153352016-05-24 19:45:30 -0700120 while (kMinSavePeriodNs * 0.9 > sleep_time) {
Calin Juravle0233a412016-05-18 15:49:36 -0700121 {
122 MutexLock mu(self, wait_lock_);
123 period_condition_.TimedWait(self, NsToMs(kMinSavePeriodNs - sleep_time), 0);
Calin Juravledc85bd72016-05-25 18:09:53 +0100124 sleep_time = NanoTime() - sleep_start;
Calin Juravle0233a412016-05-18 15:49:36 -0700125 }
126 // Check if the thread was woken up for shutdown.
127 if (ShuttingDown(self)) {
128 break;
129 }
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100130 total_number_of_wake_ups_++;
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100131 }
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000132 }
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100133 total_ms_of_sleep_ += NsToMs(NanoTime() - sleep_start);
134
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000135 if (ShuttingDown(self)) {
136 break;
137 }
138
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100139 uint16_t new_methods = 0;
140 uint64_t start_work = NanoTime();
141 bool profile_saved_to_disk = ProcessProfilingInfo(&new_methods);
142 // Update the notification counter based on result. Note that there might be contention on this
143 // but we don't care about to be 100% precise.
144 if (!profile_saved_to_disk) {
145 // If we didn't save to disk it may be because we didn't have enough new methods.
146 // Set the jit activity notifications to new_methods so we can wake up earlier if needed.
147 jit_activity_notifications_ = new_methods;
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000148 }
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100149 total_ns_of_work_ += NanoTime() - start_work;
150 }
151}
Calin Juravlec19c1c22016-03-09 15:37:48 +0000152
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100153void ProfileSaver::NotifyJitActivity() {
154 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
155 if (instance_ == nullptr || instance_->shutting_down_) {
156 return;
157 }
158 instance_->NotifyJitActivityInternal();
159}
160
161void ProfileSaver::WakeUpSaver() {
162 jit_activity_notifications_ = 0;
163 last_time_ns_saver_woke_up_ = NanoTime();
164 period_condition_.Signal(Thread::Current());
165}
166
167void ProfileSaver::NotifyJitActivityInternal() {
168 // Unlikely to overflow but if it happens,
169 // we would have waken up the saver long before that.
170 jit_activity_notifications_++;
171 // Note that we are not as precise as we could be here but we don't want to wake the saver
172 // every time we see a hot method.
173 if (jit_activity_notifications_ > kMinimumNumberOfNotificationBeforeWake) {
174 MutexLock wait_mutex(Thread::Current(), wait_lock_);
175 if ((NanoTime() - last_time_ns_saver_woke_up_) > kMinSavePeriodNs) {
176 WakeUpSaver();
177 }
178 } else if (jit_activity_notifications_ > kMaximumNumberOfNotificationBeforeWake) {
179 // Make sure to wake up the saver if we see a spike in the number of notifications.
180 // This is a precaution to avoid "loosing" a big number of methods in case
181 // this is a spike with no jit after.
182 total_number_of_hot_spikes_++;
183 MutexLock wait_mutex(Thread::Current(), wait_lock_);
184 WakeUpSaver();
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000185 }
186}
187
Calin Juravle85f7bf32016-03-18 16:23:40 +0000188ProfileCompilationInfo* ProfileSaver::GetCachedProfiledInfo(const std::string& filename) {
189 auto info_it = profile_cache_.find(filename);
190 if (info_it == profile_cache_.end()) {
191 info_it = profile_cache_.Put(filename, ProfileCompilationInfo());
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000192 }
Calin Juravle85f7bf32016-03-18 16:23:40 +0000193 return &info_it->second;
194}
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000195
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700196// Get resolved methods that have a profile info or more than kStartupMethodSamples samples.
197// Excludes native methods and classes in the boot image.
198class GetMethodsVisitor : public ClassVisitor {
199 public:
200 explicit GetMethodsVisitor(std::vector<MethodReference>* methods) : methods_(methods) {}
201
202 virtual bool operator()(mirror::Class* klass) SHARED_REQUIRES(Locks::mutator_lock_) {
203 if (Runtime::Current()->GetHeap()->ObjectIsInBootImageSpace(klass)) {
204 return true;
205 }
206 for (ArtMethod& method : klass->GetMethods(sizeof(void*))) {
207 if (!method.IsNative()) {
208 if (method.GetCounter() >= kStartupMethodSamples ||
209 method.GetProfilingInfo(sizeof(void*)) != nullptr) {
210 // Have samples, add to profile.
211 const DexFile* dex_file = method.GetInterfaceMethodIfProxy(sizeof(void*))->GetDexFile();
212 methods_->push_back(MethodReference(dex_file, method.GetDexMethodIndex()));
213 }
214 }
215 }
216 return true;
217 }
218
219 private:
220 std::vector<MethodReference>* const methods_;
221};
222
223void ProfileSaver::FetchAndCacheResolvedClassesAndMethods() {
Calin Juravle85f7bf32016-03-18 16:23:40 +0000224 ScopedTrace trace(__PRETTY_FUNCTION__);
Calin Juravle85f7bf32016-03-18 16:23:40 +0000225 ClassLinker* const class_linker = Runtime::Current()->GetClassLinker();
226 std::set<DexCacheResolvedClasses> resolved_classes =
227 class_linker->GetResolvedClasses(/*ignore boot classes*/ true);
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700228
229 std::vector<MethodReference> methods;
230 {
231 ScopedTrace trace2("Get hot methods");
232 GetMethodsVisitor visitor(&methods);
233 ScopedObjectAccess soa(Thread::Current());
234 class_linker->VisitClasses(&visitor);
235 VLOG(profiler) << "Methods with samples greater than "
236 << kStartupMethodSamples << " = " << methods.size();
237 }
Calin Juravle85f7bf32016-03-18 16:23:40 +0000238 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
239 uint64_t total_number_of_profile_entries_cached = 0;
Mathieu Chartier9275af62016-04-29 12:03:56 -0700240
Calin Juravle85f7bf32016-03-18 16:23:40 +0000241 for (const auto& it : tracked_dex_base_locations_) {
Mathieu Chartier9275af62016-04-29 12:03:56 -0700242 std::set<DexCacheResolvedClasses> resolved_classes_for_location;
Calin Juravle85f7bf32016-03-18 16:23:40 +0000243 const std::string& filename = it.first;
244 const std::set<std::string>& locations = it.second;
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700245 std::vector<MethodReference> methods_for_location;
246 for (const MethodReference& ref : methods) {
247 if (locations.find(ref.dex_file->GetBaseLocation()) != locations.end()) {
248 methods_for_location.push_back(ref);
249 }
250 }
Calin Juravle85f7bf32016-03-18 16:23:40 +0000251 for (const DexCacheResolvedClasses& classes : resolved_classes) {
Mathieu Chartier9275af62016-04-29 12:03:56 -0700252 if (locations.find(classes.GetBaseLocation()) != locations.end()) {
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700253 VLOG(profiler) << "Added " << classes.GetClasses().size() << " classes for location "
254 << classes.GetBaseLocation() << " (" << classes.GetDexLocation() << ")";
Calin Juravle85f7bf32016-03-18 16:23:40 +0000255 resolved_classes_for_location.insert(classes);
Mathieu Chartier9275af62016-04-29 12:03:56 -0700256 } else {
257 VLOG(profiler) << "Location not found " << classes.GetBaseLocation()
258 << " (" << classes.GetDexLocation() << ")";
Calin Juravle85f7bf32016-03-18 16:23:40 +0000259 }
260 }
261 ProfileCompilationInfo* info = GetCachedProfiledInfo(filename);
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700262 info->AddMethodsAndClasses(methods_for_location, resolved_classes_for_location);
Calin Juravle85f7bf32016-03-18 16:23:40 +0000263 total_number_of_profile_entries_cached += resolved_classes_for_location.size();
264 }
265 max_number_of_profile_entries_cached_ = std::max(
266 max_number_of_profile_entries_cached_,
267 total_number_of_profile_entries_cached);
268}
269
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100270bool ProfileSaver::ProcessProfilingInfo(uint16_t* new_methods) {
Calin Juravle85f7bf32016-03-18 16:23:40 +0000271 ScopedTrace trace(__PRETTY_FUNCTION__);
Calin Juravleb4eddd22016-01-13 15:52:33 -0800272 SafeMap<std::string, std::set<std::string>> tracked_locations;
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000273 {
Calin Juravleb4eddd22016-01-13 15:52:33 -0800274 // Make a copy so that we don't hold the lock while doing I/O.
275 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
276 tracked_locations = tracked_dex_base_locations_;
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000277 }
Calin Juravlec15e5662016-03-17 17:07:52 +0000278
Calin Juravle85f7bf32016-03-18 16:23:40 +0000279 bool profile_file_saved = false;
280 uint64_t total_number_of_profile_entries_cached = 0;
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100281 *new_methods = 0;
282
Calin Juravleb4eddd22016-01-13 15:52:33 -0800283 for (const auto& it : tracked_locations) {
284 if (ShuttingDown(Thread::Current())) {
285 return true;
286 }
287 const std::string& filename = it.first;
288 const std::set<std::string>& locations = it.second;
Calin Juravlee2d066d2016-04-19 16:33:46 +0100289 std::vector<MethodReference> methods;
Calin Juravleb4eddd22016-01-13 15:52:33 -0800290 {
291 ScopedObjectAccess soa(Thread::Current());
Calin Juravlee2d066d2016-04-19 16:33:46 +0100292 jit_code_cache_->GetProfiledMethods(locations, methods);
Calin Juravlec19c1c22016-03-09 15:37:48 +0000293 total_number_of_code_cache_queries_++;
Calin Juravleb4eddd22016-01-13 15:52:33 -0800294 }
Calin Juravlec15e5662016-03-17 17:07:52 +0000295
Calin Juravle85f7bf32016-03-18 16:23:40 +0000296 ProfileCompilationInfo* cached_info = GetCachedProfiledInfo(filename);
297 cached_info->AddMethodsAndClasses(methods, std::set<DexCacheResolvedClasses>());
Calin Juravle0cdaa6c2016-03-30 18:18:58 +0100298 int64_t delta_number_of_methods =
299 cached_info->GetNumberOfMethods() -
300 static_cast<int64_t>(last_save_number_of_methods_);
301 int64_t delta_number_of_classes =
302 cached_info->GetNumberOfResolvedClasses() -
303 static_cast<int64_t>(last_save_number_of_classes_);
Calin Juravle85f7bf32016-03-18 16:23:40 +0000304
305 if (delta_number_of_methods < kMinimumNumberOfMethodsToSave &&
306 delta_number_of_classes < kMinimumNumberOfClassesToSave) {
Calin Juravle0cdaa6c2016-03-30 18:18:58 +0100307 VLOG(profiler) << "Not enough information to save to: " << filename
Calin Juravle85f7bf32016-03-18 16:23:40 +0000308 << " Nr of methods: " << delta_number_of_methods
309 << " Nr of classes: " << delta_number_of_classes;
Calin Juravlec19c1c22016-03-09 15:37:48 +0000310 total_number_of_skipped_writes_++;
Calin Juravle85f7bf32016-03-18 16:23:40 +0000311 continue;
Calin Juravleb4eddd22016-01-13 15:52:33 -0800312 }
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100313 *new_methods = std::max(static_cast<uint16_t>(delta_number_of_methods), *new_methods);
Calin Juravlec19c1c22016-03-09 15:37:48 +0000314 uint64_t bytes_written;
Calin Juravlefe297a92016-03-24 20:33:22 +0000315 // Force the save. In case the profile data is corrupted or the the profile
316 // has the wrong version this will "fix" the file to the correct format.
317 if (cached_info->MergeAndSave(filename, &bytes_written, /*force*/ true)) {
Calin Juravle85f7bf32016-03-18 16:23:40 +0000318 last_save_number_of_methods_ = cached_info->GetNumberOfMethods();
Calin Juravle0cdaa6c2016-03-30 18:18:58 +0100319 last_save_number_of_classes_ = cached_info->GetNumberOfResolvedClasses();
Calin Juravle85f7bf32016-03-18 16:23:40 +0000320 // Clear resolved classes. No need to store them around as
321 // they don't change after the first write.
322 cached_info->ClearResolvedClasses();
Calin Juravlec19c1c22016-03-09 15:37:48 +0000323 if (bytes_written > 0) {
324 total_number_of_writes_++;
325 total_bytes_written_ += bytes_written;
Calin Juravle0cdaa6c2016-03-30 18:18:58 +0100326 profile_file_saved = true;
Calin Juravle85f7bf32016-03-18 16:23:40 +0000327 } else {
328 // At this point we could still have avoided the write.
329 // We load and merge the data from the file lazily at its first ever
330 // save attempt. So, whatever we are trying to save could already be
331 // in the file.
332 total_number_of_skipped_writes_++;
Calin Juravlec19c1c22016-03-09 15:37:48 +0000333 }
Calin Juravle85f7bf32016-03-18 16:23:40 +0000334 } else {
335 LOG(WARNING) << "Could not save profiling info to " << filename;
336 total_number_of_failed_writes_++;
Calin Juravleb4eddd22016-01-13 15:52:33 -0800337 }
Calin Juravle85f7bf32016-03-18 16:23:40 +0000338 total_number_of_profile_entries_cached +=
339 cached_info->GetNumberOfMethods() +
340 cached_info->GetNumberOfResolvedClasses();
Calin Juravleb4eddd22016-01-13 15:52:33 -0800341 }
Calin Juravle85f7bf32016-03-18 16:23:40 +0000342 max_number_of_profile_entries_cached_ = std::max(
343 max_number_of_profile_entries_cached_,
344 total_number_of_profile_entries_cached);
345 return profile_file_saved;
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000346}
347
348void* ProfileSaver::RunProfileSaverThread(void* arg) {
349 Runtime* runtime = Runtime::Current();
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000350
Calin Juravlee55fda12016-04-28 12:59:33 +0100351 bool attached = runtime->AttachCurrentThread("Profile Saver",
352 /*as_daemon*/true,
353 runtime->GetSystemThreadGroup(),
354 /*create_peer*/true);
355 if (!attached) {
356 CHECK(runtime->IsShuttingDown(Thread::Current()));
357 return nullptr;
358 }
359
360 ProfileSaver* profile_saver = reinterpret_cast<ProfileSaver*>(arg);
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000361 profile_saver->Run();
362
363 runtime->DetachCurrentThread();
364 VLOG(profiler) << "Profile saver shutdown";
365 return nullptr;
366}
367
Calin Juravle6044fa72016-03-25 17:17:09 +0000368static bool ShouldProfileLocation(const std::string& location) {
Calin Juravle75064232016-04-18 16:38:27 +0100369 OatFileManager& oat_manager = Runtime::Current()->GetOatFileManager();
370 const OatFile* oat_file = oat_manager.FindOpenedOatFileFromDexLocation(location);
Calin Juravle6044fa72016-03-25 17:17:09 +0000371 if (oat_file == nullptr) {
372 // This can happen if we fallback to run code directly from the APK.
373 // Profile it with the hope that the background dexopt will get us back into
374 // a good state.
Calin Juravle75064232016-04-18 16:38:27 +0100375 VLOG(profiler) << "Asked to profile a location without an oat file:" << location;
Calin Juravle6044fa72016-03-25 17:17:09 +0000376 return true;
377 }
378 CompilerFilter::Filter filter = oat_file->GetCompilerFilter();
Calin Juravled19dc462016-04-19 18:17:41 +0100379 if ((filter == CompilerFilter::kSpeed) || (filter == CompilerFilter::kEverything)) {
Calin Juravle75064232016-04-18 16:38:27 +0100380 VLOG(profiler)
Calin Juravled19dc462016-04-19 18:17:41 +0100381 << "Skip profiling oat file because it's already speed|everything compiled: "
382 << location << " oat location: " << oat_file->GetLocation();
Calin Juravle6044fa72016-03-25 17:17:09 +0000383 return false;
384 }
385 return true;
386}
387
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000388void ProfileSaver::Start(const std::string& output_filename,
389 jit::JitCodeCache* jit_code_cache,
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000390 const std::vector<std::string>& code_paths,
391 const std::string& foreign_dex_profile_path,
392 const std::string& app_data_dir) {
Calin Juravlee5de54c2016-04-20 14:22:09 +0100393 DCHECK(Runtime::Current()->SaveProfileInfo());
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000394 DCHECK(!output_filename.empty());
395 DCHECK(jit_code_cache != nullptr);
396
Calin Juravle6044fa72016-03-25 17:17:09 +0000397 std::vector<std::string> code_paths_to_profile;
398
399 for (const std::string& location : code_paths) {
400 if (ShouldProfileLocation(location)) {
401 code_paths_to_profile.push_back(location);
Calin Juravle6044fa72016-03-25 17:17:09 +0000402 }
403 }
404 if (code_paths_to_profile.empty()) {
Calin Juravle75064232016-04-18 16:38:27 +0100405 VLOG(profiler) << "No code paths should be profiled.";
Calin Juravle6044fa72016-03-25 17:17:09 +0000406 return;
407 }
408
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000409 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000410 if (instance_ != nullptr) {
Calin Juravleb4eddd22016-01-13 15:52:33 -0800411 // If we already have an instance, make sure it uses the same jit_code_cache.
412 // This may be called multiple times via Runtime::registerAppInfo (e.g. for
413 // apps which share the same runtime).
414 DCHECK_EQ(instance_->jit_code_cache_, jit_code_cache);
415 // Add the code_paths to the tracked locations.
Calin Juravle20ae7932016-04-18 18:59:22 +0100416 instance_->AddTrackedLocations(output_filename, app_data_dir, code_paths_to_profile);
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000417 return;
418 }
419
420 VLOG(profiler) << "Starting profile saver using output file: " << output_filename
Calin Juravle75064232016-04-18 16:38:27 +0100421 << ". Tracking: " << Join(code_paths_to_profile, ':');
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000422
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000423 instance_ = new ProfileSaver(output_filename,
424 jit_code_cache,
Calin Juravle75064232016-04-18 16:38:27 +0100425 code_paths_to_profile,
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000426 foreign_dex_profile_path,
427 app_data_dir);
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000428
429 // Create a new thread which does the saving.
430 CHECK_PTHREAD_CALL(
431 pthread_create,
432 (&profiler_pthread_, nullptr, &RunProfileSaverThread, reinterpret_cast<void*>(instance_)),
433 "Profile saver thread");
434}
435
Calin Juravlec19c1c22016-03-09 15:37:48 +0000436void ProfileSaver::Stop(bool dump_info) {
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000437 ProfileSaver* profile_saver = nullptr;
438 pthread_t profiler_pthread = 0U;
439
440 {
441 MutexLock profiler_mutex(Thread::Current(), *Locks::profiler_lock_);
Calin Juravleb4eddd22016-01-13 15:52:33 -0800442 VLOG(profiler) << "Stopping profile saver thread";
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000443 profile_saver = instance_;
444 profiler_pthread = profiler_pthread_;
445 if (instance_ == nullptr) {
446 DCHECK(false) << "Tried to stop a profile saver which was not started";
447 return;
448 }
449 if (instance_->shutting_down_) {
450 DCHECK(false) << "Tried to stop the profile saver twice";
451 return;
452 }
453 instance_->shutting_down_ = true;
Calin Juravlec19c1c22016-03-09 15:37:48 +0000454 if (dump_info) {
455 instance_->DumpInfo(LOG(INFO));
456 }
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000457 }
458
459 {
460 // Wake up the saver thread if it is sleeping to allow for a clean exit.
461 MutexLock wait_mutex(Thread::Current(), profile_saver->wait_lock_);
462 profile_saver->period_condition_.Signal(Thread::Current());
463 }
464
465 // Wait for the saver thread to stop.
466 CHECK_PTHREAD_CALL(pthread_join, (profiler_pthread, nullptr), "profile saver thread shutdown");
467
468 {
469 MutexLock profiler_mutex(Thread::Current(), *Locks::profiler_lock_);
470 instance_ = nullptr;
471 profiler_pthread_ = 0U;
472 }
473 delete profile_saver;
474}
475
476bool ProfileSaver::ShuttingDown(Thread* self) {
477 MutexLock mu(self, *Locks::profiler_lock_);
478 return shutting_down_;
479}
480
481bool ProfileSaver::IsStarted() {
482 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
483 return instance_ != nullptr;
484}
485
Calin Juravleb4eddd22016-01-13 15:52:33 -0800486void ProfileSaver::AddTrackedLocations(const std::string& output_filename,
Calin Juravle20ae7932016-04-18 18:59:22 +0100487 const std::string& app_data_dir,
Calin Juravleb4eddd22016-01-13 15:52:33 -0800488 const std::vector<std::string>& code_paths) {
489 auto it = tracked_dex_base_locations_.find(output_filename);
490 if (it == tracked_dex_base_locations_.end()) {
491 tracked_dex_base_locations_.Put(output_filename,
492 std::set<std::string>(code_paths.begin(), code_paths.end()));
Calin Juravle655c3c32016-05-25 16:45:16 +0100493 if (!app_data_dir.empty()) {
494 app_data_dirs_.insert(app_data_dir);
495 }
Calin Juravleb4eddd22016-01-13 15:52:33 -0800496 } else {
497 it->second.insert(code_paths.begin(), code_paths.end());
498 }
499}
500
Calin Juravle655c3c32016-05-25 16:45:16 +0100501// TODO(calin): This may lead to several calls to realpath.
502// Consider moving the logic to the saver thread (i.e. when notified,
503// only cache the location, and then wake up the saver thread to do the
504// comparisons with the real file paths and to create the markers).
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000505void ProfileSaver::NotifyDexUse(const std::string& dex_location) {
Calin Juravle6044fa72016-03-25 17:17:09 +0000506 if (!ShouldProfileLocation(dex_location)) {
507 return;
508 }
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000509 std::set<std::string> app_code_paths;
510 std::string foreign_dex_profile_path;
Calin Juravle20ae7932016-04-18 18:59:22 +0100511 std::set<std::string> app_data_dirs;
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000512 {
513 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
Calin Juravlec19c1c22016-03-09 15:37:48 +0000514 if (instance_ == nullptr) {
515 return;
516 }
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000517 // Make a copy so that we don't hold the lock while doing I/O.
518 for (const auto& it : instance_->tracked_dex_base_locations_) {
519 app_code_paths.insert(it.second.begin(), it.second.end());
520 }
521 foreign_dex_profile_path = instance_->foreign_dex_profile_path_;
Calin Juravle20ae7932016-04-18 18:59:22 +0100522 app_data_dirs.insert(instance_->app_data_dirs_.begin(), instance_->app_data_dirs_.end());
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000523 }
524
Calin Juravlec19c1c22016-03-09 15:37:48 +0000525 bool mark_created = MaybeRecordDexUseInternal(dex_location,
526 app_code_paths,
527 foreign_dex_profile_path,
Calin Juravle20ae7932016-04-18 18:59:22 +0100528 app_data_dirs);
Calin Juravlec19c1c22016-03-09 15:37:48 +0000529 if (mark_created) {
530 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
531 if (instance_ != nullptr) {
532 instance_->total_number_of_foreign_dex_marks_++;
533 }
534 }
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000535}
536
Calin Juravle655c3c32016-05-25 16:45:16 +0100537static bool CheckContainsWithRealPath(const std::set<std::string>& paths_set,
538 const std::string& path_to_check) {
539 for (const auto& path : paths_set) {
540 UniqueCPtr<const char[]> real_path(realpath(path.c_str(), nullptr));
541 if (real_path == nullptr) {
542 PLOG(WARNING) << "Could not get realpath for " << path;
543 continue;
Calin Juravle1fae45f2016-03-08 12:52:52 +0000544 }
Calin Juravle655c3c32016-05-25 16:45:16 +0100545 std::string real_path_str(real_path.get());
546 if (real_path_str == path_to_check) {
547 return true;
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000548 }
549 }
Calin Juravle655c3c32016-05-25 16:45:16 +0100550 return false;
551}
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000552
Calin Juravle655c3c32016-05-25 16:45:16 +0100553// After the call, dex_location_real_path will contain the marker's name.
554static bool CreateForeignDexMarker(const std::string& foreign_dex_profile_path,
555 /*in-out*/ std::string* dex_location_real_path) {
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000556 // For foreign dex files we record a flag on disk. PackageManager will (potentially) take this
557 // into account when deciding how to optimize the loaded dex file.
558 // The expected flag name is the canonical path of the apk where '/' is substituted to '@'.
559 // (it needs to be kept in sync with
560 // frameworks/base/services/core/java/com/android/server/pm/PackageDexOptimizer.java)
Calin Juravle655c3c32016-05-25 16:45:16 +0100561 std::replace(dex_location_real_path->begin(), dex_location_real_path->end(), '/', '@');
562 std::string flag_path = foreign_dex_profile_path + "/" + *dex_location_real_path;
Richard Uhler12e41572016-05-10 14:01:18 -0700563 // We use O_RDONLY as the access mode because we must supply some access
564 // mode, and there is no access mode that means 'create but do not read' the
565 // file. We will not not actually read from the file.
566 int fd = TEMP_FAILURE_RETRY(open(flag_path.c_str(),
567 O_CREAT | O_RDONLY | O_EXCL | O_CLOEXEC | O_NOFOLLOW, 0));
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000568 if (fd != -1) {
569 if (close(fd) != 0) {
570 PLOG(WARNING) << "Could not close file after flagging foreign dex use " << flag_path;
571 }
Calin Juravlec19c1c22016-03-09 15:37:48 +0000572 return true;
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000573 } else {
Richard Uhler12e41572016-05-10 14:01:18 -0700574 if (errno != EEXIST && errno != EACCES) {
575 // Another app could have already created the file, and selinux may not
576 // allow the read access to the file implied by the call to open.
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000577 PLOG(WARNING) << "Could not create foreign dex use mark " << flag_path;
Calin Juravlec19c1c22016-03-09 15:37:48 +0000578 return false;
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000579 }
Calin Juravlec19c1c22016-03-09 15:37:48 +0000580 return true;
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000581 }
582}
583
Calin Juravle655c3c32016-05-25 16:45:16 +0100584bool ProfileSaver::MaybeRecordDexUseInternal(
585 const std::string& dex_location,
586 const std::set<std::string>& app_code_paths,
587 const std::string& foreign_dex_profile_path,
588 const std::set<std::string>& app_data_dirs) {
589 if (dex_location.empty()) {
590 LOG(WARNING) << "Asked to record foreign dex use with an empty dex location.";
591 return false;
592 }
593 if (foreign_dex_profile_path.empty()) {
594 LOG(WARNING) << "Asked to record foreign dex use without a valid profile path ";
595 return false;
596 }
597
598 if (app_code_paths.find(dex_location) != app_code_paths.end()) {
599 // The dex location belongs to the application code paths. Nothing to record.
600 return false;
601 }
602
603 if (app_data_dirs.find(dex_location) != app_data_dirs.end()) {
604 // The dex location is under the application folder. Nothing to record.
605 return false;
606 }
607
608 // Do another round of checks with the real paths.
609 // Application directory could be a symlink (e.g. /data/data instead of /data/user/0), and we
610 // don't have control over how the dex files are actually loaded (symlink or canonical path),
611
612 // Note that we could cache all the real locations in the saver (since it's an expensive
613 // operation). However we expect that app_code_paths is small (usually 1 element), and
614 // NotifyDexUse is called just a few times in the app lifetime. So we make the compromise
615 // to save some bytes of memory usage.
616
617 UniqueCPtr<const char[]> dex_location_real_path(realpath(dex_location.c_str(), nullptr));
618 if (dex_location_real_path == nullptr) {
619 PLOG(WARNING) << "Could not get realpath for " << dex_location;
620 return false;
621 }
622 std::string dex_location_real_path_str(dex_location_real_path.get());
623
624 if (CheckContainsWithRealPath(app_code_paths, dex_location_real_path_str)) {
625 return false;
626 }
627
628 if (CheckContainsWithRealPath(app_data_dirs, dex_location_real_path_str)) {
629 return false;
630 }
631
632 return CreateForeignDexMarker(foreign_dex_profile_path, &dex_location_real_path_str);
633}
634
Calin Juravlec19c1c22016-03-09 15:37:48 +0000635void ProfileSaver::DumpInstanceInfo(std::ostream& os) {
636 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
637 if (instance_ != nullptr) {
638 instance_->DumpInfo(os);
639 }
640}
641
642void ProfileSaver::DumpInfo(std::ostream& os) {
643 os << "ProfileSaver total_bytes_written=" << total_bytes_written_ << '\n'
644 << "ProfileSaver total_number_of_writes=" << total_number_of_writes_ << '\n'
Calin Juravle85f7bf32016-03-18 16:23:40 +0000645 << "ProfileSaver total_number_of_code_cache_queries="
646 << total_number_of_code_cache_queries_ << '\n'
Calin Juravlec19c1c22016-03-09 15:37:48 +0000647 << "ProfileSaver total_number_of_skipped_writes=" << total_number_of_skipped_writes_ << '\n'
648 << "ProfileSaver total_number_of_failed_writes=" << total_number_of_failed_writes_ << '\n'
Calin Juravle85f7bf32016-03-18 16:23:40 +0000649 << "ProfileSaver total_ms_of_sleep=" << total_ms_of_sleep_ << '\n'
Calin Juravle6044fa72016-03-25 17:17:09 +0000650 << "ProfileSaver total_ms_of_work=" << NsToMs(total_ns_of_work_) << '\n'
Calin Juravle85f7bf32016-03-18 16:23:40 +0000651 << "ProfileSaver total_number_of_foreign_dex_marks="
652 << total_number_of_foreign_dex_marks_ << '\n'
653 << "ProfileSaver max_number_profile_entries_cached="
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100654 << max_number_of_profile_entries_cached_ << '\n'
655 << "ProfileSaver total_number_of_hot_spikes=" << total_number_of_hot_spikes_ << '\n'
656 << "ProfileSaver total_number_of_wake_ups=" << total_number_of_wake_ups_ << '\n';
Calin Juravlec19c1c22016-03-09 15:37:48 +0000657}
658
Calin Juravlee5de54c2016-04-20 14:22:09 +0100659
660void ProfileSaver::ForceProcessProfiles() {
661 ProfileSaver* saver = nullptr;
662 {
663 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
664 saver = instance_;
665 }
666 // TODO(calin): this is not actually thread safe as the instance_ may have been deleted,
667 // but we only use this in testing when we now this won't happen.
668 // Refactor the way we handle the instance so that we don't end up in this situation.
669 if (saver != nullptr) {
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100670 uint16_t new_methods;
671 saver->ProcessProfilingInfo(&new_methods);
Calin Juravlee5de54c2016-04-20 14:22:09 +0100672 }
673}
674
675bool ProfileSaver::HasSeenMethod(const std::string& profile,
676 const DexFile* dex_file,
677 uint16_t method_idx) {
678 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
679 if (instance_ != nullptr) {
680 ProfileCompilationInfo* info = instance_->GetCachedProfiledInfo(profile);
681 if (info != nullptr) {
682 return info->ContainsMethod(MethodReference(dex_file, method_idx));
683 }
684 }
685 return false;
686}
687
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000688} // namespace art