Calin Juravle | 4d77b6a | 2015-12-01 18:38:09 +0000 | [diff] [blame] | 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 "art_method-inl.h" |
| 20 | #include "scoped_thread_state_change.h" |
| 21 | #include "oat_file_manager.h" |
| 22 | |
| 23 | namespace art { |
| 24 | |
Calin Juravle | 932a051 | 2016-01-19 14:32:26 -0800 | [diff] [blame] | 25 | // An arbitrary value to throttle save requests. Set to 2s for now. |
Calin Juravle | 4d77b6a | 2015-12-01 18:38:09 +0000 | [diff] [blame] | 26 | static constexpr const uint64_t kMilisecondsToNano = 1000000; |
Calin Juravle | 932a051 | 2016-01-19 14:32:26 -0800 | [diff] [blame] | 27 | static constexpr const uint64_t kMinimumTimeBetweenCodeCacheUpdatesNs = 2000 * kMilisecondsToNano; |
Calin Juravle | 4d77b6a | 2015-12-01 18:38:09 +0000 | [diff] [blame] | 28 | |
| 29 | // TODO: read the constants from ProfileOptions, |
| 30 | // Add a random delay each time we go to sleep so that we don't hammer the CPU |
| 31 | // with all profile savers running at the same time. |
Calin Juravle | 932a051 | 2016-01-19 14:32:26 -0800 | [diff] [blame] | 32 | static constexpr const uint64_t kRandomDelayMaxMs = 20 * 1000; // 20 seconds |
| 33 | static constexpr const uint64_t kMaxBackoffMs = 5 * 60 * 1000; // 5 minutes |
| 34 | static constexpr const uint64_t kSavePeriodMs = 10 * 1000; // 10 seconds |
Mathieu Chartier | c5dd319 | 2015-12-09 16:38:30 -0800 | [diff] [blame] | 35 | static constexpr const uint64_t kInitialDelayMs = 2 * 1000; // 2 seconds |
Calin Juravle | 4d77b6a | 2015-12-01 18:38:09 +0000 | [diff] [blame] | 36 | static constexpr const double kBackoffCoef = 1.5; |
| 37 | |
| 38 | static constexpr const uint32_t kMinimumNrOrMethodsToSave = 10; |
| 39 | |
| 40 | ProfileSaver* ProfileSaver::instance_ = nullptr; |
| 41 | pthread_t ProfileSaver::profiler_pthread_ = 0U; |
| 42 | |
| 43 | ProfileSaver::ProfileSaver(const std::string& output_filename, |
| 44 | jit::JitCodeCache* jit_code_cache, |
| 45 | const std::vector<std::string>& code_paths) |
Calin Juravle | b4eddd2 | 2016-01-13 15:52:33 -0800 | [diff] [blame] | 46 | : jit_code_cache_(jit_code_cache), |
Calin Juravle | 4d77b6a | 2015-12-01 18:38:09 +0000 | [diff] [blame] | 47 | code_cache_last_update_time_ns_(0), |
| 48 | shutting_down_(false), |
Mathieu Chartier | c5dd319 | 2015-12-09 16:38:30 -0800 | [diff] [blame] | 49 | first_profile_(true), |
Calin Juravle | 4d77b6a | 2015-12-01 18:38:09 +0000 | [diff] [blame] | 50 | wait_lock_("ProfileSaver wait lock"), |
| 51 | period_condition_("ProfileSaver period condition", wait_lock_) { |
Calin Juravle | b4eddd2 | 2016-01-13 15:52:33 -0800 | [diff] [blame] | 52 | AddTrackedLocations(output_filename, code_paths); |
Calin Juravle | 4d77b6a | 2015-12-01 18:38:09 +0000 | [diff] [blame] | 53 | } |
| 54 | |
| 55 | void ProfileSaver::Run() { |
| 56 | srand(MicroTime() * getpid()); |
| 57 | Thread* self = Thread::Current(); |
| 58 | |
| 59 | uint64_t save_period_ms = kSavePeriodMs; |
| 60 | VLOG(profiler) << "Save profiling information every " << save_period_ms << " ms"; |
Calin Juravle | 4d77b6a | 2015-12-01 18:38:09 +0000 | [diff] [blame] | 61 | |
Mathieu Chartier | c5dd319 | 2015-12-09 16:38:30 -0800 | [diff] [blame] | 62 | bool first_iteration = true; |
| 63 | while (!ShuttingDown(self)) { |
| 64 | uint64_t sleep_time_ms; |
| 65 | if (first_iteration) { |
| 66 | // Sleep less long for the first iteration since we want to record loaded classes shortly |
| 67 | // after app launch. |
| 68 | sleep_time_ms = kInitialDelayMs; |
| 69 | } else { |
| 70 | const uint64_t random_sleep_delay_ms = rand() % kRandomDelayMaxMs; |
| 71 | sleep_time_ms = save_period_ms + random_sleep_delay_ms; |
| 72 | } |
Calin Juravle | 4d77b6a | 2015-12-01 18:38:09 +0000 | [diff] [blame] | 73 | { |
| 74 | MutexLock mu(self, wait_lock_); |
| 75 | period_condition_.TimedWait(self, sleep_time_ms, 0); |
| 76 | } |
| 77 | |
| 78 | if (ShuttingDown(self)) { |
| 79 | break; |
| 80 | } |
| 81 | |
| 82 | if (!ProcessProfilingInfo() && save_period_ms < kMaxBackoffMs) { |
| 83 | // If we don't need to save now it is less likely that we will need to do |
| 84 | // so in the future. Increase the time between saves according to the |
| 85 | // kBackoffCoef, but make it no larger than kMaxBackoffMs. |
| 86 | save_period_ms = static_cast<uint64_t>(kBackoffCoef * save_period_ms); |
| 87 | } else { |
| 88 | // Reset the period to the initial value as it's highly likely to JIT again. |
| 89 | save_period_ms = kSavePeriodMs; |
| 90 | } |
Mathieu Chartier | c5dd319 | 2015-12-09 16:38:30 -0800 | [diff] [blame] | 91 | first_iteration = false; |
Calin Juravle | 4d77b6a | 2015-12-01 18:38:09 +0000 | [diff] [blame] | 92 | } |
| 93 | } |
| 94 | |
| 95 | bool ProfileSaver::ProcessProfilingInfo() { |
Calin Juravle | 4d77b6a | 2015-12-01 18:38:09 +0000 | [diff] [blame] | 96 | uint64_t last_update_time_ns = jit_code_cache_->GetLastUpdateTimeNs(); |
Mathieu Chartier | c5dd319 | 2015-12-09 16:38:30 -0800 | [diff] [blame] | 97 | if (!first_profile_ && last_update_time_ns - code_cache_last_update_time_ns_ |
| 98 | < kMinimumTimeBetweenCodeCacheUpdatesNs) { |
Calin Juravle | 877fd96 | 2016-01-05 14:29:29 +0000 | [diff] [blame] | 99 | VLOG(profiler) << "Not enough time has passed since the last code cache update." |
| 100 | << "Last update: " << last_update_time_ns |
| 101 | << " Last save: " << code_cache_last_update_time_ns_; |
Calin Juravle | 4d77b6a | 2015-12-01 18:38:09 +0000 | [diff] [blame] | 102 | return false; |
| 103 | } |
| 104 | |
| 105 | uint64_t start = NanoTime(); |
| 106 | code_cache_last_update_time_ns_ = last_update_time_ns; |
Calin Juravle | b4eddd2 | 2016-01-13 15:52:33 -0800 | [diff] [blame] | 107 | SafeMap<std::string, std::set<std::string>> tracked_locations; |
Calin Juravle | 4d77b6a | 2015-12-01 18:38:09 +0000 | [diff] [blame] | 108 | { |
Calin Juravle | b4eddd2 | 2016-01-13 15:52:33 -0800 | [diff] [blame] | 109 | // Make a copy so that we don't hold the lock while doing I/O. |
| 110 | MutexLock mu(Thread::Current(), *Locks::profiler_lock_); |
| 111 | tracked_locations = tracked_dex_base_locations_; |
Calin Juravle | 4d77b6a | 2015-12-01 18:38:09 +0000 | [diff] [blame] | 112 | } |
Calin Juravle | b4eddd2 | 2016-01-13 15:52:33 -0800 | [diff] [blame] | 113 | for (const auto& it : tracked_locations) { |
| 114 | if (ShuttingDown(Thread::Current())) { |
| 115 | return true; |
| 116 | } |
| 117 | const std::string& filename = it.first; |
| 118 | const std::set<std::string>& locations = it.second; |
| 119 | std::vector<ArtMethod*> methods; |
| 120 | { |
| 121 | ScopedObjectAccess soa(Thread::Current()); |
| 122 | jit_code_cache_->GetCompiledArtMethods(locations, methods); |
| 123 | } |
Mathieu Chartier | c5dd319 | 2015-12-09 16:38:30 -0800 | [diff] [blame] | 124 | // Always save for the first one for loaded classes profile. |
| 125 | if (methods.size() < kMinimumNrOrMethodsToSave && !first_profile_) { |
Calin Juravle | b4eddd2 | 2016-01-13 15:52:33 -0800 | [diff] [blame] | 126 | VLOG(profiler) << "Not enough information to save to: " << filename |
| 127 | <<" Nr of methods: " << methods.size(); |
| 128 | return false; |
| 129 | } |
Calin Juravle | 4d77b6a | 2015-12-01 18:38:09 +0000 | [diff] [blame] | 130 | |
Mathieu Chartier | c5dd319 | 2015-12-09 16:38:30 -0800 | [diff] [blame] | 131 | std::set<DexCacheResolvedClasses> resolved_classes; |
| 132 | if (first_profile_) { |
| 133 | ClassLinker* const class_linker = Runtime::Current()->GetClassLinker(); |
| 134 | resolved_classes = class_linker->GetResolvedClasses(/*ignore boot classes*/true); |
| 135 | } |
| 136 | |
| 137 | if (!ProfileCompilationInfo::SaveProfilingInfo(filename, methods, resolved_classes)) { |
Calin Juravle | b4eddd2 | 2016-01-13 15:52:33 -0800 | [diff] [blame] | 138 | LOG(WARNING) << "Could not save profiling info to " << filename; |
| 139 | return false; |
| 140 | } |
| 141 | |
| 142 | VLOG(profiler) << "Profile process time: " << PrettyDuration(NanoTime() - start); |
| 143 | } |
Mathieu Chartier | c5dd319 | 2015-12-09 16:38:30 -0800 | [diff] [blame] | 144 | first_profile_ = false; |
Calin Juravle | 4d77b6a | 2015-12-01 18:38:09 +0000 | [diff] [blame] | 145 | return true; |
| 146 | } |
| 147 | |
| 148 | void* ProfileSaver::RunProfileSaverThread(void* arg) { |
| 149 | Runtime* runtime = Runtime::Current(); |
| 150 | ProfileSaver* profile_saver = reinterpret_cast<ProfileSaver*>(arg); |
| 151 | |
| 152 | CHECK(runtime->AttachCurrentThread("Profile Saver", |
| 153 | /*as_daemon*/true, |
| 154 | runtime->GetSystemThreadGroup(), |
| 155 | /*create_peer*/true)); |
| 156 | profile_saver->Run(); |
| 157 | |
| 158 | runtime->DetachCurrentThread(); |
| 159 | VLOG(profiler) << "Profile saver shutdown"; |
| 160 | return nullptr; |
| 161 | } |
| 162 | |
| 163 | void ProfileSaver::Start(const std::string& output_filename, |
| 164 | jit::JitCodeCache* jit_code_cache, |
| 165 | const std::vector<std::string>& code_paths) { |
| 166 | DCHECK(Runtime::Current()->UseJit()); |
| 167 | DCHECK(!output_filename.empty()); |
| 168 | DCHECK(jit_code_cache != nullptr); |
| 169 | |
| 170 | MutexLock mu(Thread::Current(), *Locks::profiler_lock_); |
Calin Juravle | 4d77b6a | 2015-12-01 18:38:09 +0000 | [diff] [blame] | 171 | if (instance_ != nullptr) { |
Calin Juravle | b4eddd2 | 2016-01-13 15:52:33 -0800 | [diff] [blame] | 172 | // If we already have an instance, make sure it uses the same jit_code_cache. |
| 173 | // This may be called multiple times via Runtime::registerAppInfo (e.g. for |
| 174 | // apps which share the same runtime). |
| 175 | DCHECK_EQ(instance_->jit_code_cache_, jit_code_cache); |
| 176 | // Add the code_paths to the tracked locations. |
| 177 | instance_->AddTrackedLocations(output_filename, code_paths); |
Calin Juravle | 4d77b6a | 2015-12-01 18:38:09 +0000 | [diff] [blame] | 178 | return; |
| 179 | } |
| 180 | |
| 181 | VLOG(profiler) << "Starting profile saver using output file: " << output_filename |
| 182 | << ". Tracking: " << Join(code_paths, ':'); |
| 183 | |
| 184 | instance_ = new ProfileSaver(output_filename, jit_code_cache, code_paths); |
| 185 | |
| 186 | // Create a new thread which does the saving. |
| 187 | CHECK_PTHREAD_CALL( |
| 188 | pthread_create, |
| 189 | (&profiler_pthread_, nullptr, &RunProfileSaverThread, reinterpret_cast<void*>(instance_)), |
| 190 | "Profile saver thread"); |
| 191 | } |
| 192 | |
| 193 | void ProfileSaver::Stop() { |
| 194 | ProfileSaver* profile_saver = nullptr; |
| 195 | pthread_t profiler_pthread = 0U; |
| 196 | |
| 197 | { |
| 198 | MutexLock profiler_mutex(Thread::Current(), *Locks::profiler_lock_); |
Calin Juravle | b4eddd2 | 2016-01-13 15:52:33 -0800 | [diff] [blame] | 199 | VLOG(profiler) << "Stopping profile saver thread"; |
Calin Juravle | 4d77b6a | 2015-12-01 18:38:09 +0000 | [diff] [blame] | 200 | profile_saver = instance_; |
| 201 | profiler_pthread = profiler_pthread_; |
| 202 | if (instance_ == nullptr) { |
| 203 | DCHECK(false) << "Tried to stop a profile saver which was not started"; |
| 204 | return; |
| 205 | } |
| 206 | if (instance_->shutting_down_) { |
| 207 | DCHECK(false) << "Tried to stop the profile saver twice"; |
| 208 | return; |
| 209 | } |
| 210 | instance_->shutting_down_ = true; |
| 211 | } |
| 212 | |
| 213 | { |
| 214 | // Wake up the saver thread if it is sleeping to allow for a clean exit. |
| 215 | MutexLock wait_mutex(Thread::Current(), profile_saver->wait_lock_); |
| 216 | profile_saver->period_condition_.Signal(Thread::Current()); |
| 217 | } |
| 218 | |
| 219 | // Wait for the saver thread to stop. |
| 220 | CHECK_PTHREAD_CALL(pthread_join, (profiler_pthread, nullptr), "profile saver thread shutdown"); |
| 221 | |
| 222 | { |
| 223 | MutexLock profiler_mutex(Thread::Current(), *Locks::profiler_lock_); |
| 224 | instance_ = nullptr; |
| 225 | profiler_pthread_ = 0U; |
| 226 | } |
| 227 | delete profile_saver; |
| 228 | } |
| 229 | |
| 230 | bool ProfileSaver::ShuttingDown(Thread* self) { |
| 231 | MutexLock mu(self, *Locks::profiler_lock_); |
| 232 | return shutting_down_; |
| 233 | } |
| 234 | |
| 235 | bool ProfileSaver::IsStarted() { |
| 236 | MutexLock mu(Thread::Current(), *Locks::profiler_lock_); |
| 237 | return instance_ != nullptr; |
| 238 | } |
| 239 | |
Calin Juravle | b4eddd2 | 2016-01-13 15:52:33 -0800 | [diff] [blame] | 240 | void ProfileSaver::AddTrackedLocations(const std::string& output_filename, |
| 241 | const std::vector<std::string>& code_paths) { |
| 242 | auto it = tracked_dex_base_locations_.find(output_filename); |
| 243 | if (it == tracked_dex_base_locations_.end()) { |
| 244 | tracked_dex_base_locations_.Put(output_filename, |
| 245 | std::set<std::string>(code_paths.begin(), code_paths.end())); |
| 246 | } else { |
| 247 | it->second.insert(code_paths.begin(), code_paths.end()); |
| 248 | } |
| 249 | } |
| 250 | |
Calin Juravle | 4d77b6a | 2015-12-01 18:38:09 +0000 | [diff] [blame] | 251 | } // namespace art |