summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
Diffstat
-rw-r--r--runtime/thread.cc13
-rw-r--r--runtime/thread.h3
-rw-r--r--runtime/trace.cc60
-rw-r--r--runtime/trace.h14
-rw-r--r--runtime/trace_common.h40
-rw-r--r--runtime/trace_profile.cc6
6 files changed, 75 insertions, 61 deletions
diff --git a/runtime/thread.cc b/runtime/thread.cc
index 50f6bfc499..89465979da 100644
--- a/runtime/thread.cc
+++ b/runtime/thread.cc
@@ -1485,12 +1485,21 @@ void Thread::GetThreadName(std::string& name) const {
uint64_t Thread::GetCpuMicroTime() const {
#if defined(__linux__)
+ return Thread::GetCpuNanoTime() / 1000;
+#else // __APPLE__
+ UNIMPLEMENTED(WARNING);
+ return -1;
+#endif
+}
+
+uint64_t Thread::GetCpuNanoTime() const {
+#if defined(__linux__)
clockid_t cpu_clock_id;
pthread_getcpuclockid(tlsPtr_.pthread_self, &cpu_clock_id);
timespec now;
clock_gettime(cpu_clock_id, &now);
- return static_cast<uint64_t>(now.tv_sec) * UINT64_C(1000000) +
- static_cast<uint64_t>(now.tv_nsec) / UINT64_C(1000);
+ return static_cast<uint64_t>(now.tv_sec) * UINT64_C(1000000000) +
+ static_cast<uint64_t>(now.tv_nsec);
#else // __APPLE__
UNIMPLEMENTED(WARNING);
return -1;
diff --git a/runtime/thread.h b/runtime/thread.h
index be4ffd0bc2..4a675d4c99 100644
--- a/runtime/thread.h
+++ b/runtime/thread.h
@@ -643,6 +643,9 @@ class EXPORT Thread {
// Returns the thread-specific CPU-time clock in microseconds or -1 if unavailable.
uint64_t GetCpuMicroTime() const;
+ // Returns the thread-specific CPU-time clock in nanoseconds or -1 if unavailable.
+ uint64_t GetCpuNanoTime() const;
+
mirror::Object* GetPeer() const REQUIRES_SHARED(Locks::mutator_lock_) {
DCHECK(Thread::Current() == this) << "Use GetPeerFromOtherThread instead";
CHECK(tlsPtr_.jpeer == nullptr);
diff --git a/runtime/trace.cc b/runtime/trace.cc
index 13a7dd26d4..2892023074 100644
--- a/runtime/trace.cc
+++ b/runtime/trace.cc
@@ -61,8 +61,8 @@ namespace art HIDDEN {
struct MethodTraceRecord {
ArtMethod* method;
TraceAction action;
- uint32_t wall_clock_time;
- uint32_t thread_cpu_time;
+ uint64_t wall_clock_time;
+ uint64_t thread_cpu_time;
};
using android::base::StringPrintf;
@@ -95,7 +95,7 @@ static constexpr size_t kScalingFactorEncodedEntries = 6;
// The key identifying the tracer to update instrumentation.
static constexpr const char* kTracerInstrumentationKey = "Tracer";
-double TimestampCounter::tsc_to_microsec_scaling_factor = -1;
+double TimestampCounter::tsc_to_nanosec_scaling_factor = -1;
Trace* Trace::the_trace_ = nullptr;
pthread_t Trace::sampling_pthread_ = 0U;
@@ -288,7 +288,7 @@ bool UseFastTraceListeners(TraceClockSource clock_source) {
void Trace::MeasureClockOverhead() {
if (UseThreadCpuClock(clock_source_)) {
- Thread::Current()->GetCpuMicroTime();
+ Thread::Current()->GetCpuNanoTime();
}
if (UseWallClock(clock_source_)) {
TimestampCounter::GetTimestamp();
@@ -296,11 +296,12 @@ void Trace::MeasureClockOverhead() {
}
// Compute an average time taken to measure clocks.
-uint32_t Trace::GetClockOverheadNanoSeconds() {
+uint64_t Trace::GetClockOverheadNanoSeconds() {
Thread* self = Thread::Current();
- uint64_t start = self->GetCpuMicroTime();
+ uint64_t start = self->GetCpuNanoTime();
- for (int i = 4000; i > 0; i--) {
+ const uint64_t numIter = 4000;
+ for (int i = numIter; i > 0; i--) {
MeasureClockOverhead();
MeasureClockOverhead();
MeasureClockOverhead();
@@ -311,8 +312,8 @@ uint32_t Trace::GetClockOverheadNanoSeconds() {
MeasureClockOverhead();
}
- uint64_t elapsed_us = self->GetCpuMicroTime() - start;
- return static_cast<uint32_t>(elapsed_us / 32);
+ uint64_t elapsed_ns = self->GetCpuNanoTime() - start;
+ return elapsed_ns / (numIter * 8);
}
static void GetSample(Thread* thread, void* arg) REQUIRES_SHARED(Locks::mutator_lock_) {
@@ -347,7 +348,7 @@ void Trace::CompareAndUpdateStackTrace(Thread* thread,
// Update the thread's stack trace sample.
thread->SetStackTraceSample(stack_trace);
// Read timer clocks to use for all events in this trace.
- uint32_t thread_clock_diff = 0;
+ uint64_t thread_clock_diff = 0;
uint64_t timestamp_counter = 0;
ReadClocks(thread, &thread_clock_diff, &timestamp_counter);
if (old_stack_trace == nullptr) {
@@ -896,14 +897,14 @@ TraceWriter::TraceWriter(File* trace_file,
size_t buffer_size,
int num_trace_buffers,
int trace_format_version,
- uint32_t clock_overhead_ns)
+ uint64_t clock_overhead_ns)
: trace_file_(trace_file),
trace_output_mode_(output_mode),
clock_source_(clock_source),
buf_(new uint8_t[std::max(kMinBufSize, buffer_size)]()),
buffer_size_(std::max(kMinBufSize, buffer_size)),
trace_format_version_(trace_format_version),
- start_time_(TimestampCounter::GetMicroTime(TimestampCounter::GetTimestamp())),
+ start_time_(TimestampCounter::GetNanoTime(TimestampCounter::GetTimestamp())),
overflow_(false),
num_records_(0),
clock_overhead_ns_(clock_overhead_ns),
@@ -921,7 +922,7 @@ TraceWriter::TraceWriter(File* trace_file,
// construct a cpu profile. See b/318052824 for more context.
uint64_t start_time_monotonic =
start_time_ +
- (MicroTime() - TimestampCounter::GetMicroTime(TimestampCounter::GetTimestamp()));
+ (NanoTime() - TimestampCounter::GetNanoTime(TimestampCounter::GetTimestamp()));
uint16_t trace_version = GetTraceVersion(clock_source_, trace_format_version_);
if (output_mode == TraceOutputMode::kStreaming) {
trace_version |= 0xF0U;
@@ -1004,7 +1005,7 @@ Trace::Trace(File* trace_file,
std::string TraceWriter::CreateSummary(int flags) {
std::ostringstream os;
// Compute elapsed time.
- uint64_t elapsed = TimestampCounter::GetMicroTime(TimestampCounter::GetTimestamp()) - start_time_;
+ uint64_t elapsed = TimestampCounter::GetNanoTime(TimestampCounter::GetTimestamp()) - start_time_;
os << StringPrintf("%cversion\n", kTraceTokenChar);
os << StringPrintf("%d\n", GetTraceVersion(clock_source_, trace_format_version_));
os << StringPrintf("data-file-overflow=%s\n", overflow_ ? "true" : "false");
@@ -1021,7 +1022,7 @@ std::string TraceWriter::CreateSummary(int flags) {
if (trace_output_mode_ != TraceOutputMode::kStreaming) {
os << StringPrintf("num-method-calls=%zd\n", num_records_);
}
- os << StringPrintf("clock-call-overhead-nsec=%d\n", clock_overhead_ns_);
+ os << StringPrintf("clock-call-overhead-nsec=%" PRIu64 "\n", clock_overhead_ns_);
os << StringPrintf("vm=art\n");
os << StringPrintf("pid=%d\n", getpid());
if ((flags & Trace::kTraceCountAllocs) != 0) {
@@ -1173,7 +1174,7 @@ void Trace::FieldWritten([[maybe_unused]] Thread* thread,
}
void Trace::MethodEntered(Thread* thread, ArtMethod* method) {
- uint32_t thread_clock_diff = 0;
+ uint64_t thread_clock_diff = 0;
uint64_t timestamp_counter = 0;
ReadClocks(thread, &thread_clock_diff, &timestamp_counter);
LogMethodTraceEvent(thread, method, kTraceMethodEnter, thread_clock_diff, timestamp_counter);
@@ -1183,14 +1184,14 @@ void Trace::MethodExited(Thread* thread,
ArtMethod* method,
[[maybe_unused]] instrumentation::OptionalFrame frame,
[[maybe_unused]] JValue& return_value) {
- uint32_t thread_clock_diff = 0;
+ uint64_t thread_clock_diff = 0;
uint64_t timestamp_counter = 0;
ReadClocks(thread, &thread_clock_diff, &timestamp_counter);
LogMethodTraceEvent(thread, method, kTraceMethodExit, thread_clock_diff, timestamp_counter);
}
void Trace::MethodUnwind(Thread* thread, ArtMethod* method, [[maybe_unused]] uint32_t dex_pc) {
- uint32_t thread_clock_diff = 0;
+ uint64_t thread_clock_diff = 0;
uint64_t timestamp_counter = 0;
ReadClocks(thread, &thread_clock_diff, &timestamp_counter);
LogMethodTraceEvent(thread, method, kTraceUnroll, thread_clock_diff, timestamp_counter);
@@ -1219,15 +1220,15 @@ void Trace::WatchedFramePop([[maybe_unused]] Thread* self,
LOG(ERROR) << "Unexpected WatchedFramePop event in tracing";
}
-void Trace::ReadClocks(Thread* thread, uint32_t* thread_clock_diff, uint64_t* timestamp_counter) {
+void Trace::ReadClocks(Thread* thread, uint64_t* thread_clock_diff, uint64_t* timestamp_counter) {
if (UseThreadCpuClock(clock_source_)) {
uint64_t clock_base = thread->GetTraceClockBase();
if (UNLIKELY(clock_base == 0)) {
// First event, record the base time in the map.
- uint64_t time = thread->GetCpuMicroTime();
+ uint64_t time = thread->GetCpuNanoTime();
thread->SetTraceClockBase(time);
} else {
- *thread_clock_diff = thread->GetCpuMicroTime() - clock_base;
+ *thread_clock_diff = thread->GetCpuNanoTime() - clock_base;
}
}
if (UseWallClock(clock_source_)) {
@@ -1550,7 +1551,7 @@ void TraceWriter::ReadValuesFromRecord(uintptr_t* method_trace_entries,
uint64_t high_timestamp = method_trace_entries[record_index++];
timestamp = (high_timestamp << 32 | timestamp);
}
- record.wall_clock_time = TimestampCounter::GetMicroTime(timestamp) - start_time_;
+ record.wall_clock_time = TimestampCounter::GetNanoTime(timestamp) - start_time_;
}
}
@@ -1606,8 +1607,8 @@ void TraceWriter::FlushEntriesFormatV2(
bool has_thread_cpu_clock = UseThreadCpuClock(clock_source_);
bool has_wall_clock = UseWallClock(clock_source_);
size_t num_entries = GetNumEntries(clock_source_);
- uint32_t prev_wall_timestamp = 0;
- uint32_t prev_thread_timestamp = 0;
+ uint64_t prev_wall_timestamp = 0;
+ uint64_t prev_thread_timestamp = 0;
uint64_t prev_method_action_encoding = 0;
size_t entry_index = kPerThreadBufSize;
for (size_t i = 0; i < num_records; i++) {
@@ -1703,7 +1704,7 @@ void TraceWriter::FlushBuffer(uintptr_t* method_trace_entries,
void Trace::LogMethodTraceEvent(Thread* thread,
ArtMethod* method,
TraceAction action,
- uint32_t thread_clock_diff,
+ uint64_t thread_clock_diff,
uint64_t timestamp_counter) {
// This method is called in both tracing modes (method and sampling). In sampling mode, this
// method is only called by the sampling thread. In method tracing mode, it can be called
@@ -1763,8 +1764,8 @@ void TraceWriter::EncodeEventEntry(uint8_t* ptr,
uint16_t thread_id,
uint32_t method_index,
TraceAction action,
- uint32_t thread_clock_diff,
- uint32_t wall_clock_diff) {
+ uint64_t thread_clock_diff,
+ uint64_t wall_clock_diff) {
static constexpr size_t kPacketSize = 14U; // The maximum size of data in a packet.
DCHECK(method_index < (1 << (32 - TraceActionBits)));
uint32_t method_value = (method_index << TraceActionBits) | action;
@@ -1772,12 +1773,13 @@ void TraceWriter::EncodeEventEntry(uint8_t* ptr,
Append4LE(ptr + 2, method_value);
ptr += 6;
+ static constexpr uint64_t ns_to_us = 1000;
if (UseThreadCpuClock(clock_source_)) {
- Append4LE(ptr, thread_clock_diff);
+ Append4LE(ptr, thread_clock_diff / ns_to_us);
ptr += 4;
}
if (UseWallClock(clock_source_)) {
- Append4LE(ptr, wall_clock_diff);
+ Append4LE(ptr, wall_clock_diff / ns_to_us);
}
static_assert(kPacketSize == 2 + 4 + 4 + 4, "Packet size incorrect.");
}
diff --git a/runtime/trace.h b/runtime/trace.h
index 63c96f927c..ff24538901 100644
--- a/runtime/trace.h
+++ b/runtime/trace.h
@@ -200,7 +200,7 @@ class TraceWriter {
size_t buffer_size,
int num_trace_buffers,
int trace_format_version,
- uint32_t clock_overhead_ns);
+ uint64_t clock_overhead_ns);
// This encodes all the events in the per-thread trace buffer and writes it to the trace file /
// buffer. This acquires streaming lock to prevent any other threads writing concurrently. It is
@@ -342,8 +342,8 @@ class TraceWriter {
uint16_t thread_id,
uint32_t method_index,
TraceAction action,
- uint32_t thread_clock_diff,
- uint32_t wall_clock_diff) REQUIRES(trace_writer_lock_);
+ uint64_t thread_clock_diff,
+ uint64_t wall_clock_diff) REQUIRES(trace_writer_lock_);
// Encodes the header for the events block. This assumes that there is enough space reserved to
// encode the entry.
@@ -417,7 +417,7 @@ class TraceWriter {
size_t num_records_;
// Clock overhead.
- const uint32_t clock_overhead_ns_;
+ const uint64_t clock_overhead_ns_;
std::vector<std::atomic<size_t>> owner_tids_;
std::unique_ptr<uintptr_t[]> trace_buffer_;
@@ -519,7 +519,7 @@ class Trace final : public instrumentation::InstrumentationListener, public Clas
static void RemoveListeners() REQUIRES(Locks::mutator_lock_);
void MeasureClockOverhead();
- uint32_t GetClockOverheadNanoSeconds();
+ uint64_t GetClockOverheadNanoSeconds();
void CompareAndUpdateStackTrace(Thread* thread, std::vector<ArtMethod*>* stack_trace)
REQUIRES_SHARED(Locks::mutator_lock_);
@@ -605,12 +605,12 @@ class Trace final : public instrumentation::InstrumentationListener, public Clas
// how to annotate this.
NO_THREAD_SAFETY_ANALYSIS;
- void ReadClocks(Thread* thread, uint32_t* thread_clock_diff, uint64_t* timestamp_counter);
+ void ReadClocks(Thread* thread, uint64_t* thread_clock_diff, uint64_t* timestamp_counter);
void LogMethodTraceEvent(Thread* thread,
ArtMethod* method,
TraceAction action,
- uint32_t thread_clock_diff,
+ uint64_t thread_clock_diff,
uint64_t timestamp_counter) REQUIRES_SHARED(Locks::mutator_lock_);
// Singleton instance of the Trace or null when no method tracing is active.
diff --git a/runtime/trace_common.h b/runtime/trace_common.h
index 759a0bbc49..f29b347462 100644
--- a/runtime/trace_common.h
+++ b/runtime/trace_common.h
@@ -47,7 +47,7 @@ class TimestampCounter {
// access is disabled only for 32-bit processes even when 64-bit processes can accesses the
// timer from user space. These are not reflected in the HWCAP_EVTSTRM capability.So just
// fallback to clock_gettime on these processes. See b/289178149 for more discussion.
- t = MicroTime();
+ t = NanoTime();
#elif defined(__aarch64__)
// See Arm Architecture Registers Armv8 section System Registers
asm volatile("mrs %0, cntvct_el0" : "=r"(t));
@@ -59,7 +59,7 @@ class TimestampCounter {
#elif defined(__riscv)
asm volatile("rdtime %0" : "=r"(t));
#else
- t = MicroTime();
+ t = NanoTime();
#endif
return t;
}
@@ -67,36 +67,36 @@ class TimestampCounter {
static void InitializeTimestampCounters() {
// It is sufficient to initialize this once for the entire execution. Just return if it is
// already initialized.
- if (tsc_to_microsec_scaling_factor > 0.0) {
+ if (tsc_to_nanosec_scaling_factor > 0.0) {
return;
}
#if defined(__arm__)
// On ARM 32 bit, we don't always have access to the timestamp counters from
// user space. Seem comment in GetTimestamp for more details.
- tsc_to_microsec_scaling_factor = 1.0;
+ tsc_to_nanosec_scaling_factor = 1.0;
#elif defined(__aarch64__)
- double seconds_to_microseconds = 1000 * 1000;
+ double seconds_to_nanoseconds = 1000 * 1000;
uint64_t freq = 0;
// See Arm Architecture Registers Armv8 section System Registers
asm volatile("mrs %0, cntfrq_el0" : "=r"(freq));
if (freq == 0) {
// It is expected that cntfrq_el0 is correctly setup during system initialization but some
// devices don't do this. In such cases fall back to computing the frequency. See b/315139000.
- tsc_to_microsec_scaling_factor = computeScalingFactor();
+ tsc_to_nanosec_scaling_factor = computeScalingFactor();
} else {
- tsc_to_microsec_scaling_factor = seconds_to_microseconds / static_cast<double>(freq);
+ tsc_to_nanosec_scaling_factor = seconds_to_nanoseconds / static_cast<double>(freq);
}
#elif defined(__i386__) || defined(__x86_64__)
- tsc_to_microsec_scaling_factor = GetScalingFactorForX86();
+ tsc_to_nanosec_scaling_factor = GetScalingFactorForX86();
#else
- tsc_to_microsec_scaling_factor = 1.0;
+ tsc_to_nanosec_scaling_factor = 1.0;
#endif
}
- static ALWAYS_INLINE uint64_t GetMicroTime(uint64_t counter) {
- DCHECK(tsc_to_microsec_scaling_factor > 0.0) << tsc_to_microsec_scaling_factor;
- return tsc_to_microsec_scaling_factor * counter;
+ static ALWAYS_INLINE uint64_t GetNanoTime(uint64_t counter) {
+ DCHECK(tsc_to_nanosec_scaling_factor > 0.0) << tsc_to_nanosec_scaling_factor;
+ return tsc_to_nanosec_scaling_factor * counter;
}
private:
@@ -107,12 +107,12 @@ class TimestampCounter {
// step using these two samples. However, that would require a change in Android Studio which is
// the main consumer of these profiles. For now, just compute the frequency of tsc updates here.
static double computeScalingFactor() {
- uint64_t start = MicroTime();
+ uint64_t start = NanoTime();
uint64_t start_tsc = GetTimestamp();
// Sleep for one millisecond.
usleep(1000);
uint64_t diff_tsc = GetTimestamp() - start_tsc;
- uint64_t diff_time = MicroTime() - start;
+ uint64_t diff_time = NanoTime() - start;
double scaling_factor = static_cast<double>(diff_time) / diff_tsc;
DCHECK(scaling_factor > 0.0) << scaling_factor;
return scaling_factor;
@@ -150,18 +150,18 @@ class TimestampCounter {
}
double coreCrystalFreq = ecx;
// frequency = coreCrystalFreq * (ebx / eax)
- // scaling_factor = seconds_to_microseconds / frequency
- // = seconds_to_microseconds * eax / (coreCrystalFreq * ebx)
- double seconds_to_microseconds = 1000 * 1000;
- double scaling_factor = (seconds_to_microseconds * eax) / (coreCrystalFreq * ebx);
+ // scaling_factor = seconds_to_nanoseconds / frequency
+ // = seconds_to_nanoseconds * eax / (coreCrystalFreq * ebx)
+ double seconds_to_nanoseconds = 1000 * 1000;
+ double scaling_factor = (seconds_to_nanoseconds * eax) / (coreCrystalFreq * ebx);
return scaling_factor;
}
#endif
- // Scaling factor to convert timestamp counter into wall clock time reported in micro seconds.
+ // Scaling factor to convert timestamp counter into wall clock time reported in nano seconds.
// This is initialized at the start of tracing using the timestamp counter update frequency.
// See InitializeTimestampCounters for more details.
- static double tsc_to_microsec_scaling_factor;
+ static double tsc_to_nanosec_scaling_factor;
};
} // namespace art
diff --git a/runtime/trace_profile.cc b/runtime/trace_profile.cc
index d0d234c476..19e0a56bcc 100644
--- a/runtime/trace_profile.cc
+++ b/runtime/trace_profile.cc
@@ -140,7 +140,7 @@ void RecordMethodsOnThreadStack(Thread* thread, uintptr_t* method_trace_buffer)
visitor.WalkStack(true);
// Create method entry events for all methods currently on the thread's stack.
- uint64_t init_time = TimestampCounter::GetMicroTime(TimestampCounter::GetTimestamp());
+ uint64_t init_time = TimestampCounter::GetNanoTime(TimestampCounter::GetTimestamp());
// Set the lsb to 0 to indicate method entry.
init_time = init_time & ~1;
std::ostringstream os;
@@ -492,13 +492,13 @@ void TraceProfiler::DumpLongRunningMethodBuffer(uint32_t thread_id,
// start of the trace. Just ignore this entry.
} else if (entry & 0x1) {
// Method exit
- os << "<-" << TimestampCounter::GetMicroTime(entry & ~1) << "\n";
+ os << "<-" << TimestampCounter::GetNanoTime(entry & ~1) << "\n";
} else {
// Method entry
ArtMethod* method = reinterpret_cast<ArtMethod*>(entry);
ptr--;
CHECK(ptr >= end_trace_entries);
- os << "->" << method << " " << TimestampCounter::GetMicroTime(*ptr) << "\n";
+ os << "->" << method << " " << TimestampCounter::GetNanoTime(*ptr) << "\n";
methods.insert(method);
}
ptr--;
generated by cgit v1.2.3-59-g8ed1b (git 2.39.0) at 2025-10-20 02:43:57 +0000