Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 1 | /* |
| 2 | * Copyright (C) 2011 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 "profiler.h" |
| 18 | |
Calin Juravle | 9dae5b4 | 2014-04-07 16:36:21 +0300 | [diff] [blame] | 19 | #include <fstream> |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 20 | #include <sys/uio.h> |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 21 | #include <sys/file.h> |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 22 | |
| 23 | #include "base/stl_util.h" |
| 24 | #include "base/unix_file/fd_file.h" |
| 25 | #include "class_linker.h" |
| 26 | #include "common_throws.h" |
| 27 | #include "debugger.h" |
| 28 | #include "dex_file-inl.h" |
| 29 | #include "instrumentation.h" |
| 30 | #include "mirror/art_method-inl.h" |
| 31 | #include "mirror/class-inl.h" |
| 32 | #include "mirror/dex_cache.h" |
| 33 | #include "mirror/object_array-inl.h" |
| 34 | #include "mirror/object-inl.h" |
| 35 | #include "object_utils.h" |
| 36 | #include "os.h" |
| 37 | #include "scoped_thread_state_change.h" |
| 38 | #include "ScopedLocalRef.h" |
| 39 | #include "thread.h" |
| 40 | #include "thread_list.h" |
Dave Allison | 4a7867b | 2014-01-30 17:44:12 -0800 | [diff] [blame] | 41 | |
| 42 | #ifdef HAVE_ANDROID_OS |
| 43 | #include "cutils/properties.h" |
| 44 | #endif |
| 45 | |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 46 | #if !defined(ART_USE_PORTABLE_COMPILER) |
| 47 | #include "entrypoints/quick/quick_entrypoints.h" |
| 48 | #endif |
| 49 | |
| 50 | namespace art { |
| 51 | |
| 52 | BackgroundMethodSamplingProfiler* BackgroundMethodSamplingProfiler::profiler_ = nullptr; |
| 53 | pthread_t BackgroundMethodSamplingProfiler::profiler_pthread_ = 0U; |
| 54 | volatile bool BackgroundMethodSamplingProfiler::shutting_down_ = false; |
| 55 | |
| 56 | |
| 57 | // TODO: this profiler runs regardless of the state of the machine. Maybe we should use the |
| 58 | // wakelock or something to modify the run characteristics. This can be done when we |
| 59 | // have some performance data after it's been used for a while. |
| 60 | |
| 61 | |
| 62 | // This is called from either a thread list traversal or from a checkpoint. Regardless |
| 63 | // of which caller, the mutator lock must be held. |
| 64 | static void GetSample(Thread* thread, void* arg) SHARED_LOCKS_REQUIRED(Locks::mutator_lock_) { |
| 65 | BackgroundMethodSamplingProfiler* profiler = |
| 66 | reinterpret_cast<BackgroundMethodSamplingProfiler*>(arg); |
| 67 | mirror::ArtMethod* method = thread->GetCurrentMethod(nullptr); |
| 68 | if (false && method == nullptr) { |
| 69 | LOG(INFO) << "No current method available"; |
| 70 | std::ostringstream os; |
| 71 | thread->Dump(os); |
| 72 | std::string data(os.str()); |
| 73 | LOG(INFO) << data; |
| 74 | } |
| 75 | profiler->RecordMethod(method); |
| 76 | } |
| 77 | |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 78 | // A closure that is called by the thread checkpoint code. |
| 79 | class SampleCheckpoint : public Closure { |
| 80 | public: |
| 81 | explicit SampleCheckpoint(BackgroundMethodSamplingProfiler* const profiler) : |
| 82 | profiler_(profiler) {} |
| 83 | |
| 84 | virtual void Run(Thread* thread) NO_THREAD_SAFETY_ANALYSIS { |
| 85 | Thread* self = Thread::Current(); |
| 86 | if (thread == nullptr) { |
| 87 | LOG(ERROR) << "Checkpoint with nullptr thread"; |
| 88 | return; |
| 89 | } |
| 90 | |
| 91 | // Grab the mutator lock (shared access). |
| 92 | ScopedObjectAccess soa(self); |
| 93 | |
| 94 | // Grab a sample. |
| 95 | GetSample(thread, this->profiler_); |
| 96 | |
| 97 | // And finally tell the barrier that we're done. |
| 98 | this->profiler_->GetBarrier().Pass(self); |
| 99 | } |
| 100 | |
| 101 | private: |
| 102 | BackgroundMethodSamplingProfiler* const profiler_; |
| 103 | }; |
| 104 | |
| 105 | bool BackgroundMethodSamplingProfiler::ShuttingDown(Thread* self) { |
| 106 | MutexLock mu(self, *Locks::profiler_lock_); |
| 107 | return shutting_down_; |
| 108 | } |
| 109 | |
| 110 | void* BackgroundMethodSamplingProfiler::RunProfilerThread(void* arg) { |
| 111 | Runtime* runtime = Runtime::Current(); |
| 112 | BackgroundMethodSamplingProfiler* profiler = |
| 113 | reinterpret_cast<BackgroundMethodSamplingProfiler*>(arg); |
| 114 | |
| 115 | // Add a random delay for the first time run so that we don't hammer the CPU |
| 116 | // with all profiles running at the same time. |
| 117 | const int kRandomDelayMaxSecs = 30; |
| 118 | const double kMaxBackoffSecs = 24*60*60; // Max backoff time. |
| 119 | |
| 120 | srand(MicroTime() * getpid()); |
| 121 | int startup_delay = rand() % kRandomDelayMaxSecs; // random delay for startup. |
| 122 | |
| 123 | |
| 124 | CHECK(runtime->AttachCurrentThread("Profiler", true, runtime->GetSystemThreadGroup(), |
| 125 | !runtime->IsCompiler())); |
| 126 | |
| 127 | Thread* self = Thread::Current(); |
| 128 | |
| 129 | while (true) { |
| 130 | if (ShuttingDown(self)) { |
| 131 | break; |
| 132 | } |
| 133 | |
| 134 | { |
| 135 | // wait until we need to run another profile |
| 136 | uint64_t delay_secs = profiler->period_s_ * profiler->backoff_factor_; |
| 137 | |
| 138 | // Add a startup delay to prevent all the profiles running at once. |
| 139 | delay_secs += startup_delay; |
| 140 | |
| 141 | // Immediate startup for benchmarking? |
| 142 | if (profiler->start_immediately_ && startup_delay > 0) { |
| 143 | delay_secs = 0; |
| 144 | } |
| 145 | |
| 146 | startup_delay = 0; |
| 147 | |
Brian Carlstrom | 4d466a8 | 2014-05-08 19:05:29 -0700 | [diff] [blame] | 148 | VLOG(profiler) << "Delaying profile start for " << delay_secs << " secs"; |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 149 | MutexLock mu(self, profiler->wait_lock_); |
| 150 | profiler->period_condition_.TimedWait(self, delay_secs * 1000, 0); |
| 151 | |
| 152 | // Expand the backoff by its coefficient, but don't go beyond the max. |
| 153 | double new_backoff = profiler->backoff_factor_ * profiler->backoff_coefficient_; |
| 154 | if (new_backoff < kMaxBackoffSecs) { |
| 155 | profiler->backoff_factor_ = new_backoff; |
| 156 | } |
| 157 | } |
| 158 | |
| 159 | if (ShuttingDown(self)) { |
| 160 | break; |
| 161 | } |
| 162 | |
| 163 | |
| 164 | uint64_t start_us = MicroTime(); |
Ian Rogers | 0f67847 | 2014-03-10 16:18:37 -0700 | [diff] [blame] | 165 | uint64_t end_us = start_us + profiler->duration_s_ * UINT64_C(1000000); |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 166 | uint64_t now_us = start_us; |
| 167 | |
Brian Carlstrom | 4d466a8 | 2014-05-08 19:05:29 -0700 | [diff] [blame] | 168 | VLOG(profiler) << "Starting profiling run now for " << PrettyDuration((end_us - start_us) * 1000); |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 169 | |
| 170 | |
| 171 | SampleCheckpoint check_point(profiler); |
| 172 | |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 173 | size_t valid_samples = 0; |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 174 | while (now_us < end_us) { |
| 175 | if (ShuttingDown(self)) { |
| 176 | break; |
| 177 | } |
| 178 | |
| 179 | usleep(profiler->interval_us_); // Non-interruptible sleep. |
| 180 | |
| 181 | ThreadList* thread_list = runtime->GetThreadList(); |
| 182 | |
| 183 | profiler->profiler_barrier_->Init(self, 0); |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 184 | size_t barrier_count = thread_list->RunCheckpointOnRunnableThreads(&check_point); |
| 185 | |
| 186 | // All threads are suspended, nothing to do. |
| 187 | if (barrier_count == 0) { |
| 188 | now_us = MicroTime(); |
| 189 | continue; |
| 190 | } |
| 191 | |
| 192 | valid_samples += barrier_count; |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 193 | |
Wei Jin | 6a58691 | 2014-05-21 16:07:40 -0700 | [diff] [blame] | 194 | ScopedThreadStateChange tsc(self, kWaitingForCheckPointsToRun); |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 195 | |
| 196 | // Wait for the barrier to be crossed by all runnable threads. This wait |
| 197 | // is done with a timeout so that we can detect problems with the checkpoint |
| 198 | // running code. We should never see this. |
| 199 | const uint32_t kWaitTimeoutMs = 10000; |
| 200 | const uint32_t kWaitTimeoutUs = kWaitTimeoutMs * 1000; |
| 201 | |
| 202 | uint64_t waitstart_us = MicroTime(); |
| 203 | // Wait for all threads to pass the barrier. |
| 204 | profiler->profiler_barrier_->Increment(self, barrier_count, kWaitTimeoutMs); |
| 205 | uint64_t waitend_us = MicroTime(); |
| 206 | uint64_t waitdiff_us = waitend_us - waitstart_us; |
| 207 | |
| 208 | // We should never get a timeout. If we do, it suggests a problem with the checkpoint |
| 209 | // code. Crash the process in this case. |
| 210 | CHECK_LT(waitdiff_us, kWaitTimeoutUs); |
| 211 | |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 212 | // Update the current time. |
| 213 | now_us = MicroTime(); |
| 214 | } |
| 215 | |
Wei Jin | 6a58691 | 2014-05-21 16:07:40 -0700 | [diff] [blame] | 216 | if (valid_samples > 0) { |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 217 | // After the profile has been taken, write it out. |
| 218 | ScopedObjectAccess soa(self); // Acquire the mutator lock. |
| 219 | uint32_t size = profiler->WriteProfile(); |
Brian Carlstrom | 4d466a8 | 2014-05-08 19:05:29 -0700 | [diff] [blame] | 220 | VLOG(profiler) << "Profile size: " << size; |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 221 | } |
| 222 | } |
| 223 | |
| 224 | LOG(INFO) << "Profiler shutdown"; |
| 225 | runtime->DetachCurrentThread(); |
| 226 | return nullptr; |
| 227 | } |
| 228 | |
| 229 | // Write out the profile file if we are generating a profile. |
| 230 | uint32_t BackgroundMethodSamplingProfiler::WriteProfile() { |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 231 | std::string full_name = profile_file_name_; |
Brian Carlstrom | 4d466a8 | 2014-05-08 19:05:29 -0700 | [diff] [blame] | 232 | VLOG(profiler) << "Saving profile to " << full_name; |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 233 | |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 234 | int fd = open(full_name.c_str(), O_RDWR); |
| 235 | if (fd < 0) { |
| 236 | // Open failed. |
| 237 | LOG(ERROR) << "Failed to open profile file " << full_name; |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 238 | return 0; |
| 239 | } |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 240 | |
| 241 | // Lock the file for exclusive access. This will block if another process is using |
| 242 | // the file. |
| 243 | int err = flock(fd, LOCK_EX); |
| 244 | if (err < 0) { |
| 245 | LOG(ERROR) << "Failed to lock profile file " << full_name; |
| 246 | return 0; |
| 247 | } |
| 248 | |
| 249 | // Read the previous profile. |
| 250 | profile_table_.ReadPrevious(fd); |
| 251 | |
| 252 | // Move back to the start of the file. |
| 253 | lseek(fd, 0, SEEK_SET); |
| 254 | |
| 255 | // Format the profile output and write to the file. |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 256 | std::ostringstream os; |
| 257 | uint32_t num_methods = DumpProfile(os); |
| 258 | std::string data(os.str()); |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 259 | const char *p = data.c_str(); |
| 260 | size_t length = data.length(); |
| 261 | size_t full_length = length; |
| 262 | do { |
| 263 | int n = ::write(fd, p, length); |
| 264 | p += n; |
| 265 | length -= n; |
| 266 | } while (length > 0); |
| 267 | |
| 268 | // Truncate the file to the new length. |
| 269 | ftruncate(fd, full_length); |
| 270 | |
| 271 | // Now unlock the file, allowing another process in. |
| 272 | err = flock(fd, LOCK_UN); |
| 273 | if (err < 0) { |
| 274 | LOG(ERROR) << "Failed to unlock profile file " << full_name; |
| 275 | } |
| 276 | |
| 277 | // Done, close the file. |
| 278 | ::close(fd); |
| 279 | |
| 280 | // Clean the profile for the next time. |
| 281 | CleanProfile(); |
| 282 | |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 283 | return num_methods; |
| 284 | } |
| 285 | |
| 286 | // Start a profile thread with the user-supplied arguments. |
| 287 | void BackgroundMethodSamplingProfiler::Start(int period, int duration, |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 288 | const std::string& profile_file_name, const std::string& procName, |
| 289 | int interval_us, |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 290 | double backoff_coefficient, bool startImmediately) { |
| 291 | Thread* self = Thread::Current(); |
| 292 | { |
| 293 | MutexLock mu(self, *Locks::profiler_lock_); |
| 294 | // Don't start two profiler threads. |
| 295 | if (profiler_ != nullptr) { |
| 296 | return; |
| 297 | } |
| 298 | } |
| 299 | |
Dave Allison | 4a7867b | 2014-01-30 17:44:12 -0800 | [diff] [blame] | 300 | // Only on target... |
| 301 | #ifdef HAVE_ANDROID_OS |
Dave Allison | 2d524dd | 2014-04-09 13:51:55 -0700 | [diff] [blame] | 302 | // Switch off profiler if the dalvik.vm.profiler property has value 0. |
| 303 | char buf[PROP_VALUE_MAX]; |
| 304 | property_get("dalvik.vm.profiler", buf, "0"); |
| 305 | if (strcmp(buf, "0") == 0) { |
| 306 | LOG(INFO) << "Profiler disabled. To enable setprop dalvik.vm.profiler 1"; |
| 307 | return; |
Dave Allison | 4a7867b | 2014-01-30 17:44:12 -0800 | [diff] [blame] | 308 | } |
| 309 | #endif |
| 310 | |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 311 | LOG(INFO) << "Starting profile with period " << period << "s, duration " << duration << |
| 312 | "s, interval " << interval_us << "us. Profile file " << profile_file_name; |
| 313 | |
| 314 | { |
| 315 | MutexLock mu(self, *Locks::profiler_lock_); |
| 316 | profiler_ = new BackgroundMethodSamplingProfiler(period, duration, profile_file_name, |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 317 | procName, |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 318 | backoff_coefficient, |
| 319 | interval_us, startImmediately); |
| 320 | |
| 321 | CHECK_PTHREAD_CALL(pthread_create, (&profiler_pthread_, nullptr, &RunProfilerThread, |
| 322 | reinterpret_cast<void*>(profiler_)), |
| 323 | "Profiler thread"); |
| 324 | } |
| 325 | } |
| 326 | |
| 327 | |
| 328 | |
| 329 | void BackgroundMethodSamplingProfiler::Stop() { |
| 330 | BackgroundMethodSamplingProfiler* profiler = nullptr; |
| 331 | pthread_t profiler_pthread = 0U; |
| 332 | { |
| 333 | MutexLock trace_mu(Thread::Current(), *Locks::profiler_lock_); |
Wei Jin | 6a58691 | 2014-05-21 16:07:40 -0700 | [diff] [blame] | 334 | CHECK(!shutting_down_); |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 335 | profiler = profiler_; |
| 336 | shutting_down_ = true; |
| 337 | profiler_pthread = profiler_pthread_; |
| 338 | } |
| 339 | |
| 340 | // Now wake up the sampler thread if it sleeping. |
| 341 | { |
| 342 | MutexLock profile_mu(Thread::Current(), profiler->wait_lock_); |
| 343 | profiler->period_condition_.Signal(Thread::Current()); |
| 344 | } |
| 345 | // Wait for the sample thread to stop. |
| 346 | CHECK_PTHREAD_CALL(pthread_join, (profiler_pthread, nullptr), "profiler thread shutdown"); |
| 347 | |
| 348 | { |
| 349 | MutexLock mu(Thread::Current(), *Locks::profiler_lock_); |
| 350 | profiler_ = nullptr; |
| 351 | } |
| 352 | delete profiler; |
| 353 | } |
| 354 | |
| 355 | |
| 356 | void BackgroundMethodSamplingProfiler::Shutdown() { |
| 357 | Stop(); |
| 358 | } |
| 359 | |
| 360 | BackgroundMethodSamplingProfiler::BackgroundMethodSamplingProfiler(int period, int duration, |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 361 | const std::string& profile_file_name, |
| 362 | const std::string& process_name, |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 363 | double backoff_coefficient, int interval_us, bool startImmediately) |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 364 | : profile_file_name_(profile_file_name), process_name_(process_name), |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 365 | period_s_(period), start_immediately_(startImmediately), |
| 366 | interval_us_(interval_us), backoff_factor_(1.0), |
| 367 | backoff_coefficient_(backoff_coefficient), duration_s_(duration), |
| 368 | wait_lock_("Profile wait lock"), |
| 369 | period_condition_("Profile condition", wait_lock_), |
| 370 | profile_table_(wait_lock_), |
| 371 | profiler_barrier_(new Barrier(0)) { |
| 372 | // Populate the filtered_methods set. |
| 373 | // This is empty right now, but to add a method, do this: |
| 374 | // |
| 375 | // filtered_methods_.insert("void java.lang.Object.wait(long, int)"); |
| 376 | } |
| 377 | |
| 378 | // A method has been hit, record its invocation in the method map. |
| 379 | // The mutator_lock must be held (shared) when this is called. |
| 380 | void BackgroundMethodSamplingProfiler::RecordMethod(mirror::ArtMethod* method) { |
| 381 | if (method == nullptr) { |
| 382 | profile_table_.NullMethod(); |
| 383 | // Don't record a nullptr method. |
| 384 | return; |
| 385 | } |
| 386 | |
| 387 | mirror::Class* cls = method->GetDeclaringClass(); |
| 388 | if (cls != nullptr) { |
| 389 | if (cls->GetClassLoader() == nullptr) { |
| 390 | // Don't include things in the boot |
| 391 | profile_table_.BootMethod(); |
| 392 | return; |
| 393 | } |
| 394 | } |
| 395 | |
| 396 | bool is_filtered = false; |
| 397 | |
| 398 | MethodHelper mh(method); |
| 399 | if (strcmp(mh.GetName(), "<clinit>") == 0) { |
| 400 | // always filter out class init |
| 401 | is_filtered = true; |
| 402 | } |
| 403 | |
| 404 | // Filter out methods by name if there are any. |
| 405 | if (!is_filtered && filtered_methods_.size() > 0) { |
| 406 | std::string method_full_name = PrettyMethod(method); |
| 407 | |
| 408 | // Don't include specific filtered methods. |
| 409 | is_filtered = filtered_methods_.count(method_full_name) != 0; |
| 410 | } |
| 411 | |
| 412 | // Add to the profile table unless it is filtered out. |
| 413 | if (!is_filtered) { |
| 414 | profile_table_.Put(method); |
| 415 | } |
| 416 | } |
| 417 | |
| 418 | // Clean out any recordings for the method traces. |
| 419 | void BackgroundMethodSamplingProfiler::CleanProfile() { |
| 420 | profile_table_.Clear(); |
| 421 | } |
| 422 | |
| 423 | uint32_t BackgroundMethodSamplingProfiler::DumpProfile(std::ostream& os) { |
| 424 | return profile_table_.Write(os); |
| 425 | } |
| 426 | |
| 427 | // Profile Table. |
| 428 | // This holds a mapping of mirror::ArtMethod* to a count of how many times a sample |
| 429 | // hit it at the top of the stack. |
| 430 | ProfileSampleResults::ProfileSampleResults(Mutex& lock) : lock_(lock), num_samples_(0), |
| 431 | num_null_methods_(0), |
| 432 | num_boot_methods_(0) { |
| 433 | for (int i = 0; i < kHashSize; i++) { |
| 434 | table[i] = nullptr; |
| 435 | } |
| 436 | } |
| 437 | |
| 438 | ProfileSampleResults::~ProfileSampleResults() { |
| 439 | for (int i = 0; i < kHashSize; i++) { |
| 440 | delete table[i]; |
| 441 | } |
| 442 | } |
| 443 | |
Calin Juravle | bb0b53f | 2014-05-23 17:33:29 +0100 | [diff] [blame^] | 444 | // Add a method to the profile table. If it's the first time the method |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 445 | // has been seen, add it with count=1, otherwise increment the count. |
| 446 | void ProfileSampleResults::Put(mirror::ArtMethod* method) { |
| 447 | lock_.Lock(Thread::Current()); |
| 448 | uint32_t index = Hash(method); |
| 449 | if (table[index] == nullptr) { |
| 450 | table[index] = new Map(); |
| 451 | } |
| 452 | Map::iterator i = table[index]->find(method); |
| 453 | if (i == table[index]->end()) { |
| 454 | (*table[index])[method] = 1; |
| 455 | } else { |
| 456 | i->second++; |
| 457 | } |
| 458 | num_samples_++; |
| 459 | lock_.Unlock(Thread::Current()); |
| 460 | } |
| 461 | |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 462 | // Write the profile table to the output stream. Also merge with the previous profile. |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 463 | uint32_t ProfileSampleResults::Write(std::ostream &os) { |
| 464 | ScopedObjectAccess soa(Thread::Current()); |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 465 | num_samples_ += previous_num_samples_; |
| 466 | num_null_methods_ += previous_num_null_methods_; |
| 467 | num_boot_methods_ += previous_num_boot_methods_; |
| 468 | |
Brian Carlstrom | 4d466a8 | 2014-05-08 19:05:29 -0700 | [diff] [blame] | 469 | VLOG(profiler) << "Profile: " << num_samples_ << "/" << num_null_methods_ << "/" << num_boot_methods_; |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 470 | os << num_samples_ << "/" << num_null_methods_ << "/" << num_boot_methods_ << "\n"; |
| 471 | uint32_t num_methods = 0; |
| 472 | for (int i = 0 ; i < kHashSize; i++) { |
| 473 | Map *map = table[i]; |
| 474 | if (map != nullptr) { |
| 475 | for (const auto &meth_iter : *map) { |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 476 | mirror::ArtMethod *method = meth_iter.first; |
| 477 | std::string method_name = PrettyMethod(method); |
| 478 | |
| 479 | MethodHelper mh(method); |
| 480 | const DexFile::CodeItem* codeitem = mh.GetCodeItem(); |
| 481 | uint32_t method_size = 0; |
| 482 | if (codeitem != nullptr) { |
| 483 | method_size = codeitem->insns_size_in_code_units_; |
| 484 | } |
| 485 | uint32_t count = meth_iter.second; |
| 486 | |
| 487 | // Merge this profile entry with one from a previous run (if present). Also |
| 488 | // remove the previous entry. |
| 489 | PreviousProfile::iterator pi = previous_.find(method_name); |
| 490 | if (pi != previous_.end()) { |
| 491 | count += pi->second.count_; |
| 492 | previous_.erase(pi); |
| 493 | } |
| 494 | os << StringPrintf("%s/%u/%u\n", method_name.c_str(), count, method_size); |
| 495 | ++num_methods; |
| 496 | } |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 497 | } |
| 498 | } |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 499 | |
| 500 | // Now we write out the remaining previous methods. |
| 501 | for (PreviousProfile::iterator pi = previous_.begin(); pi != previous_.end(); ++pi) { |
| 502 | os << StringPrintf("%s/%u/%u\n", pi->first.c_str(), pi->second.count_, pi->second.method_size_); |
| 503 | ++num_methods; |
| 504 | } |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 505 | return num_methods; |
| 506 | } |
| 507 | |
| 508 | void ProfileSampleResults::Clear() { |
| 509 | num_samples_ = 0; |
| 510 | num_null_methods_ = 0; |
| 511 | num_boot_methods_ = 0; |
| 512 | for (int i = 0; i < kHashSize; i++) { |
| 513 | delete table[i]; |
| 514 | table[i] = nullptr; |
| 515 | } |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 516 | previous_.clear(); |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 517 | } |
| 518 | |
| 519 | uint32_t ProfileSampleResults::Hash(mirror::ArtMethod* method) { |
Ian Rogers | ef7d42f | 2014-01-06 12:55:46 -0800 | [diff] [blame] | 520 | return (PointerToLowMemUInt32(method) >> 3) % kHashSize; |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 521 | } |
| 522 | |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 523 | // Read a single line into the given string. Returns true if everything OK, false |
| 524 | // on EOF or error. |
| 525 | static bool ReadProfileLine(int fd, std::string& line) { |
| 526 | char buf[4]; |
| 527 | line.clear(); |
| 528 | while (true) { |
| 529 | int n = read(fd, buf, 1); // TODO: could speed this up but is it worth it? |
| 530 | if (n != 1) { |
| 531 | return false; |
| 532 | } |
| 533 | if (buf[0] == '\n') { |
| 534 | break; |
| 535 | } |
| 536 | line += buf[0]; |
| 537 | } |
| 538 | return true; |
| 539 | } |
| 540 | |
| 541 | void ProfileSampleResults::ReadPrevious(int fd) { |
| 542 | // Reset counters. |
| 543 | previous_num_samples_ = previous_num_null_methods_ = previous_num_boot_methods_ = 0; |
| 544 | |
| 545 | std::string line; |
| 546 | |
| 547 | // The first line contains summary information. |
| 548 | if (!ReadProfileLine(fd, line)) { |
| 549 | return; |
| 550 | } |
| 551 | std::vector<std::string> summary_info; |
| 552 | Split(line, '/', summary_info); |
| 553 | if (summary_info.size() != 3) { |
| 554 | // Bad summary info. It should be count/nullcount/bootcount |
| 555 | return; |
| 556 | } |
| 557 | previous_num_samples_ = atoi(summary_info[0].c_str()); |
| 558 | previous_num_null_methods_ = atoi(summary_info[1].c_str()); |
| 559 | previous_num_boot_methods_ = atoi(summary_info[2].c_str()); |
| 560 | |
| 561 | // Now read each line until the end of file. Each line consists of 3 fields separated by / |
| 562 | while (true) { |
| 563 | if (!ReadProfileLine(fd, line)) { |
| 564 | break; |
| 565 | } |
| 566 | std::vector<std::string> info; |
| 567 | Split(line, '/', info); |
| 568 | if (info.size() != 3) { |
| 569 | // Malformed. |
| 570 | break; |
| 571 | } |
| 572 | std::string methodname = info[0]; |
| 573 | uint32_t count = atoi(info[1].c_str()); |
| 574 | uint32_t size = atoi(info[2].c_str()); |
| 575 | previous_[methodname] = PreviousValue(count, size); |
| 576 | } |
| 577 | } |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 578 | |
Calin Juravle | bb0b53f | 2014-05-23 17:33:29 +0100 | [diff] [blame^] | 579 | bool ProfileFile::LoadFile(const std::string& fileName) { |
Calin Juravle | 9dae5b4 | 2014-04-07 16:36:21 +0300 | [diff] [blame] | 580 | LOG(VERBOSE) << "reading profile file " << fileName; |
| 581 | struct stat st; |
| 582 | int err = stat(fileName.c_str(), &st); |
| 583 | if (err == -1) { |
| 584 | LOG(VERBOSE) << "not found"; |
| 585 | return false; |
| 586 | } |
| 587 | if (st.st_size == 0) { |
Dave Allison | 644789f | 2014-04-10 13:06:10 -0700 | [diff] [blame] | 588 | return false; // Empty profiles are invalid. |
Calin Juravle | 9dae5b4 | 2014-04-07 16:36:21 +0300 | [diff] [blame] | 589 | } |
| 590 | std::ifstream in(fileName.c_str()); |
| 591 | if (!in) { |
| 592 | LOG(VERBOSE) << "profile file " << fileName << " exists but can't be opened"; |
| 593 | LOG(VERBOSE) << "file owner: " << st.st_uid << ":" << st.st_gid; |
| 594 | LOG(VERBOSE) << "me: " << getuid() << ":" << getgid(); |
| 595 | LOG(VERBOSE) << "file permissions: " << std::oct << st.st_mode; |
| 596 | LOG(VERBOSE) << "errno: " << errno; |
| 597 | return false; |
| 598 | } |
| 599 | // The first line contains summary information. |
| 600 | std::string line; |
| 601 | std::getline(in, line); |
| 602 | if (in.eof()) { |
| 603 | return false; |
| 604 | } |
| 605 | std::vector<std::string> summary_info; |
| 606 | Split(line, '/', summary_info); |
| 607 | if (summary_info.size() != 3) { |
| 608 | // Bad summary info. It should be count/total/bootpath. |
| 609 | return false; |
| 610 | } |
| 611 | // This is the number of hits in all methods. |
| 612 | uint32_t total_count = 0; |
| 613 | for (int i = 0 ; i < 3; ++i) { |
| 614 | total_count += atoi(summary_info[i].c_str()); |
| 615 | } |
| 616 | |
| 617 | // Now read each line until the end of file. Each line consists of 3 fields separated by '/'. |
| 618 | // Store the info in descending order given by the most used methods. |
| 619 | typedef std::set<std::pair<int, std::vector<std::string>>> ProfileSet; |
| 620 | ProfileSet countSet; |
| 621 | while (!in.eof()) { |
| 622 | std::getline(in, line); |
| 623 | if (in.eof()) { |
| 624 | break; |
| 625 | } |
| 626 | std::vector<std::string> info; |
| 627 | Split(line, '/', info); |
| 628 | if (info.size() != 3) { |
| 629 | // Malformed. |
Calin Juravle | bb0b53f | 2014-05-23 17:33:29 +0100 | [diff] [blame^] | 630 | return false; |
Calin Juravle | 9dae5b4 | 2014-04-07 16:36:21 +0300 | [diff] [blame] | 631 | } |
| 632 | int count = atoi(info[1].c_str()); |
| 633 | countSet.insert(std::make_pair(-count, info)); |
| 634 | } |
| 635 | |
| 636 | uint32_t curTotalCount = 0; |
| 637 | ProfileSet::iterator end = countSet.end(); |
| 638 | const ProfileData* prevData = nullptr; |
| 639 | for (ProfileSet::iterator it = countSet.begin(); it != end ; it++) { |
| 640 | const std::string& methodname = it->second[0]; |
| 641 | uint32_t count = -it->first; |
| 642 | uint32_t size = atoi(it->second[2].c_str()); |
| 643 | double usedPercent = (count * 100.0) / total_count; |
| 644 | |
| 645 | curTotalCount += count; |
| 646 | // Methods with the same count should be part of the same top K percentage bucket. |
| 647 | double topKPercentage = (prevData != nullptr) && (prevData->GetCount() == count) |
| 648 | ? prevData->GetTopKUsedPercentage() |
| 649 | : 100 * static_cast<double>(curTotalCount) / static_cast<double>(total_count); |
| 650 | |
| 651 | // Add it to the profile map. |
| 652 | ProfileData curData = ProfileData(methodname, count, size, usedPercent, topKPercentage); |
Calin Juravle | bb0b53f | 2014-05-23 17:33:29 +0100 | [diff] [blame^] | 653 | profile_map_[methodname] = curData; |
Calin Juravle | 9dae5b4 | 2014-04-07 16:36:21 +0300 | [diff] [blame] | 654 | prevData = &curData; |
| 655 | } |
| 656 | return true; |
| 657 | } |
| 658 | |
Calin Juravle | bb0b53f | 2014-05-23 17:33:29 +0100 | [diff] [blame^] | 659 | bool ProfileFile::GetProfileData(ProfileFile::ProfileData* data, const std::string& method_name) { |
| 660 | ProfileMap::iterator i = profile_map_.find(method_name); |
| 661 | if (i == profile_map_.end()) { |
Calin Juravle | 9dae5b4 | 2014-04-07 16:36:21 +0300 | [diff] [blame] | 662 | return false; |
| 663 | } |
Calin Juravle | bb0b53f | 2014-05-23 17:33:29 +0100 | [diff] [blame^] | 664 | *data = i->second; |
| 665 | return true; |
| 666 | } |
| 667 | |
| 668 | bool ProfileFile::GetTopKSamples(std::set<std::string>& topKSamples, double topKPercentage) { |
| 669 | ProfileMap::iterator end = profile_map_.end(); |
| 670 | for (ProfileMap::iterator it = profile_map_.begin(); it != end; it++) { |
Calin Juravle | 9dae5b4 | 2014-04-07 16:36:21 +0300 | [diff] [blame] | 671 | if (it->second.GetTopKUsedPercentage() < topKPercentage) { |
| 672 | topKSamples.insert(it->first); |
| 673 | } |
| 674 | } |
| 675 | return true; |
| 676 | } |
| 677 | |
| 678 | } // namespace art |