Record a periodic clock snapshot
Periodically (every 10s when packets are read) record a snapshot of all
system clocks. This will allow the consumer to align clocks between
multiple data sources.
Change-Id: I0f0d07764cff141d8874c4e225f90094d0836e7d
diff --git a/Android.bp b/Android.bp
index bf0711f..9c6a192 100644
--- a/Android.bp
+++ b/Android.bp
@@ -2539,6 +2539,7 @@
genrule {
name: "perfetto_protos_perfetto_trace_lite_gen",
srcs: [
+ "protos/perfetto/trace/clock_snapshot.proto",
"protos/perfetto/trace/test_event.proto",
"protos/perfetto/trace/trace.proto",
"protos/perfetto/trace/trace_packet.proto",
@@ -2549,6 +2550,7 @@
],
cmd: "mkdir -p $(genDir)/external/perfetto/protos && $(location aprotoc) --cpp_out=$(genDir)/external/perfetto/protos --proto_path=external/perfetto/protos $(in)",
out: [
+ "external/perfetto/protos/perfetto/trace/clock_snapshot.pb.cc",
"external/perfetto/protos/perfetto/trace/test_event.pb.cc",
"external/perfetto/protos/perfetto/trace/trace.pb.cc",
"external/perfetto/protos/perfetto/trace/trace_packet.pb.cc",
@@ -2560,6 +2562,7 @@
genrule {
name: "perfetto_protos_perfetto_trace_lite_gen_headers",
srcs: [
+ "protos/perfetto/trace/clock_snapshot.proto",
"protos/perfetto/trace/test_event.proto",
"protos/perfetto/trace/trace.proto",
"protos/perfetto/trace/trace_packet.proto",
@@ -2570,6 +2573,7 @@
],
cmd: "mkdir -p $(genDir)/external/perfetto/protos && $(location aprotoc) --cpp_out=$(genDir)/external/perfetto/protos --proto_path=external/perfetto/protos $(in)",
out: [
+ "external/perfetto/protos/perfetto/trace/clock_snapshot.pb.h",
"external/perfetto/protos/perfetto/trace/test_event.pb.h",
"external/perfetto/protos/perfetto/trace/trace.pb.h",
"external/perfetto/protos/perfetto/trace/trace_packet.pb.h",
@@ -2652,6 +2656,7 @@
genrule {
name: "perfetto_protos_perfetto_trace_zero_gen",
srcs: [
+ "protos/perfetto/trace/clock_snapshot.proto",
"protos/perfetto/trace/test_event.proto",
"protos/perfetto/trace/trace.proto",
"protos/perfetto/trace/trace_packet.proto",
@@ -2663,6 +2668,7 @@
],
cmd: "mkdir -p $(genDir)/external/perfetto/protos && $(location aprotoc) --cpp_out=$(genDir)/external/perfetto/protos --proto_path=external/perfetto/protos --plugin=protoc-gen-plugin=$(location perfetto_src_protozero_protoc_plugin_protoc_plugin___gn_standalone_toolchain_gcc_like_host_) --plugin_out=wrapper_namespace=pbzero:$(genDir)/external/perfetto/protos $(in)",
out: [
+ "external/perfetto/protos/perfetto/trace/clock_snapshot.pbzero.cc",
"external/perfetto/protos/perfetto/trace/test_event.pbzero.cc",
"external/perfetto/protos/perfetto/trace/trace.pbzero.cc",
"external/perfetto/protos/perfetto/trace/trace_packet.pbzero.cc",
@@ -2674,6 +2680,7 @@
genrule {
name: "perfetto_protos_perfetto_trace_zero_gen_headers",
srcs: [
+ "protos/perfetto/trace/clock_snapshot.proto",
"protos/perfetto/trace/test_event.proto",
"protos/perfetto/trace/trace.proto",
"protos/perfetto/trace/trace_packet.proto",
@@ -2685,6 +2692,7 @@
],
cmd: "mkdir -p $(genDir)/external/perfetto/protos && $(location aprotoc) --cpp_out=$(genDir)/external/perfetto/protos --proto_path=external/perfetto/protos --plugin=protoc-gen-plugin=$(location perfetto_src_protozero_protoc_plugin_protoc_plugin___gn_standalone_toolchain_gcc_like_host_) --plugin_out=wrapper_namespace=pbzero:$(genDir)/external/perfetto/protos $(in)",
out: [
+ "external/perfetto/protos/perfetto/trace/clock_snapshot.pbzero.h",
"external/perfetto/protos/perfetto/trace/test_event.pbzero.h",
"external/perfetto/protos/perfetto/trace/trace.pbzero.h",
"external/perfetto/protos/perfetto/trace/trace_packet.pbzero.h",
diff --git a/include/perfetto/base/time.h b/include/perfetto/base/time.h
index d0c2744..90e8535 100644
--- a/include/perfetto/base/time.h
+++ b/include/perfetto/base/time.h
@@ -30,10 +30,14 @@
using TimeNanos = std::chrono::nanoseconds;
constexpr clockid_t kWallTimeClockSource = CLOCK_MONOTONIC;
+inline TimeNanos FromPosixTimespec(const struct timespec& ts) {
+ return TimeNanos(ts.tv_sec * 1000000000LL + ts.tv_nsec);
+}
+
inline TimeNanos GetTimeInternalNs(clockid_t clk_id) {
struct timespec ts = {};
PERFETTO_CHECK(clock_gettime(clk_id, &ts) == 0);
- return TimeNanos(ts.tv_sec * 1000000000LL + ts.tv_nsec);
+ return FromPosixTimespec(ts);
}
inline TimeNanos GetWallTimeNs() {
diff --git a/protos/perfetto/trace/BUILD.gn b/protos/perfetto/trace/BUILD.gn
index 85947c0..a081c71 100644
--- a/protos/perfetto/trace/BUILD.gn
+++ b/protos/perfetto/trace/BUILD.gn
@@ -17,6 +17,7 @@
import("../../../gn/proto_library.gni")
proto_sources = [
+ "clock_snapshot.proto",
"test_event.proto",
"trace_packet.proto",
"trace.proto",
diff --git a/protos/perfetto/trace/clock_snapshot.proto b/protos/perfetto/trace/clock_snapshot.proto
new file mode 100644
index 0000000..7cf74ba
--- /dev/null
+++ b/protos/perfetto/trace/clock_snapshot.proto
@@ -0,0 +1,40 @@
+/*
+ * Copyright (C) 2018 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.
+ */
+
+syntax = "proto2";
+option optimize_for = LITE_RUNTIME;
+
+package perfetto.protos;
+
+// A snapshot of clock readings to allow for trace alignment.
+message ClockSnapshot {
+ message Clock {
+ enum Type {
+ UNKNOWN = 0;
+ REALTIME = 1;
+ REALTIME_COARSE = 2;
+ MONOTONIC = 3;
+ MONOTONIC_COARSE = 4;
+ MONOTONIC_RAW = 5;
+ BOOTTIME = 6;
+ PROCESS_CPUTIME = 7;
+ THREAD_CPUTIME = 8;
+ }
+ optional Type type = 1;
+ optional uint64 timestamp = 2;
+ }
+ repeated Clock clocks = 1;
+}
diff --git a/protos/perfetto/trace/trace_packet.proto b/protos/perfetto/trace/trace_packet.proto
index a487c10..df06282 100644
--- a/protos/perfetto/trace/trace_packet.proto
+++ b/protos/perfetto/trace/trace_packet.proto
@@ -18,21 +18,25 @@
option optimize_for = LITE_RUNTIME;
import "perfetto/trace/chrome/chrome_trace_event.proto";
+import "perfetto/trace/clock_snapshot.proto";
+import "perfetto/trace/filesystem/inode_file_map.proto";
import "perfetto/trace/ftrace/ftrace_event_bundle.proto";
import "perfetto/trace/ps/process_tree.proto";
-import "perfetto/trace/filesystem/inode_file_map.proto";
import "perfetto/trace/test_event.proto";
package perfetto.protos;
// The root object emitted by Perfetto. A perfetto trace is just a stream of
// TracePacket(s).
+//
+// Next id: 7.
message TracePacket {
oneof data {
FtraceEventBundle ftrace_events = 1;
ProcessTree process_tree = 2;
InodeFileMap inode_file_map = 4;
ChromeEventBundle chrome_events = 5;
+ ClockSnapshot clock_snapshot = 6;
// This field is only used for testing.
TestEvent for_testing = 536870911; // 2^29 - 1, max field id for protos.
diff --git a/src/tracing/core/service_impl.cc b/src/tracing/core/service_impl.cc
index 294e241..dd9e919 100644
--- a/src/tracing/core/service_impl.cc
+++ b/src/tracing/core/service_impl.cc
@@ -33,6 +33,7 @@
#include "src/tracing/core/packet_stream_validator.h"
#include "src/tracing/core/trace_buffer.h"
+#include "perfetto/trace/clock_snapshot.pb.h"
#include "perfetto/trace/trace_packet.pb.h"
#include "perfetto/trace/trusted_packet.pb.h"
@@ -51,6 +52,7 @@
constexpr size_t kDefaultShmSize = 256 * 1024ul;
constexpr size_t kMaxShmSize = 4096 * 1024 * 1024ul;
constexpr int kMaxBuffersPerConsumer = 128;
+constexpr base::TimeMillis kClockSnapshotInterval(10 * 1000);
constexpr uint64_t kMillisPerHour = 3600000;
@@ -334,6 +336,7 @@
}
std::vector<TracePacket> packets;
size_t packets_bytes = 0; // SUM(slice.size() for each slice in |packets|).
+ MaybeSnapshotClocks(tracing_session, &packets);
// This is a rough threshold to determine how to split packets within each
// IPC. This is not an upper bound, we just stop accumulating packets and send
@@ -665,6 +668,54 @@
#endif
}
+void ServiceImpl::MaybeSnapshotClocks(TracingSession* tracing_session,
+ std::vector<TracePacket>* packets) {
+ base::TimeMillis now = base::GetWallTimeMs();
+ if (now < tracing_session->last_clock_snapshot + kClockSnapshotInterval)
+ return;
+ tracing_session->last_clock_snapshot = now;
+ struct {
+ clockid_t id;
+ protos::ClockSnapshot::Clock::Type type;
+ struct timespec ts;
+ } clocks[] = {
+ {CLOCK_BOOTTIME, protos::ClockSnapshot::Clock::BOOTTIME, {0, 0}},
+ {CLOCK_REALTIME, protos::ClockSnapshot::Clock::REALTIME, {0, 0}},
+ {CLOCK_MONOTONIC, protos::ClockSnapshot::Clock::MONOTONIC, {0, 0}},
+ {CLOCK_MONOTONIC_RAW,
+ protos::ClockSnapshot::Clock::MONOTONIC_RAW,
+ {0, 0}},
+ {CLOCK_PROCESS_CPUTIME_ID,
+ protos::ClockSnapshot::Clock::PROCESS_CPUTIME,
+ {0, 0}},
+ {CLOCK_THREAD_CPUTIME_ID,
+ protos::ClockSnapshot::Clock::THREAD_CPUTIME,
+ {0, 0}},
+ {CLOCK_REALTIME_COARSE,
+ protos::ClockSnapshot::Clock::REALTIME_COARSE,
+ {0, 0}},
+ {CLOCK_MONOTONIC_COARSE,
+ protos::ClockSnapshot::Clock::MONOTONIC_COARSE,
+ {0, 0}},
+ };
+ protos::TracePacket packet;
+ protos::ClockSnapshot* clock_snapshot = packet.mutable_clock_snapshot();
+ // First snapshot all the clocks as atomically as we can.
+ for (auto& clock : clocks) {
+ if (clock_gettime(clock.id, &clock.ts) == -1)
+ PERFETTO_DLOG("clock_gettime failed for clock %d", clock.id);
+ }
+ for (auto& clock : clocks) {
+ protos::ClockSnapshot::Clock* c = clock_snapshot->add_clocks();
+ c->set_type(clock.type);
+ c->set_timestamp(base::FromPosixTimespec(clock.ts).count());
+ }
+ Slice slice = Slice::Allocate(packet.ByteSize());
+ PERFETTO_CHECK(packet.SerializeWithCachedSizesToArray(slice.own_data()));
+ packets->emplace_back();
+ packets->back().AddSlice(std::move(slice));
+}
+
////////////////////////////////////////////////////////////////////////////////
// ServiceImpl::ConsumerEndpointImpl implementation
////////////////////////////////////////////////////////////////////////////////
diff --git a/src/tracing/core/service_impl.h b/src/tracing/core/service_impl.h
index d06f550..ac6b780 100644
--- a/src/tracing/core/service_impl.h
+++ b/src/tracing/core/service_impl.h
@@ -24,6 +24,7 @@
#include "gtest/gtest_prod.h"
#include "perfetto/base/page_allocator.h"
+#include "perfetto/base/time.h"
#include "perfetto/base/weak_ptr.h"
#include "perfetto/tracing/core/basic_types.h"
#include "perfetto/tracing/core/commit_data_request.h"
@@ -45,6 +46,7 @@
class SharedMemory;
class TraceBuffez;
class TraceConfig;
+class TracePacket;
// The tracing service business logic.
class ServiceImpl : public Service {
@@ -189,6 +191,9 @@
// BufferID (shared namespace amongst all consumers). This vector has as
// many entries as |config.buffers_size()|.
std::vector<BufferID> buffers_index;
+
+ // When the last clock snapshot was emitted into the output stream.
+ base::TimeMillis last_clock_snapshot = {};
};
ServiceImpl(const ServiceImpl&) = delete;
@@ -209,6 +214,8 @@
// shared memory and trace buffers.
void UpdateMemoryGuardrail();
+ void MaybeSnapshotClocks(TracingSession*, std::vector<TracePacket>*);
+
TraceBuffez* GetBufferByID(BufferID);
base::TaskRunner* const task_runner_;
diff --git a/src/tracing/test/tracing_integration_test.cc b/src/tracing/test/tracing_integration_test.cc
index 6688938..6969fd0 100644
--- a/src/tracing/test/tracing_integration_test.cc
+++ b/src/tracing/test/tracing_integration_test.cc
@@ -32,6 +32,7 @@
#include "src/ipc/test/test_socket.h"
#include "perfetto/trace/test_event.pbzero.h"
+#include "perfetto/trace/trace_packet.pb.h"
#include "perfetto/trace/trace_packet.pbzero.h"
namespace perfetto {
@@ -186,18 +187,29 @@
// Read the log buffer.
consumer_endpoint->ReadBuffers();
size_t num_pack_rx = 0;
+ bool saw_clock_snapshot = false;
auto all_packets_rx = task_runner_->CreateCheckpoint("all_packets_rx");
EXPECT_CALL(consumer, OnTracePackets(_, _))
.WillRepeatedly(
- Invoke([&num_pack_rx, all_packets_rx](
+ Invoke([&num_pack_rx, all_packets_rx, &saw_clock_snapshot](
std::vector<TracePacket>* packets, bool has_more) {
- // TODO(primiano): check contents, requires both pblite and pzero.
- num_pack_rx += packets->size();
+ for (auto& packet : *packets) {
+ ASSERT_TRUE(packet.Decode());
+ if (packet->has_for_testing()) {
+ char buf[8];
+ sprintf(buf, "evt_%zu", num_pack_rx++);
+ EXPECT_EQ(std::string(buf), packet->for_testing().str());
+ } else if (packet->has_clock_snapshot()) {
+ EXPECT_GE(packet->clock_snapshot().clocks_size(), 8);
+ saw_clock_snapshot = true;
+ }
+ }
if (!has_more)
all_packets_rx();
}));
task_runner_->RunUntilCheckpoint("all_packets_rx");
ASSERT_EQ(kNumPackets, num_pack_rx);
+ EXPECT_TRUE(saw_clock_snapshot);
// TODO(primiano): cover FreeBuffers.
diff --git a/test/end_to_end_integrationtest.cc b/test/end_to_end_integrationtest.cc
index 0a13b9e..5183dd1 100644
--- a/test/end_to_end_integrationtest.cc
+++ b/test/end_to_end_integrationtest.cc
@@ -96,7 +96,9 @@
bool has_more) {
for (auto& packet : packets) {
ASSERT_TRUE(packet.Decode());
- ASSERT_TRUE(packet->has_ftrace_events());
+ ASSERT_TRUE(packet->has_ftrace_events() || packet->has_clock_snapshot());
+ if (packet->has_clock_snapshot())
+ continue;
for (int ev = 0; ev < packet->ftrace_events().event_size(); ev++) {
ASSERT_TRUE(packet->ftrace_events().event(ev).has_sched_switch());
}
@@ -171,6 +173,8 @@
for (auto& packet : packets) {
ASSERT_TRUE(packet.Decode());
+ if (packet->has_clock_snapshot())
+ continue;
ASSERT_TRUE(packet->has_for_testing());
ASSERT_EQ(protos::TracePacket::kTrustedUid,
packet->optional_trusted_uid_case());
@@ -179,7 +183,8 @@
total += packets.size();
if (!has_more) {
- ASSERT_EQ(total, kEventCount);
+ // One extra packet for the clock snapshot.
+ ASSERT_EQ(total, kEventCount + 1);
finish();
}
};