blob: edce9cd96c1bfe7fbacefb932713b5affc4cbc8b [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
Nicolas Geoffray23caed82017-04-21 14:30:18 +010019#include <sys/resource.h>
Calin Juravle86a9ebe2016-02-24 10:13:09 +000020#include <sys/types.h>
21#include <sys/stat.h>
22#include <fcntl.h>
23
Andreas Gampe9186ced2016-12-12 14:28:21 -080024#include "android-base/strings.h"
25
Calin Juravle4d77b6a2015-12-01 18:38:09 +000026#include "art_method-inl.h"
Andreas Gampe542451c2016-07-26 09:02:02 -070027#include "base/enums.h"
Mathieu Chartierfaf83202017-06-08 10:35:20 -070028#include "base/scoped_arena_containers.h"
Andreas Gampe5678db52017-06-08 14:11:18 -070029#include "base/stl_util.h"
Mathieu Chartierdabdc0f2016-03-04 14:58:03 -080030#include "base/systrace.h"
Calin Juravle6044fa72016-03-25 17:17:09 +000031#include "base/time_utils.h"
32#include "compiler_filter.h"
Mathieu Chartierfaf83202017-06-08 10:35:20 -070033#include "dex_reference_collection.h"
Mathieu Chartier39100372017-05-17 13:14:10 -070034#include "gc/collector_type.h"
35#include "gc/gc_cause.h"
36#include "gc/scoped_gc_critical_section.h"
Mathieu Chartierfaf83202017-06-08 10:35:20 -070037#include "jit/profile_compilation_info-inl.h"
Calin Juravle4d77b6a2015-12-01 18:38:09 +000038#include "oat_file_manager.h"
Mathieu Chartier0795f232016-09-27 18:43:30 -070039#include "scoped_thread_state_change-inl.h"
Calin Juravle6044fa72016-03-25 17:17:09 +000040
Calin Juravle4d77b6a2015-12-01 18:38:09 +000041namespace art {
42
Calin Juravle4d77b6a2015-12-01 18:38:09 +000043ProfileSaver* ProfileSaver::instance_ = nullptr;
44pthread_t ProfileSaver::profiler_pthread_ = 0U;
45
Calin Juravle138dbff2016-06-28 19:36:58 +010046ProfileSaver::ProfileSaver(const ProfileSaverOptions& options,
47 const std::string& output_filename,
Calin Juravle4d77b6a2015-12-01 18:38:09 +000048 jit::JitCodeCache* jit_code_cache,
Calin Juravle77651c42017-03-03 18:04:02 -080049 const std::vector<std::string>& code_paths)
Calin Juravleb4eddd22016-01-13 15:52:33 -080050 : jit_code_cache_(jit_code_cache),
Calin Juravle4d77b6a2015-12-01 18:38:09 +000051 shutting_down_(false),
Calin Juravle5fbb0fe2016-04-29 16:44:11 +010052 last_time_ns_saver_woke_up_(0),
53 jit_activity_notifications_(0),
Calin Juravle4d77b6a2015-12-01 18:38:09 +000054 wait_lock_("ProfileSaver wait lock"),
Calin Juravlec19c1c22016-03-09 15:37:48 +000055 period_condition_("ProfileSaver period condition", wait_lock_),
56 total_bytes_written_(0),
57 total_number_of_writes_(0),
58 total_number_of_code_cache_queries_(0),
59 total_number_of_skipped_writes_(0),
60 total_number_of_failed_writes_(0),
Calin Juravle85f7bf32016-03-18 16:23:40 +000061 total_ms_of_sleep_(0),
Calin Juravlec19c1c22016-03-09 15:37:48 +000062 total_ns_of_work_(0),
Calin Juravle5fbb0fe2016-04-29 16:44:11 +010063 max_number_of_profile_entries_cached_(0),
64 total_number_of_hot_spikes_(0),
Calin Juravle138dbff2016-06-28 19:36:58 +010065 total_number_of_wake_ups_(0),
66 options_(options) {
67 DCHECK(options_.IsEnabled());
Calin Juravle77651c42017-03-03 18:04:02 -080068 AddTrackedLocations(output_filename, code_paths);
Calin Juravle4d77b6a2015-12-01 18:38:09 +000069}
70
Calin Juravlecc3171a2017-05-19 16:47:53 -070071ProfileSaver::~ProfileSaver() {
72 for (auto& it : profile_cache_) {
73 delete it.second;
74 }
75}
76
Calin Juravle4d77b6a2015-12-01 18:38:09 +000077void ProfileSaver::Run() {
Calin Juravle4d77b6a2015-12-01 18:38:09 +000078 Thread* self = Thread::Current();
79
Calin Juravle5fbb0fe2016-04-29 16:44:11 +010080 // Fetch the resolved classes for the app images after sleeping for
Calin Juravle138dbff2016-06-28 19:36:58 +010081 // options_.GetSaveResolvedClassesDelayMs().
Calin Juravle5fbb0fe2016-04-29 16:44:11 +010082 // TODO(calin) This only considers the case of the primary profile file.
83 // Anything that gets loaded in the same VM will not have their resolved
84 // classes save (unless they started before the initial saving was done).
85 {
86 MutexLock mu(self, wait_lock_);
Calin Juravle138dbff2016-06-28 19:36:58 +010087 const uint64_t end_time = NanoTime() + MsToNs(options_.GetSaveResolvedClassesDelayMs());
Mathieu Chartier0ec065d2016-05-18 19:51:23 -070088 while (true) {
89 const uint64_t current_time = NanoTime();
90 if (current_time >= end_time) {
91 break;
92 }
93 period_condition_.TimedWait(self, NsToMs(end_time - current_time), 0);
94 }
Calin Juravle138dbff2016-06-28 19:36:58 +010095 total_ms_of_sleep_ += options_.GetSaveResolvedClassesDelayMs();
Calin Juravle5fbb0fe2016-04-29 16:44:11 +010096 }
Mathieu Chartierc600eaa2016-05-18 08:51:52 -070097 FetchAndCacheResolvedClassesAndMethods();
Calin Juravle5fbb0fe2016-04-29 16:44:11 +010098
99 // Loop for the profiled methods.
Mathieu Chartier8913fc12015-12-09 16:38:30 -0800100 while (!ShuttingDown(self)) {
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100101 uint64_t sleep_start = NanoTime();
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000102 {
Calin Juravle0233a412016-05-18 15:49:36 -0700103 uint64_t sleep_time = 0;
104 {
105 MutexLock mu(self, wait_lock_);
106 period_condition_.Wait(self);
Calin Juravledc85bd72016-05-25 18:09:53 +0100107 sleep_time = NanoTime() - sleep_start;
Calin Juravle0233a412016-05-18 15:49:36 -0700108 }
109 // Check if the thread was woken up for shutdown.
110 if (ShuttingDown(self)) {
111 break;
112 }
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100113 total_number_of_wake_ups_++;
114 // We might have been woken up by a huge number of notifications to guarantee saving.
115 // If we didn't meet the minimum saving period go back to sleep (only if missed by
116 // a reasonable margin).
Calin Juravle138dbff2016-06-28 19:36:58 +0100117 uint64_t min_save_period_ns = MsToNs(options_.GetMinSavePeriodMs());
118 while (min_save_period_ns * 0.9 > sleep_time) {
Calin Juravle0233a412016-05-18 15:49:36 -0700119 {
120 MutexLock mu(self, wait_lock_);
Calin Juravle138dbff2016-06-28 19:36:58 +0100121 period_condition_.TimedWait(self, NsToMs(min_save_period_ns - sleep_time), 0);
Calin Juravledc85bd72016-05-25 18:09:53 +0100122 sleep_time = NanoTime() - sleep_start;
Calin Juravle0233a412016-05-18 15:49:36 -0700123 }
124 // Check if the thread was woken up for shutdown.
125 if (ShuttingDown(self)) {
126 break;
127 }
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100128 total_number_of_wake_ups_++;
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100129 }
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000130 }
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100131 total_ms_of_sleep_ += NsToMs(NanoTime() - sleep_start);
132
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000133 if (ShuttingDown(self)) {
134 break;
135 }
136
Calin Juravlea345d312017-03-14 18:45:55 -0700137 uint16_t number_of_new_methods = 0;
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100138 uint64_t start_work = NanoTime();
Calin Juravlea345d312017-03-14 18:45:55 -0700139 bool profile_saved_to_disk = ProcessProfilingInfo(/*force_save*/false, &number_of_new_methods);
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100140 // Update the notification counter based on result. Note that there might be contention on this
141 // but we don't care about to be 100% precise.
142 if (!profile_saved_to_disk) {
143 // If we didn't save to disk it may be because we didn't have enough new methods.
Calin Juravlea345d312017-03-14 18:45:55 -0700144 // Set the jit activity notifications to number_of_new_methods so we can wake up earlier
145 // if needed.
146 jit_activity_notifications_ = number_of_new_methods;
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000147 }
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100148 total_ns_of_work_ += NanoTime() - start_work;
149 }
150}
Calin Juravlec19c1c22016-03-09 15:37:48 +0000151
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100152void ProfileSaver::NotifyJitActivity() {
153 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
154 if (instance_ == nullptr || instance_->shutting_down_) {
155 return;
156 }
157 instance_->NotifyJitActivityInternal();
158}
159
160void ProfileSaver::WakeUpSaver() {
161 jit_activity_notifications_ = 0;
162 last_time_ns_saver_woke_up_ = NanoTime();
163 period_condition_.Signal(Thread::Current());
164}
165
166void ProfileSaver::NotifyJitActivityInternal() {
167 // Unlikely to overflow but if it happens,
168 // we would have waken up the saver long before that.
169 jit_activity_notifications_++;
170 // Note that we are not as precise as we could be here but we don't want to wake the saver
171 // every time we see a hot method.
Calin Juravle138dbff2016-06-28 19:36:58 +0100172 if (jit_activity_notifications_ > options_.GetMinNotificationBeforeWake()) {
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100173 MutexLock wait_mutex(Thread::Current(), wait_lock_);
Calin Juravle138dbff2016-06-28 19:36:58 +0100174 if ((NanoTime() - last_time_ns_saver_woke_up_) > MsToNs(options_.GetMinSavePeriodMs())) {
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100175 WakeUpSaver();
Serguei Katkov87de9cf2016-08-01 17:47:04 +0700176 } else if (jit_activity_notifications_ > options_.GetMaxNotificationBeforeWake()) {
177 // Make sure to wake up the saver if we see a spike in the number of notifications.
178 // This is a precaution to avoid losing a big number of methods in case
179 // this is a spike with no jit after.
180 total_number_of_hot_spikes_++;
181 WakeUpSaver();
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100182 }
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000183 }
184}
185
Mathieu Chartierfaf83202017-06-08 10:35:20 -0700186using MethodReferenceCollection = DexReferenceCollection<uint16_t, ScopedArenaAllocatorAdapter>;
187using TypeReferenceCollection = DexReferenceCollection<dex::TypeIndex,
188 ScopedArenaAllocatorAdapter>;
189
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700190// Get resolved methods that have a profile info or more than kStartupMethodSamples samples.
191// Excludes native methods and classes in the boot image.
Mathieu Chartierfaf83202017-06-08 10:35:20 -0700192class GetClassesAndMethodsVisitor : public ClassVisitor {
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700193 public:
Mathieu Chartierfaf83202017-06-08 10:35:20 -0700194 GetClassesAndMethodsVisitor(MethodReferenceCollection* hot_methods,
195 MethodReferenceCollection* sampled_methods,
196 TypeReferenceCollection* resolved_classes,
197 uint32_t hot_method_sample_threshold)
Mathieu Chartierea650f32017-05-24 12:04:13 -0700198 : hot_methods_(hot_methods),
Mathieu Chartier7b135c82017-06-05 12:54:01 -0700199 sampled_methods_(sampled_methods),
Mathieu Chartierfaf83202017-06-08 10:35:20 -0700200 resolved_classes_(resolved_classes),
Mathieu Chartier7b135c82017-06-05 12:54:01 -0700201 hot_method_sample_threshold_(hot_method_sample_threshold) {}
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700202
Mathieu Chartier28357fa2016-10-18 16:27:40 -0700203 virtual bool operator()(ObjPtr<mirror::Class> klass) REQUIRES_SHARED(Locks::mutator_lock_) {
Mathieu Chartierfaf83202017-06-08 10:35:20 -0700204 if (klass->IsProxyClass() ||
205 klass->IsArrayClass() ||
206 !klass->IsResolved() ||
207 klass->IsErroneousResolved() ||
208 klass->GetClassLoader() == nullptr) {
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700209 return true;
210 }
Mathieu Chartierfaf83202017-06-08 10:35:20 -0700211 DCHECK(klass->GetDexCache() != nullptr) << klass->PrettyClass();
212 resolved_classes_->AddReference(&klass->GetDexFile(), klass->GetDexTypeIndex());
Andreas Gampe542451c2016-07-26 09:02:02 -0700213 for (ArtMethod& method : klass->GetMethods(kRuntimePointerSize)) {
Mathieu Chartierfaf83202017-06-08 10:35:20 -0700214 if (!method.IsNative()) {
215 DCHECK(!method.IsProxyMethod());
Mathieu Chartierea650f32017-05-24 12:04:13 -0700216 const uint16_t counter = method.GetCounter();
Mathieu Chartier7b135c82017-06-05 12:54:01 -0700217 // Mark startup methods as hot if they have more than hot_method_sample_threshold_ samples.
218 // This means they will get compiled by the compiler driver.
Mathieu Chartierea650f32017-05-24 12:04:13 -0700219 if (method.GetProfilingInfo(kRuntimePointerSize) != nullptr ||
Mathieu Chartier7b135c82017-06-05 12:54:01 -0700220 (method.GetAccessFlags() & kAccPreviouslyWarm) != 0 ||
221 counter >= hot_method_sample_threshold_) {
Mathieu Chartierfaf83202017-06-08 10:35:20 -0700222 hot_methods_->AddReference(method.GetDexFile(), method.GetDexMethodIndex());
Mathieu Chartier7b135c82017-06-05 12:54:01 -0700223 } else if (counter != 0) {
Mathieu Chartierfaf83202017-06-08 10:35:20 -0700224 sampled_methods_->AddReference(method.GetDexFile(), method.GetDexMethodIndex());
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700225 }
Mathieu Chartierea650f32017-05-24 12:04:13 -0700226 } else {
227 CHECK_EQ(method.GetCounter(), 0u);
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700228 }
229 }
230 return true;
231 }
232
233 private:
Mathieu Chartierfaf83202017-06-08 10:35:20 -0700234 MethodReferenceCollection* const hot_methods_;
235 MethodReferenceCollection* const sampled_methods_;
236 TypeReferenceCollection* const resolved_classes_;
Mathieu Chartier7b135c82017-06-05 12:54:01 -0700237 uint32_t hot_method_sample_threshold_;
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700238};
239
240void ProfileSaver::FetchAndCacheResolvedClassesAndMethods() {
Calin Juravle85f7bf32016-03-18 16:23:40 +0000241 ScopedTrace trace(__PRETTY_FUNCTION__);
Mathieu Chartierfaf83202017-06-08 10:35:20 -0700242 const uint64_t start_time = NanoTime();
Calin Juravle8b5d9b62017-05-05 17:27:23 -0700243
244 // Resolve any new registered locations.
245 ResolveTrackedLocations();
246
Mathieu Chartier39100372017-05-17 13:14:10 -0700247 Thread* const self = Thread::Current();
Mathieu Chartierfaf83202017-06-08 10:35:20 -0700248 Runtime* const runtime = Runtime::Current();
249 ArenaStack stack(runtime->GetArenaPool());
250 ScopedArenaAllocator allocator(&stack);
251 MethodReferenceCollection hot_methods(allocator.Adapter(), allocator.Adapter());
252 MethodReferenceCollection startup_methods(allocator.Adapter(), allocator.Adapter());
253 TypeReferenceCollection resolved_classes(allocator.Adapter(), allocator.Adapter());
Mathieu Chartier273d1102017-06-06 17:07:13 -0700254 const bool is_low_ram = Runtime::Current()->GetHeap()->IsLowMemoryMode();
255 const size_t hot_threshold = options_.GetHotStartupMethodSamples(is_low_ram);
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700256 {
Mathieu Chartier39100372017-05-17 13:14:10 -0700257 ScopedObjectAccess soa(self);
258 gc::ScopedGCCriticalSection sgcs(self,
259 gc::kGcCauseProfileSaver,
260 gc::kCollectorTypeCriticalSection);
Mathieu Chartier39100372017-05-17 13:14:10 -0700261 {
262 ScopedTrace trace2("Get hot methods");
Mathieu Chartierfaf83202017-06-08 10:35:20 -0700263 GetClassesAndMethodsVisitor visitor(&hot_methods,
264 &startup_methods,
265 &resolved_classes,
266 hot_threshold);
267 runtime->GetClassLinker()->VisitClasses(&visitor);
Mathieu Chartier39100372017-05-17 13:14:10 -0700268 }
Mathieu Chartierc600eaa2016-05-18 08:51:52 -0700269 }
Mathieu Chartierfaf83202017-06-08 10:35:20 -0700270
Mathieu Chartier39100372017-05-17 13:14:10 -0700271 MutexLock mu(self, *Locks::profiler_lock_);
Calin Juravle85f7bf32016-03-18 16:23:40 +0000272 uint64_t total_number_of_profile_entries_cached = 0;
Mathieu Chartier9275af62016-04-29 12:03:56 -0700273
Calin Juravle85f7bf32016-03-18 16:23:40 +0000274 for (const auto& it : tracked_dex_base_locations_) {
Mathieu Chartier9275af62016-04-29 12:03:56 -0700275 std::set<DexCacheResolvedClasses> resolved_classes_for_location;
Calin Juravle85f7bf32016-03-18 16:23:40 +0000276 const std::string& filename = it.first;
Calin Juravlee6f87cc2017-05-24 17:41:05 -0700277 auto info_it = profile_cache_.Put(
278 filename,
279 new ProfileCompilationInfo(Runtime::Current()->GetArenaPool()));
Calin Juravlecc3171a2017-05-19 16:47:53 -0700280 ProfileCompilationInfo* cached_info = info_it->second;
Mathieu Chartierfaf83202017-06-08 10:35:20 -0700281
282 const std::set<std::string>& locations = it.second;
283 for (const auto& pair : hot_methods.GetMap()) {
284 const DexFile* const dex_file = pair.first;
285 if (locations.find(dex_file->GetBaseLocation()) != locations.end()) {
286 cached_info->AddSampledMethodsForDex(/*startup*/ true,
287 dex_file,
288 pair.second.begin(),
289 pair.second.end());
290 // Adding hot methods is a bit slow, TODO: optimize.
291 cached_info->AddHotMethodsForDex(dex_file, pair.second.begin(), pair.second.end());
292 }
293 }
294 for (const auto& pair : startup_methods.GetMap()) {
295 const DexFile* const dex_file = pair.first;
296 if (locations.find(dex_file->GetBaseLocation()) != locations.end()) {
297 cached_info->AddSampledMethodsForDex(/*startup*/ true,
298 dex_file,
299 pair.second.begin(),
300 pair.second.end());
301 }
302 }
303 for (const auto& pair : resolved_classes.GetMap()) {
304 const DexFile* const dex_file = pair.first;
305 if (locations.find(dex_file->GetBaseLocation()) != locations.end()) {
306 const TypeReferenceCollection::IndexVector& classes = pair.second;
307 VLOG(profiler) << "Added " << classes.size() << " classes for location "
308 << dex_file->GetBaseLocation()
309 << " (" << dex_file->GetLocation() << ")";
310 cached_info->AddClassesForDex(dex_file, classes.begin(), classes.end());
311 } else {
312 VLOG(profiler) << "Location not found " << dex_file->GetBaseLocation()
313 << " (" << dex_file->GetLocation() << ")";
314 }
315 }
Calin Juravle85f7bf32016-03-18 16:23:40 +0000316 total_number_of_profile_entries_cached += resolved_classes_for_location.size();
317 }
318 max_number_of_profile_entries_cached_ = std::max(
319 max_number_of_profile_entries_cached_,
320 total_number_of_profile_entries_cached);
Mathieu Chartierfaf83202017-06-08 10:35:20 -0700321 VLOG(profiler) << "Profile saver recorded " << hot_methods.NumReferences() << " hot methods and "
322 << startup_methods.NumReferences() << " startup methods with threshold "
323 << hot_threshold << " in " << PrettyDuration(NanoTime() - start_time);
Calin Juravle85f7bf32016-03-18 16:23:40 +0000324}
325
Calin Juravlea345d312017-03-14 18:45:55 -0700326bool ProfileSaver::ProcessProfilingInfo(bool force_save, /*out*/uint16_t* number_of_new_methods) {
Calin Juravle85f7bf32016-03-18 16:23:40 +0000327 ScopedTrace trace(__PRETTY_FUNCTION__);
Calin Juravle8b5d9b62017-05-05 17:27:23 -0700328
329 // Resolve any new registered locations.
330 ResolveTrackedLocations();
331
Calin Juravleb4eddd22016-01-13 15:52:33 -0800332 SafeMap<std::string, std::set<std::string>> tracked_locations;
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000333 {
Calin Juravleb4eddd22016-01-13 15:52:33 -0800334 // Make a copy so that we don't hold the lock while doing I/O.
335 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
336 tracked_locations = tracked_dex_base_locations_;
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000337 }
Calin Juravlec15e5662016-03-17 17:07:52 +0000338
Calin Juravle85f7bf32016-03-18 16:23:40 +0000339 bool profile_file_saved = false;
Calin Juravlea345d312017-03-14 18:45:55 -0700340 if (number_of_new_methods != nullptr) {
341 *number_of_new_methods = 0;
342 }
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100343
Calin Juravleb4eddd22016-01-13 15:52:33 -0800344 for (const auto& it : tracked_locations) {
Calin Juravlea345d312017-03-14 18:45:55 -0700345 if (!force_save && ShuttingDown(Thread::Current())) {
346 // The ProfileSaver is in shutdown mode, meaning a stop request was made and
347 // we need to exit cleanly (by waiting for the saver thread to finish). Unless
348 // we have a request for a forced save, do not do any processing so that we
349 // speed up the exit.
Calin Juravleb4eddd22016-01-13 15:52:33 -0800350 return true;
351 }
352 const std::string& filename = it.first;
353 const std::set<std::string>& locations = it.second;
Calin Juravle940eb0c2017-01-30 19:30:44 -0800354 std::vector<ProfileMethodInfo> profile_methods;
Calin Juravleb4eddd22016-01-13 15:52:33 -0800355 {
356 ScopedObjectAccess soa(Thread::Current());
Calin Juravle940eb0c2017-01-30 19:30:44 -0800357 jit_code_cache_->GetProfiledMethods(locations, profile_methods);
Calin Juravlec19c1c22016-03-09 15:37:48 +0000358 total_number_of_code_cache_queries_++;
Calin Juravleb4eddd22016-01-13 15:52:33 -0800359 }
Calin Juravlecc3171a2017-05-19 16:47:53 -0700360 {
361 ProfileCompilationInfo info(Runtime::Current()->GetArenaPool());
362 if (!info.Load(filename, /*clear_if_invalid*/ true)) {
363 LOG(WARNING) << "Could not forcefully load profile " << filename;
364 continue;
365 }
366 uint64_t last_save_number_of_methods = info.GetNumberOfMethods();
367 uint64_t last_save_number_of_classes = info.GetNumberOfResolvedClasses();
Calin Juravlec15e5662016-03-17 17:07:52 +0000368
Mathieu Chartierea650f32017-05-24 12:04:13 -0700369 info.AddMethodsAndClasses(profile_methods, std::set<DexCacheResolvedClasses>());
Calin Juravlecc3171a2017-05-19 16:47:53 -0700370 auto profile_cache_it = profile_cache_.find(filename);
Calin Juravledcab1902017-05-12 19:18:47 -0700371 if (profile_cache_it != profile_cache_.end()) {
Calin Juravlecc3171a2017-05-19 16:47:53 -0700372 info.MergeWith(*(profile_cache_it->second));
Calin Juravledcab1902017-05-12 19:18:47 -0700373 }
Calin Juravlecc3171a2017-05-19 16:47:53 -0700374
375 int64_t delta_number_of_methods =
376 info.GetNumberOfMethods() - last_save_number_of_methods;
377 int64_t delta_number_of_classes =
378 info.GetNumberOfResolvedClasses() - last_save_number_of_classes;
379
380 if (!force_save &&
381 delta_number_of_methods < options_.GetMinMethodsToSave() &&
382 delta_number_of_classes < options_.GetMinClassesToSave()) {
383 VLOG(profiler) << "Not enough information to save to: " << filename
384 << " Number of methods: " << delta_number_of_methods
385 << " Number of classes: " << delta_number_of_classes;
Calin Juravle85f7bf32016-03-18 16:23:40 +0000386 total_number_of_skipped_writes_++;
Calin Juravlecc3171a2017-05-19 16:47:53 -0700387 continue;
Calin Juravlec19c1c22016-03-09 15:37:48 +0000388 }
Calin Juravlecc3171a2017-05-19 16:47:53 -0700389 if (number_of_new_methods != nullptr) {
390 *number_of_new_methods =
391 std::max(static_cast<uint16_t>(delta_number_of_methods),
392 *number_of_new_methods);
393 }
394 uint64_t bytes_written;
395 // Force the save. In case the profile data is corrupted or the the profile
396 // has the wrong version this will "fix" the file to the correct format.
397 if (info.Save(filename, &bytes_written)) {
398 // We managed to save the profile. Clear the cache stored during startup.
399 if (profile_cache_it != profile_cache_.end()) {
400 ProfileCompilationInfo *cached_info = profile_cache_it->second;
401 profile_cache_.erase(profile_cache_it);
402 delete cached_info;
403 }
404 if (bytes_written > 0) {
405 total_number_of_writes_++;
406 total_bytes_written_ += bytes_written;
407 profile_file_saved = true;
408 } else {
409 // At this point we could still have avoided the write.
410 // We load and merge the data from the file lazily at its first ever
411 // save attempt. So, whatever we are trying to save could already be
412 // in the file.
413 total_number_of_skipped_writes_++;
414 }
415 } else {
416 LOG(WARNING) << "Could not save profiling info to " << filename;
417 total_number_of_failed_writes_++;
418 }
Calin Juravleb4eddd22016-01-13 15:52:33 -0800419 }
Calin Juravlee6f87cc2017-05-24 17:41:05 -0700420 // Trim the maps to madvise the pages used for profile info.
421 // It is unlikely we will need them again in the near feature.
Calin Juravlecc3171a2017-05-19 16:47:53 -0700422 Runtime::Current()->GetArenaPool()->TrimMaps();
Calin Juravleb4eddd22016-01-13 15:52:33 -0800423 }
Calin Juravledcab1902017-05-12 19:18:47 -0700424
Calin Juravle85f7bf32016-03-18 16:23:40 +0000425 return profile_file_saved;
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000426}
427
428void* ProfileSaver::RunProfileSaverThread(void* arg) {
429 Runtime* runtime = Runtime::Current();
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000430
Calin Juravlee55fda12016-04-28 12:59:33 +0100431 bool attached = runtime->AttachCurrentThread("Profile Saver",
432 /*as_daemon*/true,
433 runtime->GetSystemThreadGroup(),
434 /*create_peer*/true);
435 if (!attached) {
436 CHECK(runtime->IsShuttingDown(Thread::Current()));
437 return nullptr;
438 }
439
440 ProfileSaver* profile_saver = reinterpret_cast<ProfileSaver*>(arg);
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000441 profile_saver->Run();
442
443 runtime->DetachCurrentThread();
444 VLOG(profiler) << "Profile saver shutdown";
445 return nullptr;
446}
447
Calin Juravle6044fa72016-03-25 17:17:09 +0000448static bool ShouldProfileLocation(const std::string& location) {
Calin Juravle75064232016-04-18 16:38:27 +0100449 OatFileManager& oat_manager = Runtime::Current()->GetOatFileManager();
450 const OatFile* oat_file = oat_manager.FindOpenedOatFileFromDexLocation(location);
Calin Juravle6044fa72016-03-25 17:17:09 +0000451 if (oat_file == nullptr) {
452 // This can happen if we fallback to run code directly from the APK.
453 // Profile it with the hope that the background dexopt will get us back into
454 // a good state.
Calin Juravle75064232016-04-18 16:38:27 +0100455 VLOG(profiler) << "Asked to profile a location without an oat file:" << location;
Calin Juravle6044fa72016-03-25 17:17:09 +0000456 return true;
457 }
458 CompilerFilter::Filter filter = oat_file->GetCompilerFilter();
Calin Juravled19dc462016-04-19 18:17:41 +0100459 if ((filter == CompilerFilter::kSpeed) || (filter == CompilerFilter::kEverything)) {
Calin Juravle75064232016-04-18 16:38:27 +0100460 VLOG(profiler)
Calin Juravled19dc462016-04-19 18:17:41 +0100461 << "Skip profiling oat file because it's already speed|everything compiled: "
462 << location << " oat location: " << oat_file->GetLocation();
Calin Juravle6044fa72016-03-25 17:17:09 +0000463 return false;
464 }
465 return true;
466}
467
Calin Juravle138dbff2016-06-28 19:36:58 +0100468void ProfileSaver::Start(const ProfileSaverOptions& options,
469 const std::string& output_filename,
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000470 jit::JitCodeCache* jit_code_cache,
Calin Juravle77651c42017-03-03 18:04:02 -0800471 const std::vector<std::string>& code_paths) {
Calin Juravle138dbff2016-06-28 19:36:58 +0100472 DCHECK(options.IsEnabled());
473 DCHECK(Runtime::Current()->GetJit() != nullptr);
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000474 DCHECK(!output_filename.empty());
475 DCHECK(jit_code_cache != nullptr);
476
Calin Juravle6044fa72016-03-25 17:17:09 +0000477 std::vector<std::string> code_paths_to_profile;
478
479 for (const std::string& location : code_paths) {
480 if (ShouldProfileLocation(location)) {
481 code_paths_to_profile.push_back(location);
Calin Juravle6044fa72016-03-25 17:17:09 +0000482 }
483 }
484 if (code_paths_to_profile.empty()) {
Calin Juravle75064232016-04-18 16:38:27 +0100485 VLOG(profiler) << "No code paths should be profiled.";
Calin Juravle6044fa72016-03-25 17:17:09 +0000486 return;
487 }
488
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000489 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000490 if (instance_ != nullptr) {
Calin Juravleb4eddd22016-01-13 15:52:33 -0800491 // If we already have an instance, make sure it uses the same jit_code_cache.
492 // This may be called multiple times via Runtime::registerAppInfo (e.g. for
493 // apps which share the same runtime).
494 DCHECK_EQ(instance_->jit_code_cache_, jit_code_cache);
495 // Add the code_paths to the tracked locations.
Calin Juravle77651c42017-03-03 18:04:02 -0800496 instance_->AddTrackedLocations(output_filename, code_paths_to_profile);
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000497 return;
498 }
499
500 VLOG(profiler) << "Starting profile saver using output file: " << output_filename
Andreas Gampe9186ced2016-12-12 14:28:21 -0800501 << ". Tracking: " << android::base::Join(code_paths_to_profile, ':');
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000502
Calin Juravle138dbff2016-06-28 19:36:58 +0100503 instance_ = new ProfileSaver(options,
504 output_filename,
Calin Juravle86a9ebe2016-02-24 10:13:09 +0000505 jit_code_cache,
Calin Juravle77651c42017-03-03 18:04:02 -0800506 code_paths_to_profile);
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000507
508 // Create a new thread which does the saving.
509 CHECK_PTHREAD_CALL(
510 pthread_create,
511 (&profiler_pthread_, nullptr, &RunProfileSaverThread, reinterpret_cast<void*>(instance_)),
512 "Profile saver thread");
Nicolas Geoffray23caed82017-04-21 14:30:18 +0100513
514#if defined(ART_TARGET_ANDROID)
515 // At what priority to schedule the saver threads. 9 is the lowest foreground priority on device.
516 static constexpr int kProfileSaverPthreadPriority = 9;
517 int result = setpriority(
518 PRIO_PROCESS, pthread_gettid_np(profiler_pthread_), kProfileSaverPthreadPriority);
519 if (result != 0) {
520 PLOG(ERROR) << "Failed to setpriority to :" << kProfileSaverPthreadPriority;
521 }
522#endif
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000523}
524
Calin Juravlec19c1c22016-03-09 15:37:48 +0000525void ProfileSaver::Stop(bool dump_info) {
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000526 ProfileSaver* profile_saver = nullptr;
527 pthread_t profiler_pthread = 0U;
528
529 {
530 MutexLock profiler_mutex(Thread::Current(), *Locks::profiler_lock_);
Calin Juravleb4eddd22016-01-13 15:52:33 -0800531 VLOG(profiler) << "Stopping profile saver thread";
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000532 profile_saver = instance_;
533 profiler_pthread = profiler_pthread_;
534 if (instance_ == nullptr) {
535 DCHECK(false) << "Tried to stop a profile saver which was not started";
536 return;
537 }
538 if (instance_->shutting_down_) {
539 DCHECK(false) << "Tried to stop the profile saver twice";
540 return;
541 }
542 instance_->shutting_down_ = true;
543 }
544
545 {
546 // Wake up the saver thread if it is sleeping to allow for a clean exit.
547 MutexLock wait_mutex(Thread::Current(), profile_saver->wait_lock_);
548 profile_saver->period_condition_.Signal(Thread::Current());
549 }
550
551 // Wait for the saver thread to stop.
552 CHECK_PTHREAD_CALL(pthread_join, (profiler_pthread, nullptr), "profile saver thread shutdown");
553
Calin Juravlea345d312017-03-14 18:45:55 -0700554 // Force save everything before destroying the instance.
555 instance_->ProcessProfilingInfo(/*force_save*/true, /*number_of_new_methods*/nullptr);
556
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000557 {
558 MutexLock profiler_mutex(Thread::Current(), *Locks::profiler_lock_);
Calin Juravle9db22e82017-03-30 16:31:23 -0700559 if (dump_info) {
560 instance_->DumpInfo(LOG_STREAM(INFO));
561 }
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000562 instance_ = nullptr;
563 profiler_pthread_ = 0U;
564 }
565 delete profile_saver;
566}
567
568bool ProfileSaver::ShuttingDown(Thread* self) {
569 MutexLock mu(self, *Locks::profiler_lock_);
570 return shutting_down_;
571}
572
573bool ProfileSaver::IsStarted() {
574 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
575 return instance_ != nullptr;
576}
577
Calin Juravle8b5d9b62017-05-05 17:27:23 -0700578static void AddTrackedLocationsToMap(const std::string& output_filename,
579 const std::vector<std::string>& code_paths,
580 SafeMap<std::string, std::set<std::string>>* map) {
581 auto it = map->find(output_filename);
582 if (it == map->end()) {
583 map->Put(output_filename, std::set<std::string>(code_paths.begin(), code_paths.end()));
Calin Juravleb4eddd22016-01-13 15:52:33 -0800584 } else {
585 it->second.insert(code_paths.begin(), code_paths.end());
586 }
587}
588
Calin Juravle8b5d9b62017-05-05 17:27:23 -0700589void ProfileSaver::AddTrackedLocations(const std::string& output_filename,
590 const std::vector<std::string>& code_paths) {
591 // Add the code paths to the list of tracked location.
592 AddTrackedLocationsToMap(output_filename, code_paths, &tracked_dex_base_locations_);
593 // The code paths may contain symlinks which could fool the profiler.
594 // If the dex file is compiled with an absolute location but loaded with symlink
595 // the profiler could skip the dex due to location mismatch.
596 // To avoid this, we add the code paths to the temporary cache of 'to_be_resolved'
597 // locations. When the profiler thread executes we will resolve the paths to their
598 // real paths.
599 // Note that we delay taking the realpath to avoid spending more time than needed
600 // when registering location (as it is done during app launch).
601 AddTrackedLocationsToMap(output_filename,
602 code_paths,
603 &tracked_dex_base_locations_to_be_resolved_);
604}
605
Calin Juravlec19c1c22016-03-09 15:37:48 +0000606void ProfileSaver::DumpInstanceInfo(std::ostream& os) {
607 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
608 if (instance_ != nullptr) {
609 instance_->DumpInfo(os);
610 }
611}
612
613void ProfileSaver::DumpInfo(std::ostream& os) {
614 os << "ProfileSaver total_bytes_written=" << total_bytes_written_ << '\n'
615 << "ProfileSaver total_number_of_writes=" << total_number_of_writes_ << '\n'
Calin Juravle85f7bf32016-03-18 16:23:40 +0000616 << "ProfileSaver total_number_of_code_cache_queries="
617 << total_number_of_code_cache_queries_ << '\n'
Calin Juravlec19c1c22016-03-09 15:37:48 +0000618 << "ProfileSaver total_number_of_skipped_writes=" << total_number_of_skipped_writes_ << '\n'
619 << "ProfileSaver total_number_of_failed_writes=" << total_number_of_failed_writes_ << '\n'
Calin Juravle85f7bf32016-03-18 16:23:40 +0000620 << "ProfileSaver total_ms_of_sleep=" << total_ms_of_sleep_ << '\n'
Calin Juravle6044fa72016-03-25 17:17:09 +0000621 << "ProfileSaver total_ms_of_work=" << NsToMs(total_ns_of_work_) << '\n'
Calin Juravle85f7bf32016-03-18 16:23:40 +0000622 << "ProfileSaver max_number_profile_entries_cached="
Calin Juravle5fbb0fe2016-04-29 16:44:11 +0100623 << max_number_of_profile_entries_cached_ << '\n'
624 << "ProfileSaver total_number_of_hot_spikes=" << total_number_of_hot_spikes_ << '\n'
625 << "ProfileSaver total_number_of_wake_ups=" << total_number_of_wake_ups_ << '\n';
Calin Juravlec19c1c22016-03-09 15:37:48 +0000626}
627
Calin Juravlee5de54c2016-04-20 14:22:09 +0100628
629void ProfileSaver::ForceProcessProfiles() {
630 ProfileSaver* saver = nullptr;
631 {
632 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
633 saver = instance_;
634 }
635 // TODO(calin): this is not actually thread safe as the instance_ may have been deleted,
636 // but we only use this in testing when we now this won't happen.
637 // Refactor the way we handle the instance so that we don't end up in this situation.
638 if (saver != nullptr) {
Calin Juravlea345d312017-03-14 18:45:55 -0700639 saver->ProcessProfilingInfo(/*force_save*/true, /*number_of_new_methods*/nullptr);
Calin Juravlee5de54c2016-04-20 14:22:09 +0100640 }
641}
642
643bool ProfileSaver::HasSeenMethod(const std::string& profile,
644 const DexFile* dex_file,
645 uint16_t method_idx) {
646 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
647 if (instance_ != nullptr) {
Calin Juravlecc3171a2017-05-19 16:47:53 -0700648 ProfileCompilationInfo info(Runtime::Current()->GetArenaPool());
Calin Juravledcab1902017-05-12 19:18:47 -0700649 if (!info.Load(profile, /*clear_if_invalid*/false)) {
650 return false;
651 }
Mathieu Chartier7b135c82017-06-05 12:54:01 -0700652 return info.ContainsHotMethod(MethodReference(dex_file, method_idx));
Calin Juravlee5de54c2016-04-20 14:22:09 +0100653 }
654 return false;
655}
656
Calin Juravle8b5d9b62017-05-05 17:27:23 -0700657void ProfileSaver::ResolveTrackedLocations() {
658 SafeMap<std::string, std::set<std::string>> locations_to_be_resolved;
659 {
660 // Make a copy so that we don't hold the lock while doing I/O.
661 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
662 locations_to_be_resolved = tracked_dex_base_locations_to_be_resolved_;
663 tracked_dex_base_locations_to_be_resolved_.clear();
664 }
665
666 // Resolve the locations.
667 SafeMap<std::string, std::vector<std::string>> resolved_locations_map;
668 for (const auto& it : locations_to_be_resolved) {
669 const std::string& filename = it.first;
670 const std::set<std::string>& locations = it.second;
671 auto resolved_locations_it = resolved_locations_map.Put(
672 filename,
673 std::vector<std::string>(locations.size()));
674
675 for (const auto& location : locations) {
676 UniqueCPtr<const char[]> location_real(realpath(location.c_str(), nullptr));
677 // Note that it's ok if we cannot get the real path.
678 if (location_real != nullptr) {
679 resolved_locations_it->second.emplace_back(location_real.get());
680 }
681 }
682 }
683
684 // Add the resolved locations to the tracked collection.
685 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
686 for (const auto& it : resolved_locations_map) {
687 AddTrackedLocationsToMap(it.first, it.second, &tracked_dex_base_locations_);
688 }
689}
690
Calin Juravle4d77b6a2015-12-01 18:38:09 +0000691} // namespace art