summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
authorYabin Cui <yabinc@google.com>2016-09-15 10:43:20 -0700
committerYabin Cui <yabinc@google.com>2016-09-15 18:47:04 -0700
commitaa65c8b250b99f1684f46e2c40b77e42bf7c5f31 (patch)
tree98076608b0afb20e68bb4f5d94ac55a47b596d2a
parent812d0a9a51201845b82426da581bfed27cb03194 (diff)
downloadextras-aa65c8b250b99f1684f46e2c40b77e42bf7c5f31.tar.gz
simpleperf: calculate perf clock based on system clock.
The timestamps of perf event records are not generated by MONOTONIC system clock. However, we can calculate perf clock based on MONOTONIC system clock. See http://www.gossamer-threads.com/lists/linux/kernel/1970811 Bug: http://b/30975131 Test: run `simpleperf record -a --log verbose ls` and check the result. Change-Id: I78ef28b501aa45a4696c05ec76f6d04363082c5d
-rw-r--r--simpleperf/Android.mk1
-rw-r--r--simpleperf/cmd_record.cpp11
-rw-r--r--simpleperf/perf_clock.cpp188
-rw-r--r--simpleperf/perf_clock.h31
4 files changed, 227 insertions, 4 deletions
diff --git a/simpleperf/Android.mk b/simpleperf/Android.mk
index c9108bed..c62ca59a 100644
--- a/simpleperf/Android.mk
+++ b/simpleperf/Android.mk
@@ -110,6 +110,7 @@ libsimpleperf_src_files_linux := \
event_fd.cpp \
event_selection_set.cpp \
IOEventLoop.cpp \
+ perf_clock.cpp \
record_file_writer.cpp \
workload.cpp \
diff --git a/simpleperf/cmd_record.cpp b/simpleperf/cmd_record.cpp
index a28cdb87..07e14687 100644
--- a/simpleperf/cmd_record.cpp
+++ b/simpleperf/cmd_record.cpp
@@ -35,6 +35,7 @@
#include "event_selection_set.h"
#include "event_type.h"
#include "IOEventLoop.h"
+#include "perf_clock.h"
#include "read_apk.h"
#include "read_elf.h"
#include "record.h"
@@ -229,6 +230,9 @@ bool RecordCommand::Run(const std::vector<std::string>& args) {
if (!CheckPerfEventLimit()) {
return false;
}
+ if (!InitPerfClock()) {
+ return false;
+ }
// 1. Parse options, and use default measured event type if not given.
std::vector<std::string> workload_args;
@@ -302,12 +306,11 @@ bool RecordCommand::Run(const std::vector<std::string>& args) {
// 6. Write records in mapped buffers of perf_event_files to output file while
// workload is running.
- timespec ts;
- if (clock_gettime(CLOCK_MONOTONIC, &ts) != 0) {
- PLOG(ERROR) << "clock_gettime failed";
+ if (!GetPerfClock(&start_sampling_time_in_ns_)) {
return false;
}
- start_sampling_time_in_ns_ = ts.tv_sec * 1000000000ULL + ts.tv_nsec;
+ LOG(VERBOSE) << "start_sampling_time is " << start_sampling_time_in_ns_
+ << " ns";
if (workload != nullptr && !workload->Start()) {
return false;
}
diff --git a/simpleperf/perf_clock.cpp b/simpleperf/perf_clock.cpp
new file mode 100644
index 00000000..9ce41344
--- /dev/null
+++ b/simpleperf/perf_clock.cpp
@@ -0,0 +1,188 @@
+/*
+ * 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.
+ */
+
+#include "perf_clock.h"
+
+#include <sys/mman.h>
+#include <sys/syscall.h>
+
+#include <atomic>
+#include <chrono>
+#include <thread>
+
+#include <android-base/logging.h>
+
+#include "event_attr.h"
+#include "event_fd.h"
+#include "event_type.h"
+#include "record.h"
+
+static bool perf_clock_initialized = false;
+static int64_t perf_clock_and_system_clock_diff_in_ns = 0;
+
+struct ThreadArg {
+ std::atomic<pid_t> thread_a_tid;
+ std::atomic<bool> start_mmap;
+ std::atomic<uint64_t> mmap_start_addr;
+ uint64_t system_time_in_ns;
+ std::atomic<bool> has_error;
+};
+
+static bool GetSystemClock(uint64_t* time_in_ns) {
+ timespec ts;
+ if (clock_gettime(CLOCK_MONOTONIC, &ts) != 0) {
+ PLOG(ERROR) << "clock_gettime() failed";
+ return false;
+ }
+ *time_in_ns = ts.tv_sec * 1000000000ULL + ts.tv_nsec;
+ return true;
+}
+
+static void ThreadA(ThreadArg* thread_arg) {
+ thread_arg->thread_a_tid = syscall(SYS_gettid);
+ while (!thread_arg->start_mmap) {
+ usleep(1000);
+ }
+
+ size_t TRY_MMAP_COUNT = 10;
+
+ struct TryMmap {
+ void* mmap_start_addr;
+ uint64_t start_system_time_in_ns;
+ uint64_t end_system_time_in_ns;
+ };
+ TryMmap array[TRY_MMAP_COUNT];
+
+ // In case current thread is preempted by other threads, we run mmap()
+ // multiple times and use the one with the smallest time interval.
+ for (size_t i = 0; i < TRY_MMAP_COUNT; ++i) {
+ if (!GetSystemClock(&array[i].start_system_time_in_ns)) {
+ thread_arg->has_error = true;
+ return;
+ }
+ array[i].mmap_start_addr =
+ mmap(NULL, 4096, PROT_WRITE, MAP_PRIVATE | MAP_ANONYMOUS, -1, 0);
+ if (array[i].mmap_start_addr == MAP_FAILED) {
+ PLOG(ERROR) << "mmap() failed";
+ thread_arg->has_error = true;
+ return;
+ }
+
+ if (!GetSystemClock(&array[i].end_system_time_in_ns)) {
+ thread_arg->has_error = true;
+ return;
+ }
+ }
+ size_t best_index = 0;
+ uint64_t min_duration_in_ns = UINT64_MAX;
+ for (size_t i = 0; i < TRY_MMAP_COUNT; ++i) {
+ uint64_t d =
+ array[i].end_system_time_in_ns - array[i].start_system_time_in_ns;
+ if (min_duration_in_ns > d) {
+ min_duration_in_ns = d;
+ best_index = i;
+ }
+ munmap(array[i].mmap_start_addr, 4096);
+ }
+ thread_arg->mmap_start_addr =
+ reinterpret_cast<uint64_t>(array[best_index].mmap_start_addr);
+ // Perf time is generated at the end of mmap() syscall, which is close to
+ // the end time instead of the start time.
+ thread_arg->system_time_in_ns = array[best_index].end_system_time_in_ns;
+}
+
+static bool GetClockDiff(int64_t* clock_diff_in_ns) {
+ ThreadArg thread_arg;
+ thread_arg.thread_a_tid = 0;
+ thread_arg.start_mmap = false;
+ thread_arg.has_error = false;
+ std::thread thread_a(ThreadA, &thread_arg);
+ while (thread_arg.thread_a_tid == 0) {
+ usleep(1000);
+ }
+ std::unique_ptr<EventTypeAndModifier> event_type =
+ ParseEventType("cpu-clock");
+ if (event_type == nullptr) {
+ return false;
+ }
+ perf_event_attr attr = CreateDefaultPerfEventAttr(event_type->event_type);
+ attr.comm = 0;
+ attr.mmap_data = 1;
+ attr.mmap = 0;
+ attr.inherit = 0;
+ attr.sample_id_all = 1;
+ attr.freq = 0;
+ attr.sample_period = 1ULL << 62; // Sample records are not needed.
+ std::unique_ptr<EventFd> event_fd =
+ EventFd::OpenEventFile(attr, thread_arg.thread_a_tid, -1, nullptr);
+ if (event_fd == nullptr) {
+ return false;
+ }
+ if (!event_fd->CreateMappedBuffer(4, true)) {
+ return false;
+ }
+
+ thread_arg.start_mmap = true;
+ thread_a.join();
+
+ if (thread_arg.has_error) {
+ return false;
+ }
+
+ const char* data;
+ size_t size = event_fd->GetAvailableMmapData(&data);
+ std::vector<std::unique_ptr<Record>> records =
+ ReadRecordsFromBuffer(attr, data, size);
+ uint64_t perf_time_in_ns = 0;
+ for (auto& r : records) {
+ if (r->type() == PERF_RECORD_MMAP) {
+ auto& record = *static_cast<MmapRecord*>(r.get());
+ if (record.data->addr == thread_arg.mmap_start_addr) {
+ perf_time_in_ns = record.Timestamp();
+ }
+ }
+ }
+ if (perf_time_in_ns == 0) {
+ LOG(ERROR) << "GetPerfClockAndSystemClockDiff: can't get perf time.";
+ return false;
+ }
+
+ *clock_diff_in_ns = perf_time_in_ns - thread_arg.system_time_in_ns;
+ LOG(VERBOSE) << "perf_time is " << perf_time_in_ns << " ns, system_time is "
+ << thread_arg.system_time_in_ns << " ns , clock_diff is "
+ << *clock_diff_in_ns << " ns.";
+ return true;
+}
+
+bool InitPerfClock() {
+ if (!perf_clock_initialized) {
+ if (!GetClockDiff(&perf_clock_and_system_clock_diff_in_ns)) {
+ return false;
+ }
+ perf_clock_initialized = true;
+ }
+ return true;
+}
+
+bool GetPerfClock(uint64_t* time_in_ns) {
+ CHECK(perf_clock_initialized);
+ uint64_t system_time_in_ns;
+ if (!GetSystemClock(&system_time_in_ns)) {
+ return false;
+ }
+ *time_in_ns = system_time_in_ns + perf_clock_and_system_clock_diff_in_ns;
+ return true;
+}
diff --git a/simpleperf/perf_clock.h b/simpleperf/perf_clock.h
new file mode 100644
index 00000000..9bd5db9c
--- /dev/null
+++ b/simpleperf/perf_clock.h
@@ -0,0 +1,31 @@
+/*
+ * 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 SIMPLE_PERF_PERF_CLOCK_H_
+#define SIMPLE_PERF_PERF_CLOCK_H_
+
+#include <stdint.h>
+
+// Perf clock is the clock used by the kernel to generate timestamps in perf
+// event records. We use a separate init function because it allocates a mapped
+// buffer for perf event file, which might not be available during profiling.
+// And we'd better call the init function before profiling.
+// InitPerfClock() must be called before GetPerfClock().
+bool InitPerfClock();
+
+bool GetPerfClock(uint64_t* time_in_ns);
+
+#endif // SIMPLE_PERF_PERF_CLOCK_H_