blob: c5d3ccd748ef9f75d73aac115721bf109fb350af [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 Juravle86a9ebe2016-02-24 10:13:09 +000077 if (!app_data_dir.empty()) {
78 // The application directory is used to determine which dex files are owned by app.
79 // Since it could be a symlink (e.g. /data/data instead of /data/user/0), and we
80 // don't have control over how the dex files are actually loaded (symlink or canonical path),
81 // store it's canonical form to be sure we use the same base when comparing.
82 UniqueCPtr<const char[]> app_data_dir_real_path(realpath(app_data_dir.c_str(), nullptr));
83 if (app_data_dir_real_path != nullptr) {
Calin Juravle20ae7932016-04-18 18:59:22 +010084 app_data_dirs_.emplace(app_data_dir_real_path.get());
Calin Juravle86a9ebe2016-02-24 10:13:09 +000085 } else {
Calin Juravle20ae7932016-04-18 18:59:22 +010086 LOG(WARNING) << "Failed to get the real path for app dir: " << app_data_dir
Calin Juravle86a9ebe2016-02-24 10:13:09 +000087 << ". The app dir will not be used to determine which dex files belong to the app";
88 }
89 }
Calin Juravle4d77b6a2015-12-01 18:38:09 +000090}
91
92void ProfileSaver::Run() {
Calin Juravle4d77b6a2015-12-01 18:38:09 +000093 Thread* self = Thread::Current();
94
Calin Juravle5fbb0fe2016-04-29 16:44:11 +010095 // Fetch the resolved classes for the app images after sleeping for
96 // kSaveResolvedClassesDelayMs.
97 // TODO(calin) This only considers the case of the primary profile file.
98 // Anything that gets loaded in the same VM will not have their resolved
99 // classes save (unless they started before the initial saving was done).
100 {
101 MutexLock mu(self, wait_lock_);
Mathieu Chartier0ec065d2016-05-18 19:51:23 -0700102 constexpr uint64_t kSleepTime = kSaveResolvedClassesDelayMs;
103 const uint64_t end_time = NanoTime() + MsToNs(kSleepTime);
104 while (true) {
105 const uint64_t current_time = NanoTime();
106 if (current_time >= end_time) {
107 break;
108 }
109 period_condition_.TimedWait(self, NsToMs(end_time - current_time), 0);
110 }
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100111 total_ms_of_sleep_ += kSaveResolvedClassesDelayMs;
112 }
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700113 FetchAndCacheResolvedClassesAndMethods();
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100114
115 // Loop for the profiled methods.
Mathieu Chartier8913fc12015-12-09 16:38:30 -0800116 while (!ShuttingDown(self)) {
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100117 uint64_t sleep_start = NanoTime();
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000118 {
Calin Juravle0233a412016-05-18 15:49:36 -0700119 uint64_t sleep_time = 0;
120 {
121 MutexLock mu(self, wait_lock_);
122 period_condition_.Wait(self);
123 sleep_time = NanoTime() - last_time_ns_saver_woke_up_;
124 }
125 // Check if the thread was woken up for shutdown.
126 if (ShuttingDown(self)) {
127 break;
128 }
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100129 total_number_of_wake_ups_++;
130 // We might have been woken up by a huge number of notifications to guarantee saving.
131 // If we didn't meet the minimum saving period go back to sleep (only if missed by
132 // a reasonable margin).
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100133 while (kMinSavePeriodNs - sleep_time > (kMinSavePeriodNs / 10)) {
Calin Juravle0233a412016-05-18 15:49:36 -0700134 {
135 MutexLock mu(self, wait_lock_);
136 period_condition_.TimedWait(self, NsToMs(kMinSavePeriodNs - sleep_time), 0);
137 sleep_time = NanoTime() - last_time_ns_saver_woke_up_;
138 }
139 // Check if the thread was woken up for shutdown.
140 if (ShuttingDown(self)) {
141 break;
142 }
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100143 total_number_of_wake_ups_++;
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100144 }
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000145 }
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100146 total_ms_of_sleep_ += NsToMs(NanoTime() - sleep_start);
147
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000148 if (ShuttingDown(self)) {
149 break;
150 }
151
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100152 uint16_t new_methods = 0;
153 uint64_t start_work = NanoTime();
154 bool profile_saved_to_disk = ProcessProfilingInfo(&new_methods);
155 // Update the notification counter based on result. Note that there might be contention on this
156 // but we don't care about to be 100% precise.
157 if (!profile_saved_to_disk) {
158 // If we didn't save to disk it may be because we didn't have enough new methods.
159 // Set the jit activity notifications to new_methods so we can wake up earlier if needed.
160 jit_activity_notifications_ = new_methods;
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000161 }
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100162 total_ns_of_work_ += NanoTime() - start_work;
163 }
164}
Calin Juravlec19c1c22016-03-09 15:37:48 +0000165
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100166void ProfileSaver::NotifyJitActivity() {
167 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
168 if (instance_ == nullptr || instance_->shutting_down_) {
169 return;
170 }
171 instance_->NotifyJitActivityInternal();
172}
173
174void ProfileSaver::WakeUpSaver() {
175 jit_activity_notifications_ = 0;
176 last_time_ns_saver_woke_up_ = NanoTime();
177 period_condition_.Signal(Thread::Current());
178}
179
180void ProfileSaver::NotifyJitActivityInternal() {
181 // Unlikely to overflow but if it happens,
182 // we would have waken up the saver long before that.
183 jit_activity_notifications_++;
184 // Note that we are not as precise as we could be here but we don't want to wake the saver
185 // every time we see a hot method.
186 if (jit_activity_notifications_ > kMinimumNumberOfNotificationBeforeWake) {
187 MutexLock wait_mutex(Thread::Current(), wait_lock_);
188 if ((NanoTime() - last_time_ns_saver_woke_up_) > kMinSavePeriodNs) {
189 WakeUpSaver();
190 }
191 } else if (jit_activity_notifications_ > kMaximumNumberOfNotificationBeforeWake) {
192 // Make sure to wake up the saver if we see a spike in the number of notifications.
193 // This is a precaution to avoid "loosing" a big number of methods in case
194 // this is a spike with no jit after.
195 total_number_of_hot_spikes_++;
196 MutexLock wait_mutex(Thread::Current(), wait_lock_);
197 WakeUpSaver();
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000198 }
199}
200
Calin Juravle85f7bf32016-03-18 16:23:40 +0000201ProfileCompilationInfo* ProfileSaver::GetCachedProfiledInfo(const std::string& filename) {
202 auto info_it = profile_cache_.find(filename);
203 if (info_it == profile_cache_.end()) {
204 info_it = profile_cache_.Put(filename, ProfileCompilationInfo());
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000205 }
Calin Juravle85f7bf32016-03-18 16:23:40 +0000206 return &info_it->second;
207}
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000208
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700209// Get resolved methods that have a profile info or more than kStartupMethodSamples samples.
210// Excludes native methods and classes in the boot image.
211class GetMethodsVisitor : public ClassVisitor {
212 public:
213 explicit GetMethodsVisitor(std::vector<MethodReference>* methods) : methods_(methods) {}
214
215 virtual bool operator()(mirror::Class* klass) SHARED_REQUIRES(Locks::mutator_lock_) {
216 if (Runtime::Current()->GetHeap()->ObjectIsInBootImageSpace(klass)) {
217 return true;
218 }
219 for (ArtMethod& method : klass->GetMethods(sizeof(void*))) {
220 if (!method.IsNative()) {
221 if (method.GetCounter() >= kStartupMethodSamples ||
222 method.GetProfilingInfo(sizeof(void*)) != nullptr) {
223 // Have samples, add to profile.
224 const DexFile* dex_file = method.GetInterfaceMethodIfProxy(sizeof(void*))->GetDexFile();
225 methods_->push_back(MethodReference(dex_file, method.GetDexMethodIndex()));
226 }
227 }
228 }
229 return true;
230 }
231
232 private:
233 std::vector<MethodReference>* const methods_;
234};
235
236void ProfileSaver::FetchAndCacheResolvedClassesAndMethods() {
Calin Juravle85f7bf32016-03-18 16:23:40 +0000237 ScopedTrace trace(__PRETTY_FUNCTION__);
Calin Juravle85f7bf32016-03-18 16:23:40 +0000238 ClassLinker* const class_linker = Runtime::Current()->GetClassLinker();
239 std::set<DexCacheResolvedClasses> resolved_classes =
240 class_linker->GetResolvedClasses(/*ignore boot classes*/ true);
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700241
242 std::vector<MethodReference> methods;
243 {
244 ScopedTrace trace2("Get hot methods");
245 GetMethodsVisitor visitor(&methods);
246 ScopedObjectAccess soa(Thread::Current());
247 class_linker->VisitClasses(&visitor);
248 VLOG(profiler) << "Methods with samples greater than "
249 << kStartupMethodSamples << " = " << methods.size();
250 }
Calin Juravle85f7bf32016-03-18 16:23:40 +0000251 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
252 uint64_t total_number_of_profile_entries_cached = 0;
Mathieu Chartier9275af62016-04-29 12:03:56 -0700253
Calin Juravle85f7bf32016-03-18 16:23:40 +0000254 for (const auto& it : tracked_dex_base_locations_) {
Mathieu Chartier9275af62016-04-29 12:03:56 -0700255 std::set<DexCacheResolvedClasses> resolved_classes_for_location;
Calin Juravle85f7bf32016-03-18 16:23:40 +0000256 const std::string& filename = it.first;
257 const std::set<std::string>& locations = it.second;
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700258 std::vector<MethodReference> methods_for_location;
259 for (const MethodReference& ref : methods) {
260 if (locations.find(ref.dex_file->GetBaseLocation()) != locations.end()) {
261 methods_for_location.push_back(ref);
262 }
263 }
Calin Juravle85f7bf32016-03-18 16:23:40 +0000264 for (const DexCacheResolvedClasses& classes : resolved_classes) {
Mathieu Chartier9275af62016-04-29 12:03:56 -0700265 if (locations.find(classes.GetBaseLocation()) != locations.end()) {
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700266 VLOG(profiler) << "Added " << classes.GetClasses().size() << " classes for location "
267 << classes.GetBaseLocation() << " (" << classes.GetDexLocation() << ")";
Calin Juravle85f7bf32016-03-18 16:23:40 +0000268 resolved_classes_for_location.insert(classes);
Mathieu Chartier9275af62016-04-29 12:03:56 -0700269 } else {
270 VLOG(profiler) << "Location not found " << classes.GetBaseLocation()
271 << " (" << classes.GetDexLocation() << ")";
Calin Juravle85f7bf32016-03-18 16:23:40 +0000272 }
273 }
274 ProfileCompilationInfo* info = GetCachedProfiledInfo(filename);
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700275 info->AddMethodsAndClasses(methods_for_location, resolved_classes_for_location);
Calin Juravle85f7bf32016-03-18 16:23:40 +0000276 total_number_of_profile_entries_cached += resolved_classes_for_location.size();
277 }
278 max_number_of_profile_entries_cached_ = std::max(
279 max_number_of_profile_entries_cached_,
280 total_number_of_profile_entries_cached);
281}
282
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100283bool ProfileSaver::ProcessProfilingInfo(uint16_t* new_methods) {
Calin Juravle85f7bf32016-03-18 16:23:40 +0000284 ScopedTrace trace(__PRETTY_FUNCTION__);
Calin Juravleb4eddd22016-01-13 15:52:33 -0800285 SafeMap<std::string, std::set<std::string>> tracked_locations;
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000286 {
Calin Juravleb4eddd22016-01-13 15:52:33 -0800287 // Make a copy so that we don't hold the lock while doing I/O.
288 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
289 tracked_locations = tracked_dex_base_locations_;
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000290 }
Calin Juravlec15e5662016-03-17 17:07:52 +0000291
Calin Juravle85f7bf32016-03-18 16:23:40 +0000292 bool profile_file_saved = false;
293 uint64_t total_number_of_profile_entries_cached = 0;
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100294 *new_methods = 0;
295
Calin Juravleb4eddd22016-01-13 15:52:33 -0800296 for (const auto& it : tracked_locations) {
297 if (ShuttingDown(Thread::Current())) {
298 return true;
299 }
300 const std::string& filename = it.first;
301 const std::set<std::string>& locations = it.second;
Calin Juravlee2d066d2016-04-19 16:33:46 +0100302 std::vector<MethodReference> methods;
Calin Juravleb4eddd22016-01-13 15:52:33 -0800303 {
304 ScopedObjectAccess soa(Thread::Current());
Calin Juravlee2d066d2016-04-19 16:33:46 +0100305 jit_code_cache_->GetProfiledMethods(locations, methods);
Calin Juravlec19c1c22016-03-09 15:37:48 +0000306 total_number_of_code_cache_queries_++;
Calin Juravleb4eddd22016-01-13 15:52:33 -0800307 }
Calin Juravlec15e5662016-03-17 17:07:52 +0000308
Calin Juravle85f7bf32016-03-18 16:23:40 +0000309 ProfileCompilationInfo* cached_info = GetCachedProfiledInfo(filename);
310 cached_info->AddMethodsAndClasses(methods, std::set<DexCacheResolvedClasses>());
Calin Juravle0cdaa6c2016-03-30 18:18:58 +0100311 int64_t delta_number_of_methods =
312 cached_info->GetNumberOfMethods() -
313 static_cast<int64_t>(last_save_number_of_methods_);
314 int64_t delta_number_of_classes =
315 cached_info->GetNumberOfResolvedClasses() -
316 static_cast<int64_t>(last_save_number_of_classes_);
Calin Juravle85f7bf32016-03-18 16:23:40 +0000317
318 if (delta_number_of_methods < kMinimumNumberOfMethodsToSave &&
319 delta_number_of_classes < kMinimumNumberOfClassesToSave) {
Calin Juravle0cdaa6c2016-03-30 18:18:58 +0100320 VLOG(profiler) << "Not enough information to save to: " << filename
Calin Juravle85f7bf32016-03-18 16:23:40 +0000321 << " Nr of methods: " << delta_number_of_methods
322 << " Nr of classes: " << delta_number_of_classes;
Calin Juravlec19c1c22016-03-09 15:37:48 +0000323 total_number_of_skipped_writes_++;
Calin Juravle85f7bf32016-03-18 16:23:40 +0000324 continue;
Calin Juravleb4eddd22016-01-13 15:52:33 -0800325 }
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100326 *new_methods = std::max(static_cast<uint16_t>(delta_number_of_methods), *new_methods);
Calin Juravlec19c1c22016-03-09 15:37:48 +0000327 uint64_t bytes_written;
Calin Juravlefe297a92016-03-24 20:33:22 +0000328 // Force the save. In case the profile data is corrupted or the the profile
329 // has the wrong version this will "fix" the file to the correct format.
330 if (cached_info->MergeAndSave(filename, &bytes_written, /*force*/ true)) {
Calin Juravle85f7bf32016-03-18 16:23:40 +0000331 last_save_number_of_methods_ = cached_info->GetNumberOfMethods();
Calin Juravle0cdaa6c2016-03-30 18:18:58 +0100332 last_save_number_of_classes_ = cached_info->GetNumberOfResolvedClasses();
Calin Juravle85f7bf32016-03-18 16:23:40 +0000333 // Clear resolved classes. No need to store them around as
334 // they don't change after the first write.
335 cached_info->ClearResolvedClasses();
Calin Juravlec19c1c22016-03-09 15:37:48 +0000336 if (bytes_written > 0) {
337 total_number_of_writes_++;
338 total_bytes_written_ += bytes_written;
Calin Juravle0cdaa6c2016-03-30 18:18:58 +0100339 profile_file_saved = true;
Calin Juravle85f7bf32016-03-18 16:23:40 +0000340 } else {
341 // At this point we could still have avoided the write.
342 // We load and merge the data from the file lazily at its first ever
343 // save attempt. So, whatever we are trying to save could already be
344 // in the file.
345 total_number_of_skipped_writes_++;
Calin Juravlec19c1c22016-03-09 15:37:48 +0000346 }
Calin Juravle85f7bf32016-03-18 16:23:40 +0000347 } else {
348 LOG(WARNING) << "Could not save profiling info to " << filename;
349 total_number_of_failed_writes_++;
Calin Juravleb4eddd22016-01-13 15:52:33 -0800350 }
Calin Juravle85f7bf32016-03-18 16:23:40 +0000351 total_number_of_profile_entries_cached +=
352 cached_info->GetNumberOfMethods() +
353 cached_info->GetNumberOfResolvedClasses();
Calin Juravleb4eddd22016-01-13 15:52:33 -0800354 }
Calin Juravle85f7bf32016-03-18 16:23:40 +0000355 max_number_of_profile_entries_cached_ = std::max(
356 max_number_of_profile_entries_cached_,
357 total_number_of_profile_entries_cached);
358 return profile_file_saved;
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000359}
360
361void* ProfileSaver::RunProfileSaverThread(void* arg) {
362 Runtime* runtime = Runtime::Current();
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000363
Calin Juravlee55fda12016-04-28 12:59:33 +0100364 bool attached = runtime->AttachCurrentThread("Profile Saver",
365 /*as_daemon*/true,
366 runtime->GetSystemThreadGroup(),
367 /*create_peer*/true);
368 if (!attached) {
369 CHECK(runtime->IsShuttingDown(Thread::Current()));
370 return nullptr;
371 }
372
373 ProfileSaver* profile_saver = reinterpret_cast<ProfileSaver*>(arg);
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000374 profile_saver->Run();
375
376 runtime->DetachCurrentThread();
377 VLOG(profiler) << "Profile saver shutdown";
378 return nullptr;
379}
380
Calin Juravle6044fa72016-03-25 17:17:09 +0000381static bool ShouldProfileLocation(const std::string& location) {
Calin Juravle75064232016-04-18 16:38:27 +0100382 OatFileManager& oat_manager = Runtime::Current()->GetOatFileManager();
383 const OatFile* oat_file = oat_manager.FindOpenedOatFileFromDexLocation(location);
Calin Juravle6044fa72016-03-25 17:17:09 +0000384 if (oat_file == nullptr) {
385 // This can happen if we fallback to run code directly from the APK.
386 // Profile it with the hope that the background dexopt will get us back into
387 // a good state.
Calin Juravle75064232016-04-18 16:38:27 +0100388 VLOG(profiler) << "Asked to profile a location without an oat file:" << location;
Calin Juravle6044fa72016-03-25 17:17:09 +0000389 return true;
390 }
391 CompilerFilter::Filter filter = oat_file->GetCompilerFilter();
Calin Juravled19dc462016-04-19 18:17:41 +0100392 if ((filter == CompilerFilter::kSpeed) || (filter == CompilerFilter::kEverything)) {
Calin Juravle75064232016-04-18 16:38:27 +0100393 VLOG(profiler)
Calin Juravled19dc462016-04-19 18:17:41 +0100394 << "Skip profiling oat file because it's already speed|everything compiled: "
395 << location << " oat location: " << oat_file->GetLocation();
Calin Juravle6044fa72016-03-25 17:17:09 +0000396 return false;
397 }
398 return true;
399}
400
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000401void ProfileSaver::Start(const std::string& output_filename,
402 jit::JitCodeCache* jit_code_cache,
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000403 const std::vector<std::string>& code_paths,
404 const std::string& foreign_dex_profile_path,
405 const std::string& app_data_dir) {
Calin Juravlee5de54c2016-04-20 14:22:09 +0100406 DCHECK(Runtime::Current()->SaveProfileInfo());
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000407 DCHECK(!output_filename.empty());
408 DCHECK(jit_code_cache != nullptr);
409
Calin Juravle6044fa72016-03-25 17:17:09 +0000410 std::vector<std::string> code_paths_to_profile;
411
412 for (const std::string& location : code_paths) {
413 if (ShouldProfileLocation(location)) {
414 code_paths_to_profile.push_back(location);
Calin Juravle6044fa72016-03-25 17:17:09 +0000415 }
416 }
417 if (code_paths_to_profile.empty()) {
Calin Juravle75064232016-04-18 16:38:27 +0100418 VLOG(profiler) << "No code paths should be profiled.";
Calin Juravle6044fa72016-03-25 17:17:09 +0000419 return;
420 }
421
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000422 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000423 if (instance_ != nullptr) {
Calin Juravleb4eddd22016-01-13 15:52:33 -0800424 // If we already have an instance, make sure it uses the same jit_code_cache.
425 // This may be called multiple times via Runtime::registerAppInfo (e.g. for
426 // apps which share the same runtime).
427 DCHECK_EQ(instance_->jit_code_cache_, jit_code_cache);
428 // Add the code_paths to the tracked locations.
Calin Juravle20ae7932016-04-18 18:59:22 +0100429 instance_->AddTrackedLocations(output_filename, app_data_dir, code_paths_to_profile);
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000430 return;
431 }
432
433 VLOG(profiler) << "Starting profile saver using output file: " << output_filename
Calin Juravle75064232016-04-18 16:38:27 +0100434 << ". Tracking: " << Join(code_paths_to_profile, ':');
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000435
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000436 instance_ = new ProfileSaver(output_filename,
437 jit_code_cache,
Calin Juravle75064232016-04-18 16:38:27 +0100438 code_paths_to_profile,
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000439 foreign_dex_profile_path,
440 app_data_dir);
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000441
442 // Create a new thread which does the saving.
443 CHECK_PTHREAD_CALL(
444 pthread_create,
445 (&profiler_pthread_, nullptr, &RunProfileSaverThread, reinterpret_cast<void*>(instance_)),
446 "Profile saver thread");
447}
448
Calin Juravlec19c1c22016-03-09 15:37:48 +0000449void ProfileSaver::Stop(bool dump_info) {
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000450 ProfileSaver* profile_saver = nullptr;
451 pthread_t profiler_pthread = 0U;
452
453 {
454 MutexLock profiler_mutex(Thread::Current(), *Locks::profiler_lock_);
Calin Juravleb4eddd22016-01-13 15:52:33 -0800455 VLOG(profiler) << "Stopping profile saver thread";
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000456 profile_saver = instance_;
457 profiler_pthread = profiler_pthread_;
458 if (instance_ == nullptr) {
459 DCHECK(false) << "Tried to stop a profile saver which was not started";
460 return;
461 }
462 if (instance_->shutting_down_) {
463 DCHECK(false) << "Tried to stop the profile saver twice";
464 return;
465 }
466 instance_->shutting_down_ = true;
Calin Juravlec19c1c22016-03-09 15:37:48 +0000467 if (dump_info) {
468 instance_->DumpInfo(LOG(INFO));
469 }
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000470 }
471
472 {
473 // Wake up the saver thread if it is sleeping to allow for a clean exit.
474 MutexLock wait_mutex(Thread::Current(), profile_saver->wait_lock_);
475 profile_saver->period_condition_.Signal(Thread::Current());
476 }
477
478 // Wait for the saver thread to stop.
479 CHECK_PTHREAD_CALL(pthread_join, (profiler_pthread, nullptr), "profile saver thread shutdown");
480
481 {
482 MutexLock profiler_mutex(Thread::Current(), *Locks::profiler_lock_);
483 instance_ = nullptr;
484 profiler_pthread_ = 0U;
485 }
486 delete profile_saver;
487}
488
489bool ProfileSaver::ShuttingDown(Thread* self) {
490 MutexLock mu(self, *Locks::profiler_lock_);
491 return shutting_down_;
492}
493
494bool ProfileSaver::IsStarted() {
495 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
496 return instance_ != nullptr;
497}
498
Calin Juravleb4eddd22016-01-13 15:52:33 -0800499void ProfileSaver::AddTrackedLocations(const std::string& output_filename,
Calin Juravle20ae7932016-04-18 18:59:22 +0100500 const std::string& app_data_dir,
Calin Juravleb4eddd22016-01-13 15:52:33 -0800501 const std::vector<std::string>& code_paths) {
502 auto it = tracked_dex_base_locations_.find(output_filename);
503 if (it == tracked_dex_base_locations_.end()) {
504 tracked_dex_base_locations_.Put(output_filename,
505 std::set<std::string>(code_paths.begin(), code_paths.end()));
Calin Juravle20ae7932016-04-18 18:59:22 +0100506 app_data_dirs_.insert(app_data_dir);
Calin Juravleb4eddd22016-01-13 15:52:33 -0800507 } else {
508 it->second.insert(code_paths.begin(), code_paths.end());
509 }
510}
511
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000512void ProfileSaver::NotifyDexUse(const std::string& dex_location) {
Calin Juravle6044fa72016-03-25 17:17:09 +0000513 if (!ShouldProfileLocation(dex_location)) {
514 return;
515 }
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000516 std::set<std::string> app_code_paths;
517 std::string foreign_dex_profile_path;
Calin Juravle20ae7932016-04-18 18:59:22 +0100518 std::set<std::string> app_data_dirs;
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000519 {
520 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
Calin Juravlec19c1c22016-03-09 15:37:48 +0000521 if (instance_ == nullptr) {
522 return;
523 }
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000524 // Make a copy so that we don't hold the lock while doing I/O.
525 for (const auto& it : instance_->tracked_dex_base_locations_) {
526 app_code_paths.insert(it.second.begin(), it.second.end());
527 }
528 foreign_dex_profile_path = instance_->foreign_dex_profile_path_;
Calin Juravle20ae7932016-04-18 18:59:22 +0100529 app_data_dirs.insert(instance_->app_data_dirs_.begin(), instance_->app_data_dirs_.end());
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000530 }
531
Calin Juravlec19c1c22016-03-09 15:37:48 +0000532 bool mark_created = MaybeRecordDexUseInternal(dex_location,
533 app_code_paths,
534 foreign_dex_profile_path,
Calin Juravle20ae7932016-04-18 18:59:22 +0100535 app_data_dirs);
Calin Juravlec19c1c22016-03-09 15:37:48 +0000536 if (mark_created) {
537 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
538 if (instance_ != nullptr) {
539 instance_->total_number_of_foreign_dex_marks_++;
540 }
541 }
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000542}
543
Calin Juravlec19c1c22016-03-09 15:37:48 +0000544bool ProfileSaver::MaybeRecordDexUseInternal(
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000545 const std::string& dex_location,
546 const std::set<std::string>& app_code_paths,
547 const std::string& foreign_dex_profile_path,
Calin Juravle20ae7932016-04-18 18:59:22 +0100548 const std::set<std::string>& app_data_dirs) {
Calin Juravle1fae45f2016-03-08 12:52:52 +0000549 if (dex_location.empty()) {
550 LOG(WARNING) << "Asked to record foreign dex use with an empty dex location.";
Calin Juravlec19c1c22016-03-09 15:37:48 +0000551 return false;
Calin Juravle1fae45f2016-03-08 12:52:52 +0000552 }
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000553 if (foreign_dex_profile_path.empty()) {
554 LOG(WARNING) << "Asked to record foreign dex use without a valid profile path ";
Calin Juravlec19c1c22016-03-09 15:37:48 +0000555 return false;
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000556 }
557
558 UniqueCPtr<const char[]> dex_location_real_path(realpath(dex_location.c_str(), nullptr));
Calin Juravle1fae45f2016-03-08 12:52:52 +0000559 if (dex_location_real_path == nullptr) {
560 PLOG(WARNING) << "Could not get realpath for " << dex_location;
561 }
562 std::string dex_location_real_path_str((dex_location_real_path == nullptr)
563 ? dex_location.c_str()
564 : dex_location_real_path.get());
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000565
Calin Juravle20ae7932016-04-18 18:59:22 +0100566 if (app_data_dirs.find(dex_location_real_path_str) != app_data_dirs.end()) {
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000567 // The dex location is under the application folder. Nothing to record.
Calin Juravlec19c1c22016-03-09 15:37:48 +0000568 return false;
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000569 }
570
571 if (app_code_paths.find(dex_location) != app_code_paths.end()) {
572 // The dex location belongs to the application code paths. Nothing to record.
Calin Juravlec19c1c22016-03-09 15:37:48 +0000573 return false;
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000574 }
575 // Do another round of checks with the real paths.
576 // Note that we could cache all the real locations in the saver (since it's an expensive
577 // operation). However we expect that app_code_paths is small (usually 1 element), and
578 // NotifyDexUse is called just a few times in the app lifetime. So we make the compromise
579 // to save some bytes of memory usage.
580 for (const auto& app_code_location : app_code_paths) {
581 UniqueCPtr<const char[]> real_app_code_location(realpath(app_code_location.c_str(), nullptr));
Calin Juravle1fae45f2016-03-08 12:52:52 +0000582 if (real_app_code_location == nullptr) {
583 PLOG(WARNING) << "Could not get realpath for " << app_code_location;
584 }
585 std::string real_app_code_location_str((real_app_code_location == nullptr)
586 ? app_code_location.c_str()
587 : real_app_code_location.get());
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000588 if (real_app_code_location_str == dex_location_real_path_str) {
589 // The dex location belongs to the application code paths. Nothing to record.
Calin Juravlec19c1c22016-03-09 15:37:48 +0000590 return false;
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000591 }
592 }
593
594 // For foreign dex files we record a flag on disk. PackageManager will (potentially) take this
595 // into account when deciding how to optimize the loaded dex file.
596 // The expected flag name is the canonical path of the apk where '/' is substituted to '@'.
597 // (it needs to be kept in sync with
598 // frameworks/base/services/core/java/com/android/server/pm/PackageDexOptimizer.java)
599 std::replace(dex_location_real_path_str.begin(), dex_location_real_path_str.end(), '/', '@');
600 std::string flag_path = foreign_dex_profile_path + "/" + dex_location_real_path_str;
Richard Uhler12e41572016-05-10 14:01:18 -0700601 // We use O_RDONLY as the access mode because we must supply some access
602 // mode, and there is no access mode that means 'create but do not read' the
603 // file. We will not not actually read from the file.
604 int fd = TEMP_FAILURE_RETRY(open(flag_path.c_str(),
605 O_CREAT | O_RDONLY | O_EXCL | O_CLOEXEC | O_NOFOLLOW, 0));
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000606 if (fd != -1) {
607 if (close(fd) != 0) {
608 PLOG(WARNING) << "Could not close file after flagging foreign dex use " << flag_path;
609 }
Calin Juravlec19c1c22016-03-09 15:37:48 +0000610 return true;
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000611 } else {
Richard Uhler12e41572016-05-10 14:01:18 -0700612 if (errno != EEXIST && errno != EACCES) {
613 // Another app could have already created the file, and selinux may not
614 // allow the read access to the file implied by the call to open.
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000615 PLOG(WARNING) << "Could not create foreign dex use mark " << flag_path;
Calin Juravlec19c1c22016-03-09 15:37:48 +0000616 return false;
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000617 }
Calin Juravlec19c1c22016-03-09 15:37:48 +0000618 return true;
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000619 }
620}
621
Calin Juravlec19c1c22016-03-09 15:37:48 +0000622void ProfileSaver::DumpInstanceInfo(std::ostream& os) {
623 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
624 if (instance_ != nullptr) {
625 instance_->DumpInfo(os);
626 }
627}
628
629void ProfileSaver::DumpInfo(std::ostream& os) {
630 os << "ProfileSaver total_bytes_written=" << total_bytes_written_ << '\n'
631 << "ProfileSaver total_number_of_writes=" << total_number_of_writes_ << '\n'
Calin Juravle85f7bf32016-03-18 16:23:40 +0000632 << "ProfileSaver total_number_of_code_cache_queries="
633 << total_number_of_code_cache_queries_ << '\n'
Calin Juravlec19c1c22016-03-09 15:37:48 +0000634 << "ProfileSaver total_number_of_skipped_writes=" << total_number_of_skipped_writes_ << '\n'
635 << "ProfileSaver total_number_of_failed_writes=" << total_number_of_failed_writes_ << '\n'
Calin Juravle85f7bf32016-03-18 16:23:40 +0000636 << "ProfileSaver total_ms_of_sleep=" << total_ms_of_sleep_ << '\n'
Calin Juravle6044fa72016-03-25 17:17:09 +0000637 << "ProfileSaver total_ms_of_work=" << NsToMs(total_ns_of_work_) << '\n'
Calin Juravle85f7bf32016-03-18 16:23:40 +0000638 << "ProfileSaver total_number_of_foreign_dex_marks="
639 << total_number_of_foreign_dex_marks_ << '\n'
640 << "ProfileSaver max_number_profile_entries_cached="
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100641 << max_number_of_profile_entries_cached_ << '\n'
642 << "ProfileSaver total_number_of_hot_spikes=" << total_number_of_hot_spikes_ << '\n'
643 << "ProfileSaver total_number_of_wake_ups=" << total_number_of_wake_ups_ << '\n';
Calin Juravlec19c1c22016-03-09 15:37:48 +0000644}
645
Calin Juravlee5de54c2016-04-20 14:22:09 +0100646
647void ProfileSaver::ForceProcessProfiles() {
648 ProfileSaver* saver = nullptr;
649 {
650 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
651 saver = instance_;
652 }
653 // TODO(calin): this is not actually thread safe as the instance_ may have been deleted,
654 // but we only use this in testing when we now this won't happen.
655 // Refactor the way we handle the instance so that we don't end up in this situation.
656 if (saver != nullptr) {
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100657 uint16_t new_methods;
658 saver->ProcessProfilingInfo(&new_methods);
Calin Juravlee5de54c2016-04-20 14:22:09 +0100659 }
660}
661
662bool ProfileSaver::HasSeenMethod(const std::string& profile,
663 const DexFile* dex_file,
664 uint16_t method_idx) {
665 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
666 if (instance_ != nullptr) {
667 ProfileCompilationInfo* info = instance_->GetCachedProfiledInfo(profile);
668 if (info != nullptr) {
669 return info->ContainsMethod(MethodReference(dex_file, method_idx));
670 }
671 }
672 return false;
673}
674
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000675} // namespace art