diff --git a/protos/perfetto/common/builtin_clock.proto b/protos/perfetto/common/builtin_clock.proto index 559d1636ec5..453534fff3a 100644 --- a/protos/perfetto/common/builtin_clock.proto +++ b/protos/perfetto/common/builtin_clock.proto @@ -18,16 +18,55 @@ syntax = "proto2"; package perfetto.protos; +// Builtin clock domains used in Perfetto traces. +// +// The default trace time clock is BUILTIN_CLOCK_TRACE_FILE: a synthetic clock +// representing the trace file's own timeline. Each trace file gets its own +// instance (scoped by trace file index). +// +// For backwards compatibility, Perfetto proto traces register BOOTTIME as a +// fallback: if the first timestamp conversion uses a clock other than the +// trace file clock and no explicit clock snapshot data exists, the trace time +// is switched to BOOTTIME. This fallback does not fire for modern traces that +// include ClockSnapshots or that only use the trace file clock directly. +// +// The `primary_trace_clock` field in ClockSnapshot can definitively override +// the trace time clock regardless of the above. enum BuiltinClock { BUILTIN_CLOCK_UNKNOWN = 0; + + // Corresponds to CLOCK_REALTIME. See clock_gettime(2). BUILTIN_CLOCK_REALTIME = 1; + + // Corresponds to CLOCK_REALTIME_COARSE. See clock_gettime(2). BUILTIN_CLOCK_REALTIME_COARSE = 2; + + // Corresponds to CLOCK_MONOTONIC. See clock_gettime(2). BUILTIN_CLOCK_MONOTONIC = 3; + + // Corresponds to CLOCK_MONOTONIC_COARSE. See clock_gettime(2). BUILTIN_CLOCK_MONOTONIC_COARSE = 4; + + // Corresponds to CLOCK_MONOTONIC_RAW. See clock_gettime(2). BUILTIN_CLOCK_MONOTONIC_RAW = 5; + + // Corresponds to CLOCK_BOOTTIME. See clock_gettime(2). + // For proto traces, this is used as a backwards-compatible fallback trace + // time clock when no explicit clock snapshots are present. BUILTIN_CLOCK_BOOTTIME = 6; + + // TSC (Time Stamp Counter). Architecture-specific high-resolution counter. BUILTIN_CLOCK_TSC = 9; + + // Corresponds to the perf event clock (PERF_CLOCK). BUILTIN_CLOCK_PERF = 10; + + // A synthetic clock representing the trace file's own timeline. Each trace + // file gets its own instance (scoped by trace file index). This is the + // default trace time clock before any clock snapshot or format-specific + // override takes effect. + BUILTIN_CLOCK_TRACE_FILE = 11; + BUILTIN_CLOCK_MAX_ID = 63; reserved 7, 8; diff --git a/protos/perfetto/config/perfetto_config.proto b/protos/perfetto/config/perfetto_config.proto index 19d2c5adf4c..c9c1cb8a610 100644 --- a/protos/perfetto/config/perfetto_config.proto +++ b/protos/perfetto/config/perfetto_config.proto @@ -456,16 +456,55 @@ message TracingServiceState { // Begin of protos/perfetto/common/builtin_clock.proto +// Builtin clock domains used in Perfetto traces. +// +// The default trace time clock is BUILTIN_CLOCK_TRACE_FILE: a synthetic clock +// representing the trace file's own timeline. Each trace file gets its own +// instance (scoped by trace file index). +// +// For backwards compatibility, Perfetto proto traces register BOOTTIME as a +// fallback: if the first timestamp conversion uses a clock other than the +// trace file clock and no explicit clock snapshot data exists, the trace time +// is switched to BOOTTIME. This fallback does not fire for modern traces that +// include ClockSnapshots or that only use the trace file clock directly. +// +// The `primary_trace_clock` field in ClockSnapshot can definitively override +// the trace time clock regardless of the above. enum BuiltinClock { BUILTIN_CLOCK_UNKNOWN = 0; + + // Corresponds to CLOCK_REALTIME. See clock_gettime(2). BUILTIN_CLOCK_REALTIME = 1; + + // Corresponds to CLOCK_REALTIME_COARSE. See clock_gettime(2). BUILTIN_CLOCK_REALTIME_COARSE = 2; + + // Corresponds to CLOCK_MONOTONIC. See clock_gettime(2). BUILTIN_CLOCK_MONOTONIC = 3; + + // Corresponds to CLOCK_MONOTONIC_COARSE. See clock_gettime(2). BUILTIN_CLOCK_MONOTONIC_COARSE = 4; + + // Corresponds to CLOCK_MONOTONIC_RAW. See clock_gettime(2). BUILTIN_CLOCK_MONOTONIC_RAW = 5; + + // Corresponds to CLOCK_BOOTTIME. See clock_gettime(2). + // For proto traces, this is used as a backwards-compatible fallback trace + // time clock when no explicit clock snapshots are present. BUILTIN_CLOCK_BOOTTIME = 6; + + // TSC (Time Stamp Counter). Architecture-specific high-resolution counter. BUILTIN_CLOCK_TSC = 9; + + // Corresponds to the perf event clock (PERF_CLOCK). BUILTIN_CLOCK_PERF = 10; + + // A synthetic clock representing the trace file's own timeline. Each trace + // file gets its own instance (scoped by trace file index). This is the + // default trace time clock before any clock snapshot or format-specific + // override takes effect. + BUILTIN_CLOCK_TRACE_FILE = 11; + BUILTIN_CLOCK_MAX_ID = 63; reserved 7, 8; diff --git a/protos/perfetto/trace/clock_snapshot.proto b/protos/perfetto/trace/clock_snapshot.proto index b590d38a270..3e6d29c3753 100644 --- a/protos/perfetto/trace/clock_snapshot.proto +++ b/protos/perfetto/trace/clock_snapshot.proto @@ -72,9 +72,12 @@ message ClockSnapshot { } repeated Clock clocks = 1; - // The authoritative clock domain for the trace. Defaults to BOOTTIME, but can - // be overridden in TraceConfig's builtin_data_sources. Trace processor will - // attempt to translate packet/event timestamps from various data sources (and - // their chosen clock domains) to this domain during import. + // The authoritative clock domain for the trace. When set, this definitively + // overrides the trace time clock. If not set, the trace time clock remains + // at its default (BUILTIN_CLOCK_TRACE_FILE), unless a format-specific + // fallback applies (e.g. BOOTTIME for legacy proto traces without clock + // snapshots). Trace processor will attempt to translate packet/event + // timestamps from various data sources (and their chosen clock domains) to + // this domain during import. optional BuiltinClock primary_trace_clock = 2; } diff --git a/protos/perfetto/trace/perfetto_trace.proto b/protos/perfetto/trace/perfetto_trace.proto index d605954027e..95dec5bf125 100644 --- a/protos/perfetto/trace/perfetto_trace.proto +++ b/protos/perfetto/trace/perfetto_trace.proto @@ -456,16 +456,55 @@ message TracingServiceState { // Begin of protos/perfetto/common/builtin_clock.proto +// Builtin clock domains used in Perfetto traces. +// +// The default trace time clock is BUILTIN_CLOCK_TRACE_FILE: a synthetic clock +// representing the trace file's own timeline. Each trace file gets its own +// instance (scoped by trace file index). +// +// For backwards compatibility, Perfetto proto traces register BOOTTIME as a +// fallback: if the first timestamp conversion uses a clock other than the +// trace file clock and no explicit clock snapshot data exists, the trace time +// is switched to BOOTTIME. This fallback does not fire for modern traces that +// include ClockSnapshots or that only use the trace file clock directly. +// +// The `primary_trace_clock` field in ClockSnapshot can definitively override +// the trace time clock regardless of the above. enum BuiltinClock { BUILTIN_CLOCK_UNKNOWN = 0; + + // Corresponds to CLOCK_REALTIME. See clock_gettime(2). BUILTIN_CLOCK_REALTIME = 1; + + // Corresponds to CLOCK_REALTIME_COARSE. See clock_gettime(2). BUILTIN_CLOCK_REALTIME_COARSE = 2; + + // Corresponds to CLOCK_MONOTONIC. See clock_gettime(2). BUILTIN_CLOCK_MONOTONIC = 3; + + // Corresponds to CLOCK_MONOTONIC_COARSE. See clock_gettime(2). BUILTIN_CLOCK_MONOTONIC_COARSE = 4; + + // Corresponds to CLOCK_MONOTONIC_RAW. See clock_gettime(2). BUILTIN_CLOCK_MONOTONIC_RAW = 5; + + // Corresponds to CLOCK_BOOTTIME. See clock_gettime(2). + // For proto traces, this is used as a backwards-compatible fallback trace + // time clock when no explicit clock snapshots are present. BUILTIN_CLOCK_BOOTTIME = 6; + + // TSC (Time Stamp Counter). Architecture-specific high-resolution counter. BUILTIN_CLOCK_TSC = 9; + + // Corresponds to the perf event clock (PERF_CLOCK). BUILTIN_CLOCK_PERF = 10; + + // A synthetic clock representing the trace file's own timeline. Each trace + // file gets its own instance (scoped by trace file index). This is the + // default trace time clock before any clock snapshot or format-specific + // override takes effect. + BUILTIN_CLOCK_TRACE_FILE = 11; + BUILTIN_CLOCK_MAX_ID = 63; reserved 7, 8; @@ -7971,10 +8010,13 @@ message ClockSnapshot { } repeated Clock clocks = 1; - // The authoritative clock domain for the trace. Defaults to BOOTTIME, but can - // be overridden in TraceConfig's builtin_data_sources. Trace processor will - // attempt to translate packet/event timestamps from various data sources (and - // their chosen clock domains) to this domain during import. + // The authoritative clock domain for the trace. When set, this definitively + // overrides the trace time clock. If not set, the trace time clock remains + // at its default (BUILTIN_CLOCK_TRACE_FILE), unless a format-specific + // fallback applies (e.g. BOOTTIME for legacy proto traces without clock + // snapshots). Trace processor will attempt to translate packet/event + // timestamps from various data sources (and their chosen clock domains) to + // this domain during import. optional BuiltinClock primary_trace_clock = 2; } diff --git a/src/trace_processor/BUILD.gn b/src/trace_processor/BUILD.gn index 5e1a1950783..0f63f1d5b31 100644 --- a/src/trace_processor/BUILD.gn +++ b/src/trace_processor/BUILD.gn @@ -143,6 +143,7 @@ source_set("storage_minimal") { "tables", "types", "util:blob", + "util:clock", "util:descriptors", "util:gzip", "util:proto_to_args_parser", diff --git a/src/trace_processor/forwarding_trace_parser.cc b/src/trace_processor/forwarding_trace_parser.cc index 8078bddf82e..4a3a07d3115 100644 --- a/src/trace_processor/forwarding_trace_parser.cc +++ b/src/trace_processor/forwarding_trace_parser.cc @@ -25,6 +25,7 @@ #include "perfetto/ext/base/status_macros.h" #include "perfetto/trace_processor/basic_types.h" #include "src/trace_processor/importers/common/chunked_trace_reader.h" +#include "src/trace_processor/importers/common/clock_tracker.h" #include "src/trace_processor/importers/common/process_tracker.h" #include "src/trace_processor/importers/common/trace_file_tracker.h" #include "src/trace_processor/importers/proto/proto_trace_reader.h" @@ -33,8 +34,11 @@ #include "src/trace_processor/tables/metadata_tables_py.h" #include "src/trace_processor/trace_reader_registry.h" #include "src/trace_processor/types/trace_processor_context.h" +#include "src/trace_processor/util/clock_synchronizer.h" #include "src/trace_processor/util/trace_type.h" +#include "protos/perfetto/common/builtin_clock.pbzero.h" + namespace perfetto::trace_processor { namespace { @@ -140,6 +144,33 @@ base::Status ForwardingTraceParser::Init(const TraceBlobView& blob) { } ASSIGN_OR_RETURN(reader_, input_context_->reader_registry->CreateTraceReader( trace_type_, trace_context_)); + + // Centralize clock setup for all trace formats. Proto traces add an identity + // sync so BOOTTIME is reachable in the clock graph; the trace default clock + // is set later by ParseClockSnapshot. All other formats know their clock + // statically and set the global clock directly. + using ClockId = ClockTracker::ClockId; + if (trace_type_ == kProtoTraceType) { + trace_context_->clock_tracker->AddDeferredIdentitySync( + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_BOOTTIME)); + } else if (trace_type_ == kSystraceTraceType || + trace_type_ == kSimpleperfProtoTraceType || + trace_type_ == kPerfTextTraceType || + trace_type_ == kPerfDataTraceType || + trace_type_ == kArtMethodTraceType) { + trace_context_->clock_tracker->SetGlobalClock( + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_MONOTONIC)); + } else if (trace_type_ == kFuchsiaTraceType) { + trace_context_->clock_tracker->SetGlobalClock( + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_BOOTTIME)); + } else if (trace_type_ == kGeckoTraceType || trace_type_ == kJsonTraceType || + trace_type_ == kInstrumentsXmlTraceType) { + trace_context_->clock_tracker->SetGlobalClock( + ClockId::TraceFile(trace_context_->trace_id().value)); + } else if (trace_type_ == kAndroidDumpstateTraceType) { + trace_context_->clock_tracker->SetGlobalClock( + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_REALTIME)); + } return base::OkStatus(); } diff --git a/src/trace_processor/importers/android_bugreport/android_battery_stats_reader.cc b/src/trace_processor/importers/android_bugreport/android_battery_stats_reader.cc index 11c44c3a77a..0b1953bf08c 100644 --- a/src/trace_processor/importers/android_bugreport/android_battery_stats_reader.cc +++ b/src/trace_processor/importers/android_bugreport/android_battery_stats_reader.cc @@ -153,7 +153,7 @@ base::Status AndroidBatteryStatsReader::SendToSorter( std::chrono::nanoseconds event_ts, AndroidDumpstateEvent event) { std::optional trace_ts = context_->clock_tracker->ToTraceTime( - ClockTracker::ClockId(protos::pbzero::ClockSnapshot::Clock::REALTIME), + ClockId::Machine(protos::pbzero::ClockSnapshot::Clock::REALTIME), event_ts.count()); if (trace_ts) { stream_->Push(*trace_ts, std::move(event)); diff --git a/src/trace_processor/importers/android_bugreport/android_bugreport_reader.cc b/src/trace_processor/importers/android_bugreport/android_bugreport_reader.cc index dbf7900bb22..b0db8d09496 100644 --- a/src/trace_processor/importers/android_bugreport/android_bugreport_reader.cc +++ b/src/trace_processor/importers/android_bugreport/android_bugreport_reader.cc @@ -38,6 +38,7 @@ #include "src/trace_processor/importers/common/clock_tracker.h" #include "src/trace_processor/importers/common/trace_file_tracker.h" #include "src/trace_processor/types/trace_processor_context.h" +#include "src/trace_processor/util/clock_synchronizer.h" #include "src/trace_processor/util/trace_type.h" #include "src/trace_processor/util/zip_reader.h" @@ -95,7 +96,14 @@ std::optional FindBugReportFile( AndroidBugreportReader::AndroidBugreportReader(TraceProcessorContext* context) : context_(context), - dumpstate_reader_(std::make_unique(context_)) {} + dumpstate_reader_(std::make_unique(context_)) { + // All logs in Android bugreports use wall time (which creates problems + // in case of early boot events before NTP kicks in, which get emitted as + // 1970), but that is the state of affairs. + using ClockId = ClockTracker::ClockId; + context_->clock_tracker->SetGlobalClock( + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_REALTIME)); +} AndroidBugreportReader::~AndroidBugreportReader() = default; @@ -129,12 +137,6 @@ base::Status AndroidBugreportReader::Parse(std::vector files) { ordered_log_files.insert(LogFile{id, timestamp, std::move(files[i])}); } - // All logs in Android bugreports use wall time (which creates problems - // in case of early boot events before NTP kicks in, which get emitted as - // 1970), but that is the state of affairs. - context_->clock_tracker->SetTraceTimeClock( - ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_REALTIME)); - ASSIGN_OR_RETURN(std::vector logcat_events, ParseDumpstateTxt(bug_report)); return ParsePersistentLogcat(bug_report, ordered_log_files, diff --git a/src/trace_processor/importers/android_bugreport/android_dumpstate_reader.cc b/src/trace_processor/importers/android_bugreport/android_dumpstate_reader.cc index 95f6e96b66e..b716c092dc9 100644 --- a/src/trace_processor/importers/android_bugreport/android_dumpstate_reader.cc +++ b/src/trace_processor/importers/android_bugreport/android_dumpstate_reader.cc @@ -27,7 +27,6 @@ #include "perfetto/ext/base/string_utils.h" #include "perfetto/ext/base/string_view.h" #include "perfetto/ext/base/string_view_splitter.h" -#include "protos/perfetto/common/builtin_clock.pbzero.h" #include "src/trace_processor/importers/android_bugreport/android_battery_stats_reader.h" #include "src/trace_processor/importers/android_bugreport/android_log_reader.h" #include "src/trace_processor/importers/common/clock_tracker.h" @@ -53,9 +52,6 @@ base::Status AndroidDumpstateReader::ParseLine(base::StringView line) { base::Status AndroidDumpstateReader::ParseLine( BufferingAndroidLogReader* const log_reader, base::StringView line) { - context_->clock_tracker->SetTraceTimeClock( - ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_REALTIME)); - // Dumpstate is organized in a two level hierarchy, beautifully flattened into // one text file with load bearing ----- markers: // 1. Various dumpstate sections, examples: diff --git a/src/trace_processor/importers/android_bugreport/android_log_reader.cc b/src/trace_processor/importers/android_bugreport/android_log_reader.cc index 9d8ebf0dc5c..839f6aa9bfb 100644 --- a/src/trace_processor/importers/android_bugreport/android_log_reader.cc +++ b/src/trace_processor/importers/android_bugreport/android_log_reader.cc @@ -273,8 +273,7 @@ base::Status AndroidLogReader::SendToSorter(std::chrono::nanoseconds event_ts, int64_t ts = event_ts.count() - context_->clock_tracker->timezone_offset().value_or(0); std::optional trace_ts = context_->clock_tracker->ToTraceTime( - ClockTracker::ClockId(protos::pbzero::ClockSnapshot::Clock::REALTIME), - ts); + ClockId::Machine(protos::pbzero::ClockSnapshot::Clock::REALTIME), ts); if (trace_ts) { stream_->Push(*trace_ts, event); } diff --git a/src/trace_processor/importers/android_bugreport/android_log_unittest.cc b/src/trace_processor/importers/android_bugreport/android_log_unittest.cc index 0e867aa0541..959337b1af2 100644 --- a/src/trace_processor/importers/android_bugreport/android_log_unittest.cc +++ b/src/trace_processor/importers/android_bugreport/android_log_unittest.cc @@ -38,6 +38,8 @@ #include "src/trace_processor/storage/stats.h" #include "src/trace_processor/storage/trace_storage.h" #include "src/trace_processor/types/trace_processor_context.h" +#include "src/trace_processor/types/trace_processor_context_ptr.h" +#include "src/trace_processor/util/clock_synchronizer.h" #include "test/gtest_and_gmock.h" #include "protos/perfetto/common/android_log_constants.pbzero.h" @@ -74,12 +76,16 @@ class AndroidLogReaderTest : public ::testing::Test { TraceProcessorContextPtr::MakeRoot( TraceProcessorContext::TraceState{TraceId(0)}); context_.metadata_tracker = std::make_unique(&context_); - context_.trace_time_state = std::make_unique(TraceTimeState{ - ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_BOOTTIME), false}); + context_.trace_time_state = std::make_unique( + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_BOOTTIME)); + primary_sync_ = std::make_unique( + context_.trace_time_state.get(), + std::make_unique(&context_)); context_.clock_tracker = std::make_unique( - &context_, std::make_unique(&context_)); - context_.clock_tracker->SetTraceTimeClock( - ClockTracker::ClockId(protos::pbzero::ClockSnapshot::Clock::REALTIME)); + &context_, std::make_unique(&context_), + primary_sync_.get(), true); + context_.clock_tracker->SetGlobalClock( + ClockId::Machine(protos::pbzero::ClockSnapshot::Clock::REALTIME)); context_.sorter = std::make_unique( &context_, TraceSorter::SortingMode::kDefault); } @@ -92,6 +98,7 @@ class AndroidLogReaderTest : public ::testing::Test { private: TraceProcessorContext context_; + std::unique_ptr primary_sync_; }; TEST_F(AndroidLogReaderTest, PersistentLogFormat) { diff --git a/src/trace_processor/importers/art_method/art_method_tokenizer.cc b/src/trace_processor/importers/art_method/art_method_tokenizer.cc index f5283964dcf..fbe742c48b0 100644 --- a/src/trace_processor/importers/art_method/art_method_tokenizer.cc +++ b/src/trace_processor/importers/art_method/art_method_tokenizer.cc @@ -42,6 +42,7 @@ #include "src/trace_processor/importers/common/stack_profile_tracker.h" #include "src/trace_processor/storage/trace_storage.h" #include "src/trace_processor/types/trace_processor_context.h" +#include "src/trace_processor/util/clock_synchronizer.h" #include "src/trace_processor/util/trace_blob_view_reader.h" #include "protos/perfetto/common/builtin_clock.pbzero.h" @@ -106,8 +107,6 @@ base::Status ArtMethodTokenizer::Parse(TraceBlobView blob) { uint32_t magic = ToInt(*smagic); sub_parser_ = magic == kTraceMagic ? SubParser{Streaming{this}} : SubParser{NonStreaming{this}}; - context_->clock_tracker->SetTraceTimeClock( - ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_MONOTONIC)); } if (sub_parser_.index() == base::variant_index()) { return std::get(sub_parser_).Parse(); @@ -216,7 +215,7 @@ base::Status ArtMethodTokenizer::ParseRecord(uint32_t tid, break; } std::optional ts = context_->clock_tracker->ToTraceTime( - ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_MONOTONIC), + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_MONOTONIC), (ts_ + ts_delta) * 1000); if (ts) { stream_->Push(*ts, evt); diff --git a/src/trace_processor/importers/common/BUILD.gn b/src/trace_processor/importers/common/BUILD.gn index fef1cd974ac..eeab79d2343 100644 --- a/src/trace_processor/importers/common/BUILD.gn +++ b/src/trace_processor/importers/common/BUILD.gn @@ -86,6 +86,7 @@ source_set("common") { ] public_deps = [ ":synthetic_tid_hdr", + "../../util:clock", "../../util:proto_to_args_parser", "../../util:protozero_to_text", ] @@ -107,7 +108,6 @@ source_set("common") { "../../tables:tables", "../../types", "../../util:build_id", - "../../util:clock", "../../util:profiler_util", "../../util:trace_type", "../../util/elf", diff --git a/src/trace_processor/importers/common/clock_tracker.cc b/src/trace_processor/importers/common/clock_tracker.cc index 5e1bb34def5..8d61a116f3e 100644 --- a/src/trace_processor/importers/common/clock_tracker.cc +++ b/src/trace_processor/importers/common/clock_tracker.cc @@ -21,12 +21,14 @@ #include #include #include +#include #include #include "perfetto/base/logging.h" #include "perfetto/base/status.h" #include "perfetto/ext/base/flat_hash_map.h" #include "perfetto/ext/base/status_or.h" +#include "perfetto/public/compiler.h" #include "src/trace_processor/importers/common/args_tracker.h" #include "src/trace_processor/importers/common/import_logs_tracker.h" #include "src/trace_processor/importers/common/metadata_tracker.h" @@ -43,31 +45,78 @@ namespace perfetto::trace_processor { ClockTracker::ClockTracker( TraceProcessorContext* context, - std::unique_ptr listener) + std::unique_ptr listener, + ClockSynchronizer* primary_sync, + bool is_primary) : context_(context), - sync_(context->trace_time_state.get(), std::move(listener)) {} + sync_(context->trace_time_state.get(), std::move(listener)), + active_sync_(primary_sync), + is_primary_(is_primary) { + PERFETTO_CHECK(primary_sync); +} base::StatusOr ClockTracker::AddSnapshot( const std::vector& clock_timestamps) { - return sync_.AddSnapshot(clock_timestamps); + if (PERFETTO_UNLIKELY(!is_primary_)) { + // Non-primary trace: if we were using the primary's pool and already + // converted timestamps, those conversions may have used different clock + // data than our own. + if (PERFETTO_UNLIKELY(active_sync_ != &sync_ && num_conversions_ > 0)) { + context_->import_logs_tracker->RecordAnalysisError( + stats::clock_sync_mixed_clock_sources, + [&](ArgsTracker::BoundInserter& inserter) { + StringId key = context_->storage->InternString( + "num_conversions_using_primary"); + inserter.AddArg(key, Variadic::UnsignedInteger(num_conversions_)); + }); + } + // Switch to our own sync and add the snapshot there. + active_sync_ = &sync_; + } + return active_sync_->AddSnapshot(clock_timestamps); } -base::Status ClockTracker::SetTraceTimeClock(ClockId clock_id) { - PERFETTO_DCHECK(!ClockSynchronizer::IsSequenceClock(clock_id.clock_id)); - auto* state = context_->trace_time_state.get(); - if (state->used_for_conversion && state->clock_id != clock_id) { +base::Status ClockTracker::SetGlobalClock(ClockId clock_id) { + PERFETTO_DCHECK(!clock_id.IsSequenceClock()); + if (num_conversions_ > 0) { + auto* state = context_->trace_time_state.get(); return base::ErrStatus( "Not updating trace time clock from %s to %s" " because the old clock was already used for timestamp " "conversion - ClockSnapshot too late in trace?", state->clock_id.ToString().c_str(), clock_id.ToString().c_str()); } + auto* state = context_->trace_time_state.get(); + uint32_t my_trace_id = context_->trace_id().value; + // Another trace file owns the clock. Don't override. + if (state->trace_time_clock_owner && + *state->trace_time_clock_owner != my_trace_id) { + return base::OkStatus(); + } + state->trace_time_clock_owner = my_trace_id; state->clock_id = clock_id; context_->metadata_tracker->SetMetadata(metadata::trace_time_clock_id, Variadic::Integer(clock_id.clock_id)); return base::OkStatus(); } +void ClockTracker::SetTraceDefaultClock(ClockId clock_id) { + trace_default_clock_ = clock_id; +} + +void ClockTracker::AddDeferredIdentitySync(ClockId clock_id) { + deferred_identity_clock_ = clock_id; +} + +void ClockTracker::FlushDeferredIdentitySync() { + ClockId clock_id = *deferred_identity_clock_; + deferred_identity_clock_.reset(); + auto* state = context_->trace_time_state.get(); + if (clock_id != state->clock_id && !active_sync_->HasClock(clock_id)) { + active_sync_->AddSnapshot({{clock_id, 0}, {state->clock_id, 0}}); + } +} + std::optional ClockTracker::ToTraceTimeFromSnapshot( const std::vector& snapshot) { auto* state = context_->trace_time_state.get(); @@ -75,46 +124,37 @@ std::optional ClockTracker::ToTraceTimeFromSnapshot( [state](const ClockTimestamp& clock_timestamp) { return clock_timestamp.clock.id == state->clock_id; }); - if (it == snapshot.end()) + if (it == snapshot.end()) { return std::nullopt; + } return it->timestamp; } void ClockTracker::SetRemoteClockOffset(ClockId clock_id, int64_t offset) { - remote_clock_offsets_[clock_id] = offset; + context_->trace_time_state->remote_clock_offsets[clock_id] = offset; } std::optional ClockTracker::timezone_offset() const { - return timezone_offset_; + return context_->trace_time_state->timezone_offset; } void ClockTracker::set_timezone_offset(int64_t offset) { - timezone_offset_ = offset; -} - -// --- ClockTracker: private slow paths --- - -void ClockTracker::OnFirstTraceTimeUse() { - auto* state = context_->trace_time_state.get(); - context_->metadata_tracker->SetMetadata( - metadata::trace_time_clock_id, - Variadic::Integer(state->clock_id.clock_id)); - state->used_for_conversion = true; + context_->trace_time_state->timezone_offset = offset; } // --- ClockTracker: testing --- void ClockTracker::set_cache_lookups_disabled_for_testing(bool v) { - sync_.set_cache_lookups_disabled_for_testing(v); + active_sync_->set_cache_lookups_disabled_for_testing(v); } const base::FlatHashMap& ClockTracker::remote_clock_offsets_for_testing() { - return remote_clock_offsets_; + return context_->trace_time_state->remote_clock_offsets; } uint32_t ClockTracker::cache_hits_for_testing() const { - return sync_.cache_hits_for_testing(); + return active_sync_->cache_hits_for_testing(); } // --- ClockSynchronizerListenerImpl --- diff --git a/src/trace_processor/importers/common/clock_tracker.h b/src/trace_processor/importers/common/clock_tracker.h index 6ea31ffa7d7..f2843f2b639 100644 --- a/src/trace_processor/importers/common/clock_tracker.h +++ b/src/trace_processor/importers/common/clock_tracker.h @@ -47,22 +47,31 @@ class ClockTracker { using ClockTimestamp = ::perfetto::trace_processor::ClockTimestamp; using Clock = ::perfetto::trace_processor::Clock; + // |primary_sync| is the primary trace's ClockSynchronizer. For the primary + // trace (first trace for a machine), snapshots are added directly to + // |primary_sync| and it is used for all conversions. For non-primary traces, + // |primary_sync| is used for conversions until the first AddSnapshot call, + // at which point the tracker switches to its own internal sync. ClockTracker(TraceProcessorContext* context, - std::unique_ptr listener); + std::unique_ptr listener, + ClockSynchronizer* primary_sync, + bool is_primary); // --- Hot-path APIs (inlined) --- // Converts a timestamp to the trace time domain. On the first call, also - // "locks" the trace time clock, preventing it from being changed later. + // finalizes the trace time clock, preventing it from being changed later. PERFETTO_ALWAYS_INLINE std::optional ToTraceTime( ClockId clock_id, int64_t timestamp, std::optional byte_offset = std::nullopt) { - auto* state = context_->trace_time_state.get(); - if (PERFETTO_UNLIKELY(!state->used_for_conversion)) { - OnFirstTraceTimeUse(); + if (PERFETTO_UNLIKELY(deferred_identity_clock_.has_value())) { + FlushDeferredIdentitySync(); } - auto ts = sync_.Convert(clock_id, timestamp, state->clock_id, byte_offset); + auto* state = context_->trace_time_state.get(); + ++num_conversions_; + auto ts = active_sync_->Convert(clock_id, timestamp, state->clock_id, + byte_offset); return ts ? std::optional(ToHostTraceTime(*ts)) : ts; } @@ -72,17 +81,8 @@ class ClockTracker { int64_t ts, ClockId target, std::optional byte_offset = {}) { - return sync_.Convert(src, ts, target, byte_offset); - } - - static bool IsSequenceClock(uint32_t raw_clock_id) { - return ClockSynchronizer::IsSequenceClock(raw_clock_id); - } - - static ClockId SequenceToGlobalClock(uint32_t tfi, - uint32_t seq, - uint32_t clk) { - return ClockSynchronizer::SequenceToGlobalClock(tfi, seq, clk); + ++num_conversions_; + return active_sync_->Convert(src, ts, target, byte_offset); } // --- Slow-path public APIs --- @@ -90,7 +90,27 @@ class ClockTracker { base::StatusOr AddSnapshot( const std::vector& clock_timestamps); - base::Status SetTraceTimeClock(ClockId clock_id); + // --- Low-level clock primitives. Do not call without understanding the + // --- consequences. Most callers should use the helpers below these. + + // Sets the global trace time clock (trace_time_state->clock_id). + // All TP timestamps will be converted to this clock domain. + // Returns error if called after conversions have already happened. + base::Status SetGlobalClock(ClockId clock_id); + + // Sets the default clock for this trace file only (no global effect). + // Used as fallback when no timestamp_clock_id is specified. + void SetTraceDefaultClock(ClockId clock_id); + + // Registers a deferred identity sync: on the first ToTraceTime call that + // fails, a zero-offset edge between |clock_id| and the global trace time + // clock will be injected and the conversion retried. + void AddDeferredIdentitySync(ClockId clock_id); + + // Returns the trace default clock, if one has been set. + std::optional trace_default_clock() const { + return trace_default_clock_; + } std::optional ToTraceTimeFromSnapshot( const std::vector& snapshot); @@ -113,16 +133,41 @@ class ClockTracker { return timestamp; } auto* state = context_->trace_time_state.get(); - int64_t clock_offset = remote_clock_offsets_[state->clock_id]; + int64_t clock_offset = state->remote_clock_offsets[state->clock_id]; return timestamp - clock_offset; } - void OnFirstTraceTimeUse(); + PERFETTO_NO_INLINE void FlushDeferredIdentitySync(); TraceProcessorContext* context_; + + // Private ClockSynchronizer used for non-primary traces. Primary traces use + // the externally provided |primary_sync_| directly and don't use this member. ClockSynchronizer sync_; - base::FlatHashMap remote_clock_offsets_; - std::optional timezone_offset_; + + // Points to the ClockSynchronizer used for conversions. Starts at + // |primary_sync_| and switches to |sync_| for non-primary traces + // on the first AddSnapshot call. + ClockSynchronizer* active_sync_; + + // Whether this is the primary trace for its machine. Non-primary + // traces start using primary_sync_ and switch to sync_ on first AddSnapshot. + bool is_primary_ = true; + + // Total number of conversions performed. When a non-primary trace switches + // to its own sync, this value indicates how many conversions used the + // primary trace's clocks. + uint32_t num_conversions_ = 0; + + // The default clock for this trace file, set via SetTraceDefaultClock. + // Used by proto_trace_reader as a fallback when no timestamp_clock_id + // is specified. + std::optional trace_default_clock_; + + // Clock registered via AddDeferredIdentitySync. Flushed (and cleared) on + // first ToTraceTime call: if the clock is not yet in the graph, a 0:0 + // identity edge is injected. + std::optional deferred_identity_clock_; }; class ClockSynchronizerListenerImpl : public ClockSynchronizerListener { diff --git a/src/trace_processor/importers/common/clock_tracker_unittest.cc b/src/trace_processor/importers/common/clock_tracker_unittest.cc index a33739c2891..acabe62e043 100644 --- a/src/trace_processor/importers/common/clock_tracker_unittest.cc +++ b/src/trace_processor/importers/common/clock_tracker_unittest.cc @@ -30,6 +30,8 @@ #include "src/trace_processor/importers/common/metadata_tracker.h" #include "src/trace_processor/storage/trace_storage.h" #include "src/trace_processor/types/trace_processor_context.h" +#include "src/trace_processor/types/trace_processor_context_ptr.h" +#include "src/trace_processor/util/clock_synchronizer.h" #include "test/gtest_and_gmock.h" #include "protos/perfetto/common/builtin_clock.pbzero.h" @@ -53,10 +55,14 @@ class ClockTrackerTest : public ::testing::Test { new ImportLogsTracker(&context_, TraceId(1))); context_.machine_tracker = std::make_unique(&context_, kDefaultMachineId); - context_.trace_time_state = std::make_unique(TraceTimeState{ - ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_BOOTTIME), false}); + context_.trace_time_state = std::make_unique( + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_BOOTTIME)); + primary_sync_ = std::make_unique( + context_.trace_time_state.get(), + std::make_unique(&context_)); ct_ = std::make_unique( - &context_, std::make_unique(&context_)); + &context_, std::make_unique(&context_), + primary_sync_.get(), true); } std::optional Convert(ClockTracker::ClockId src_clock_id, int64_t src_timestamp, @@ -65,6 +71,7 @@ class ClockTrackerTest : public ::testing::Test { } TraceProcessorContext context_; + std::unique_ptr primary_sync_; std::unique_ptr ct_; }; @@ -73,16 +80,16 @@ namespace { using ::testing::NiceMock; using Clock = protos::pbzero::ClockSnapshot::Clock; -constexpr ClockTracker::ClockId REALTIME( - protos::pbzero::BUILTIN_CLOCK_REALTIME); -constexpr ClockTracker::ClockId BOOTTIME( - protos::pbzero::BUILTIN_CLOCK_BOOTTIME); -constexpr ClockTracker::ClockId MONOTONIC( - protos::pbzero::BUILTIN_CLOCK_MONOTONIC); -constexpr ClockTracker::ClockId MONOTONIC_COARSE( - protos::pbzero::BUILTIN_CLOCK_MONOTONIC_COARSE); -constexpr ClockTracker::ClockId MONOTONIC_RAW( - protos::pbzero::BUILTIN_CLOCK_MONOTONIC_RAW); +constexpr ClockTracker::ClockId REALTIME = + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_REALTIME); +constexpr ClockTracker::ClockId BOOTTIME = + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_BOOTTIME); +constexpr ClockTracker::ClockId MONOTONIC = + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_MONOTONIC); +constexpr ClockTracker::ClockId MONOTONIC_COARSE = + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_MONOTONIC_COARSE); +constexpr ClockTracker::ClockId MONOTONIC_RAW = + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_MONOTONIC_RAW); TEST_F(ClockTrackerTest, ClockDomainConversions) { EXPECT_FALSE(ct_->ToTraceTime(REALTIME, 0).has_value()); @@ -232,10 +239,10 @@ TEST_F(ClockTrackerTest, NonStrictlyMonotonic) { TEST_F(ClockTrackerTest, SequenceScopedClocks) { ct_->AddSnapshot({{MONOTONIC, 1000}, {BOOTTIME, 100000}}); - ClockTracker::ClockId c64_1 = ClockTracker::SequenceToGlobalClock(0, 1, 64); - ClockTracker::ClockId c65_1 = ClockTracker::SequenceToGlobalClock(0, 1, 65); - ClockTracker::ClockId c66_1 = ClockTracker::SequenceToGlobalClock(0, 1, 66); - ClockTracker::ClockId c66_2 = ClockTracker::SequenceToGlobalClock(0, 2, 64); + ClockTracker::ClockId c64_1 = ClockId::Sequence(0, 1, 64); + ClockTracker::ClockId c65_1 = ClockId::Sequence(0, 1, 65); + ClockTracker::ClockId c66_1 = ClockId::Sequence(0, 1, 66); + ClockTracker::ClockId c66_2 = ClockId::Sequence(0, 2, 64); ct_->AddSnapshot({{MONOTONIC, 10000}, {c64_1, 100000}, @@ -372,8 +379,8 @@ TEST_F(ClockTrackerTest, ClockOffset) { ct_->AddSnapshot({{REALTIME, 30}, {BOOTTIME, 30030}}); ct_->AddSnapshot({{MONOTONIC, 1000}, {BOOTTIME, 100000}}); - auto seq_clock_1 = ClockTracker::SequenceToGlobalClock(0, 1, 64); - auto seq_clock_2 = ClockTracker::SequenceToGlobalClock(0, 2, 64); + auto seq_clock_1 = ClockId::Sequence(0, 1, 64); + auto seq_clock_2 = ClockId::Sequence(0, 2, 64); ct_->AddSnapshot({{MONOTONIC, 2000}, {seq_clock_1, 1200}}); ct_->AddSnapshot({{seq_clock_1, 1300}, {seq_clock_2, 2000, 10, false}}); @@ -413,8 +420,8 @@ TEST_F(ClockTrackerTest, RemoteNoClockOffset) { ct_->AddSnapshot({{REALTIME, 20}, {BOOTTIME, 20220}}); ct_->AddSnapshot({{MONOTONIC, 1000}, {BOOTTIME, 100000}}); - auto seq_clock_1 = ClockTracker::SequenceToGlobalClock(0, 1, 64); - auto seq_clock_2 = ClockTracker::SequenceToGlobalClock(0, 2, 64); + auto seq_clock_1 = ClockId::Sequence(0, 1, 64); + auto seq_clock_2 = ClockId::Sequence(0, 2, 64); ct_->AddSnapshot({{MONOTONIC, 2000}, {seq_clock_1, 1200}}); ct_->AddSnapshot({{seq_clock_1, 1300}, {seq_clock_2, 2000, 10, false}}); @@ -444,14 +451,14 @@ TEST_F(ClockTrackerTest, NonDefaultTraceTimeClock) { context_.machine_tracker = std::make_unique(&context_, 0x1001); - ct_->SetTraceTimeClock(MONOTONIC); + ct_->SetGlobalClock(MONOTONIC); ct_->SetRemoteClockOffset(MONOTONIC, -2000); ct_->SetRemoteClockOffset(BOOTTIME, -10000); // This doesn't take effect. ct_->AddSnapshot({{REALTIME, 10}, {BOOTTIME, 10010}}); ct_->AddSnapshot({{MONOTONIC, 1000}, {BOOTTIME, 100000}}); - auto seq_clock_1 = ClockTracker::SequenceToGlobalClock(0, 1, 64); + auto seq_clock_1 = ClockId::Sequence(0, 1, 64); ct_->AddSnapshot({{MONOTONIC, 2000}, {seq_clock_1, 1200}}); int64_t realtime_to_trace_time_delta = -10 + 10010 - 100000 + 1000 - (-2000); @@ -567,5 +574,152 @@ TEST_F(ClockTrackerTest, ThreeHopConversion) { EXPECT_EQ(ct_->cache_hits_for_testing(), hits + 2); } +// Tests for multi-trace clock isolation (shared_sync fallback). +TEST_F(ClockTrackerTest, NonPrimaryUsesSharedSnapshots) { + // Set up a shared ClockSynchronizer (simulating the per-machine shared sync). + ClockSynchronizer shared_sync( + context_.trace_time_state.get(), + std::make_unique(&context_)); + // Add snapshots to the shared sync (primary trace's snapshots). + shared_sync.AddSnapshot({{REALTIME, 10}, {BOOTTIME, 10010}}); + shared_sync.AddSnapshot({{MONOTONIC, 1000}, {BOOTTIME, 100000}}); + + // Create a non-primary ClockTracker that falls back to shared_sync. + auto non_primary = std::make_unique( + &context_, std::make_unique(&context_), + &shared_sync, /*is_primary=*/false); + + // Non-primary should be able to convert using the shared snapshots. + EXPECT_EQ(*non_primary->ToTraceTime(REALTIME, 10), 10010); + EXPECT_EQ(*non_primary->ToTraceTime(REALTIME, 20), 10020); + EXPECT_EQ(*non_primary->ToTraceTime(MONOTONIC, 1000), 100000); +} + +TEST_F(ClockTrackerTest, NonPrimarySwitchesToOwnOnAddSnapshot) { + ClockSynchronizer shared_sync( + context_.trace_time_state.get(), + std::make_unique(&context_)); + shared_sync.AddSnapshot({{REALTIME, 10}, {BOOTTIME, 10010}}); + + auto non_primary = std::make_unique( + &context_, std::make_unique(&context_), + &shared_sync, /*is_primary=*/false); + + // Before own snapshot: uses shared snapshots. + EXPECT_EQ(*non_primary->ToTraceTime(REALTIME, 10), 10010); + + // Add own snapshot with different offset. + non_primary->AddSnapshot({{REALTIME, 100}, {BOOTTIME, 200100}}); + + // After own snapshot: uses own sync, not shared. + EXPECT_EQ(*non_primary->ToTraceTime(REALTIME, 100), 200100); + EXPECT_EQ(*non_primary->ToTraceTime(REALTIME, 110), 200110); +} + +TEST_F(ClockTrackerTest, PrimaryTraceAlwaysUsesSharedSync) { + ClockSynchronizer shared_sync( + context_.trace_time_state.get(), + std::make_unique(&context_)); + + // Create primary trace ClockTracker pointing to shared_sync. + auto primary = std::make_unique( + &context_, std::make_unique(&context_), + &shared_sync, /*is_primary=*/true); + + // Primary adds snapshots — they should go to shared_sync. + primary->AddSnapshot({{REALTIME, 10}, {BOOTTIME, 10010}}); + + // Primary converts using shared_sync. + EXPECT_EQ(*primary->ToTraceTime(REALTIME, 10), 10010); + + // A non-primary trace should also see the primary's snapshots. + auto non_primary = std::make_unique( + &context_, std::make_unique(&context_), + &shared_sync, /*is_primary=*/false); + EXPECT_EQ(*non_primary->ToTraceTime(REALTIME, 10), 10010); +} + +// --- TraceTimeSetup state machine tests --- + +TEST_F(ClockTrackerTest, SetTraceTimeClockBehavior) { + ct_->SetGlobalClock(BOOTTIME); + ct_->AddSnapshot({{REALTIME, 10}, {BOOTTIME, 10010}}); + EXPECT_EQ(*ct_->ToTraceTime(REALTIME, 10), 10010); +} + +TEST_F(ClockTrackerTest, AddDeferredIdentitySync_InjectsEdge) { + // AddDeferredIdentitySync injects a zero-offset edge between the given clock + // and the trace time clock (BOOTTIME in test fixture). + constexpr ClockTracker::ClockId TRACE_FILE = ClockId::TraceFile(0); + ct_->AddDeferredIdentitySync(TRACE_FILE); + + // The identity edge allows conversion: TRACE_FILE timestamps pass through. + EXPECT_EQ(*ct_->ToTraceTime(TRACE_FILE, 42), 42); + EXPECT_EQ(*ct_->ToTraceTime(TRACE_FILE, 100), 100); +} + +TEST_F(ClockTrackerTest, SetTraceDefaultClock_SetsDefaultClock) { + constexpr ClockTracker::ClockId TRACE_FILE = ClockId::TraceFile(0); + ct_->SetTraceDefaultClock(TRACE_FILE); + + ASSERT_TRUE(ct_->trace_default_clock().has_value()); + EXPECT_EQ(*ct_->trace_default_clock(), TRACE_FILE); +} + +TEST_F(ClockTrackerTest, AddDeferredIdentitySync_MatchesTraceTimeClock) { + // If the identity clock IS the trace time clock, no edge needed. + ct_->AddDeferredIdentitySync(BOOTTIME); + + ct_->AddSnapshot({{REALTIME, 10}, {BOOTTIME, 10010}}); + EXPECT_EQ(*ct_->ToTraceTime(REALTIME, 10), 10010); + EXPECT_EQ(*ct_->ToTraceTime(BOOTTIME, 42), 42); +} + +TEST_F(ClockTrackerTest, AddDeferredIdentitySync_WithExplicitSnapshot) { + // AddDeferredIdentitySync creates a zero-offset edge TRACE_FILE ↔ BOOTTIME + // (since BOOTTIME is the global trace time clock in the test fixture). + constexpr ClockTracker::ClockId TRACE_FILE = ClockId::TraceFile(0); + ct_->AddDeferredIdentitySync(TRACE_FILE); + + // Without any other snapshot, TRACE_FILE converts to BOOTTIME at offset 0. + EXPECT_EQ(*ct_->ToTraceTime(TRACE_FILE, 42), 42); + + // An explicit snapshot overrides the identity edge with real data. + ct_->AddSnapshot({{TRACE_FILE, 100}, {BOOTTIME, 1100}}); + EXPECT_EQ(*ct_->ToTraceTime(TRACE_FILE, 100), 1100); + EXPECT_EQ(*ct_->ToTraceTime(BOOTTIME, 1100), 1100); +} + +TEST_F(ClockTrackerTest, + AddDeferredIdentitySync_DoesNotChangeGlobalTraceClock) { + // Trace time starts as BOOTTIME (test fixture default). + constexpr ClockTracker::ClockId TRACE_FILE = ClockId::TraceFile(0); + ct_->AddDeferredIdentitySync(TRACE_FILE); + + // AddDeferredIdentitySync does NOT change the global trace time clock. + EXPECT_EQ(context_.trace_time_state->clock_id, BOOTTIME); +} + +TEST_F(ClockTrackerTest, SetGlobalClock_ChangesGlobalClock) { + ct_->SetGlobalClock(MONOTONIC); + ct_->AddSnapshot({{REALTIME, 10}, {MONOTONIC, 500}}); + + EXPECT_EQ(*ct_->ToTraceTime(REALTIME, 10), 500); + EXPECT_EQ(context_.trace_time_state->clock_id, MONOTONIC); +} + +TEST_F(ClockTrackerTest, SetGlobalClock_DoesNotSetTraceDefaultClock) { + ct_->SetGlobalClock(MONOTONIC); + + EXPECT_FALSE(ct_->trace_default_clock().has_value()); +} + +TEST_F(ClockTrackerTest, SetTraceDefaultClock_DoesNotChangeGlobalClock) { + ct_->SetTraceDefaultClock(MONOTONIC); + + // Global clock should still be BOOTTIME (test fixture default). + EXPECT_EQ(context_.trace_time_state->clock_id, BOOTTIME); +} + } // namespace } // namespace perfetto::trace_processor diff --git a/src/trace_processor/importers/ftrace/ftrace_tokenizer.cc b/src/trace_processor/importers/ftrace/ftrace_tokenizer.cc index 70f6230cb44..78d873097d2 100644 --- a/src/trace_processor/importers/ftrace/ftrace_tokenizer.cc +++ b/src/trace_processor/importers/ftrace/ftrace_tokenizer.cc @@ -53,6 +53,7 @@ #include "protos/perfetto/trace/ftrace/fwtp_ftrace.pbzero.h" #include "protos/perfetto/trace/ftrace/power.pbzero.h" #include "protos/perfetto/trace/ftrace/thermal_exynos.pbzero.h" +#include "src/trace_processor/util/clock_synchronizer.h" namespace perfetto::trace_processor { @@ -140,7 +141,8 @@ base::Status FtraceTokenizer::TokenizeFtraceBundle( // Deal with ftrace recorded using a clock that isn't our preferred default // (boottime). Do a best-effort fit to the "primary trace clock" based on // per-bundle timestamp snapshots. - ClockTracker::ClockId clock_id(BuiltinClock::BUILTIN_CLOCK_BOOTTIME); + ClockTracker::ClockId clock_id = + ClockId::Machine(BuiltinClock::BUILTIN_CLOCK_BOOTTIME); if (decoder.has_ftrace_clock()) { ASSIGN_OR_RETURN(clock_id, HandleFtraceClockSnapshot(decoder, packet_sequence_id)); @@ -442,14 +444,14 @@ FtraceTokenizer::HandleFtraceClockSnapshot( protos::pbzero::FtraceEventBundle::Decoder& decoder, uint32_t packet_sequence_id) { // Convert from ftrace clock enum to a clock id for trace parsing. - ClockTracker::ClockId clock_id(BuiltinClock::BUILTIN_CLOCK_BOOTTIME); + ClockTracker::ClockId clock_id = + ClockId::Machine(BuiltinClock::BUILTIN_CLOCK_BOOTTIME); switch (decoder.ftrace_clock()) { case FtraceClock::FTRACE_CLOCK_UNSPECIFIED: - clock_id = ClockTracker::ClockId(BuiltinClock::BUILTIN_CLOCK_BOOTTIME); + clock_id = ClockId::Machine(BuiltinClock::BUILTIN_CLOCK_BOOTTIME); break; case FtraceClock::FTRACE_CLOCK_MONO_RAW: - clock_id = - ClockTracker::ClockId(BuiltinClock::BUILTIN_CLOCK_MONOTONIC_RAW); + clock_id = ClockId::Machine(BuiltinClock::BUILTIN_CLOCK_MONOTONIC_RAW); break; case FtraceClock::FTRACE_CLOCK_GLOBAL: case FtraceClock::FTRACE_CLOCK_LOCAL: @@ -463,9 +465,8 @@ FtraceTokenizer::HandleFtraceClockSnapshot( // cpu0 as recorded in the bundle. Note: the timestamps will be in the // future relative to the data covered by the bundle, as the timestamping // is done at ftrace read time. - clock_id = ClockTracker::SequenceToGlobalClock(context_->trace_id().value, - packet_sequence_id, - kSequenceScopedClockId); + clock_id = ClockId::Sequence(context_->trace_id().value, + packet_sequence_id, kSequenceScopedClockId); break; default: return base::ErrStatus( @@ -476,14 +477,17 @@ FtraceTokenizer::HandleFtraceClockSnapshot( // duplicates since multiple sequential ftrace bundles can share a snapshot. if (decoder.has_ftrace_timestamp() && decoder.has_boot_timestamp() && latest_ftrace_clock_snapshot_ts_ != decoder.ftrace_timestamp()) { - PERFETTO_DCHECK(clock_id != ClockTracker::ClockId( - BuiltinClock::BUILTIN_CLOCK_BOOTTIME)); + PERFETTO_DCHECK(clock_id != + ClockId::Machine(BuiltinClock::BUILTIN_CLOCK_BOOTTIME)); int64_t ftrace_timestamp = decoder.ftrace_timestamp(); - context_->clock_tracker->AddSnapshot( - {ClockTracker::ClockTimestamp(clock_id, ftrace_timestamp), - ClockTracker::ClockTimestamp( - ClockTracker::ClockId(BuiltinClock::BUILTIN_CLOCK_BOOTTIME), - decoder.boot_timestamp())}); + auto x = context_->clock_tracker->AddSnapshot({ + ClockTracker::ClockTimestamp(clock_id, ftrace_timestamp), + ClockTracker::ClockTimestamp( + ClockId::Machine(BuiltinClock::BUILTIN_CLOCK_BOOTTIME), + decoder.boot_timestamp()), + }); + PERFETTO_ELOG("%s", x.ok() ? "Added ftrace clock snapshot" + : x.status().message().c_str()); latest_ftrace_clock_snapshot_ts_ = ftrace_timestamp; } return clock_id; @@ -511,7 +515,7 @@ void FtraceTokenizer::TokenizeFtraceGpuWorkPeriod( // Enforce clock type for the event data to be CLOCK_MONOTONIC_RAW // as specified, to calculate the timestamp correctly. std::optional timestamp = context_->clock_tracker->ToTraceTime( - ClockTracker::ClockId(BuiltinClock::BUILTIN_CLOCK_MONOTONIC_RAW), + ClockId::Machine(BuiltinClock::BUILTIN_CLOCK_MONOTONIC_RAW), static_cast(raw_timestamp)); // ClockTracker will increment some error stats if it failed to convert the diff --git a/src/trace_processor/importers/fuchsia/BUILD.gn b/src/trace_processor/importers/fuchsia/BUILD.gn index fc0ee388106..b73212c6438 100644 --- a/src/trace_processor/importers/fuchsia/BUILD.gn +++ b/src/trace_processor/importers/fuchsia/BUILD.gn @@ -38,6 +38,7 @@ source_set("full") { ":fuchsia_record", ":minimal", "../../../../gn:default_deps", + "../../../../protos/perfetto/common:zero", "../../sorter", "../../storage", "../../tables", diff --git a/src/trace_processor/importers/fuchsia/fuchsia_parser_unittest.cc b/src/trace_processor/importers/fuchsia/fuchsia_parser_unittest.cc index df04b4505d2..91b0c4f821b 100644 --- a/src/trace_processor/importers/fuchsia/fuchsia_parser_unittest.cc +++ b/src/trace_processor/importers/fuchsia/fuchsia_parser_unittest.cc @@ -201,10 +201,14 @@ class FuchsiaTraceParserTest : public ::testing::Test { context_.slice_tracker = std::make_unique(&context_); context_.slice_translation_table = std::make_unique(storage_); - context_.trace_time_state = std::make_unique(TraceTimeState{ - ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_BOOTTIME), false}); + context_.trace_time_state = std::make_unique( + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_BOOTTIME)); + primary_sync_ = std::make_unique( + context_.trace_time_state.get(), + std::make_unique(&context_)); context_.clock_tracker = std::make_unique( - &context_, std::make_unique(&context_)); + &context_, std::make_unique(&context_), + primary_sync_.get(), true); clock_ = context_.clock_tracker.get(); context_.flow_tracker = std::make_unique(&context_); context_.sorter = std::make_unique( @@ -240,6 +244,7 @@ class FuchsiaTraceParserTest : public ::testing::Test { std::vector trace_bytes_; TraceProcessorContext context_; + std::unique_ptr primary_sync_; MockEventTracker* event_; MockSchedEventTracker* sched_; MockProcessTracker* process_; diff --git a/src/trace_processor/importers/fuchsia/fuchsia_trace_tokenizer.cc b/src/trace_processor/importers/fuchsia/fuchsia_trace_tokenizer.cc index 7c3712b01c6..4d70cc98cbe 100644 --- a/src/trace_processor/importers/fuchsia/fuchsia_trace_tokenizer.cc +++ b/src/trace_processor/importers/fuchsia/fuchsia_trace_tokenizer.cc @@ -26,14 +26,13 @@ #include "perfetto/base/logging.h" #include "perfetto/base/status.h" -#include "perfetto/ext/base/status_macros.h" #include "perfetto/ext/base/string_view.h" #include "perfetto/trace_processor/trace_blob.h" #include "perfetto/trace_processor/trace_blob_view.h" +#include "src/trace_processor/importers/common/clock_tracker.h" #include "src/trace_processor/importers/common/cpu_tracker.h" #include "src/trace_processor/importers/common/process_tracker.h" #include "src/trace_processor/importers/common/slice_tracker.h" -#include "src/trace_processor/importers/common/trace_file_tracker.h" #include "src/trace_processor/importers/fuchsia/fuchsia_record.h" #include "src/trace_processor/importers/fuchsia/fuchsia_trace_parser.h" #include "src/trace_processor/importers/fuchsia/fuchsia_trace_utils.h" @@ -42,6 +41,9 @@ #include "src/trace_processor/storage/stats.h" #include "src/trace_processor/storage/trace_storage.h" #include "src/trace_processor/types/trace_processor_context.h" +#include "src/trace_processor/util/clock_synchronizer.h" + +#include "protos/perfetto/common/builtin_clock.pbzero.h" namespace perfetto::trace_processor { @@ -427,7 +429,13 @@ void FuchsiaTraceTokenizer::ParseRecord(TraceBlobView tbv) { if (!insert_args(n_args, cursor, record)) { return; } - stream_->Push(ts, std::move(record)); + { + auto trace_ts = context_->clock_tracker->ToTraceTime( + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_BOOTTIME), ts); + if (trace_ts) { + stream_->Push(*trace_ts, std::move(record)); + } + } break; } case kBlob: { @@ -589,7 +597,13 @@ void FuchsiaTraceTokenizer::ParseRecord(TraceBlobView tbv) { incoming_thread_ref, current_provider_->GetThread(incoming_thread_ref)); } - stream_->Push(ts, std::move(record)); + { + auto trace_ts = context_->clock_tracker->ToTraceTime( + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_BOOTTIME), ts); + if (trace_ts) { + stream_->Push(*trace_ts, std::move(record)); + } + } break; } case kSchedulerEventContextSwitch: { @@ -623,7 +637,13 @@ void FuchsiaTraceTokenizer::ParseRecord(TraceBlobView tbv) { if (!insert_args(n_args, cursor, record)) { return; } - stream_->Push(ts, std::move(record)); + { + auto trace_ts = context_->clock_tracker->ToTraceTime( + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_BOOTTIME), ts); + if (trace_ts) { + stream_->Push(*trace_ts, std::move(record)); + } + } break; } case kSchedulerEventThreadWakeup: { @@ -651,7 +671,13 @@ void FuchsiaTraceTokenizer::ParseRecord(TraceBlobView tbv) { if (!insert_args(n_args, cursor, record)) { return; } - stream_->Push(ts, std::move(record)); + { + auto trace_ts = context_->clock_tracker->ToTraceTime( + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_BOOTTIME), ts); + if (trace_ts) { + stream_->Push(*trace_ts, std::move(record)); + } + } break; } default: diff --git a/src/trace_processor/importers/fuchsia/fuchsia_trace_tokenizer.h b/src/trace_processor/importers/fuchsia/fuchsia_trace_tokenizer.h index 747f2376c5c..279c8413adc 100644 --- a/src/trace_processor/importers/fuchsia/fuchsia_trace_tokenizer.h +++ b/src/trace_processor/importers/fuchsia/fuchsia_trace_tokenizer.h @@ -25,6 +25,7 @@ #include "perfetto/base/status.h" #include "src/trace_processor/importers/common/chunked_trace_reader.h" +#include "src/trace_processor/importers/common/clock_tracker.h" #include "src/trace_processor/importers/fuchsia/fuchsia_record.h" #include "src/trace_processor/importers/fuchsia/fuchsia_trace_parser.h" #include "src/trace_processor/importers/proto/proto_trace_reader.h" diff --git a/src/trace_processor/importers/gecko/gecko_trace_tokenizer.cc b/src/trace_processor/importers/gecko/gecko_trace_tokenizer.cc index 564215e56fd..ee6eeaca672 100644 --- a/src/trace_processor/importers/gecko/gecko_trace_tokenizer.cc +++ b/src/trace_processor/importers/gecko/gecko_trace_tokenizer.cc @@ -33,7 +33,6 @@ #include "perfetto/ext/base/string_utils.h" #include "perfetto/ext/base/string_view.h" #include "perfetto/trace_processor/trace_blob_view.h" -#include "protos/perfetto/trace/clock_snapshot.pbzero.h" #include "src/trace_processor/importers/common/clock_tracker.h" #include "src/trace_processor/importers/common/mapping_tracker.h" #include "src/trace_processor/importers/common/stack_profile_tracker.h" @@ -42,6 +41,7 @@ #include "src/trace_processor/importers/gecko/gecko_trace_parser.h" #include "src/trace_processor/storage/trace_storage.h" #include "src/trace_processor/types/trace_processor_context.h" +#include "src/trace_processor/util/clock_synchronizer.h" #include "src/trace_processor/util/simple_json_parser.h" namespace perfetto::trace_processor::gecko_importer { @@ -320,7 +320,8 @@ base::StatusOr> ParseGeckoProfile( GeckoTraceTokenizer::GeckoTraceTokenizer(TraceProcessorContext* ctx) : context_(ctx), stream_( - ctx->sorter->CreateStream(std::make_unique(ctx))) {} + ctx->sorter->CreateStream(std::make_unique(ctx))), + trace_file_clock_(ClockId::TraceFile(ctx->trace_id().value)) {} GeckoTraceTokenizer::~GeckoTraceTokenizer() = default; base::Status GeckoTraceTokenizer::Parse(TraceBlobView blob) { @@ -337,9 +338,6 @@ base::Status GeckoTraceTokenizer::OnPushDataToSorter() { threads_or.status().message().c_str()); } - context_->clock_tracker->SetTraceTimeClock( - ClockTracker::ClockId(protos::pbzero::ClockSnapshot::Clock::MONOTONIC)); - for (const auto& t : *threads_or) { if (t.is_preprocessed) { ProcessPreprocessedThread(t); @@ -453,20 +451,21 @@ void GeckoTraceTokenizer::ProcessLegacyThread(const GeckoThread& t) { } auto ts = static_cast(time_val * 1000 * 1000); + std::optional converted = + context_->clock_tracker->ToTraceTime(trace_file_clock_, ts); + if (!converted) { + continue; + } if (!added_metadata) { stream_->Push( - ts, GeckoEvent{GeckoEvent::ThreadMetadata{ - t.tid, t.pid, - context_->storage->InternString(base::StringView(t.name))}}); + *converted, + GeckoEvent{GeckoEvent::ThreadMetadata{ + t.tid, t.pid, + context_->storage->InternString(base::StringView(t.name))}}); added_metadata = true; } - std::optional converted = context_->clock_tracker->ToTraceTime( - ClockTracker::ClockId(protos::pbzero::ClockSnapshot::Clock::MONOTONIC), - ts); - if (converted) { - stream_->Push(*converted, GeckoEvent{GeckoEvent::StackSample{ - t.tid, callsites[*stack_val].id}}); - } + stream_->Push(*converted, GeckoEvent{GeckoEvent::StackSample{ + t.tid, callsites[*stack_val].id}}); } } @@ -552,20 +551,21 @@ void GeckoTraceTokenizer::ProcessPreprocessedThread(const GeckoThread& t) { } auto ts = static_cast(t.sample_times[i] * 1000 * 1000); + std::optional converted = + context_->clock_tracker->ToTraceTime(trace_file_clock_, ts); + if (!converted) { + continue; + } if (!added_metadata) { stream_->Push( - ts, GeckoEvent{GeckoEvent::ThreadMetadata{ - t.tid, t.pid, - context_->storage->InternString(base::StringView(t.name))}}); + *converted, + GeckoEvent{GeckoEvent::ThreadMetadata{ + t.tid, t.pid, + context_->storage->InternString(base::StringView(t.name))}}); added_metadata = true; } - std::optional converted = context_->clock_tracker->ToTraceTime( - ClockTracker::ClockId(protos::pbzero::ClockSnapshot::Clock::MONOTONIC), - ts); - if (converted) { - stream_->Push(*converted, GeckoEvent{GeckoEvent::StackSample{ - t.tid, callsites[stack_idx].id}}); - } + stream_->Push(*converted, GeckoEvent{GeckoEvent::StackSample{ + t.tid, callsites[stack_idx].id}}); } } diff --git a/src/trace_processor/importers/gecko/gecko_trace_tokenizer.h b/src/trace_processor/importers/gecko/gecko_trace_tokenizer.h index 67134236ce3..205037cc324 100644 --- a/src/trace_processor/importers/gecko/gecko_trace_tokenizer.h +++ b/src/trace_processor/importers/gecko/gecko_trace_tokenizer.h @@ -17,11 +17,13 @@ #ifndef SRC_TRACE_PROCESSOR_IMPORTERS_GECKO_GECKO_TRACE_TOKENIZER_H_ #define SRC_TRACE_PROCESSOR_IMPORTERS_GECKO_GECKO_TRACE_TOKENIZER_H_ +#include #include #include "perfetto/base/status.h" #include "perfetto/ext/base/flat_hash_map.h" #include "src/trace_processor/importers/common/chunked_trace_reader.h" +#include "src/trace_processor/importers/common/clock_tracker.h" #include "src/trace_processor/importers/gecko/gecko_event.h" #include "src/trace_processor/sorter/trace_sorter.h" #include "src/trace_processor/types/trace_processor_context.h" @@ -54,6 +56,7 @@ class GeckoTraceTokenizer : public ChunkedTraceReader { TraceProcessorContext* const context_; std::unique_ptr> stream_; std::string pending_json_; + ClockTracker::ClockId trace_file_clock_; // Shared across all threads to avoid creating duplicate mappings. DummyMemoryMapping* dummy_mapping_ = nullptr; diff --git a/src/trace_processor/importers/instruments/instruments_xml_tokenizer.cc b/src/trace_processor/importers/instruments/instruments_xml_tokenizer.cc index a9e54ea936b..87692ee3fcf 100644 --- a/src/trace_processor/importers/instruments/instruments_xml_tokenizer.cc +++ b/src/trace_processor/importers/instruments/instruments_xml_tokenizer.cc @@ -35,7 +35,6 @@ #include "perfetto/base/build_config.h" #include "perfetto/base/logging.h" #include "perfetto/base/status.h" -#include "perfetto/ext/base/murmur_hash.h" #include "perfetto/ext/base/status_or.h" #include "perfetto/ext/base/string_view.h" #include "perfetto/public/compiler.h" @@ -49,6 +48,7 @@ #include "src/trace_processor/sorter/trace_sorter.h" // IWYU pragma: keep #include "src/trace_processor/storage/trace_storage.h" #include "src/trace_processor/util/build_id.h" +#include "src/trace_processor/util/clock_synchronizer.h" #if !PERFETTO_BUILDFLAG(PERFETTO_TP_INSTRUMENTS) #error \ @@ -151,18 +151,9 @@ class InstrumentsXmlTokenizer::Impl { : context_(context), parser_(nullptr), has_data_(false), + clock_(ClockId::TraceFile(context->trace_id().value)), stream_(context->sorter->CreateStream( - std::make_unique(context, data_))) { - static constexpr std::string_view kSubsystem = - "dev.perfetto.instruments_clock"; - clock_ = ClockTracker::ClockId( - static_cast(base::MurmurHashValue(kSubsystem) | 0x80000000), - 0, context->trace_id().value); - - // Use the above clock if we can, in case there is no other trace and - // no clock sync events. - context_->clock_tracker->SetTraceTimeClock(clock_); - } + std::make_unique(context, data_))) {} ~Impl() { if (parser_) { XML_ParserFree(parser_); @@ -417,7 +408,7 @@ class InstrumentsXmlTokenizer::Impl { latest_clock_sync_timestamp_ = clock_sync_timestamp; auto status = context_->clock_tracker->AddSnapshot( {{clock_, current_row_.timestamp_}, - {ClockTracker::ClockId( + {ClockId::Machine( protos::pbzero::ClockSnapshot::Clock::BOOTTIME), static_cast(latest_clock_sync_timestamp_)}}); if (!status.ok()) { diff --git a/src/trace_processor/importers/json/json_trace_tokenizer.cc b/src/trace_processor/importers/json/json_trace_tokenizer.cc index ef00cbd54c7..f2f9a4d42bf 100644 --- a/src/trace_processor/importers/json/json_trace_tokenizer.cc +++ b/src/trace_processor/importers/json/json_trace_tokenizer.cc @@ -32,7 +32,7 @@ #include "perfetto/base/logging.h" #include "perfetto/base/status.h" -#include "perfetto/ext/base/fnv_hash.h" +#include "perfetto/ext/base/murmur_hash.h" #include "perfetto/ext/base/status_macros.h" #include "perfetto/ext/base/string_utils.h" #include "perfetto/ext/base/string_view.h" @@ -40,6 +40,7 @@ #include "perfetto/public/compiler.h" #include "perfetto/trace_processor/trace_blob_view.h" #include "src/trace_processor/containers/string_pool.h" +#include "src/trace_processor/importers/common/clock_tracker.h" #include "src/trace_processor/importers/common/legacy_v8_cpu_profile_tracker.h" #include "src/trace_processor/importers/common/parser_types.h" #include "src/trace_processor/importers/common/v8_profile_parser.h" @@ -48,7 +49,8 @@ #include "src/trace_processor/sorter/trace_sorter.h" // IWYU pragma: keep #include "src/trace_processor/storage/stats.h" #include "src/trace_processor/storage/trace_storage.h" -#include "src/trace_processor/util/simple_json_parser.h" +#include "src/trace_processor/util/clock_synchronizer.h" +#include "src/trace_processor/util/json_parser.h" namespace perfetto::trace_processor { namespace { @@ -488,7 +490,8 @@ JsonTraceTokenizer::JsonTraceTokenizer(TraceProcessorContext* ctx) systrace_stream_(context_->sorter->CreateStream( std::make_unique(&parser_))), v8_stream_(context_->sorter->CreateStream( - std::make_unique(v8_tracker_.get()))) {} + std::make_unique(v8_tracker_.get()))), + trace_file_clock_(ClockId::TraceFile(ctx->trace_id().value)) {} JsonTraceTokenizer::~JsonTraceTokenizer() = default; base::Status JsonTraceTokenizer::Parse(TraceBlobView blob) { @@ -799,7 +802,10 @@ bool JsonTraceTokenizer::ParseTraceEventContents() { } return true; } - json_stream_->Push(ts, std::move(event)); + auto trace_ts = context_->clock_tracker->ToTraceTime(trace_file_clock_, ts); + if (trace_ts) { + json_stream_->Push(*trace_ts, std::move(event)); + } return true; } @@ -855,8 +861,12 @@ base::Status JsonTraceTokenizer::ParseV8SampleEvent(const JsonEvent& event) { ASSIGN_OR_RETURN(int64_t ts, v8_tracker_->AddDeltaAndGetTs( id, event.pid, profile.time_deltas[i] * 1000)); - v8_stream_->Push(ts, LegacyV8CpuProfileEvent{id, event.pid, event.tid, - profile.samples[i]}); + auto trace_ts = context_->clock_tracker->ToTraceTime(trace_file_clock_, ts); + if (trace_ts) { + v8_stream_->Push(*trace_ts, + LegacyV8CpuProfileEvent{id, event.pid, event.tid, + profile.samples[i]}); + } } return base::OkStatus(); } @@ -970,7 +980,11 @@ base::Status JsonTraceTokenizer::HandleSystemTraceEvent(const char* start, SystraceLine line; RETURN_IF_ERROR(systrace_line_tokenizer_.Tokenize(raw_line, &line)); - systrace_stream_->Push(line.ts, std::move(line)); + auto trace_ts = + context_->clock_tracker->ToTraceTime(trace_file_clock_, line.ts); + if (trace_ts) { + systrace_stream_->Push(*trace_ts, std::move(line)); + } } return SetOutAndReturn(next, out); } diff --git a/src/trace_processor/importers/json/json_trace_tokenizer.h b/src/trace_processor/importers/json/json_trace_tokenizer.h index 93935e9cca8..6d4b6325300 100644 --- a/src/trace_processor/importers/json/json_trace_tokenizer.h +++ b/src/trace_processor/importers/json/json_trace_tokenizer.h @@ -25,6 +25,7 @@ #include "perfetto/base/status.h" #include "src/trace_processor/importers/common/chunked_trace_reader.h" +#include "src/trace_processor/importers/common/clock_tracker.h" #include "src/trace_processor/importers/common/legacy_v8_cpu_profile_tracker.h" #include "src/trace_processor/importers/common/parser_types.h" #include "src/trace_processor/importers/json/json_trace_parser.h" @@ -145,6 +146,7 @@ class JsonTraceTokenizer : public ChunkedTraceReader { json::Iterator it_; json::Iterator inner_it_; + ClockTracker::ClockId trace_file_clock_; uint64_t offset_ = 0; // Used to glue together JSON objects that span across two (or more) // Parse boundaries. diff --git a/src/trace_processor/importers/perf/perf_data_tokenizer.cc b/src/trace_processor/importers/perf/perf_data_tokenizer.cc index 4303ec4ef41..709e6b4f0fe 100644 --- a/src/trace_processor/importers/perf/perf_data_tokenizer.cc +++ b/src/trace_processor/importers/perf/perf_data_tokenizer.cc @@ -28,17 +28,14 @@ #include #include -#include "perfetto/base/build_config.h" #include "perfetto/base/flat_set.h" #include "perfetto/base/logging.h" #include "perfetto/base/status.h" #include "perfetto/ext/base/status_macros.h" #include "perfetto/ext/base/status_or.h" -#include "perfetto/public/compiler.h" #include "perfetto/trace_processor/ref_counted.h" #include "perfetto/trace_processor/trace_blob_view.h" #include "protos/perfetto/common/builtin_clock.pbzero.h" -#include "protos/perfetto/trace/clock_snapshot.pbzero.h" #include "protos/third_party/simpleperf/record_file.pbzero.h" #include "src/trace_processor/importers/common/clock_tracker.h" #include "src/trace_processor/importers/common/metadata_tracker.h" @@ -67,6 +64,7 @@ #include "src/trace_processor/storage/stats.h" #include "src/trace_processor/types/variadic.h" #include "src/trace_processor/util/build_id.h" +#include "src/trace_processor/util/clock_synchronizer.h" #include "src/trace_processor/util/trace_blob_view_reader.h" namespace perfetto::trace_processor::perf_importer { @@ -209,9 +207,6 @@ PerfDataTokenizer::ParseHeader() { feature_ids_ = ExtractFeatureIds(header_.flags, header_.flags1); feature_headers_section_ = {header_.data.end(), feature_ids_.size() * sizeof(PerfFile::Section)}; - context_->clock_tracker->SetTraceTimeClock( - ClockTracker::ClockId(protos::pbzero::ClockSnapshot::Clock::MONOTONIC)); - PERFETTO_CHECK(buffer_.PopFrontUntil(sizeof(PerfFile::Header))); parsing_state_ = ParsingState::kParseAttrs; return ParsingResult::kSuccess; @@ -250,8 +245,8 @@ PerfDataTokenizer::ParseAttrs() { ASSIGN_OR_RETURN(perf_invocation_, builder.Build()); if (perf_invocation_->HasPerfClock()) { - context_->clock_tracker->SetTraceTimeClock( - ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_PERF)); + context_->clock_tracker->SetGlobalClock( + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_PERF)); } parsing_state_ = ParsingState::kSeekRecords; return ParsingResult::kSuccess; diff --git a/src/trace_processor/importers/perf/perf_event_attr.cc b/src/trace_processor/importers/perf/perf_event_attr.cc index 01435a5cfab..3e69c3a988a 100644 --- a/src/trace_processor/importers/perf/perf_event_attr.cc +++ b/src/trace_processor/importers/perf/perf_event_attr.cc @@ -23,6 +23,7 @@ #include #include +#include "perfetto/base/compiler.h" #include "perfetto/ext/base/string_view.h" #include "protos/perfetto/common/builtin_clock.pbzero.h" #include "src/trace_processor/importers/common/args_tracker.h" @@ -36,6 +37,7 @@ #include "src/trace_processor/tables/track_tables_py.h" #include "src/trace_processor/types/trace_processor_context.h" #include "src/trace_processor/types/variadic.h" +#include "src/trace_processor/util/clock_synchronizer.h" namespace perfetto::trace_processor::perf_importer { @@ -112,27 +114,25 @@ size_t GetSampleIdSize(const perf_event_attr& attr) { ClockTracker::ClockId ExtractClockId(const perf_event_attr& attr) { if (!attr.use_clockid) { - return ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_PERF); + return ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_PERF); } switch (attr.clockid) { // Linux perf uses the values in not sure if these are portable // across platforms, so using the actual values here just in case. case 0: // CLOCK_REALTIME - return ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_REALTIME); + return ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_REALTIME); case 1: // CLOCK_MONOTONIC - return ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_MONOTONIC); + return ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_MONOTONIC); case 4: // CLOCK_MONOTONIC_RAW - return ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_MONOTONIC_RAW); + return ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_MONOTONIC_RAW); case 5: // CLOCK_REALTIME_COARSE - return ClockTracker::ClockId( - protos::pbzero::BUILTIN_CLOCK_REALTIME_COARSE); + return ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_REALTIME_COARSE); case 6: // CLOCK_MONOTONIC_COARSE - return ClockTracker::ClockId( - protos::pbzero::BUILTIN_CLOCK_MONOTONIC_COARSE); + return ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_MONOTONIC_COARSE); case 7: // CLOCK_BOOTTIME - return ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_BOOTTIME); + return ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_BOOTTIME); default: - return ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_UNKNOWN); + return ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_UNKNOWN); } } } // namespace diff --git a/src/trace_processor/importers/perf/perf_invocation.cc b/src/trace_processor/importers/perf/perf_invocation.cc index 07e0ac0fe71..dfda0e27427 100644 --- a/src/trace_processor/importers/perf/perf_invocation.cc +++ b/src/trace_processor/importers/perf/perf_invocation.cc @@ -40,6 +40,7 @@ #include "src/trace_processor/storage/trace_storage.h" // IWYU pragma: keep #include "src/trace_processor/types/trace_processor_context.h" #include "src/trace_processor/util/build_id.h" +#include "src/trace_processor/util/clock_synchronizer.h" namespace perfetto::trace_processor::perf_importer { namespace { @@ -203,7 +204,7 @@ void PerfInvocation::SetCmdline(const std::vector& args) { bool PerfInvocation::HasPerfClock() const { for (auto it = attrs_by_id_.GetIterator(); it; ++it) { if (it.value()->clock_id() == - ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_PERF)) { + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_PERF)) { return true; } } diff --git a/src/trace_processor/importers/perf_text/perf_text_trace_tokenizer.cc b/src/trace_processor/importers/perf_text/perf_text_trace_tokenizer.cc index a198c7eb57b..f179bf33020 100644 --- a/src/trace_processor/importers/perf_text/perf_text_trace_tokenizer.cc +++ b/src/trace_processor/importers/perf_text/perf_text_trace_tokenizer.cc @@ -28,7 +28,6 @@ #include "perfetto/base/logging.h" #include "perfetto/base/status.h" -#include "perfetto/ext/base/status_macros.h" #include "perfetto/ext/base/string_utils.h" #include "perfetto/ext/base/string_view.h" #include "perfetto/trace_processor/trace_blob_view.h" @@ -43,6 +42,7 @@ #include "src/trace_processor/storage/stats.h" #include "src/trace_processor/storage/trace_storage.h" #include "src/trace_processor/types/trace_processor_context.h" +#include "src/trace_processor/util/clock_synchronizer.h" #include "src/trace_processor/util/trace_blob_view_reader.h" #include "protos/perfetto/trace/clock_snapshot.pbzero.h" @@ -68,15 +68,6 @@ PerfTextTraceTokenizer::PerfTextTraceTokenizer(TraceProcessorContext* ctx) PerfTextTraceTokenizer::~PerfTextTraceTokenizer() = default; base::Status PerfTextTraceTokenizer::Parse(TraceBlobView blob) { - // Guess the clock used for timestamps, which would normally be described in - // `perf script --header`, which we don't expect to be included. - // Further, if the recording was using the default perf_clock (typically - // equivalent to sched_clock), the latter doesn't have a representation in - // perfetto at the time of writing. - // Therefore, approximate all clocks as MONOTONIC. - context_->clock_tracker->SetTraceTimeClock( - ClockTracker::ClockId(protos::pbzero::ClockSnapshot::Clock::MONOTONIC)); - reader_.PushBack(std::move(blob)); std::vector frames; // Loop over each sample. @@ -173,7 +164,7 @@ base::Status PerfTextTraceTokenizer::Parse(TraceBlobView blob) { evt.callsite_id = *parent_callsite; std::optional trace_ts = context_->clock_tracker->ToTraceTime( - ClockTracker::ClockId(protos::pbzero::ClockSnapshot::Clock::MONOTONIC), + ClockId::Machine(protos::pbzero::ClockSnapshot::Clock::MONOTONIC), sample->ts); if (trace_ts) { stream_->Push(*trace_ts, evt); diff --git a/src/trace_processor/importers/primes/primes_trace_tokenizer.cc b/src/trace_processor/importers/primes/primes_trace_tokenizer.cc index c3428252e70..36c0c477b53 100644 --- a/src/trace_processor/importers/primes/primes_trace_tokenizer.cc +++ b/src/trace_processor/importers/primes/primes_trace_tokenizer.cc @@ -16,10 +16,19 @@ #include "src/trace_processor/importers/primes/primes_trace_tokenizer.h" +#include #include +#include +#include +#include "perfetto/base/logging.h" +#include "perfetto/base/status.h" +#include "perfetto/trace_processor/trace_blob_view.h" +#include "src/trace_processor/importers/common/clock_tracker.h" #include "src/trace_processor/importers/common/import_logs_tracker.h" #include "src/trace_processor/importers/primes/primes_trace_parser.h" +#include "src/trace_processor/storage/stats.h" +#include "src/trace_processor/util/clock_synchronizer.h" #include "protos/third_party/primes/primes_tracing.pbzero.h" @@ -29,6 +38,7 @@ namespace perfetto::trace_processor::primes { PrimesTraceTokenizer::PrimesTraceTokenizer(TraceProcessorContext* ctx) : context_(ctx), + trace_file_clock_(ClockId::TraceFile(ctx->trace_id().value)), stream_( ctx->sorter->CreateStream(std::make_unique(ctx))) { } @@ -89,7 +99,11 @@ base::Status PrimesTraceTokenizer::OnPushDataToSorter() { // Create a TraceBlobView for the edge data. TraceBlobView edge_slice = slice->slice_off( static_cast((*edge).data - slice->data()), (*edge).size); - stream_->Push(edge_timestamp, std::move(edge_slice)); + auto trace_ts = + context_->clock_tracker->ToTraceTime(trace_file_clock_, edge_timestamp); + if (trace_ts) { + stream_->Push(*trace_ts, std::move(edge_slice)); + } } return base::OkStatus(); } diff --git a/src/trace_processor/importers/primes/primes_trace_tokenizer.h b/src/trace_processor/importers/primes/primes_trace_tokenizer.h index bc5d1381f4a..3260dcf45dc 100644 --- a/src/trace_processor/importers/primes/primes_trace_tokenizer.h +++ b/src/trace_processor/importers/primes/primes_trace_tokenizer.h @@ -17,7 +17,11 @@ #ifndef SRC_TRACE_PROCESSOR_IMPORTERS_PRIMES_PRIMES_TRACE_TOKENIZER_H_ #define SRC_TRACE_PROCESSOR_IMPORTERS_PRIMES_PRIMES_TRACE_TOKENIZER_H_ +#include + +#include "perfetto/base/status.h" #include "src/trace_processor/importers/common/chunked_trace_reader.h" +#include "src/trace_processor/importers/common/clock_tracker.h" #include "src/trace_processor/sorter/trace_sorter.h" #include "src/trace_processor/types/trace_processor_context.h" #include "src/trace_processor/util/trace_blob_view_reader.h" @@ -39,6 +43,7 @@ class PrimesTraceTokenizer : public ChunkedTraceReader { private: util::TraceBlobViewReader reader_; TraceProcessorContext* const context_; + ClockTracker::ClockId trace_file_clock_; std::unique_ptr> stream_; }; diff --git a/src/trace_processor/importers/proto/android_probes_module.cc b/src/trace_processor/importers/proto/android_probes_module.cc index b12cc747b95..2f4c4eff101 100644 --- a/src/trace_processor/importers/proto/android_probes_module.cc +++ b/src/trace_processor/importers/proto/android_probes_module.cc @@ -16,7 +16,6 @@ #include "src/trace_processor/importers/proto/android_probes_module.h" -#include #include #include #include @@ -39,6 +38,7 @@ #include "src/trace_processor/sorter/trace_sorter.h" #include "src/trace_processor/storage/stats.h" #include "src/trace_processor/storage/trace_storage.h" +#include "src/trace_processor/util/clock_synchronizer.h" #include "protos/perfetto/common/android_energy_consumer_descriptor.pbzero.h" #include "protos/perfetto/common/android_log_constants.pbzero.h" @@ -46,7 +46,6 @@ #include "protos/perfetto/trace/android/android_log.pbzero.h" #include "protos/perfetto/trace/android/packages_list.pbzero.h" #include "protos/perfetto/trace/android/user_list.pbzero.h" - #include "protos/perfetto/trace/power/android_energy_estimation_breakdown.pbzero.h" #include "protos/perfetto/trace/power/android_entity_state_residency.pbzero.h" #include "protos/perfetto/trace/power/power_rails.pbzero.h" @@ -126,8 +125,7 @@ ModuleResult AndroidProbesModule::TokenizePacket( // timestamp_ms is always in boottime per protobuf spec. int64_t ts_ns = static_cast(data.timestamp_ms()) * 1000000; auto trace_ts = context_->clock_tracker->ToTraceTime( - ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_BOOTTIME), - ts_ns); + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_BOOTTIME), ts_ns); if (!trace_ts.has_value()) { // Rely on implicitly incremented error stat in ToTraceTime instead // of fatally erroring. @@ -168,7 +166,7 @@ ModuleResult AndroidProbesModule::TokenizePacket( protos::pbzero::AndroidLogPacket::LogEvent::Decoder evt(*it); auto realtime_ts = static_cast(evt.timestamp()); std::optional trace_ts = context_->clock_tracker->ToTraceTime( - ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_REALTIME), + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_REALTIME), realtime_ts); if (!trace_ts.has_value()) { continue; diff --git a/src/trace_processor/importers/proto/network_trace_module_unittest.cc b/src/trace_processor/importers/proto/network_trace_module_unittest.cc index a08893bb88d..130e33b1c3e 100644 --- a/src/trace_processor/importers/proto/network_trace_module_unittest.cc +++ b/src/trace_processor/importers/proto/network_trace_module_unittest.cc @@ -14,8 +14,6 @@ * limitations under the License. */ -#include "src/trace_processor/importers/proto/network_trace_module.h" - #include #include #include @@ -31,7 +29,6 @@ #include "protos/perfetto/trace/android/network_trace.pbzero.h" #include "protos/perfetto/trace/trace.pbzero.h" #include "src/trace_processor/core/dataframe/specs.h" -#include "src/trace_processor/importers/common/args_tracker.h" #include "src/trace_processor/importers/common/args_translation_table.h" #include "src/trace_processor/importers/common/clock_tracker.h" #include "src/trace_processor/importers/common/global_args_tracker.h" @@ -46,7 +43,6 @@ #include "src/trace_processor/importers/common/track_tracker.h" #include "src/trace_processor/importers/proto/additional_modules.h" #include "src/trace_processor/importers/proto/blob_packet_writer.h" -#include "src/trace_processor/importers/proto/default_modules.h" #include "src/trace_processor/importers/proto/proto_importer_module.h" #include "src/trace_processor/importers/proto/proto_trace_parser_impl.h" #include "src/trace_processor/importers/proto/proto_trace_reader.h" @@ -57,6 +53,7 @@ #include "src/trace_processor/types/trace_processor_context_ptr.h" #include "src/trace_processor/types/variadic.h" #include "src/trace_processor/util/args_utils.h" +#include "src/trace_processor/util/clock_synchronizer.h" #include "src/trace_processor/util/descriptors.h" #include "test/gtest_and_gmock.h" @@ -81,10 +78,14 @@ class NetworkTraceModuleTest : public testing::Test { context_.metadata_tracker = std::make_unique(&context_); context_.import_logs_tracker = std::make_unique(&context_, TraceId(1)); - context_.trace_time_state = std::make_unique(TraceTimeState{ - ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_BOOTTIME), false}); + context_.trace_time_state = std::make_unique( + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_BOOTTIME)); + primary_sync_ = std::make_unique( + context_.trace_time_state.get(), + std::make_unique(&context_)); context_.clock_tracker = std::make_unique( - &context_, std::make_unique(&context_)); + &context_, std::make_unique(&context_), + primary_sync_.get(), true); context_.track_tracker = std::make_unique(&context_); context_.slice_tracker = std::make_unique(&context_); context_.global_args_tracker = @@ -146,6 +147,7 @@ class NetworkTraceModuleTest : public testing::Test { protected: protozero::HeapBuffered trace_; TraceProcessorContext context_; + std::unique_ptr primary_sync_; TraceStorage* storage_; }; diff --git a/src/trace_processor/importers/proto/profile_module.cc b/src/trace_processor/importers/proto/profile_module.cc index 53e1ccff4ce..b735914269e 100644 --- a/src/trace_processor/importers/proto/profile_module.cc +++ b/src/trace_processor/importers/proto/profile_module.cc @@ -22,7 +22,6 @@ #include #include "perfetto/base/logging.h" -#include "perfetto/ext/base/status_or.h" #include "perfetto/ext/base/string_view.h" #include "perfetto/protozero/field.h" #include "perfetto/trace_processor/ref_counted.h" @@ -37,6 +36,7 @@ #include "src/trace_processor/importers/common/process_tracker.h" #include "src/trace_processor/importers/common/stack_profile_tracker.h" #include "src/trace_processor/importers/proto/packet_sequence_state_generation.h" +#include "src/trace_processor/importers/proto/perf_sample_tracker.h" #include "src/trace_processor/importers/proto/profile_packet_sequence_state.h" #include "src/trace_processor/importers/proto/profile_packet_utils.h" #include "src/trace_processor/importers/proto/proto_importer_module.h" @@ -47,6 +47,7 @@ #include "src/trace_processor/tables/profiler_tables_py.h" #include "src/trace_processor/types/trace_processor_context.h" #include "src/trace_processor/util/build_id.h" +#include "src/trace_processor/util/clock_synchronizer.h" #include "protos/perfetto/common/builtin_clock.pbzero.h" #include "protos/perfetto/trace/profiling/profile_common.pbzero.h" @@ -151,8 +152,7 @@ ModuleResult ProfileModule::TokenizeStreamingProfilePacket( auto packet_ts = sequence_state->IncrementAndGetTrackEventTimeNs(/*delta_ns=*/0); std::optional trace_ts = context_->clock_tracker->ToTraceTime( - ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_MONOTONIC), - packet_ts); + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_MONOTONIC), packet_ts); if (trace_ts) packet_ts = *trace_ts; @@ -375,8 +375,7 @@ void ProfileModule::ParseProfilePacket( std::optional maybe_timestamp = context_->clock_tracker->ToTraceTime( - ClockTracker::ClockId( - protos::pbzero::BUILTIN_CLOCK_MONOTONIC_COARSE), + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_MONOTONIC_COARSE), static_cast(entry.timestamp())); if (!maybe_timestamp) continue; diff --git a/src/trace_processor/importers/proto/proto_trace_parser_impl_unittest.cc b/src/trace_processor/importers/proto/proto_trace_parser_impl_unittest.cc index 1ac90bcf790..1f9fab469a7 100644 --- a/src/trace_processor/importers/proto/proto_trace_parser_impl_unittest.cc +++ b/src/trace_processor/importers/proto/proto_trace_parser_impl_unittest.cc @@ -32,7 +32,6 @@ #include "perfetto/trace_processor/basic_types.h" #include "perfetto/trace_processor/trace_blob.h" #include "perfetto/trace_processor/trace_blob_view.h" -#include "src/base/test/status_matchers.h" #include "src/trace_processor/core/dataframe/specs.h" #include "src/trace_processor/importers/common/args_tracker.h" #include "src/trace_processor/importers/common/args_translation_table.h" @@ -66,8 +65,10 @@ #include "src/trace_processor/tables/slice_tables_py.h" #include "src/trace_processor/tables/track_tables_py.h" #include "src/trace_processor/types/trace_processor_context.h" +#include "src/trace_processor/types/trace_processor_context_ptr.h" #include "src/trace_processor/types/variadic.h" #include "src/trace_processor/util/args_utils.h" +#include "src/trace_processor/util/clock_synchronizer.h" #include "src/trace_processor/util/descriptors.h" #include "test/gtest_and_gmock.h" @@ -280,10 +281,14 @@ class ProtoTraceParserTest : public ::testing::Test { context_.slice_tracker = std::make_unique(&context_); context_.slice_translation_table = std::make_unique(storage_); - context_.trace_time_state = std::make_unique(TraceTimeState{ - ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_BOOTTIME), false}); + context_.trace_time_state = std::make_unique( + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_BOOTTIME)); + primary_sync_ = std::make_unique( + context_.trace_time_state.get(), + std::make_unique(&context_)); context_.clock_tracker = std::make_unique( - &context_, std::make_unique(&context_)); + &context_, std::make_unique(&context_), + primary_sync_.get(), true); context_.flow_tracker = std::make_unique(&context_); context_.sorter = std::make_unique( &context_, TraceSorter::SortingMode::kFullSort); @@ -355,6 +360,7 @@ class ProtoTraceParserTest : public ::testing::Test { protected: protozero::HeapBuffered trace_; TraceProcessorContext context_; + std::unique_ptr primary_sync_; MockEventTracker* event_; MockSchedEventTracker* sched_; MockProcessTracker* process_; @@ -2423,9 +2429,8 @@ TEST_F(ProtoTraceParserTest, TrackEventParseLegacyEventIntoRawTable) { TEST_F(ProtoTraceParserTest, TrackEventLegacyTimestampsWithClockSnapshot) { clock_->AddSnapshot( - {{ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_BOOTTIME), 0}, - {ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_MONOTONIC), - 1000000}}); + {{ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_BOOTTIME), 0}, + {ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_MONOTONIC), 1000000}}); { auto* packet = trace_->add_packet(); @@ -2639,12 +2644,13 @@ TEST_F(ProtoTraceParserTest, LoadChromeBenchmarkMetadata) { base::StringView tags = metadata::kNames[metadata::benchmark_story_tags]; context_.sorter->ExtractEventsForced(); - EXPECT_EQ(storage_->metadata_table().row_count(), 3u); std::vector> meta_entries; for (auto it = storage_->metadata_table().IterateRows(); it; ++it) { - meta_entries.emplace_back(storage_->GetString(it.name()), - storage_->GetString(*it.str_value())); + base::StringView name = storage_->GetString(it.name()); + if (name == metadata::kNames[metadata::trace_time_clock_id]) + continue; + meta_entries.emplace_back(name, storage_->GetString(*it.str_value())); } EXPECT_THAT(meta_entries, UnorderedElementsAreArray({make_pair(benchmark, kName), diff --git a/src/trace_processor/importers/proto/proto_trace_reader.cc b/src/trace_processor/importers/proto/proto_trace_reader.cc index ee52c47ff78..cd9030bfe4a 100644 --- a/src/trace_processor/importers/proto/proto_trace_reader.cc +++ b/src/trace_processor/importers/proto/proto_trace_reader.cc @@ -223,7 +223,12 @@ base::Status ProtoTraceReader::ParsePacket(TraceBlobView packet) { auto* machine_context = context_->ForkContextForMachineInCurrentTrace(decoder.machine_id()); *it = std::make_unique(machine_context); - + auto parent_default = context_->clock_tracker->trace_default_clock(); + if (parent_default) { + machine_context->clock_tracker->SetTraceDefaultClock(*parent_default); + } + machine_context->clock_tracker->AddDeferredIdentitySync( + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_BOOTTIME)); // TODO(lalitm): this doesn't seem the right place for this but I cannot // think of a much better place either. machine_context->process_tracker->SetPidZeroIsUpidZeroIdleProcess(); @@ -349,12 +354,20 @@ base::Status ProtoTraceReader::TimestampTokenizeAndPushToSorter( if (decoder.has_timestamp()) { timestamp = static_cast(decoder.timestamp()); - uint32_t timestamp_clock_id = - decoder.has_timestamp_clock_id() - ? decoder.timestamp_clock_id() - : (defaults ? defaults->timestamp_clock_id() - : static_cast( - protos::pbzero::BUILTIN_CLOCK_BOOTTIME)); + // Use the packet's clock_id, falling back to sequence defaults, then + // to the trace's default clock (e.g. BOOTTIME for proto traces). + // If none is set, timestamp_clock_id stays 0 and no conversion + // happens — the timestamp is assumed to be in trace time already. + uint32_t timestamp_clock_id = decoder.timestamp_clock_id(); + if (PERFETTO_UNLIKELY(!timestamp_clock_id && defaults)) { + timestamp_clock_id = defaults->timestamp_clock_id(); + } + if (PERFETTO_UNLIKELY(!timestamp_clock_id)) { + auto default_clock = context_->clock_tracker->trace_default_clock(); + if (default_clock) { + timestamp_clock_id = default_clock->clock_id; + } + } if ((decoder.has_chrome_events() || decoder.has_chrome_metadata()) && (!timestamp_clock_id || @@ -366,15 +379,14 @@ base::Status ProtoTraceReader::TimestampTokenizeAndPushToSorter( // TODO(eseckler): Set timestamp_clock_id and emit ClockSnapshots in // chrome and then remove this. auto trace_ts = context_->clock_tracker->ToTraceTime( - ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_MONOTONIC), - timestamp); + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_MONOTONIC), timestamp); if (trace_ts) timestamp = *trace_ts; } else if (timestamp_clock_id) { // If the TracePacket specifies a non-zero clock-id, translate the // timestamp into the trace-time clock domain. - ClockTracker::ClockId converted_clock_id(timestamp_clock_id); - if (ClockTracker::IsSequenceClock(timestamp_clock_id)) { + ClockTracker::ClockId converted_clock_id; + if (ClockId::IsSequenceClock(timestamp_clock_id)) { if (!seq_id) { return base::ErrStatus( "TracePacket specified a sequence-local clock id (%" PRIu32 @@ -382,8 +394,10 @@ base::Status ProtoTraceReader::TimestampTokenizeAndPushToSorter( "probably too old)", timestamp_clock_id); } - converted_clock_id = ClockTracker::SequenceToGlobalClock( - context_->trace_id().value, seq_id, timestamp_clock_id); + converted_clock_id = ClockId::Sequence(context_->trace_id().value, + seq_id, timestamp_clock_id); + } else { + converted_clock_id = ClockId::Machine(timestamp_clock_id); } auto trace_ts = context_->clock_tracker->ToTraceTime( converted_clock_id, timestamp, packet.offset()); @@ -538,22 +552,20 @@ base::Status ProtoTraceReader::ParseClockSnapshot(ConstBytes blob, uint32_t seq_id) { std::vector clock_timestamps; protos::pbzero::ClockSnapshot::Decoder evt(blob.data, blob.size); - if (evt.primary_trace_clock()) { - context_->clock_tracker->SetTraceTimeClock( - ClockId(static_cast(evt.primary_trace_clock()))); - } for (auto it = evt.clocks(); it; ++it) { protos::pbzero::ClockSnapshot::Clock::Decoder clk(*it); - ClockTracker::ClockId clock_id(clk.clock_id()); - if (ClockTracker::IsSequenceClock(clk.clock_id())) { + ClockTracker::ClockId clock_id; + if (ClockId::IsSequenceClock(clk.clock_id())) { if (!seq_id) { return base::ErrStatus( "ClockSnapshot packet is specifying a sequence-scoped clock id " "(%" PRIu32 ") but the TracePacket sequence_id is zero", clock_id.clock_id); } - clock_id = ClockTracker::SequenceToGlobalClock(context_->trace_id().value, - seq_id, clk.clock_id()); + clock_id = + ClockId::Sequence(context_->trace_id().value, seq_id, clk.clock_id()); + } else { + clock_id = ClockId::Machine(clk.clock_id()); } int64_t unit_multiplier_ns = clk.unit_multiplier_ns() @@ -563,6 +575,33 @@ base::Status ProtoTraceReader::ParseClockSnapshot(ConstBytes blob, clk.is_incremental()); } + if (evt.primary_trace_clock()) { + auto clock = + ClockId::Machine(static_cast(evt.primary_trace_clock())); + context_->clock_tracker->SetTraceDefaultClock(clock); + context_->clock_tracker->SetGlobalClock(clock); + } else { + // For legacy proto traces without primary_trace_clock: if the snapshot + // contains BOOTTIME but not TRACE_FILE, infer BOOTTIME as the trace time + // clock. This matches the old behavior where BOOTTIME was hardcoded as + // the default for proto traces. + bool has_boottime = false; + bool has_trace_file = false; + for (const auto& ct : clock_timestamps) { + if (ct.clock.id.clock_id == protos::pbzero::BUILTIN_CLOCK_BOOTTIME) { + has_boottime = true; + } + if (ct.clock.id.clock_id == protos::pbzero::BUILTIN_CLOCK_TRACE_FILE) { + has_trace_file = true; + } + } + if (has_boottime && !has_trace_file) { + auto clock = ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_BOOTTIME); + context_->clock_tracker->SetTraceDefaultClock(clock); + context_->clock_tracker->SetGlobalClock(clock); + } + } + base::StatusOr snapshot_id = context_->clock_tracker->AddSnapshot(clock_timestamps); if (!snapshot_id.ok()) { @@ -644,7 +683,7 @@ base::Status ProtoTraceReader::ParseRemoteClockSync(ConstBytes blob) { protos::pbzero::ClockSnapshot::ClockSnapshot::Clock::Decoder clock( *clock_it); sync_clocks[clock.clock_id()].second = clock.timestamp(); - clock_timestamps.emplace_back(ClockTracker::ClockId(clock.clock_id()), + clock_timestamps.emplace_back(ClockId::Machine(clock.clock_id()), clock.timestamp(), 1, false); } @@ -731,7 +770,7 @@ ProtoTraceReader::CalculateClockOffsets( int64_t avg_offset = std::accumulate(offsets.begin(), offsets.end(), 0LL) / static_cast(offsets.size()); - clock_offsets[ClockId(clock_id)] = avg_offset; + clock_offsets[ClockId::Machine(clock_id)] = avg_offset; } } diff --git a/src/trace_processor/importers/proto/proto_trace_reader_unittest.cc b/src/trace_processor/importers/proto/proto_trace_reader_unittest.cc index eb208315ab4..25ee2a275a0 100644 --- a/src/trace_processor/importers/proto/proto_trace_reader_unittest.cc +++ b/src/trace_processor/importers/proto/proto_trace_reader_unittest.cc @@ -30,12 +30,16 @@ #include "protos/perfetto/trace/trace.pbzero.h" #include "src/trace_processor/importers/common/clock_tracker.h" #include "src/trace_processor/importers/common/global_args_tracker.h" +#include "src/trace_processor/importers/common/global_metadata_tracker.h" #include "src/trace_processor/importers/common/import_logs_tracker.h" #include "src/trace_processor/importers/common/machine_tracker.h" +#include "src/trace_processor/importers/common/metadata_tracker.h" #include "src/trace_processor/importers/proto/additional_modules.h" #include "src/trace_processor/sorter/trace_sorter.h" #include "src/trace_processor/storage/trace_storage.h" #include "src/trace_processor/types/trace_processor_context.h" +#include "src/trace_processor/types/trace_processor_context_ptr.h" +#include "src/trace_processor/util/clock_synchronizer.h" #include "src/trace_processor/util/descriptors.h" #include "test/gtest_and_gmock.h" @@ -63,13 +67,19 @@ class ProtoTraceReaderTest : public ::testing::Test { std::make_unique(host_context_.storage.get()); host_context_.import_logs_tracker = std::make_unique(&host_context_, TraceId(1)); - host_context_.trace_time_state = - std::make_unique(TraceTimeState{ - ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_BOOTTIME), - false}); + host_context_.trace_time_state = std::make_unique( + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_BOOTTIME)); + primary_sync_ = std::make_unique( + host_context_.trace_time_state.get(), + std::make_unique(&host_context_)); host_context_.clock_tracker = std::make_unique( &host_context_, - std::make_unique(&host_context_)); + std::make_unique(&host_context_), + primary_sync_.get(), true); + host_context_.global_metadata_tracker = + std::make_unique(host_context_.storage.get()); + host_context_.metadata_tracker = + std::make_unique(&host_context_); host_context_.sorter = std::make_unique( &host_context_, TraceSorter::SortingMode::kDefault); host_context_.descriptor_pool_ = std::make_unique(); @@ -93,6 +103,7 @@ class ProtoTraceReaderTest : public ::testing::Test { protected: protozero::HeapBuffered trace_; TraceProcessorContext host_context_; + std::unique_ptr primary_sync_; std::unique_ptr proto_trace_reader_; }; @@ -192,13 +203,13 @@ TEST_F(ProtoTraceReaderTest, CalculateClockOffset) { // Estimated offsets: (10000 + 20000)/2 - 120000 = -105000, // 20000 - (120000 + 140000) / 2 = -110000. // Average = -107500. - ASSERT_EQ(-107500, clock_offsets[ClockTracker::ClockId(BOOTTIME)]); + ASSERT_EQ(-107500, clock_offsets[ClockId::Machine(BOOTTIME)]); // Client 25000 35000 // Host 135000 150000 // Estimated offsets: (25000 + 35000)/2 - 135000 = -105000, // 35000 - (135000 + 150000) / 2 = -107500. // Average = -106250. - ASSERT_EQ(-106250, clock_offsets[ClockTracker::ClockId(REALTIME)]); + ASSERT_EQ(-106250, clock_offsets[ClockId::Machine(REALTIME)]); } TEST_F(ProtoTraceReaderTest, CalculateClockOffset_AboveThreshold) { @@ -243,7 +254,7 @@ TEST_F(ProtoTraceReaderTest, CalculateClockOffset_MultiRounds) { CalculateClockOffsetsForTesting(sync_clock_snapshots); ASSERT_EQ(1u, clock_offsets.size()); // Average(-105000, -110000, -122500, -120000) = -114375. - ASSERT_EQ(-114375, clock_offsets[ClockTracker::ClockId(BOOTTIME)]); + ASSERT_EQ(-114375, clock_offsets[ClockId::Machine(BOOTTIME)]); } } // namespace diff --git a/src/trace_processor/importers/proto/system_probes_parser.cc b/src/trace_processor/importers/proto/system_probes_parser.cc index 06196f8b9b0..1bf4404331b 100644 --- a/src/trace_processor/importers/proto/system_probes_parser.cc +++ b/src/trace_processor/importers/proto/system_probes_parser.cc @@ -17,7 +17,6 @@ #include "src/trace_processor/importers/proto/system_probes_parser.h" #include -#include #include #include #include @@ -27,7 +26,6 @@ #include #include "perfetto/base/logging.h" -#include "perfetto/ext/base/status_or.h" #include "perfetto/ext/base/string_utils.h" #include "perfetto/ext/base/string_view.h" #include "perfetto/ext/traced/sys_stats_counters.h" @@ -56,6 +54,7 @@ #include "src/trace_processor/tables/metadata_tables_py.h" #include "src/trace_processor/types/trace_processor_context.h" #include "src/trace_processor/types/variadic.h" +#include "src/trace_processor/util/clock_synchronizer.h" #include "protos/perfetto/common/builtin_clock.pbzero.h" #include "protos/perfetto/common/system_info.pbzero.h" @@ -717,7 +716,7 @@ void SystemProbesParser::ParseProcessTree(int64_t ts, ConstBytes blob) { // note: early kernel threads can have an age of zero (at tick resolution) if (proc.has_process_start_from_boot()) { std::optional start_ts = context_->clock_tracker->ToTraceTime( - ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_BOOTTIME), + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_BOOTTIME), static_cast(proc.process_start_from_boot())); if (start_ts) { context_->process_tracker->SetStartTsIfUnset(upid, *start_ts); diff --git a/src/trace_processor/importers/proto/track_event_tokenizer.cc b/src/trace_processor/importers/proto/track_event_tokenizer.cc index cd1d4d82640..68531c9a8d6 100644 --- a/src/trace_processor/importers/proto/track_event_tokenizer.cc +++ b/src/trace_processor/importers/proto/track_event_tokenizer.cc @@ -21,9 +21,9 @@ #include #include #include +#include #include -#include "perfetto/base/build_config.h" #include "perfetto/base/compiler.h" #include "perfetto/base/status.h" #include "perfetto/ext/base/status_macros.h" @@ -51,7 +51,7 @@ #include "src/trace_processor/storage/stats.h" #include "src/trace_processor/storage/trace_storage.h" #include "src/trace_processor/types/variadic.h" -#include "src/trace_processor/util/simple_json_parser.h" +#include "src/trace_processor/util/clock_synchronizer.h" #include "protos/perfetto/common/builtin_clock.pbzero.h" #include "protos/perfetto/trace/trace_packet.pbzero.h" @@ -434,8 +434,7 @@ ModuleResult TrackEventTokenizer::TokenizeTrackEventPacket( // Legacy TrackEvent timestamp fields are in MONOTONIC domain. Adjust to // trace time if we have a clock snapshot. std::optional trace_ts = context_->clock_tracker->ToTraceTime( - ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_MONOTONIC), - timestamp); + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_MONOTONIC), timestamp); if (trace_ts) timestamp = *trace_ts; } else if (int64_t ts_absolute_us = event.timestamp_absolute_us()) { @@ -445,8 +444,7 @@ ModuleResult TrackEventTokenizer::TokenizeTrackEventPacket( // Legacy TrackEvent timestamp fields are in MONOTONIC domain. Adjust to // trace time if we have a clock snapshot. std::optional trace_ts = context_->clock_tracker->ToTraceTime( - ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_MONOTONIC), - timestamp); + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_MONOTONIC), timestamp); if (trace_ts) timestamp = *trace_ts; } else if (packet.has_timestamp()) { @@ -641,7 +639,7 @@ base::Status TrackEventTokenizer::TokenizeLegacySampleEvent( const V8Profile& profile = *profile_or; if (profile.start_time.has_value()) { std::optional ts = context_->clock_tracker->ToTraceTime( - ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_MONOTONIC), + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_MONOTONIC), *profile.start_time * 1000); if (ts) { v8_tracker_->SetStartTsForSessionAndPid( diff --git a/src/trace_processor/importers/simpleperf_proto/BUILD.gn b/src/trace_processor/importers/simpleperf_proto/BUILD.gn index 870a68dc200..b4e768d5537 100644 --- a/src/trace_processor/importers/simpleperf_proto/BUILD.gn +++ b/src/trace_processor/importers/simpleperf_proto/BUILD.gn @@ -24,6 +24,7 @@ source_set("simpleperf_proto") { "../../../../gn:default_deps", "../../../../include/perfetto/ext/base:base", "../../../../include/perfetto/protozero:protozero", + "../../../../protos/perfetto/common:zero", "../../../../protos/third_party/simpleperf:zero", "../../importers/common:common", "../../sorter", diff --git a/src/trace_processor/importers/simpleperf_proto/simpleperf_proto_tokenizer.cc b/src/trace_processor/importers/simpleperf_proto/simpleperf_proto_tokenizer.cc index 29aec3fe75a..01d75860cf8 100644 --- a/src/trace_processor/importers/simpleperf_proto/simpleperf_proto_tokenizer.cc +++ b/src/trace_processor/importers/simpleperf_proto/simpleperf_proto_tokenizer.cc @@ -28,13 +28,16 @@ #include "perfetto/ext/base/string_view.h" #include "perfetto/protozero/field.h" #include "perfetto/trace_processor/trace_blob_view.h" +#include "src/trace_processor/importers/common/clock_tracker.h" #include "src/trace_processor/importers/common/mapping_tracker.h" #include "src/trace_processor/importers/common/virtual_memory_mapping.h" #include "src/trace_processor/importers/simpleperf_proto/simpleperf_proto_parser.h" #include "src/trace_processor/sorter/trace_sorter.h" #include "src/trace_processor/storage/trace_storage.h" #include "src/trace_processor/types/trace_processor_context.h" +#include "src/trace_processor/util/clock_synchronizer.h" +#include "protos/perfetto/common/builtin_clock.pbzero.h" #include "protos/third_party/simpleperf/cmd_report_sample.pbzero.h" namespace perfetto::trace_processor::simpleperf_proto_importer { @@ -227,10 +230,14 @@ base::Status SimpleperfProtoTokenizer::ParseRecord() { } // Create event with the record data and push to sorter - SimpleperfProtoEvent event; - event.ts = ts; - event.record_data = std::move(*record_data); - stream_->Push(ts, std::move(event)); + auto trace_ts = context_->clock_tracker->ToTraceTime( + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_MONOTONIC), ts); + if (trace_ts) { + SimpleperfProtoEvent event; + event.ts = *trace_ts; + event.record_data = std::move(*record_data); + stream_->Push(*trace_ts, std::move(event)); + } reader_.PopFrontUntil(iter.file_offset()); state_ = State::kExpectingRecordSize; diff --git a/src/trace_processor/importers/systrace/systrace_trace_parser.cc b/src/trace_processor/importers/systrace/systrace_trace_parser.cc index 9a33d076fd2..cfd3810245c 100644 --- a/src/trace_processor/importers/systrace/systrace_trace_parser.cc +++ b/src/trace_processor/importers/systrace/systrace_trace_parser.cc @@ -33,13 +33,16 @@ #include "perfetto/ext/base/string_utils.h" #include "perfetto/ext/base/string_view.h" #include "perfetto/trace_processor/trace_blob_view.h" +#include "protos/perfetto/common/builtin_clock.pbzero.h" #include "src/trace_processor/forwarding_trace_parser.h" +#include "src/trace_processor/importers/common/clock_tracker.h" #include "src/trace_processor/importers/common/process_tracker.h" #include "src/trace_processor/importers/systrace/systrace_line.h" #include "src/trace_processor/importers/systrace/systrace_line_parser.h" #include "src/trace_processor/sorter/trace_sorter.h" #include "src/trace_processor/storage/stats.h" #include "src/trace_processor/storage/trace_storage.h" +#include "src/trace_processor/util/clock_synchronizer.h" #include "src/trace_processor/util/trace_type.h" namespace perfetto::trace_processor { @@ -183,7 +186,12 @@ base::Status SystraceTraceParser::Parse(TraceBlobView blob) { SystraceLine line; base::Status status = line_tokenizer_.Tokenize(buffer, &line); if (status.ok()) { - stream_->Push(line.ts, std::move(line)); + auto trace_ts = ctx_->clock_tracker->ToTraceTime( + ClockId::Machine(protos::pbzero::BUILTIN_CLOCK_MONOTONIC), + line.ts); + if (trace_ts) { + stream_->Push(*trace_ts, std::move(line)); + } } else { ctx_->storage->IncrementStats(stats::systrace_parse_failure); } diff --git a/src/trace_processor/importers/systrace/systrace_trace_parser.h b/src/trace_processor/importers/systrace/systrace_trace_parser.h index bfa63aec125..c1a041c13e3 100644 --- a/src/trace_processor/importers/systrace/systrace_trace_parser.h +++ b/src/trace_processor/importers/systrace/systrace_trace_parser.h @@ -23,6 +23,7 @@ #include "perfetto/base/status.h" #include "src/trace_processor/importers/common/chunked_trace_reader.h" +#include "src/trace_processor/importers/common/clock_tracker.h" #include "src/trace_processor/importers/systrace/systrace_line.h" #include "src/trace_processor/importers/systrace/systrace_line_parser.h" #include "src/trace_processor/importers/systrace/systrace_line_tokenizer.h" diff --git a/src/trace_processor/storage/stats.h b/src/trace_processor/storage/stats.h index 147bd5906d1..2fb2741efc4 100644 --- a/src/trace_processor/storage/stats.h +++ b/src/trace_processor/storage/stats.h @@ -296,6 +296,11 @@ namespace perfetto::trace_processor::stats { "time clock. Both clocks exist in snapshots, but never together or " \ "via a common intermediate clock. Ensure ClockSnapshots link all used " \ "clocks to the trace time clock."), \ + F(clock_sync_mixed_clock_sources, kSingle, kError, kAnalysis, \ + "A non-primary trace file used both the primary trace's clock " \ + "snapshots and its own for timestamp conversion. Timestamps " \ + "converted before the first own clock snapshot used the primary " \ + "trace's clocks which may differ."), \ F(clock_sync_cache_miss, kSingle, kInfo, kAnalysis, ""), \ F(process_tracker_errors, kSingle, kError, kAnalysis, ""), \ F(namespaced_thread_missing_process, kSingle, kError, kAnalysis, \ diff --git a/src/trace_processor/trace_processor_context.cc b/src/trace_processor/trace_processor_context.cc index 3901ca843c1..843838d1676 100644 --- a/src/trace_processor/trace_processor_context.cc +++ b/src/trace_processor/trace_processor_context.cc @@ -52,8 +52,7 @@ #include "src/trace_processor/storage/trace_storage.h" #include "src/trace_processor/trace_reader_registry.h" #include "src/trace_processor/types/trace_processor_context_ptr.h" - -#include "protos/perfetto/common/builtin_clock.pbzero.h" +#include "src/trace_processor/util/clock_synchronizer.h" namespace perfetto::trace_processor { namespace { @@ -61,8 +60,11 @@ namespace { template using Ptr = TraceProcessorContextPtr; -void InitPerTraceAndMachineState(TraceProcessorContext* context) { - // Per-machine state (legacy). +void InitPerTraceAndMachineState(TraceProcessorContext* context, + bool is_primary_trace_for_machine) { + context->clock_tracker = Ptr::MakeRoot( + context, std::make_unique(context), + context->primary_clock_sync.get(), is_primary_trace_for_machine); context->track_tracker = Ptr::MakeRoot(context); context->track_compressor = Ptr::MakeRoot(context); context->slice_tracker = Ptr::MakeRoot(context); @@ -88,8 +90,9 @@ void InitPerMachineState(TraceProcessorContext* context, uint32_t machine_id) { context->symbol_tracker = Ptr::MakeRoot(context); context->machine_tracker = Ptr::MakeRoot(context, machine_id); context->process_tracker = Ptr::MakeRoot(context); - context->clock_tracker = Ptr::MakeRoot( - context, std::make_unique(context)); + context->primary_clock_sync = Ptr::MakeRoot( + context->trace_time_state.get(), + std::make_unique(context)); context->mapping_tracker = Ptr::MakeRoot(context); context->cpu_tracker = Ptr::MakeRoot(context); } @@ -99,7 +102,7 @@ void CopyPerMachineState(const TraceProcessorContext* source, dest->symbol_tracker = source->symbol_tracker.Fork(); dest->machine_tracker = source->machine_tracker.Fork(); dest->process_tracker = source->process_tracker.Fork(); - dest->clock_tracker = source->clock_tracker.Fork(); + dest->primary_clock_sync = source->primary_clock_sync.Fork(); dest->mapping_tracker = source->mapping_tracker.Fork(); dest->cpu_tracker = source->cpu_tracker.Fork(); } @@ -158,9 +161,8 @@ void InitGlobalState(TraceProcessorContext* context, const Config& config) { context->forked_context_state = Ptr::MakeRoot(); context->clock_converter = Ptr::MakeRoot(context); - context->trace_time_state = Ptr::MakeRoot(TraceTimeState{ - ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_BOOTTIME), - /*used_for_conversion=*/false}); + context->trace_time_state = + Ptr::MakeRoot(ClockId::TraceFile(0)); context->track_group_idx_state = Ptr::MakeRoot(); context->stack_profile_tracker = Ptr::MakeRoot(context); @@ -241,7 +243,7 @@ TraceProcessorContext* TraceProcessorContext::ForkContextForTrace( } // Initialize per-trace & per-machine state. - InitPerTraceAndMachineState(context.get()); + InitPerTraceAndMachineState(context.get(), machine_inserted); *it = std::move(context); } diff --git a/src/trace_processor/types/trace_processor_context.h b/src/trace_processor/types/trace_processor_context.h index 204f76589f1..1626eeb194a 100644 --- a/src/trace_processor/types/trace_processor_context.h +++ b/src/trace_processor/types/trace_processor_context.h @@ -32,6 +32,7 @@ namespace perfetto::trace_processor { class ArgsTranslationTable; class ClockConverter; +class ClockSynchronizer; class ClockTracker; class CpuTracker; class DescriptorPool; @@ -188,7 +189,7 @@ class TraceProcessorContext { PerMachinePtr symbol_tracker; PerMachinePtr process_tracker; - PerMachinePtr clock_tracker; + PerMachinePtr primary_clock_sync; PerMachinePtr mapping_tracker; PerMachinePtr machine_tracker; PerMachinePtr cpu_tracker; @@ -198,6 +199,7 @@ class TraceProcessorContext { // // This state is unique to each (machine, trace) pair. + PerTraceAndMachinePtr clock_tracker; PerTraceAndMachinePtr args_translation_table; PerTraceAndMachinePtr process_track_translation_table; diff --git a/src/trace_processor/util/clock_synchronizer.cc b/src/trace_processor/util/clock_synchronizer.cc index 0ef78c72755..0d7f6fbd985 100644 --- a/src/trace_processor/util/clock_synchronizer.cc +++ b/src/trace_processor/util/clock_synchronizer.cc @@ -127,8 +127,7 @@ base::StatusOr ClockSynchronizer::AddSnapshot( // Clock ids in the range [64, 128) are sequence-scoped and must be // translated to global ids via SequenceToGlobalClock() before calling // this function. - PERFETTO_DCHECK(!IsSequenceClock(clock_id.clock_id) || - clock_id.seq_id != 0); + PERFETTO_DCHECK(!clock_id.IsSequenceClock() || clock_id.seq_id != 0); // Snapshot IDs must be always monotonic. PERFETTO_DCHECK(vect.snapshot_ids.empty() || @@ -204,9 +203,8 @@ std::optional ClockSynchronizer::ConvertSlowpath( std::optional src_ts_ns, ClockId target_clock_id, std::optional byte_offset) { - PERFETTO_DCHECK(!IsSequenceClock(src_clock_id.clock_id) || - src_clock_id.seq_id != 0); - PERFETTO_DCHECK(!IsSequenceClock(target_clock_id.clock_id) || + PERFETTO_DCHECK(!src_clock_id.IsSequenceClock() || src_clock_id.seq_id != 0); + PERFETTO_DCHECK(!target_clock_id.IsSequenceClock() || target_clock_id.seq_id != 0); clock_event_listener_->OnClockSyncCacheMiss(); diff --git a/src/trace_processor/util/clock_synchronizer.h b/src/trace_processor/util/clock_synchronizer.h index 4ed6e22ff83..34c390818c8 100644 --- a/src/trace_processor/util/clock_synchronizer.h +++ b/src/trace_processor/util/clock_synchronizer.h @@ -33,9 +33,12 @@ #include "perfetto/base/logging.h" #include "perfetto/base/status.h" #include "perfetto/ext/base/circular_queue.h" +#include "perfetto/ext/base/flat_hash_map.h" #include "perfetto/ext/base/status_or.h" #include "perfetto/public/compiler.h" +#include "protos/perfetto/common/builtin_clock.pbzero.h" + namespace perfetto::trace_processor { // This class handles synchronization of timestamps across different clock @@ -122,9 +125,22 @@ struct ClockId { uint32_t trace_file_id = 0; constexpr ClockId() = default; - constexpr explicit ClockId(uint32_t _clock_id) : ClockId(_clock_id, 0, 0) {} - constexpr ClockId(uint32_t cid, uint32_t sid, uint32_t tfi) - : clock_id(cid), seq_id(sid), trace_file_id(tfi) {} + + // Factory for machine-scoped builtin clocks (e.g. BOOTTIME, MONOTONIC). + static constexpr ClockId Machine(uint32_t builtin_clock_id) { + return {builtin_clock_id, 0, 0}; + } + + // Factory for trace-file-scoped clocks. + static constexpr ClockId TraceFile(uint32_t tfi) { + return {protos::pbzero::BUILTIN_CLOCK_TRACE_FILE, 0, tfi}; + } + + // Factory for sequence-scoped clocks. + static constexpr ClockId Sequence(uint32_t tfi, uint32_t sid, uint32_t cid) { + PERFETTO_DCHECK(IsSequenceClock(cid)); + return {cid, sid, tfi}; + } bool operator==(const ClockId& o) const { return clock_id == o.clock_id && seq_id == o.seq_id && @@ -142,6 +158,18 @@ struct ClockId { friend H PerfettoHashValue(H h, const ClockId& c) { return H::Combine(std::move(h), c.clock_id, c.seq_id, c.trace_file_id); } + + static constexpr bool IsSequenceClock(uint32_t clock_id) { + return clock_id >= 64 && clock_id < 128; + } + + bool IsSequenceClock() const { return IsSequenceClock(clock_id); } + + private: + friend class ClockSynchronizer; + + constexpr ClockId(uint32_t cid, uint32_t sid, uint32_t tfi) + : clock_id(cid), seq_id(sid), trace_file_id(tfi) {} }; // Clock description. @@ -178,8 +206,21 @@ enum class ClockSyncErrorType { // that AddSnapshot can validate against the current trace-time clock // without a virtual call. struct TraceTimeState { + TraceTimeState() = default; + explicit TraceTimeState(ClockId _clock_id) : clock_id(_clock_id) {} + ClockId clock_id; - bool used_for_conversion = false; + + // Which trace file owns the trace time clock. Only the owner (or no owner) + // may change clock_id. Prevents secondary traces in a ZIP from overriding + // the primary trace's clock choice. + std::optional trace_time_clock_owner; + + std::optional timezone_offset; + + // TODO(lalitm): remote_clock_offsets is a hack. We should have a proper + // definition for dealing with cross-machine clock synchronization. + base::FlatHashMap remote_clock_offsets; }; // Virtual interface for listening to clock synchronization events. @@ -201,20 +242,10 @@ class ClockSynchronizer { ClockSynchronizer(TraceTimeState* trace_time_state, std::unique_ptr listener); - // IDs in the range [64, 128) are reserved for sequence-scoped clock ids. - // They can't be passed directly in ClockSynchronizer calls and must be - // resolved to global clock ids by calling SequenceToGlobalClock(). - static bool IsSequenceClock(uint32_t raw_clock_id) { - return raw_clock_id >= 64 && raw_clock_id < 128; - } - - // Converts a sequence-scoped clock id to a global clock id that can be - // passed as argument to ClockSynchronizer functions. - static ClockId SequenceToGlobalClock(uint32_t trace_file_id, - uint32_t seq_id, - uint32_t clock_id) { - PERFETTO_DCHECK(IsSequenceClock(clock_id)); - return ClockId{clock_id, seq_id, trace_file_id}; + // Returns true if the clock synchronizer has seen the given clock in any + // snapshot. + bool HasClock(ClockId clock_id) const { + return clocks_.find(clock_id) != clocks_.end(); } // Appends a new snapshot for the given clock domains. diff --git a/src/trace_redaction/collect_clocks.cc b/src/trace_redaction/collect_clocks.cc index db3bdc91583..d042e62f8e6 100644 --- a/src/trace_redaction/collect_clocks.cc +++ b/src/trace_redaction/collect_clocks.cc @@ -67,7 +67,7 @@ base::Status CollectClocks::ParseClockSnapshot( auto trace_clock = static_cast(snapshot_decoder.primary_trace_clock()); RETURN_IF_ERROR( - context->clock_converter.SetTraceClock(ClockId(trace_clock))); + context->clock_converter.SetTraceClock(ClockId::Machine(trace_clock))); } for (auto clock_it = snapshot_decoder.clocks(); clock_it; clock_it++) { ASSIGN_OR_RETURN(ClockTimestamp clock_ts, ParseClock(clock_it->as_bytes())); @@ -97,7 +97,7 @@ base::Status CollectClocks::ParseTracePacketDefaults( base::StatusOr CollectClocks::ParseClock( protozero::ConstBytes clock_bytes) const { - ClockTimestamp clock_ts(ClockId(0), 0); + ClockTimestamp clock_ts(ClockId::Machine(0), 0); protos::pbzero::ClockSnapshot_Clock::Decoder clock_decoder(clock_bytes); if (!clock_decoder.has_clock_id()) { return base::ErrStatus("Could not find clock id in clock snapshot"); @@ -106,7 +106,7 @@ base::StatusOr CollectClocks::ParseClock( if (!clock_decoder.has_timestamp()) { return base::ErrStatus("Could not find clock timestamp in clock snapshot"); } - return ClockTimestamp(ClockId(clock_decoder.clock_id()), + return ClockTimestamp(ClockId::Machine(clock_decoder.clock_id()), static_cast(clock_decoder.timestamp())); } @@ -127,7 +127,7 @@ base::Status CollectClocks::OnTracePacketDefaults( uint32_t perf_clock_id = trace_packet_defaults_decoder.timestamp_clock_id(); context->clock_converter.SetDefaultDataSourceClock( RedactorClockConverter::DataSourceType::kPerfDataSource, - ClockId(perf_clock_id), trusted_sequence_id); + ClockId::Machine(perf_clock_id), trusted_sequence_id); } return base::OkStatus(); diff --git a/src/trace_redaction/collect_clocks_unittest.cc b/src/trace_redaction/collect_clocks_unittest.cc index 33f2d3f3845..69cc863dcbc 100644 --- a/src/trace_redaction/collect_clocks_unittest.cc +++ b/src/trace_redaction/collect_clocks_unittest.cc @@ -63,8 +63,8 @@ class CollectClocksTest : public testing::Test { TEST_F(CollectClocksTest, CollectsClocksAndConvertsPerfToTraceTs) { // We need a trusted sequence id that will be used to map the clock ids. constexpr uint32_t trusted_sequence_id = 7; - constexpr ClockId perf_clock_id(1); - constexpr ClockId trace_clock_id(4); + constexpr ClockId perf_clock_id = ClockId::Machine(1); + constexpr ClockId trace_clock_id = ClockId::Machine(4); protos::gen::TracePacket trace_defaults_packet; AddPerfTraceDefaultsToPacket(trace_defaults_packet, trusted_sequence_id, @@ -123,11 +123,11 @@ TEST_F(CollectClocksTest, CollectsClocksAndConvertsPerfToTraceTs) { TEST_F(CollectClocksTest, CollectsClocksMultiSequence) { packets_.clear(); - constexpr ClockId trace_clock_id(4); + constexpr ClockId trace_clock_id = ClockId::Machine(4); // Create defaults for first trusted sequence constexpr int trusted_sequence_id_1 = 1; - constexpr ClockId perf_clock_id_seq_1(5); + constexpr ClockId perf_clock_id_seq_1 = ClockId::Machine(5); protos::gen::TracePacket trace_defaults_packet_seq_1; AddPerfTraceDefaultsToPacket(trace_defaults_packet_seq_1, trusted_sequence_id_1, @@ -136,7 +136,7 @@ TEST_F(CollectClocksTest, CollectsClocksMultiSequence) { // Create defaults for second trusted sequence constexpr int trusted_sequence_id_2 = 2; - constexpr ClockId perf_clock_id_seq_2(6); + constexpr ClockId perf_clock_id_seq_2 = ClockId::Machine(6); protos::gen::TracePacket trace_defaults_packet_seq_2; AddPerfTraceDefaultsToPacket(trace_defaults_packet_seq_2, trusted_sequence_id_2, diff --git a/src/trace_redaction/prune_perf_events.cc b/src/trace_redaction/prune_perf_events.cc index aa119558ff4..4ad73ee8872 100644 --- a/src/trace_redaction/prune_perf_events.cc +++ b/src/trace_redaction/prune_perf_events.cc @@ -127,7 +127,7 @@ base::Status PrunePerfEvents::OnPerfSample( static_cast(trusted_packet_sequence_id.value()), RedactorClockConverter::DataSourceType::kPerfDataSource)); } else { - clock_id = ClockId(trace_packet_clock_id.value()); + clock_id = ClockId::Machine(trace_packet_clock_id.value()); } ASSIGN_OR_RETURN(trace_ts, diff --git a/src/trace_redaction/redactor_clock_converter.cc b/src/trace_redaction/redactor_clock_converter.cc index e3d0578d044..fa17139b342 100644 --- a/src/trace_redaction/redactor_clock_converter.cc +++ b/src/trace_redaction/redactor_clock_converter.cc @@ -53,9 +53,8 @@ void RedactorClockSynchronizerListenerImpl::RecordConversionError( } RedactorClockConverter::RedactorClockConverter() - : trace_time_state_{ClockId(protos::pbzero::BuiltinClock:: - BUILTIN_CLOCK_BOOTTIME), - /*used_for_conversion=*/false}, + : trace_time_state_{ClockId::Machine( + protos::pbzero::BuiltinClock::BUILTIN_CLOCK_BOOTTIME)}, clock_synchronizer_( &trace_time_state_, std::make_unique()) {} @@ -63,8 +62,8 @@ RedactorClockConverter::RedactorClockConverter() base::StatusOr RedactorClockConverter::GetTraceClock() { if (!primary_trace_clock_.has_value()) { // Set the default clocks if none has been provided. - RETURN_IF_ERROR(SetTraceClock( - ClockId(protos::pbzero::BuiltinClock::BUILTIN_CLOCK_BOOTTIME))); + RETURN_IF_ERROR(SetTraceClock(ClockId::Machine( + protos::pbzero::BuiltinClock::BUILTIN_CLOCK_BOOTTIME))); } PERFETTO_DCHECK(primary_trace_clock_.has_value()); return primary_trace_clock_.value(); @@ -98,7 +97,8 @@ base::StatusOr RedactorClockConverter::GetGlobalDefaultDataSourceClock( const DataSourceType& clock_type) const { switch (clock_type) { case DataSourceType::kPerfDataSource: - return ClockId(protos::pbzero::BuiltinClock::BUILTIN_CLOCK_MONOTONIC_RAW); + return ClockId::Machine( + protos::pbzero::BuiltinClock::BUILTIN_CLOCK_MONOTONIC_RAW); case DataSourceType::kUnknown: // A default needs to be set for the data source if you get here. return base::ErrStatus( diff --git a/test/trace_processor/diff_tests/parser/power/tests_power_rails.py b/test/trace_processor/diff_tests/parser/power/tests_power_rails.py index 5bed6c10664..2aa5e86e0b9 100644 --- a/test/trace_processor/diff_tests/parser/power/tests_power_rails.py +++ b/test/trace_processor/diff_tests/parser/power/tests_power_rails.py @@ -388,6 +388,11 @@ def test_power_rails_multi_device(self): } } } + packet { + clock_snapshot { + primary_trace_clock: BUILTIN_CLOCK_BOOTTIME + } + } packet { timestamp: 1000000 power_rails {