xref: /6.6.0/phosphor/tests/library/macro_test.cc (revision d380e59b)
1/* -*- Mode: C++; tab-width: 4; c-basic-offset: 4; indent-tabs-mode: nil -*- */
2/*
3 *     Copyright 2016 Couchbase, Inc
4 *
5 *   Licensed under the Apache License, Version 2.0 (the "License");
6 *   you may not use this file except in compliance with the License.
7 *   You may obtain a copy of the License at
8 *
9 *       http://www.apache.org/licenses/LICENSE-2.0
10 *
11 *   Unless required by applicable law or agreed to in writing, software
12 *   distributed under the License is distributed on an "AS IS" BASIS,
13 *   WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
14 *   See the License for the specific language governing permissions and
15 *   limitations under the License.
16 */
17
18#include "macro_test.h"
19
20TEST_F(MacroTraceEventTest, Synchronous) {
21    TRACE_EVENT_START0("category", "name");
22    verifications.emplace_back([](const phosphor::TraceEvent& event) {
23        EXPECT_STREQ("name", event.getName());
24        EXPECT_STREQ("category", event.getCategory());
25        EXPECT_EQ(phosphor::TraceEvent::Type::SyncStart, event.getType());
26    });
27    TRACE_EVENT_END0("category", "name");
28    verifications.emplace_back([](const phosphor::TraceEvent& event) {
29        EXPECT_STREQ("name", event.getName());
30        EXPECT_STREQ("category", event.getCategory());
31        EXPECT_EQ(phosphor::TraceEvent::Type::SyncEnd, event.getType());
32    });
33    TRACE_EVENT_START1("category", "name", "my_arg1", 3);
34    verifications.emplace_back([](const phosphor::TraceEvent& event) {
35        EXPECT_STREQ("name", event.getName());
36        EXPECT_STREQ("category", event.getCategory());
37        EXPECT_EQ(phosphor::TraceEvent::Type::SyncStart, event.getType());
38        EXPECT_EQ(3, event.getArgs()[0].as_int);
39        EXPECT_STREQ("my_arg1", event.getArgNames()[0]);
40    });
41    TRACE_EVENT_END1("category", "name", "my_arg1", 3);
42    verifications.emplace_back([](const phosphor::TraceEvent& event) {
43        EXPECT_STREQ("name", event.getName());
44        EXPECT_STREQ("category", event.getCategory());
45        EXPECT_EQ(phosphor::TraceEvent::Type::SyncEnd, event.getType());
46        EXPECT_EQ(3, event.getArgs()[0].as_int);
47        EXPECT_STREQ("my_arg1", event.getArgNames()[0]);
48    });
49    TRACE_EVENT_START2("category", "name", "my_arg1", 3, "my_arg2", 4);
50    verifications.emplace_back([](const phosphor::TraceEvent& event) {
51        EXPECT_STREQ("name", event.getName());
52        EXPECT_STREQ("category", event.getCategory());
53        EXPECT_EQ(phosphor::TraceEvent::Type::SyncStart, event.getType());
54        EXPECT_EQ(3, event.getArgs()[0].as_int);
55        EXPECT_STREQ("my_arg1", event.getArgNames()[0]);
56        EXPECT_EQ(4, event.getArgs()[1].as_int);
57        EXPECT_STREQ("my_arg2", event.getArgNames()[1]);
58    });
59    TRACE_EVENT_END2("category", "name", "my_arg1", 3, "my_arg2", 4);
60    verifications.emplace_back([](const phosphor::TraceEvent& event) {
61        EXPECT_STREQ("name", event.getName());
62        EXPECT_STREQ("category", event.getCategory());
63        EXPECT_EQ(phosphor::TraceEvent::Type::SyncEnd, event.getType());
64        EXPECT_EQ(3, event.getArgs()[0].as_int);
65        EXPECT_STREQ("my_arg1", event.getArgNames()[0]);
66        EXPECT_EQ(4, event.getArgs()[1].as_int);
67        EXPECT_STREQ("my_arg2", event.getArgNames()[1]);
68    });
69}
70
71TEST_F(MacroTraceEventTest, Asynchronous) {
72    TRACE_ASYNC_START0("category", "name", 3);
73    verifications.emplace_back([](const phosphor::TraceEvent& event) {
74        EXPECT_STREQ("name", event.getName());
75        EXPECT_STREQ("category", event.getCategory());
76        EXPECT_EQ(phosphor::TraceEvent::Type::AsyncStart, event.getType());
77        EXPECT_EQ(3, event.getArgs()[0].as_int);
78        EXPECT_STREQ("id", event.getArgNames()[0]);
79    });
80    TRACE_ASYNC_END0("category", "name", 5);
81    verifications.emplace_back([](const phosphor::TraceEvent& event) {
82        EXPECT_STREQ("name", event.getName());
83        EXPECT_STREQ("category", event.getCategory());
84        EXPECT_EQ(phosphor::TraceEvent::Type::AsyncEnd, event.getType());
85        EXPECT_EQ(5, event.getArgs()[0].as_int);
86        EXPECT_STREQ("id_end", event.getArgNames()[0]);
87    });
88    TRACE_ASYNC_START1("category", "name", 3, "my_arg1", 4);
89    verifications.emplace_back([](const phosphor::TraceEvent& event) {
90        EXPECT_STREQ("name", event.getName());
91        EXPECT_STREQ("category", event.getCategory());
92        EXPECT_EQ(phosphor::TraceEvent::Type::AsyncStart, event.getType());
93        EXPECT_EQ(3, event.getArgs()[0].as_int);
94        EXPECT_STREQ("id", event.getArgNames()[0]);
95        EXPECT_EQ(4, event.getArgs()[1].as_int);
96        EXPECT_STREQ("my_arg1", event.getArgNames()[1]);
97    });
98    TRACE_ASYNC_END1("category", "name", 3, "my_arg1", 4);
99    verifications.emplace_back([](const phosphor::TraceEvent& event) {
100        EXPECT_STREQ("name", event.getName());
101        EXPECT_STREQ("category", event.getCategory());
102        EXPECT_EQ(phosphor::TraceEvent::Type::AsyncEnd, event.getType());
103        EXPECT_EQ(3, event.getArgs()[0].as_int);
104        EXPECT_STREQ("id_end", event.getArgNames()[0]);
105        EXPECT_EQ(4, event.getArgs()[1].as_int);
106        EXPECT_STREQ("my_arg1", event.getArgNames()[1]);
107    });
108}
109
110TEST_F(MacroTraceEventTest, Instant) {
111    TRACE_INSTANT0("category", "name");
112    verifications.emplace_back([](const phosphor::TraceEvent& event) {
113        EXPECT_STREQ("name", event.getName());
114        EXPECT_STREQ("category", event.getCategory());
115        EXPECT_EQ(phosphor::TraceEvent::Type::Instant, event.getType());
116    });
117    TRACE_INSTANT1("category", "name", "my_arg1", 3);
118    verifications.emplace_back([](const phosphor::TraceEvent& event) {
119        EXPECT_STREQ("name", event.getName());
120        EXPECT_STREQ("category", event.getCategory());
121        EXPECT_EQ(phosphor::TraceEvent::Type::Instant, event.getType());
122        EXPECT_EQ(3, event.getArgs()[0].as_int);
123        EXPECT_STREQ("my_arg1", event.getArgNames()[0]);
124    });
125    TRACE_INSTANT2("category", "name", "my_arg1", 3, "my_arg2", 4);
126    verifications.emplace_back([](const phosphor::TraceEvent& event) {
127        EXPECT_STREQ("name", event.getName());
128        EXPECT_STREQ("category", event.getCategory());
129        EXPECT_EQ(phosphor::TraceEvent::Type::Instant, event.getType());
130        EXPECT_EQ(3, event.getArgs()[0].as_int);
131        EXPECT_STREQ("my_arg1", event.getArgNames()[0]);
132        EXPECT_EQ(4, event.getArgs()[1].as_int);
133        EXPECT_STREQ("my_arg2", event.getArgNames()[1]);
134    });
135}
136
137TEST_F(MacroTraceEventTest, Global) {
138    TRACE_GLOBAL0("category", "name");
139    verifications.emplace_back([](const phosphor::TraceEvent& event) {
140        EXPECT_STREQ("name", event.getName());
141        EXPECT_STREQ("category", event.getCategory());
142        EXPECT_EQ(phosphor::TraceEvent::Type::GlobalInstant, event.getType());
143    });
144    TRACE_GLOBAL1("category", "name", "my_arg1", 3);
145    verifications.emplace_back([](const phosphor::TraceEvent& event) {
146        EXPECT_STREQ("name", event.getName());
147        EXPECT_STREQ("category", event.getCategory());
148        EXPECT_EQ(phosphor::TraceEvent::Type::GlobalInstant, event.getType());
149        EXPECT_EQ(3, event.getArgs()[0].as_int);
150        EXPECT_STREQ("my_arg1", event.getArgNames()[0]);
151    });
152    TRACE_GLOBAL2("category", "name", "my_arg1", 3, "my_arg2", 4);
153    verifications.emplace_back([](const phosphor::TraceEvent& event) {
154        EXPECT_STREQ("name", event.getName());
155        EXPECT_STREQ("category", event.getCategory());
156        EXPECT_EQ(phosphor::TraceEvent::Type::GlobalInstant, event.getType());
157        EXPECT_EQ(3, event.getArgs()[0].as_int);
158        EXPECT_STREQ("my_arg1", event.getArgNames()[0]);
159        EXPECT_EQ(4, event.getArgs()[1].as_int);
160        EXPECT_STREQ("my_arg2", event.getArgNames()[1]);
161    });
162}
163
164TEST_F(MacroTraceEventTest, Scoped) {
165    {
166        TRACE_EVENT0("category", "name");
167        verifications.emplace_back([](const phosphor::TraceEvent& event) {
168            EXPECT_STREQ("name", event.getName());
169            EXPECT_STREQ("category", event.getCategory());
170            EXPECT_EQ(phosphor::TraceEvent::Type::Complete, event.getType());
171        });
172    }
173    {
174        TRACE_EVENT1("category", "name", "my_arg1", 3);
175        verifications.emplace_back([](const phosphor::TraceEvent& event) {
176            EXPECT_STREQ("name", event.getName());
177            EXPECT_STREQ("category", event.getCategory());
178            EXPECT_EQ(phosphor::TraceEvent::Type::Complete, event.getType());
179            EXPECT_EQ(3, event.getArgs()[0].as_int);
180            EXPECT_STREQ("my_arg1", event.getArgNames()[0]);
181        });
182    }
183    {
184        TRACE_EVENT2("category", "name", "my_arg1", 3, "my_arg2", 4);
185        verifications.emplace_back([](const phosphor::TraceEvent& event) {
186            EXPECT_STREQ("name", event.getName());
187            EXPECT_STREQ("category", event.getCategory());
188            EXPECT_EQ(phosphor::TraceEvent::Type::Complete, event.getType());
189            EXPECT_EQ(3, event.getArgs()[0].as_int);
190            EXPECT_STREQ("my_arg1", event.getArgNames()[0]);
191            EXPECT_EQ(4, event.getArgs()[1].as_int);
192            EXPECT_STREQ("my_arg2", event.getArgNames()[1]);
193        });
194    }
195}
196
197TEST_F(MacroTraceEventTest, LockGuard) {
198    {
199        testing::InSequence dummy;
200        MockUniqueLock m;
201        EXPECT_CALL(m, lock()).Times(1);
202        EXPECT_CALL(m, unlock()).Times(1);
203        TRACE_LOCKGUARD(m, "category", "name");
204        verifications.emplace_back([](const phosphor::TraceEvent& event) {
205            EXPECT_STREQ("name.wait", event.getName());
206            EXPECT_STREQ("category", event.getCategory());
207            EXPECT_EQ(phosphor::TraceEvent::Type::Complete, event.getType());
208        });
209        verifications.emplace_back([](const phosphor::TraceEvent& event) {
210            EXPECT_STREQ("name.held", event.getName());
211            EXPECT_STREQ("category", event.getCategory());
212            EXPECT_EQ(phosphor::TraceEvent::Type::Complete, event.getType());
213        });
214    }
215}
216
217/// Test where we specify a tiny limit for the lock guard; so should be traced.
218TEST_F(MacroTraceEventTest, LockGuardTimedSlow) {
219    {
220        testing::InSequence dummy;
221        MockUniqueLock m;
222        EXPECT_CALL(m, lock()).Times(1);
223        EXPECT_CALL(m, unlock()).Times(1);
224        TRACE_LOCKGUARD_TIMED(m, "category", "name", std::chrono::nanoseconds(0));
225        verifications.emplace_back([](const phosphor::TraceEvent& event) {
226            EXPECT_STREQ("name.wait", event.getName());
227            EXPECT_STREQ("category", event.getCategory());
228            EXPECT_EQ(phosphor::TraceEvent::Type::Complete, event.getType());
229        });
230        verifications.emplace_back([](const phosphor::TraceEvent& event) {
231            EXPECT_STREQ("name.held", event.getName());
232            EXPECT_STREQ("category", event.getCategory());
233            EXPECT_EQ(phosphor::TraceEvent::Type::Complete, event.getType());
234        });
235    }
236}
237
238/// Test where we specify a huge limit for the lock guard; so should not be
239/// traced.
240TEST_F(MacroTraceEventTest, LockGuardTimedFast) {
241    testing::InSequence dummy;
242    MockUniqueLock m;
243    EXPECT_CALL(m, lock()).Times(1);
244    EXPECT_CALL(m, unlock()).Times(1);
245    TRACE_LOCKGUARD_TIMED(m, "category", "name", std::chrono::seconds(100));
246    // empty vector of verifications - to check that we shouldn't expect
247    // any trace events.
248    verifications.clear();
249}
250
251void macro_test_functionA() {
252    TRACE_FUNCTION0("category");
253}
254
255void macro_test_functionC() {
256    TRACE_FUNCTION1("category", "my_arg1", 3);
257}
258
259void macro_test_functionD() {
260    TRACE_FUNCTION2("category", "my_arg1", 3, "my_arg2", 4);
261}
262
263TEST_F(MacroTraceEventTest, Function) {
264    {
265        macro_test_functionA();
266        verifications.emplace_back([](const phosphor::TraceEvent &event) {
267            EXPECT_STREQ("macro_test_functionA", event.getName());
268            EXPECT_STREQ("category", event.getCategory());
269            EXPECT_EQ(phosphor::TraceEvent::Type::Complete, event.getType());
270        });
271    }
272    {
273        macro_test_functionC();
274        verifications.emplace_back([](const phosphor::TraceEvent &event) {
275            EXPECT_STREQ("macro_test_functionC", event.getName());
276            EXPECT_STREQ("category", event.getCategory());
277            EXPECT_EQ(phosphor::TraceEvent::Type::Complete, event.getType());
278            EXPECT_EQ(3, event.getArgs()[0].as_int);
279            EXPECT_STREQ("my_arg1", event.getArgNames()[0]);
280        });
281    }
282    {
283        macro_test_functionD();
284        verifications.emplace_back([](const phosphor::TraceEvent &event) {
285            EXPECT_STREQ("macro_test_functionD", event.getName());
286            EXPECT_STREQ("category", event.getCategory());
287            EXPECT_EQ(phosphor::TraceEvent::Type::Complete, event.getType());
288            EXPECT_EQ(3, event.getArgs()[0].as_int);
289            EXPECT_STREQ("my_arg1", event.getArgNames()[0]);
290            EXPECT_EQ(4, event.getArgs()[1].as_int);
291            EXPECT_STREQ("my_arg2", event.getArgNames()[1]);
292        });
293    }
294}
295
296TEST_F(MacroTraceEventTest, Complete) {
297    int variable = 4;
298    const auto start = std::chrono::steady_clock::now();
299    const auto end = start + std::chrono::microseconds(1);
300    TRACE_COMPLETE0("category", "name", start, end);
301    verifications.emplace_back([](const phosphor::TraceEvent& event) {
302        EXPECT_STREQ("name", event.getName());
303        EXPECT_STREQ("category", event.getCategory());
304        EXPECT_EQ(1000, event.getDuration());
305        EXPECT_EQ(phosphor::TraceEvent::Type::Complete, event.getType());
306    });
307
308    TRACE_COMPLETE1("category", "name", start, end, "my_arg1", 3);
309    verifications.emplace_back([](const phosphor::TraceEvent& event) {
310        EXPECT_STREQ("name", event.getName());
311        EXPECT_STREQ("category", event.getCategory());
312        EXPECT_EQ(1000, event.getDuration());
313        EXPECT_EQ(phosphor::TraceEvent::Type::Complete, event.getType());
314        EXPECT_EQ(3, event.getArgs()[0].as_int);
315        EXPECT_STREQ("my_arg1", event.getArgNames()[0]);
316    });
317
318    TRACE_COMPLETE2(
319            "category", "name", start, end, "my_arg1", 3, "my_arg2", variable);
320    verifications.emplace_back([](const phosphor::TraceEvent& event) {
321        EXPECT_STREQ("name", event.getName());
322        EXPECT_STREQ("category", event.getCategory());
323        EXPECT_EQ(1000, event.getDuration());
324        EXPECT_EQ(phosphor::TraceEvent::Type::Complete, event.getType());
325        EXPECT_EQ(3, event.getArgs()[0].as_int);
326        EXPECT_STREQ("my_arg1", event.getArgNames()[0]);
327        EXPECT_EQ(4, event.getArgs()[1].as_int);
328        EXPECT_STREQ("my_arg2", event.getArgNames()[1]);
329    });
330}
331
332TEST_F(MacroTraceEventTest, InlineString) {
333    TRACE_INSTANT1("category", "name", "arg", PHOSPHOR_INLINE_STR("Hello, World!"));
334    verifications.emplace_back([](const phosphor::TraceEvent& event) {
335        EXPECT_STREQ("name", event.getName());
336        EXPECT_STREQ("category", event.getCategory());
337        EXPECT_EQ(phosphor::TraceEvent::Type::Instant, event.getType());
338        EXPECT_EQ("Hello, W",
339                  std::string(event.getArgs()[0].as_istring));
340    });
341    TRACE_INSTANT1("category", "name", "arg", PHOSPHOR_INLINE_STR("Hello"));
342    verifications.emplace_back([](const phosphor::TraceEvent& event) {
343        EXPECT_STREQ("name", event.getName());
344        EXPECT_STREQ("category", event.getCategory());
345        EXPECT_EQ(phosphor::TraceEvent::Type::Instant, event.getType());
346        EXPECT_EQ("Hello",
347                  std::string(event.getArgs()[0].as_istring));
348    });
349    TRACE_INSTANT1("category", "name", "arg", PHOSPHOR_INLINE_STR(""));
350    verifications.emplace_back([](const phosphor::TraceEvent& event) {
351        EXPECT_STREQ("name", event.getName());
352        EXPECT_STREQ("category", event.getCategory());
353        EXPECT_EQ(phosphor::TraceEvent::Type::Instant, event.getType());
354        EXPECT_EQ("",
355                  std::string(event.getArgs()[0].as_istring));
356    });
357}
358
359// Basic smoke test that category filtering works at a macro level,
360// other unit tests should handle the more extensive testing
361TEST_F(MacroTraceEventTest, CategoryFiltering) {
362    TRACE_INSTANT0("excluded", "name");
363    TRACE_INSTANT0("example", "name");
364    verifications.emplace_back([](const phosphor::TraceEvent& event) {
365        EXPECT_STREQ("name", event.getName());
366        EXPECT_STREQ("example", event.getCategory());
367        EXPECT_EQ(phosphor::TraceEvent::Type::Instant, event.getType());
368    });
369    TRACE_INSTANT2("excluded", "name", "arga", 3, "argb", 4);
370    TRACE_INSTANT2("example", "name", "arga", 3, "argb", 4);
371    verifications.emplace_back([](const phosphor::TraceEvent& event) {
372        EXPECT_STREQ("name", event.getName());
373        EXPECT_STREQ("example", event.getCategory());
374        EXPECT_EQ(phosphor::TraceEvent::Type::Instant, event.getType());
375        EXPECT_EQ(3, event.getArgs()[0].as_int);
376        EXPECT_EQ(4, event.getArgs()[1].as_int);
377    });
378}
379
380// Ensures that const values can be processed by the macros
381TEST_F(MacroTraceEventTest, ConstArgument) {
382    const int x = 5;
383    constexpr int y = 6;
384    TRACE_INSTANT2("category", "name", "const", x, "constexpr", y);
385    verifications.emplace_back([](const phosphor::TraceEvent& event) {
386        EXPECT_STREQ("name", event.getName());
387        EXPECT_STREQ("category", event.getCategory());
388        EXPECT_EQ(phosphor::TraceEvent::Type::Instant, event.getType());
389        EXPECT_EQ(5, event.getArgs()[0].as_int);
390        EXPECT_EQ(6, event.getArgs()[1].as_int);
391    });
392}
393