traced: Add initial timestamp
The trace currently includes a clock snapshot at the physical
beginning of the trace but since this is taken at read time
this may be after the trace has ended. This adds an additional
clock snapshot taken at the time the trace actually began and
reported at read time.
Bug: 130543265
Test: take a trace and look at first packet
Change-Id: I360eec3b71dd3e372914183218a939eb88443acf
diff --git a/src/tracing/core/tracing_service_impl.cc b/src/tracing/core/tracing_service_impl.cc
index e34c325..e375411 100644
--- a/src/tracing/core/tracing_service_impl.cc
+++ b/src/tracing/core/tracing_service_impl.cc
@@ -642,6 +642,11 @@
tracing_session->state = TracingSession::STARTED;
+ if (!tracing_session->config.builtin_data_sources()
+ .disable_clock_snapshotting()) {
+ SnapshotClocks(&tracing_session->initial_clock_snapshot_);
+ }
+
// Trigger delayed task if the trace is time limited.
const uint32_t trace_duration_ms = tracing_session->config.duration_ms();
if (trace_duration_ms > 0) {
@@ -1386,6 +1391,11 @@
std::vector<TracePacket> packets;
packets.reserve(1024); // Just an educated guess to avoid trivial expansions.
+ std::move(tracing_session->initial_clock_snapshot_.begin(),
+ tracing_session->initial_clock_snapshot_.end(),
+ std::back_inserter(packets));
+ tracing_session->initial_clock_snapshot_.clear();
+
base::TimeMillis now = base::GetWallTimeMs();
if (now >= tracing_session->last_snapshot_time + kSnapshotsInterval) {
tracing_session->last_snapshot_time = now;
@@ -1394,7 +1404,10 @@
if (!tracing_session->config.builtin_data_sources()
.disable_clock_snapshotting()) {
- SnapshotClocks(&packets);
+ // We don't want to put a root timestamp in this snapshot as the packet
+ // may be very out of order with respect to the actual trace packets
+ // since consuming the trace may happen at any point after it starts.
+ SnapshotClocks(&packets, /*set_timestamp*/ false);
}
}
if (!tracing_session->config.builtin_data_sources().disable_trace_config()) {
@@ -2060,7 +2073,8 @@
packets->back().AddSlice(&sync_marker_packet_[0], sync_marker_packet_size_);
}
-void TracingServiceImpl::SnapshotClocks(std::vector<TracePacket>* packets) {
+void TracingServiceImpl::SnapshotClocks(std::vector<TracePacket>* packets,
+ bool root_timestamp) {
protos::TrustedPacket packet;
protos::ClockSnapshot* clock_snapshot = packet.mutable_clock_snapshot();
@@ -2096,6 +2110,11 @@
PERFETTO_DLOG("clock_gettime failed for clock %d", clock.id);
}
for (auto& clock : clocks) {
+ if (root_timestamp &&
+ clock.type == protos::ClockSnapshot::Clock::BOOTTIME) {
+ packet.set_timestamp(
+ static_cast<uint64_t>(base::FromPosixTimespec(clock.ts).count()));
+ };
protos::ClockSnapshot::Clock* c = clock_snapshot->add_clocks();
c->set_type(clock.type);
c->set_timestamp(
diff --git a/src/tracing/core/tracing_service_impl.h b/src/tracing/core/tracing_service_impl.h
index c643b3a..40cb924 100644
--- a/src/tracing/core/tracing_service_impl.h
+++ b/src/tracing/core/tracing_service_impl.h
@@ -448,6 +448,11 @@
// The number of received triggers we've emitted into the trace output.
size_t num_triggers_emitted_into_trace = 0;
+ // Initial clock snapshot, captured at trace start time (when state goes
+ // to TracingSession::STARTED). Emitted into the trace when the consumer
+ // first begins reading the trace.
+ std::vector<TracePacket> initial_clock_snapshot_;
+
State state = DISABLED;
// If the consumer detached the session, this variable defines the key used
@@ -491,7 +496,7 @@
TracingSession* tracing_session,
DataSourceInstance* instance);
void SnapshotSyncMarker(std::vector<TracePacket>*);
- void SnapshotClocks(std::vector<TracePacket>*);
+ void SnapshotClocks(std::vector<TracePacket>*, bool set_timestamp = true);
void SnapshotStats(TracingSession*, std::vector<TracePacket>*);
TraceStats GetTraceStats(TracingSession* tracing_session);
void MaybeEmitTraceConfig(TracingSession*, std::vector<TracePacket>*);
diff --git a/src/tracing/core/tracing_service_impl_unittest.cc b/src/tracing/core/tracing_service_impl_unittest.cc
index 74653c6..781d672 100644
--- a/src/tracing/core/tracing_service_impl_unittest.cc
+++ b/src/tracing/core/tracing_service_impl_unittest.cc
@@ -1315,11 +1315,14 @@
producer->WaitForDataSourceStart("data_source");
// The preamble packets are:
+ // Trace start clocksnapshot
// Config
// SystemInfo
- // 3x unknown
- static const int kNumPreamblePackets = 5;
- static const int kNumTestPackets = 10;
+ // Trace read clocksnapshot
+ // Trace synchronisation
+ // Trace stats
+ static const int kNumPreamblePackets = 6;
+ static const int kNumTestPackets = 9;
static const char kPayload[] = "1234567890abcdef-";
std::unique_ptr<TraceWriter> writer =