1 // Copyright 2020 The Pigweed Authors
3 // Licensed under the Apache License, Version 2.0 (the "License"); you may not
4 // use this file except in compliance with the License. You may obtain a copy of
7 // https://www.apache.org/licenses/LICENSE-2.0
9 // Unless required by applicable law or agreed to in writing, software
10 // distributed under the License is distributed on an "AS IS" BASIS, WITHOUT
11 // WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
12 // License for the specific language governing permissions and limitations under
16 #define PW_TRACE_MODULE_NAME "TST"
18 #include "pw_trace/trace.h"
19 #include "pw_trace_tokenized/trace_tokenized.h"
20 #include "pw_trace_tokenized/trace_callback.h"
24 #include "gtest/gtest.h"
28 // Moving these to other lines will require updating the variables
29 #define kTraceFunctionLine 32
30 #define kTraceFunctionGroupLine 33
31 #define kTraceFunctionIdLine 35
32 void TraceFunction() { PW_TRACE_FUNCTION(); }
33 void TraceFunctionGroup() { PW_TRACE_FUNCTION("FunctionGroup"); }
34 void TraceFunctionTraceId(uint32_t id) {
35 PW_TRACE_FUNCTION("FunctionGroup", id);
38 // This trace test interface registers as a trace callback to capture trace
39 // events to verify extpected behaviour. It also supports testing common actions
40 // within the callback.
41 class TraceTestInterface {
45 pw::trace::EventType event_type;
48 bool operator==(const TraceInfo& b) const {
49 return trace_ref == b.trace_ref && event_type == b.event_type &&
50 module == b.module && trace_id == b.trace_id;
54 TraceTestInterface() {
55 PW_TRACE_SET_ENABLED(true);
56 pw::trace::Callbacks::Instance().RegisterSink(TraceSinkStartBlock,
61 pw::trace::Callbacks::Instance().RegisterEventCallback(
63 pw::trace::CallbacksImpl::kCallOnlyWhenEnabled,
65 &event_callback_handle_);
67 ~TraceTestInterface() {
68 pw::trace::Callbacks::Instance().UnregisterSink(sink_handle_);
69 pw::trace::Callbacks::Instance().UnregisterEventCallback(
70 event_callback_handle_);
72 // ActionOnEvent will perform a specific action within the callback when an
73 // event matches one of the characteristics of event_match_.
74 enum class ActionOnEvent { None, Enable, Disable, DisableAfter, Skip };
75 void SetCallbackEventAction(ActionOnEvent action, TraceInfo event) {
80 // The trace event callback will save the trace event info and add it to
81 // buffer_ in the TraceSink callback, that way it only gets added to the
82 // buffer if tracing is enabled and the sample was not surpressed.
83 static pw_trace_TraceEventReturnFlags TraceEventCallback(
86 pw_trace_EventType event_type,
90 TraceTestInterface* test_interface =
91 reinterpret_cast<TraceTestInterface*>(user_data);
93 pw_trace_TraceEventReturnFlags ret = 0;
94 if (test_interface->action_ != ActionOnEvent::None &&
95 (test_interface->event_match_.trace_ref == trace_ref ||
96 test_interface->event_match_.event_type == event_type ||
97 test_interface->event_match_.module == module ||
98 (trace_id != PW_TRACE_TRACE_ID_DEFAULT &&
99 test_interface->event_match_.trace_id == trace_id))) {
100 if (test_interface->action_ == ActionOnEvent::Skip) {
101 ret |= PW_TRACE_EVENT_RETURN_FLAGS_SKIP_EVENT;
102 } else if (test_interface->action_ == ActionOnEvent::Enable) {
103 PW_TRACE_SET_ENABLED(true);
104 } else if (test_interface->action_ == ActionOnEvent::Disable) {
105 PW_TRACE_SET_ENABLED(false);
106 } else if (test_interface->action_ == ActionOnEvent::DisableAfter) {
107 ret |= PW_TRACE_EVENT_RETURN_FLAGS_DISABLE_AFTER_PROCESSING;
111 test_interface->current_trace_event_ =
112 TraceInfo{trace_ref, event_type, module, trace_id};
116 // Only adds the event to buffer if the number of bytes inidcates is what is
118 static void TraceSinkStartBlock(void* user_data, size_t size) {
119 TraceTestInterface* test_interface =
120 reinterpret_cast<TraceTestInterface*>(user_data);
121 test_interface->sink_block_size_ = size;
122 test_interface->sink_bytes_received_ = 0;
125 static void TraceSinkAddBytes(void* user_data,
128 TraceTestInterface* test_interface =
129 reinterpret_cast<TraceTestInterface*>(user_data);
131 test_interface->sink_bytes_received_ += size;
134 static void TraceSinkEndBlock(void* user_data) {
135 TraceTestInterface* test_interface =
136 reinterpret_cast<TraceTestInterface*>(user_data);
137 if (test_interface->sink_block_size_ ==
138 test_interface->sink_bytes_received_) {
139 test_interface->buffer_.push_back(test_interface->current_trace_event_);
143 // Get the event buffer.
144 std::deque<TraceInfo>& GetEvents() { return buffer_; }
146 // Check that the next event in the buffer is equal to the expected (and pop
148 bool CheckEvent(const TraceInfo& expected) {
149 if (buffer_.empty()) {
152 TraceInfo actual = buffer_.front();
154 return actual == expected;
158 ActionOnEvent action_ = ActionOnEvent::None;
159 TraceInfo event_match_;
160 TraceInfo current_trace_event_;
161 size_t sink_block_size_;
162 size_t sink_bytes_received_;
163 std::deque<TraceInfo> buffer_;
164 pw::trace::CallbacksImpl::SinkHandle sink_handle_;
165 pw::trace::CallbacksImpl::EventCallbackHandle event_callback_handle_;
170 // Helper macro to pop the next trace out of test interface and check it against
172 #define EXPECT_TRACE(...) PW_DELEGATE_BY_ARG_COUNT(_EXPECT_TRACE, __VA_ARGS__)
173 #define _EXPECT_TRACE3(interface, event_type, label) \
174 _EXPECT_TRACE7(interface, \
177 PW_TRACE_GROUP_LABEL_DEFAULT, \
178 PW_TRACE_TRACE_ID_DEFAULT, \
179 PW_TRACE_MODULE_NAME, \
180 PW_TRACE_FLAGS_DEFAULT)
181 #define _EXPECT_TRACE4(interface, event_type, label, group) \
182 _EXPECT_TRACE7(interface, \
186 PW_TRACE_TRACE_ID_DEFAULT, \
187 PW_TRACE_MODULE_NAME, \
188 PW_TRACE_FLAGS_DEFAULT)
189 #define _EXPECT_TRACE5(interface, event_type, label, group, trace_id) \
190 _EXPECT_TRACE7(interface, \
195 PW_TRACE_MODULE_NAME, \
196 PW_TRACE_FLAGS_DEFAULT)
197 #define _EXPECT_TRACE6(interface, event_type, label, group, trace_id, module) \
198 _EXPECT_TRACE7(interface, \
204 PW_TRACE_FLAGS_DEFAULT)
205 #define _EXPECT_TRACE7( \
206 interface, event_type, label, group, trace_id, module, flags) \
208 static uint32_t _label_token = \
209 PW_TRACE_REF(event_type, module, label, flags, group); \
211 interface.CheckEvent({_label_token, event_type, module, trace_id})); \
214 #define EXPECT_TRACE_DATA(...) \
215 PW_DELEGATE_BY_ARG_COUNT(_EXPECT_TRACE_DATA, __VA_ARGS__)
216 #define _EXPECT_TRACE_DATA4(interface, event_type, label, data_type) \
217 _EXPECT_TRACE_DATA8(interface, \
220 PW_TRACE_GROUP_LABEL_DEFAULT, \
221 PW_TRACE_TRACE_ID_DEFAULT, \
223 PW_TRACE_MODULE_NAME, \
224 PW_TRACE_FLAGS_DEFAULT)
225 #define _EXPECT_TRACE_DATA5(interface, event_type, label, group, data_type) \
226 _EXPECT_TRACE_DATA8(interface, \
230 PW_TRACE_TRACE_ID_DEFAULT, \
232 PW_TRACE_MODULE_NAME, \
233 PW_TRACE_FLAGS_DEFAULT)
234 #define _EXPECT_TRACE_DATA6( \
235 interface, event_type, label, group, trace_id, data_type) \
236 _EXPECT_TRACE_DATA8(interface, \
242 PW_TRACE_MODULE_NAME, \
243 PW_TRACE_FLAGS_DEFAULT)
244 #define _EXPECT_TRACE_DATA7( \
245 interface, event_type, label, group, trace_id, data_type, module) \
246 _EXPECT_TRACE_DATA8(interface, \
253 PW_TRACE_FLAGS_DEFAULT)
254 #define _EXPECT_TRACE_DATA8( \
255 interface, event_type, label, group, trace_id, data_type, module, flags) \
257 static uint32_t _label_token = \
258 PW_TRACE_REF_DATA(event_type, module, label, flags, group, data_type); \
260 interface.CheckEvent({_label_token, event_type, module, trace_id})); \
265 TEST(TokenizedTrace, Instant) {
266 TraceTestInterface test_interface;
268 PW_TRACE_INSTANT("Test");
269 PW_TRACE_INSTANT("Test2", "g");
270 PW_TRACE_INSTANT("Test3", "g", 2);
273 EXPECT_TRACE(test_interface, PW_TRACE_TYPE_INSTANT, "Test");
274 EXPECT_TRACE(test_interface, PW_TRACE_TYPE_INSTANT_GROUP, "Test2", "g");
275 EXPECT_TRACE(test_interface, PW_TRACE_TYPE_ASYNC_INSTANT, "Test3", "g", 2);
276 EXPECT_TRUE(test_interface.GetEvents().empty());
279 TEST(TokenizedTrace, Duration) {
280 TraceTestInterface test_interface;
282 PW_TRACE_START("Test");
283 PW_TRACE_END("Test");
286 EXPECT_TRACE(test_interface, PW_TRACE_TYPE_DURATION_START, "Test");
287 EXPECT_TRACE(test_interface, PW_TRACE_TYPE_DURATION_END, "Test");
288 EXPECT_TRUE(test_interface.GetEvents().empty());
291 TEST(TokenizedTrace, DurationGroup) {
292 TraceTestInterface test_interface;
294 PW_TRACE_START("Parent", "group");
295 PW_TRACE_START("Child", "group");
296 PW_TRACE_END("Child", "group");
297 PW_TRACE_END("Parent", "group");
301 test_interface, PW_TRACE_TYPE_DURATION_GROUP_START, "Parent", "group");
303 test_interface, PW_TRACE_TYPE_DURATION_GROUP_START, "Child", "group");
305 test_interface, PW_TRACE_TYPE_DURATION_GROUP_END, "Child", "group");
307 test_interface, PW_TRACE_TYPE_DURATION_GROUP_END, "Parent", "group");
308 EXPECT_TRUE(test_interface.GetEvents().empty());
311 TEST(TokenizedTrace, Async) {
312 TraceTestInterface test_interface;
314 uint32_t trace_id = 1;
315 PW_TRACE_START("label for async", "group", trace_id);
316 PW_TRACE_INSTANT("label for step", "group", trace_id);
317 PW_TRACE_END("label for async", "group", trace_id);
320 EXPECT_TRACE(test_interface,
321 PW_TRACE_TYPE_ASYNC_START,
325 EXPECT_TRACE(test_interface,
326 PW_TRACE_TYPE_ASYNC_INSTANT,
330 EXPECT_TRACE(test_interface,
331 PW_TRACE_TYPE_ASYNC_END,
335 EXPECT_TRUE(test_interface.GetEvents().empty());
338 TEST(TokenizedTrace, SkipEvent) {
339 TraceTestInterface test_interface;
341 // Set trace interface to use skip flag in callback for a specific event.
342 TraceTestInterface::TraceInfo skip_event{
343 0, PW_TRACE_EVENT_TYPE_INVALID, "", PW_TRACE_TRACE_ID_DEFAULT};
344 skip_event.trace_ref = PW_TRACE_REF(PW_TRACE_TYPE_INSTANT,
347 PW_TRACE_FLAGS_DEFAULT,
348 PW_TRACE_GROUP_LABEL_DEFAULT);
349 test_interface.SetCallbackEventAction(TraceTestInterface::ActionOnEvent::Skip,
352 PW_TRACE_INSTANT("Test");
353 PW_TRACE_INSTANT("Test2");
356 EXPECT_TRACE(test_interface, PW_TRACE_TYPE_INSTANT, "Test");
357 EXPECT_TRUE(test_interface.GetEvents().empty());
360 TEST(TokenizedTrace, SkipModule) {
361 TraceTestInterface test_interface;
362 // Set trace interface to use skip flag in callback for a module.
363 TraceTestInterface::TraceInfo skip_event{
364 0, PW_TRACE_EVENT_TYPE_INVALID, "", PW_TRACE_TRACE_ID_DEFAULT};
365 skip_event.module = "SkipModule";
366 test_interface.SetCallbackEventAction(TraceTestInterface::ActionOnEvent::Skip,
369 #undef PW_TRACE_MODULE_NAME
370 #define PW_TRACE_MODULE_NAME "SkipModule"
371 PW_TRACE_INSTANT("Test");
372 #undef PW_TRACE_MODULE_NAME
373 #define PW_TRACE_MODULE_NAME "TST"
374 PW_TRACE_INSTANT("Test2");
377 EXPECT_TRACE(test_interface, PW_TRACE_TYPE_INSTANT, "Test2");
378 EXPECT_TRUE(test_interface.GetEvents().empty());
381 TEST(TokenizedTrace, DisableBeforeTrace) {
382 TraceTestInterface test_interface;
384 // Set trace interface to disable when a specific event happens.
385 TraceTestInterface::TraceInfo trigger{
386 0, PW_TRACE_EVENT_TYPE_INVALID, "", PW_TRACE_TRACE_ID_DEFAULT};
387 // Stop capturing when Test2 event shows up.
388 trigger.trace_ref = PW_TRACE_REF(PW_TRACE_TYPE_INSTANT,
391 PW_TRACE_FLAGS_DEFAULT,
392 PW_TRACE_GROUP_LABEL_DEFAULT);
393 test_interface.SetCallbackEventAction(
394 TraceTestInterface::ActionOnEvent::Disable, trigger);
396 PW_TRACE_INSTANT("Test1");
397 PW_TRACE_INSTANT("Test2");
398 PW_TRACE_INSTANT("Test3");
401 EXPECT_TRACE(test_interface, PW_TRACE_TYPE_INSTANT, "Test1");
402 EXPECT_TRUE(test_interface.GetEvents().empty());
405 TEST(TokenizedTrace, DisableAfterTrace) {
406 TraceTestInterface test_interface;
408 // Set trace interface to use flag to disable after a specific event happens.
409 TraceTestInterface::TraceInfo trigger{
410 0, PW_TRACE_EVENT_TYPE_INVALID, "", PW_TRACE_TRACE_ID_DEFAULT};
411 // Stop capturing after Test2 event shows up.
412 trigger.trace_ref = PW_TRACE_REF(PW_TRACE_TYPE_INSTANT,
415 PW_TRACE_FLAGS_DEFAULT,
416 PW_TRACE_GROUP_LABEL_DEFAULT);
417 test_interface.SetCallbackEventAction(
418 TraceTestInterface::ActionOnEvent::DisableAfter, trigger);
420 PW_TRACE_INSTANT("Test1");
421 PW_TRACE_INSTANT("Test2");
422 PW_TRACE_INSTANT("Test3");
425 EXPECT_TRACE(test_interface, PW_TRACE_TYPE_INSTANT, "Test1");
426 EXPECT_TRACE(test_interface, PW_TRACE_TYPE_INSTANT, "Test2");
427 EXPECT_TRUE(test_interface.GetEvents().empty());
430 TEST(TokenizedTrace, Scope) {
431 TraceTestInterface test_interface;
433 { PW_TRACE_SCOPE("scoped trace"); }
436 EXPECT_TRACE(test_interface, PW_TRACE_TYPE_DURATION_START, "scoped trace");
437 EXPECT_TRACE(test_interface, PW_TRACE_TYPE_DURATION_END, "scoped trace");
438 EXPECT_TRUE(test_interface.GetEvents().empty());
441 TEST(TokenizedTrace, ScopeGroup) {
442 TraceTestInterface test_interface;
444 { PW_TRACE_SCOPE("scoped group trace", "group"); }
447 EXPECT_TRACE(test_interface,
448 PW_TRACE_TYPE_DURATION_GROUP_START,
449 "scoped group trace",
451 EXPECT_TRACE(test_interface,
452 PW_TRACE_TYPE_DURATION_GROUP_END,
453 "scoped group trace",
455 EXPECT_TRUE(test_interface.GetEvents().empty());
458 TEST(TokenizedTrace, ScopeLoop) {
459 TraceTestInterface test_interface;
461 for (uint32_t i = 0; i < 10; i++) {
462 PW_TRACE_SCOPE("scoped loop", "group", i);
465 for (uint32_t i = 0; i < 10; i++) {
467 test_interface, PW_TRACE_TYPE_ASYNC_START, "scoped loop", "group", i);
469 test_interface, PW_TRACE_TYPE_ASYNC_END, "scoped loop", "group", i);
471 EXPECT_TRUE(test_interface.GetEvents().empty());
474 TEST(TokenizedTrace, Function) {
475 TraceTestInterface test_interface;
480 EXPECT_TRACE(test_interface,
481 PW_TRACE_TYPE_DURATION_START,
482 PW_TRACE_FUNCTION_LABEL_FILE_LINE(__FILE__, kTraceFunctionLine));
483 EXPECT_TRACE(test_interface,
484 PW_TRACE_TYPE_DURATION_END,
485 PW_TRACE_FUNCTION_LABEL_FILE_LINE(__FILE__, kTraceFunctionLine));
486 EXPECT_TRUE(test_interface.GetEvents().empty());
489 TEST(TokenizedTrace, FunctionGroup) {
490 TraceTestInterface test_interface;
492 TraceFunctionGroup();
497 PW_TRACE_TYPE_DURATION_GROUP_START,
498 PW_TRACE_FUNCTION_LABEL_FILE_LINE(__FILE__, kTraceFunctionGroupLine),
502 PW_TRACE_TYPE_DURATION_GROUP_END,
503 PW_TRACE_FUNCTION_LABEL_FILE_LINE(__FILE__, kTraceFunctionGroupLine),
505 EXPECT_TRUE(test_interface.GetEvents().empty());
508 TEST(TokenizedTrace, FunctionTraceId) {
509 TraceTestInterface test_interface;
510 static constexpr uint32_t kTraceId = 5;
511 TraceFunctionTraceId(kTraceId);
516 PW_TRACE_TYPE_ASYNC_START,
517 PW_TRACE_FUNCTION_LABEL_FILE_LINE(__FILE__, kTraceFunctionIdLine),
522 PW_TRACE_TYPE_ASYNC_END,
523 PW_TRACE_FUNCTION_LABEL_FILE_LINE(__FILE__, kTraceFunctionIdLine),
526 EXPECT_TRUE(test_interface.GetEvents().empty());
529 TEST(TokenizedTrace, Data) {
530 TraceTestInterface test_interface;
532 PW_TRACE_INSTANT_DATA("label", "i", &value, sizeof(value));
534 EXPECT_TRACE_DATA(test_interface,
535 PW_TRACE_TYPE_INSTANT,
537 "i"); // TODO(rgoliver): check data
538 EXPECT_TRUE(test_interface.GetEvents().empty());
541 // Create some helper macros that generated some test trace data based from a
542 // number, and can check that it is correct.
543 constexpr std::byte kTestData[] = {
544 std::byte{0}, std::byte{1}, std::byte{2}, std::byte{3}, std::byte{4}};
545 #define QUEUE_TESTS_ARGS(num) \
546 (num), static_cast<pw_trace_EventType>((num) % 10), \
547 "module_" PW_STRINGIFY(num), (num), (num), kTestData, \
548 (num) % PW_ARRAY_SIZE(kTestData)
549 #define QUEUE_CHECK_RESULT(queue_size, result, num) \
550 result && ((result->trace_token) == (num)) && \
551 ((result->event_type) == static_cast<pw_trace_EventType>((num) % 10)) && \
552 (strncmp(result->module, \
553 "module_" PW_STRINGIFY(num), \
554 strlen("module_" PW_STRINGIFY(num))) == 0) && \
555 ((result->trace_id) == (num)) && ((result->flags) == (num)) && \
556 (memcmp(const_cast<const pw::trace::internal::TraceQueue< \
557 queue_size>::QueueEventBlock*>(result) \
560 result->data_size) == 0) && \
561 (result->data_size == (num) % PW_ARRAY_SIZE(kTestData))
563 TEST(TokenizedTrace, QueueSimple) {
564 constexpr size_t kQueueSize = 5;
565 pw::trace::internal::TraceQueue<kQueueSize> queue;
566 constexpr size_t kTestNum = 1;
567 queue.TryPushBack(QUEUE_TESTS_ARGS(kTestNum));
568 EXPECT_FALSE(queue.IsEmpty());
569 EXPECT_FALSE(queue.IsFull());
570 EXPECT_TRUE(QUEUE_CHECK_RESULT(kQueueSize, queue.PeekFront(), kTestNum));
572 EXPECT_TRUE(queue.IsEmpty());
573 EXPECT_TRUE(queue.PeekFront() == nullptr);
574 EXPECT_FALSE(queue.IsFull());
577 TEST(TokenizedTrace, QueueFull) {
578 constexpr size_t kQueueSize = 5;
579 pw::trace::internal::TraceQueue<kQueueSize> queue;
580 for (size_t i = 0; i < kQueueSize; i++) {
581 EXPECT_EQ(queue.TryPushBack(QUEUE_TESTS_ARGS(i)), pw::OkStatus());
583 EXPECT_FALSE(queue.IsEmpty());
584 EXPECT_TRUE(queue.IsFull());
585 EXPECT_EQ(queue.TryPushBack(QUEUE_TESTS_ARGS(1)),
586 pw::Status::ResourceExhausted());
588 for (size_t i = 0; i < kQueueSize; i++) {
589 EXPECT_TRUE(QUEUE_CHECK_RESULT(kQueueSize, queue.PeekFront(), i));
592 EXPECT_TRUE(queue.IsEmpty());
593 EXPECT_TRUE(queue.PeekFront() == nullptr);
594 EXPECT_FALSE(queue.IsFull());
597 TEST(TokenizedTrace, Clear) {
598 constexpr size_t kQueueSize = 5;
599 pw::trace::internal::TraceQueue<kQueueSize> queue;
600 for (size_t i = 0; i < kQueueSize; i++) {
601 EXPECT_EQ(queue.TryPushBack(QUEUE_TESTS_ARGS(i)), pw::OkStatus());
603 EXPECT_FALSE(queue.IsEmpty());
604 EXPECT_TRUE(queue.IsFull());
606 EXPECT_TRUE(queue.IsEmpty());
607 EXPECT_TRUE(queue.PeekFront() == nullptr);
608 EXPECT_FALSE(queue.IsFull());