typed_macros_unittest.cc 13 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401
  1. // Copyright (c) 2020 The Chromium Authors. All rights reserved.
  2. // Use of this source code is governed by a BSD-style license that can be
  3. // found in the LICENSE file.
  4. #include "base/trace_event/typed_macros.h"
  5. #include "base/location.h"
  6. #include "base/synchronization/waitable_event.h"
  7. #include "base/test/trace_test_utils.h"
  8. #include "base/trace_event/interned_args_helper.h"
  9. #include "base/trace_event/trace_log.h"
  10. #include "base/trace_event/typed_macros_embedder_support.h"
  11. #include "testing/gmock/include/gmock/gmock.h"
  12. #include "testing/gtest/include/gtest/gtest.h"
  13. #include "third_party/perfetto/include/perfetto/protozero/scattered_heap_buffer.h"
  14. #include "third_party/perfetto/include/perfetto/tracing/track_event_interned_data_index.h"
  15. #include "third_party/perfetto/protos/perfetto/trace/interned_data/interned_data.pb.h"
  16. #include "third_party/perfetto/protos/perfetto/trace/trace.pb.h"
  17. #include "third_party/perfetto/protos/perfetto/trace/track_event/log_message.pbzero.h"
  18. #include "third_party/perfetto/protos/perfetto/trace/track_event/source_location.pb.h"
  19. #include "third_party/perfetto/protos/perfetto/trace/track_event/source_location.pbzero.h"
  20. #if BUILDFLAG(USE_PERFETTO_CLIENT_LIBRARY)
  21. #include "base/tracing/perfetto_platform.h"
  22. #endif
  23. namespace base {
  24. namespace trace_event {
  25. namespace {
  26. #if BUILDFLAG(USE_PERFETTO_CLIENT_LIBRARY)
  27. std::unique_ptr<perfetto::TracingSession> g_tracing_session;
  28. #else
  29. constexpr const char kRecordAllCategoryFilter[] = "*";
  30. #endif
  31. void EnableTrace() {
  32. #if BUILDFLAG(USE_PERFETTO_CLIENT_LIBRARY)
  33. g_tracing_session = perfetto::Tracing::NewTrace();
  34. g_tracing_session->Setup(test::TracingEnvironment::GetDefaultTraceConfig());
  35. g_tracing_session->StartBlocking();
  36. #else // !BUILDFLAG(USE_PERFETTO_CLIENT_LIBRARY)
  37. TraceLog::GetInstance()->SetEnabled(TraceConfig(kRecordAllCategoryFilter, ""),
  38. TraceLog::RECORDING_MODE);
  39. #endif // !BUILDFLAG(USE_PERFETTO_CLIENT_LIBRARY)
  40. }
  41. #if !BUILDFLAG(USE_PERFETTO_CLIENT_LIBRARY)
  42. void CancelTraceAsync(WaitableEvent* flush_complete_event) {
  43. TraceLog::GetInstance()->CancelTracing(base::BindRepeating(
  44. [](WaitableEvent* complete_event,
  45. const scoped_refptr<base::RefCountedString>&, bool has_more_events) {
  46. if (!has_more_events)
  47. complete_event->Signal();
  48. },
  49. base::Unretained(flush_complete_event)));
  50. }
  51. #endif // !BUILDFLAG(USE_PERFETTO_CLIENT_LIBRARY)
  52. void CancelTrace() {
  53. #if BUILDFLAG(USE_PERFETTO_CLIENT_LIBRARY)
  54. g_tracing_session.reset();
  55. #else // !BUILDFLAG(USE_PERFETTO_CLIENT_LIBRARY)
  56. WaitableEvent flush_complete_event(WaitableEvent::ResetPolicy::AUTOMATIC,
  57. WaitableEvent::InitialState::NOT_SIGNALED);
  58. CancelTraceAsync(&flush_complete_event);
  59. flush_complete_event.Wait();
  60. #endif
  61. }
  62. struct TestTrackEvent;
  63. struct TestTracePacket;
  64. TestTrackEvent* g_test_track_event;
  65. TestTracePacket* g_test_trace_packet;
  66. struct TestTrackEvent : public TrackEventHandle::CompletionListener {
  67. public:
  68. TestTrackEvent() {
  69. CHECK_EQ(g_test_track_event, nullptr)
  70. << "Another instance of TestTrackEvent is already active";
  71. g_test_track_event = this;
  72. }
  73. ~TestTrackEvent() override { g_test_track_event = nullptr; }
  74. void OnTrackEventCompleted() override {
  75. EXPECT_FALSE(event_completed);
  76. event_completed = true;
  77. }
  78. protozero::HeapBuffered<perfetto::protos::pbzero::TrackEvent> event;
  79. perfetto::internal::TrackEventIncrementalState incremental_state;
  80. bool prepare_called = false;
  81. bool event_completed = false;
  82. };
  83. struct TestTracePacket : public TracePacketHandle::CompletionListener {
  84. public:
  85. TestTracePacket() {
  86. CHECK_EQ(g_test_trace_packet, nullptr)
  87. << "Another instance of TestTracePacket is already active";
  88. g_test_trace_packet = this;
  89. }
  90. ~TestTracePacket() override { g_test_trace_packet = nullptr; }
  91. void OnTracePacketCompleted() override {
  92. EXPECT_FALSE(packet_completed);
  93. packet_completed = true;
  94. }
  95. protozero::HeapBuffered<perfetto::protos::pbzero::TracePacket> packet;
  96. bool prepare_called = false;
  97. bool packet_completed = false;
  98. bool emit_empty_called = false;
  99. };
  100. TrackEventHandle PrepareTrackEvent(TraceEvent*) {
  101. CHECK_NE(g_test_track_event, nullptr) << "TestTrackEvent not set yet";
  102. g_test_track_event->prepare_called = true;
  103. return TrackEventHandle(g_test_track_event->event.get(),
  104. &g_test_track_event->incremental_state,
  105. g_test_track_event);
  106. }
  107. TracePacketHandle PrepareTracePacket() {
  108. CHECK_NE(g_test_track_event, nullptr) << "TestTracePacket not set yet";
  109. g_test_trace_packet->prepare_called = true;
  110. return TracePacketHandle(TracePacketHandle::PerfettoPacketHandle(
  111. g_test_trace_packet->packet.get()),
  112. g_test_trace_packet);
  113. }
  114. void EmitEmptyPacket() {
  115. CHECK_NE(g_test_track_event, nullptr) << "TestTracePacket not set yet";
  116. g_test_trace_packet->emit_empty_called = true;
  117. }
  118. class TypedTraceEventTest : public testing::Test {
  119. public:
  120. TypedTraceEventTest() {
  121. perfetto::internal::TrackRegistry::InitializeInstance();
  122. EnableTypedTraceEvents(&PrepareTrackEvent, &PrepareTracePacket,
  123. &EmitEmptyPacket);
  124. }
  125. ~TypedTraceEventTest() override { ResetTypedTraceEventsForTesting(); }
  126. void FlushTrace() {
  127. #if BUILDFLAG(USE_PERFETTO_CLIENT_LIBRARY)
  128. perfetto::TrackEvent::Flush();
  129. g_tracing_session->StopBlocking();
  130. std::vector<char> serialized_data = g_tracing_session->ReadTraceBlocking();
  131. perfetto::protos::Trace trace;
  132. EXPECT_TRUE(
  133. trace.ParseFromArray(serialized_data.data(), serialized_data.size()));
  134. for (const auto& packet : trace.packet()) {
  135. if (packet.has_track_event()) {
  136. std::string serialized_event = packet.track_event().SerializeAsString();
  137. event_.prepare_called = true;
  138. event_.event->AppendRawProtoBytes(serialized_event.data(),
  139. serialized_event.size());
  140. event_.OnTrackEventCompleted();
  141. std::string serialized_interned_data =
  142. packet.interned_data().SerializeAsString();
  143. event_.incremental_state.serialized_interned_data->AppendRawProtoBytes(
  144. serialized_interned_data.data(), serialized_interned_data.size());
  145. std::string serialized_packet = packet.SerializeAsString();
  146. packet_.prepare_called = true;
  147. packet_.packet->AppendRawProtoBytes(serialized_packet.data(),
  148. serialized_packet.size());
  149. packet_.OnTracePacketCompleted();
  150. break;
  151. }
  152. }
  153. #endif // BUILDFLAG(USE_PERFETTO_CLIENT_LIBRARY)
  154. }
  155. perfetto::protos::TrackEvent ParseTrackEvent() {
  156. FlushTrace();
  157. auto serialized_data = event_.event.SerializeAsArray();
  158. perfetto::protos::TrackEvent track_event;
  159. EXPECT_TRUE(track_event.ParseFromArray(serialized_data.data(),
  160. serialized_data.size()));
  161. return track_event;
  162. }
  163. protected:
  164. #if BUILDFLAG(USE_PERFETTO_CLIENT_LIBRARY)
  165. test::TracingEnvironment tracing_environment_;
  166. #endif
  167. TestTrackEvent event_;
  168. TestTracePacket packet_;
  169. };
  170. } // namespace
  171. TEST_F(TypedTraceEventTest, CallbackExecutedWhenTracingEnabled) {
  172. EnableTrace();
  173. TRACE_EVENT("cat", "Name", [&](perfetto::EventContext ctx) {
  174. #if !BUILDFLAG(USE_PERFETTO_CLIENT_LIBRARY)
  175. EXPECT_EQ(ctx.event(), event_.event.get());
  176. #endif
  177. perfetto::protos::pbzero::LogMessage* log = ctx.event()->set_log_message();
  178. log->set_body_iid(1);
  179. });
  180. FlushTrace();
  181. EXPECT_TRUE(event_.prepare_called);
  182. EXPECT_FALSE(event_.event.empty());
  183. EXPECT_TRUE(event_.event_completed);
  184. CancelTrace();
  185. }
  186. TEST_F(TypedTraceEventTest, CallbackNotExecutedWhenTracingDisabled) {
  187. TRACE_EVENT("cat", "Name", [this](perfetto::EventContext ctx) {
  188. EXPECT_EQ(ctx.event(), event_.event.get());
  189. perfetto::protos::pbzero::LogMessage* log = ctx.event()->set_log_message();
  190. log->set_body_iid(1);
  191. });
  192. EXPECT_FALSE(event_.prepare_called);
  193. EXPECT_TRUE(event_.event.empty());
  194. EXPECT_FALSE(event_.event_completed);
  195. }
  196. TEST_F(TypedTraceEventTest, DescriptorPacketWrittenForEventWithTrack) {
  197. EnableTrace();
  198. TRACE_EVENT("cat", "Name", perfetto::Track(1234));
  199. FlushTrace();
  200. EXPECT_TRUE(event_.prepare_called);
  201. EXPECT_FALSE(event_.event.empty());
  202. EXPECT_TRUE(event_.event_completed);
  203. EXPECT_TRUE(packet_.prepare_called);
  204. EXPECT_FALSE(packet_.packet.empty());
  205. EXPECT_TRUE(packet_.packet_completed);
  206. CancelTrace();
  207. }
  208. TEST_F(TypedTraceEventTest, InternedData) {
  209. EnableTrace();
  210. const TraceSourceLocation location("TestFunction", "test.cc", 123);
  211. size_t iid = 0;
  212. TRACE_EVENT("cat", "Name", [&location, &iid](perfetto::EventContext ctx) {
  213. auto* log = ctx.event()->set_log_message();
  214. iid = InternedSourceLocation::Get(&ctx, location);
  215. EXPECT_NE(0u, iid);
  216. log->set_body_iid(iid);
  217. size_t iid2 = InternedSourceLocation::Get(&ctx, location);
  218. EXPECT_EQ(iid, iid2);
  219. TraceSourceLocation location2("TestFunction2", "test.cc", 456);
  220. size_t iid3 = InternedSourceLocation::Get(&ctx, location2);
  221. EXPECT_NE(0u, iid3);
  222. EXPECT_NE(iid, iid3);
  223. // Test getting an interned ID directly from a base::Location object, the
  224. // only attributes that are compared are function_name, file_name and
  225. // line_number.
  226. const void* dummy_pc = &iid;
  227. base::Location base_location =
  228. base::Location("TestFunction", "test.cc", 123, dummy_pc);
  229. TraceSourceLocation location3(base_location);
  230. size_t iid4 = InternedSourceLocation::Get(&ctx, location3);
  231. EXPECT_EQ(iid, iid4);
  232. });
  233. FlushTrace();
  234. auto serialized_data =
  235. event_.incremental_state.serialized_interned_data.SerializeAsArray();
  236. perfetto::protos::InternedData interned_data;
  237. EXPECT_TRUE(interned_data.ParseFromArray(serialized_data.data(),
  238. serialized_data.size()));
  239. EXPECT_EQ(2, interned_data.source_locations_size());
  240. auto interned_loc = interned_data.source_locations()[0];
  241. EXPECT_EQ(iid, interned_loc.iid());
  242. EXPECT_EQ("TestFunction", interned_loc.function_name());
  243. EXPECT_EQ("test.cc", interned_loc.file_name());
  244. interned_loc = interned_data.source_locations()[1];
  245. EXPECT_EQ("TestFunction2", interned_loc.function_name());
  246. EXPECT_EQ("test.cc", interned_loc.file_name());
  247. // Make sure the in-memory interning index persists between trace events by
  248. // recording another event.
  249. event_.incremental_state.serialized_interned_data.Reset();
  250. event_.event_completed = false;
  251. TRACE_EVENT("cat", "Name", [&location](perfetto::EventContext ctx) {
  252. auto* log = ctx.event()->set_log_message();
  253. size_t iid = InternedSourceLocation::Get(&ctx, location);
  254. EXPECT_NE(0u, iid);
  255. log->set_body_iid(iid);
  256. });
  257. FlushTrace();
  258. // No new data should have been interned the second time around.
  259. EXPECT_EQ(
  260. "",
  261. event_.incremental_state.serialized_interned_data.SerializeAsString());
  262. CancelTrace();
  263. }
  264. TEST_F(TypedTraceEventTest, InstantThreadEvent) {
  265. EnableTrace();
  266. TRACE_EVENT_INSTANT("cat", "ThreadEvent", [](perfetto::EventContext) {});
  267. auto track_event = ParseTrackEvent();
  268. EXPECT_FALSE(track_event.has_track_uuid());
  269. CancelTrace();
  270. }
  271. TEST_F(TypedTraceEventTest, InstantProcessEvent) {
  272. EnableTrace();
  273. TRACE_EVENT_INSTANT("cat", "ProcessEvent", perfetto::ProcessTrack::Current(),
  274. [](perfetto::EventContext) {});
  275. auto track_event = ParseTrackEvent();
  276. EXPECT_TRUE(track_event.has_track_uuid());
  277. EXPECT_EQ(track_event.track_uuid(), perfetto::ProcessTrack::Current().uuid);
  278. CancelTrace();
  279. }
  280. TEST_F(TypedTraceEventTest, InstantGlobalEvent) {
  281. EnableTrace();
  282. TRACE_EVENT_INSTANT("cat", "GlobalEvent", perfetto::Track::Global(1234),
  283. [](perfetto::EventContext) {});
  284. auto track_event = ParseTrackEvent();
  285. EXPECT_TRUE(track_event.has_track_uuid());
  286. EXPECT_EQ(track_event.track_uuid(), perfetto::Track::Global(1234).uuid);
  287. CancelTrace();
  288. }
  289. TEST_F(TypedTraceEventTest, InstantGlobalDefaultEvent) {
  290. EnableTrace();
  291. TRACE_EVENT_INSTANT("cat", "GlobalDefaultEvent", perfetto::Track::Global(0),
  292. [](perfetto::EventContext) {});
  293. auto track_event = ParseTrackEvent();
  294. EXPECT_TRUE(track_event.has_track_uuid());
  295. EXPECT_EQ(track_event.track_uuid(), perfetto::Track::Global(0).uuid);
  296. CancelTrace();
  297. }
  298. TEST_F(TypedTraceEventTest, BeginEventOnDefaultTrackDoesNotWriteTrackUuid) {
  299. EnableTrace();
  300. TRACE_EVENT_BEGIN("cat", "Name");
  301. auto begin_event = ParseTrackEvent();
  302. EXPECT_FALSE(begin_event.has_track_uuid());
  303. CancelTrace();
  304. }
  305. TEST_F(TypedTraceEventTest, EndEventOnDefaultTrackDoesNotWriteTrackUuid) {
  306. EnableTrace();
  307. TRACE_EVENT_END("cat");
  308. auto end_event = ParseTrackEvent();
  309. EXPECT_FALSE(end_event.has_track_uuid());
  310. CancelTrace();
  311. }
  312. // In the client library, EmitEmptyPacket() isn't called and the packet
  313. // disappears from the trace. This functionality is instead tested in Perfetto's
  314. // API integration tests. We just verify that the macro builds correctly here
  315. // when building with the client library.
  316. #if BUILDFLAG(USE_PERFETTO_CLIENT_LIBRARY)
  317. #define MAYBE_EmptyEvent DISABLED_EmptyEvent
  318. #else
  319. #define MAYBE_EmptyEvent EmptyEvent
  320. #endif
  321. TEST_F(TypedTraceEventTest, MAYBE_EmptyEvent) {
  322. EnableTrace();
  323. EXPECT_FALSE(g_test_trace_packet->emit_empty_called);
  324. PERFETTO_INTERNAL_ADD_EMPTY_EVENT();
  325. EXPECT_TRUE(g_test_trace_packet->emit_empty_called);
  326. CancelTrace();
  327. }
  328. } // namespace trace_event
  329. } // namespace base