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 | |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 19 | #include <sys/file.h> |
Ian Rogers | 6f3dbba | 2014-10-14 17:41:57 -0700 | [diff] [blame] | 20 | #include <sys/stat.h> |
| 21 | #include <sys/uio.h> |
| 22 | |
| 23 | #include <fstream> |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 24 | |
Mathieu Chartier | e401d14 | 2015-04-22 13:56:20 -0700 | [diff] [blame] | 25 | #include "art_method-inl.h" |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 26 | #include "base/stl_util.h" |
Vladimir Marko | 80afd02 | 2015-05-19 18:08:00 +0100 | [diff] [blame] | 27 | #include "base/time_utils.h" |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 28 | #include "base/unix_file/fd_file.h" |
| 29 | #include "class_linker.h" |
| 30 | #include "common_throws.h" |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 31 | #include "dex_file-inl.h" |
| 32 | #include "instrumentation.h" |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 33 | #include "mirror/class-inl.h" |
| 34 | #include "mirror/dex_cache.h" |
| 35 | #include "mirror/object_array-inl.h" |
| 36 | #include "mirror/object-inl.h" |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 37 | #include "os.h" |
| 38 | #include "scoped_thread_state_change.h" |
| 39 | #include "ScopedLocalRef.h" |
| 40 | #include "thread.h" |
| 41 | #include "thread_list.h" |
Vladimir Marko | 80afd02 | 2015-05-19 18:08:00 +0100 | [diff] [blame] | 42 | #include "utils.h" |
Dave Allison | 4a7867b | 2014-01-30 17:44:12 -0800 | [diff] [blame] | 43 | |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 44 | #include "entrypoints/quick/quick_entrypoints.h" |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 45 | |
| 46 | namespace art { |
| 47 | |
| 48 | BackgroundMethodSamplingProfiler* BackgroundMethodSamplingProfiler::profiler_ = nullptr; |
| 49 | pthread_t BackgroundMethodSamplingProfiler::profiler_pthread_ = 0U; |
| 50 | volatile bool BackgroundMethodSamplingProfiler::shutting_down_ = false; |
| 51 | |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 52 | // TODO: this profiler runs regardless of the state of the machine. Maybe we should use the |
| 53 | // wakelock or something to modify the run characteristics. This can be done when we |
| 54 | // have some performance data after it's been used for a while. |
| 55 | |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 56 | // Walk through the method within depth of max_depth_ on the Java stack |
| 57 | class BoundedStackVisitor : public StackVisitor { |
| 58 | public: |
Mathieu Chartier | e401d14 | 2015-04-22 13:56:20 -0700 | [diff] [blame] | 59 | BoundedStackVisitor(std::vector<std::pair<ArtMethod*, uint32_t>>* stack, |
Sebastien Hertz | 26f7286 | 2015-09-15 09:52:07 +0200 | [diff] [blame] | 60 | Thread* thread, |
| 61 | uint32_t max_depth) |
Mathieu Chartier | 9044347 | 2015-07-16 20:32:27 -0700 | [diff] [blame] | 62 | SHARED_REQUIRES(Locks::mutator_lock_) |
Nicolas Geoffray | 8e5bd18 | 2015-05-06 11:34:34 +0100 | [diff] [blame] | 63 | : StackVisitor(thread, nullptr, StackVisitor::StackWalkKind::kIncludeInlinedFrames), |
| 64 | stack_(stack), |
| 65 | max_depth_(max_depth), |
| 66 | depth_(0) {} |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 67 | |
Mathieu Chartier | 9044347 | 2015-07-16 20:32:27 -0700 | [diff] [blame] | 68 | bool VisitFrame() SHARED_REQUIRES(Locks::mutator_lock_) { |
Mathieu Chartier | e401d14 | 2015-04-22 13:56:20 -0700 | [diff] [blame] | 69 | ArtMethod* m = GetMethod(); |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 70 | if (m->IsRuntimeMethod()) { |
| 71 | return true; |
| 72 | } |
| 73 | uint32_t dex_pc_ = GetDexPc(); |
| 74 | stack_->push_back(std::make_pair(m, dex_pc_)); |
| 75 | ++depth_; |
| 76 | if (depth_ < max_depth_) { |
| 77 | return true; |
| 78 | } else { |
| 79 | return false; |
| 80 | } |
| 81 | } |
| 82 | |
| 83 | private: |
Sebastien Hertz | 26f7286 | 2015-09-15 09:52:07 +0200 | [diff] [blame] | 84 | std::vector<std::pair<ArtMethod*, uint32_t>>* const stack_; |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 85 | const uint32_t max_depth_; |
| 86 | uint32_t depth_; |
Sebastien Hertz | 26f7286 | 2015-09-15 09:52:07 +0200 | [diff] [blame] | 87 | |
| 88 | DISALLOW_COPY_AND_ASSIGN(BoundedStackVisitor); |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 89 | }; |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 90 | |
| 91 | // This is called from either a thread list traversal or from a checkpoint. Regardless |
| 92 | // of which caller, the mutator lock must be held. |
Mathieu Chartier | 9044347 | 2015-07-16 20:32:27 -0700 | [diff] [blame] | 93 | static void GetSample(Thread* thread, void* arg) SHARED_REQUIRES(Locks::mutator_lock_) { |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 94 | BackgroundMethodSamplingProfiler* profiler = |
| 95 | reinterpret_cast<BackgroundMethodSamplingProfiler*>(arg); |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 96 | const ProfilerOptions profile_options = profiler->GetProfilerOptions(); |
| 97 | switch (profile_options.GetProfileType()) { |
| 98 | case kProfilerMethod: { |
Mathieu Chartier | e401d14 | 2015-04-22 13:56:20 -0700 | [diff] [blame] | 99 | ArtMethod* method = thread->GetCurrentMethod(nullptr); |
Ian Rogers | cf7f191 | 2014-10-22 22:06:39 -0700 | [diff] [blame] | 100 | if ((false) && method == nullptr) { |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 101 | LOG(INFO) << "No current method available"; |
| 102 | std::ostringstream os; |
| 103 | thread->Dump(os); |
| 104 | std::string data(os.str()); |
| 105 | LOG(INFO) << data; |
| 106 | } |
| 107 | profiler->RecordMethod(method); |
| 108 | break; |
| 109 | } |
| 110 | case kProfilerBoundedStack: { |
| 111 | std::vector<InstructionLocation> stack; |
| 112 | uint32_t max_depth = profile_options.GetMaxStackDepth(); |
| 113 | BoundedStackVisitor bounded_stack_visitor(&stack, thread, max_depth); |
| 114 | bounded_stack_visitor.WalkStack(); |
| 115 | profiler->RecordStack(stack); |
| 116 | break; |
| 117 | } |
| 118 | default: |
| 119 | LOG(INFO) << "This profile type is not implemented."; |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 120 | } |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 121 | } |
| 122 | |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 123 | // A closure that is called by the thread checkpoint code. |
Ian Rogers | 7b078e8 | 2014-09-10 14:44:24 -0700 | [diff] [blame] | 124 | class SampleCheckpoint FINAL : public Closure { |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 125 | public: |
| 126 | explicit SampleCheckpoint(BackgroundMethodSamplingProfiler* const profiler) : |
| 127 | profiler_(profiler) {} |
| 128 | |
Ian Rogers | 7b078e8 | 2014-09-10 14:44:24 -0700 | [diff] [blame] | 129 | void Run(Thread* thread) OVERRIDE { |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 130 | Thread* self = Thread::Current(); |
| 131 | if (thread == nullptr) { |
| 132 | LOG(ERROR) << "Checkpoint with nullptr thread"; |
| 133 | return; |
| 134 | } |
| 135 | |
| 136 | // Grab the mutator lock (shared access). |
| 137 | ScopedObjectAccess soa(self); |
| 138 | |
| 139 | // Grab a sample. |
| 140 | GetSample(thread, this->profiler_); |
| 141 | |
| 142 | // And finally tell the barrier that we're done. |
| 143 | this->profiler_->GetBarrier().Pass(self); |
| 144 | } |
| 145 | |
| 146 | private: |
| 147 | BackgroundMethodSamplingProfiler* const profiler_; |
| 148 | }; |
| 149 | |
| 150 | bool BackgroundMethodSamplingProfiler::ShuttingDown(Thread* self) { |
| 151 | MutexLock mu(self, *Locks::profiler_lock_); |
| 152 | return shutting_down_; |
| 153 | } |
| 154 | |
| 155 | void* BackgroundMethodSamplingProfiler::RunProfilerThread(void* arg) { |
| 156 | Runtime* runtime = Runtime::Current(); |
| 157 | BackgroundMethodSamplingProfiler* profiler = |
| 158 | reinterpret_cast<BackgroundMethodSamplingProfiler*>(arg); |
| 159 | |
| 160 | // Add a random delay for the first time run so that we don't hammer the CPU |
| 161 | // with all profiles running at the same time. |
| 162 | const int kRandomDelayMaxSecs = 30; |
| 163 | const double kMaxBackoffSecs = 24*60*60; // Max backoff time. |
| 164 | |
| 165 | srand(MicroTime() * getpid()); |
| 166 | int startup_delay = rand() % kRandomDelayMaxSecs; // random delay for startup. |
| 167 | |
| 168 | |
| 169 | CHECK(runtime->AttachCurrentThread("Profiler", true, runtime->GetSystemThreadGroup(), |
Mathieu Chartier | e5f13e5 | 2015-02-24 09:37:21 -0800 | [diff] [blame] | 170 | !runtime->IsAotCompiler())); |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 171 | |
| 172 | Thread* self = Thread::Current(); |
| 173 | |
Calin Juravle | c1b643c | 2014-05-30 23:44:11 +0100 | [diff] [blame] | 174 | double backoff = 1.0; |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 175 | while (true) { |
| 176 | if (ShuttingDown(self)) { |
| 177 | break; |
| 178 | } |
| 179 | |
| 180 | { |
| 181 | // wait until we need to run another profile |
Calin Juravle | c1b643c | 2014-05-30 23:44:11 +0100 | [diff] [blame] | 182 | uint64_t delay_secs = profiler->options_.GetPeriodS() * backoff; |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 183 | |
| 184 | // Add a startup delay to prevent all the profiles running at once. |
| 185 | delay_secs += startup_delay; |
| 186 | |
| 187 | // Immediate startup for benchmarking? |
Calin Juravle | c1b643c | 2014-05-30 23:44:11 +0100 | [diff] [blame] | 188 | if (profiler->options_.GetStartImmediately() && startup_delay > 0) { |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 189 | delay_secs = 0; |
| 190 | } |
| 191 | |
| 192 | startup_delay = 0; |
| 193 | |
Brian Carlstrom | 4d466a8 | 2014-05-08 19:05:29 -0700 | [diff] [blame] | 194 | VLOG(profiler) << "Delaying profile start for " << delay_secs << " secs"; |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 195 | MutexLock mu(self, profiler->wait_lock_); |
| 196 | profiler->period_condition_.TimedWait(self, delay_secs * 1000, 0); |
Ian Rogers | 7b078e8 | 2014-09-10 14:44:24 -0700 | [diff] [blame] | 197 | // We were either signaled by Stop or timedout, in either case ignore the timed out result. |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 198 | |
| 199 | // Expand the backoff by its coefficient, but don't go beyond the max. |
Calin Juravle | c1b643c | 2014-05-30 23:44:11 +0100 | [diff] [blame] | 200 | backoff = std::min(backoff * profiler->options_.GetBackoffCoefficient(), kMaxBackoffSecs); |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 201 | } |
| 202 | |
| 203 | if (ShuttingDown(self)) { |
| 204 | break; |
| 205 | } |
| 206 | |
| 207 | |
| 208 | uint64_t start_us = MicroTime(); |
Calin Juravle | c1b643c | 2014-05-30 23:44:11 +0100 | [diff] [blame] | 209 | uint64_t end_us = start_us + profiler->options_.GetDurationS() * UINT64_C(1000000); |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 210 | uint64_t now_us = start_us; |
| 211 | |
Calin Juravle | c1b643c | 2014-05-30 23:44:11 +0100 | [diff] [blame] | 212 | VLOG(profiler) << "Starting profiling run now for " |
| 213 | << PrettyDuration((end_us - start_us) * 1000); |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 214 | |
| 215 | SampleCheckpoint check_point(profiler); |
| 216 | |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 217 | size_t valid_samples = 0; |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 218 | while (now_us < end_us) { |
| 219 | if (ShuttingDown(self)) { |
| 220 | break; |
| 221 | } |
| 222 | |
Calin Juravle | c1b643c | 2014-05-30 23:44:11 +0100 | [diff] [blame] | 223 | usleep(profiler->options_.GetIntervalUs()); // Non-interruptible sleep. |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 224 | |
| 225 | ThreadList* thread_list = runtime->GetThreadList(); |
| 226 | |
| 227 | profiler->profiler_barrier_->Init(self, 0); |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 228 | size_t barrier_count = thread_list->RunCheckpointOnRunnableThreads(&check_point); |
| 229 | |
| 230 | // All threads are suspended, nothing to do. |
| 231 | if (barrier_count == 0) { |
| 232 | now_us = MicroTime(); |
| 233 | continue; |
| 234 | } |
| 235 | |
| 236 | valid_samples += barrier_count; |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 237 | |
Wei Jin | 6a58691 | 2014-05-21 16:07:40 -0700 | [diff] [blame] | 238 | ScopedThreadStateChange tsc(self, kWaitingForCheckPointsToRun); |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 239 | |
| 240 | // Wait for the barrier to be crossed by all runnable threads. This wait |
| 241 | // is done with a timeout so that we can detect problems with the checkpoint |
| 242 | // running code. We should never see this. |
| 243 | const uint32_t kWaitTimeoutMs = 10000; |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 244 | |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 245 | // Wait for all threads to pass the barrier. |
Ian Rogers | 7b078e8 | 2014-09-10 14:44:24 -0700 | [diff] [blame] | 246 | bool timed_out = profiler->profiler_barrier_->Increment(self, barrier_count, kWaitTimeoutMs); |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 247 | |
| 248 | // We should never get a timeout. If we do, it suggests a problem with the checkpoint |
| 249 | // code. Crash the process in this case. |
Ian Rogers | 7b078e8 | 2014-09-10 14:44:24 -0700 | [diff] [blame] | 250 | CHECK(!timed_out); |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 251 | |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 252 | // Update the current time. |
| 253 | now_us = MicroTime(); |
| 254 | } |
| 255 | |
Wei Jin | 6a58691 | 2014-05-21 16:07:40 -0700 | [diff] [blame] | 256 | if (valid_samples > 0) { |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 257 | // After the profile has been taken, write it out. |
| 258 | ScopedObjectAccess soa(self); // Acquire the mutator lock. |
| 259 | uint32_t size = profiler->WriteProfile(); |
Brian Carlstrom | 4d466a8 | 2014-05-08 19:05:29 -0700 | [diff] [blame] | 260 | VLOG(profiler) << "Profile size: " << size; |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 261 | } |
| 262 | } |
| 263 | |
| 264 | LOG(INFO) << "Profiler shutdown"; |
| 265 | runtime->DetachCurrentThread(); |
| 266 | return nullptr; |
| 267 | } |
| 268 | |
| 269 | // Write out the profile file if we are generating a profile. |
| 270 | uint32_t BackgroundMethodSamplingProfiler::WriteProfile() { |
Calin Juravle | c1b643c | 2014-05-30 23:44:11 +0100 | [diff] [blame] | 271 | std::string full_name = output_filename_; |
Brian Carlstrom | 4d466a8 | 2014-05-08 19:05:29 -0700 | [diff] [blame] | 272 | VLOG(profiler) << "Saving profile to " << full_name; |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 273 | |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 274 | int fd = open(full_name.c_str(), O_RDWR); |
| 275 | if (fd < 0) { |
| 276 | // Open failed. |
| 277 | LOG(ERROR) << "Failed to open profile file " << full_name; |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 278 | return 0; |
| 279 | } |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 280 | |
| 281 | // Lock the file for exclusive access. This will block if another process is using |
| 282 | // the file. |
| 283 | int err = flock(fd, LOCK_EX); |
| 284 | if (err < 0) { |
| 285 | LOG(ERROR) << "Failed to lock profile file " << full_name; |
| 286 | return 0; |
| 287 | } |
| 288 | |
| 289 | // Read the previous profile. |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 290 | profile_table_.ReadPrevious(fd, options_.GetProfileType()); |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 291 | |
| 292 | // Move back to the start of the file. |
| 293 | lseek(fd, 0, SEEK_SET); |
| 294 | |
| 295 | // Format the profile output and write to the file. |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 296 | std::ostringstream os; |
| 297 | uint32_t num_methods = DumpProfile(os); |
| 298 | std::string data(os.str()); |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 299 | const char *p = data.c_str(); |
| 300 | size_t length = data.length(); |
| 301 | size_t full_length = length; |
| 302 | do { |
| 303 | int n = ::write(fd, p, length); |
| 304 | p += n; |
| 305 | length -= n; |
| 306 | } while (length > 0); |
| 307 | |
| 308 | // Truncate the file to the new length. |
Elliott Hughes | 06f08e4 | 2015-05-12 21:25:36 -0700 | [diff] [blame] | 309 | if (ftruncate(fd, full_length) == -1) { |
| 310 | LOG(ERROR) << "Failed to truncate profile file " << full_name; |
| 311 | } |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 312 | |
| 313 | // Now unlock the file, allowing another process in. |
| 314 | err = flock(fd, LOCK_UN); |
| 315 | if (err < 0) { |
| 316 | LOG(ERROR) << "Failed to unlock profile file " << full_name; |
| 317 | } |
| 318 | |
| 319 | // Done, close the file. |
| 320 | ::close(fd); |
| 321 | |
| 322 | // Clean the profile for the next time. |
| 323 | CleanProfile(); |
| 324 | |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 325 | return num_methods; |
| 326 | } |
| 327 | |
Calin Juravle | c1b643c | 2014-05-30 23:44:11 +0100 | [diff] [blame] | 328 | bool BackgroundMethodSamplingProfiler::Start( |
| 329 | const std::string& output_filename, const ProfilerOptions& options) { |
| 330 | if (!options.IsEnabled()) { |
Calin Juravle | c1b643c | 2014-05-30 23:44:11 +0100 | [diff] [blame] | 331 | return false; |
| 332 | } |
| 333 | |
| 334 | CHECK(!output_filename.empty()); |
| 335 | |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 336 | Thread* self = Thread::Current(); |
| 337 | { |
| 338 | MutexLock mu(self, *Locks::profiler_lock_); |
| 339 | // Don't start two profiler threads. |
| 340 | if (profiler_ != nullptr) { |
Calin Juravle | c1b643c | 2014-05-30 23:44:11 +0100 | [diff] [blame] | 341 | return true; |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 342 | } |
| 343 | } |
| 344 | |
Calin Juravle | c1b643c | 2014-05-30 23:44:11 +0100 | [diff] [blame] | 345 | LOG(INFO) << "Starting profiler using output file: " << output_filename |
| 346 | << " and options: " << options; |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 347 | { |
| 348 | MutexLock mu(self, *Locks::profiler_lock_); |
Calin Juravle | c1b643c | 2014-05-30 23:44:11 +0100 | [diff] [blame] | 349 | profiler_ = new BackgroundMethodSamplingProfiler(output_filename, options); |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 350 | |
| 351 | CHECK_PTHREAD_CALL(pthread_create, (&profiler_pthread_, nullptr, &RunProfilerThread, |
| 352 | reinterpret_cast<void*>(profiler_)), |
| 353 | "Profiler thread"); |
| 354 | } |
Calin Juravle | c1b643c | 2014-05-30 23:44:11 +0100 | [diff] [blame] | 355 | return true; |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 356 | } |
| 357 | |
| 358 | |
| 359 | |
| 360 | void BackgroundMethodSamplingProfiler::Stop() { |
| 361 | BackgroundMethodSamplingProfiler* profiler = nullptr; |
| 362 | pthread_t profiler_pthread = 0U; |
| 363 | { |
| 364 | MutexLock trace_mu(Thread::Current(), *Locks::profiler_lock_); |
Wei Jin | 6a58691 | 2014-05-21 16:07:40 -0700 | [diff] [blame] | 365 | CHECK(!shutting_down_); |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 366 | profiler = profiler_; |
| 367 | shutting_down_ = true; |
| 368 | profiler_pthread = profiler_pthread_; |
| 369 | } |
| 370 | |
| 371 | // Now wake up the sampler thread if it sleeping. |
| 372 | { |
| 373 | MutexLock profile_mu(Thread::Current(), profiler->wait_lock_); |
| 374 | profiler->period_condition_.Signal(Thread::Current()); |
| 375 | } |
| 376 | // Wait for the sample thread to stop. |
| 377 | CHECK_PTHREAD_CALL(pthread_join, (profiler_pthread, nullptr), "profiler thread shutdown"); |
| 378 | |
| 379 | { |
| 380 | MutexLock mu(Thread::Current(), *Locks::profiler_lock_); |
| 381 | profiler_ = nullptr; |
| 382 | } |
| 383 | delete profiler; |
| 384 | } |
| 385 | |
| 386 | |
| 387 | void BackgroundMethodSamplingProfiler::Shutdown() { |
| 388 | Stop(); |
| 389 | } |
| 390 | |
Calin Juravle | c1b643c | 2014-05-30 23:44:11 +0100 | [diff] [blame] | 391 | BackgroundMethodSamplingProfiler::BackgroundMethodSamplingProfiler( |
| 392 | const std::string& output_filename, const ProfilerOptions& options) |
| 393 | : output_filename_(output_filename), |
| 394 | options_(options), |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 395 | wait_lock_("Profile wait lock"), |
| 396 | period_condition_("Profile condition", wait_lock_), |
| 397 | profile_table_(wait_lock_), |
| 398 | profiler_barrier_(new Barrier(0)) { |
| 399 | // Populate the filtered_methods set. |
| 400 | // This is empty right now, but to add a method, do this: |
| 401 | // |
| 402 | // filtered_methods_.insert("void java.lang.Object.wait(long, int)"); |
| 403 | } |
| 404 | |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 405 | // Filter out methods the profiler doesn't want to record. |
| 406 | // We require mutator lock since some statistics will be updated here. |
Mathieu Chartier | e401d14 | 2015-04-22 13:56:20 -0700 | [diff] [blame] | 407 | bool BackgroundMethodSamplingProfiler::ProcessMethod(ArtMethod* method) { |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 408 | if (method == nullptr) { |
| 409 | profile_table_.NullMethod(); |
Mathieu Chartier | 2cebb24 | 2015-04-21 16:50:40 -0700 | [diff] [blame] | 410 | // Don't record a null method. |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 411 | return false; |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 412 | } |
| 413 | |
| 414 | mirror::Class* cls = method->GetDeclaringClass(); |
| 415 | if (cls != nullptr) { |
| 416 | if (cls->GetClassLoader() == nullptr) { |
| 417 | // Don't include things in the boot |
| 418 | profile_table_.BootMethod(); |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 419 | return false; |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 420 | } |
| 421 | } |
| 422 | |
| 423 | bool is_filtered = false; |
| 424 | |
Mathieu Chartier | bfd9a43 | 2014-05-21 17:43:44 -0700 | [diff] [blame] | 425 | if (strcmp(method->GetName(), "<clinit>") == 0) { |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 426 | // always filter out class init |
| 427 | is_filtered = true; |
| 428 | } |
| 429 | |
| 430 | // Filter out methods by name if there are any. |
| 431 | if (!is_filtered && filtered_methods_.size() > 0) { |
| 432 | std::string method_full_name = PrettyMethod(method); |
| 433 | |
| 434 | // Don't include specific filtered methods. |
| 435 | is_filtered = filtered_methods_.count(method_full_name) != 0; |
| 436 | } |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 437 | return !is_filtered; |
| 438 | } |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 439 | |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 440 | // A method has been hit, record its invocation in the method map. |
| 441 | // The mutator_lock must be held (shared) when this is called. |
Mathieu Chartier | e401d14 | 2015-04-22 13:56:20 -0700 | [diff] [blame] | 442 | void BackgroundMethodSamplingProfiler::RecordMethod(ArtMethod* method) { |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 443 | // Add to the profile table unless it is filtered out. |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 444 | if (ProcessMethod(method)) { |
| 445 | profile_table_.Put(method); |
| 446 | } |
| 447 | } |
| 448 | |
| 449 | // Record the current bounded stack into sampling results. |
| 450 | void BackgroundMethodSamplingProfiler::RecordStack(const std::vector<InstructionLocation>& stack) { |
| 451 | if (stack.size() == 0) { |
| 452 | return; |
| 453 | } |
| 454 | // Get the method on top of the stack. We use this method to perform filtering. |
Mathieu Chartier | e401d14 | 2015-04-22 13:56:20 -0700 | [diff] [blame] | 455 | ArtMethod* method = stack.front().first; |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 456 | if (ProcessMethod(method)) { |
| 457 | profile_table_.PutStack(stack); |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 458 | } |
| 459 | } |
| 460 | |
| 461 | // Clean out any recordings for the method traces. |
| 462 | void BackgroundMethodSamplingProfiler::CleanProfile() { |
| 463 | profile_table_.Clear(); |
| 464 | } |
| 465 | |
| 466 | uint32_t BackgroundMethodSamplingProfiler::DumpProfile(std::ostream& os) { |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 467 | return profile_table_.Write(os, options_.GetProfileType()); |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 468 | } |
| 469 | |
| 470 | // Profile Table. |
Mathieu Chartier | e401d14 | 2015-04-22 13:56:20 -0700 | [diff] [blame] | 471 | // This holds a mapping of ArtMethod* to a count of how many times a sample |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 472 | // hit it at the top of the stack. |
Sebastien Hertz | aa50d3a | 2015-08-25 15:25:41 +0200 | [diff] [blame] | 473 | ProfileSampleResults::ProfileSampleResults(Mutex& lock) |
| 474 | : lock_(lock), |
| 475 | num_samples_(0U), |
| 476 | num_null_methods_(0U), |
| 477 | num_boot_methods_(0U), |
| 478 | previous_num_samples_(0U), |
| 479 | previous_num_null_methods_(0U), |
| 480 | previous_num_boot_methods_(0U) { |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 481 | for (int i = 0; i < kHashSize; i++) { |
| 482 | table[i] = nullptr; |
| 483 | } |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 484 | method_context_table = nullptr; |
| 485 | stack_trie_root_ = nullptr; |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 486 | } |
| 487 | |
| 488 | ProfileSampleResults::~ProfileSampleResults() { |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 489 | Clear(); |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 490 | } |
| 491 | |
Calin Juravle | bb0b53f | 2014-05-23 17:33:29 +0100 | [diff] [blame] | 492 | // 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] | 493 | // has been seen, add it with count=1, otherwise increment the count. |
Mathieu Chartier | e401d14 | 2015-04-22 13:56:20 -0700 | [diff] [blame] | 494 | void ProfileSampleResults::Put(ArtMethod* method) { |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 495 | MutexLock mu(Thread::Current(), lock_); |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 496 | uint32_t index = Hash(method); |
| 497 | if (table[index] == nullptr) { |
| 498 | table[index] = new Map(); |
| 499 | } |
| 500 | Map::iterator i = table[index]->find(method); |
| 501 | if (i == table[index]->end()) { |
| 502 | (*table[index])[method] = 1; |
| 503 | } else { |
| 504 | i->second++; |
| 505 | } |
| 506 | num_samples_++; |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 507 | } |
| 508 | |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 509 | // Add a bounded stack to the profile table. Only the count of the method on |
| 510 | // top of the frame will be increased. |
| 511 | void ProfileSampleResults::PutStack(const std::vector<InstructionLocation>& stack) { |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 512 | MutexLock mu(Thread::Current(), lock_); |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 513 | ScopedObjectAccess soa(Thread::Current()); |
| 514 | if (stack_trie_root_ == nullptr) { |
| 515 | // The root of the stack trie is a dummy node so that we don't have to maintain |
| 516 | // a collection of tries. |
| 517 | stack_trie_root_ = new StackTrieNode(); |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 518 | } |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 519 | |
| 520 | StackTrieNode* current = stack_trie_root_; |
| 521 | if (stack.size() == 0) { |
| 522 | current->IncreaseCount(); |
| 523 | return; |
| 524 | } |
| 525 | |
| 526 | for (std::vector<InstructionLocation>::const_reverse_iterator iter = stack.rbegin(); |
| 527 | iter != stack.rend(); ++iter) { |
| 528 | InstructionLocation inst_loc = *iter; |
Mathieu Chartier | e401d14 | 2015-04-22 13:56:20 -0700 | [diff] [blame] | 529 | ArtMethod* method = inst_loc.first; |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 530 | if (method == nullptr) { |
| 531 | // skip null method |
| 532 | continue; |
| 533 | } |
| 534 | uint32_t dex_pc = inst_loc.second; |
| 535 | uint32_t method_idx = method->GetDexMethodIndex(); |
| 536 | const DexFile* dex_file = method->GetDeclaringClass()->GetDexCache()->GetDexFile(); |
| 537 | MethodReference method_ref(dex_file, method_idx); |
| 538 | StackTrieNode* child = current->FindChild(method_ref, dex_pc); |
| 539 | if (child != nullptr) { |
| 540 | current = child; |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 541 | } else { |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 542 | uint32_t method_size = 0; |
| 543 | const DexFile::CodeItem* codeitem = method->GetCodeItem(); |
| 544 | if (codeitem != nullptr) { |
| 545 | method_size = codeitem->insns_size_in_code_units_; |
| 546 | } |
| 547 | StackTrieNode* new_node = new StackTrieNode(method_ref, dex_pc, method_size, current); |
| 548 | current->AppendChild(new_node); |
| 549 | current = new_node; |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 550 | } |
| 551 | } |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 552 | |
| 553 | if (current != stack_trie_root_ && current->GetCount() == 0) { |
| 554 | // Insert into method_context table; |
| 555 | if (method_context_table == nullptr) { |
| 556 | method_context_table = new MethodContextMap(); |
| 557 | } |
| 558 | MethodReference method = current->GetMethod(); |
| 559 | MethodContextMap::iterator i = method_context_table->find(method); |
| 560 | if (i == method_context_table->end()) { |
| 561 | TrieNodeSet* node_set = new TrieNodeSet(); |
| 562 | node_set->insert(current); |
| 563 | (*method_context_table)[method] = node_set; |
| 564 | } else { |
| 565 | TrieNodeSet* node_set = i->second; |
| 566 | node_set->insert(current); |
| 567 | } |
| 568 | } |
| 569 | current->IncreaseCount(); |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 570 | num_samples_++; |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 571 | } |
| 572 | |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 573 | // Write the profile table to the output stream. Also merge with the previous profile. |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 574 | uint32_t ProfileSampleResults::Write(std::ostream& os, ProfileDataType type) { |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 575 | ScopedObjectAccess soa(Thread::Current()); |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 576 | num_samples_ += previous_num_samples_; |
| 577 | num_null_methods_ += previous_num_null_methods_; |
| 578 | num_boot_methods_ += previous_num_boot_methods_; |
| 579 | |
Calin Juravle | c1b643c | 2014-05-30 23:44:11 +0100 | [diff] [blame] | 580 | VLOG(profiler) << "Profile: " |
| 581 | << num_samples_ << "/" << num_null_methods_ << "/" << num_boot_methods_; |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 582 | os << num_samples_ << "/" << num_null_methods_ << "/" << num_boot_methods_ << "\n"; |
| 583 | uint32_t num_methods = 0; |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 584 | if (type == kProfilerMethod) { |
| 585 | for (int i = 0 ; i < kHashSize; i++) { |
| 586 | Map *map = table[i]; |
| 587 | if (map != nullptr) { |
| 588 | for (const auto &meth_iter : *map) { |
Mathieu Chartier | e401d14 | 2015-04-22 13:56:20 -0700 | [diff] [blame] | 589 | ArtMethod *method = meth_iter.first; |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 590 | std::string method_name = PrettyMethod(method); |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 591 | |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 592 | const DexFile::CodeItem* codeitem = method->GetCodeItem(); |
| 593 | uint32_t method_size = 0; |
| 594 | if (codeitem != nullptr) { |
| 595 | method_size = codeitem->insns_size_in_code_units_; |
| 596 | } |
| 597 | uint32_t count = meth_iter.second; |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 598 | |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 599 | // Merge this profile entry with one from a previous run (if present). Also |
| 600 | // remove the previous entry. |
| 601 | PreviousProfile::iterator pi = previous_.find(method_name); |
| 602 | if (pi != previous_.end()) { |
| 603 | count += pi->second.count_; |
| 604 | previous_.erase(pi); |
| 605 | } |
| 606 | os << StringPrintf("%s/%u/%u\n", method_name.c_str(), count, method_size); |
| 607 | ++num_methods; |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 608 | } |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 609 | } |
| 610 | } |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 611 | } else if (type == kProfilerBoundedStack) { |
| 612 | if (method_context_table != nullptr) { |
| 613 | for (const auto &method_iter : *method_context_table) { |
| 614 | MethodReference method = method_iter.first; |
| 615 | TrieNodeSet* node_set = method_iter.second; |
| 616 | std::string method_name = PrettyMethod(method.dex_method_index, *(method.dex_file)); |
| 617 | uint32_t method_size = 0; |
| 618 | uint32_t total_count = 0; |
| 619 | PreviousContextMap new_context_map; |
| 620 | for (const auto &trie_node_i : *node_set) { |
| 621 | StackTrieNode* node = trie_node_i; |
| 622 | method_size = node->GetMethodSize(); |
| 623 | uint32_t count = node->GetCount(); |
| 624 | uint32_t dexpc = node->GetDexPC(); |
| 625 | total_count += count; |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 626 | |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 627 | StackTrieNode* current = node->GetParent(); |
| 628 | // We go backward on the trie to retrieve context and dex_pc until the dummy root. |
| 629 | // The format of the context is "method_1@pc_1@method_2@pc_2@..." |
| 630 | std::vector<std::string> context_vector; |
| 631 | while (current != nullptr && current->GetParent() != nullptr) { |
| 632 | context_vector.push_back(StringPrintf("%s@%u", |
| 633 | PrettyMethod(current->GetMethod().dex_method_index, *(current->GetMethod().dex_file)).c_str(), |
| 634 | current->GetDexPC())); |
| 635 | current = current->GetParent(); |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 636 | } |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 637 | std::string context_sig = Join(context_vector, '@'); |
| 638 | new_context_map[std::make_pair(dexpc, context_sig)] = count; |
| 639 | } |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 640 | |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 641 | PreviousProfile::iterator pi = previous_.find(method_name); |
| 642 | if (pi != previous_.end()) { |
| 643 | total_count += pi->second.count_; |
| 644 | PreviousContextMap* previous_context_map = pi->second.context_map_; |
| 645 | if (previous_context_map != nullptr) { |
| 646 | for (const auto &context_i : *previous_context_map) { |
| 647 | uint32_t count = context_i.second; |
| 648 | PreviousContextMap::iterator ci = new_context_map.find(context_i.first); |
| 649 | if (ci == new_context_map.end()) { |
| 650 | new_context_map[context_i.first] = count; |
| 651 | } else { |
| 652 | ci->second += count; |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 653 | } |
| 654 | } |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 655 | } |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 656 | delete previous_context_map; |
| 657 | previous_.erase(pi); |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 658 | } |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 659 | // We write out profile data with dex pc and context information in the following format: |
| 660 | // "method/total_count/size/[pc_1:count_1:context_1#pc_2:count_2:context_2#...]". |
| 661 | std::vector<std::string> context_count_vector; |
| 662 | for (const auto &context_i : new_context_map) { |
| 663 | context_count_vector.push_back(StringPrintf("%u:%u:%s", context_i.first.first, |
| 664 | context_i.second, context_i.first.second.c_str())); |
| 665 | } |
| 666 | os << StringPrintf("%s/%u/%u/[%s]\n", method_name.c_str(), total_count, |
| 667 | method_size, Join(context_count_vector, '#').c_str()); |
| 668 | ++num_methods; |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 669 | } |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 670 | } |
| 671 | } |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 672 | |
| 673 | // Now we write out the remaining previous methods. |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 674 | for (const auto &pi : previous_) { |
| 675 | if (type == kProfilerMethod) { |
| 676 | os << StringPrintf("%s/%u/%u\n", pi.first.c_str(), pi.second.count_, pi.second.method_size_); |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 677 | } else if (type == kProfilerBoundedStack) { |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 678 | os << StringPrintf("%s/%u/%u/[", pi.first.c_str(), pi.second.count_, pi.second.method_size_); |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 679 | PreviousContextMap* previous_context_map = pi.second.context_map_; |
| 680 | if (previous_context_map != nullptr) { |
| 681 | std::vector<std::string> context_count_vector; |
| 682 | for (const auto &context_i : *previous_context_map) { |
| 683 | context_count_vector.push_back(StringPrintf("%u:%u:%s", context_i.first.first, |
| 684 | context_i.second, context_i.first.second.c_str())); |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 685 | } |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 686 | os << Join(context_count_vector, '#'); |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 687 | } |
| 688 | os << "]\n"; |
| 689 | } |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 690 | ++num_methods; |
| 691 | } |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 692 | return num_methods; |
| 693 | } |
| 694 | |
| 695 | void ProfileSampleResults::Clear() { |
| 696 | num_samples_ = 0; |
| 697 | num_null_methods_ = 0; |
| 698 | num_boot_methods_ = 0; |
| 699 | for (int i = 0; i < kHashSize; i++) { |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 700 | delete table[i]; |
| 701 | table[i] = nullptr; |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 702 | } |
| 703 | if (stack_trie_root_ != nullptr) { |
| 704 | stack_trie_root_->DeleteChildren(); |
| 705 | delete stack_trie_root_; |
| 706 | stack_trie_root_ = nullptr; |
| 707 | if (method_context_table != nullptr) { |
| 708 | delete method_context_table; |
| 709 | method_context_table = nullptr; |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 710 | } |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 711 | } |
| 712 | for (auto &pi : previous_) { |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 713 | if (pi.second.context_map_ != nullptr) { |
| 714 | delete pi.second.context_map_; |
| 715 | pi.second.context_map_ = nullptr; |
| 716 | } |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 717 | } |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 718 | previous_.clear(); |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 719 | } |
| 720 | |
Mathieu Chartier | e401d14 | 2015-04-22 13:56:20 -0700 | [diff] [blame] | 721 | uint32_t ProfileSampleResults::Hash(ArtMethod* method) { |
Ian Rogers | ef7d42f | 2014-01-06 12:55:46 -0800 | [diff] [blame] | 722 | return (PointerToLowMemUInt32(method) >> 3) % kHashSize; |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 723 | } |
| 724 | |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 725 | // Read a single line into the given string. Returns true if everything OK, false |
| 726 | // on EOF or error. |
| 727 | static bool ReadProfileLine(int fd, std::string& line) { |
| 728 | char buf[4]; |
| 729 | line.clear(); |
| 730 | while (true) { |
| 731 | int n = read(fd, buf, 1); // TODO: could speed this up but is it worth it? |
| 732 | if (n != 1) { |
| 733 | return false; |
| 734 | } |
| 735 | if (buf[0] == '\n') { |
| 736 | break; |
| 737 | } |
| 738 | line += buf[0]; |
| 739 | } |
| 740 | return true; |
| 741 | } |
| 742 | |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 743 | void ProfileSampleResults::ReadPrevious(int fd, ProfileDataType type) { |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 744 | // Reset counters. |
| 745 | previous_num_samples_ = previous_num_null_methods_ = previous_num_boot_methods_ = 0; |
| 746 | |
| 747 | std::string line; |
| 748 | |
| 749 | // The first line contains summary information. |
| 750 | if (!ReadProfileLine(fd, line)) { |
| 751 | return; |
| 752 | } |
| 753 | std::vector<std::string> summary_info; |
Ian Rogers | 6f3dbba | 2014-10-14 17:41:57 -0700 | [diff] [blame] | 754 | Split(line, '/', &summary_info); |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 755 | if (summary_info.size() != 3) { |
| 756 | // Bad summary info. It should be count/nullcount/bootcount |
| 757 | return; |
| 758 | } |
Wei Jin | f21f0a9 | 2014-06-27 17:44:18 -0700 | [diff] [blame] | 759 | previous_num_samples_ = strtoul(summary_info[0].c_str(), nullptr, 10); |
| 760 | previous_num_null_methods_ = strtoul(summary_info[1].c_str(), nullptr, 10); |
| 761 | previous_num_boot_methods_ = strtoul(summary_info[2].c_str(), nullptr, 10); |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 762 | |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 763 | // Now read each line until the end of file. Each line consists of 3 or 4 fields separated by / |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 764 | while (true) { |
| 765 | if (!ReadProfileLine(fd, line)) { |
| 766 | break; |
| 767 | } |
| 768 | std::vector<std::string> info; |
Ian Rogers | 6f3dbba | 2014-10-14 17:41:57 -0700 | [diff] [blame] | 769 | Split(line, '/', &info); |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 770 | if (info.size() != 3 && info.size() != 4) { |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 771 | // Malformed. |
| 772 | break; |
| 773 | } |
| 774 | std::string methodname = info[0]; |
Wei Jin | f21f0a9 | 2014-06-27 17:44:18 -0700 | [diff] [blame] | 775 | uint32_t total_count = strtoul(info[1].c_str(), nullptr, 10); |
| 776 | uint32_t size = strtoul(info[2].c_str(), nullptr, 10); |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 777 | PreviousContextMap* context_map = nullptr; |
| 778 | if (type == kProfilerBoundedStack && info.size() == 4) { |
| 779 | context_map = new PreviousContextMap(); |
| 780 | std::string context_counts_str = info[3].substr(1, info[3].size() - 2); |
| 781 | std::vector<std::string> context_count_pairs; |
Ian Rogers | 6f3dbba | 2014-10-14 17:41:57 -0700 | [diff] [blame] | 782 | Split(context_counts_str, '#', &context_count_pairs); |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 783 | for (uint32_t i = 0; i < context_count_pairs.size(); ++i) { |
| 784 | std::vector<std::string> context_count; |
Ian Rogers | 6f3dbba | 2014-10-14 17:41:57 -0700 | [diff] [blame] | 785 | Split(context_count_pairs[i], ':', &context_count); |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 786 | if (context_count.size() == 2) { |
| 787 | // Handles the situtation when the profile file doesn't contain context information. |
Wei Jin | f21f0a9 | 2014-06-27 17:44:18 -0700 | [diff] [blame] | 788 | uint32_t dexpc = strtoul(context_count[0].c_str(), nullptr, 10); |
| 789 | uint32_t count = strtoul(context_count[1].c_str(), nullptr, 10); |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 790 | (*context_map)[std::make_pair(dexpc, "")] = count; |
| 791 | } else { |
| 792 | // Handles the situtation when the profile file contains context information. |
Wei Jin | f21f0a9 | 2014-06-27 17:44:18 -0700 | [diff] [blame] | 793 | uint32_t dexpc = strtoul(context_count[0].c_str(), nullptr, 10); |
| 794 | uint32_t count = strtoul(context_count[1].c_str(), nullptr, 10); |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 795 | std::string context = context_count[2]; |
| 796 | (*context_map)[std::make_pair(dexpc, context)] = count; |
| 797 | } |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 798 | } |
| 799 | } |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 800 | previous_[methodname] = PreviousValue(total_count, size, context_map); |
Dave Allison | 39c3bfb | 2014-01-28 18:33:52 -0800 | [diff] [blame] | 801 | } |
| 802 | } |
Dave Allison | 0aded08 | 2013-11-07 13:15:11 -0800 | [diff] [blame] | 803 | |
Calin Juravle | bb0b53f | 2014-05-23 17:33:29 +0100 | [diff] [blame] | 804 | bool ProfileFile::LoadFile(const std::string& fileName) { |
Calin Juravle | 9dae5b4 | 2014-04-07 16:36:21 +0300 | [diff] [blame] | 805 | LOG(VERBOSE) << "reading profile file " << fileName; |
| 806 | struct stat st; |
| 807 | int err = stat(fileName.c_str(), &st); |
| 808 | if (err == -1) { |
| 809 | LOG(VERBOSE) << "not found"; |
| 810 | return false; |
| 811 | } |
| 812 | if (st.st_size == 0) { |
Dave Allison | 644789f | 2014-04-10 13:06:10 -0700 | [diff] [blame] | 813 | return false; // Empty profiles are invalid. |
Calin Juravle | 9dae5b4 | 2014-04-07 16:36:21 +0300 | [diff] [blame] | 814 | } |
| 815 | std::ifstream in(fileName.c_str()); |
| 816 | if (!in) { |
| 817 | LOG(VERBOSE) << "profile file " << fileName << " exists but can't be opened"; |
| 818 | LOG(VERBOSE) << "file owner: " << st.st_uid << ":" << st.st_gid; |
| 819 | LOG(VERBOSE) << "me: " << getuid() << ":" << getgid(); |
| 820 | LOG(VERBOSE) << "file permissions: " << std::oct << st.st_mode; |
| 821 | LOG(VERBOSE) << "errno: " << errno; |
| 822 | return false; |
| 823 | } |
| 824 | // The first line contains summary information. |
| 825 | std::string line; |
| 826 | std::getline(in, line); |
| 827 | if (in.eof()) { |
| 828 | return false; |
| 829 | } |
| 830 | std::vector<std::string> summary_info; |
Ian Rogers | 6f3dbba | 2014-10-14 17:41:57 -0700 | [diff] [blame] | 831 | Split(line, '/', &summary_info); |
Calin Juravle | 9dae5b4 | 2014-04-07 16:36:21 +0300 | [diff] [blame] | 832 | if (summary_info.size() != 3) { |
Calin Juravle | 19477a8 | 2014-06-06 12:24:21 +0100 | [diff] [blame] | 833 | // Bad summary info. It should be total/null/boot. |
Calin Juravle | 9dae5b4 | 2014-04-07 16:36:21 +0300 | [diff] [blame] | 834 | return false; |
| 835 | } |
Mathieu Chartier | 2cebb24 | 2015-04-21 16:50:40 -0700 | [diff] [blame] | 836 | // This is the number of hits in all profiled methods (without null or boot methods) |
Wei Jin | f21f0a9 | 2014-06-27 17:44:18 -0700 | [diff] [blame] | 837 | uint32_t total_count = strtoul(summary_info[0].c_str(), nullptr, 10); |
Calin Juravle | 9dae5b4 | 2014-04-07 16:36:21 +0300 | [diff] [blame] | 838 | |
| 839 | // Now read each line until the end of file. Each line consists of 3 fields separated by '/'. |
| 840 | // Store the info in descending order given by the most used methods. |
| 841 | typedef std::set<std::pair<int, std::vector<std::string>>> ProfileSet; |
| 842 | ProfileSet countSet; |
| 843 | while (!in.eof()) { |
| 844 | std::getline(in, line); |
| 845 | if (in.eof()) { |
| 846 | break; |
| 847 | } |
| 848 | std::vector<std::string> info; |
Ian Rogers | 6f3dbba | 2014-10-14 17:41:57 -0700 | [diff] [blame] | 849 | Split(line, '/', &info); |
Wei Jin | a93b0bb | 2014-06-09 16:19:15 -0700 | [diff] [blame] | 850 | if (info.size() != 3 && info.size() != 4) { |
Calin Juravle | 9dae5b4 | 2014-04-07 16:36:21 +0300 | [diff] [blame] | 851 | // Malformed. |
Calin Juravle | bb0b53f | 2014-05-23 17:33:29 +0100 | [diff] [blame] | 852 | return false; |
Calin Juravle | 9dae5b4 | 2014-04-07 16:36:21 +0300 | [diff] [blame] | 853 | } |
| 854 | int count = atoi(info[1].c_str()); |
| 855 | countSet.insert(std::make_pair(-count, info)); |
| 856 | } |
| 857 | |
| 858 | uint32_t curTotalCount = 0; |
| 859 | ProfileSet::iterator end = countSet.end(); |
| 860 | const ProfileData* prevData = nullptr; |
| 861 | for (ProfileSet::iterator it = countSet.begin(); it != end ; it++) { |
| 862 | const std::string& methodname = it->second[0]; |
| 863 | uint32_t count = -it->first; |
Wei Jin | f21f0a9 | 2014-06-27 17:44:18 -0700 | [diff] [blame] | 864 | uint32_t size = strtoul(it->second[2].c_str(), nullptr, 10); |
Calin Juravle | 9dae5b4 | 2014-04-07 16:36:21 +0300 | [diff] [blame] | 865 | double usedPercent = (count * 100.0) / total_count; |
| 866 | |
| 867 | curTotalCount += count; |
| 868 | // Methods with the same count should be part of the same top K percentage bucket. |
| 869 | double topKPercentage = (prevData != nullptr) && (prevData->GetCount() == count) |
| 870 | ? prevData->GetTopKUsedPercentage() |
| 871 | : 100 * static_cast<double>(curTotalCount) / static_cast<double>(total_count); |
| 872 | |
| 873 | // Add it to the profile map. |
| 874 | ProfileData curData = ProfileData(methodname, count, size, usedPercent, topKPercentage); |
Calin Juravle | bb0b53f | 2014-05-23 17:33:29 +0100 | [diff] [blame] | 875 | profile_map_[methodname] = curData; |
Calin Juravle | 9dae5b4 | 2014-04-07 16:36:21 +0300 | [diff] [blame] | 876 | prevData = &curData; |
| 877 | } |
| 878 | return true; |
| 879 | } |
| 880 | |
Calin Juravle | bb0b53f | 2014-05-23 17:33:29 +0100 | [diff] [blame] | 881 | bool ProfileFile::GetProfileData(ProfileFile::ProfileData* data, const std::string& method_name) { |
| 882 | ProfileMap::iterator i = profile_map_.find(method_name); |
| 883 | if (i == profile_map_.end()) { |
Calin Juravle | 9dae5b4 | 2014-04-07 16:36:21 +0300 | [diff] [blame] | 884 | return false; |
| 885 | } |
Calin Juravle | bb0b53f | 2014-05-23 17:33:29 +0100 | [diff] [blame] | 886 | *data = i->second; |
| 887 | return true; |
| 888 | } |
| 889 | |
| 890 | bool ProfileFile::GetTopKSamples(std::set<std::string>& topKSamples, double topKPercentage) { |
| 891 | ProfileMap::iterator end = profile_map_.end(); |
| 892 | for (ProfileMap::iterator it = profile_map_.begin(); it != end; it++) { |
Calin Juravle | 9dae5b4 | 2014-04-07 16:36:21 +0300 | [diff] [blame] | 893 | if (it->second.GetTopKUsedPercentage() < topKPercentage) { |
| 894 | topKSamples.insert(it->first); |
| 895 | } |
| 896 | } |
| 897 | return true; |
| 898 | } |
| 899 | |
Wei Jin | 445220d | 2014-06-20 15:56:53 -0700 | [diff] [blame] | 900 | StackTrieNode* StackTrieNode::FindChild(MethodReference method, uint32_t dex_pc) { |
| 901 | if (children_.size() == 0) { |
| 902 | return nullptr; |
| 903 | } |
| 904 | // Create a dummy node for searching. |
| 905 | StackTrieNode* node = new StackTrieNode(method, dex_pc, 0, nullptr); |
| 906 | std::set<StackTrieNode*, StackTrieNodeComparator>::iterator i = children_.find(node); |
| 907 | delete node; |
| 908 | return (i == children_.end()) ? nullptr : *i; |
| 909 | } |
| 910 | |
| 911 | void StackTrieNode::DeleteChildren() { |
| 912 | for (auto &child : children_) { |
| 913 | if (child != nullptr) { |
| 914 | child->DeleteChildren(); |
| 915 | delete child; |
| 916 | } |
| 917 | } |
| 918 | } |
| 919 | |
Calin Juravle | 9dae5b4 | 2014-04-07 16:36:21 +0300 | [diff] [blame] | 920 | } // namespace art |