blob: db372c3277d3eee65e3bef6d17e52e242241db2c [file] [log] [blame]
Dave Allison0aded082013-11-07 13:15:11 -08001/*
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 Allison39c3bfb2014-01-28 18:33:52 -080019#include <sys/file.h>
Ian Rogers6f3dbba2014-10-14 17:41:57 -070020#include <sys/stat.h>
21#include <sys/uio.h>
22
23#include <fstream>
Dave Allison0aded082013-11-07 13:15:11 -080024
25#include "base/stl_util.h"
26#include "base/unix_file/fd_file.h"
27#include "class_linker.h"
28#include "common_throws.h"
29#include "debugger.h"
30#include "dex_file-inl.h"
31#include "instrumentation.h"
32#include "mirror/art_method-inl.h"
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 Allison0aded082013-11-07 13:15:11 -080037#include "os.h"
38#include "scoped_thread_state_change.h"
39#include "ScopedLocalRef.h"
40#include "thread.h"
41#include "thread_list.h"
Dave Allison4a7867b2014-01-30 17:44:12 -080042
Dave Allison0aded082013-11-07 13:15:11 -080043#include "entrypoints/quick/quick_entrypoints.h"
Dave Allison0aded082013-11-07 13:15:11 -080044
45namespace art {
46
47BackgroundMethodSamplingProfiler* BackgroundMethodSamplingProfiler::profiler_ = nullptr;
48pthread_t BackgroundMethodSamplingProfiler::profiler_pthread_ = 0U;
49volatile bool BackgroundMethodSamplingProfiler::shutting_down_ = false;
50
Dave Allison0aded082013-11-07 13:15:11 -080051// TODO: this profiler runs regardless of the state of the machine. Maybe we should use the
52// wakelock or something to modify the run characteristics. This can be done when we
53// have some performance data after it's been used for a while.
54
Wei Jin445220d2014-06-20 15:56:53 -070055// Walk through the method within depth of max_depth_ on the Java stack
56class BoundedStackVisitor : public StackVisitor {
57 public:
58 BoundedStackVisitor(std::vector<std::pair<mirror::ArtMethod*, uint32_t>>* stack,
59 Thread* thread, uint32_t max_depth)
60 SHARED_LOCKS_REQUIRED(Locks::mutator_lock_)
61 : StackVisitor(thread, NULL), stack_(stack), max_depth_(max_depth), depth_(0) {
62 }
63
64 bool VisitFrame() SHARED_LOCKS_REQUIRED(Locks::mutator_lock_) {
65 mirror::ArtMethod* m = GetMethod();
66 if (m->IsRuntimeMethod()) {
67 return true;
68 }
69 uint32_t dex_pc_ = GetDexPc();
70 stack_->push_back(std::make_pair(m, dex_pc_));
71 ++depth_;
72 if (depth_ < max_depth_) {
73 return true;
74 } else {
75 return false;
76 }
77 }
78
79 private:
80 std::vector<std::pair<mirror::ArtMethod*, uint32_t>>* stack_;
81 const uint32_t max_depth_;
82 uint32_t depth_;
83};
Dave Allison0aded082013-11-07 13:15:11 -080084
85// This is called from either a thread list traversal or from a checkpoint. Regardless
86// of which caller, the mutator lock must be held.
87static void GetSample(Thread* thread, void* arg) SHARED_LOCKS_REQUIRED(Locks::mutator_lock_) {
88 BackgroundMethodSamplingProfiler* profiler =
89 reinterpret_cast<BackgroundMethodSamplingProfiler*>(arg);
Wei Jin445220d2014-06-20 15:56:53 -070090 const ProfilerOptions profile_options = profiler->GetProfilerOptions();
91 switch (profile_options.GetProfileType()) {
92 case kProfilerMethod: {
93 mirror::ArtMethod* method = thread->GetCurrentMethod(nullptr);
Ian Rogerscf7f1912014-10-22 22:06:39 -070094 if ((false) && method == nullptr) {
Wei Jin445220d2014-06-20 15:56:53 -070095 LOG(INFO) << "No current method available";
96 std::ostringstream os;
97 thread->Dump(os);
98 std::string data(os.str());
99 LOG(INFO) << data;
100 }
101 profiler->RecordMethod(method);
102 break;
103 }
104 case kProfilerBoundedStack: {
105 std::vector<InstructionLocation> stack;
106 uint32_t max_depth = profile_options.GetMaxStackDepth();
107 BoundedStackVisitor bounded_stack_visitor(&stack, thread, max_depth);
108 bounded_stack_visitor.WalkStack();
109 profiler->RecordStack(stack);
110 break;
111 }
112 default:
113 LOG(INFO) << "This profile type is not implemented.";
Dave Allison0aded082013-11-07 13:15:11 -0800114 }
Dave Allison0aded082013-11-07 13:15:11 -0800115}
116
Dave Allison0aded082013-11-07 13:15:11 -0800117// A closure that is called by the thread checkpoint code.
Ian Rogers7b078e82014-09-10 14:44:24 -0700118class SampleCheckpoint FINAL : public Closure {
Dave Allison0aded082013-11-07 13:15:11 -0800119 public:
120 explicit SampleCheckpoint(BackgroundMethodSamplingProfiler* const profiler) :
121 profiler_(profiler) {}
122
Ian Rogers7b078e82014-09-10 14:44:24 -0700123 void Run(Thread* thread) OVERRIDE {
Dave Allison0aded082013-11-07 13:15:11 -0800124 Thread* self = Thread::Current();
125 if (thread == nullptr) {
126 LOG(ERROR) << "Checkpoint with nullptr thread";
127 return;
128 }
129
130 // Grab the mutator lock (shared access).
131 ScopedObjectAccess soa(self);
132
133 // Grab a sample.
134 GetSample(thread, this->profiler_);
135
136 // And finally tell the barrier that we're done.
137 this->profiler_->GetBarrier().Pass(self);
138 }
139
140 private:
141 BackgroundMethodSamplingProfiler* const profiler_;
142};
143
144bool BackgroundMethodSamplingProfiler::ShuttingDown(Thread* self) {
145 MutexLock mu(self, *Locks::profiler_lock_);
146 return shutting_down_;
147}
148
149void* BackgroundMethodSamplingProfiler::RunProfilerThread(void* arg) {
150 Runtime* runtime = Runtime::Current();
151 BackgroundMethodSamplingProfiler* profiler =
152 reinterpret_cast<BackgroundMethodSamplingProfiler*>(arg);
153
154 // Add a random delay for the first time run so that we don't hammer the CPU
155 // with all profiles running at the same time.
156 const int kRandomDelayMaxSecs = 30;
157 const double kMaxBackoffSecs = 24*60*60; // Max backoff time.
158
159 srand(MicroTime() * getpid());
160 int startup_delay = rand() % kRandomDelayMaxSecs; // random delay for startup.
161
162
163 CHECK(runtime->AttachCurrentThread("Profiler", true, runtime->GetSystemThreadGroup(),
Mathieu Chartiere5f13e52015-02-24 09:37:21 -0800164 !runtime->IsAotCompiler()));
Dave Allison0aded082013-11-07 13:15:11 -0800165
166 Thread* self = Thread::Current();
167
Calin Juravlec1b643c2014-05-30 23:44:11 +0100168 double backoff = 1.0;
Dave Allison0aded082013-11-07 13:15:11 -0800169 while (true) {
170 if (ShuttingDown(self)) {
171 break;
172 }
173
174 {
175 // wait until we need to run another profile
Calin Juravlec1b643c2014-05-30 23:44:11 +0100176 uint64_t delay_secs = profiler->options_.GetPeriodS() * backoff;
Dave Allison0aded082013-11-07 13:15:11 -0800177
178 // Add a startup delay to prevent all the profiles running at once.
179 delay_secs += startup_delay;
180
181 // Immediate startup for benchmarking?
Calin Juravlec1b643c2014-05-30 23:44:11 +0100182 if (profiler->options_.GetStartImmediately() && startup_delay > 0) {
Dave Allison0aded082013-11-07 13:15:11 -0800183 delay_secs = 0;
184 }
185
186 startup_delay = 0;
187
Brian Carlstrom4d466a82014-05-08 19:05:29 -0700188 VLOG(profiler) << "Delaying profile start for " << delay_secs << " secs";
Dave Allison0aded082013-11-07 13:15:11 -0800189 MutexLock mu(self, profiler->wait_lock_);
190 profiler->period_condition_.TimedWait(self, delay_secs * 1000, 0);
Ian Rogers7b078e82014-09-10 14:44:24 -0700191 // We were either signaled by Stop or timedout, in either case ignore the timed out result.
Dave Allison0aded082013-11-07 13:15:11 -0800192
193 // Expand the backoff by its coefficient, but don't go beyond the max.
Calin Juravlec1b643c2014-05-30 23:44:11 +0100194 backoff = std::min(backoff * profiler->options_.GetBackoffCoefficient(), kMaxBackoffSecs);
Dave Allison0aded082013-11-07 13:15:11 -0800195 }
196
197 if (ShuttingDown(self)) {
198 break;
199 }
200
201
202 uint64_t start_us = MicroTime();
Calin Juravlec1b643c2014-05-30 23:44:11 +0100203 uint64_t end_us = start_us + profiler->options_.GetDurationS() * UINT64_C(1000000);
Dave Allison0aded082013-11-07 13:15:11 -0800204 uint64_t now_us = start_us;
205
Calin Juravlec1b643c2014-05-30 23:44:11 +0100206 VLOG(profiler) << "Starting profiling run now for "
207 << PrettyDuration((end_us - start_us) * 1000);
Dave Allison0aded082013-11-07 13:15:11 -0800208
209 SampleCheckpoint check_point(profiler);
210
Dave Allison39c3bfb2014-01-28 18:33:52 -0800211 size_t valid_samples = 0;
Dave Allison0aded082013-11-07 13:15:11 -0800212 while (now_us < end_us) {
213 if (ShuttingDown(self)) {
214 break;
215 }
216
Calin Juravlec1b643c2014-05-30 23:44:11 +0100217 usleep(profiler->options_.GetIntervalUs()); // Non-interruptible sleep.
Dave Allison0aded082013-11-07 13:15:11 -0800218
219 ThreadList* thread_list = runtime->GetThreadList();
220
221 profiler->profiler_barrier_->Init(self, 0);
Dave Allison39c3bfb2014-01-28 18:33:52 -0800222 size_t barrier_count = thread_list->RunCheckpointOnRunnableThreads(&check_point);
223
224 // All threads are suspended, nothing to do.
225 if (barrier_count == 0) {
226 now_us = MicroTime();
227 continue;
228 }
229
230 valid_samples += barrier_count;
Dave Allison0aded082013-11-07 13:15:11 -0800231
Wei Jin6a586912014-05-21 16:07:40 -0700232 ScopedThreadStateChange tsc(self, kWaitingForCheckPointsToRun);
Dave Allison0aded082013-11-07 13:15:11 -0800233
234 // Wait for the barrier to be crossed by all runnable threads. This wait
235 // is done with a timeout so that we can detect problems with the checkpoint
236 // running code. We should never see this.
237 const uint32_t kWaitTimeoutMs = 10000;
Dave Allison0aded082013-11-07 13:15:11 -0800238
Dave Allison0aded082013-11-07 13:15:11 -0800239 // Wait for all threads to pass the barrier.
Ian Rogers7b078e82014-09-10 14:44:24 -0700240 bool timed_out = profiler->profiler_barrier_->Increment(self, barrier_count, kWaitTimeoutMs);
Dave Allison0aded082013-11-07 13:15:11 -0800241
242 // We should never get a timeout. If we do, it suggests a problem with the checkpoint
243 // code. Crash the process in this case.
Ian Rogers7b078e82014-09-10 14:44:24 -0700244 CHECK(!timed_out);
Dave Allison0aded082013-11-07 13:15:11 -0800245
Dave Allison0aded082013-11-07 13:15:11 -0800246 // Update the current time.
247 now_us = MicroTime();
248 }
249
Wei Jin6a586912014-05-21 16:07:40 -0700250 if (valid_samples > 0) {
Dave Allison0aded082013-11-07 13:15:11 -0800251 // After the profile has been taken, write it out.
252 ScopedObjectAccess soa(self); // Acquire the mutator lock.
253 uint32_t size = profiler->WriteProfile();
Brian Carlstrom4d466a82014-05-08 19:05:29 -0700254 VLOG(profiler) << "Profile size: " << size;
Dave Allison0aded082013-11-07 13:15:11 -0800255 }
256 }
257
258 LOG(INFO) << "Profiler shutdown";
259 runtime->DetachCurrentThread();
260 return nullptr;
261}
262
263// Write out the profile file if we are generating a profile.
264uint32_t BackgroundMethodSamplingProfiler::WriteProfile() {
Calin Juravlec1b643c2014-05-30 23:44:11 +0100265 std::string full_name = output_filename_;
Brian Carlstrom4d466a82014-05-08 19:05:29 -0700266 VLOG(profiler) << "Saving profile to " << full_name;
Dave Allison0aded082013-11-07 13:15:11 -0800267
Dave Allison39c3bfb2014-01-28 18:33:52 -0800268 int fd = open(full_name.c_str(), O_RDWR);
269 if (fd < 0) {
270 // Open failed.
271 LOG(ERROR) << "Failed to open profile file " << full_name;
Dave Allison0aded082013-11-07 13:15:11 -0800272 return 0;
273 }
Dave Allison39c3bfb2014-01-28 18:33:52 -0800274
275 // Lock the file for exclusive access. This will block if another process is using
276 // the file.
277 int err = flock(fd, LOCK_EX);
278 if (err < 0) {
279 LOG(ERROR) << "Failed to lock profile file " << full_name;
280 return 0;
281 }
282
283 // Read the previous profile.
Wei Jina93b0bb2014-06-09 16:19:15 -0700284 profile_table_.ReadPrevious(fd, options_.GetProfileType());
Dave Allison39c3bfb2014-01-28 18:33:52 -0800285
286 // Move back to the start of the file.
287 lseek(fd, 0, SEEK_SET);
288
289 // Format the profile output and write to the file.
Dave Allison0aded082013-11-07 13:15:11 -0800290 std::ostringstream os;
291 uint32_t num_methods = DumpProfile(os);
292 std::string data(os.str());
Dave Allison39c3bfb2014-01-28 18:33:52 -0800293 const char *p = data.c_str();
294 size_t length = data.length();
295 size_t full_length = length;
296 do {
297 int n = ::write(fd, p, length);
298 p += n;
299 length -= n;
300 } while (length > 0);
301
302 // Truncate the file to the new length.
303 ftruncate(fd, full_length);
304
305 // Now unlock the file, allowing another process in.
306 err = flock(fd, LOCK_UN);
307 if (err < 0) {
308 LOG(ERROR) << "Failed to unlock profile file " << full_name;
309 }
310
311 // Done, close the file.
312 ::close(fd);
313
314 // Clean the profile for the next time.
315 CleanProfile();
316
Dave Allison0aded082013-11-07 13:15:11 -0800317 return num_methods;
318}
319
Calin Juravlec1b643c2014-05-30 23:44:11 +0100320bool BackgroundMethodSamplingProfiler::Start(
321 const std::string& output_filename, const ProfilerOptions& options) {
322 if (!options.IsEnabled()) {
Calin Juravlec1b643c2014-05-30 23:44:11 +0100323 return false;
324 }
325
326 CHECK(!output_filename.empty());
327
Dave Allison0aded082013-11-07 13:15:11 -0800328 Thread* self = Thread::Current();
329 {
330 MutexLock mu(self, *Locks::profiler_lock_);
331 // Don't start two profiler threads.
332 if (profiler_ != nullptr) {
Calin Juravlec1b643c2014-05-30 23:44:11 +0100333 return true;
Dave Allison0aded082013-11-07 13:15:11 -0800334 }
335 }
336
Calin Juravlec1b643c2014-05-30 23:44:11 +0100337 LOG(INFO) << "Starting profiler using output file: " << output_filename
338 << " and options: " << options;
Dave Allison0aded082013-11-07 13:15:11 -0800339 {
340 MutexLock mu(self, *Locks::profiler_lock_);
Calin Juravlec1b643c2014-05-30 23:44:11 +0100341 profiler_ = new BackgroundMethodSamplingProfiler(output_filename, options);
Dave Allison0aded082013-11-07 13:15:11 -0800342
343 CHECK_PTHREAD_CALL(pthread_create, (&profiler_pthread_, nullptr, &RunProfilerThread,
344 reinterpret_cast<void*>(profiler_)),
345 "Profiler thread");
346 }
Calin Juravlec1b643c2014-05-30 23:44:11 +0100347 return true;
Dave Allison0aded082013-11-07 13:15:11 -0800348}
349
350
351
352void BackgroundMethodSamplingProfiler::Stop() {
353 BackgroundMethodSamplingProfiler* profiler = nullptr;
354 pthread_t profiler_pthread = 0U;
355 {
356 MutexLock trace_mu(Thread::Current(), *Locks::profiler_lock_);
Wei Jin6a586912014-05-21 16:07:40 -0700357 CHECK(!shutting_down_);
Dave Allison0aded082013-11-07 13:15:11 -0800358 profiler = profiler_;
359 shutting_down_ = true;
360 profiler_pthread = profiler_pthread_;
361 }
362
363 // Now wake up the sampler thread if it sleeping.
364 {
365 MutexLock profile_mu(Thread::Current(), profiler->wait_lock_);
366 profiler->period_condition_.Signal(Thread::Current());
367 }
368 // Wait for the sample thread to stop.
369 CHECK_PTHREAD_CALL(pthread_join, (profiler_pthread, nullptr), "profiler thread shutdown");
370
371 {
372 MutexLock mu(Thread::Current(), *Locks::profiler_lock_);
373 profiler_ = nullptr;
374 }
375 delete profiler;
376}
377
378
379void BackgroundMethodSamplingProfiler::Shutdown() {
380 Stop();
381}
382
Calin Juravlec1b643c2014-05-30 23:44:11 +0100383BackgroundMethodSamplingProfiler::BackgroundMethodSamplingProfiler(
384 const std::string& output_filename, const ProfilerOptions& options)
385 : output_filename_(output_filename),
386 options_(options),
Dave Allison0aded082013-11-07 13:15:11 -0800387 wait_lock_("Profile wait lock"),
388 period_condition_("Profile condition", wait_lock_),
389 profile_table_(wait_lock_),
390 profiler_barrier_(new Barrier(0)) {
391 // Populate the filtered_methods set.
392 // This is empty right now, but to add a method, do this:
393 //
394 // filtered_methods_.insert("void java.lang.Object.wait(long, int)");
395}
396
Wei Jin445220d2014-06-20 15:56:53 -0700397// Filter out methods the profiler doesn't want to record.
398// We require mutator lock since some statistics will be updated here.
399bool BackgroundMethodSamplingProfiler::ProcessMethod(mirror::ArtMethod* method) {
Dave Allison0aded082013-11-07 13:15:11 -0800400 if (method == nullptr) {
401 profile_table_.NullMethod();
402 // Don't record a nullptr method.
Wei Jin445220d2014-06-20 15:56:53 -0700403 return false;
Dave Allison0aded082013-11-07 13:15:11 -0800404 }
405
406 mirror::Class* cls = method->GetDeclaringClass();
407 if (cls != nullptr) {
408 if (cls->GetClassLoader() == nullptr) {
409 // Don't include things in the boot
410 profile_table_.BootMethod();
Wei Jin445220d2014-06-20 15:56:53 -0700411 return false;
Dave Allison0aded082013-11-07 13:15:11 -0800412 }
413 }
414
415 bool is_filtered = false;
416
Mathieu Chartierbfd9a432014-05-21 17:43:44 -0700417 if (strcmp(method->GetName(), "<clinit>") == 0) {
Dave Allison0aded082013-11-07 13:15:11 -0800418 // always filter out class init
419 is_filtered = true;
420 }
421
422 // Filter out methods by name if there are any.
423 if (!is_filtered && filtered_methods_.size() > 0) {
424 std::string method_full_name = PrettyMethod(method);
425
426 // Don't include specific filtered methods.
427 is_filtered = filtered_methods_.count(method_full_name) != 0;
428 }
Wei Jin445220d2014-06-20 15:56:53 -0700429 return !is_filtered;
430}
Dave Allison0aded082013-11-07 13:15:11 -0800431
Wei Jin445220d2014-06-20 15:56:53 -0700432// A method has been hit, record its invocation in the method map.
433// The mutator_lock must be held (shared) when this is called.
434void BackgroundMethodSamplingProfiler::RecordMethod(mirror::ArtMethod* method) {
Dave Allison0aded082013-11-07 13:15:11 -0800435 // Add to the profile table unless it is filtered out.
Wei Jin445220d2014-06-20 15:56:53 -0700436 if (ProcessMethod(method)) {
437 profile_table_.Put(method);
438 }
439}
440
441// Record the current bounded stack into sampling results.
442void BackgroundMethodSamplingProfiler::RecordStack(const std::vector<InstructionLocation>& stack) {
443 if (stack.size() == 0) {
444 return;
445 }
446 // Get the method on top of the stack. We use this method to perform filtering.
447 mirror::ArtMethod* method = stack.front().first;
448 if (ProcessMethod(method)) {
449 profile_table_.PutStack(stack);
Dave Allison0aded082013-11-07 13:15:11 -0800450 }
451}
452
453// Clean out any recordings for the method traces.
454void BackgroundMethodSamplingProfiler::CleanProfile() {
455 profile_table_.Clear();
456}
457
458uint32_t BackgroundMethodSamplingProfiler::DumpProfile(std::ostream& os) {
Wei Jina93b0bb2014-06-09 16:19:15 -0700459 return profile_table_.Write(os, options_.GetProfileType());
Dave Allison0aded082013-11-07 13:15:11 -0800460}
461
462// Profile Table.
463// This holds a mapping of mirror::ArtMethod* to a count of how many times a sample
464// hit it at the top of the stack.
465ProfileSampleResults::ProfileSampleResults(Mutex& lock) : lock_(lock), num_samples_(0),
466 num_null_methods_(0),
467 num_boot_methods_(0) {
468 for (int i = 0; i < kHashSize; i++) {
469 table[i] = nullptr;
470 }
Wei Jin445220d2014-06-20 15:56:53 -0700471 method_context_table = nullptr;
472 stack_trie_root_ = nullptr;
Dave Allison0aded082013-11-07 13:15:11 -0800473}
474
475ProfileSampleResults::~ProfileSampleResults() {
Wei Jina93b0bb2014-06-09 16:19:15 -0700476 Clear();
Dave Allison0aded082013-11-07 13:15:11 -0800477}
478
Calin Juravlebb0b53f2014-05-23 17:33:29 +0100479// Add a method to the profile table. If it's the first time the method
Dave Allison0aded082013-11-07 13:15:11 -0800480// has been seen, add it with count=1, otherwise increment the count.
481void ProfileSampleResults::Put(mirror::ArtMethod* method) {
Wei Jina93b0bb2014-06-09 16:19:15 -0700482 MutexLock mu(Thread::Current(), lock_);
Dave Allison0aded082013-11-07 13:15:11 -0800483 uint32_t index = Hash(method);
484 if (table[index] == nullptr) {
485 table[index] = new Map();
486 }
487 Map::iterator i = table[index]->find(method);
488 if (i == table[index]->end()) {
489 (*table[index])[method] = 1;
490 } else {
491 i->second++;
492 }
493 num_samples_++;
Wei Jina93b0bb2014-06-09 16:19:15 -0700494}
495
Wei Jin445220d2014-06-20 15:56:53 -0700496// Add a bounded stack to the profile table. Only the count of the method on
497// top of the frame will be increased.
498void ProfileSampleResults::PutStack(const std::vector<InstructionLocation>& stack) {
Wei Jina93b0bb2014-06-09 16:19:15 -0700499 MutexLock mu(Thread::Current(), lock_);
Wei Jin445220d2014-06-20 15:56:53 -0700500 ScopedObjectAccess soa(Thread::Current());
501 if (stack_trie_root_ == nullptr) {
502 // The root of the stack trie is a dummy node so that we don't have to maintain
503 // a collection of tries.
504 stack_trie_root_ = new StackTrieNode();
Wei Jina93b0bb2014-06-09 16:19:15 -0700505 }
Wei Jin445220d2014-06-20 15:56:53 -0700506
507 StackTrieNode* current = stack_trie_root_;
508 if (stack.size() == 0) {
509 current->IncreaseCount();
510 return;
511 }
512
513 for (std::vector<InstructionLocation>::const_reverse_iterator iter = stack.rbegin();
514 iter != stack.rend(); ++iter) {
515 InstructionLocation inst_loc = *iter;
516 mirror::ArtMethod* method = inst_loc.first;
517 if (method == nullptr) {
518 // skip null method
519 continue;
520 }
521 uint32_t dex_pc = inst_loc.second;
522 uint32_t method_idx = method->GetDexMethodIndex();
523 const DexFile* dex_file = method->GetDeclaringClass()->GetDexCache()->GetDexFile();
524 MethodReference method_ref(dex_file, method_idx);
525 StackTrieNode* child = current->FindChild(method_ref, dex_pc);
526 if (child != nullptr) {
527 current = child;
Wei Jina93b0bb2014-06-09 16:19:15 -0700528 } else {
Wei Jin445220d2014-06-20 15:56:53 -0700529 uint32_t method_size = 0;
530 const DexFile::CodeItem* codeitem = method->GetCodeItem();
531 if (codeitem != nullptr) {
532 method_size = codeitem->insns_size_in_code_units_;
533 }
534 StackTrieNode* new_node = new StackTrieNode(method_ref, dex_pc, method_size, current);
535 current->AppendChild(new_node);
536 current = new_node;
Wei Jina93b0bb2014-06-09 16:19:15 -0700537 }
538 }
Wei Jin445220d2014-06-20 15:56:53 -0700539
540 if (current != stack_trie_root_ && current->GetCount() == 0) {
541 // Insert into method_context table;
542 if (method_context_table == nullptr) {
543 method_context_table = new MethodContextMap();
544 }
545 MethodReference method = current->GetMethod();
546 MethodContextMap::iterator i = method_context_table->find(method);
547 if (i == method_context_table->end()) {
548 TrieNodeSet* node_set = new TrieNodeSet();
549 node_set->insert(current);
550 (*method_context_table)[method] = node_set;
551 } else {
552 TrieNodeSet* node_set = i->second;
553 node_set->insert(current);
554 }
555 }
556 current->IncreaseCount();
Wei Jina93b0bb2014-06-09 16:19:15 -0700557 num_samples_++;
Dave Allison0aded082013-11-07 13:15:11 -0800558}
559
Dave Allison39c3bfb2014-01-28 18:33:52 -0800560// Write the profile table to the output stream. Also merge with the previous profile.
Wei Jina93b0bb2014-06-09 16:19:15 -0700561uint32_t ProfileSampleResults::Write(std::ostream& os, ProfileDataType type) {
Dave Allison0aded082013-11-07 13:15:11 -0800562 ScopedObjectAccess soa(Thread::Current());
Dave Allison39c3bfb2014-01-28 18:33:52 -0800563 num_samples_ += previous_num_samples_;
564 num_null_methods_ += previous_num_null_methods_;
565 num_boot_methods_ += previous_num_boot_methods_;
566
Calin Juravlec1b643c2014-05-30 23:44:11 +0100567 VLOG(profiler) << "Profile: "
568 << num_samples_ << "/" << num_null_methods_ << "/" << num_boot_methods_;
Dave Allison0aded082013-11-07 13:15:11 -0800569 os << num_samples_ << "/" << num_null_methods_ << "/" << num_boot_methods_ << "\n";
570 uint32_t num_methods = 0;
Wei Jina93b0bb2014-06-09 16:19:15 -0700571 if (type == kProfilerMethod) {
572 for (int i = 0 ; i < kHashSize; i++) {
573 Map *map = table[i];
574 if (map != nullptr) {
575 for (const auto &meth_iter : *map) {
576 mirror::ArtMethod *method = meth_iter.first;
577 std::string method_name = PrettyMethod(method);
Dave Allison39c3bfb2014-01-28 18:33:52 -0800578
Wei Jina93b0bb2014-06-09 16:19:15 -0700579 const DexFile::CodeItem* codeitem = method->GetCodeItem();
580 uint32_t method_size = 0;
581 if (codeitem != nullptr) {
582 method_size = codeitem->insns_size_in_code_units_;
583 }
584 uint32_t count = meth_iter.second;
Dave Allison39c3bfb2014-01-28 18:33:52 -0800585
Wei Jina93b0bb2014-06-09 16:19:15 -0700586 // Merge this profile entry with one from a previous run (if present). Also
587 // remove the previous entry.
588 PreviousProfile::iterator pi = previous_.find(method_name);
589 if (pi != previous_.end()) {
590 count += pi->second.count_;
591 previous_.erase(pi);
592 }
593 os << StringPrintf("%s/%u/%u\n", method_name.c_str(), count, method_size);
594 ++num_methods;
Dave Allison39c3bfb2014-01-28 18:33:52 -0800595 }
Wei Jina93b0bb2014-06-09 16:19:15 -0700596 }
597 }
Wei Jin445220d2014-06-20 15:56:53 -0700598 } else if (type == kProfilerBoundedStack) {
599 if (method_context_table != nullptr) {
600 for (const auto &method_iter : *method_context_table) {
601 MethodReference method = method_iter.first;
602 TrieNodeSet* node_set = method_iter.second;
603 std::string method_name = PrettyMethod(method.dex_method_index, *(method.dex_file));
604 uint32_t method_size = 0;
605 uint32_t total_count = 0;
606 PreviousContextMap new_context_map;
607 for (const auto &trie_node_i : *node_set) {
608 StackTrieNode* node = trie_node_i;
609 method_size = node->GetMethodSize();
610 uint32_t count = node->GetCount();
611 uint32_t dexpc = node->GetDexPC();
612 total_count += count;
Wei Jina93b0bb2014-06-09 16:19:15 -0700613
Wei Jin445220d2014-06-20 15:56:53 -0700614 StackTrieNode* current = node->GetParent();
615 // We go backward on the trie to retrieve context and dex_pc until the dummy root.
616 // The format of the context is "method_1@pc_1@method_2@pc_2@..."
617 std::vector<std::string> context_vector;
618 while (current != nullptr && current->GetParent() != nullptr) {
619 context_vector.push_back(StringPrintf("%s@%u",
620 PrettyMethod(current->GetMethod().dex_method_index, *(current->GetMethod().dex_file)).c_str(),
621 current->GetDexPC()));
622 current = current->GetParent();
Wei Jina93b0bb2014-06-09 16:19:15 -0700623 }
Wei Jin445220d2014-06-20 15:56:53 -0700624 std::string context_sig = Join(context_vector, '@');
625 new_context_map[std::make_pair(dexpc, context_sig)] = count;
626 }
Wei Jina93b0bb2014-06-09 16:19:15 -0700627
Wei Jin445220d2014-06-20 15:56:53 -0700628 PreviousProfile::iterator pi = previous_.find(method_name);
629 if (pi != previous_.end()) {
630 total_count += pi->second.count_;
631 PreviousContextMap* previous_context_map = pi->second.context_map_;
632 if (previous_context_map != nullptr) {
633 for (const auto &context_i : *previous_context_map) {
634 uint32_t count = context_i.second;
635 PreviousContextMap::iterator ci = new_context_map.find(context_i.first);
636 if (ci == new_context_map.end()) {
637 new_context_map[context_i.first] = count;
638 } else {
639 ci->second += count;
Wei Jina93b0bb2014-06-09 16:19:15 -0700640 }
641 }
Wei Jina93b0bb2014-06-09 16:19:15 -0700642 }
Wei Jin445220d2014-06-20 15:56:53 -0700643 delete previous_context_map;
644 previous_.erase(pi);
Wei Jina93b0bb2014-06-09 16:19:15 -0700645 }
Wei Jin445220d2014-06-20 15:56:53 -0700646 // We write out profile data with dex pc and context information in the following format:
647 // "method/total_count/size/[pc_1:count_1:context_1#pc_2:count_2:context_2#...]".
648 std::vector<std::string> context_count_vector;
649 for (const auto &context_i : new_context_map) {
650 context_count_vector.push_back(StringPrintf("%u:%u:%s", context_i.first.first,
651 context_i.second, context_i.first.second.c_str()));
652 }
653 os << StringPrintf("%s/%u/%u/[%s]\n", method_name.c_str(), total_count,
654 method_size, Join(context_count_vector, '#').c_str());
655 ++num_methods;
Dave Allison39c3bfb2014-01-28 18:33:52 -0800656 }
Dave Allison0aded082013-11-07 13:15:11 -0800657 }
658 }
Dave Allison39c3bfb2014-01-28 18:33:52 -0800659
660 // Now we write out the remaining previous methods.
Wei Jina93b0bb2014-06-09 16:19:15 -0700661 for (const auto &pi : previous_) {
662 if (type == kProfilerMethod) {
663 os << StringPrintf("%s/%u/%u\n", pi.first.c_str(), pi.second.count_, pi.second.method_size_);
Wei Jin445220d2014-06-20 15:56:53 -0700664 } else if (type == kProfilerBoundedStack) {
Wei Jina93b0bb2014-06-09 16:19:15 -0700665 os << StringPrintf("%s/%u/%u/[", pi.first.c_str(), pi.second.count_, pi.second.method_size_);
Wei Jin445220d2014-06-20 15:56:53 -0700666 PreviousContextMap* previous_context_map = pi.second.context_map_;
667 if (previous_context_map != nullptr) {
668 std::vector<std::string> context_count_vector;
669 for (const auto &context_i : *previous_context_map) {
670 context_count_vector.push_back(StringPrintf("%u:%u:%s", context_i.first.first,
671 context_i.second, context_i.first.second.c_str()));
Wei Jina93b0bb2014-06-09 16:19:15 -0700672 }
Wei Jin445220d2014-06-20 15:56:53 -0700673 os << Join(context_count_vector, '#');
Wei Jina93b0bb2014-06-09 16:19:15 -0700674 }
675 os << "]\n";
676 }
Dave Allison39c3bfb2014-01-28 18:33:52 -0800677 ++num_methods;
678 }
Dave Allison0aded082013-11-07 13:15:11 -0800679 return num_methods;
680}
681
682void ProfileSampleResults::Clear() {
683 num_samples_ = 0;
684 num_null_methods_ = 0;
685 num_boot_methods_ = 0;
686 for (int i = 0; i < kHashSize; i++) {
Wei Jina93b0bb2014-06-09 16:19:15 -0700687 delete table[i];
688 table[i] = nullptr;
Wei Jin445220d2014-06-20 15:56:53 -0700689 }
690 if (stack_trie_root_ != nullptr) {
691 stack_trie_root_->DeleteChildren();
692 delete stack_trie_root_;
693 stack_trie_root_ = nullptr;
694 if (method_context_table != nullptr) {
695 delete method_context_table;
696 method_context_table = nullptr;
Wei Jina93b0bb2014-06-09 16:19:15 -0700697 }
Wei Jina93b0bb2014-06-09 16:19:15 -0700698 }
699 for (auto &pi : previous_) {
Wei Jin445220d2014-06-20 15:56:53 -0700700 if (pi.second.context_map_ != nullptr) {
701 delete pi.second.context_map_;
702 pi.second.context_map_ = nullptr;
703 }
Dave Allison0aded082013-11-07 13:15:11 -0800704 }
Dave Allison39c3bfb2014-01-28 18:33:52 -0800705 previous_.clear();
Dave Allison0aded082013-11-07 13:15:11 -0800706}
707
708uint32_t ProfileSampleResults::Hash(mirror::ArtMethod* method) {
Ian Rogersef7d42f2014-01-06 12:55:46 -0800709 return (PointerToLowMemUInt32(method) >> 3) % kHashSize;
Dave Allison0aded082013-11-07 13:15:11 -0800710}
711
Dave Allison39c3bfb2014-01-28 18:33:52 -0800712// Read a single line into the given string. Returns true if everything OK, false
713// on EOF or error.
714static bool ReadProfileLine(int fd, std::string& line) {
715 char buf[4];
716 line.clear();
717 while (true) {
718 int n = read(fd, buf, 1); // TODO: could speed this up but is it worth it?
719 if (n != 1) {
720 return false;
721 }
722 if (buf[0] == '\n') {
723 break;
724 }
725 line += buf[0];
726 }
727 return true;
728}
729
Wei Jina93b0bb2014-06-09 16:19:15 -0700730void ProfileSampleResults::ReadPrevious(int fd, ProfileDataType type) {
Dave Allison39c3bfb2014-01-28 18:33:52 -0800731 // Reset counters.
732 previous_num_samples_ = previous_num_null_methods_ = previous_num_boot_methods_ = 0;
733
734 std::string line;
735
736 // The first line contains summary information.
737 if (!ReadProfileLine(fd, line)) {
738 return;
739 }
740 std::vector<std::string> summary_info;
Ian Rogers6f3dbba2014-10-14 17:41:57 -0700741 Split(line, '/', &summary_info);
Dave Allison39c3bfb2014-01-28 18:33:52 -0800742 if (summary_info.size() != 3) {
743 // Bad summary info. It should be count/nullcount/bootcount
744 return;
745 }
Wei Jinf21f0a92014-06-27 17:44:18 -0700746 previous_num_samples_ = strtoul(summary_info[0].c_str(), nullptr, 10);
747 previous_num_null_methods_ = strtoul(summary_info[1].c_str(), nullptr, 10);
748 previous_num_boot_methods_ = strtoul(summary_info[2].c_str(), nullptr, 10);
Dave Allison39c3bfb2014-01-28 18:33:52 -0800749
Wei Jina93b0bb2014-06-09 16:19:15 -0700750 // Now read each line until the end of file. Each line consists of 3 or 4 fields separated by /
Dave Allison39c3bfb2014-01-28 18:33:52 -0800751 while (true) {
752 if (!ReadProfileLine(fd, line)) {
753 break;
754 }
755 std::vector<std::string> info;
Ian Rogers6f3dbba2014-10-14 17:41:57 -0700756 Split(line, '/', &info);
Wei Jina93b0bb2014-06-09 16:19:15 -0700757 if (info.size() != 3 && info.size() != 4) {
Dave Allison39c3bfb2014-01-28 18:33:52 -0800758 // Malformed.
759 break;
760 }
761 std::string methodname = info[0];
Wei Jinf21f0a92014-06-27 17:44:18 -0700762 uint32_t total_count = strtoul(info[1].c_str(), nullptr, 10);
763 uint32_t size = strtoul(info[2].c_str(), nullptr, 10);
Wei Jin445220d2014-06-20 15:56:53 -0700764 PreviousContextMap* context_map = nullptr;
765 if (type == kProfilerBoundedStack && info.size() == 4) {
766 context_map = new PreviousContextMap();
767 std::string context_counts_str = info[3].substr(1, info[3].size() - 2);
768 std::vector<std::string> context_count_pairs;
Ian Rogers6f3dbba2014-10-14 17:41:57 -0700769 Split(context_counts_str, '#', &context_count_pairs);
Wei Jin445220d2014-06-20 15:56:53 -0700770 for (uint32_t i = 0; i < context_count_pairs.size(); ++i) {
771 std::vector<std::string> context_count;
Ian Rogers6f3dbba2014-10-14 17:41:57 -0700772 Split(context_count_pairs[i], ':', &context_count);
Wei Jin445220d2014-06-20 15:56:53 -0700773 if (context_count.size() == 2) {
774 // Handles the situtation when the profile file doesn't contain context information.
Wei Jinf21f0a92014-06-27 17:44:18 -0700775 uint32_t dexpc = strtoul(context_count[0].c_str(), nullptr, 10);
776 uint32_t count = strtoul(context_count[1].c_str(), nullptr, 10);
Wei Jin445220d2014-06-20 15:56:53 -0700777 (*context_map)[std::make_pair(dexpc, "")] = count;
778 } else {
779 // Handles the situtation when the profile file contains context information.
Wei Jinf21f0a92014-06-27 17:44:18 -0700780 uint32_t dexpc = strtoul(context_count[0].c_str(), nullptr, 10);
781 uint32_t count = strtoul(context_count[1].c_str(), nullptr, 10);
Wei Jin445220d2014-06-20 15:56:53 -0700782 std::string context = context_count[2];
783 (*context_map)[std::make_pair(dexpc, context)] = count;
784 }
Wei Jina93b0bb2014-06-09 16:19:15 -0700785 }
786 }
Wei Jin445220d2014-06-20 15:56:53 -0700787 previous_[methodname] = PreviousValue(total_count, size, context_map);
Dave Allison39c3bfb2014-01-28 18:33:52 -0800788 }
789}
Dave Allison0aded082013-11-07 13:15:11 -0800790
Calin Juravlebb0b53f2014-05-23 17:33:29 +0100791bool ProfileFile::LoadFile(const std::string& fileName) {
Calin Juravle9dae5b42014-04-07 16:36:21 +0300792 LOG(VERBOSE) << "reading profile file " << fileName;
793 struct stat st;
794 int err = stat(fileName.c_str(), &st);
795 if (err == -1) {
796 LOG(VERBOSE) << "not found";
797 return false;
798 }
799 if (st.st_size == 0) {
Dave Allison644789f2014-04-10 13:06:10 -0700800 return false; // Empty profiles are invalid.
Calin Juravle9dae5b42014-04-07 16:36:21 +0300801 }
802 std::ifstream in(fileName.c_str());
803 if (!in) {
804 LOG(VERBOSE) << "profile file " << fileName << " exists but can't be opened";
805 LOG(VERBOSE) << "file owner: " << st.st_uid << ":" << st.st_gid;
806 LOG(VERBOSE) << "me: " << getuid() << ":" << getgid();
807 LOG(VERBOSE) << "file permissions: " << std::oct << st.st_mode;
808 LOG(VERBOSE) << "errno: " << errno;
809 return false;
810 }
811 // The first line contains summary information.
812 std::string line;
813 std::getline(in, line);
814 if (in.eof()) {
815 return false;
816 }
817 std::vector<std::string> summary_info;
Ian Rogers6f3dbba2014-10-14 17:41:57 -0700818 Split(line, '/', &summary_info);
Calin Juravle9dae5b42014-04-07 16:36:21 +0300819 if (summary_info.size() != 3) {
Calin Juravle19477a82014-06-06 12:24:21 +0100820 // Bad summary info. It should be total/null/boot.
Calin Juravle9dae5b42014-04-07 16:36:21 +0300821 return false;
822 }
Calin Juravle19477a82014-06-06 12:24:21 +0100823 // This is the number of hits in all profiled methods (without nullptr or boot methods)
Wei Jinf21f0a92014-06-27 17:44:18 -0700824 uint32_t total_count = strtoul(summary_info[0].c_str(), nullptr, 10);
Calin Juravle9dae5b42014-04-07 16:36:21 +0300825
826 // Now read each line until the end of file. Each line consists of 3 fields separated by '/'.
827 // Store the info in descending order given by the most used methods.
828 typedef std::set<std::pair<int, std::vector<std::string>>> ProfileSet;
829 ProfileSet countSet;
830 while (!in.eof()) {
831 std::getline(in, line);
832 if (in.eof()) {
833 break;
834 }
835 std::vector<std::string> info;
Ian Rogers6f3dbba2014-10-14 17:41:57 -0700836 Split(line, '/', &info);
Wei Jina93b0bb2014-06-09 16:19:15 -0700837 if (info.size() != 3 && info.size() != 4) {
Calin Juravle9dae5b42014-04-07 16:36:21 +0300838 // Malformed.
Calin Juravlebb0b53f2014-05-23 17:33:29 +0100839 return false;
Calin Juravle9dae5b42014-04-07 16:36:21 +0300840 }
841 int count = atoi(info[1].c_str());
842 countSet.insert(std::make_pair(-count, info));
843 }
844
845 uint32_t curTotalCount = 0;
846 ProfileSet::iterator end = countSet.end();
847 const ProfileData* prevData = nullptr;
848 for (ProfileSet::iterator it = countSet.begin(); it != end ; it++) {
849 const std::string& methodname = it->second[0];
850 uint32_t count = -it->first;
Wei Jinf21f0a92014-06-27 17:44:18 -0700851 uint32_t size = strtoul(it->second[2].c_str(), nullptr, 10);
Calin Juravle9dae5b42014-04-07 16:36:21 +0300852 double usedPercent = (count * 100.0) / total_count;
853
854 curTotalCount += count;
855 // Methods with the same count should be part of the same top K percentage bucket.
856 double topKPercentage = (prevData != nullptr) && (prevData->GetCount() == count)
857 ? prevData->GetTopKUsedPercentage()
858 : 100 * static_cast<double>(curTotalCount) / static_cast<double>(total_count);
859
860 // Add it to the profile map.
861 ProfileData curData = ProfileData(methodname, count, size, usedPercent, topKPercentage);
Calin Juravlebb0b53f2014-05-23 17:33:29 +0100862 profile_map_[methodname] = curData;
Calin Juravle9dae5b42014-04-07 16:36:21 +0300863 prevData = &curData;
864 }
865 return true;
866}
867
Calin Juravlebb0b53f2014-05-23 17:33:29 +0100868bool ProfileFile::GetProfileData(ProfileFile::ProfileData* data, const std::string& method_name) {
869 ProfileMap::iterator i = profile_map_.find(method_name);
870 if (i == profile_map_.end()) {
Calin Juravle9dae5b42014-04-07 16:36:21 +0300871 return false;
872 }
Calin Juravlebb0b53f2014-05-23 17:33:29 +0100873 *data = i->second;
874 return true;
875}
876
877bool ProfileFile::GetTopKSamples(std::set<std::string>& topKSamples, double topKPercentage) {
878 ProfileMap::iterator end = profile_map_.end();
879 for (ProfileMap::iterator it = profile_map_.begin(); it != end; it++) {
Calin Juravle9dae5b42014-04-07 16:36:21 +0300880 if (it->second.GetTopKUsedPercentage() < topKPercentage) {
881 topKSamples.insert(it->first);
882 }
883 }
884 return true;
885}
886
Wei Jin445220d2014-06-20 15:56:53 -0700887StackTrieNode* StackTrieNode::FindChild(MethodReference method, uint32_t dex_pc) {
888 if (children_.size() == 0) {
889 return nullptr;
890 }
891 // Create a dummy node for searching.
892 StackTrieNode* node = new StackTrieNode(method, dex_pc, 0, nullptr);
893 std::set<StackTrieNode*, StackTrieNodeComparator>::iterator i = children_.find(node);
894 delete node;
895 return (i == children_.end()) ? nullptr : *i;
896}
897
898void StackTrieNode::DeleteChildren() {
899 for (auto &child : children_) {
900 if (child != nullptr) {
901 child->DeleteChildren();
902 delete child;
903 }
904 }
905}
906
Calin Juravle9dae5b42014-04-07 16:36:21 +0300907} // namespace art