diff --git a/src/trace_processor/BUILD.gn b/src/trace_processor/BUILD.gn index 5e1a195078..0f63f1d5b3 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/importers/android_bugreport/android_log_unittest.cc b/src/trace_processor/importers/android_bugreport/android_log_unittest.cc index 0e867aa054..4c0af828f5 100644 --- a/src/trace_processor/importers/android_bugreport/android_log_unittest.cc +++ b/src/trace_processor/importers/android_bugreport/android_log_unittest.cc @@ -76,8 +76,12 @@ class AndroidLogReaderTest : public ::testing::Test { context_.metadata_tracker = std::make_unique(&context_); context_.trace_time_state = std::make_unique(TraceTimeState{ ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_BOOTTIME), false}); + 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()); context_.clock_tracker->SetTraceTimeClock( ClockTracker::ClockId(protos::pbzero::ClockSnapshot::Clock::REALTIME)); context_.sorter = std::make_unique( @@ -92,6 +96,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/common/clock_tracker.cc b/src/trace_processor/importers/common/clock_tracker.cc index 5e1bb34def..8ae8bdda32 100644 --- a/src/trace_processor/importers/common/clock_tracker.cc +++ b/src/trace_processor/importers/common/clock_tracker.cc @@ -21,12 +21,15 @@ #include #include #include +#include #include +#include "perfetto/base/compiler.h" #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,13 +46,37 @@ 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), + primary_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_LIKELY(is_primary_)) { + return primary_sync_->AddSnapshot(clock_timestamps); + } + // 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) { @@ -81,15 +108,15 @@ std::optional ClockTracker::ToTraceTimeFromSnapshot( } 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; + context_->trace_time_state->timezone_offset = offset; } // --- ClockTracker: private slow paths --- @@ -105,16 +132,16 @@ void ClockTracker::OnFirstTraceTimeUse() { // --- 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 6ea31ffa7d..6e8c2752a7 100644 --- a/src/trace_processor/importers/common/clock_tracker.h +++ b/src/trace_processor/importers/common/clock_tracker.h @@ -47,8 +47,15 @@ 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 = true); // --- Hot-path APIs (inlined) --- @@ -62,7 +69,9 @@ class ClockTracker { if (PERFETTO_UNLIKELY(!state->used_for_conversion)) { OnFirstTraceTimeUse(); } - auto ts = sync_.Convert(clock_id, timestamp, state->clock_id, byte_offset); + ++num_conversions_; + auto ts = active_sync_->Convert(clock_id, timestamp, state->clock_id, + byte_offset); return ts ? std::optional(ToHostTraceTime(*ts)) : ts; } @@ -72,7 +81,8 @@ class ClockTracker { int64_t ts, ClockId target, std::optional byte_offset = {}) { - return sync_.Convert(src, ts, target, byte_offset); + ++num_conversions_; + return active_sync_->Convert(src, ts, target, byte_offset); } static bool IsSequenceClock(uint32_t raw_clock_id) { @@ -113,7 +123,7 @@ 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; } @@ -121,8 +131,21 @@ class ClockTracker { TraceProcessorContext* context_; 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_; + // The primary trace's ClockSynchronizer. All traces add snapshots here + // so that traces without their own snapshots can still convert timestamps. + // Null when no primary sync is configured (e.g. in tests). + ClockSynchronizer* primary_sync_ = nullptr; + // Whether this is the primary trace for its machine (or a test). 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; }; 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 a33739c289..88d61c741a 100644 --- a/src/trace_processor/importers/common/clock_tracker_unittest.cc +++ b/src/trace_processor/importers/common/clock_tracker_unittest.cc @@ -55,8 +55,12 @@ class ClockTrackerTest : public ::testing::Test { std::make_unique(&context_, kDefaultMachineId); context_.trace_time_state = std::make_unique(TraceTimeState{ ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_BOOTTIME), false}); + 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()); } std::optional Convert(ClockTracker::ClockId src_clock_id, int64_t src_timestamp, @@ -65,6 +69,7 @@ class ClockTrackerTest : public ::testing::Test { } TraceProcessorContext context_; + std::unique_ptr primary_sync_; std::unique_ptr ct_; }; @@ -567,5 +572,70 @@ 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); +} + } // namespace } // namespace perfetto::trace_processor diff --git a/src/trace_processor/importers/fuchsia/fuchsia_parser_unittest.cc b/src/trace_processor/importers/fuchsia/fuchsia_parser_unittest.cc index df04b4505d..8fb4dd3f62 100644 --- a/src/trace_processor/importers/fuchsia/fuchsia_parser_unittest.cc +++ b/src/trace_processor/importers/fuchsia/fuchsia_parser_unittest.cc @@ -203,8 +203,12 @@ class FuchsiaTraceParserTest : public ::testing::Test { std::make_unique(storage_); context_.trace_time_state = std::make_unique(TraceTimeState{ ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_BOOTTIME), false}); + 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()); 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/proto/network_trace_module_unittest.cc b/src/trace_processor/importers/proto/network_trace_module_unittest.cc index a08893bb88..41fe5df8d2 100644 --- a/src/trace_processor/importers/proto/network_trace_module_unittest.cc +++ b/src/trace_processor/importers/proto/network_trace_module_unittest.cc @@ -83,8 +83,12 @@ class NetworkTraceModuleTest : public testing::Test { std::make_unique(&context_, TraceId(1)); context_.trace_time_state = std::make_unique(TraceTimeState{ ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_BOOTTIME), false}); + 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()); context_.track_tracker = std::make_unique(&context_); context_.slice_tracker = std::make_unique(&context_); context_.global_args_tracker = @@ -146,6 +150,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/proto_trace_parser_impl_unittest.cc b/src/trace_processor/importers/proto/proto_trace_parser_impl_unittest.cc index 1ac90bcf79..e23334daf3 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 @@ -282,8 +282,12 @@ class ProtoTraceParserTest : public ::testing::Test { std::make_unique(storage_); context_.trace_time_state = std::make_unique(TraceTimeState{ ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_BOOTTIME), false}); + 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()); context_.flow_tracker = std::make_unique(&context_); context_.sorter = std::make_unique( &context_, TraceSorter::SortingMode::kFullSort); @@ -355,6 +359,7 @@ class ProtoTraceParserTest : public ::testing::Test { protected: protozero::HeapBuffered trace_; TraceProcessorContext context_; + std::unique_ptr primary_sync_; MockEventTracker* event_; MockSchedEventTracker* sched_; MockProcessTracker* process_; 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 eb208315ab..03b131f166 100644 --- a/src/trace_processor/importers/proto/proto_trace_reader_unittest.cc +++ b/src/trace_processor/importers/proto/proto_trace_reader_unittest.cc @@ -67,9 +67,13 @@ class ProtoTraceReaderTest : public ::testing::Test { std::make_unique(TraceTimeState{ ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_BOOTTIME), false}); + 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()); host_context_.sorter = std::make_unique( &host_context_, TraceSorter::SortingMode::kDefault); host_context_.descriptor_pool_ = std::make_unique(); @@ -93,6 +97,7 @@ class ProtoTraceReaderTest : public ::testing::Test { protected: protozero::HeapBuffered trace_; TraceProcessorContext host_context_; + std::unique_ptr primary_sync_; std::unique_ptr proto_trace_reader_; }; diff --git a/src/trace_processor/storage/stats.h b/src/trace_processor/storage/stats.h index 147bd5906d..2fb2741efc 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 3901ca843c..83ecc14888 100644 --- a/src/trace_processor/trace_processor_context.cc +++ b/src/trace_processor/trace_processor_context.cc @@ -52,6 +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 "src/trace_processor/util/clock_synchronizer.h" #include "protos/perfetto/common/builtin_clock.pbzero.h" @@ -61,8 +62,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 +92,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 +104,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(); } @@ -241,7 +246,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 204f76589f..9836c9764d 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,10 @@ class TraceProcessorContext { PerMachinePtr symbol_tracker; PerMachinePtr process_tracker; - PerMachinePtr clock_tracker; + // The ClockSynchronizer for the primary trace (the first trace for a + // machine). Primary trace adds snapshots here; non-primary traces read from + // it until they receive their own clock snapshots. + PerMachinePtr primary_clock_sync; PerMachinePtr mapping_tracker; PerMachinePtr machine_tracker; PerMachinePtr cpu_tracker; @@ -198,6 +202,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.h b/src/trace_processor/util/clock_synchronizer.h index 4ed6e22ff8..e3b0d80ab1 100644 --- a/src/trace_processor/util/clock_synchronizer.h +++ b/src/trace_processor/util/clock_synchronizer.h @@ -33,6 +33,7 @@ #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" @@ -178,8 +179,16 @@ enum class ClockSyncErrorType { // that AddSnapshot can validate against the current trace-time clock // without a virtual call. struct TraceTimeState { + TraceTimeState() = default; + TraceTimeState(ClockId _clock_id, bool _used_for_conversion) + : clock_id(_clock_id), used_for_conversion(_used_for_conversion) {} + ClockId clock_id; bool used_for_conversion = false; + 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.