Skip to content
1 change: 1 addition & 0 deletions src/trace_processor/BUILD.gn
Original file line number Diff line number Diff line change
Expand Up @@ -143,6 +143,7 @@ source_set("storage_minimal") {
"tables",
"types",
"util:blob",
"util:clock",
"util:descriptors",
"util:gzip",
"util:proto_to_args_parser",
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -76,8 +76,12 @@ class AndroidLogReaderTest : public ::testing::Test {
context_.metadata_tracker = std::make_unique<MetadataTracker>(&context_);
context_.trace_time_state = std::make_unique<TraceTimeState>(TraceTimeState{
ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_BOOTTIME), false});
primary_sync_ = std::make_unique<ClockSynchronizer>(
context_.trace_time_state.get(),
std::make_unique<ClockSynchronizerListenerImpl>(&context_));
context_.clock_tracker = std::make_unique<ClockTracker>(
&context_, std::make_unique<ClockSynchronizerListenerImpl>(&context_));
&context_, std::make_unique<ClockSynchronizerListenerImpl>(&context_),
primary_sync_.get());
context_.clock_tracker->SetTraceTimeClock(
ClockTracker::ClockId(protos::pbzero::ClockSnapshot::Clock::REALTIME));
context_.sorter = std::make_unique<TraceSorter>(
Expand All @@ -92,6 +96,7 @@ class AndroidLogReaderTest : public ::testing::Test {

private:
TraceProcessorContext context_;
std::unique_ptr<ClockSynchronizer> primary_sync_;
};

TEST_F(AndroidLogReaderTest, PersistentLogFormat) {
Expand Down
45 changes: 36 additions & 9 deletions src/trace_processor/importers/common/clock_tracker.cc
Original file line number Diff line number Diff line change
Expand Up @@ -21,12 +21,15 @@
#include <cstdint>
#include <memory>
#include <optional>
#include <utility>
#include <vector>

#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"
Expand All @@ -43,13 +46,37 @@ namespace perfetto::trace_processor {

ClockTracker::ClockTracker(
TraceProcessorContext* context,
std::unique_ptr<ClockSynchronizerListenerImpl> listener)
std::unique_ptr<ClockSynchronizerListenerImpl> 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<uint32_t> ClockTracker::AddSnapshot(
const std::vector<ClockTimestamp>& 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) {
Expand Down Expand Up @@ -81,15 +108,15 @@ std::optional<int64_t> 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<int64_t> 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 ---
Expand All @@ -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<ClockId, int64_t>&
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 ---
Expand Down
35 changes: 29 additions & 6 deletions src/trace_processor/importers/common/clock_tracker.h
Original file line number Diff line number Diff line change
Expand Up @@ -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<ClockSynchronizerListenerImpl> listener);
std::unique_ptr<ClockSynchronizerListenerImpl> listener,
ClockSynchronizer* primary_sync,
bool is_primary = true);

// --- Hot-path APIs (inlined) ---

Expand All @@ -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;
}

Expand All @@ -72,7 +81,8 @@ class ClockTracker {
int64_t ts,
ClockId target,
std::optional<size_t> 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) {
Expand Down Expand Up @@ -113,16 +123,29 @@ 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();

TraceProcessorContext* context_;
ClockSynchronizer sync_;
base::FlatHashMap<ClockId, int64_t> remote_clock_offsets_;
std::optional<int64_t> 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 {
Expand Down
72 changes: 71 additions & 1 deletion src/trace_processor/importers/common/clock_tracker_unittest.cc
Original file line number Diff line number Diff line change
Expand Up @@ -55,8 +55,12 @@ class ClockTrackerTest : public ::testing::Test {
std::make_unique<MachineTracker>(&context_, kDefaultMachineId);
context_.trace_time_state = std::make_unique<TraceTimeState>(TraceTimeState{
ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_BOOTTIME), false});
primary_sync_ = std::make_unique<ClockSynchronizer>(
context_.trace_time_state.get(),
std::make_unique<ClockSynchronizerListenerImpl>(&context_));
ct_ = std::make_unique<ClockTracker>(
&context_, std::make_unique<ClockSynchronizerListenerImpl>(&context_));
&context_, std::make_unique<ClockSynchronizerListenerImpl>(&context_),
primary_sync_.get());
}
std::optional<int64_t> Convert(ClockTracker::ClockId src_clock_id,
int64_t src_timestamp,
Expand All @@ -65,6 +69,7 @@ class ClockTrackerTest : public ::testing::Test {
}

TraceProcessorContext context_;
std::unique_ptr<ClockSynchronizer> primary_sync_;
std::unique_ptr<ClockTracker> ct_;
};

Expand Down Expand Up @@ -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<ClockSynchronizerListenerImpl>(&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<ClockTracker>(
&context_, std::make_unique<ClockSynchronizerListenerImpl>(&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<ClockSynchronizerListenerImpl>(&context_));
shared_sync.AddSnapshot({{REALTIME, 10}, {BOOTTIME, 10010}});

auto non_primary = std::make_unique<ClockTracker>(
&context_, std::make_unique<ClockSynchronizerListenerImpl>(&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<ClockSynchronizerListenerImpl>(&context_));

// Create primary trace ClockTracker pointing to shared_sync.
auto primary = std::make_unique<ClockTracker>(
&context_, std::make_unique<ClockSynchronizerListenerImpl>(&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<ClockTracker>(
&context_, std::make_unique<ClockSynchronizerListenerImpl>(&context_),
&shared_sync, /*is_primary=*/false);
EXPECT_EQ(*non_primary->ToTraceTime(REALTIME, 10), 10010);
}

} // namespace
} // namespace perfetto::trace_processor
Original file line number Diff line number Diff line change
Expand Up @@ -203,8 +203,12 @@ class FuchsiaTraceParserTest : public ::testing::Test {
std::make_unique<SliceTranslationTable>(storage_);
context_.trace_time_state = std::make_unique<TraceTimeState>(TraceTimeState{
ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_BOOTTIME), false});
primary_sync_ = std::make_unique<ClockSynchronizer>(
context_.trace_time_state.get(),
std::make_unique<ClockSynchronizerListenerImpl>(&context_));
context_.clock_tracker = std::make_unique<ClockTracker>(
&context_, std::make_unique<ClockSynchronizerListenerImpl>(&context_));
&context_, std::make_unique<ClockSynchronizerListenerImpl>(&context_),
primary_sync_.get());
clock_ = context_.clock_tracker.get();
context_.flow_tracker = std::make_unique<FlowTracker>(&context_);
context_.sorter = std::make_unique<TraceSorter>(
Expand Down Expand Up @@ -240,6 +244,7 @@ class FuchsiaTraceParserTest : public ::testing::Test {
std::vector<uint64_t> trace_bytes_;

TraceProcessorContext context_;
std::unique_ptr<ClockSynchronizer> primary_sync_;
MockEventTracker* event_;
MockSchedEventTracker* sched_;
MockProcessTracker* process_;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -83,8 +83,12 @@ class NetworkTraceModuleTest : public testing::Test {
std::make_unique<ImportLogsTracker>(&context_, TraceId(1));
context_.trace_time_state = std::make_unique<TraceTimeState>(TraceTimeState{
ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_BOOTTIME), false});
primary_sync_ = std::make_unique<ClockSynchronizer>(
context_.trace_time_state.get(),
std::make_unique<ClockSynchronizerListenerImpl>(&context_));
context_.clock_tracker = std::make_unique<ClockTracker>(
&context_, std::make_unique<ClockSynchronizerListenerImpl>(&context_));
&context_, std::make_unique<ClockSynchronizerListenerImpl>(&context_),
primary_sync_.get());
context_.track_tracker = std::make_unique<TrackTracker>(&context_);
context_.slice_tracker = std::make_unique<SliceTracker>(&context_);
context_.global_args_tracker =
Expand Down Expand Up @@ -146,6 +150,7 @@ class NetworkTraceModuleTest : public testing::Test {
protected:
protozero::HeapBuffered<protos::pbzero::Trace> trace_;
TraceProcessorContext context_;
std::unique_ptr<ClockSynchronizer> primary_sync_;
TraceStorage* storage_;
};

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -282,8 +282,12 @@ class ProtoTraceParserTest : public ::testing::Test {
std::make_unique<SliceTranslationTable>(storage_);
context_.trace_time_state = std::make_unique<TraceTimeState>(TraceTimeState{
ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_BOOTTIME), false});
primary_sync_ = std::make_unique<ClockSynchronizer>(
context_.trace_time_state.get(),
std::make_unique<ClockSynchronizerListenerImpl>(&context_));
context_.clock_tracker = std::make_unique<ClockTracker>(
&context_, std::make_unique<ClockSynchronizerListenerImpl>(&context_));
&context_, std::make_unique<ClockSynchronizerListenerImpl>(&context_),
primary_sync_.get());
context_.flow_tracker = std::make_unique<FlowTracker>(&context_);
context_.sorter = std::make_unique<TraceSorter>(
&context_, TraceSorter::SortingMode::kFullSort);
Expand Down Expand Up @@ -355,6 +359,7 @@ class ProtoTraceParserTest : public ::testing::Test {
protected:
protozero::HeapBuffered<protos::pbzero::Trace> trace_;
TraceProcessorContext context_;
std::unique_ptr<ClockSynchronizer> primary_sync_;
MockEventTracker* event_;
MockSchedEventTracker* sched_;
MockProcessTracker* process_;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -67,9 +67,13 @@ class ProtoTraceReaderTest : public ::testing::Test {
std::make_unique<TraceTimeState>(TraceTimeState{
ClockTracker::ClockId(protos::pbzero::BUILTIN_CLOCK_BOOTTIME),
false});
primary_sync_ = std::make_unique<ClockSynchronizer>(
host_context_.trace_time_state.get(),
std::make_unique<ClockSynchronizerListenerImpl>(&host_context_));
host_context_.clock_tracker = std::make_unique<ClockTracker>(
&host_context_,
std::make_unique<ClockSynchronizerListenerImpl>(&host_context_));
std::make_unique<ClockSynchronizerListenerImpl>(&host_context_),
primary_sync_.get());
host_context_.sorter = std::make_unique<TraceSorter>(
&host_context_, TraceSorter::SortingMode::kDefault);
host_context_.descriptor_pool_ = std::make_unique<DescriptorPool>();
Expand All @@ -93,6 +97,7 @@ class ProtoTraceReaderTest : public ::testing::Test {
protected:
protozero::HeapBuffered<protos::pbzero::Trace> trace_;
TraceProcessorContext host_context_;
std::unique_ptr<ClockSynchronizer> primary_sync_;
std::unique_ptr<ProtoTraceReader> proto_trace_reader_;
};

Expand Down
5 changes: 5 additions & 0 deletions src/trace_processor/storage/stats.h
Original file line number Diff line number Diff line change
Expand Up @@ -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, \
Expand Down
Loading