Clock domain of TracingServiceEvent timestamps when primary_trace_clock is not BOOTTIME

[fabien0008]

Hi,

I’m trying to confirm the expected clock handling for TracingServiceEvent timestamps.

TracingServiceImpl captures lifecycle event timestamps using GetBootTimeNs() and emits the packet without timestamp_clock_id:

• Timestamp capture (

  perfetto/src/tracing/service/tracing_service_impl.cc

  Lines 3811 to 3841 in 0b6a9e9

  	void TracingServiceImpl::SnapshotLifecycleEvent(TracingSession* tracing_session,
  	uint32_t field_id,
  	bool snapshot_clocks) {
  	// field_id should be an id of a field in TracingServiceEvent.
  	auto& lifecycle_events = tracing_session->lifecycle_events;
  	auto event_it =
  	std::find_if(lifecycle_events.begin(), lifecycle_events.end(),
  	[field_id](const TracingSession::LifecycleEvent& event) {
  	return event.field_id == field_id;
  	});
  	TracingSession::LifecycleEvent* event;
  	if (event_it == lifecycle_events.end()) {
  	lifecycle_events.emplace_back(field_id);
  	event = &lifecycle_events.back();
  	} else {
  	event = &*event_it;
  	}
  	// Snapshot the clocks before capturing the timestamp for the event so we can
  	// use this snapshot to resolve the event timestamp if necessary.
  	if (snapshot_clocks)
  	MaybeSnapshotClocksIntoRingBuffer(tracing_session);
  	// Erase before emplacing to prevent a unncessary doubling of memory if
  	// not needed.
  	if (event->timestamps.size() >= event->max_size) {
  	event->timestamps.erase_front(1 + event->timestamps.size() -
  	event->max_size);
  	}
  	event->timestamps.emplace_back(clock_->GetBootTimeNs().count());

  )
• Packet emission (

  perfetto/src/tracing/service/tracing_service_impl.cc

  Lines 4237 to 4248 in 0b6a9e9

  	void TracingServiceImpl::EmitLifecycleEvents(
  	TracingSession* tracing_session,
  	std::vector<TracePacket>* packets) {
  	using TimestampedPacket =
  	std::pair<int64_t /* ts */, std::vector<uint8_t> /* serialized packet */>;
  	std::vector<TimestampedPacket> timestamped_packets;
  	for (auto& event : tracing_session->lifecycle_events) {
  	for (int64_t ts : event.timestamps) {
  	protozero::HeapBuffered<protos::pbzero::TracePacket> packet;
  	packet->set_timestamp(static_cast<uint64_t>(ts));
  	SetServiceTracePacketHeader(packet.get());

  )

TracePacket definition says that, when neither the packet nor its sequence defaults specify a clock, timestamp_clock_id defaults to BOOTTIME:

TracePacket timestamp clock (

perfetto/protos/perfetto/trace/trace_packet.proto

Lines 131 to 144 in 0b6a9e9

	// The timestamp of the TracePacket.
	// By default this timestamps refers to the trace clock (CLOCK_BOOTTIME on
	// Android). It can be overridden using a different timestamp_clock_id.
	// The clock domain definition in ClockSnapshot can also override:
	// - The unit (default: 1ns).
	// - The absolute vs delta encoding (default: absolute timestamp).
	optional uint64 timestamp = 8;
	// Specifies the ID of the clock used for the TracePacket |timestamp|. Can be
	// one of the built-in types from ClockSnapshot::BuiltinClocks, or a
	// producer-defined clock id.
	// If unspecified and if no default per-sequence value has been provided via
	// TracePacketDefaults, it defaults to BuiltinClocks::BOOTTIME.
	optional uint32 timestamp_clock_id = 58;

)

ProtoTraceReader handles service_event before the normal timestamp conversion path and passes the packet timestamp directly to ParseServiceEvent:

Service-event handling (

perfetto/src/trace_processor/importers/proto/proto_trace_reader.cc

Lines 374 to 377 in 0b6a9e9

	if (decoder.has_service_event()) {
	PERFETTO_DCHECK(decoder.has_timestamp());
	int64_t ts = static_cast<int64_t>(decoder.timestamp());
	return ParseServiceEvent(ts, decoder.service_event());

)

Consider a clock snapshot where BOOTTIME 1000 corresponds to MONOTONIC_RAW 100, with MONOTONIC_RAW selected as primary_trace_clock. If tracing_started has timestamp 1050 and no timestamp_clock_id, should tracing_started_ns be converted to 150? The current code appears to store 1050.

This seems related to issue #3705 and #3709, but the special service-event path bypasses the normal packet timestamp handling.

Am I missing an invariant that makes these timestamps already expressed in the primary trace clock, or should Trace Processor convert them from BOOTTIME?

[LalitMaganti]

Am I missing an invariant that makes these timestamps already expressed in the primary trace clock, or should Trace Processor convert them from BOOTTIME?

No you're not missing anything, this is indeed a missing conversion! Will send a change to fix this :)

[LalitMaganti]

#7117 should fix this issue.

[fabien0008]

Thanks Lalit! much appreciated. I checked #7117 and it covers the case I was seeing. Setting BOOTTIME explicitly on service packets also makes the intent much clearer.