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 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 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 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 101 ProfileSaver::~ProfileSaver() { 102 for (auto& it : profile_cache_) { 103 delete it.second; 104 } 105 } 106 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 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 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 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: 230 explicit ScopedDefaultPriority(pthread_t thread) : thread_(thread) { 231 SetProfileSaverThreadPriority(thread_, GetDefaultThreadPriority()); 232 } 233 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: 247 explicit GetClassLoadersVisitor(VariableSizedHandleScope* hs, 248 std::vector<Handle<mirror::ClassLoader>>* class_loaders) 249 : hs_(hs), 250 class_loaders_(class_loaders) {} 251 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: 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 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. 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 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 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 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 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 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 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 765 bool ProfileSaver::ShuttingDown(Thread* self) { 766 MutexLock mu(self, *Locks::profiler_lock_); 767 return shutting_down_; 768 } 769 770 bool ProfileSaver::IsStarted() { 771 MutexLock mu(Thread::Current(), *Locks::profiler_lock_); 772 return instance_ != nullptr; 773 } 774 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 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 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 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 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 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 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