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