1 /*
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
19 #include <fcntl.h>
20 #include <sys/resource.h>
21 #include <sys/stat.h>
22 #include <sys/types.h>
23
24 #include "android-base/strings.h"
25
26 #include "art_method-inl.h"
27 #include "base/enums.h"
28 #include "base/logging.h" // For VLOG.
29 #include "base/scoped_arena_containers.h"
30 #include "base/stl_util.h"
31 #include "base/systrace.h"
32 #include "base/time_utils.h"
33 #include "class_table-inl.h"
34 #include "compiler_filter.h"
35 #include "dex/dex_file_loader.h"
36 #include "dex_reference_collection.h"
37 #include "gc/collector_type.h"
38 #include "gc/gc_cause.h"
39 #include "gc/scoped_gc_critical_section.h"
40 #include "jit/profile_compilation_info.h"
41 #include "oat_file_manager.h"
42 #include "scoped_thread_state_change-inl.h"
43
44 namespace art {
45
46 ProfileSaver* ProfileSaver::instance_ = nullptr;
47 pthread_t ProfileSaver::profiler_pthread_ = 0U;
48
49 // At what priority to schedule the saver threads. 9 is the lowest foreground priority on device.
50 static constexpr int kProfileSaverPthreadPriority = 9;
51
SetProfileSaverThreadPriority(pthread_t thread,int priority)52 static void SetProfileSaverThreadPriority(pthread_t thread, int priority) {
53 #if defined(ART_TARGET_ANDROID)
54 int result = setpriority(PRIO_PROCESS, pthread_gettid_np(thread), priority);
55 if (result != 0) {
56 LOG(ERROR) << "Failed to setpriority to :" << priority;
57 }
58 #else
59 UNUSED(thread);
60 UNUSED(priority);
61 #endif
62 }
63
GetDefaultThreadPriority()64 static int GetDefaultThreadPriority() {
65 #if defined(ART_TARGET_ANDROID)
66 pthread_attr_t attr;
67 sched_param param;
68 pthread_attr_init(&attr);
69 pthread_attr_getschedparam(&attr, ¶m);
70 return param.sched_priority;
71 #else
72 return 0;
73 #endif
74 }
75
ProfileSaver(const ProfileSaverOptions & options,const std::string & output_filename,jit::JitCodeCache * jit_code_cache,const std::vector<std::string> & code_paths)76 ProfileSaver::ProfileSaver(const ProfileSaverOptions& options,
77 const std::string& output_filename,
78 jit::JitCodeCache* jit_code_cache,
79 const std::vector<std::string>& code_paths)
80 : jit_code_cache_(jit_code_cache),
81 shutting_down_(false),
82 last_time_ns_saver_woke_up_(0),
83 jit_activity_notifications_(0),
84 wait_lock_("ProfileSaver wait lock"),
85 period_condition_("ProfileSaver period condition", wait_lock_),
86 total_bytes_written_(0),
87 total_number_of_writes_(0),
88 total_number_of_code_cache_queries_(0),
89 total_number_of_skipped_writes_(0),
90 total_number_of_failed_writes_(0),
91 total_ms_of_sleep_(0),
92 total_ns_of_work_(0),
93 max_number_of_profile_entries_cached_(0),
94 total_number_of_hot_spikes_(0),
95 total_number_of_wake_ups_(0),
96 options_(options) {
97 DCHECK(options_.IsEnabled());
98 AddTrackedLocations(output_filename, code_paths);
99 }
100
~ProfileSaver()101 ProfileSaver::~ProfileSaver() {
102 for (auto& it : profile_cache_) {
103 delete it.second;
104 }
105 }
106
Run()107 void ProfileSaver::Run() {
108 Thread* self = Thread::Current();
109
110 // Fetch the resolved classes for the app images after sleeping for
111 // options_.GetSaveResolvedClassesDelayMs().
112 // TODO(calin) This only considers the case of the primary profile file.
113 // Anything that gets loaded in the same VM will not have their resolved
114 // classes save (unless they started before the initial saving was done).
115 {
116 MutexLock mu(self, wait_lock_);
117 const uint64_t end_time = NanoTime() + MsToNs(options_.GetSaveResolvedClassesDelayMs());
118 while (true) {
119 const uint64_t current_time = NanoTime();
120 if (current_time >= end_time) {
121 break;
122 }
123 period_condition_.TimedWait(self, NsToMs(end_time - current_time), 0);
124 }
125 total_ms_of_sleep_ += options_.GetSaveResolvedClassesDelayMs();
126 }
127 FetchAndCacheResolvedClassesAndMethods(/*startup*/ true);
128
129
130 // When we save without waiting for JIT notifications we use a simple
131 // exponential back off policy bounded by max_wait_without_jit.
132 uint32_t max_wait_without_jit = options_.GetMinSavePeriodMs() * 16;
133 uint64_t cur_wait_without_jit = options_.GetMinSavePeriodMs();
134 // Loop for the profiled methods.
135 while (!ShuttingDown(self)) {
136 uint64_t sleep_start = NanoTime();
137 {
138 uint64_t sleep_time = 0;
139 {
140 MutexLock mu(self, wait_lock_);
141 if (options_.GetWaitForJitNotificationsToSave()) {
142 period_condition_.Wait(self);
143 } else {
144 period_condition_.TimedWait(self, cur_wait_without_jit, 0);
145 if (cur_wait_without_jit < max_wait_without_jit) {
146 cur_wait_without_jit *= 2;
147 }
148 }
149 sleep_time = NanoTime() - sleep_start;
150 }
151 // Check if the thread was woken up for shutdown.
152 if (ShuttingDown(self)) {
153 break;
154 }
155 total_number_of_wake_ups_++;
156 // We might have been woken up by a huge number of notifications to guarantee saving.
157 // If we didn't meet the minimum saving period go back to sleep (only if missed by
158 // a reasonable margin).
159 uint64_t min_save_period_ns = MsToNs(options_.GetMinSavePeriodMs());
160 while (min_save_period_ns * 0.9 > sleep_time) {
161 {
162 MutexLock mu(self, wait_lock_);
163 period_condition_.TimedWait(self, NsToMs(min_save_period_ns - sleep_time), 0);
164 sleep_time = NanoTime() - sleep_start;
165 }
166 // Check if the thread was woken up for shutdown.
167 if (ShuttingDown(self)) {
168 break;
169 }
170 total_number_of_wake_ups_++;
171 }
172 }
173 total_ms_of_sleep_ += NsToMs(NanoTime() - sleep_start);
174
175 if (ShuttingDown(self)) {
176 break;
177 }
178
179 uint16_t number_of_new_methods = 0;
180 uint64_t start_work = NanoTime();
181 bool profile_saved_to_disk = ProcessProfilingInfo(/*force_save*/false, &number_of_new_methods);
182 // Update the notification counter based on result. Note that there might be contention on this
183 // but we don't care about to be 100% precise.
184 if (!profile_saved_to_disk) {
185 // If we didn't save to disk it may be because we didn't have enough new methods.
186 // Set the jit activity notifications to number_of_new_methods so we can wake up earlier
187 // if needed.
188 jit_activity_notifications_ = number_of_new_methods;
189 }
190 total_ns_of_work_ += NanoTime() - start_work;
191 }
192 }
193
NotifyJitActivity()194 void ProfileSaver::NotifyJitActivity() {
195 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
196 if (instance_ == nullptr || instance_->shutting_down_) {
197 return;
198 }
199 instance_->NotifyJitActivityInternal();
200 }
201
WakeUpSaver()202 void ProfileSaver::WakeUpSaver() {
203 jit_activity_notifications_ = 0;
204 last_time_ns_saver_woke_up_ = NanoTime();
205 period_condition_.Signal(Thread::Current());
206 }
207
NotifyJitActivityInternal()208 void ProfileSaver::NotifyJitActivityInternal() {
209 // Unlikely to overflow but if it happens,
210 // we would have waken up the saver long before that.
211 jit_activity_notifications_++;
212 // Note that we are not as precise as we could be here but we don't want to wake the saver
213 // every time we see a hot method.
214 if (jit_activity_notifications_ > options_.GetMinNotificationBeforeWake()) {
215 MutexLock wait_mutex(Thread::Current(), wait_lock_);
216 if ((NanoTime() - last_time_ns_saver_woke_up_) > MsToNs(options_.GetMinSavePeriodMs())) {
217 WakeUpSaver();
218 } else if (jit_activity_notifications_ > options_.GetMaxNotificationBeforeWake()) {
219 // Make sure to wake up the saver if we see a spike in the number of notifications.
220 // This is a precaution to avoid losing a big number of methods in case
221 // this is a spike with no jit after.
222 total_number_of_hot_spikes_++;
223 WakeUpSaver();
224 }
225 }
226 }
227
228 class ScopedDefaultPriority {
229 public:
ScopedDefaultPriority(pthread_t thread)230 explicit ScopedDefaultPriority(pthread_t thread) : thread_(thread) {
231 SetProfileSaverThreadPriority(thread_, GetDefaultThreadPriority());
232 }
233
~ScopedDefaultPriority()234 ~ScopedDefaultPriority() {
235 SetProfileSaverThreadPriority(thread_, kProfileSaverPthreadPriority);
236 }
237
238 private:
239 const pthread_t thread_;
240 };
241
242 // GetClassLoadersVisitor takes a snapshot of the class loaders and stores them in the out
243 // class_loaders argument. Not affected by class unloading since there are no suspend points in
244 // the caller.
245 class GetClassLoadersVisitor : public ClassLoaderVisitor {
246 public:
GetClassLoadersVisitor(VariableSizedHandleScope * hs,std::vector<Handle<mirror::ClassLoader>> * class_loaders)247 explicit GetClassLoadersVisitor(VariableSizedHandleScope* hs,
248 std::vector<Handle<mirror::ClassLoader>>* class_loaders)
249 : hs_(hs),
250 class_loaders_(class_loaders) {}
251
Visit(ObjPtr<mirror::ClassLoader> class_loader)252 void Visit(ObjPtr<mirror::ClassLoader> class_loader)
253 REQUIRES_SHARED(Locks::classlinker_classes_lock_, Locks::mutator_lock_) OVERRIDE {
254 class_loaders_->push_back(hs_->NewHandle(class_loader));
255 }
256
257 private:
258 VariableSizedHandleScope* const hs_;
259 std::vector<Handle<mirror::ClassLoader>>* const class_loaders_;
260 };
261
262 // GetClassesVisitor takes a snapshot of the loaded classes that we may want to visit and stores
263 // them in the out argument. Not affected by class unloading since there are no suspend points in
264 // the caller.
265 class GetClassesVisitor : public ClassVisitor {
266 public:
GetClassesVisitor(bool profile_boot_class_path,ScopedArenaVector<ObjPtr<mirror::Class>> * out)267 explicit GetClassesVisitor(bool profile_boot_class_path,
268 ScopedArenaVector<ObjPtr<mirror::Class>>* out)
269 : profile_boot_class_path_(profile_boot_class_path),
270 out_(out) {}
271
operator ()(ObjPtr<mirror::Class> klass)272 virtual bool operator()(ObjPtr<mirror::Class> klass) REQUIRES_SHARED(Locks::mutator_lock_) {
273 if (klass->IsProxyClass() ||
274 klass->IsArrayClass() ||
275 klass->IsPrimitive() ||
276 !klass->IsResolved() ||
277 klass->IsErroneousResolved() ||
278 (!profile_boot_class_path_ && klass->GetClassLoader() == nullptr)) {
279 return true;
280 }
281 out_->push_back(klass);
282 return true;
283 }
284
285 private:
286 const bool profile_boot_class_path_;
287 ScopedArenaVector<ObjPtr<mirror::Class>>* const out_;
288 };
289
290 using MethodReferenceCollection = DexReferenceCollection<uint16_t, ScopedArenaAllocatorAdapter>;
291 using TypeReferenceCollection = DexReferenceCollection<dex::TypeIndex,
292 ScopedArenaAllocatorAdapter>;
293
294 // Iterate over all of the loaded classes and visit each one. For each class, add it to the
295 // resolved_classes out argument if startup is true.
296 // Add methods to the hot_methods out argument if the number of samples is greater or equal to
297 // hot_method_sample_threshold, add it to sampled_methods if it has at least one sample.
SampleClassesAndExecutedMethods(pthread_t profiler_pthread,bool profile_boot_class_path,ScopedArenaAllocator * allocator,uint32_t hot_method_sample_threshold,bool startup,TypeReferenceCollection * resolved_classes,MethodReferenceCollection * hot_methods,MethodReferenceCollection * sampled_methods)298 static void SampleClassesAndExecutedMethods(pthread_t profiler_pthread,
299 bool profile_boot_class_path,
300 ScopedArenaAllocator* allocator,
301 uint32_t hot_method_sample_threshold,
302 bool startup,
303 TypeReferenceCollection* resolved_classes,
304 MethodReferenceCollection* hot_methods,
305 MethodReferenceCollection* sampled_methods) {
306 Thread* const self = Thread::Current();
307 ClassLinker* const class_linker = Runtime::Current()->GetClassLinker();
308 // Restore profile saver thread priority during the GC critical section. This helps prevent
309 // priority inversions blocking the GC for long periods of time.
310 std::unique_ptr<ScopedDefaultPriority> sdp;
311 // Only restore default priority if we are the profile saver thread. Other threads that call this
312 // are threads calling Stop and the signal catcher (for SIGUSR1).
313 if (pthread_self() == profiler_pthread) {
314 sdp.reset(new ScopedDefaultPriority(profiler_pthread));
315 }
316
317 // Do ScopedGCCriticalSection before acquiring mutator lock to prevent the GC running and
318 // blocking threads during thread root flipping. Since the GC is a background thread, blocking it
319 // is not a problem.
320 ScopedObjectAccess soa(self);
321 gc::ScopedGCCriticalSection sgcs(self,
322 gc::kGcCauseProfileSaver,
323 gc::kCollectorTypeCriticalSection);
324 VariableSizedHandleScope hs(soa.Self());
325 std::vector<Handle<mirror::ClassLoader>> class_loaders;
326 if (profile_boot_class_path) {
327 // First add the boot class loader since visit classloaders doesn't visit it.
328 class_loaders.push_back(hs.NewHandle<mirror::ClassLoader>(nullptr));
329 }
330 GetClassLoadersVisitor class_loader_visitor(&hs, &class_loaders);
331 {
332 // Read the class loaders into a temporary array to prevent contention problems on the
333 // class_linker_classes_lock.
334 ScopedTrace trace2("Get class loaders");
335 ReaderMutexLock mu(soa.Self(), *Locks::classlinker_classes_lock_);
336 class_linker->VisitClassLoaders(&class_loader_visitor);
337 }
338 ScopedArenaVector<ObjPtr<mirror::Class>> classes(allocator->Adapter());
339 for (Handle<mirror::ClassLoader> class_loader : class_loaders) {
340 ClassTable* table = class_linker->ClassTableForClassLoader(class_loader.Get());
341 if (table == nullptr) {
342 // If the class loader has not loaded any classes, it may have a null table.
343 continue;
344 }
345 GetClassesVisitor get_classes_visitor(profile_boot_class_path, &classes);
346 {
347 // Collect the classes into a temporary array to prevent lock contention on the class
348 // table lock. We want to avoid blocking class loading in other threads as much as
349 // possible.
350 ScopedTrace trace3("Visiting class table");
351 table->Visit(get_classes_visitor);
352 }
353 for (ObjPtr<mirror::Class> klass : classes) {
354 if (startup) {
355 // We only record classes for the startup case. This may change in the future.
356 resolved_classes->AddReference(&klass->GetDexFile(), klass->GetDexTypeIndex());
357 }
358 // Visit all of the methods in the class to see which ones were executed.
359 for (ArtMethod& method : klass->GetMethods(kRuntimePointerSize)) {
360 if (!method.IsNative()) {
361 DCHECK(!method.IsProxyMethod());
362 const uint16_t counter = method.GetCounter();
363 // Mark startup methods as hot if they have more than hot_method_sample_threshold
364 // samples. This means they will get compiled by the compiler driver.
365 if (method.GetProfilingInfo(kRuntimePointerSize) != nullptr ||
366 method.PreviouslyWarm() ||
367 counter >= hot_method_sample_threshold) {
368 hot_methods->AddReference(method.GetDexFile(), method.GetDexMethodIndex());
369 } else if (counter != 0) {
370 sampled_methods->AddReference(method.GetDexFile(), method.GetDexMethodIndex());
371 }
372 } else {
373 // We do not record native methods. Once we AOT-compile the app, all native
374 // methods shall have their thunks compiled.
375 }
376 }
377 }
378 classes.clear();
379 }
380 }
381
FetchAndCacheResolvedClassesAndMethods(bool startup)382 void ProfileSaver::FetchAndCacheResolvedClassesAndMethods(bool startup) {
383 ScopedTrace trace(__PRETTY_FUNCTION__);
384 const uint64_t start_time = NanoTime();
385
386 // Resolve any new registered locations.
387 ResolveTrackedLocations();
388
389 Thread* const self = Thread::Current();
390 Runtime* const runtime = Runtime::Current();
391 ArenaStack stack(runtime->GetArenaPool());
392 ScopedArenaAllocator allocator(&stack);
393 MethodReferenceCollection hot_methods(allocator.Adapter(), allocator.Adapter());
394 MethodReferenceCollection sampled_methods(allocator.Adapter(), allocator.Adapter());
395 TypeReferenceCollection resolved_classes(allocator.Adapter(), allocator.Adapter());
396 const bool is_low_ram = Runtime::Current()->GetHeap()->IsLowMemoryMode();
397 pthread_t profiler_pthread;
398 {
399 MutexLock mu(self, *Locks::profiler_lock_);
400 profiler_pthread = profiler_pthread_;
401 }
402 const uint32_t hot_method_sample_threshold = startup ?
403 options_.GetHotStartupMethodSamples(is_low_ram) :
404 std::numeric_limits<uint32_t>::max();
405 SampleClassesAndExecutedMethods(profiler_pthread,
406 options_.GetProfileBootClassPath(),
407 &allocator,
408 hot_method_sample_threshold,
409 startup,
410 &resolved_classes,
411 &hot_methods,
412 &sampled_methods);
413 MutexLock mu(self, *Locks::profiler_lock_);
414 uint64_t total_number_of_profile_entries_cached = 0;
415 using Hotness = ProfileCompilationInfo::MethodHotness;
416
417 for (const auto& it : tracked_dex_base_locations_) {
418 std::set<DexCacheResolvedClasses> resolved_classes_for_location;
419 const std::string& filename = it.first;
420 auto info_it = profile_cache_.find(filename);
421 if (info_it == profile_cache_.end()) {
422 info_it = profile_cache_.Put(
423 filename,
424 new ProfileCompilationInfo(Runtime::Current()->GetArenaPool()));
425 }
426 ProfileCompilationInfo* cached_info = info_it->second;
427
428 const std::set<std::string>& locations = it.second;
429 for (const auto& pair : hot_methods.GetMap()) {
430 const DexFile* const dex_file = pair.first;
431 const std::string base_location = DexFileLoader::GetBaseLocation(dex_file->GetLocation());
432 if (locations.find(base_location) != locations.end()) {
433 const MethodReferenceCollection::IndexVector& indices = pair.second;
434 uint8_t flags = Hotness::kFlagHot;
435 flags |= startup ? Hotness::kFlagStartup : Hotness::kFlagPostStartup;
436 cached_info->AddMethodsForDex(
437 static_cast<Hotness::Flag>(flags),
438 dex_file,
439 indices.begin(),
440 indices.end());
441 }
442 }
443 for (const auto& pair : sampled_methods.GetMap()) {
444 const DexFile* const dex_file = pair.first;
445 const std::string base_location = DexFileLoader::GetBaseLocation(dex_file->GetLocation());
446 if (locations.find(base_location) != locations.end()) {
447 const MethodReferenceCollection::IndexVector& indices = pair.second;
448 cached_info->AddMethodsForDex(startup ? Hotness::kFlagStartup : Hotness::kFlagPostStartup,
449 dex_file,
450 indices.begin(),
451 indices.end());
452 }
453 }
454 for (const auto& pair : resolved_classes.GetMap()) {
455 const DexFile* const dex_file = pair.first;
456 const std::string base_location = DexFileLoader::GetBaseLocation(dex_file->GetLocation());
457 if (locations.find(base_location) != locations.end()) {
458 const TypeReferenceCollection::IndexVector& classes = pair.second;
459 VLOG(profiler) << "Added " << classes.size() << " classes for location "
460 << base_location
461 << " (" << dex_file->GetLocation() << ")";
462 cached_info->AddClassesForDex(dex_file, classes.begin(), classes.end());
463 } else {
464 VLOG(profiler) << "Location not found " << base_location
465 << " (" << dex_file->GetLocation() << ")";
466 }
467 }
468 total_number_of_profile_entries_cached += resolved_classes_for_location.size();
469 }
470 max_number_of_profile_entries_cached_ = std::max(
471 max_number_of_profile_entries_cached_,
472 total_number_of_profile_entries_cached);
473 VLOG(profiler) << "Profile saver recorded " << hot_methods.NumReferences() << " hot methods and "
474 << sampled_methods.NumReferences() << " sampled methods with threshold "
475 << hot_method_sample_threshold << " in "
476 << PrettyDuration(NanoTime() - start_time);
477 }
478
ProcessProfilingInfo(bool force_save,uint16_t * number_of_new_methods)479 bool ProfileSaver::ProcessProfilingInfo(bool force_save, /*out*/uint16_t* number_of_new_methods) {
480 ScopedTrace trace(__PRETTY_FUNCTION__);
481
482 // Resolve any new registered locations.
483 ResolveTrackedLocations();
484
485 SafeMap<std::string, std::set<std::string>> tracked_locations;
486 {
487 // Make a copy so that we don't hold the lock while doing I/O.
488 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
489 tracked_locations = tracked_dex_base_locations_;
490 }
491
492 bool profile_file_saved = false;
493 if (number_of_new_methods != nullptr) {
494 *number_of_new_methods = 0;
495 }
496
497 // We only need to do this once, not once per dex location.
498 // TODO: Figure out a way to only do it when stuff has changed? It takes 30-50ms.
499 FetchAndCacheResolvedClassesAndMethods(/*startup*/ false);
500
501 for (const auto& it : tracked_locations) {
502 if (!force_save && ShuttingDown(Thread::Current())) {
503 // The ProfileSaver is in shutdown mode, meaning a stop request was made and
504 // we need to exit cleanly (by waiting for the saver thread to finish). Unless
505 // we have a request for a forced save, do not do any processing so that we
506 // speed up the exit.
507 return true;
508 }
509 const std::string& filename = it.first;
510 const std::set<std::string>& locations = it.second;
511 std::vector<ProfileMethodInfo> profile_methods;
512 {
513 ScopedObjectAccess soa(Thread::Current());
514 jit_code_cache_->GetProfiledMethods(locations, profile_methods);
515 total_number_of_code_cache_queries_++;
516 }
517 {
518 ProfileCompilationInfo info(Runtime::Current()->GetArenaPool());
519 if (!info.Load(filename, /*clear_if_invalid*/ true)) {
520 LOG(WARNING) << "Could not forcefully load profile " << filename;
521 continue;
522 }
523 uint64_t last_save_number_of_methods = info.GetNumberOfMethods();
524 uint64_t last_save_number_of_classes = info.GetNumberOfResolvedClasses();
525
526 // Try to add the method data. Note this may fail is the profile loaded from disk contains
527 // outdated data (e.g. the previous profiled dex files might have been updated).
528 // If this happens we clear the profile data and for the save to ensure the file is cleared.
529 if (!info.AddMethods(profile_methods,
530 ProfileCompilationInfo::MethodHotness::kFlagPostStartup)) {
531 LOG(WARNING) << "Could not add methods to the existing profiler. "
532 << "Clearing the profile data.";
533 info.ClearData();
534 force_save = true;
535 }
536
537 auto profile_cache_it = profile_cache_.find(filename);
538 if (profile_cache_it != profile_cache_.end()) {
539 if (!info.MergeWith(*(profile_cache_it->second))) {
540 LOG(WARNING) << "Could not merge the profile. Clearing the profile data.";
541 info.ClearData();
542 force_save = true;
543 }
544 }
545
546 int64_t delta_number_of_methods =
547 info.GetNumberOfMethods() - last_save_number_of_methods;
548 int64_t delta_number_of_classes =
549 info.GetNumberOfResolvedClasses() - last_save_number_of_classes;
550
551 if (!force_save &&
552 delta_number_of_methods < options_.GetMinMethodsToSave() &&
553 delta_number_of_classes < options_.GetMinClassesToSave()) {
554 VLOG(profiler) << "Not enough information to save to: " << filename
555 << " Number of methods: " << delta_number_of_methods
556 << " Number of classes: " << delta_number_of_classes;
557 total_number_of_skipped_writes_++;
558 continue;
559 }
560
561 if (number_of_new_methods != nullptr) {
562 *number_of_new_methods =
563 std::max(static_cast<uint16_t>(delta_number_of_methods),
564 *number_of_new_methods);
565 }
566 uint64_t bytes_written;
567 // Force the save. In case the profile data is corrupted or the the profile
568 // has the wrong version this will "fix" the file to the correct format.
569 if (info.Save(filename, &bytes_written)) {
570 // We managed to save the profile. Clear the cache stored during startup.
571 if (profile_cache_it != profile_cache_.end()) {
572 ProfileCompilationInfo *cached_info = profile_cache_it->second;
573 profile_cache_.erase(profile_cache_it);
574 delete cached_info;
575 }
576 if (bytes_written > 0) {
577 total_number_of_writes_++;
578 total_bytes_written_ += bytes_written;
579 profile_file_saved = true;
580 } else {
581 // At this point we could still have avoided the write.
582 // We load and merge the data from the file lazily at its first ever
583 // save attempt. So, whatever we are trying to save could already be
584 // in the file.
585 total_number_of_skipped_writes_++;
586 }
587 } else {
588 LOG(WARNING) << "Could not save profiling info to " << filename;
589 total_number_of_failed_writes_++;
590 }
591 }
592 }
593
594 // Trim the maps to madvise the pages used for profile info.
595 // It is unlikely we will need them again in the near feature.
596 Runtime::Current()->GetArenaPool()->TrimMaps();
597
598 return profile_file_saved;
599 }
600
RunProfileSaverThread(void * arg)601 void* ProfileSaver::RunProfileSaverThread(void* arg) {
602 Runtime* runtime = Runtime::Current();
603
604 bool attached = runtime->AttachCurrentThread("Profile Saver",
605 /*as_daemon*/true,
606 runtime->GetSystemThreadGroup(),
607 /*create_peer*/true);
608 if (!attached) {
609 CHECK(runtime->IsShuttingDown(Thread::Current()));
610 return nullptr;
611 }
612
613 ProfileSaver* profile_saver = reinterpret_cast<ProfileSaver*>(arg);
614 profile_saver->Run();
615
616 runtime->DetachCurrentThread();
617 VLOG(profiler) << "Profile saver shutdown";
618 return nullptr;
619 }
620
ShouldProfileLocation(const std::string & location,bool profile_aot_code)621 static bool ShouldProfileLocation(const std::string& location, bool profile_aot_code) {
622 if (profile_aot_code) {
623 // If we have to profile all the code, irrespective of its compilation state, return true
624 // right away.
625 return true;
626 }
627
628 OatFileManager& oat_manager = Runtime::Current()->GetOatFileManager();
629 const OatFile* oat_file = oat_manager.FindOpenedOatFileFromDexLocation(location);
630 if (oat_file == nullptr) {
631 // This can happen if we fallback to run code directly from the APK.
632 // Profile it with the hope that the background dexopt will get us back into
633 // a good state.
634 VLOG(profiler) << "Asked to profile a location without an oat file:" << location;
635 return true;
636 }
637 CompilerFilter::Filter filter = oat_file->GetCompilerFilter();
638 if ((filter == CompilerFilter::kSpeed) || (filter == CompilerFilter::kEverything)) {
639 VLOG(profiler)
640 << "Skip profiling oat file because it's already speed|everything compiled: "
641 << location << " oat location: " << oat_file->GetLocation();
642 return false;
643 }
644 return true;
645 }
646
Start(const ProfileSaverOptions & options,const std::string & output_filename,jit::JitCodeCache * jit_code_cache,const std::vector<std::string> & code_paths)647 void ProfileSaver::Start(const ProfileSaverOptions& options,
648 const std::string& output_filename,
649 jit::JitCodeCache* jit_code_cache,
650 const std::vector<std::string>& code_paths) {
651 Runtime* const runtime = Runtime::Current();
652 DCHECK(options.IsEnabled());
653 DCHECK(runtime->GetJit() != nullptr);
654 DCHECK(!output_filename.empty());
655 DCHECK(jit_code_cache != nullptr);
656
657 std::vector<std::string> code_paths_to_profile;
658 for (const std::string& location : code_paths) {
659 if (ShouldProfileLocation(location, options.GetProfileAOTCode())) {
660 code_paths_to_profile.push_back(location);
661 }
662 }
663
664 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
665 // Support getting profile samples for the boot class path. This will be used to generate the boot
666 // image profile. The intention is to use this code to generate to boot image but not use it in
667 // production. b/37966211
668 if (options.GetProfileBootClassPath()) {
669 std::set<std::string> code_paths_keys;
670 for (const std::string& location : code_paths) {
671 code_paths_keys.insert(ProfileCompilationInfo::GetProfileDexFileKey(location));
672 }
673 for (const DexFile* dex_file : runtime->GetClassLinker()->GetBootClassPath()) {
674 // Don't check ShouldProfileLocation since the boot class path may be speed compiled.
675 const std::string& location = dex_file->GetLocation();
676 const std::string key = ProfileCompilationInfo::GetProfileDexFileKey(location);
677 VLOG(profiler) << "Registering boot dex file " << location;
678 if (code_paths_keys.find(key) != code_paths_keys.end()) {
679 LOG(WARNING) << "Boot class path location key conflicts with code path " << location;
680 } else if (instance_ == nullptr) {
681 // Only add the boot class path once since Start may be called multiple times for secondary
682 // dexes.
683 // We still do the collision check above. This handles any secondary dexes that conflict
684 // with the boot class path dex files.
685 code_paths_to_profile.push_back(location);
686 }
687 }
688 }
689 if (code_paths_to_profile.empty()) {
690 VLOG(profiler) << "No code paths should be profiled.";
691 return;
692 }
693
694 if (instance_ != nullptr) {
695 // If we already have an instance, make sure it uses the same jit_code_cache.
696 // This may be called multiple times via Runtime::registerAppInfo (e.g. for
697 // apps which share the same runtime).
698 DCHECK_EQ(instance_->jit_code_cache_, jit_code_cache);
699 // Add the code_paths to the tracked locations.
700 instance_->AddTrackedLocations(output_filename, code_paths_to_profile);
701 return;
702 }
703
704 VLOG(profiler) << "Starting profile saver using output file: " << output_filename
705 << ". Tracking: " << android::base::Join(code_paths_to_profile, ':');
706
707 instance_ = new ProfileSaver(options,
708 output_filename,
709 jit_code_cache,
710 code_paths_to_profile);
711
712 // Create a new thread which does the saving.
713 CHECK_PTHREAD_CALL(
714 pthread_create,
715 (&profiler_pthread_, nullptr, &RunProfileSaverThread, reinterpret_cast<void*>(instance_)),
716 "Profile saver thread");
717
718 SetProfileSaverThreadPriority(profiler_pthread_, kProfileSaverPthreadPriority);
719 }
720
Stop(bool dump_info)721 void ProfileSaver::Stop(bool dump_info) {
722 ProfileSaver* profile_saver = nullptr;
723 pthread_t profiler_pthread = 0U;
724
725 {
726 MutexLock profiler_mutex(Thread::Current(), *Locks::profiler_lock_);
727 VLOG(profiler) << "Stopping profile saver thread";
728 profile_saver = instance_;
729 profiler_pthread = profiler_pthread_;
730 if (instance_ == nullptr) {
731 DCHECK(false) << "Tried to stop a profile saver which was not started";
732 return;
733 }
734 if (instance_->shutting_down_) {
735 DCHECK(false) << "Tried to stop the profile saver twice";
736 return;
737 }
738 instance_->shutting_down_ = true;
739 }
740
741 {
742 // Wake up the saver thread if it is sleeping to allow for a clean exit.
743 MutexLock wait_mutex(Thread::Current(), profile_saver->wait_lock_);
744 profile_saver->period_condition_.Signal(Thread::Current());
745 }
746
747 // Force save everything before destroying the thread since we want profiler_pthread_ to remain
748 // valid.
749 instance_->ProcessProfilingInfo(/*force_save*/true, /*number_of_new_methods*/nullptr);
750
751 // Wait for the saver thread to stop.
752 CHECK_PTHREAD_CALL(pthread_join, (profiler_pthread, nullptr), "profile saver thread shutdown");
753
754 {
755 MutexLock profiler_mutex(Thread::Current(), *Locks::profiler_lock_);
756 if (dump_info) {
757 instance_->DumpInfo(LOG_STREAM(INFO));
758 }
759 instance_ = nullptr;
760 profiler_pthread_ = 0U;
761 }
762 delete profile_saver;
763 }
764
ShuttingDown(Thread * self)765 bool ProfileSaver::ShuttingDown(Thread* self) {
766 MutexLock mu(self, *Locks::profiler_lock_);
767 return shutting_down_;
768 }
769
IsStarted()770 bool ProfileSaver::IsStarted() {
771 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
772 return instance_ != nullptr;
773 }
774
AddTrackedLocationsToMap(const std::string & output_filename,const std::vector<std::string> & code_paths,SafeMap<std::string,std::set<std::string>> * map)775 static void AddTrackedLocationsToMap(const std::string& output_filename,
776 const std::vector<std::string>& code_paths,
777 SafeMap<std::string, std::set<std::string>>* map) {
778 auto it = map->find(output_filename);
779 if (it == map->end()) {
780 map->Put(output_filename, std::set<std::string>(code_paths.begin(), code_paths.end()));
781 } else {
782 it->second.insert(code_paths.begin(), code_paths.end());
783 }
784 }
785
AddTrackedLocations(const std::string & output_filename,const std::vector<std::string> & code_paths)786 void ProfileSaver::AddTrackedLocations(const std::string& output_filename,
787 const std::vector<std::string>& code_paths) {
788 // Add the code paths to the list of tracked location.
789 AddTrackedLocationsToMap(output_filename, code_paths, &tracked_dex_base_locations_);
790 // The code paths may contain symlinks which could fool the profiler.
791 // If the dex file is compiled with an absolute location but loaded with symlink
792 // the profiler could skip the dex due to location mismatch.
793 // To avoid this, we add the code paths to the temporary cache of 'to_be_resolved'
794 // locations. When the profiler thread executes we will resolve the paths to their
795 // real paths.
796 // Note that we delay taking the realpath to avoid spending more time than needed
797 // when registering location (as it is done during app launch).
798 AddTrackedLocationsToMap(output_filename,
799 code_paths,
800 &tracked_dex_base_locations_to_be_resolved_);
801 }
802
DumpInstanceInfo(std::ostream & os)803 void ProfileSaver::DumpInstanceInfo(std::ostream& os) {
804 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
805 if (instance_ != nullptr) {
806 instance_->DumpInfo(os);
807 }
808 }
809
DumpInfo(std::ostream & os)810 void ProfileSaver::DumpInfo(std::ostream& os) {
811 os << "ProfileSaver total_bytes_written=" << total_bytes_written_ << '\n'
812 << "ProfileSaver total_number_of_writes=" << total_number_of_writes_ << '\n'
813 << "ProfileSaver total_number_of_code_cache_queries="
814 << total_number_of_code_cache_queries_ << '\n'
815 << "ProfileSaver total_number_of_skipped_writes=" << total_number_of_skipped_writes_ << '\n'
816 << "ProfileSaver total_number_of_failed_writes=" << total_number_of_failed_writes_ << '\n'
817 << "ProfileSaver total_ms_of_sleep=" << total_ms_of_sleep_ << '\n'
818 << "ProfileSaver total_ms_of_work=" << NsToMs(total_ns_of_work_) << '\n'
819 << "ProfileSaver max_number_profile_entries_cached="
820 << max_number_of_profile_entries_cached_ << '\n'
821 << "ProfileSaver total_number_of_hot_spikes=" << total_number_of_hot_spikes_ << '\n'
822 << "ProfileSaver total_number_of_wake_ups=" << total_number_of_wake_ups_ << '\n';
823 }
824
825
ForceProcessProfiles()826 void ProfileSaver::ForceProcessProfiles() {
827 ProfileSaver* saver = nullptr;
828 {
829 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
830 saver = instance_;
831 }
832 // TODO(calin): this is not actually thread safe as the instance_ may have been deleted,
833 // but we only use this in testing when we now this won't happen.
834 // Refactor the way we handle the instance so that we don't end up in this situation.
835 if (saver != nullptr) {
836 saver->ProcessProfilingInfo(/*force_save*/true, /*number_of_new_methods*/nullptr);
837 }
838 }
839
HasSeenMethod(const std::string & profile,bool hot,MethodReference ref)840 bool ProfileSaver::HasSeenMethod(const std::string& profile, bool hot, MethodReference ref) {
841 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
842 if (instance_ != nullptr) {
843 ProfileCompilationInfo info(Runtime::Current()->GetArenaPool());
844 if (!info.Load(profile, /*clear_if_invalid*/false)) {
845 return false;
846 }
847 ProfileCompilationInfo::MethodHotness hotness = info.GetMethodHotness(ref);
848 // Ignore hot parameter for now since it was causing test 595 to be flaky. TODO: Investigate.
849 // b/63635729
850 UNUSED(hot);
851 return hotness.IsInProfile();
852 }
853 return false;
854 }
855
ResolveTrackedLocations()856 void ProfileSaver::ResolveTrackedLocations() {
857 SafeMap<std::string, std::set<std::string>> locations_to_be_resolved;
858 {
859 // Make a copy so that we don't hold the lock while doing I/O.
860 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
861 locations_to_be_resolved = tracked_dex_base_locations_to_be_resolved_;
862 tracked_dex_base_locations_to_be_resolved_.clear();
863 }
864
865 // Resolve the locations.
866 SafeMap<std::string, std::vector<std::string>> resolved_locations_map;
867 for (const auto& it : locations_to_be_resolved) {
868 const std::string& filename = it.first;
869 const std::set<std::string>& locations = it.second;
870 auto resolved_locations_it = resolved_locations_map.Put(
871 filename,
872 std::vector<std::string>(locations.size()));
873
874 for (const auto& location : locations) {
875 UniqueCPtr<const char[]> location_real(realpath(location.c_str(), nullptr));
876 // Note that it's ok if we cannot get the real path.
877 if (location_real != nullptr) {
878 resolved_locations_it->second.emplace_back(location_real.get());
879 }
880 }
881 }
882
883 // Add the resolved locations to the tracked collection.
884 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
885 for (const auto& it : resolved_locations_map) {
886 AddTrackedLocationsToMap(it.first, it.second, &tracked_dex_base_locations_);
887 }
888 }
889
890 } // namespace art
891