Add more systracing everywhere
Added to:
JIT
DexFile functions
Oat file manager
Added helper ScopedTrace to prevent errors and reduce excess code.
Bug: 27502458
Change-Id: Ifaeff8913d79eefc797380987d13cc00456266f8
diff --git a/runtime/base/arena_allocator.cc b/runtime/base/arena_allocator.cc
index a4b38ea..fba26fe 100644
--- a/runtime/base/arena_allocator.cc
+++ b/runtime/base/arena_allocator.cc
@@ -23,6 +23,7 @@
#include "mem_map.h"
#include "mutex.h"
#include "thread-inl.h"
+#include "systrace.h"
namespace art {
@@ -258,6 +259,7 @@
void ArenaPool::TrimMaps() {
if (!use_malloc_) {
+ ScopedTrace trace(__PRETTY_FUNCTION__);
// Doesn't work for malloc.
MutexLock lock(Thread::Current(), lock_);
for (auto* arena = free_arenas_; arena != nullptr; arena = arena->next_) {
diff --git a/runtime/base/mutex.cc b/runtime/base/mutex.cc
index 6972b3e..620bf9c 100644
--- a/runtime/base/mutex.cc
+++ b/runtime/base/mutex.cc
@@ -19,12 +19,10 @@
#include <errno.h>
#include <sys/time.h>
-#define ATRACE_TAG ATRACE_TAG_DALVIK
-#include "cutils/trace.h"
-
#include "atomic.h"
#include "base/logging.h"
#include "base/time_utils.h"
+#include "base/systrace.h"
#include "base/value_object.h"
#include "mutex-inl.h"
#include "runtime.h"
diff --git a/runtime/base/systrace.h b/runtime/base/systrace.h
new file mode 100644
index 0000000..3901f96
--- /dev/null
+++ b/runtime/base/systrace.h
@@ -0,0 +1,42 @@
+/*
+ * Copyright (C) 2016 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+#ifndef ART_RUNTIME_BASE_SYSTRACE_H_
+#define ART_RUNTIME_BASE_SYSTRACE_H_
+
+#define ATRACE_TAG ATRACE_TAG_DALVIK
+#include <cutils/trace.h>
+#include <string>
+#include <utils/Trace.h>
+
+namespace art {
+
+class ScopedTrace {
+ public:
+ explicit ScopedTrace(const char* name) {
+ ATRACE_BEGIN(name);
+ }
+
+ explicit ScopedTrace(const std::string& name) : ScopedTrace(name.c_str()) {}
+
+ ~ScopedTrace() {
+ ATRACE_END();
+ }
+};
+
+} // namespace art
+
+#endif // ART_RUNTIME_BASE_SYSTRACE_H_
diff --git a/runtime/base/timing_logger.cc b/runtime/base/timing_logger.cc
index 1942e1d..9a0e0d0 100644
--- a/runtime/base/timing_logger.cc
+++ b/runtime/base/timing_logger.cc
@@ -15,15 +15,14 @@
*/
-#define ATRACE_TAG ATRACE_TAG_DALVIK
#include <stdio.h>
-#include <cutils/trace.h>
#include "timing_logger.h"
#include "base/logging.h"
#include "base/stl_util.h"
#include "base/histogram-inl.h"
+#include "base/systrace.h"
#include "base/time_utils.h"
#include "thread-inl.h"
diff --git a/runtime/class_linker.cc b/runtime/class_linker.cc
index 302fa06..70e2e33 100644
--- a/runtime/class_linker.cc
+++ b/runtime/class_linker.cc
@@ -36,6 +36,7 @@
#include "base/scoped_arena_containers.h"
#include "base/scoped_flock.h"
#include "base/stl_util.h"
+#include "base/systrace.h"
#include "base/time_utils.h"
#include "base/unix_file/fd_file.h"
#include "base/value_object.h"
@@ -7671,6 +7672,7 @@
}
std::set<DexCacheResolvedClasses> ClassLinker::GetResolvedClasses(bool ignore_boot_classes) {
+ ScopedTrace trace(__PRETTY_FUNCTION__);
ScopedObjectAccess soa(Thread::Current());
ScopedAssertNoThreadSuspension ants(soa.Self(), __FUNCTION__);
std::set<DexCacheResolvedClasses> ret;
@@ -7737,6 +7739,7 @@
std::unordered_set<std::string> ClassLinker::GetClassDescriptorsForProfileKeys(
const std::set<DexCacheResolvedClasses>& classes) {
+ ScopedTrace trace(__PRETTY_FUNCTION__);
std::unordered_set<std::string> ret;
Thread* const self = Thread::Current();
std::unordered_map<std::string, const DexFile*> location_to_dex_file;
diff --git a/runtime/dex_file.cc b/runtime/dex_file.cc
index 81a3e4b..4a0a6fc 100644
--- a/runtime/dex_file.cc
+++ b/runtime/dex_file.cc
@@ -34,6 +34,7 @@
#include "base/logging.h"
#include "base/stl_util.h"
#include "base/stringprintf.h"
+#include "base/systrace.h"
#include "class_linker-inl.h"
#include "dex_file-inl.h"
#include "dex_file_verifier.h"
@@ -116,6 +117,7 @@
bool DexFile::Open(const char* filename, const char* location, std::string* error_msg,
std::vector<std::unique_ptr<const DexFile>>* dex_files) {
+ ScopedTrace trace(std::string("Open dex file ") + location);
DCHECK(dex_files != nullptr) << "DexFile::Open: out-param is nullptr";
uint32_t magic;
ScopedFd fd(OpenAndReadMagic(filename, &magic, error_msg));
@@ -201,6 +203,7 @@
const OatDexFile* oat_dex_file,
bool verify,
std::string* error_msg) {
+ ScopedTrace trace(std::string("Open dex file from RAM ") + location);
std::unique_ptr<const DexFile> dex_file = OpenMemory(base,
size,
location,
@@ -221,6 +224,7 @@
std::unique_ptr<const DexFile> DexFile::OpenFile(int fd, const char* location, bool verify,
std::string* error_msg) {
+ ScopedTrace trace(std::string("Open dex file ") + location);
CHECK(location != nullptr);
std::unique_ptr<MemMap> map;
{
@@ -278,6 +282,7 @@
bool DexFile::OpenZip(int fd, const std::string& location, std::string* error_msg,
std::vector<std::unique_ptr<const DexFile>>* dex_files) {
+ ScopedTrace trace("Dex file open Zip " + std::string(location));
DCHECK(dex_files != nullptr) << "DexFile::OpenZip: out-param is nullptr";
std::unique_ptr<ZipArchive> zip_archive(ZipArchive::OpenFromFd(fd, location.c_str(), error_msg));
if (zip_archive.get() == nullptr) {
@@ -303,6 +308,7 @@
std::unique_ptr<const DexFile> DexFile::Open(const ZipArchive& zip_archive, const char* entry_name,
const std::string& location, std::string* error_msg,
ZipOpenErrorCode* error_code) {
+ ScopedTrace trace("Dex file open from Zip Archive " + std::string(location));
CHECK(!location.empty());
std::unique_ptr<ZipEntry> zip_entry(zip_archive.Find(entry_name, error_msg));
if (zip_entry.get() == nullptr) {
@@ -348,6 +354,7 @@
bool DexFile::OpenFromZip(const ZipArchive& zip_archive, const std::string& location,
std::string* error_msg,
std::vector<std::unique_ptr<const DexFile>>* dex_files) {
+ ScopedTrace trace("Dex file open from Zip " + std::string(location));
DCHECK(dex_files != nullptr) << "DexFile::OpenFromZip: out-param is nullptr";
ZipOpenErrorCode error_code;
std::unique_ptr<const DexFile> dex_file(Open(zip_archive, kClassesDex, location, error_msg,
diff --git a/runtime/gc/accounting/card_table.cc b/runtime/gc/accounting/card_table.cc
index 1a7b1a3..121da37 100644
--- a/runtime/gc/accounting/card_table.cc
+++ b/runtime/gc/accounting/card_table.cc
@@ -17,6 +17,7 @@
#include "card_table.h"
#include "base/logging.h"
+#include "base/systrace.h"
#include "card_table-inl.h"
#include "gc/heap.h"
#include "gc/space/space.h"
@@ -57,6 +58,7 @@
*/
CardTable* CardTable::Create(const uint8_t* heap_begin, size_t heap_capacity) {
+ ScopedTrace trace(__PRETTY_FUNCTION__);
/* Set up the card table */
size_t capacity = heap_capacity / kCardSize;
/* Allocate an extra 256 bytes to allow fixed low-byte of base */
diff --git a/runtime/gc/collector/garbage_collector.cc b/runtime/gc/collector/garbage_collector.cc
index afd0a30..18c4adf 100644
--- a/runtime/gc/collector/garbage_collector.cc
+++ b/runtime/gc/collector/garbage_collector.cc
@@ -18,13 +18,11 @@
#include "garbage_collector.h"
-#define ATRACE_TAG ATRACE_TAG_DALVIK
-#include "cutils/trace.h"
-
#include "base/dumpable.h"
#include "base/histogram-inl.h"
#include "base/logging.h"
#include "base/mutex-inl.h"
+#include "base/systrace.h"
#include "base/time_utils.h"
#include "gc/accounting/heap_bitmap.h"
#include "gc/space/large_object_space.h"
@@ -81,7 +79,7 @@
}
void GarbageCollector::Run(GcCause gc_cause, bool clear_soft_references) {
- ATRACE_BEGIN(StringPrintf("%s %s GC", PrettyCause(gc_cause), GetName()).c_str());
+ ScopedTrace trace(StringPrintf("%s %s GC", PrettyCause(gc_cause), GetName()));
Thread* self = Thread::Current();
uint64_t start_time = NanoTime();
Iteration* current_iteration = GetCurrentIteration();
@@ -107,7 +105,6 @@
MutexLock mu(self, pause_histogram_lock_);
pause_histogram_.AdjustAndAddValue(pause_time);
}
- ATRACE_END();
}
void GarbageCollector::SwapBitmaps() {
diff --git a/runtime/gc/collector/mark_sweep.cc b/runtime/gc/collector/mark_sweep.cc
index 64c8e9a..6073fc8 100644
--- a/runtime/gc/collector/mark_sweep.cc
+++ b/runtime/gc/collector/mark_sweep.cc
@@ -22,13 +22,11 @@
#include <climits>
#include <vector>
-#define ATRACE_TAG ATRACE_TAG_DALVIK
-#include "cutils/trace.h"
-
#include "base/bounded_fifo.h"
#include "base/logging.h"
#include "base/macros.h"
#include "base/mutex-inl.h"
+#include "base/systrace.h"
#include "base/time_utils.h"
#include "base/timing_logger.h"
#include "gc/accounting/card_table-inl.h"
@@ -1137,17 +1135,15 @@
}
virtual void Run(Thread* thread) OVERRIDE NO_THREAD_SAFETY_ANALYSIS {
- ATRACE_BEGIN("Marking thread roots");
+ ScopedTrace trace("Marking thread roots");
// Note: self is not necessarily equal to thread since thread may be suspended.
Thread* const self = Thread::Current();
CHECK(thread == self || thread->IsSuspended() || thread->GetState() == kWaitingPerformingGc)
<< thread->GetState() << " thread " << thread << " self " << self;
thread->VisitRoots(this);
- ATRACE_END();
if (revoke_ros_alloc_thread_local_buffers_at_checkpoint_) {
- ATRACE_BEGIN("RevokeRosAllocThreadLocalBuffers");
+ ScopedTrace trace2("RevokeRosAllocThreadLocalBuffers");
mark_sweep_->GetHeap()->RevokeRosAllocThreadLocalBuffers(thread);
- ATRACE_END();
}
// If thread is a running mutator, then act on behalf of the garbage collector.
// See the code in ThreadList::RunCheckpoint.
diff --git a/runtime/gc/heap.cc b/runtime/gc/heap.cc
index 81a8831..3026ac1 100644
--- a/runtime/gc/heap.cc
+++ b/runtime/gc/heap.cc
@@ -16,9 +16,6 @@
#include "heap.h"
-#define ATRACE_TAG ATRACE_TAG_DALVIK
-#include <cutils/trace.h>
-
#include <limits>
#include <memory>
#include <unwind.h> // For GC verification.
@@ -30,6 +27,7 @@
#include "base/dumpable.h"
#include "base/histogram-inl.h"
#include "base/stl_util.h"
+#include "base/systrace.h"
#include "base/time_utils.h"
#include "common_throws.h"
#include "cutils/sched_policy.h"
@@ -240,6 +238,7 @@
if (VLOG_IS_ON(heap) || VLOG_IS_ON(startup)) {
LOG(INFO) << "Heap() entering";
}
+ ScopedTrace trace(__FUNCTION__);
Runtime* const runtime = Runtime::Current();
// If we aren't the zygote, switch to the default non zygote allocator. This may update the
// entrypoints.
@@ -274,14 +273,12 @@
uint8_t* const original_requested_alloc_space_begin = requested_alloc_space_begin;
for (size_t index = 0; index < image_file_names.size(); ++index) {
std::string& image_name = image_file_names[index];
- ATRACE_BEGIN("ImageSpace::Create");
std::string error_msg;
space::ImageSpace* boot_image_space = space::ImageSpace::CreateBootImage(
image_name.c_str(),
image_instruction_set,
index > 0,
&error_msg);
- ATRACE_END();
if (boot_image_space != nullptr) {
AddSpace(boot_image_space);
added_image_spaces.push_back(boot_image_space);
@@ -373,8 +370,8 @@
}
std::string error_str;
std::unique_ptr<MemMap> non_moving_space_mem_map;
- ATRACE_BEGIN("Create heap maps");
if (separate_non_moving_space) {
+ ScopedTrace trace2("Create separate non moving space");
// If we are the zygote, the non moving space becomes the zygote space when we run
// PreZygoteFork the first time. In this case, call the map "zygote space" since we can't
// rename the mem map later.
@@ -391,6 +388,7 @@
}
// Attempt to create 2 mem maps at or after the requested begin.
if (foreground_collector_type_ != kCollectorTypeCC) {
+ ScopedTrace trace2("Create main mem map");
if (separate_non_moving_space || !is_zygote) {
main_mem_map_1.reset(MapAnonymousPreferredAddress(kMemMapSpaceName[0],
request_begin,
@@ -409,14 +407,15 @@
if (support_homogeneous_space_compaction ||
background_collector_type_ == kCollectorTypeSS ||
foreground_collector_type_ == kCollectorTypeSS) {
+ ScopedTrace trace2("Create main mem map 2");
main_mem_map_2.reset(MapAnonymousPreferredAddress(kMemMapSpaceName[1], main_mem_map_1->End(),
capacity_, &error_str));
CHECK(main_mem_map_2.get() != nullptr) << error_str;
}
- ATRACE_END();
- ATRACE_BEGIN("Create spaces");
+
// Create the non moving space first so that bitmaps don't take up the address range.
if (separate_non_moving_space) {
+ ScopedTrace trace2("Add non moving space");
// Non moving space is always dlmalloc since we currently don't have support for multiple
// active rosalloc spaces.
const size_t size = non_moving_space_mem_map->Size();
@@ -504,9 +503,7 @@
if (main_space_backup_.get() != nullptr) {
RemoveSpace(main_space_backup_.get());
}
- ATRACE_END();
// Allocate the card table.
- ATRACE_BEGIN("Create card table");
// We currently don't support dynamically resizing the card table.
// Since we don't know where in the low_4gb the app image will be located, make the card table
// cover the whole low_4gb. TODO: Extend the card table in AddSpace.
@@ -517,7 +514,6 @@
card_table_.reset(accounting::CardTable::Create(reinterpret_cast<uint8_t*>(kMinHeapAddress),
4 * GB - kMinHeapAddress));
CHECK(card_table_.get() != nullptr) << "Failed to create card table";
- ATRACE_END();
if (foreground_collector_type_ == kCollectorTypeCC && kUseTableLookupReadBarrier) {
rb_table_.reset(new accounting::ReadBarrierTable());
DCHECK(rb_table_->IsAllCleared());
@@ -1340,24 +1336,19 @@
void Heap::Trim(Thread* self) {
Runtime* const runtime = Runtime::Current();
if (!CareAboutPauseTimes()) {
- ATRACE_BEGIN("Deflating monitors");
// Deflate the monitors, this can cause a pause but shouldn't matter since we don't care
// about pauses.
- {
- ScopedSuspendAll ssa(__FUNCTION__);
- uint64_t start_time = NanoTime();
- size_t count = runtime->GetMonitorList()->DeflateMonitors();
- VLOG(heap) << "Deflating " << count << " monitors took "
- << PrettyDuration(NanoTime() - start_time);
- }
- ATRACE_END();
+ ScopedTrace trace("Deflating monitors");
+ ScopedSuspendAll ssa(__FUNCTION__);
+ uint64_t start_time = NanoTime();
+ size_t count = runtime->GetMonitorList()->DeflateMonitors();
+ VLOG(heap) << "Deflating " << count << " monitors took "
+ << PrettyDuration(NanoTime() - start_time);
}
TrimIndirectReferenceTables(self);
TrimSpaces(self);
// Trim arenas that may have been used by JIT or verifier.
- ATRACE_BEGIN("Trimming arena maps");
runtime->GetArenaPool()->TrimMaps();
- ATRACE_END();
}
class TrimIndirectReferenceTableClosure : public Closure {
@@ -1365,9 +1356,7 @@
explicit TrimIndirectReferenceTableClosure(Barrier* barrier) : barrier_(barrier) {
}
virtual void Run(Thread* thread) OVERRIDE NO_THREAD_SAFETY_ANALYSIS {
- ATRACE_BEGIN("Trimming reference table");
thread->GetJniEnv()->locals.Trim();
- ATRACE_END();
// If thread is a running mutator, then act on behalf of the trim thread.
// See the code in ThreadList::RunCheckpoint.
barrier_->Pass(Thread::Current());
@@ -1379,7 +1368,7 @@
void Heap::TrimIndirectReferenceTables(Thread* self) {
ScopedObjectAccess soa(self);
- ATRACE_BEGIN(__FUNCTION__);
+ ScopedTrace trace(__PRETTY_FUNCTION__);
JavaVMExt* vm = soa.Vm();
// Trim globals indirect reference table.
vm->TrimGlobals();
@@ -1391,7 +1380,6 @@
if (barrier_count != 0) {
barrier.Increment(self, barrier_count);
}
- ATRACE_END();
}
void Heap::StartGC(Thread* self, GcCause cause, CollectorType collector_type) {
@@ -1410,7 +1398,7 @@
// trimming.
StartGC(self, kGcCauseTrim, kCollectorTypeHeapTrim);
}
- ATRACE_BEGIN(__FUNCTION__);
+ ScopedTrace trace(__PRETTY_FUNCTION__);
const uint64_t start_ns = NanoTime();
// Trim the managed spaces.
uint64_t total_alloc_space_allocated = 0;
@@ -1449,7 +1437,6 @@
VLOG(heap) << "Heap trim of managed (duration=" << PrettyDuration(gc_heap_end_ns - start_ns)
<< ", advised=" << PrettySize(managed_reclaimed) << ") heap. Managed heap utilization of "
<< static_cast<int>(100 * managed_utilization) << "%.";
- ATRACE_END();
}
bool Heap::IsValidObjectAddress(const mirror::Object* obj) const {
@@ -3434,11 +3421,10 @@
running_collection_is_blocking_ = true;
VLOG(gc) << "Waiting for a blocking GC " << cause;
}
- ATRACE_BEGIN("GC: Wait For Completion");
+ ScopedTrace trace("GC: Wait For Completion");
// We must wait, change thread state then sleep on gc_complete_cond_;
gc_complete_cond_->Wait(self);
last_gc_type = last_gc_type_;
- ATRACE_END();
}
uint64_t wait_time = NanoTime() - wait_start;
total_wait_time_ += wait_time;
diff --git a/runtime/gc/space/image_space.cc b/runtime/gc/space/image_space.cc
index 6b65b73..b3a8e84 100644
--- a/runtime/gc/space/image_space.cc
+++ b/runtime/gc/space/image_space.cc
@@ -26,6 +26,7 @@
#include "base/macros.h"
#include "base/stl_util.h"
#include "base/scoped_flock.h"
+#include "base/systrace.h"
#include "base/time_utils.h"
#include "gc/accounting/space_bitmap-inl.h"
#include "image-inl.h"
@@ -371,6 +372,7 @@
const InstructionSet image_isa,
bool secondary_image,
std::string* error_msg) {
+ ScopedTrace trace(__FUNCTION__);
std::string system_filename;
bool has_system = false;
std::string cache_filename;
@@ -1091,7 +1093,7 @@
CHECK(image_filename != nullptr);
CHECK(image_location != nullptr);
- TimingLogger logger(__FUNCTION__, true, false);
+ TimingLogger logger(__PRETTY_FUNCTION__, true, VLOG_IS_ON(image));
VLOG(image) << "ImageSpace::Init entering image_filename=" << image_filename;
std::unique_ptr<File> file;
diff --git a/runtime/gc/space/rosalloc_space.cc b/runtime/gc/space/rosalloc_space.cc
index fd4d0a1..203d3bc 100644
--- a/runtime/gc/space/rosalloc_space.cc
+++ b/runtime/gc/space/rosalloc_space.cc
@@ -17,9 +17,6 @@
#include "rosalloc_space-inl.h"
-#define ATRACE_TAG ATRACE_TAG_DALVIK
-#include "cutils/trace.h"
-
#include "base/time_utils.h"
#include "gc/accounting/card_table.h"
#include "gc/accounting/space_bitmap-inl.h"
diff --git a/runtime/indirect_reference_table.cc b/runtime/indirect_reference_table.cc
index a5b63b4..8e49492 100644
--- a/runtime/indirect_reference_table.cc
+++ b/runtime/indirect_reference_table.cc
@@ -16,6 +16,7 @@
#include "indirect_reference_table-inl.h"
+#include "base/systrace.h"
#include "jni_internal.h"
#include "nth_caller_visitor.h"
#include "reference_table.h"
@@ -261,6 +262,7 @@
}
void IndirectReferenceTable::Trim() {
+ ScopedTrace trace(__PRETTY_FUNCTION__);
const size_t top_index = Capacity();
auto* release_start = AlignUp(reinterpret_cast<uint8_t*>(&table_[top_index]), kPageSize);
uint8_t* release_end = table_mem_map_->End();
diff --git a/runtime/java_vm_ext.cc b/runtime/java_vm_ext.cc
index 191c0c7..a41fd45 100644
--- a/runtime/java_vm_ext.cc
+++ b/runtime/java_vm_ext.cc
@@ -16,15 +16,13 @@
#include "jni_internal.h"
-#define ATRACE_TAG ATRACE_TAG_DALVIK
-
-#include <cutils/trace.h>
#include <dlfcn.h>
#include "art_method.h"
#include "base/dumpable.h"
#include "base/mutex.h"
#include "base/stl_util.h"
+#include "base/systrace.h"
#include "check_jni.h"
#include "dex_file-inl.h"
#include "fault_handler.h"
@@ -929,11 +927,10 @@
// JNI Invocation interface.
extern "C" jint JNI_CreateJavaVM(JavaVM** p_vm, JNIEnv** p_env, void* vm_args) {
- ATRACE_BEGIN(__FUNCTION__);
+ ScopedTrace trace(__FUNCTION__);
const JavaVMInitArgs* args = static_cast<JavaVMInitArgs*>(vm_args);
if (IsBadJniVersion(args->version)) {
LOG(ERROR) << "Bad JNI version passed to CreateJavaVM: " << args->version;
- ATRACE_END();
return JNI_EVERSION;
}
RuntimeOptions options;
@@ -943,7 +940,6 @@
}
bool ignore_unrecognized = args->ignoreUnrecognized;
if (!Runtime::Create(options, ignore_unrecognized)) {
- ATRACE_END();
return JNI_ERR;
}
Runtime* runtime = Runtime::Current();
@@ -952,12 +948,10 @@
delete Thread::Current()->GetJniEnv();
delete runtime->GetJavaVM();
LOG(WARNING) << "CreateJavaVM failed";
- ATRACE_END();
return JNI_ERR;
}
*p_env = Thread::Current()->GetJniEnv();
*p_vm = runtime->GetJavaVM();
- ATRACE_END();
return JNI_OK;
}
diff --git a/runtime/jit/jit_code_cache.cc b/runtime/jit/jit_code_cache.cc
index e041a42..63a941a 100644
--- a/runtime/jit/jit_code_cache.cc
+++ b/runtime/jit/jit_code_cache.cc
@@ -20,6 +20,7 @@
#include "art_method-inl.h"
#include "base/stl_util.h"
+#include "base/systrace.h"
#include "base/time_utils.h"
#include "debugger_interface.h"
#include "entrypoints/runtime_asm_entrypoints.h"
@@ -51,6 +52,7 @@
size_t max_capacity,
bool generate_debug_info,
std::string* error_msg) {
+ ScopedTrace trace(__PRETTY_FUNCTION__);
CHECK_GE(max_capacity, initial_capacity);
// Generating debug information is mostly for using the 'perf' tool, which does
@@ -252,6 +254,7 @@
}
void JitCodeCache::RemoveMethodsIn(Thread* self, const LinearAlloc& alloc) {
+ ScopedTrace trace(__PRETTY_FUNCTION__);
MutexLock mu(self, lock_);
// We do not check if a code cache GC is in progress, as this method comes
// with the classlinker_classes_lock_ held, and suspending ourselves could
@@ -464,6 +467,7 @@
: code_cache_(code_cache), barrier_(barrier) {}
void Run(Thread* thread) OVERRIDE SHARED_REQUIRES(Locks::mutator_lock_) {
+ ScopedTrace trace(__PRETTY_FUNCTION__);
DCHECK(thread == Thread::Current() || thread->IsSuspended());
MarkCodeVisitor visitor(thread, code_cache_);
visitor.WalkStack();
@@ -564,6 +568,7 @@
}
void JitCodeCache::GarbageCollectCache(Thread* self) {
+ ScopedTrace trace(__FUNCTION__);
if (!garbage_collect_code_) {
MutexLock mu(self, lock_);
IncreaseCodeCacheCapacity();
@@ -645,6 +650,7 @@
}
void JitCodeCache::RemoveUnusedAndUnmarkedCode(Thread* self) {
+ ScopedTrace trace(__FUNCTION__);
MutexLock mu(self, lock_);
ScopedCodeCacheWrite scc(code_map_.get());
// Iterate over all compiled code and remove entries that are not marked and not
@@ -668,6 +674,7 @@
}
void JitCodeCache::DoCollection(Thread* self, bool collect_profiling_info) {
+ ScopedTrace trace(__FUNCTION__);
{
MutexLock mu(self, lock_);
if (collect_profiling_info) {
@@ -730,6 +737,7 @@
}
bool JitCodeCache::CheckLiveCompiledCodeHasProfilingInfo() {
+ ScopedTrace trace(__FUNCTION__);
// Check that methods we have compiled do have a ProfilingInfo object. We would
// have memory leaks of compiled code otherwise.
for (const auto& it : method_code_map_) {
@@ -845,6 +853,7 @@
void JitCodeCache::GetCompiledArtMethods(const std::set<std::string>& dex_base_locations,
std::vector<ArtMethod*>& methods) {
+ ScopedTrace trace(__FUNCTION__);
MutexLock mu(Thread::Current(), lock_);
for (auto it : method_code_map_) {
if (ContainsElement(dex_base_locations, it.second->GetDexFile()->GetBaseLocation())) {
diff --git a/runtime/jit/offline_profiling_info.cc b/runtime/jit/offline_profiling_info.cc
index 67c9b5f..ecf34f5 100644
--- a/runtime/jit/offline_profiling_info.cc
+++ b/runtime/jit/offline_profiling_info.cc
@@ -26,6 +26,7 @@
#include "base/mutex.h"
#include "base/scoped_flock.h"
#include "base/stl_util.h"
+#include "base/systrace.h"
#include "base/unix_file/fd_file.h"
#include "jit/profiling_info.h"
#include "os.h"
@@ -57,6 +58,7 @@
return true;
}
+ ScopedTrace trace(__PRETTY_FUNCTION__);
ScopedFlock flock;
std::string error;
if (!flock.Init(filename.c_str(), O_RDWR | O_NOFOLLOW | O_CLOEXEC, /* block */ false, &error)) {
@@ -132,6 +134,7 @@
* app.apk:classes5.dex,218490184,39,13,49,1
**/
bool ProfileCompilationInfo::Save(int fd) {
+ ScopedTrace trace(__PRETTY_FUNCTION__);
DCHECK_GE(fd, 0);
// TODO(calin): Profile this and see how much memory it takes. If too much,
// write to file directly.
@@ -298,6 +301,7 @@
}
bool ProfileCompilationInfo::Load(int fd) {
+ ScopedTrace trace(__PRETTY_FUNCTION__);
DCHECK_GE(fd, 0);
std::string current_line;
diff --git a/runtime/jit/profile_saver.cc b/runtime/jit/profile_saver.cc
index 5abfa6c..8dc696f 100644
--- a/runtime/jit/profile_saver.cc
+++ b/runtime/jit/profile_saver.cc
@@ -21,6 +21,7 @@
#include <fcntl.h>
#include "art_method-inl.h"
+#include "base/systrace.h"
#include "scoped_thread_state_change.h"
#include "oat_file_manager.h"
@@ -114,6 +115,7 @@
}
bool ProfileSaver::ProcessProfilingInfo() {
+ ScopedTrace trace(__PRETTY_FUNCTION__);
uint64_t last_update_time_ns = jit_code_cache_->GetLastUpdateTimeNs();
if (!first_profile_ && last_update_time_ns - code_cache_last_update_time_ns_
< kMinimumTimeBetweenCodeCacheUpdatesNs) {
diff --git a/runtime/monitor.cc b/runtime/monitor.cc
index 19c71f6..1ce5841 100644
--- a/runtime/monitor.cc
+++ b/runtime/monitor.cc
@@ -16,14 +16,12 @@
#include "monitor.h"
-#define ATRACE_TAG ATRACE_TAG_DALVIK
-
-#include <cutils/trace.h>
#include <vector>
#include "art_method-inl.h"
#include "base/mutex.h"
#include "base/stl_util.h"
+#include "base/systrace.h"
#include "base/time_utils.h"
#include "class_linker.h"
#include "dex_file-inl.h"
diff --git a/runtime/oat_file.cc b/runtime/oat_file.cc
index 49fbf72..c0f5906 100644
--- a/runtime/oat_file.cc
+++ b/runtime/oat_file.cc
@@ -35,6 +35,7 @@
#include "art_method-inl.h"
#include "base/bit_vector.h"
#include "base/stl_util.h"
+#include "base/systrace.h"
#include "base/unix_file/fd_file.h"
#include "elf_file.h"
#include "elf_utils.h"
@@ -746,6 +747,7 @@
bool executable,
const char* abs_dex_location,
std::string* error_msg) {
+ ScopedTrace trace("Open elf file " + location);
std::unique_ptr<ElfOatFile> oat_file(new ElfOatFile(location, executable));
bool success = oat_file->ElfFileOpen(file, oat_file_begin, writable, executable, error_msg);
if (!success) {
@@ -768,6 +770,7 @@
bool ElfOatFile::InitializeFromElfFile(ElfFile* elf_file,
const char* abs_dex_location,
std::string* error_msg) {
+ ScopedTrace trace(__PRETTY_FUNCTION__);
if (IsExecutable()) {
*error_msg = "Cannot initialize from elf file in executable mode.";
return false;
@@ -787,6 +790,7 @@
bool writable,
bool executable,
std::string* error_msg) {
+ ScopedTrace trace(__PRETTY_FUNCTION__);
std::unique_ptr<File> file(OS::OpenFileForReading(elf_filename.c_str()));
if (file == nullptr) {
*error_msg = StringPrintf("Failed to open oat filename for reading: %s", strerror(errno));
@@ -804,6 +808,7 @@
bool writable,
bool executable,
std::string* error_msg) {
+ ScopedTrace trace(__PRETTY_FUNCTION__);
// TODO: rename requested_base to oat_data_begin
elf_file_.reset(ElfFile::Open(file,
writable,
@@ -864,6 +869,7 @@
bool executable,
const char* abs_dex_location,
std::string* error_msg) {
+ ScopedTrace trace("Open oat file " + location);
CHECK(!filename.empty()) << location;
CheckLocation(location);
std::unique_ptr<OatFile> ret;
@@ -1072,6 +1078,7 @@
}
std::unique_ptr<const DexFile> OatFile::OatDexFile::OpenDexFile(std::string* error_msg) const {
+ ScopedTrace trace(__PRETTY_FUNCTION__);
return DexFile::Open(dex_file_pointer_,
FileSize(),
dex_file_location_,
diff --git a/runtime/oat_file_manager.cc b/runtime/oat_file_manager.cc
index 0912ba0..e57125b 100644
--- a/runtime/oat_file_manager.cc
+++ b/runtime/oat_file_manager.cc
@@ -16,14 +16,13 @@
#include "oat_file_manager.h"
-#define ATRACE_TAG ATRACE_TAG_DALVIK
-#include <cutils/trace.h>
#include <memory>
#include <queue>
#include <vector>
#include "base/logging.h"
#include "base/stl_util.h"
+#include "base/systrace.h"
#include "class_linker.h"
#include "dex_file-inl.h"
#include "gc/scoped_gc_critical_section.h"
@@ -299,6 +298,7 @@
jobjectArray dex_elements,
const OatFile** out_oat_file,
std::vector<std::string>* error_msgs) {
+ ScopedTrace trace(__FUNCTION__);
CHECK(dex_location != nullptr);
CHECK(error_msgs != nullptr);
@@ -393,14 +393,15 @@
ScopedSuspendAll ssa("Add image space");
runtime->GetHeap()->AddSpace(image_space.get());
}
- ATRACE_BEGIN(StringPrintf("Adding image space for location %s", dex_location).c_str());
- added_image_space = runtime->GetClassLinker()->AddImageSpace(image_space.get(),
- h_loader,
- dex_elements,
- dex_location,
- /*out*/&dex_files,
- /*out*/&temp_error_msg);
- ATRACE_END();
+ {
+ ScopedTrace trace2(StringPrintf("Adding image space for location %s", dex_location));
+ added_image_space = runtime->GetClassLinker()->AddImageSpace(image_space.get(),
+ h_loader,
+ dex_elements,
+ dex_location,
+ /*out*/&dex_files,
+ /*out*/&temp_error_msg);
+ }
if (added_image_space) {
// Successfully added image space to heap, release the map so that it does not get
// freed.
diff --git a/runtime/runtime.cc b/runtime/runtime.cc
index 4a8ed9e..b23bd66 100644
--- a/runtime/runtime.cc
+++ b/runtime/runtime.cc
@@ -23,8 +23,6 @@
#include <sys/prctl.h>
#endif
-#define ATRACE_TAG ATRACE_TAG_DALVIK
-#include <cutils/trace.h>
#include <signal.h>
#include <sys/syscall.h>
#include "base/memory_tool.h"
@@ -58,6 +56,7 @@
#include "base/arena_allocator.h"
#include "base/dumpable.h"
#include "base/stl_util.h"
+#include "base/systrace.h"
#include "base/unix_file/fd_file.h"
#include "class_linker-inl.h"
#include "compiler_callbacks.h"
@@ -216,7 +215,7 @@
}
Runtime::~Runtime() {
- ATRACE_BEGIN("Runtime shutdown");
+ ScopedTrace trace("Runtime shutdown");
if (is_native_bridge_loaded_) {
UnloadNativeBridge();
}
@@ -231,40 +230,34 @@
Thread* self = Thread::Current();
const bool attach_shutdown_thread = self == nullptr;
if (attach_shutdown_thread) {
- ATRACE_BEGIN("Attach shutdown thread");
CHECK(AttachCurrentThread("Shutdown thread", false, nullptr, false));
- ATRACE_END();
self = Thread::Current();
} else {
LOG(WARNING) << "Current thread not detached in Runtime shutdown";
}
{
- ATRACE_BEGIN("Wait for shutdown cond");
+ ScopedTrace trace2("Wait for shutdown cond");
MutexLock mu(self, *Locks::runtime_shutdown_lock_);
shutting_down_started_ = true;
while (threads_being_born_ > 0) {
shutdown_cond_->Wait(self);
}
shutting_down_ = true;
- ATRACE_END();
}
// Shutdown and wait for the daemons.
CHECK(self != nullptr);
if (IsFinishedStarting()) {
- ATRACE_BEGIN("Waiting for Daemons");
+ ScopedTrace trace2("Waiting for Daemons");
self->ClearException();
self->GetJniEnv()->CallStaticVoidMethod(WellKnownClasses::java_lang_Daemons,
WellKnownClasses::java_lang_Daemons_stop);
- ATRACE_END();
}
Trace::Shutdown();
if (attach_shutdown_thread) {
- ATRACE_BEGIN("Detach shutdown thread");
DetachCurrentThread();
- ATRACE_END();
self = nullptr;
}
@@ -272,14 +265,13 @@
heap_->WaitForGcToComplete(gc::kGcCauseBackground, self);
heap_->DeleteThreadPool();
if (jit_ != nullptr) {
- ATRACE_BEGIN("Delete jit");
+ ScopedTrace trace2("Delete jit");
VLOG(jit) << "Deleting jit thread pool";
// Delete thread pool before the thread list since we don't want to wait forever on the
// JIT compiler threads.
jit_->DeleteThreadPool();
// Similarly, stop the profile saver thread before deleting the thread list.
jit_->StopProfileSaver();
- ATRACE_END();
}
// Make sure our internal threads are dead before we start tearing down things they're using.
@@ -287,10 +279,10 @@
delete signal_catcher_;
// Make sure all other non-daemon threads have terminated, and all daemon threads are suspended.
- ATRACE_BEGIN("Delete thread list");
- delete thread_list_;
- ATRACE_END();
-
+ {
+ ScopedTrace trace2("Delete thread list");
+ delete thread_list_;
+ }
// Delete the JIT after thread list to ensure that there is no remaining threads which could be
// accessing the instrumentation when we delete it.
if (jit_ != nullptr) {
@@ -301,7 +293,7 @@
// Shutdown the fault manager if it was initialized.
fault_manager.Shutdown();
- ATRACE_BEGIN("Delete state");
+ ScopedTrace trace2("Delete state");
delete monitor_list_;
delete monitor_pool_;
delete class_linker_;
@@ -318,12 +310,10 @@
low_4gb_arena_pool_.reset();
arena_pool_.reset();
MemMap::Shutdown();
- ATRACE_END();
// TODO: acquire a static mutex on Runtime to avoid racing.
CHECK(instance_ == nullptr || instance_ == this);
instance_ = nullptr;
- ATRACE_END();
}
struct AbortState {
@@ -562,12 +552,14 @@
// Use !IsAotCompiler so that we get test coverage, tests are never the zygote.
if (!IsAotCompiler()) {
ScopedObjectAccess soa(self);
- ATRACE_BEGIN("AddImageStringsToTable");
- GetInternTable()->AddImagesStringsToTable(heap_->GetBootImageSpaces());
- ATRACE_END();
- ATRACE_BEGIN("MoveImageClassesToClassTable");
- GetClassLinker()->AddBootImageClassesToClassTable();
- ATRACE_END();
+ {
+ ScopedTrace trace2("AddImageStringsToTable");
+ GetInternTable()->AddImagesStringsToTable(heap_->GetBootImageSpaces());
+ }
+ {
+ ScopedTrace trace2("MoveImageClassesToClassTable");
+ GetClassLinker()->AddBootImageClassesToClassTable();
+ }
}
// If we are the zygote then we need to wait until after forking to create the code cache
@@ -585,9 +577,10 @@
// InitNativeMethods needs to be after started_ so that the classes
// it touches will have methods linked to the oat file if necessary.
- ATRACE_BEGIN("InitNativeMethods");
- InitNativeMethods();
- ATRACE_END();
+ {
+ ScopedTrace trace2("InitNativeMethods");
+ InitNativeMethods();
+ }
// Initialize well known thread group values that may be accessed threads while attaching.
InitThreadGroups(self);
@@ -613,9 +606,7 @@
GetInstructionSetString(kRuntimeISA));
}
- ATRACE_BEGIN("StartDaemonThreads");
StartDaemonThreads();
- ATRACE_END();
{
ScopedObjectAccess soa(self);
@@ -750,6 +741,7 @@
}
void Runtime::StartDaemonThreads() {
+ ScopedTrace trace(__FUNCTION__);
VLOG(startup) << "Runtime::StartDaemonThreads entering";
Thread* self = Thread::Current();
@@ -893,7 +885,7 @@
bool Runtime::Init(RuntimeArgumentMap&& runtime_options_in) {
RuntimeArgumentMap runtime_options(std::move(runtime_options_in));
- ATRACE_BEGIN("Runtime::Init");
+ ScopedTrace trace(__FUNCTION__);
CHECK_EQ(sysconf(_SC_PAGE_SIZE), kPageSize);
MemMap::Init();
@@ -960,7 +952,6 @@
is_low_memory_mode_ = runtime_options.Exists(Opt::LowMemoryMode);
XGcOption xgc_option = runtime_options.GetOrDefault(Opt::GcOption);
- ATRACE_BEGIN("CreateHeap");
heap_ = new gc::Heap(runtime_options.GetOrDefault(Opt::MemoryInitialSize),
runtime_options.GetOrDefault(Opt::HeapGrowthLimit),
runtime_options.GetOrDefault(Opt::HeapMinFree),
@@ -991,11 +982,9 @@
xgc_option.gcstress_,
runtime_options.GetOrDefault(Opt::EnableHSpaceCompactForOOM),
runtime_options.GetOrDefault(Opt::HSpaceCompactForOOMMinIntervalsMs));
- ATRACE_END();
if (!heap_->HasBootImageSpace() && !allow_dex_file_fallback_) {
LOG(ERROR) << "Dex file fallback disabled, cannot continue without image.";
- ATRACE_END();
return false;
}
@@ -1102,10 +1091,8 @@
CHECK_GE(GetHeap()->GetContinuousSpaces().size(), 1U);
class_linker_ = new ClassLinker(intern_table_);
if (GetHeap()->HasBootImageSpace()) {
- ATRACE_BEGIN("InitFromImage");
std::string error_msg;
bool result = class_linker_->InitFromBootImage(&error_msg);
- ATRACE_END();
if (!result) {
LOG(ERROR) << "Could not initialize from image: " << error_msg;
return false;
@@ -1248,8 +1235,6 @@
VLOG(startup) << "Runtime::Init exiting";
- ATRACE_END();
-
return true;
}
@@ -1465,10 +1450,12 @@
bool Runtime::AttachCurrentThread(const char* thread_name, bool as_daemon, jobject thread_group,
bool create_peer) {
+ ScopedTrace trace(__FUNCTION__);
return Thread::Attach(thread_name, as_daemon, thread_group, create_peer) != nullptr;
}
void Runtime::DetachCurrentThread() {
+ ScopedTrace trace(__FUNCTION__);
Thread* self = Thread::Current();
if (self == nullptr) {
LOG(FATAL) << "attempting to detach thread that is not attached";
diff --git a/runtime/thread.cc b/runtime/thread.cc
index 2ee1605..6b8c0c2 100644
--- a/runtime/thread.cc
+++ b/runtime/thread.cc
@@ -14,11 +14,8 @@
* limitations under the License.
*/
-#define ATRACE_TAG ATRACE_TAG_DALVIK
-
#include "thread.h"
-#include <cutils/trace.h>
#include <pthread.h>
#include <signal.h>
#include <sys/resource.h>
@@ -39,6 +36,7 @@
#include "base/mutex.h"
#include "base/timing_logger.h"
#include "base/to_str.h"
+#include "base/systrace.h"
#include "class_linker-inl.h"
#include "debugger.h"
#include "dex_file-inl.h"
@@ -1119,9 +1117,8 @@
bool found_checkpoint = false;
for (uint32_t i = 0; i < kMaxCheckpoints; ++i) {
if (checkpoints[i] != nullptr) {
- ATRACE_BEGIN("Checkpoint function");
+ ScopedTrace trace("Run checkpoint function");
checkpoints[i]->Run(this);
- ATRACE_END();
found_checkpoint = true;
}
}
@@ -1187,14 +1184,13 @@
}
void Thread::FullSuspendCheck() {
+ ScopedTrace trace(__FUNCTION__);
VLOG(threads) << this << " self-suspending";
- ATRACE_BEGIN("Full suspend check");
// Make thread appear suspended to other threads, release mutator_lock_.
tls32_.suspended_at_suspend_check = true;
// Transition to suspended and back to runnable, re-acquire share on mutator_lock_.
ScopedThreadSuspension(this, kSuspended);
tls32_.suspended_at_suspend_check = false;
- ATRACE_END();
VLOG(threads) << this << " self-reviving";
}
diff --git a/runtime/thread_list.cc b/runtime/thread_list.cc
index 49d54fd..cf515b6 100644
--- a/runtime/thread_list.cc
+++ b/runtime/thread_list.cc
@@ -16,10 +16,7 @@
#include "thread_list.h"
-#define ATRACE_TAG ATRACE_TAG_DALVIK
-
#include <backtrace/BacktraceMap.h>
-#include <cutils/trace.h>
#include <dirent.h>
#include <ScopedLocalRef.h>
#include <ScopedUtfChars.h>
@@ -30,6 +27,7 @@
#include "base/histogram-inl.h"
#include "base/mutex-inl.h"
+#include "base/systrace.h"
#include "base/time_utils.h"
#include "base/timing_logger.h"
#include "debugger.h"
@@ -69,38 +67,29 @@
}
ThreadList::~ThreadList() {
- ATRACE_BEGIN(__FUNCTION__);
+ ScopedTrace trace(__PRETTY_FUNCTION__);
// Detach the current thread if necessary. If we failed to start, there might not be any threads.
// We need to detach the current thread here in case there's another thread waiting to join with
// us.
bool contains = false;
+ Thread* self = Thread::Current();
{
- Thread* self = Thread::Current();
MutexLock mu(self, *Locks::thread_list_lock_);
contains = Contains(self);
}
if (contains) {
- ATRACE_BEGIN("DetachCurrentThread");
Runtime::Current()->DetachCurrentThread();
- ATRACE_END();
}
- ATRACE_BEGIN("WaitForOtherNonDaemonThreadsToExit");
WaitForOtherNonDaemonThreadsToExit();
- ATRACE_END();
// Disable GC and wait for GC to complete in case there are still daemon threads doing
// allocations.
gc::Heap* const heap = Runtime::Current()->GetHeap();
heap->DisableGCForShutdown();
// In case a GC is in progress, wait for it to finish.
- ATRACE_BEGIN("WaitForGcToComplete");
heap->WaitForGcToComplete(gc::kGcCauseBackground, Thread::Current());
- ATRACE_END();
// TODO: there's an unaddressed race here where a thread may attach during shutdown, see
// Thread::Init.
- ATRACE_BEGIN("SuspendAllDaemonThreadsForShutdown");
SuspendAllDaemonThreadsForShutdown();
- ATRACE_END();
- ATRACE_END();
}
bool ThreadList::Contains(Thread* thread) {
@@ -475,42 +464,42 @@
} else {
VLOG(threads) << "Thread[null] SuspendAll for " << cause << " starting...";
}
- ATRACE_BEGIN("Suspending mutator threads");
- const uint64_t start_time = NanoTime();
+ {
+ ScopedTrace trace("Suspending mutator threads");
+ const uint64_t start_time = NanoTime();
- SuspendAllInternal(self, self);
- // All threads are known to have suspended (but a thread may still own the mutator lock)
- // Make sure this thread grabs exclusive access to the mutator lock and its protected data.
+ SuspendAllInternal(self, self);
+ // All threads are known to have suspended (but a thread may still own the mutator lock)
+ // Make sure this thread grabs exclusive access to the mutator lock and its protected data.
#if HAVE_TIMED_RWLOCK
- while (true) {
- if (Locks::mutator_lock_->ExclusiveLockWithTimeout(self, kThreadSuspendTimeoutMs, 0)) {
- break;
- } else if (!long_suspend_) {
- // Reading long_suspend without the mutator lock is slightly racy, in some rare cases, this
- // could result in a thread suspend timeout.
- // Timeout if we wait more than kThreadSuspendTimeoutMs seconds.
- UnsafeLogFatalForThreadSuspendAllTimeout();
+ while (true) {
+ if (Locks::mutator_lock_->ExclusiveLockWithTimeout(self, kThreadSuspendTimeoutMs, 0)) {
+ break;
+ } else if (!long_suspend_) {
+ // Reading long_suspend without the mutator lock is slightly racy, in some rare cases, this
+ // could result in a thread suspend timeout.
+ // Timeout if we wait more than kThreadSuspendTimeoutMs seconds.
+ UnsafeLogFatalForThreadSuspendAllTimeout();
+ }
}
- }
#else
- Locks::mutator_lock_->ExclusiveLock(self);
+ Locks::mutator_lock_->ExclusiveLock(self);
#endif
- long_suspend_ = long_suspend;
+ long_suspend_ = long_suspend;
- const uint64_t end_time = NanoTime();
- const uint64_t suspend_time = end_time - start_time;
- suspend_all_historam_.AdjustAndAddValue(suspend_time);
- if (suspend_time > kLongThreadSuspendThreshold) {
- LOG(WARNING) << "Suspending all threads took: " << PrettyDuration(suspend_time);
+ const uint64_t end_time = NanoTime();
+ const uint64_t suspend_time = end_time - start_time;
+ suspend_all_historam_.AdjustAndAddValue(suspend_time);
+ if (suspend_time > kLongThreadSuspendThreshold) {
+ LOG(WARNING) << "Suspending all threads took: " << PrettyDuration(suspend_time);
+ }
+
+ if (kDebugLocking) {
+ // Debug check that all threads are suspended.
+ AssertThreadsAreSuspended(self, self);
+ }
}
-
- if (kDebugLocking) {
- // Debug check that all threads are suspended.
- AssertThreadsAreSuspended(self, self);
- }
-
- ATRACE_END();
ATRACE_BEGIN((std::string("Mutator threads suspended for ") + cause).c_str());
if (self != nullptr) {
@@ -640,7 +629,8 @@
}
ATRACE_END();
- ATRACE_BEGIN("Resuming mutator threads");
+
+ ScopedTrace trace("Resuming mutator threads");
if (kDebugLocking) {
// Debug check that all threads are suspended.
@@ -672,7 +662,6 @@
}
Thread::resume_cond_->Broadcast(self);
}
- ATRACE_END();
if (self != nullptr) {
VLOG(threads) << *self << " ResumeAll complete";
@@ -1117,6 +1106,7 @@
}
void ThreadList::WaitForOtherNonDaemonThreadsToExit() {
+ ScopedTrace trace(__PRETTY_FUNCTION__);
Thread* self = Thread::Current();
Locks::mutator_lock_->AssertNotHeld(self);
while (true) {
@@ -1148,6 +1138,7 @@
}
void ThreadList::SuspendAllDaemonThreadsForShutdown() {
+ ScopedTrace trace(__PRETTY_FUNCTION__);
Thread* self = Thread::Current();
MutexLock mu(self, *Locks::thread_list_lock_);
size_t daemons_left = 0;
diff --git a/runtime/trace.cc b/runtime/trace.cc
index 99b2296..b9d6a4a 100644
--- a/runtime/trace.cc
+++ b/runtime/trace.cc
@@ -19,12 +19,10 @@
#include <sys/uio.h>
#include <unistd.h>
-#define ATRACE_TAG ATRACE_TAG_DALVIK
-#include "cutils/trace.h"
-
#include "art_method-inl.h"
#include "base/casts.h"
#include "base/stl_util.h"
+#include "base/systrace.h"
#include "base/time_utils.h"
#include "base/unix_file/fd_file.h"
#include "class_linker.h"
@@ -286,7 +284,7 @@
while (true) {
usleep(interval_us);
- ATRACE_BEGIN("Profile sampling");
+ ScopedTrace trace("Profile sampling");
Thread* self = Thread::Current();
Trace* the_trace;
{
@@ -301,7 +299,6 @@
MutexLock mu(self, *Locks::thread_list_lock_);
runtime->GetThreadList()->ForEach(GetSample, the_trace);
}
- ATRACE_END();
}
runtime->DetachCurrentThread();
diff --git a/runtime/verifier/method_verifier.cc b/runtime/verifier/method_verifier.cc
index f71ebfe..4019656 100644
--- a/runtime/verifier/method_verifier.cc
+++ b/runtime/verifier/method_verifier.cc
@@ -16,9 +16,6 @@
#include "method_verifier-inl.h"
-#define ATRACE_TAG ATRACE_TAG_DALVIK
-#include <cutils/trace.h>
-
#include <iostream>
#include "art_field-inl.h"
@@ -26,6 +23,7 @@
#include "base/logging.h"
#include "base/mutex-inl.h"
#include "base/stl_util.h"
+#include "base/systrace.h"
#include "base/time_utils.h"
#include "class_linker.h"
#include "compiler_callbacks.h"
@@ -272,6 +270,7 @@
bool log_hard_failures,
std::string* error) {
DCHECK(class_def != nullptr);
+ ScopedTrace trace(__FUNCTION__);
// A class must not be abstract and final.
if ((class_def->access_flags_ & (kAccAbstract | kAccFinal)) == (kAccAbstract | kAccFinal)) {
@@ -286,7 +285,6 @@
// empty class, probably a marker interface
return kNoFailure;
}
- ATRACE_BEGIN("VerifyClass");
ClassDataItemIterator it(*dex_file, class_data);
while (it.HasNextStaticField() || it.HasNextInstanceField()) {
it.Next();
@@ -321,8 +319,6 @@
data1.Merge(data2);
- ATRACE_END();
-
if (data1.kind == kNoFailure) {
return kNoFailure;
} else {