From 64b3d9f0f29a96f851f0f161e8f55dedf9f2875f Mon Sep 17 00:00:00 2001 From: Shuhao Wu Date: Mon, 11 Mar 2024 00:15:44 -0400 Subject: [PATCH 1/6] Synced interned data to our protos from upstream This allows strings like event names and event categories to be interned, thus the size of the resulting data can be significantly reduced. --- docs/tracing.md | 4 +- protos/CMakeLists.txt | 1 + protos/counter_descriptor.proto | 4 +- protos/interned_data.proto | 68 ++++++++++++++++++++++++++++ protos/process_descriptor.proto | 4 +- protos/source_location.proto | 16 ++++++- protos/thread_descriptor.proto | 5 ++- protos/trace.proto | 4 +- protos/trace_packet.proto | 79 ++++++++++++++++++++++++++++++--- protos/track_descriptor.proto | 11 ++++- protos/track_event.proto | 20 +++++++-- 11 files changed, 200 insertions(+), 16 deletions(-) create mode 100644 protos/interned_data.proto diff --git a/docs/tracing.md b/docs/tracing.md index f9fb562..45bc668 100644 --- a/docs/tracing.md +++ b/docs/tracing.md @@ -235,7 +235,9 @@ TODO... ### Performance and limitations -TODO... +#### Too much data causing buffer overflow and trace data drops + +See https://github.com/google/perfetto/issues/575#issuecomment-1699253191 Advanced tuning and use cases ----------------------------- diff --git a/protos/CMakeLists.txt b/protos/CMakeLists.txt index 1c43e28..09d70f7 100644 --- a/protos/CMakeLists.txt +++ b/protos/CMakeLists.txt @@ -13,6 +13,7 @@ protobuf_generate_cpp( process_descriptor.proto counter_descriptor.proto track_event.proto + interned_data.proto source_location.proto ) diff --git a/protos/counter_descriptor.proto b/protos/counter_descriptor.proto index 126b30f..1d2d94f 100644 --- a/protos/counter_descriptor.proto +++ b/protos/counter_descriptor.proto @@ -16,7 +16,9 @@ syntax = "proto2"; -// Adapted from https://github.com/google/perfetto/blob/v36.1/protos/perfetto/trace/track_event/counter_descriptor.proto +// Adapted from https://github.com/google/perfetto/blob/v43.2/protos/perfetto/trace/track_event/counter_descriptor.proto +// +// No changes are made other than the package name. package cactus_tracing.vendor.perfetto.protos; diff --git a/protos/interned_data.proto b/protos/interned_data.proto new file mode 100644 index 0000000..ed3b78d --- /dev/null +++ b/protos/interned_data.proto @@ -0,0 +1,68 @@ +/* + * Copyright (C) 2019 The Android Open Source Project + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +syntax = "proto2"; + +import "source_location.proto"; +import "track_event.proto"; + +// Adapted from https://github.com/google/perfetto/blob/v43.2/protos/perfetto/trace/interned_data/interned_data.proto +// +// 1. Kept only event_names, event_categories, and source_locations + +package cactus_tracing.vendor.perfetto.protos; + +// ------------------------------ DATA INTERNING: ------------------------------ +// Interning indexes are built up gradually by adding the entries contained in +// each TracePacket of the same packet sequence (packets emitted by the same +// producer and TraceWriter, see |trusted_packet_sequence_id|). Thus, packets +// can only refer to interned data from other packets in the same sequence. +// +// The writer will emit new entries when it encounters new internable values +// that aren't yet in the index. Data in current and subsequent TracePackets can +// then refer to the entry by its position (interning ID, abbreviated "iid") in +// its index. An interning ID with value 0 is considered invalid (not set). +// +// Because of the incremental build-up, the interning index will miss data when +// TracePackets are lost, e.g. because a chunk was overridden in the central +// ring buffer. To avoid invalidation of the whole trace in such a case, the +// index is periodically reset (see SEQ_INCREMENTAL_STATE_CLEARED). +// When packet loss occurs, the reader will only lose interning data up to the +// next reset. +// ----------------------------------------------------------------------------- + +// Message that contains new entries for the interning indices of a packet +// sequence. +// +// The writer will usually emit new entries in the same TracePacket that first +// refers to them (since the last reset of interning state). They may also be +// emitted proactively in advance of referring to them in later packets. +// +// Next reserved id: 8 (up to 15). +// Next id: 36. +message InternedData { + // TODO(eseckler): Replace iid fields inside interned messages with + // map type fields in InternedData. + + // Each field's message type needs to specify an |iid| field, which is the ID + // of the entry in the field's interning index. Each field constructs its own + // index, thus interning IDs are scoped to the tracing session and field + // (usually as a counter for efficient var-int encoding), and optionally to + // the incremental state generation of the packet sequence. + repeated EventCategory event_categories = 1; + repeated EventName event_names = 2; + repeated SourceLocation source_locations = 4; +} diff --git a/protos/process_descriptor.proto b/protos/process_descriptor.proto index 73abfca..fe7fcf7 100644 --- a/protos/process_descriptor.proto +++ b/protos/process_descriptor.proto @@ -16,7 +16,9 @@ syntax = "proto2"; -// Adapted from https://github.com/google/perfetto/blob/v36.1/protos/perfetto/trace/track_event/process_descriptor.proto +// Adapted from https://github.com/google/perfetto/blob/v43.2/protos/perfetto/trace/track_event/process_descriptor.proto +// +// 1. Only the non-deprecated fields. package cactus_tracing.vendor.perfetto.protos; diff --git a/protos/source_location.proto b/protos/source_location.proto index 0ec4f97..14802c6 100644 --- a/protos/source_location.proto +++ b/protos/source_location.proto @@ -14,12 +14,26 @@ * limitations under the License. */ -// Adapted from https://github.com/google/perfetto/blob/v36.1/protos/perfetto/trace/track_event/source_location.proto +// Adapted from https://github.com/google/perfetto/blob/v43.2/protos/perfetto/trace/track_event/source_location.proto syntax = "proto2"; package cactus_tracing.vendor.perfetto.protos; +// -------------------- +// Interned data types: +// -------------------- + +// A source location, represented as a native symbol. +// This is similar to `message Frame` from +// protos/perfetto/trace/profiling/profile_common.proto, but for abitrary +// source code locations (for example in track event args), not stack frames. +message UnsymbolizedSourceLocation { + optional uint64 iid = 1; + optional uint64 mapping_id = 2; + optional uint64 rel_pc = 3; +} + message SourceLocation { optional uint64 iid = 1; optional string file_name = 2; diff --git a/protos/thread_descriptor.proto b/protos/thread_descriptor.proto index ec26426..bfd1180 100644 --- a/protos/thread_descriptor.proto +++ b/protos/thread_descriptor.proto @@ -14,13 +14,14 @@ * limitations under the License. */ -// Adapted from https://github.com/google/perfetto/blob/v36.1/protos/perfetto/trace/track_event/thread_descriptor.proto +// Adapted from https://github.com/google/perfetto/blob/v43.2/protos/perfetto/trace/track_event/thread_descriptor.proto +// +// 1. Only the three fields that describes the thread is kept as all other fields are deprecated. syntax = "proto2"; package cactus_tracing.vendor.perfetto.protos; - // Describes a thread's attributes. Emitted as part of a TrackDescriptor, // usually by the thread's trace writer. // diff --git a/protos/trace.proto b/protos/trace.proto index 21070ad..4963b72 100644 --- a/protos/trace.proto +++ b/protos/trace.proto @@ -14,7 +14,9 @@ * limitations under the License. */ -// Adapted from https://github.com/google/perfetto/blob/v36.1/protos/perfetto/trace/trace.proto +// Adapted from https://github.com/google/perfetto/blob/v43.2/protos/perfetto/trace/trace.proto +// +// No changes are made other than the package name. syntax = "proto2"; diff --git a/protos/trace_packet.proto b/protos/trace_packet.proto index 3297ab4..19dee5a 100644 --- a/protos/trace_packet.proto +++ b/protos/trace_packet.proto @@ -14,17 +14,15 @@ * limitations under the License. */ -// Adapter from https://github.com/google/perfetto/blob/v36.1/protos/perfetto/trace/trace_packet.proto +// Adapter from https://github.com/google/perfetto/blob/v43.2/protos/perfetto/trace/trace_packet.proto // -// TODO: consider adding in the following fields; -// -// - sequence_flags, trace_packet_defaults, previous_packet_dropped, first_packet_on_sequence -// - interned_data https://github.com/google/perfetto/issues/526 +// 1. Only the necessary fields are copied. Unnecessary fields are removed. syntax = "proto2"; import "track_event.proto"; import "track_descriptor.proto"; +import "interned_data.proto"; package cactus_tracing.vendor.perfetto.protos; @@ -56,6 +54,7 @@ message TracePacket { // The clock domain definition in ClockSnapshot can also override: // - The unit (default: 1ns). // - The absolute vs delta encoding (default: absolute timestamp). + // INCLUSION REASON: event timestamp optional uint64 timestamp = 8; // Specifies the ID of the clock used for the TracePacket |timestamp|. Can be @@ -63,12 +62,16 @@ message TracePacket { // producer-defined clock id. // If unspecified and if no default per-sequence value has been provided via // TracePacketDefaults, it defaults to BuiltinClocks::BOOTTIME. + // INCLUSION REASON: event timestamp optional uint32 timestamp_clock_id = 58; + // INCLUSION REASON: trace data oneof data { + // INCLUSION REASON: track event is the span information TrackEvent track_event = 11; // Only used by TrackEvent. + // INCLUSION REASON: this describes the track TrackDescriptor track_descriptor = 60; // This field is emitted at periodic intervals (~10s) and @@ -84,7 +87,73 @@ message TracePacket { // Uniquely identifies a producer + writer pair within the tracing session. A // value of zero denotes an invalid ID. Keep in sync with // TrustedPacket.trusted_packet_sequence_id. + // INCLUSION REASON: required field for the sequences oneof optional_trusted_packet_sequence_id { uint32 trusted_packet_sequence_id = 10; } + + // Incrementally emitted interned data, valid only on the packet's sequence + // (packets with the same |trusted_packet_sequence_id|). The writer will + // usually emit new interned data in the same TracePacket that first refers to + // it (since the last reset of interning state). It may also be emitted + // proactively in advance of referring to them in later packets. + // INCLUSION REASON: for interning string and other data. + optional InternedData interned_data = 12; + + enum SequenceFlags { + SEQ_UNSPECIFIED = 0; + + // Set by the writer to indicate that it will re-emit any incremental data + // for the packet's sequence before referring to it again. This includes + // interned data as well as periodically emitted data like + // Process/ThreadDescriptors. This flag only affects the current packet + // sequence (see |trusted_packet_sequence_id|). + // + // When set, this TracePacket and subsequent TracePackets on the same + // sequence will not refer to any incremental data emitted before this + // TracePacket. For example, previously emitted interned data will be + // re-emitted if it is referred to again. + // + // When the reader detects packet loss (|previous_packet_dropped|), it needs + // to skip packets in the sequence until the next one with this flag set, to + // ensure intact incremental data. + SEQ_INCREMENTAL_STATE_CLEARED = 1; + + // This packet requires incremental state, such as TracePacketDefaults or + // InternedData, to be parsed correctly. The trace reader should skip this + // packet if incremental state is not valid on this sequence, i.e. if no + // packet with the SEQ_INCREMENTAL_STATE_CLEARED flag has been seen on the + // current |trusted_packet_sequence_id|. + SEQ_NEEDS_INCREMENTAL_STATE = 2; + }; + // INCLUSION REASON: This is required for interned data. Also the flags are supposed to be binary OR'ed + optional uint32 sequence_flags = 13; + + // Flag set by the service if, for the current packet sequence (see + // |trusted_packet_sequence_id|), either: + // * this is the first packet, or + // * one or multiple packets were dropped since the last packet that the + // consumer read from the sequence. This can happen if chunks in the trace + // buffer are overridden before the consumer could read them when the trace + // is configured in ring buffer mode. + // + // When packet loss occurs, incrementally emitted data (including interned + // data) on the sequence should be considered invalid up until the next packet + // with SEQ_INCREMENTAL_STATE_CLEARED set. + optional bool previous_packet_dropped = 42; + + // Flag set by a producer (starting from SDK v29) if, for the current packet + // sequence (see |trusted_packet_sequence_id|), this is the first packet. + // + // This flag can be used for distinguishing the two situations when + // processing the trace: + // 1. There are no prior events for the sequence because of data loss, e.g. + // due to ring buffer wrapping. + // 2. There are no prior events for the sequence because it didn't start + // before this packet (= there's definitely no preceding data loss). + // + // Given that older SDK versions do not support this flag, this flag not + // being present for a particular sequence does not necessarily imply data + // loss. + optional bool first_packet_on_sequence = 87; } diff --git a/protos/track_descriptor.proto b/protos/track_descriptor.proto index 6b6e71c..027ace3 100644 --- a/protos/track_descriptor.proto +++ b/protos/track_descriptor.proto @@ -14,7 +14,9 @@ * limitations under the License. */ -// Adapted from https://github.com/google/perfetto/blob/v36.1/protos/perfetto/trace/track_event/track_descriptor.proto +// Adapted from https://github.com/google/perfetto/blob/v43.2/protos/perfetto/trace/track_event/track_descriptor.proto +// +// 1. Removed chrome_process and chrome_thread syntax = "proto2"; @@ -82,4 +84,11 @@ message TrackDescriptor { // TYPE_COUNTER TrackEvents (and values provided via TrackEvent's // |extra_counter_values|). optional CounterDescriptor counter = 8; + + // If true, forces Trace Processor to use separate tracks for track events + // and system events for the same thread. + // Track events timestamps in Chrome have microsecond resolution, while + // system events use nanoseconds. It results in broken event nesting when + // track events and system events share a track. + optional bool disallow_merging_with_system_tracks = 9; } diff --git a/protos/track_event.proto b/protos/track_event.proto index f07b128..6e560c1 100644 --- a/protos/track_event.proto +++ b/protos/track_event.proto @@ -14,9 +14,9 @@ * limitations under the License. */ -// Adapted from https://github.com/google/perfetto/blob/v36.1/protos/perfetto/trace/track_event/track_event.proto +// Adapted from https://github.com/google/perfetto/blob/v43.2/protos/perfetto/trace/track_event/track_event.proto // -// TODO: add interned data of EventCategory and EventName +// 1. Only the required fields are imported. Rest are removed. syntax = "proto2"; @@ -86,7 +86,7 @@ package cactus_tracing.vendor.perfetto.protos; // their default track association) can be emitted as part of a // TrackEventDefaults message. // -// Next reserved id: 13 (up to 15). Next id: 50. +// Next reserved id: 13 (up to 15). Next id: 51. message TrackEvent { // Names of categories of the event. In the client library, categories are a // way to turn groups of individual events on or off. @@ -213,3 +213,17 @@ message TrackEvent { uint64 source_location_iid = 34; } } + +// -------------------- +// Interned data types: +// -------------------- + +message EventCategory { + optional uint64 iid = 1; + optional string name = 2; +} + +message EventName { + optional uint64 iid = 1; + optional string name = 2; +} From 28434fe62b2fc3e7dba02f7a3ab59f2ee1fac6ce Mon Sep 17 00:00:00 2001 From: Shuhao Wu Date: Fri, 15 Mar 2024 13:43:44 -0400 Subject: [PATCH 2/6] Updated trace aggregator to emit first packet Packet loss experiment in synthetic event is current not working. --- .clang-format | 2 +- .../synthetic_events.cc | 67 ++++++++++++++++++- include/cactus_rt/tracing/trace_aggregator.h | 25 ++++++- src/cactus_rt/tracing/trace_aggregator.cc | 34 ++++++---- 4 files changed, 110 insertions(+), 18 deletions(-) diff --git a/.clang-format b/.clang-format index 49d114d..98dd12d 100644 --- a/.clang-format +++ b/.clang-format @@ -1,5 +1,6 @@ --- Language: Cpp +Standard: c++17 BasedOnStyle: Google IndentWidth: 2 ColumnLimit: 0 @@ -7,4 +8,3 @@ PointerAlignment: Left AlignConsecutiveDeclarations: true ContinuationIndentWidth: 2 AlignAfterOpenBracket: BlockIndent - diff --git a/examples/tracing_protos_example/synthetic_events.cc b/examples/tracing_protos_example/synthetic_events.cc index e2d22cf..f10ab48 100644 --- a/examples/tracing_protos_example/synthetic_events.cc +++ b/examples/tracing_protos_example/synthetic_events.cc @@ -8,6 +8,7 @@ using cactus_tracing::vendor::perfetto::protos::ProcessDescriptor; using cactus_tracing::vendor::perfetto::protos::ThreadDescriptor; using cactus_tracing::vendor::perfetto::protos::Trace; +using cactus_tracing::vendor::perfetto::protos::TracePacket_SequenceFlags_SEQ_INCREMENTAL_STATE_CLEARED; using cactus_tracing::vendor::perfetto::protos::TrackDescriptor; using cactus_tracing::vendor::perfetto::protos::TrackEvent; using cactus_tracing::vendor::perfetto::protos::TrackEvent_Type_TYPE_INSTANT; @@ -76,6 +77,9 @@ int main() { packet3->set_allocated_track_event(track_event1); packet3->set_trusted_packet_sequence_id(trusted_packet_sequence_id); + packet3->set_previous_packet_dropped(true); + packet3->set_first_packet_on_sequence(true); + packet3->set_sequence_flags(TracePacket_SequenceFlags_SEQ_INCREMENTAL_STATE_CLEARED); Trace trace4; auto* packet4 = trace4.add_packet(); @@ -125,17 +129,76 @@ int main() { // Packets complete, write it into a file! + // Now let's simulate a corruption in the middle of another slide. The idea is: + // 1. There is supposed to be three trace packets between 330 - 430 and 450 - 1000, 1050 - 2000 + // 2. The slice begin at 330 got emitted, the slice end at 430 is lost, the slice begin at 450 is lost. + // 3. We detect packet loss occurred, and hence emit a packet loss marker + // 4. Then we emit the slice end at 1000? Could also try emitting 1050. + Trace trace8; + auto* packet8 = trace8.add_packet(); + packet8->set_timestamp(330); + + auto* track_event8 = new TrackEvent(); + track_event8->set_type(TrackEvent_Type_TYPE_SLICE_BEGIN); + track_event8->set_track_uuid(thread_uuid); + track_event8->set_name("before packet loss"); + packet8->set_allocated_track_event(track_event8); + + packet8->set_trusted_packet_sequence_id(trusted_packet_sequence_id); + + Trace trace10; + auto* packet10 = trace10.add_packet(); + packet10->set_timestamp(1000); + + auto* track_event10 = new TrackEvent(); + track_event10->set_type(TrackEvent_Type_TYPE_SLICE_END); + track_event10->set_track_uuid(thread_uuid); + packet10->set_allocated_track_event(track_event10); + + packet10->set_trusted_packet_sequence_id(trusted_packet_sequence_id); + packet10->set_first_packet_on_sequence(true); + packet10->set_previous_packet_dropped(true); + packet10->set_sequence_flags(TracePacket_SequenceFlags_SEQ_INCREMENTAL_STATE_CLEARED); + + Trace trace11; + auto* packet11 = trace11.add_packet(); + packet11->set_timestamp(1050); + + auto* track_event11 = new TrackEvent(); + track_event11->set_type(TrackEvent_Type_TYPE_SLICE_BEGIN); + track_event11->set_track_uuid(thread_uuid); + track_event11->set_name("After packet loss"); + packet11->set_allocated_track_event(track_event11); + + packet11->set_trusted_packet_sequence_id(trusted_packet_sequence_id); + + Trace trace12; + auto* packet12 = trace12.add_packet(); + packet12->set_timestamp(2000); + + auto* track_event12 = new TrackEvent(); + track_event12->set_type(TrackEvent_Type_TYPE_SLICE_END); + track_event12->set_track_uuid(thread_uuid); + packet12->set_allocated_track_event(track_event12); + + packet12->set_trusted_packet_sequence_id(trusted_packet_sequence_id); + { std::fstream output("build/direct_proto_serialization.perfetto-trace", std::ios::out | std::ios::trunc | std::ios::binary); - const std::array traces{ + const std::array traces{ &trace1, &trace2, &trace3, &trace4, &trace5, &trace6, - &trace7}; + &trace7, + &trace8, + &trace10, + &trace11, + &trace12, + }; for (const auto* trace : traces) { trace->SerializeToOstream(&output); diff --git a/include/cactus_rt/tracing/trace_aggregator.h b/include/cactus_rt/tracing/trace_aggregator.h index 6b0d1b1..0dd47be 100644 --- a/include/cactus_rt/tracing/trace_aggregator.h +++ b/include/cactus_rt/tracing/trace_aggregator.h @@ -12,6 +12,8 @@ #include #include #include +#include +#include #include "sink.h" #include "thread_tracer.h" @@ -20,6 +22,7 @@ namespace cactus_rt::tracing { class TraceAggregator { using Trace = cactus_tracing::vendor::perfetto::protos::Trace; + using InternedData = cactus_tracing::vendor::perfetto::protos::InternedData; std::string process_name_; std::vector cpu_affinity_; @@ -33,14 +36,14 @@ class TraceAggregator { std::mutex mutex_; // A list of sinks the output should be written to. - std::list > sinks_; + std::list> sinks_; // This is a list of all known thread tracers. The background processing // thread will loop through this and pop all data from the queues. // Tracer is a friend class of ThreadTracer and thus can access all private // variables. These two structs are supposed to be tightly coupled so this is // no problem. - std::list > tracers_; + std::list> tracers_; // This is a vector of sticky trace packets that should always be emitted // when a new sink connects to the tracer. When a new sink connects to the @@ -53,6 +56,22 @@ class TraceAggregator { // The list of packets only grow here (although shouldn't grow that much). std::list sticky_trace_packets_; + // This is a map of trusted_sequence_id to InternedData. + // + // The InternedData is allocated directly here and kept for the duration of + // the program. This is necessary in case we detect a packet loss, and we + // would like to re-emit the interned data for that sequence so it can + // continue. + // + // TODO: cap the amount of interned data to a maximum amount. + std::unordered_map> sequence_interned_data_; + + // This is a set of sequence ids where the first packet has already been emitted. + // If a sequence is not in here, the first packet emitted with have + // first_packet_on_sequence = true, previous_packet_dropped = true, and + // sequence_flags = SEQ_INCREMENTAL_STATE_CLEARED + std::unordered_set sequences_with_first_packet_emitted_; + public: explicit TraceAggregator(std::string name, std::vector cpu_affinity = {}); @@ -109,7 +128,7 @@ class TraceAggregator { Trace CreateProcessDescriptorPacket() const; Trace CreateThreadDescriptorPacket(const ThreadTracer& thread_tracer) const; - void AddTrackEventPacketToTrace(Trace& trace, const ThreadTracer& thread_tracer, const TrackEventInternal& track_event_internal) const; + void AddTrackEventPacketToTrace(Trace& trace, const ThreadTracer& thread_tracer, const TrackEventInternal& track_event_internal); }; } // namespace cactus_rt::tracing diff --git a/src/cactus_rt/tracing/trace_aggregator.cc b/src/cactus_rt/tracing/trace_aggregator.cc index cda2d44..883b232 100644 --- a/src/cactus_rt/tracing/trace_aggregator.cc +++ b/src/cactus_rt/tracing/trace_aggregator.cc @@ -11,11 +11,12 @@ #include #include -using Trace = cactus_tracing::vendor::perfetto::protos::Trace; -using TrackDescriptor = cactus_tracing::vendor::perfetto::protos::TrackDescriptor; -using ThreadDescriptor = cactus_tracing::vendor::perfetto::protos::ThreadDescriptor; -using ProcessDescriptor = cactus_tracing::vendor::perfetto::protos::ProcessDescriptor; -using TrackEvent = cactus_tracing::vendor::perfetto::protos::TrackEvent; +using cactus_tracing::vendor::perfetto::protos::ProcessDescriptor; +using cactus_tracing::vendor::perfetto::protos::ThreadDescriptor; +using cactus_tracing::vendor::perfetto::protos::Trace; +using cactus_tracing::vendor::perfetto::protos::TracePacket_SequenceFlags_SEQ_INCREMENTAL_STATE_CLEARED; +using cactus_tracing::vendor::perfetto::protos::TrackDescriptor; +using cactus_tracing::vendor::perfetto::protos::TrackEvent; using namespace std::chrono_literals; @@ -103,12 +104,10 @@ void TraceAggregator::Run() { Trace trace; auto num_events = TryDequeueOnceFromAllTracers(trace); - // TODO: what we should do here is: - // 1. While the dequeue is happening, we should check each tracer for errors/full queue problems. - // 2. Instead of writing the trace directly, we should put it into a bigger - // memory queue (bigger than the tracer queue), which would be written out - // in another thread. That should reduce the bottlenecks for this loop as - // otherwise this loop would be blocked by the writer. + // TODO: Instead of writing the trace directly, we should put it into a + // bigger memory queue (bigger than the tracer queue), which would be + // written out in another thread. That should reduce the bottlenecks for + // this loop as otherwise this loop would be blocked by the writer. if (num_events > 0) { WriteTrace(trace); @@ -182,6 +181,9 @@ size_t TraceAggregator::TryDequeueOnceFromAllTracers(Trace& trace) noexcept { continue; } + // TODO: While the dequeue is happening, we should check each tracer for + // errors/full queue problems. + num_events++; AddTrackEventPacketToTrace(trace, *tracer, event); } @@ -248,7 +250,7 @@ void TraceAggregator::AddTrackEventPacketToTrace( Trace& trace, const ThreadTracer& thread_tracer, const TrackEventInternal& track_event_internal -) const { +) { // NOLINTBEGIN(clang-analyzer-cplusplus.NewDeleteLeaks) auto* packet = trace.add_packet(); packet->set_timestamp(track_event_internal.timestamp); @@ -268,6 +270,14 @@ void TraceAggregator::AddTrackEventPacketToTrace( packet->set_allocated_track_event(track_event); packet->set_trusted_packet_sequence_id(thread_tracer.trusted_packet_sequence_id_); + + if (sequences_with_first_packet_emitted_.count(thread_tracer.trusted_packet_sequence_id_) == 0) { + sequences_with_first_packet_emitted_.insert(thread_tracer.trusted_packet_sequence_id_); + + packet->set_first_packet_on_sequence(true); + packet->set_previous_packet_dropped(true); + packet->set_sequence_flags(TracePacket_SequenceFlags_SEQ_INCREMENTAL_STATE_CLEARED); // TODO: may need to OR this with SEQ_NEEDS_INCREMENTAL_STATE if above needs it. + } // NOLINTEND(clang-analyzer-cplusplus.NewDeleteLeaks) } From 651aa06b476e0b730fad954301249467da6c5442 Mon Sep 17 00:00:00 2001 From: Shuhao Wu Date: Fri, 15 Mar 2024 15:16:49 -0400 Subject: [PATCH 3/6] Added a string interner --- .clang-tidy | 4 +- CMakeLists.txt | 3 +- include/cactus_rt/config.h | 2 +- include/cactus_rt/tracing/trace_aggregator.h | 6 + .../cactus_rt/tracing/utils/string_interner.h | 49 +++++++ src/cactus_rt/cyclic_thread.cc | 2 +- .../tracing/utils/string_interner.cc | 19 +++ tests/CMakeLists.txt | 2 + tests/tracing/string_interner_benchmark.cc | 43 ++++++ tests/tracing/string_interner_test.cc | 123 ++++++++++++++++++ 10 files changed, 249 insertions(+), 4 deletions(-) create mode 100644 include/cactus_rt/tracing/utils/string_interner.h create mode 100644 src/cactus_rt/tracing/utils/string_interner.cc create mode 100644 tests/tracing/string_interner_benchmark.cc create mode 100644 tests/tracing/string_interner_test.cc diff --git a/.clang-tidy b/.clang-tidy index 8fa807d..e3953db 100644 --- a/.clang-tidy +++ b/.clang-tidy @@ -11,6 +11,7 @@ cert-*, -bugprone-implicit-widening-of-multiplication-result, -bugprone-narrowing-conversions, -clang-diagnostic-unused-parameter, +-misc-include-cleaner, -misc-non-private-member-variables-in-classes, -modernize-pass-by-value, -modernize-use-nodiscard, @@ -19,7 +20,8 @@ cert-*, -readability-function-cognitive-complexity, -readability-identifier-length, -readability-isolate-declaration, --readability-magic-numbers' +-readability-magic-numbers, +-readability-redundant-inline-specifier' # TODO: Re-enable bugprone-exception-escape when no longer throwing # https://github.com/isocpp/CppCoreGuidelines/issues/1589 WarningsAsErrors: '*' diff --git a/CMakeLists.txt b/CMakeLists.txt index cdcf6a9..795f9c3 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -135,10 +135,11 @@ target_compile_definitions(cactus_rt PUBLIC QUILL_USE_BOUNDED_QUEUE) if (ENABLE_TRACING) target_sources(cactus_rt PRIVATE - src/cactus_rt/tracing/tracing_enabled.cc src/cactus_rt/tracing/sink.cc src/cactus_rt/tracing/thread_tracer.cc src/cactus_rt/tracing/trace_aggregator.cc + src/cactus_rt/tracing/tracing_enabled.cc + src/cactus_rt/tracing/utils/string_interner.cc ) target_link_libraries(cactus_rt diff --git a/include/cactus_rt/config.h b/include/cactus_rt/config.h index 2739326..075e69e 100644 --- a/include/cactus_rt/config.h +++ b/include/cactus_rt/config.h @@ -105,7 +105,7 @@ struct ThreadTracerConfig { */ struct ThreadConfig { // A vector of CPUs this thread should run on. If empty, no CPU restrictions are set. - std::vector cpu_affinity = {}; + std::vector cpu_affinity; // The size of the stack for this thread. Defaults to 8MB. size_t stack_size = 8 * 1024 * 1024; diff --git a/include/cactus_rt/tracing/trace_aggregator.h b/include/cactus_rt/tracing/trace_aggregator.h index 0dd47be..f173512 100644 --- a/include/cactus_rt/tracing/trace_aggregator.h +++ b/include/cactus_rt/tracing/trace_aggregator.h @@ -17,6 +17,7 @@ #include "sink.h" #include "thread_tracer.h" +#include "utils/string_interner.h" namespace cactus_rt::tracing { @@ -56,6 +57,11 @@ class TraceAggregator { // The list of packets only grow here (although shouldn't grow that much). std::list sticky_trace_packets_; + // These are the interners for the event name and event categories to save + // space on the output. + utils::StringInterner event_name_interner_; + utils::StringInterner event_category_interner_; + // This is a map of trusted_sequence_id to InternedData. // // The InternedData is allocated directly here and kept for the duration of diff --git a/include/cactus_rt/tracing/utils/string_interner.h b/include/cactus_rt/tracing/utils/string_interner.h new file mode 100644 index 0000000..72a90ae --- /dev/null +++ b/include/cactus_rt/tracing/utils/string_interner.h @@ -0,0 +1,49 @@ +#ifndef CACTUS_TRACING_STRING_INTERNER_H_ +#define CACTUS_TRACING_STRING_INTERNER_H_ + +#include +#include +#include +#include +#include + +namespace cactus_rt::tracing::utils { + +/** + * @private + * + * This class interns strings to become ids so the ids can be written to the + * trace file to save space. + * + * It is designed to convert the same string content to uint64_t. A string could + * be a const char*, std::string_view or std::string. If const char* is used, + * the string content is copied and stored in this class the first time to + * ensure it is not deleted during the lifetime of this class. + * + * This class is NOT thread-safe. + * + * TODO: is having a list of strings as references manually necessary? Can we + * not simply have std::string as the map key. When looking up values, does C++ + * convert const char* to string view which has a hash code and thus should find + * the string?... Why is C++ so confusing for simple stuff? It looks like this + * feature only exist in C++20 and above? Heterogenous lookup: + * http://wg21.link/P0919r0. + * + * So for now we are stuck with this. + */ +class StringInterner { + uint64_t current_id_ = 0; + std::unordered_map ids_; + std::list strings_; + + public: + std::pair GetId(const std::string_view& s); + std::pair GetId(const char* s); + + size_t Size() const { + return strings_.size(); + }; +}; +} // namespace cactus_rt::tracing::utils + +#endif diff --git a/src/cactus_rt/cyclic_thread.cc b/src/cactus_rt/cyclic_thread.cc index d560e94..3c0366e 100644 --- a/src/cactus_rt/cyclic_thread.cc +++ b/src/cactus_rt/cyclic_thread.cc @@ -25,7 +25,7 @@ void CyclicThread::Run() noexcept { Tracer().StartSpan("Loop", "cactusrt", loop_start); } - bool should_stop = Loop(loop_start - Thread::StartMonotonicTimeNs()); + const bool should_stop = Loop(loop_start - Thread::StartMonotonicTimeNs()); loop_end = NowNs(); diff --git a/src/cactus_rt/tracing/utils/string_interner.cc b/src/cactus_rt/tracing/utils/string_interner.cc new file mode 100644 index 0000000..7411bf1 --- /dev/null +++ b/src/cactus_rt/tracing/utils/string_interner.cc @@ -0,0 +1,19 @@ +#include "cactus_rt/tracing/utils/string_interner.h" + +namespace cactus_rt::tracing::utils { +std::pair StringInterner::GetId(const std::string_view& s) { + if (auto it = ids_.find(s); it != ids_.end()) { + return std::make_pair(false, it->second); + } + + const auto& copied_str = strings_.emplace_back(s); + const auto id = ++current_id_; + ids_.emplace(copied_str, id); + + return std::make_pair(true, id); +} + +std::pair StringInterner::GetId(const char* s) { + return GetId(std::string_view{s}); +} +} // namespace cactus_rt::tracing::utils diff --git a/tests/CMakeLists.txt b/tests/CMakeLists.txt index 8cfc157..fc47cc9 100644 --- a/tests/CMakeLists.txt +++ b/tests/CMakeLists.txt @@ -21,6 +21,7 @@ if(ENABLE_TRACING) add_executable(cactus_rt_tracing_tests tracing/single_threaded_test.cc + tracing/string_interner_test.cc tracing/multi_threaded_test.cc tracing/helpers/assert_helpers.cc @@ -45,6 +46,7 @@ find_package(benchmark REQUIRED) add_executable(cactus_rt_tracing_benchmark tracing/tracing_benchmark.cc + tracing/string_interner_benchmark.cc ) target_link_libraries(cactus_rt_tracing_benchmark diff --git a/tests/tracing/string_interner_benchmark.cc b/tests/tracing/string_interner_benchmark.cc new file mode 100644 index 0000000..c7c8e98 --- /dev/null +++ b/tests/tracing/string_interner_benchmark.cc @@ -0,0 +1,43 @@ +#include +#include + +namespace { + +using cactus_rt::tracing::utils::StringInterner; + +StringInterner SetupInterner() { + StringInterner interner; + interner.GetId("hello1"); + interner.GetId("hello2"); + interner.GetId("hello3"); + interner.GetId("hello4"); + interner.GetId("hello5"); + interner.GetId("hello6"); + interner.GetId("hello7"); + interner.GetId("hello8"); + interner.GetId("hello9"); + return interner; +} + +void BM_StringInternerConstCharArr(benchmark::State& state) { + auto interner = SetupInterner(); + + for (auto _ : state) { + interner.GetId("hello1"); + } +} +BENCHMARK(BM_StringInternerConstCharArr); + +void BM_StringInternerStdLongString(benchmark::State& state) { + auto interner = SetupInterner(); + std::string s; + for (int i = 0; i < 500; i++) { + s.append("hello "); + } + + for (auto _ : state) { + interner.GetId(s); + } +} +BENCHMARK(BM_StringInternerStdLongString); +} // namespace diff --git a/tests/tracing/string_interner_test.cc b/tests/tracing/string_interner_test.cc new file mode 100644 index 0000000..1be87fd --- /dev/null +++ b/tests/tracing/string_interner_test.cc @@ -0,0 +1,123 @@ +#include "cactus_rt/tracing/utils/string_interner.h" + +#include + +#include +#include +#include + +using cactus_rt::tracing::utils::StringInterner; + +namespace cactus_rt::tracing::utils { + +TEST(StringInternerTest, BasicAssertions) { + StringInterner interner; + + const char* const_char_arr = "hello"; + char char_arr[sizeof(const_char_arr)]; // NOLINT(modernize-avoid-c-arrays,bugprone-sizeof-expression) + strncpy(char_arr, const_char_arr, sizeof(char_arr)); + + const std::string_view sv{const_char_arr}; + const std::string str{const_char_arr}; + + const auto [new1, id1] = interner.GetId("hello"); + const auto [new2, id2] = interner.GetId(const_char_arr); + const auto [new3, id3] = interner.GetId(char_arr); + const auto [new4, id4] = interner.GetId(sv); + const auto [new5, id5] = interner.GetId(str); + + EXPECT_NE(const_char_arr, char_arr); // Just a sanity check... + + // Everything should have the same id + EXPECT_EQ(id1, id2); + EXPECT_EQ(id1, id3); + EXPECT_EQ(id1, id4); + EXPECT_EQ(id1, id5); + + // Only one of them should be inserting. + EXPECT_TRUE(new1); + EXPECT_FALSE(new2); + EXPECT_FALSE(new3); + EXPECT_FALSE(new4); + EXPECT_FALSE(new5); + + // We expect the size of the strings memoized to be 1. + EXPECT_EQ(interner.Size(), 1); +} + +TEST(StringInternerTest, ManyStrings) { + StringInterner interner; + + const auto [new1, id1] = interner.GetId("hello1"); + const auto [new2, id2] = interner.GetId("hello2"); + const auto [new3, id3] = interner.GetId("hello3"); + const auto [new4, id4] = interner.GetId("hello4"); + const auto [new5, id5] = interner.GetId("hello5"); + const auto [new6, id6] = interner.GetId("hello6"); + const auto [new7, id7] = interner.GetId("hello7"); + const auto [new8, id8] = interner.GetId("hello8"); + const auto [new9, id9] = interner.GetId("hello9"); + + const std::unordered_set s{id1, id2, id3, id4, id5, id6, id7, id8, id9}; + + EXPECT_EQ(s.size(), 9); + EXPECT_EQ(interner.Size(), 9); + + for (const auto id : s) { + EXPECT_NE(id, 0); + } + + EXPECT_TRUE(new1); + EXPECT_TRUE(new2); + EXPECT_TRUE(new3); + EXPECT_TRUE(new4); + EXPECT_TRUE(new5); + EXPECT_TRUE(new6); + EXPECT_TRUE(new7); + EXPECT_TRUE(new8); + EXPECT_TRUE(new9); + + const std::string str{"hello1"}; + const auto [new10, id10] = interner.GetId(str.data()); + EXPECT_EQ(id1, id10); + EXPECT_FALSE(new10); + EXPECT_EQ(interner.Size(), 9); +} + +TEST(StringInternerTest, OutOfScope) { + StringInterner interner; + + uint64_t id1 = 0; + bool new1 = false; + uint64_t id2 = 0; + bool new2 = true; // intentionally wrong answer to ensure the expect is working + + { + std::string s{"hello1"}; + const auto [n, i] = interner.GetId(s.data()); + new1 = n; + id1 = i; + s.replace(1, 1, "g"); + } + + { + char c[8]; // NOLINT(modernize-avoid-c-arrays) + strncpy(c, "hello1", sizeof(c)); + const auto [n, i] = interner.GetId(c); + new2 = n; + id2 = i; + c[1] = 'g'; + } + + const auto [new3, id3] = interner.GetId("hello1"); + EXPECT_EQ(id1, id2); + EXPECT_EQ(id1, id3); + + EXPECT_TRUE(new1); + EXPECT_FALSE(new2); + EXPECT_FALSE(new3); + + EXPECT_EQ(interner.Size(), 1); +} + +} // namespace cactus_rt::tracing::utils From 42c7722cfe0d23119da0638e5c7be948d6b06227 Mon Sep 17 00:00:00 2001 From: Shuhao Wu Date: Sun, 17 Mar 2024 16:17:35 -0400 Subject: [PATCH 4/6] Some notes on perfetto's behavior upstream --- docs/tracing.md | 50 ++++++++++++- .../synthetic_events.cc | 72 ++++++------------- 2 files changed, 72 insertions(+), 50 deletions(-) diff --git a/docs/tracing.md b/docs/tracing.md index 45bc668..78f55a6 100644 --- a/docs/tracing.md +++ b/docs/tracing.md @@ -237,7 +237,55 @@ TODO... #### Too much data causing buffer overflow and trace data drops -See https://github.com/google/perfetto/issues/575#issuecomment-1699253191 +#### String interning + +Perfetto allows event names and event categories to be interned by assigning +each unique string with an id and emitting the id rather than the string to save +space in the output trace files. This feature is implemented via the +`interned_data`, `name_iid`, and `category_iids` fields. A few details worth +noting: + +1. Perfetto uses `trusted_packet_sequence_id` to identify a single sequence. A + single sequence must have monotonically increasing timestamps for its + packets. Both Perfetto upstream and cactus-rt's implementation of the tracer + gives a sequence id per thread. In cactus-rt, this is especially important + as when we pop the data from the queue originating from multiple threads. +2. The `iid`s on their own are not sufficient to identify the string being + interned as it is not "globally" unique. It is only unique per sequence + (i.e. thus `(trusted_packet_sequence_id, iid)` is sufficient to identify an + interned string). This, along with (1), implies we have to intern strings on + a per-thread interner. + +### Other notes + +#### Perfetto SDK (upstream) can grab a lock when buffer is full + +- It seems that trace events are emitted via the `TRACE_EVENT` macro, which starts [here with `TRACE_EVENT_BEGIN`](https://github.com/google/perfetto/blob/v43.2/include/perfetto/tracing/track_event.h#L354). +- This then calls [`PERFETTO_INTERNAL_TRACK_EVENT_WITH_METHOD`](https://github.com/google/perfetto/blob/v43.2/include/perfetto/tracing/internal/track_event_macros.h#L115). + - This also calls `perfetto_track_event::internal::isDynamicCategory` +- This calls [`perfetto_track_event::TrackEvent::TraceForCategory`](https://github.com/google/perfetto/blob/v43.2/include/perfetto/tracing/internal/track_event_data_source.h#L376), which eventually calls: + - [`WriteTrackEventImpl`](https://github.com/google/perfetto/blob/v43.2/include/perfetto/tracing/internal/track_event_data_source.h#L874) which creates the protobuf packet via protozero. + - This [calls](https://github.com/google/perfetto/blob/v43.2/include/perfetto/tracing/internal/track_event_data_source.h#L901) [`TrackEventInternal::WriteEvent`](https://github.com/google/perfetto/blob/v43.2/src/tracing/internal/track_event_internal.cc#L528) + - which [calls](https://github.com/google/perfetto/blob/v43.2/src/tracing/internal/track_event_internal.cc#L537) [`NewTracePacket`](https://github.com/google/perfetto/blob/v43.2/src/tracing/internal/track_event_internal.cc#L470) + - which [calls](https://github.com/google/perfetto/blob/v43.2/src/tracing/internal/track_event_internal.cc#L479) [`TraceWriterBase::NewTracePacket`](https://github.com/google/perfetto/blob/v43.2/include/perfetto/tracing/trace_writer_base.h#L41-L61), **which might be [`TraceWriterImpl::NewTracePacket`](https://github.com/google/perfetto/blob/v43.2/src/tracing/core/trace_writer_impl.cc#L119).** + +From the other side: + +- `SharedMemoryArbiterImpl::GetNewChunk` grabs [a lock](https://github.com/google/perfetto/blob/v43.2/src/tracing/core/shared_memory_arbiter_impl.cc#L106-L110) + - [called from](https://github.com/google/perfetto/blob/v43.2/src/tracing/core/trace_writer_impl.cc#L242) `TraceWriterImpl::GetNewBuffer`. + - **This is called from [`TraceWriterImpl::NewTracePacket`](https://github.com/google/perfetto/blob/v43.2/src/tracing/core/trace_writer_impl.cc#L151).** This is called if the chunk is too full for the data. + +This means that there is a small chance that a lock can be taken, and an even smaller chance that a priority inversion could take place. This means it is not suitable for hard real-time applications and a custom tracing library must be written. + +#### Perfetto SDK string interning + +- `WriteTrackEventImpl` [calls](https://github.com/google/perfetto/blob/v43.2/include/perfetto/tracing/internal/track_event_data_source.h#L907) `TrackEventInternal::WriteEventName` which calls [`InternedEventName::Get`](https://github.com/google/perfetto/blob/v43.2/src/tracing/internal/track_event_internal.cc#L506), and which is implemented in [here](https://github.com/google/perfetto/blob/v43.2/include/perfetto/tracing/track_event_interned_data_index.h#L183). + - In here there's memory allocation due to [`LookupAndInsert`](https://github.com/google/perfetto/blob/v43.2/include/perfetto/tracing/track_event_interned_data_index.h#L99-L144) (called from [here](https://github.com/google/perfetto/blob/v43.2/include/perfetto/tracing/track_event_interned_data_index.h#L189)) using a `std::map`. + - Also `GetOrCreateIndex` [calls `new`](https://github.com/google/perfetto/blob/v43.2/include/perfetto/tracing/track_event_interned_data_index.h#L243). Likely this means another allocation potential on the hot path. + +This means Perfetto uses memory allocation on the hot path, which is not acceptable for cactus-rt due to real-time constraints. + +#### Perfetto SDK data dropping counter Advanced tuning and use cases ----------------------------- diff --git a/examples/tracing_protos_example/synthetic_events.cc b/examples/tracing_protos_example/synthetic_events.cc index f10ab48..7227b09 100644 --- a/examples/tracing_protos_example/synthetic_events.cc +++ b/examples/tracing_protos_example/synthetic_events.cc @@ -5,10 +5,12 @@ #include "trace.pb.h" +using cactus_tracing::vendor::perfetto::protos::InternedData; using cactus_tracing::vendor::perfetto::protos::ProcessDescriptor; using cactus_tracing::vendor::perfetto::protos::ThreadDescriptor; using cactus_tracing::vendor::perfetto::protos::Trace; using cactus_tracing::vendor::perfetto::protos::TracePacket_SequenceFlags_SEQ_INCREMENTAL_STATE_CLEARED; +using cactus_tracing::vendor::perfetto::protos::TracePacket_SequenceFlags_SEQ_NEEDS_INCREMENTAL_STATE; using cactus_tracing::vendor::perfetto::protos::TrackDescriptor; using cactus_tracing::vendor::perfetto::protos::TrackEvent; using cactus_tracing::vendor::perfetto::protos::TrackEvent_Type_TYPE_INSTANT; @@ -70,16 +72,22 @@ int main() { auto* packet3 = trace3.add_packet(); packet3->set_timestamp(200); + auto* interned_data1 = new InternedData(); + auto* event_name = interned_data1->add_event_names(); + event_name->set_iid(1); + event_name->set_name("My special parent"); + packet3->set_allocated_interned_data(interned_data1); + auto* track_event1 = new TrackEvent(); track_event1->set_type(TrackEvent_Type_TYPE_SLICE_BEGIN); track_event1->set_track_uuid(thread_uuid); - track_event1->set_name("My special parent"); + track_event1->set_name_iid(1); packet3->set_allocated_track_event(track_event1); packet3->set_trusted_packet_sequence_id(trusted_packet_sequence_id); packet3->set_previous_packet_dropped(true); packet3->set_first_packet_on_sequence(true); - packet3->set_sequence_flags(TracePacket_SequenceFlags_SEQ_INCREMENTAL_STATE_CLEARED); + packet3->set_sequence_flags(TracePacket_SequenceFlags_SEQ_INCREMENTAL_STATE_CLEARED | TracePacket_SequenceFlags_SEQ_NEEDS_INCREMENTAL_STATE); Trace trace4; auto* packet4 = trace4.add_packet(); @@ -127,66 +135,34 @@ int main() { packet7->set_trusted_packet_sequence_id(trusted_packet_sequence_id); - // Packets complete, write it into a file! - - // Now let's simulate a corruption in the middle of another slide. The idea is: - // 1. There is supposed to be three trace packets between 330 - 430 and 450 - 1000, 1050 - 2000 - // 2. The slice begin at 330 got emitted, the slice end at 430 is lost, the slice begin at 450 is lost. - // 3. We detect packet loss occurred, and hence emit a packet loss marker - // 4. Then we emit the slice end at 1000? Could also try emitting 1050. Trace trace8; auto* packet8 = trace8.add_packet(); - packet8->set_timestamp(330); + packet8->set_timestamp(350); auto* track_event8 = new TrackEvent(); track_event8->set_type(TrackEvent_Type_TYPE_SLICE_BEGIN); track_event8->set_track_uuid(thread_uuid); - track_event8->set_name("before packet loss"); + track_event8->set_name_iid(1); packet8->set_allocated_track_event(track_event8); + packet8->set_sequence_flags(TracePacket_SequenceFlags_SEQ_NEEDS_INCREMENTAL_STATE); packet8->set_trusted_packet_sequence_id(trusted_packet_sequence_id); - Trace trace10; - auto* packet10 = trace10.add_packet(); - packet10->set_timestamp(1000); - - auto* track_event10 = new TrackEvent(); - track_event10->set_type(TrackEvent_Type_TYPE_SLICE_END); - track_event10->set_track_uuid(thread_uuid); - packet10->set_allocated_track_event(track_event10); - - packet10->set_trusted_packet_sequence_id(trusted_packet_sequence_id); - packet10->set_first_packet_on_sequence(true); - packet10->set_previous_packet_dropped(true); - packet10->set_sequence_flags(TracePacket_SequenceFlags_SEQ_INCREMENTAL_STATE_CLEARED); - - Trace trace11; - auto* packet11 = trace11.add_packet(); - packet11->set_timestamp(1050); - - auto* track_event11 = new TrackEvent(); - track_event11->set_type(TrackEvent_Type_TYPE_SLICE_BEGIN); - track_event11->set_track_uuid(thread_uuid); - track_event11->set_name("After packet loss"); - packet11->set_allocated_track_event(track_event11); - - packet11->set_trusted_packet_sequence_id(trusted_packet_sequence_id); - - Trace trace12; - auto* packet12 = trace12.add_packet(); - packet12->set_timestamp(2000); + Trace trace9; + auto* packet9 = trace9.add_packet(); + packet9->set_timestamp(500); - auto* track_event12 = new TrackEvent(); - track_event12->set_type(TrackEvent_Type_TYPE_SLICE_END); - track_event12->set_track_uuid(thread_uuid); - packet12->set_allocated_track_event(track_event12); + auto* track_event9 = new TrackEvent(); + track_event9->set_type(TrackEvent_Type_TYPE_SLICE_END); + track_event9->set_track_uuid(thread_uuid); + packet9->set_allocated_track_event(track_event9); - packet12->set_trusted_packet_sequence_id(trusted_packet_sequence_id); + packet9->set_trusted_packet_sequence_id(trusted_packet_sequence_id); { std::fstream output("build/direct_proto_serialization.perfetto-trace", std::ios::out | std::ios::trunc | std::ios::binary); - const std::array traces{ + const std::array traces{ &trace1, &trace2, &trace3, @@ -195,9 +171,7 @@ int main() { &trace6, &trace7, &trace8, - &trace10, - &trace11, - &trace12, + &trace9, }; for (const auto* trace : traces) { From 44ca43b49ecf07e645bdfcbc0b9b9fe3a53c7499 Mon Sep 17 00:00:00 2001 From: Shuhao Wu Date: Sun, 17 Mar 2024 17:38:03 -0400 Subject: [PATCH 5/6] String interning for tracing --- examples/tracing_example/main.cc | 52 +++-- include/cactus_rt/app.h | 11 +- include/cactus_rt/tracing/thread_tracer.h | 8 + include/cactus_rt/tracing/trace_aggregator.h | 28 ++- .../cactus_rt/tracing/utils/string_interner.h | 4 + src/cactus_rt/app.cc | 31 +-- src/cactus_rt/tracing/trace_aggregator.cc | 139 ++++++++++++- tests/CMakeLists.txt | 8 +- tests/tracing/helpers/assert_helpers.cc | 84 +++++--- tests/tracing/helpers/assert_helpers.h | 16 +- tests/tracing/multi_threaded_test.cc | 108 ++++++++++- tests/tracing/single_threaded_test.cc | 182 +++++++++++++++--- tests/tracing/string_interner_benchmark.cc | 4 +- tests/tracing/string_interner_test.cc | 2 - 14 files changed, 575 insertions(+), 102 deletions(-) diff --git a/examples/tracing_example/main.cc b/examples/tracing_example/main.cc index c92667e..1d8e0d7 100644 --- a/examples/tracing_example/main.cc +++ b/examples/tracing_example/main.cc @@ -16,8 +16,19 @@ void WasteTime(std::chrono::microseconds duration) { class ExampleRTThread : public CyclicThread { int64_t loop_counter_ = 0; + static cactus_rt::CyclicThreadConfig CreateThreadConfig() { + cactus_rt::CyclicThreadConfig thread_config; + thread_config.period_ns = 1'000'000; + thread_config.cpu_affinity = std::vector{2}; + thread_config.SetFifoScheduler(80); + + // thread_config.tracer_config.trace_sleep = true; + thread_config.tracer_config.trace_wakeup_latency = true; + return thread_config; + } + public: - ExampleRTThread(const char* name, cactus_rt::CyclicThreadConfig config) : CyclicThread(name, config) {} + ExampleRTThread() : CyclicThread("ExampleRTThread", CreateThreadConfig()) {} int64_t GetLoopCounter() const { return loop_counter_; @@ -60,21 +71,38 @@ class ExampleRTThread : public CyclicThread { } }; -int main() { - cactus_rt::CyclicThreadConfig thread_config; - thread_config.period_ns = 1'000'000; - thread_config.cpu_affinity = std::vector{2}; - thread_config.SetFifoScheduler(80); +class SecondRTThread : public CyclicThread { + static cactus_rt::CyclicThreadConfig CreateThreadConfig() { + cactus_rt::CyclicThreadConfig thread_config; + thread_config.period_ns = 3'000'000; + thread_config.cpu_affinity = {1}; + thread_config.SetFifoScheduler(60); - // thread_config.tracer_config.trace_sleep = true; - thread_config.tracer_config.trace_wakeup_latency = true; + // thread_config.tracer_config.trace_sleep = true; + thread_config.tracer_config.trace_wakeup_latency = true; + return thread_config; + } + public: + SecondRTThread() : CyclicThread("SecondRTThread", CreateThreadConfig()) {} + + protected: + bool Loop(int64_t /*now*/) noexcept final { + const auto span = Tracer().WithSpan("Sense"); + WasteTime(std::chrono::microseconds(2000)); + return false; + } +}; + +int main() { cactus_rt::AppConfig app_config; - app_config.tracer_config.trace_aggregator_cpu_affinity = {1}; + app_config.tracer_config.trace_aggregator_cpu_affinity = {0}; // doesn't work yet - auto thread = std::make_shared("ExampleRTThread", thread_config); + auto thread1 = std::make_shared(); + auto thread2 = std::make_shared(); App app("TracingExampleApp", app_config); - app.RegisterThread(thread); + app.RegisterThread(thread1); + app.RegisterThread(thread2); std::cout << "Testing RT loop for 15 seconds with two trace sessions.\n"; @@ -97,6 +125,6 @@ int main() { app.Join(); // Don't need to stop the trace session as the app destructor will take care of it. - std::cout << "Number of loops executed: " << thread->GetLoopCounter() << "\n"; + std::cout << "Number of loops executed: " << thread1->GetLoopCounter() << "\n"; return 0; } diff --git a/include/cactus_rt/app.h b/include/cactus_rt/app.h index 5aedf7a..5b47f4b 100644 --- a/include/cactus_rt/app.h +++ b/include/cactus_rt/app.h @@ -43,7 +43,7 @@ class App { // TODO: investigate into a weak pointer. std::list> thread_tracers_; std::unique_ptr trace_aggregator_ = nullptr; - std::mutex tracer_mutex_; + std::mutex aggregator_mutex_; void SetDefaultLogFormat(quill::Config& cfg) { // Create a handler of stdout @@ -113,15 +113,14 @@ class App { /** * @brief Starts a new tracing session for the process. Will not start a new * tracing session if an existing tracing session is in progress. This - * function is not real-time safe. This will not register any output sinks. - * Use App::RegisterTraceSink() to register custom sinks. + * function is not real-time safe. */ - bool StartTraceSession() noexcept; + bool StartTraceSession(std::shared_ptr sink) noexcept; /** * @brief Register a custom trace sink after starting the trace session */ - void RegisterTraceSink(std::shared_ptr sink) noexcept; + void RegisterTraceSink(std::shared_ptr sink) noexcept; /** * @brief Stops the tracing session for the process. Will be no-op if tracing @@ -159,7 +158,7 @@ class App { */ void DeregisterThreadTracer(const std::shared_ptr& thread_tracer) noexcept; - void CreateAndStartTraceAggregator() noexcept; + void CreateAndStartTraceAggregator(std::shared_ptr sink) noexcept; void StopTraceAggregator() noexcept; }; diff --git a/include/cactus_rt/tracing/thread_tracer.h b/include/cactus_rt/tracing/thread_tracer.h index b0a6353..c5e3615 100644 --- a/include/cactus_rt/tracing/thread_tracer.h +++ b/include/cactus_rt/tracing/thread_tracer.h @@ -12,6 +12,7 @@ #include "../experimental/lockless/atomic_message.h" #include "track_event_internal.h" +#include "utils/string_interner.h" namespace cactus_rt::tracing { struct EventCountData { @@ -35,6 +36,13 @@ class ThreadTracer { moodycamel::ReaderWriterQueue queue_; + // The event name interning must be done per thread (per sequence). Thus it is + // stored here. However, this class must NEVER call functions here (other + // than maybe .Size), as the memory allocation can occur. This variable is + // designed to be used by TraceAggregator on the non-real-time path. + utils::StringInterner event_name_interner_; + utils::StringInterner event_category_interner_; + std::string name_; uint64_t track_uuid_; diff --git a/include/cactus_rt/tracing/trace_aggregator.h b/include/cactus_rt/tracing/trace_aggregator.h index f173512..4e18dcb 100644 --- a/include/cactus_rt/tracing/trace_aggregator.h +++ b/include/cactus_rt/tracing/trace_aggregator.h @@ -132,9 +132,35 @@ class TraceAggregator { size_t TryDequeueOnceFromAllTracers(Trace& trace) noexcept; void WriteTrace(const Trace& trace) noexcept; + /** + * Creates the initial process descriptor packet + */ Trace CreateProcessDescriptorPacket() const; + + /** + * Creates a thread descriptor packet given a thread tracer. + * + * Must be called while a lock is held. + */ Trace CreateThreadDescriptorPacket(const ThreadTracer& thread_tracer) const; - void AddTrackEventPacketToTrace(Trace& trace, const ThreadTracer& thread_tracer, const TrackEventInternal& track_event_internal); + + /** + * Adds the track event packet to an existing trace. + * + * Must be called while a lock is held. + */ + void AddTrackEventPacketToTrace(Trace& trace, ThreadTracer& thread_tracer, const TrackEventInternal& track_event_internal); + + /** + * Create the initial interned data packet if a new sink joins. + * + * Must be called while a lock is held. + * + * @param initial_timestamp The initial timestamp of the track, must be before + * all other packets about to be written. Commonly this should be the + * timestamp of the sticky packets. + */ + std::optional CreateInitialInternedDataPacket() const; }; } // namespace cactus_rt::tracing diff --git a/include/cactus_rt/tracing/utils/string_interner.h b/include/cactus_rt/tracing/utils/string_interner.h index 72a90ae..fdce576 100644 --- a/include/cactus_rt/tracing/utils/string_interner.h +++ b/include/cactus_rt/tracing/utils/string_interner.h @@ -43,6 +43,10 @@ class StringInterner { size_t Size() const { return strings_.size(); }; + + const std::unordered_map& Ids() const { + return ids_; + } }; } // namespace cactus_rt::tracing::utils diff --git a/src/cactus_rt/app.cc b/src/cactus_rt/app.cc index cb9d914..794630e 100644 --- a/src/cactus_rt/app.cc +++ b/src/cactus_rt/app.cc @@ -65,30 +65,29 @@ bool App::StartTraceSession(const char* output_filename) noexcept { return false; } - CreateAndStartTraceAggregator(); - trace_aggregator_->RegisterSink(std::make_unique(output_filename)); + CreateAndStartTraceAggregator(std::make_shared(output_filename)); cactus_rt::tracing::EnableTracing(); return true; } -bool App::StartTraceSession() noexcept { +bool App::StartTraceSession(std::shared_ptr sink) noexcept { if (cactus_rt::tracing::IsTracingEnabled()) { return false; } - CreateAndStartTraceAggregator(); + CreateAndStartTraceAggregator(sink); cactus_rt::tracing::EnableTracing(); return true; } -void App::RegisterTraceSink(std::shared_ptr sink) noexcept { - if (trace_aggregator_ == nullptr) { - return; - } +void App::RegisterTraceSink(std::shared_ptr sink) noexcept { + const std::scoped_lock lock(aggregator_mutex_); - trace_aggregator_->RegisterSink(sink); + if (trace_aggregator_ != nullptr) { + trace_aggregator_->RegisterSink(sink); + } } bool App::StopTraceSession() noexcept { @@ -103,7 +102,7 @@ bool App::StopTraceSession() noexcept { } void App::RegisterThreadTracer(std::shared_ptr thread_tracer) noexcept { - const std::scoped_lock lock(tracer_mutex_); + const std::scoped_lock lock(aggregator_mutex_); thread_tracers_.push_back(thread_tracer); @@ -113,7 +112,7 @@ void App::RegisterThreadTracer(std::shared_ptr thread_tra } void App::DeregisterThreadTracer(const std::shared_ptr& thread_tracer) noexcept { - const std::scoped_lock lock(tracer_mutex_); + const std::scoped_lock lock(aggregator_mutex_); thread_tracers_.remove_if([thread_tracer](const std::shared_ptr& t) { return t == thread_tracer; @@ -190,8 +189,8 @@ void App::StartQuill() { quill::start(); } -void App::CreateAndStartTraceAggregator() noexcept { - const std::scoped_lock lock(tracer_mutex_); +void App::CreateAndStartTraceAggregator(std::shared_ptr sink) noexcept { + const std::scoped_lock lock(aggregator_mutex_); if (trace_aggregator_ != nullptr) { // TODO: error here @@ -203,11 +202,15 @@ void App::CreateAndStartTraceAggregator() noexcept { trace_aggregator_->RegisterThreadTracer(tracer); } + if (sink != nullptr) { + trace_aggregator_->RegisterSink(sink); + } + trace_aggregator_->Start(); } void App::StopTraceAggregator() noexcept { - const std::scoped_lock lock(tracer_mutex_); + const std::scoped_lock lock(aggregator_mutex_); if (trace_aggregator_ == nullptr) { // TODO: error here diff --git a/src/cactus_rt/tracing/trace_aggregator.cc b/src/cactus_rt/tracing/trace_aggregator.cc index 883b232..28c9d54 100644 --- a/src/cactus_rt/tracing/trace_aggregator.cc +++ b/src/cactus_rt/tracing/trace_aggregator.cc @@ -14,12 +14,18 @@ using cactus_tracing::vendor::perfetto::protos::ProcessDescriptor; using cactus_tracing::vendor::perfetto::protos::ThreadDescriptor; using cactus_tracing::vendor::perfetto::protos::Trace; +using cactus_tracing::vendor::perfetto::protos::TracePacket; using cactus_tracing::vendor::perfetto::protos::TracePacket_SequenceFlags_SEQ_INCREMENTAL_STATE_CLEARED; +using cactus_tracing::vendor::perfetto::protos::TracePacket_SequenceFlags_SEQ_NEEDS_INCREMENTAL_STATE; using cactus_tracing::vendor::perfetto::protos::TrackDescriptor; using cactus_tracing::vendor::perfetto::protos::TrackEvent; using namespace std::chrono_literals; +namespace { +constexpr size_t kMaxInternedStrings = 10000; +} + namespace cactus_rt::tracing { TraceAggregator::TraceAggregator(std::string process_name, std::vector cpu_affinity) : process_name_(process_name), @@ -41,6 +47,12 @@ void TraceAggregator::RegisterSink(std::shared_ptr sink) { sink->Write(trace); } + auto interned_data_trace = CreateInitialInternedDataPacket(); + if (interned_data_trace) { + // TODO: deal with errors + sink->Write(*interned_data_trace); + } + sinks_.push_back(sink); } @@ -248,37 +260,154 @@ Trace TraceAggregator::CreateThreadDescriptorPacket(const ThreadTracer& thread_t void TraceAggregator::AddTrackEventPacketToTrace( Trace& trace, - const ThreadTracer& thread_tracer, + ThreadTracer& thread_tracer, const TrackEventInternal& track_event_internal ) { // NOLINTBEGIN(clang-analyzer-cplusplus.NewDeleteLeaks) + uint32_t sequence_flags = 0; + InternedData* interned_data = nullptr; + + // Create trace packet auto* packet = trace.add_packet(); packet->set_timestamp(track_event_internal.timestamp); + // Create track event auto* track_event = new TrackEvent(); track_event->set_track_uuid(thread_tracer.track_uuid_); track_event->set_type(track_event_internal.type); + // Deal with the event name if (track_event_internal.name != nullptr) { - track_event->set_name(track_event_internal.name); + if (thread_tracer.event_name_interner_.Size() < kMaxInternedStrings) { + auto [new_event_name, event_name_iid] = thread_tracer.event_name_interner_.GetId(track_event_internal.name); + + // If this is a never-seen-before event name, we need to emit the interned data into the data stream. + if (new_event_name) { + if (interned_data == nullptr) { + interned_data = new InternedData(); + } + + auto* event_name = interned_data->add_event_names(); + event_name->set_iid(event_name_iid); + event_name->set_name(track_event_internal.name); + } + + // Finally set the name_iid + track_event->set_name_iid(event_name_iid); + sequence_flags |= TracePacket_SequenceFlags_SEQ_NEEDS_INCREMENTAL_STATE; + } else { + LOG_WARNING_LIMIT( + std::chrono::milliseconds(5000), + Logger(), + "number of unique event names emitted in tracing is exceeding {} for thread {}, string interning is disabled. trace files may be excessively large", + kMaxInternedStrings, + thread_tracer.name_ + ); + track_event->set_name(track_event_internal.name); + } } - + // Deal with the event category. Code is slightly duplicated, which is fine + // for readability as we only have name and category to intern. // TODO: support multiple categories later? if (track_event_internal.category != nullptr) { - track_event->add_categories(track_event_internal.category); + if (thread_tracer.event_category_interner_.Size() < kMaxInternedStrings) { + auto [new_category, category_iid] = thread_tracer.event_category_interner_.GetId(track_event_internal.category); + + // If this is a never-seen-before event category, we need to emit the interned data into the data stream. + if (new_category) { + if (interned_data == nullptr) { + interned_data = new InternedData(); + } + + auto* category = interned_data->add_event_categories(); + category->set_iid(category_iid); + category->set_name(track_event_internal.category); + } + + // Finally set the category + track_event->add_category_iids(category_iid); + sequence_flags |= TracePacket_SequenceFlags_SEQ_NEEDS_INCREMENTAL_STATE; + } else { + LOG_WARNING_LIMIT( + std::chrono::milliseconds(5000), + Logger(), + "number of unique event category emitted in tracing is exceeding {} for thread {}, string interning is disabled. trace files may be excessively large", + kMaxInternedStrings, + thread_tracer.name_ + ); + track_event->add_categories(track_event_internal.category); + } } + // Set the track event into the packet and setup packet sequence id packet->set_allocated_track_event(track_event); packet->set_trusted_packet_sequence_id(thread_tracer.trusted_packet_sequence_id_); + // Deal with "first packet" if (sequences_with_first_packet_emitted_.count(thread_tracer.trusted_packet_sequence_id_) == 0) { sequences_with_first_packet_emitted_.insert(thread_tracer.trusted_packet_sequence_id_); packet->set_first_packet_on_sequence(true); packet->set_previous_packet_dropped(true); - packet->set_sequence_flags(TracePacket_SequenceFlags_SEQ_INCREMENTAL_STATE_CLEARED); // TODO: may need to OR this with SEQ_NEEDS_INCREMENTAL_STATE if above needs it. + sequence_flags |= TracePacket_SequenceFlags_SEQ_INCREMENTAL_STATE_CLEARED; + } + + // If interned data exists, add it to the packet + if (interned_data != nullptr) { + packet->set_allocated_interned_data(interned_data); + } + + // Write the sequence flag is needed + if (sequence_flags != 0) { + packet->set_sequence_flags(sequence_flags); } // NOLINTEND(clang-analyzer-cplusplus.NewDeleteLeaks) } +std::optional TraceAggregator::CreateInitialInternedDataPacket() const { + Trace trace; + + bool wrote_interned_data = false; + + for (const auto& tracer : this->tracers_) { + InternedData* interned_data = nullptr; + for (const auto& [name, name_iid] : tracer->event_name_interner_.Ids()) { + if (interned_data == nullptr) { + interned_data = new InternedData(); + } + + auto* event_name = interned_data->add_event_names(); + event_name->set_name(name.data()); + event_name->set_iid(name_iid); + } + + for (const auto& [category, category_iid] : tracer->event_category_interner_.Ids()) { + if (interned_data == nullptr) { + interned_data = new InternedData(); + } + + auto* event_category = interned_data->add_event_categories(); + event_category->set_name(category.data()); + event_category->set_iid(category_iid); + } + + if (interned_data != nullptr) { + wrote_interned_data = true; + TracePacket* packet = trace.add_packet(); + + // TODO: is it okay to not have a timestamp? + // packet->set_timestamp(initial_timestamp); + + packet->set_allocated_interned_data(interned_data); + packet->set_trusted_packet_sequence_id(tracer->trusted_packet_sequence_id_); + } + } + + if (wrote_interned_data) { + return trace; + } + + return std::nullopt; +} + } // namespace cactus_rt::tracing diff --git a/tests/CMakeLists.txt b/tests/CMakeLists.txt index fc47cc9..3bc16dc 100644 --- a/tests/CMakeLists.txt +++ b/tests/CMakeLists.txt @@ -46,9 +46,15 @@ find_package(benchmark REQUIRED) add_executable(cactus_rt_tracing_benchmark tracing/tracing_benchmark.cc - tracing/string_interner_benchmark.cc ) +if (ENABLE_TRACING) + target_sources(cactus_rt_tracing_benchmark + PRIVATE + tracing/string_interner_benchmark.cc + ) +endif() + target_link_libraries(cactus_rt_tracing_benchmark PRIVATE cactus_rt diff --git a/tests/tracing/helpers/assert_helpers.cc b/tests/tracing/helpers/assert_helpers.cc index d825eed..7df1063 100644 --- a/tests/tracing/helpers/assert_helpers.cc +++ b/tests/tracing/helpers/assert_helpers.cc @@ -3,6 +3,8 @@ #include #include +#include + std::string ProtoToJson(const google::protobuf::Message& proto) { std::string json; google::protobuf::util::MessageToJsonString(proto, &json); @@ -44,8 +46,6 @@ void AssertIsThreadTrackDescriptor(const TracePacket& packet, const char* thread void AssertIsTrackEventSliceBegin( const TracePacket& packet, - const char* event_name, - const char* category, uint64_t thread_track_uuid, uint32_t trusted_packet_sequence_id ) { @@ -54,15 +54,6 @@ void AssertIsTrackEventSliceBegin( const auto& track_event = packet.track_event(); ASSERT_TRUE(track_event.has_type()); ASSERT_EQ(track_event.type(), TrackEvent_Type_TYPE_SLICE_BEGIN); - ASSERT_TRUE(track_event.has_name()); - ASSERT_EQ(track_event.name(), event_name); - - if (category == nullptr) { - ASSERT_EQ(track_event.categories_size(), 0); - } else { - ASSERT_EQ(track_event.categories_size(), 1); - ASSERT_EQ(track_event.categories(0), category); - } ASSERT_EQ(track_event.track_uuid(), thread_track_uuid); @@ -74,6 +65,66 @@ void AssertIsTrackEventSliceBegin( } } +void AssertTrackEventHasIid( + const TracePacket& packet, + uint64_t event_name_iid, + uint64_t category_iid +) { + const auto& track_event = packet.track_event(); + ASSERT_FALSE(track_event.has_name()); + ASSERT_TRUE(track_event.has_name_iid()); + ASSERT_EQ(track_event.name_iid(), event_name_iid); + + ASSERT_EQ(track_event.categories_size(), 0); + if (category_iid == 0) { + ASSERT_EQ(track_event.category_iids_size(), 0); + } else { + ASSERT_EQ(track_event.category_iids_size(), 1); + ASSERT_EQ(track_event.category_iids(0), category_iid); + } +} + +void AssertTrackEventHasNoInternedData(const TracePacket& packet) { + ASSERT_FALSE(packet.has_interned_data()); +} + +std::unordered_map GetInternedEventNames(const TracePacket& packet) { + std::unordered_map event_names; + + if (!packet.has_interned_data()) { + return event_names; + } + + const auto& interned_data = packet.interned_data(); + + for (int i = 0; i < interned_data.event_names_size(); i++) { + const auto& event_name = interned_data.event_names(i); + if (event_name.has_name() && event_name.has_iid()) { + event_names.emplace(event_name.name(), event_name.iid()); + } + } + + return event_names; +} + +std::unordered_map GetInternedEventCategories(const TracePacket& packet) { + std::unordered_map categories; + + if (!packet.has_interned_data()) { + return categories; + } + + const auto& interned_data = packet.interned_data(); + for (int i = 0; i < interned_data.event_categories_size(); i++) { + const auto& category = interned_data.event_categories(i); + if (category.has_name() && category.has_iid()) { + categories.emplace(category.name(), category.iid()); + } + } + + return categories; +} + void AssertIsTrackEventSliceEnd(const TracePacket& packet, uint64_t thread_track_uuid, uint32_t trusted_packet_sequence_id) { ASSERT_TRUE(packet.has_track_event()); const auto& track_event = packet.track_event(); @@ -88,8 +139,6 @@ void AssertIsTrackEventSliceEnd(const TracePacket& packet, uint64_t thread_track void AssertIsTrackEventInstant( const TracePacket& packet, - const char* event_name, - const char* category, uint64_t thread_track_uuid, uint32_t trusted_packet_sequence_id ) { @@ -98,15 +147,6 @@ void AssertIsTrackEventInstant( const auto& track_event = packet.track_event(); ASSERT_TRUE(track_event.has_type()); ASSERT_EQ(track_event.type(), TrackEvent_Type_TYPE_INSTANT); - ASSERT_TRUE(track_event.has_name()); - ASSERT_EQ(track_event.name(), event_name); - - if (category == nullptr) { - ASSERT_EQ(track_event.categories_size(), 0); - } else { - ASSERT_EQ(track_event.categories_size(), 1); - ASSERT_EQ(track_event.categories(0), category); - } ASSERT_EQ(track_event.track_uuid(), thread_track_uuid); diff --git a/tests/tracing/helpers/assert_helpers.h b/tests/tracing/helpers/assert_helpers.h index c494ebc..033c27a 100644 --- a/tests/tracing/helpers/assert_helpers.h +++ b/tests/tracing/helpers/assert_helpers.h @@ -23,19 +23,27 @@ void AssertIsThreadTrackDescriptor(const TracePacket& packet, const char* thread void AssertIsTrackEventSliceBegin( const TracePacket& packet, - const char* event_name, - const char* category, uint64_t thread_track_uuid, // If 0, this assertion will only check if the id is >0. Otherwise it will do an equality check uint32_t trusted_packet_sequence_id = 0 ); +void AssertTrackEventHasIid( + const TracePacket& packet, + uint64_t event_name_iid, + uint64_t category_iid +); + +void AssertTrackEventHasNoInternedData(const TracePacket& packet); + +std::unordered_map GetInternedEventNames(const TracePacket& packet); + +std::unordered_map GetInternedEventCategories(const TracePacket& packet); + void AssertIsTrackEventSliceEnd(const TracePacket& packet, uint64_t thread_track_uuid, uint32_t trusted_packet_sequence_id); void AssertIsTrackEventInstant( const TracePacket& packet, - const char* event_name, - const char* category, uint64_t thread_track_uuid, uint32_t trusted_packet_sequence_id = 0 ); diff --git a/tests/tracing/multi_threaded_test.cc b/tests/tracing/multi_threaded_test.cc index 485d196..9fcf468 100644 --- a/tests/tracing/multi_threaded_test.cc +++ b/tests/tracing/multi_threaded_test.cc @@ -38,8 +38,7 @@ class MultiThreadTracingTest : public ::testing::Test { protected: void SetUp() override { - app_.StartTraceSession(); - app_.RegisterTraceSink(sink_); // TODO: make this registerable before the trace session starts. + app_.StartTraceSession(sink_); } void TearDown() override { @@ -87,19 +86,51 @@ TEST_F(MultiThreadTracingTest, TraceFromMultipleThreads) { AssertIsThreadTrackDescriptor(*regular_thread_traces[0], kRegularThreadName, process_track_uuid); const auto regular_thread_track_uuid = regular_thread_traces[0]->track_descriptor().uuid(); - AssertIsTrackEventInstant(*regular_thread_traces[1], "Event1", nullptr, regular_thread_track_uuid); + AssertIsTrackEventInstant(*regular_thread_traces[1], regular_thread_track_uuid); + + auto event_names = GetInternedEventNames(*regular_thread_traces[1]); + ASSERT_EQ(event_names.size(), 1); + + const auto event1_iid = event_names.at("Event1"); + ASSERT_GT(event1_iid, 0); + + AssertTrackEventHasIid(*regular_thread_traces[1], event1_iid, 0); + + const auto regular_thread_sequence_id = regular_thread_traces[1]->trusted_packet_sequence_id(); AssertIsThreadTrackDescriptor(*cyclic_thread_traces[0], kCyclicThreadName, process_track_uuid); const auto cyclic_thread_track_uuid = cyclic_thread_traces[0]->track_descriptor().uuid(); - AssertIsTrackEventSliceBegin(*cyclic_thread_traces[1], "Loop", "cactusrt", cyclic_thread_track_uuid); + AssertIsTrackEventSliceBegin(*cyclic_thread_traces[1], cyclic_thread_track_uuid); + + event_names = GetInternedEventNames(*cyclic_thread_traces[1]); + ASSERT_EQ(event_names.size(), 1); + + const auto loop_iid = event_names.at("Loop"); + ASSERT_GT(loop_iid, 0); + + auto event_categories = GetInternedEventCategories(*cyclic_thread_traces[1]); + ASSERT_EQ(event_categories.size(), 1); + + const auto cactusrt_category_iid = event_categories.at("cactusrt"); + ASSERT_GT(cactusrt_category_iid, 0); + + AssertTrackEventHasIid(*cyclic_thread_traces[1], loop_iid, cactusrt_category_iid); + auto sequence_id = cyclic_thread_traces[1]->trusted_packet_sequence_id(); + ASSERT_NE(regular_thread_sequence_id, sequence_id); for (size_t i = 0; i < 20; i++) { auto begin_idx = 1 + (i * 2); auto end_idx = 1 + (i * 2) + 1; - AssertIsTrackEventSliceBegin(*cyclic_thread_traces[begin_idx], "Loop", "cactusrt", cyclic_thread_track_uuid, sequence_id); + AssertIsTrackEventSliceBegin(*cyclic_thread_traces[begin_idx], cyclic_thread_track_uuid, sequence_id); + if (i != 0) { + // The first packet will have interned data and we checked it already with the previous block + AssertTrackEventHasNoInternedData(*cyclic_thread_traces[begin_idx]); + } + + AssertTrackEventHasIid(*cyclic_thread_traces[begin_idx], loop_iid, cactusrt_category_iid); AssertIsTrackEventSliceEnd(*cyclic_thread_traces[end_idx], cyclic_thread_track_uuid, sequence_id); } } @@ -124,14 +155,35 @@ TEST_F(MultiThreadTracingTest, CyclicThreadTracesLoop) { AssertIsThreadTrackDescriptor(*packets[1], kCyclicThreadName, process_track_uuid); const auto thread_track_uuid = packets[1]->track_descriptor().uuid(); - AssertIsTrackEventSliceBegin(*packets[2], "Loop", "cactusrt", thread_track_uuid); + AssertIsTrackEventSliceBegin(*packets[2], thread_track_uuid); + + auto event_names = GetInternedEventNames(*packets[2]); + ASSERT_EQ(event_names.size(), 1); + + const auto loop_iid = event_names.at("Loop"); + ASSERT_GT(loop_iid, 0); + + auto event_categories = GetInternedEventCategories(*packets[2]); + ASSERT_EQ(event_categories.size(), 1); + + const auto cactusrt_category_iid = event_categories.at("cactusrt"); + ASSERT_GT(cactusrt_category_iid, 0); + + AssertTrackEventHasIid(*packets[2], loop_iid, cactusrt_category_iid); + auto sequence_id = packets[2]->trusted_packet_sequence_id(); for (size_t i = 0; i < 20; i++) { auto begin_idx = 2 + (i * 2); auto end_idx = 2 + (i * 2) + 1; - AssertIsTrackEventSliceBegin(*packets[begin_idx], "Loop", "cactusrt", thread_track_uuid, sequence_id); + AssertIsTrackEventSliceBegin(*packets[begin_idx], thread_track_uuid); + if (i != 0) { + // The first packet will have interned data and we checked it already with the previous block + AssertTrackEventHasNoInternedData(*packets[begin_idx]); + } + + AssertTrackEventHasIid(*packets[begin_idx], loop_iid, cactusrt_category_iid); AssertIsTrackEventSliceEnd(*packets[end_idx], thread_track_uuid, sequence_id); } } @@ -167,14 +219,36 @@ TEST_F(MultiThreadTracingTest, CyclicThreadTracesSleepAndDoesNotTraceLoopIfConfi AssertIsThreadTrackDescriptor(*packets[1], thread_name, process_track_uuid); const auto thread_track_uuid = packets[1]->track_descriptor().uuid(); - AssertIsTrackEventSliceBegin(*packets[2], "Sleep", "cactusrt", thread_track_uuid); + AssertIsTrackEventSliceBegin(*packets[2], thread_track_uuid); + + auto event_names = GetInternedEventNames(*packets[2]); + ASSERT_EQ(event_names.size(), 1); + + const auto sleep_iid = event_names.at("Sleep"); + ASSERT_GT(sleep_iid, 0); + + auto event_categories = GetInternedEventCategories(*packets[2]); + ASSERT_EQ(event_categories.size(), 1); + + const auto cactusrt_category_iid = event_categories.at("cactusrt"); + ASSERT_GT(cactusrt_category_iid, 0); + + AssertTrackEventHasIid(*packets[2], sleep_iid, cactusrt_category_iid); + auto sequence_id = packets[2]->trusted_packet_sequence_id(); for (size_t i = 0; i < 19; i++) { auto begin_idx = 2 + (i * 2); auto end_idx = 2 + (i * 2) + 1; - AssertIsTrackEventSliceBegin(*packets[begin_idx], "Sleep", "cactusrt", thread_track_uuid, sequence_id); + AssertIsTrackEventSliceBegin(*packets[begin_idx], thread_track_uuid, sequence_id); + if (i != 0) { + // The first packet will have interned data and we checked it already with the previous block + AssertTrackEventHasNoInternedData(*packets[begin_idx]); + } + + AssertTrackEventHasIid(*packets[begin_idx], sleep_iid, cactusrt_category_iid); + AssertIsTrackEventSliceEnd(*packets[end_idx], thread_track_uuid, sequence_id); // 100 Hz = 10ms loop. @@ -220,7 +294,21 @@ TEST_F(MultiThreadTracingTest, CyclicThreadTracesLoopOverrun) { AssertIsThreadTrackDescriptor(*packets[1], thread_name, process_track_uuid); const auto thread_track_uuid = packets[1]->track_descriptor().uuid(); - AssertIsTrackEventInstant(*packets[2], "LoopOverrun", "cactusrt", thread_track_uuid); + AssertIsTrackEventInstant(*packets[2], thread_track_uuid); + + auto event_names = GetInternedEventNames(*packets[2]); + ASSERT_EQ(event_names.size(), 1); + + const auto name_iid = event_names.at("LoopOverrun"); + ASSERT_GT(name_iid, 0); + + auto event_categories = GetInternedEventCategories(*packets[2]); + ASSERT_EQ(event_categories.size(), 1); + + const auto cactusrt_category_iid = event_categories.at("cactusrt"); + ASSERT_GT(cactusrt_category_iid, 0); + + AssertTrackEventHasIid(*packets[2], name_iid, cactusrt_category_iid); } } // namespace cactus_rt diff --git a/tests/tracing/single_threaded_test.cc b/tests/tracing/single_threaded_test.cc index 01f0650..2134985 100644 --- a/tests/tracing/single_threaded_test.cc +++ b/tests/tracing/single_threaded_test.cc @@ -35,10 +35,7 @@ class SingleThreadTracingTest : public ::testing::Test { protected: void SetUp() override { app_.RegisterThread(regular_thread_); - app_.StartTraceSession(); // TODO: make each test manually start the trace session! - - app_.RegisterTraceSink(sink_); - + app_.StartTraceSession(sink_); // TODO: make each test manually start the trace session! app_.Start(); } @@ -72,9 +69,23 @@ TEST_F(SingleThreadTracingTest, WithSpan) { auto thread_track_uuid = packets[1]->track_descriptor().uuid(); // Third packet is the slice begin - AssertIsTrackEventSliceBegin(*packets[2], "TestEvent", "category", thread_track_uuid); + AssertIsTrackEventSliceBegin(*packets[2], thread_track_uuid); auto sequence_id = packets[2]->trusted_packet_sequence_id(); + const auto event_names = GetInternedEventNames(*packets[2]); + ASSERT_EQ(event_names.size(), 1); + + const auto event_name_iid = event_names.at("TestEvent"); + ASSERT_GT(event_name_iid, 0); + + const auto event_categories = GetInternedEventCategories(*packets[2]); + ASSERT_EQ(event_categories.size(), 1); + + const auto category_iid = event_categories.at("category"); + ASSERT_GT(category_iid, 0); + + AssertTrackEventHasIid(*packets[2], event_name_iid, category_iid); + // Fourth packet is slice end AssertIsTrackEventSliceEnd(*packets[3], thread_track_uuid, sequence_id); @@ -117,23 +128,94 @@ TEST_F(SingleThreadTracingTest, WithSpanNested) { AssertIsThreadTrackDescriptor(*packets[1], kRegularThreadName, process_track_uuid); auto thread_track_uuid = packets[1]->track_descriptor().uuid(); - AssertIsTrackEventSliceBegin(*packets[2], "OuterEvent", "outer", thread_track_uuid); + // First OuterEvent, outer packet + AssertIsTrackEventSliceBegin(*packets[2], thread_track_uuid); auto sequence_id = packets[2]->trusted_packet_sequence_id(); - AssertIsTrackEventSliceBegin(*packets[3], "InnerEvent1", "inner", thread_track_uuid, sequence_id); + auto event_names = GetInternedEventNames(*packets[2]); + ASSERT_EQ(event_names.size(), 1); + + const auto outer_event_iid = event_names.at("OuterEvent"); + ASSERT_GT(outer_event_iid, 0); + + auto event_categories = GetInternedEventCategories(*packets[2]); + ASSERT_EQ(event_categories.size(), 1); + + const auto outer_category_iid = event_categories.at("outer"); + ASSERT_GT(outer_category_iid, 0); + + AssertTrackEventHasIid(*packets[2], outer_event_iid, outer_category_iid); + + // First InnerEvent1, inner packet + AssertIsTrackEventSliceBegin(*packets[3], thread_track_uuid, sequence_id); + event_names = GetInternedEventNames(*packets[3]); + ASSERT_EQ(event_names.size(), 1); + + const auto inner_event1_iid = event_names.at("InnerEvent1"); + ASSERT_GT(inner_event1_iid, 0); + ASSERT_NE(inner_event1_iid, outer_event_iid); + + event_categories = GetInternedEventCategories(*packets[3]); + ASSERT_EQ(event_categories.size(), 1); + + const auto inner_category_iid = event_categories.at("inner"); + ASSERT_GT(inner_category_iid, 0); + ASSERT_NE(inner_category_iid, outer_category_iid); + + AssertTrackEventHasIid(*packets[3], inner_event1_iid, inner_category_iid); + + AssertIsTrackEventSliceBegin(*packets[4], thread_track_uuid, sequence_id); + event_names = GetInternedEventNames(*packets[4]); + ASSERT_EQ(event_names.size(), 1); + + // First InnerInnerEvent1, inner packet + const auto inner_inner_event1_iid = event_names.at("InnerInnerEvent1"); + ASSERT_GT(inner_inner_event1_iid, 0); + ASSERT_NE(inner_inner_event1_iid, inner_event1_iid); + ASSERT_NE(inner_inner_event1_iid, outer_event_iid); + + event_categories = GetInternedEventCategories(*packets[4]); + ASSERT_EQ(event_categories.size(), 0); + + AssertTrackEventHasIid(*packets[4], inner_inner_event1_iid, inner_category_iid); - AssertIsTrackEventSliceBegin(*packets[4], "InnerInnerEvent1", "inner", thread_track_uuid, sequence_id); AssertIsTrackEventSliceEnd(*packets[5], thread_track_uuid, sequence_id); AssertTrackEventDuration(*packets[4], *packets[5], 1000000, 10000000); - AssertIsTrackEventSliceBegin(*packets[6], "InnerInnerEvent2", "inner", thread_track_uuid, sequence_id); + // First InnerInnerEvent2, inner packet + AssertIsTrackEventSliceBegin(*packets[6], thread_track_uuid, sequence_id); + event_names = GetInternedEventNames(*packets[6]); + ASSERT_EQ(event_names.size(), 1); + + const auto inner_inner_event2_iid = event_names.at("InnerInnerEvent2"); + ASSERT_GT(inner_inner_event2_iid, 0); + ASSERT_NE(inner_inner_event2_iid, inner_inner_event1_iid); + ASSERT_NE(inner_inner_event2_iid, inner_event1_iid); + ASSERT_NE(inner_inner_event2_iid, outer_event_iid); + + AssertTrackEventHasIid(*packets[6], inner_inner_event2_iid, inner_category_iid); + AssertIsTrackEventSliceEnd(*packets[7], thread_track_uuid, sequence_id); AssertTrackEventDuration(*packets[6], *packets[7], 1000000, 10000000); AssertIsTrackEventSliceEnd(*packets[8], thread_track_uuid, sequence_id); AssertTrackEventDuration(*packets[3], *packets[8], 2000000, 20000000); - AssertIsTrackEventSliceBegin(*packets[9], "InnerEvent2", "inner", thread_track_uuid, sequence_id); + // First InnerEvent2, inner packet + AssertIsTrackEventSliceBegin(*packets[9], thread_track_uuid, sequence_id); + + event_names = GetInternedEventNames(*packets[9]); + ASSERT_EQ(event_names.size(), 1); + + const auto inner_event2_iid = event_names.at("InnerEvent2"); + ASSERT_GT(inner_event2_iid, 0); + ASSERT_NE(inner_event2_iid, inner_inner_event2_iid); + ASSERT_NE(inner_event2_iid, inner_inner_event1_iid); + ASSERT_NE(inner_event2_iid, inner_event1_iid); + ASSERT_NE(inner_event2_iid, outer_event_iid); + + AssertTrackEventHasIid(*packets[9], inner_event2_iid, inner_category_iid); + AssertIsTrackEventSliceEnd(*packets[10], thread_track_uuid, sequence_id); AssertTrackEventDuration(*packets[9], *packets[10], 2000000, 20000000); @@ -158,7 +240,21 @@ TEST_F(SingleThreadTracingTest, InstantEvent) { AssertIsThreadTrackDescriptor(*packets[1], kRegularThreadName, process_track_uuid); auto thread_track_uuid = packets[1]->track_descriptor().uuid(); - AssertIsTrackEventInstant(*packets[2], "MyCoolEvent", "instant", thread_track_uuid); + AssertIsTrackEventInstant(*packets[2], thread_track_uuid); + + const auto event_names = GetInternedEventNames(*packets[2]); + ASSERT_EQ(event_names.size(), 1); + + const auto event_name_iid = event_names.at("MyCoolEvent"); + ASSERT_GT(event_name_iid, 0); + + const auto event_categories = GetInternedEventCategories(*packets[2]); + ASSERT_EQ(event_categories.size(), 1); + + const auto category_iid = event_categories.at("instant"); + ASSERT_GT(category_iid, 0); + + AssertTrackEventHasIid(*packets[2], event_name_iid, category_iid); } TEST_F(SingleThreadTracingTest, StopTracingAndNoEventsAreRecorded) { @@ -187,17 +283,15 @@ TEST_F(SingleThreadTracingTest, RestartTracingStartsNewSession) { auto packets = GetPacketsFromTraces(traces); ASSERT_EQ(packets.size(), 4); + auto event1_thread_sequence_id1 = packets[2]->trusted_packet_sequence_id(); + regular_thread_->RunOneIteration([](MockRegularThread* self) { auto span = self->TracerForTest().WithSpan("Event2"); WasteTime(std::chrono::microseconds(1000)); }); - // In normal API usage, we always have to re-register sinks after starting a - // trace session, which may not be ideal?? Alternatively could use the short - // hand API to log directly to file... - app_.StartTraceSession(); - sink_->Clear(); // clear the sink so we have a fresh start when restarting trace - app_.RegisterTraceSink(sink_); // TODO: make it so that sinks are cached???? Doesn't make sense tho. + sink_->Clear(); // clear the sink so we have a fresh start when restarting trace + app_.StartTraceSession(sink_); regular_thread_->RunOneIteration([](MockRegularThread* self) { auto span = self->TracerForTest().WithSpan("Event3"); @@ -208,7 +302,7 @@ TEST_F(SingleThreadTracingTest, RestartTracingStartsNewSession) { auto traces2 = sink_->LoggedTraces(); auto packets2 = GetPacketsFromTraces(traces2); - ASSERT_EQ(packets2.size(), 4); + ASSERT_EQ(packets2.size(), 5); AssertIsProcessTrackDescriptor(*packets2[0], kAppName); const auto process_track_uuid = packets2[0]->track_descriptor().uuid(); @@ -216,13 +310,36 @@ TEST_F(SingleThreadTracingTest, RestartTracingStartsNewSession) { AssertIsThreadTrackDescriptor(*packets2[1], kRegularThreadName, process_track_uuid); auto thread_track_uuid = packets2[1]->track_descriptor().uuid(); + std::cout << "packets2: " << packets2[2]->ShortDebugString() << "\n"; + + // Event1 is emitted as interned data because that thread is still active and the event name got interned previously. + auto event_names = GetInternedEventNames(*packets2[2]); + ASSERT_EQ(event_names.size(), 1); + + auto event1_name_iid = event_names.at("Event1"); + ASSERT_GT(event1_name_iid, 0); + + auto event1_thread_sequence_id2 = packets2[2]->trusted_packet_sequence_id(); + + ASSERT_EQ(event1_thread_sequence_id1, event1_thread_sequence_id2); + // Note Event2 is lost as designed - AssertIsTrackEventSliceBegin(*packets2[2], "Event3", nullptr, thread_track_uuid); - auto sequence_id = packets2[2]->trusted_packet_sequence_id(); + AssertIsTrackEventSliceBegin(*packets2[3], thread_track_uuid); + auto sequence_id = packets2[3]->trusted_packet_sequence_id(); + + ASSERT_EQ(sequence_id, event1_thread_sequence_id2); + + event_names = GetInternedEventNames(*packets2[3]); + ASSERT_EQ(event_names.size(), 1); + + const auto event3_name_iid = event_names.at("Event3"); + ASSERT_GT(event3_name_iid, 0); - AssertIsTrackEventSliceEnd(*packets2[3], thread_track_uuid, sequence_id); + AssertTrackEventHasIid(*packets2[3], event3_name_iid, 0); - AssertTrackEventDuration(*packets2[2], *packets2[3], 1000000, 10000000); + AssertIsTrackEventSliceEnd(*packets2[4], thread_track_uuid, sequence_id); + + AssertTrackEventDuration(*packets2[3], *packets2[4], 1000000, 10000000); } TEST_F(SingleThreadTracingTest, DynamicallyAddingSinkWillWork) { @@ -249,7 +366,7 @@ TEST_F(SingleThreadTracingTest, DynamicallyAddingSinkWillWork) { auto traces2 = sink2->LoggedTraces(); auto packets2 = GetPacketsFromTraces(traces2); - ASSERT_EQ(packets2.size(), 3); + ASSERT_EQ(packets2.size(), 4); AssertIsProcessTrackDescriptor(*packets2[0], kAppName); const auto process_track_uuid = packets2[0]->track_descriptor().uuid(); @@ -257,7 +374,24 @@ TEST_F(SingleThreadTracingTest, DynamicallyAddingSinkWillWork) { AssertIsThreadTrackDescriptor(*packets2[1], kRegularThreadName, process_track_uuid); auto thread_track_uuid = packets2[1]->track_descriptor().uuid(); - AssertIsTrackEventInstant(*packets2[2], "Event2", nullptr, thread_track_uuid); + auto event_names = GetInternedEventNames(*packets2[2]); + ASSERT_EQ(event_names.size(), 1); + + const auto event1_name_iid = event_names.at("Event1"); + ASSERT_GT(event1_name_iid, 0); + + auto sequence_id = packets2[2]->trusted_packet_sequence_id(); + + AssertIsTrackEventInstant(*packets2[3], thread_track_uuid, sequence_id); + + event_names = GetInternedEventNames(*packets2[3]); + ASSERT_EQ(event_names.size(), 1); + + const auto event2_name_iid = event_names.at("Event2"); + ASSERT_GT(event2_name_iid, 0); + ASSERT_NE(event2_name_iid, event1_name_iid); + + AssertTrackEventHasIid(*packets2[3], event2_name_iid, 0); auto traces = sink_->LoggedTraces(); auto packets = GetPacketsFromTraces(traces); diff --git a/tests/tracing/string_interner_benchmark.cc b/tests/tracing/string_interner_benchmark.cc index c7c8e98..2300138 100644 --- a/tests/tracing/string_interner_benchmark.cc +++ b/tests/tracing/string_interner_benchmark.cc @@ -2,7 +2,8 @@ #include namespace { - +// The for (auto _ : state) triggers the following rule... +// NOLINTBEGIN(clang-analyzer-deadcode.DeadStores) using cactus_rt::tracing::utils::StringInterner; StringInterner SetupInterner() { @@ -40,4 +41,5 @@ void BM_StringInternerStdLongString(benchmark::State& state) { } } BENCHMARK(BM_StringInternerStdLongString); +// NOLINTEND(clang-analyzer-deadcode.DeadStores) } // namespace diff --git a/tests/tracing/string_interner_test.cc b/tests/tracing/string_interner_test.cc index 1be87fd..dae5a8d 100644 --- a/tests/tracing/string_interner_test.cc +++ b/tests/tracing/string_interner_test.cc @@ -6,8 +6,6 @@ #include #include -using cactus_rt::tracing::utils::StringInterner; - namespace cactus_rt::tracing::utils { TEST(StringInternerTest, BasicAssertions) { From 2ec2c232ff40d0ce46caac1d62c297dd257c2df0 Mon Sep 17 00:00:00 2001 From: Shuhao Wu Date: Tue, 19 Mar 2024 19:50:13 -0400 Subject: [PATCH 6/6] Adjusted benchmark setup --- Makefile | 9 +++++++-- docker/scripts/01-build.sh | 3 ++- 2 files changed, 9 insertions(+), 3 deletions(-) diff --git a/Makefile b/Makefile index 5e3e418..3336393 100644 --- a/Makefile +++ b/Makefile @@ -24,11 +24,16 @@ test-debug: build-test-debug test: test-debug -benchmark: build-test-debug - build/test/tests/cactus_rt_tracing_benchmark +build-test-release: + cmake -Bbuild/benchmark -DCMAKE_BUILD_TYPE=RelWithDebInfo -DENABLE_EXAMPLES=OFF -DBUILD_TESTING=ON -DENABLE_CLANG_TIDY=$(ENABLE_CLANG_TIDY) -DENABLE_TRACING=$(ENABLE_TRACING) + cmake --build build/benchmark -j $$(nproc) + +benchmark: build-test-release + build/benchmark/tests/cactus_rt_tracing_benchmark clean: test ! -d build/test || cmake --build build/test --target clean + test ! -d build/benchmark || cmake --build build/benchmark --target clean test ! -d build/debug || cmake --build build/debug --target clean test ! -d build/release || cmake --build build/release --target clean diff --git a/docker/scripts/01-build.sh b/docker/scripts/01-build.sh index 3004153..beb74c4 100755 --- a/docker/scripts/01-build.sh +++ b/docker/scripts/01-build.sh @@ -6,5 +6,6 @@ cmake -B${CACTUS_RT_BUILD_DIR} \ -DENABLE_CLANG_TIDY=ON \ -DBUILD_DOCS=ON \ -DBUILD_TESTING=ON \ - -DENABLE_TRACING=${ENABLE_TRACING:-ON} + -DENABLE_TRACING=${ENABLE_TRACING:-ON} \ + -DCMAKE_BUILD_TYPE=RelWithDebInfo cmake --build ${CACTUS_RT_BUILD_DIR} -j $(nproc)