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 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 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 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 99 ProfileSaver::~ProfileSaver() { 100 for (auto& it : profile_cache_) { 101 delete it.second; 102 } 103 } 104 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 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 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 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: 216 explicit ScopedDefaultPriority(pthread_t thread) : thread_(thread) { 217 SetProfileSaverThreadPriority(thread_, GetDefaultThreadPriority()); 218 } 219 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: 233 explicit GetClassLoadersVisitor(VariableSizedHandleScope* hs, 234 std::vector<Handle<mirror::ClassLoader>>* class_loaders) 235 : hs_(hs), 236 class_loaders_(class_loaders) {} 237 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: 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 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. 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 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 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 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 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 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 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 728 bool ProfileSaver::ShuttingDown(Thread* self) { 729 MutexLock mu(self, *Locks::profiler_lock_); 730 return shutting_down_; 731 } 732 733 bool ProfileSaver::IsStarted() { 734 MutexLock mu(Thread::Current(), *Locks::profiler_lock_); 735 return instance_ != nullptr; 736 } 737 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 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 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 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 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 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 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