xref: /5.5.2/phosphor/tests/library/macro_test.cc (revision 5dfc7d22)
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_START("category", "name", 3, 4);
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_EQ(4, event.getArgs()[1].as_int);
40    });
41    TRACE_EVENT_END("category", "name", 5, 6);
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(5, event.getArgs()[0].as_int);
47        EXPECT_EQ(6, event.getArgs()[1].as_int);
48    });
49    TRACE_EVENT_START1("category", "name", "my_arg1", 3);
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    });
57    TRACE_EVENT_END1("category", "name", "my_arg1", 3);
58    verifications.emplace_back([](const phosphor::TraceEvent& event) {
59        EXPECT_STREQ("name", event.getName());
60        EXPECT_STREQ("category", event.getCategory());
61        EXPECT_EQ(phosphor::TraceEvent::Type::SyncEnd, event.getType());
62        EXPECT_EQ(3, event.getArgs()[0].as_int);
63        EXPECT_STREQ("my_arg1", event.getArgNames()[0]);
64    });
65    TRACE_EVENT_START2("category", "name", "my_arg1", 3, "my_arg2", 4);
66    verifications.emplace_back([](const phosphor::TraceEvent& event) {
67        EXPECT_STREQ("name", event.getName());
68        EXPECT_STREQ("category", event.getCategory());
69        EXPECT_EQ(phosphor::TraceEvent::Type::SyncStart, event.getType());
70        EXPECT_EQ(3, event.getArgs()[0].as_int);
71        EXPECT_STREQ("my_arg1", event.getArgNames()[0]);
72        EXPECT_EQ(4, event.getArgs()[1].as_int);
73        EXPECT_STREQ("my_arg2", event.getArgNames()[1]);
74    });
75    TRACE_EVENT_END2("category", "name", "my_arg1", 3, "my_arg2", 4);
76    verifications.emplace_back([](const phosphor::TraceEvent& event) {
77        EXPECT_STREQ("name", event.getName());
78        EXPECT_STREQ("category", event.getCategory());
79        EXPECT_EQ(phosphor::TraceEvent::Type::SyncEnd, event.getType());
80        EXPECT_EQ(3, event.getArgs()[0].as_int);
81        EXPECT_STREQ("my_arg1", event.getArgNames()[0]);
82        EXPECT_EQ(4, event.getArgs()[1].as_int);
83        EXPECT_STREQ("my_arg2", event.getArgNames()[1]);
84    });
85}
86
87TEST_F(MacroTraceEventTest, Asynchronous) {
88    TRACE_ASYNC_START0("category", "name", 3);
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    });
96    TRACE_ASYNC_END0("category", "name", 5);
97    verifications.emplace_back([](const phosphor::TraceEvent& event) {
98        EXPECT_STREQ("name", event.getName());
99        EXPECT_STREQ("category", event.getCategory());
100        EXPECT_EQ(phosphor::TraceEvent::Type::AsyncEnd, event.getType());
101        EXPECT_EQ(5, event.getArgs()[0].as_int);
102        EXPECT_STREQ("id_end", event.getArgNames()[0]);
103    });
104    TRACE_ASYNC_START("category", "name", 3, 4);
105    verifications.emplace_back([](const phosphor::TraceEvent& event) {
106        EXPECT_STREQ("name", event.getName());
107        EXPECT_STREQ("category", event.getCategory());
108        EXPECT_EQ(phosphor::TraceEvent::Type::AsyncStart, event.getType());
109        EXPECT_EQ(3, event.getArgs()[0].as_int);
110        EXPECT_EQ(4, event.getArgs()[1].as_int);
111        EXPECT_STREQ("id", event.getArgNames()[0]);
112    });
113    TRACE_ASYNC_END("category", "name", 5, 6);
114    verifications.emplace_back([](const phosphor::TraceEvent& event) {
115        EXPECT_STREQ("name", event.getName());
116        EXPECT_STREQ("category", event.getCategory());
117        EXPECT_EQ(phosphor::TraceEvent::Type::AsyncEnd, event.getType());
118        EXPECT_EQ(5, event.getArgs()[0].as_int);
119        EXPECT_EQ(6, event.getArgs()[1].as_int);
120        EXPECT_STREQ("id_end", event.getArgNames()[0]);
121    });
122    TRACE_ASYNC_START1("category", "name", 3, "my_arg1", 4);
123    verifications.emplace_back([](const phosphor::TraceEvent& event) {
124        EXPECT_STREQ("name", event.getName());
125        EXPECT_STREQ("category", event.getCategory());
126        EXPECT_EQ(phosphor::TraceEvent::Type::AsyncStart, event.getType());
127        EXPECT_EQ(3, event.getArgs()[0].as_int);
128        EXPECT_STREQ("id", event.getArgNames()[0]);
129        EXPECT_EQ(4, event.getArgs()[1].as_int);
130        EXPECT_STREQ("my_arg1", event.getArgNames()[1]);
131    });
132    TRACE_ASYNC_END1("category", "name", 3, "my_arg1", 4);
133    verifications.emplace_back([](const phosphor::TraceEvent& event) {
134        EXPECT_STREQ("name", event.getName());
135        EXPECT_STREQ("category", event.getCategory());
136        EXPECT_EQ(phosphor::TraceEvent::Type::AsyncEnd, event.getType());
137        EXPECT_EQ(3, event.getArgs()[0].as_int);
138        EXPECT_STREQ("id_end", event.getArgNames()[0]);
139        EXPECT_EQ(4, event.getArgs()[1].as_int);
140        EXPECT_STREQ("my_arg1", event.getArgNames()[1]);
141    });
142}
143
144TEST_F(MacroTraceEventTest, Instant) {
145    TRACE_INSTANT0("category", "name");
146    verifications.emplace_back([](const phosphor::TraceEvent& event) {
147        EXPECT_STREQ("name", event.getName());
148        EXPECT_STREQ("category", event.getCategory());
149        EXPECT_EQ(phosphor::TraceEvent::Type::Instant, event.getType());
150    });
151    TRACE_INSTANT("category", "name", 3, 4);
152    verifications.emplace_back([](const phosphor::TraceEvent& event) {
153        EXPECT_STREQ("name", event.getName());
154        EXPECT_STREQ("category", event.getCategory());
155        EXPECT_EQ(phosphor::TraceEvent::Type::Instant, event.getType());
156        EXPECT_EQ(3, event.getArgs()[0].as_int);
157        EXPECT_EQ(4, event.getArgs()[1].as_int);
158    });
159    TRACE_INSTANT1("category", "name", "my_arg1", 3);
160    verifications.emplace_back([](const phosphor::TraceEvent& event) {
161        EXPECT_STREQ("name", event.getName());
162        EXPECT_STREQ("category", event.getCategory());
163        EXPECT_EQ(phosphor::TraceEvent::Type::Instant, event.getType());
164        EXPECT_EQ(3, event.getArgs()[0].as_int);
165        EXPECT_STREQ("my_arg1", event.getArgNames()[0]);
166    });
167    TRACE_INSTANT2("category", "name", "my_arg1", 3, "my_arg2", 4);
168    verifications.emplace_back([](const phosphor::TraceEvent& event) {
169        EXPECT_STREQ("name", event.getName());
170        EXPECT_STREQ("category", event.getCategory());
171        EXPECT_EQ(phosphor::TraceEvent::Type::Instant, event.getType());
172        EXPECT_EQ(3, event.getArgs()[0].as_int);
173        EXPECT_STREQ("my_arg1", event.getArgNames()[0]);
174        EXPECT_EQ(4, event.getArgs()[1].as_int);
175        EXPECT_STREQ("my_arg2", event.getArgNames()[1]);
176    });
177}
178
179TEST_F(MacroTraceEventTest, Global) {
180    TRACE_GLOBAL0("category", "name");
181    verifications.emplace_back([](const phosphor::TraceEvent& event) {
182        EXPECT_STREQ("name", event.getName());
183        EXPECT_STREQ("category", event.getCategory());
184        EXPECT_EQ(phosphor::TraceEvent::Type::GlobalInstant, event.getType());
185    });
186    TRACE_GLOBAL("category", "name", 3, 4);
187    verifications.emplace_back([](const phosphor::TraceEvent& event) {
188        EXPECT_STREQ("name", event.getName());
189        EXPECT_STREQ("category", event.getCategory());
190        EXPECT_EQ(phosphor::TraceEvent::Type::GlobalInstant, event.getType());
191        EXPECT_EQ(3, event.getArgs()[0].as_int);
192        EXPECT_EQ(4, event.getArgs()[1].as_int);
193    });
194    TRACE_GLOBAL1("category", "name", "my_arg1", 3);
195    verifications.emplace_back([](const phosphor::TraceEvent& event) {
196        EXPECT_STREQ("name", event.getName());
197        EXPECT_STREQ("category", event.getCategory());
198        EXPECT_EQ(phosphor::TraceEvent::Type::GlobalInstant, event.getType());
199        EXPECT_EQ(3, event.getArgs()[0].as_int);
200        EXPECT_STREQ("my_arg1", event.getArgNames()[0]);
201    });
202    TRACE_GLOBAL2("category", "name", "my_arg1", 3, "my_arg2", 4);
203    verifications.emplace_back([](const phosphor::TraceEvent& event) {
204        EXPECT_STREQ("name", event.getName());
205        EXPECT_STREQ("category", event.getCategory());
206        EXPECT_EQ(phosphor::TraceEvent::Type::GlobalInstant, event.getType());
207        EXPECT_EQ(3, event.getArgs()[0].as_int);
208        EXPECT_STREQ("my_arg1", event.getArgNames()[0]);
209        EXPECT_EQ(4, event.getArgs()[1].as_int);
210        EXPECT_STREQ("my_arg2", event.getArgNames()[1]);
211    });
212}
213
214TEST_F(MacroTraceEventTest, Scoped) {
215    {
216        TRACE_EVENT0("category", "name");
217        verifications.emplace_back([](const phosphor::TraceEvent& event) {
218            EXPECT_STREQ("name", event.getName());
219            EXPECT_STREQ("category", event.getCategory());
220            EXPECT_EQ(phosphor::TraceEvent::Type::Complete, event.getType());
221        });
222    }
223    {
224        TRACE_EVENT1("category", "name", "my_arg1", 3);
225        verifications.emplace_back([](const phosphor::TraceEvent& event) {
226            EXPECT_STREQ("name", event.getName());
227            EXPECT_STREQ("category", event.getCategory());
228            EXPECT_EQ(phosphor::TraceEvent::Type::Complete, event.getType());
229            EXPECT_EQ(3, event.getArgs()[0].as_int);
230            EXPECT_STREQ("my_arg1", event.getArgNames()[0]);
231        });
232    }
233    {
234        TRACE_EVENT2("category", "name", "my_arg1", 3, "my_arg2", 4);
235        verifications.emplace_back([](const phosphor::TraceEvent& event) {
236            EXPECT_STREQ("name", event.getName());
237            EXPECT_STREQ("category", event.getCategory());
238            EXPECT_EQ(phosphor::TraceEvent::Type::Complete, event.getType());
239            EXPECT_EQ(3, event.getArgs()[0].as_int);
240            EXPECT_STREQ("my_arg1", event.getArgNames()[0]);
241            EXPECT_EQ(4, event.getArgs()[1].as_int);
242            EXPECT_STREQ("my_arg2", event.getArgNames()[1]);
243        });
244    }
245}
246
247TEST_F(MacroTraceEventTest, LockGuard) {
248    {
249        testing::InSequence dummy;
250        MockUniqueLock m;
251        EXPECT_CALL(m, lock()).Times(1);
252        EXPECT_CALL(m, unlock()).Times(1);
253        TRACE_LOCKGUARD(m, "category", "name");
254        verifications.emplace_back([](const phosphor::TraceEvent& event) {
255            EXPECT_STREQ("name.wait", event.getName());
256            EXPECT_STREQ("category", event.getCategory());
257            EXPECT_EQ(phosphor::TraceEvent::Type::Complete, event.getType());
258        });
259        verifications.emplace_back([](const phosphor::TraceEvent& event) {
260            EXPECT_STREQ("name.held", event.getName());
261            EXPECT_STREQ("category", event.getCategory());
262            EXPECT_EQ(phosphor::TraceEvent::Type::Complete, event.getType());
263        });
264    }
265}
266
267/// Test where we specify a tiny limit for the lock guard; so should be traced.
268TEST_F(MacroTraceEventTest, LockGuardTimedSlow) {
269    {
270        testing::InSequence dummy;
271        MockUniqueLock m;
272        EXPECT_CALL(m, lock()).Times(1);
273        EXPECT_CALL(m, unlock()).Times(1);
274        TRACE_LOCKGUARD_TIMED(m, "category", "name", std::chrono::nanoseconds(0));
275        verifications.emplace_back([](const phosphor::TraceEvent& event) {
276            EXPECT_STREQ("name.wait", event.getName());
277            EXPECT_STREQ("category", event.getCategory());
278            EXPECT_EQ(phosphor::TraceEvent::Type::Complete, event.getType());
279        });
280        verifications.emplace_back([](const phosphor::TraceEvent& event) {
281            EXPECT_STREQ("name.held", event.getName());
282            EXPECT_STREQ("category", event.getCategory());
283            EXPECT_EQ(phosphor::TraceEvent::Type::Complete, event.getType());
284        });
285    }
286}
287
288/// Test where we specify a huge limit for the lock guard; so should not be
289/// traced.
290TEST_F(MacroTraceEventTest, LockGuardTimedFast) {
291    testing::InSequence dummy;
292    MockUniqueLock m;
293    EXPECT_CALL(m, lock()).Times(1);
294    EXPECT_CALL(m, unlock()).Times(1);
295    TRACE_LOCKGUARD_TIMED(m, "category", "name", std::chrono::seconds(100));
296    // empty vector of verifications - to check that we shouldn't expect
297    // any trace events.
298    verifications.clear();
299}
300
301void macro_test_functionA() {
302    TRACE_FUNCTION0("category");
303}
304
305void macro_test_functionC() {
306    TRACE_FUNCTION1("category", "my_arg1", 3);
307}
308
309void macro_test_functionD() {
310    TRACE_FUNCTION2("category", "my_arg1", 3, "my_arg2", 4);
311}
312
313TEST_F(MacroTraceEventTest, Function) {
314    {
315        macro_test_functionA();
316        verifications.emplace_back([](const phosphor::TraceEvent &event) {
317            EXPECT_STREQ("macro_test_functionA", event.getName());
318            EXPECT_STREQ("category", event.getCategory());
319            EXPECT_EQ(phosphor::TraceEvent::Type::Complete, event.getType());
320        });
321    }
322    {
323        macro_test_functionC();
324        verifications.emplace_back([](const phosphor::TraceEvent &event) {
325            EXPECT_STREQ("macro_test_functionC", event.getName());
326            EXPECT_STREQ("category", event.getCategory());
327            EXPECT_EQ(phosphor::TraceEvent::Type::Complete, event.getType());
328            EXPECT_EQ(3, event.getArgs()[0].as_int);
329            EXPECT_STREQ("my_arg1", event.getArgNames()[0]);
330        });
331    }
332    {
333        macro_test_functionD();
334        verifications.emplace_back([](const phosphor::TraceEvent &event) {
335            EXPECT_STREQ("macro_test_functionD", event.getName());
336            EXPECT_STREQ("category", event.getCategory());
337            EXPECT_EQ(phosphor::TraceEvent::Type::Complete, event.getType());
338            EXPECT_EQ(3, event.getArgs()[0].as_int);
339            EXPECT_STREQ("my_arg1", event.getArgNames()[0]);
340            EXPECT_EQ(4, event.getArgs()[1].as_int);
341            EXPECT_STREQ("my_arg2", event.getArgNames()[1]);
342        });
343    }
344}
345
346TEST_F(MacroTraceEventTest, Complete) {
347    int variable = 4;
348    const auto start = std::chrono::steady_clock::now();
349    const auto end = start + std::chrono::microseconds(1);
350    TRACE_COMPLETE0("category", "name", start, end);
351    verifications.emplace_back([](const phosphor::TraceEvent& event) {
352        EXPECT_STREQ("name", event.getName());
353        EXPECT_STREQ("category", event.getCategory());
354        EXPECT_EQ(1000, event.getDuration());
355        EXPECT_EQ(phosphor::TraceEvent::Type::Complete, event.getType());
356    });
357
358    TRACE_COMPLETE("category", "name", start, end, 3, variable);
359    verifications.emplace_back([](const phosphor::TraceEvent& event) {
360        EXPECT_STREQ("name", event.getName());
361        EXPECT_STREQ("category", event.getCategory());
362        EXPECT_EQ(phosphor::TraceEvent::Type::Complete, event.getType());
363        EXPECT_EQ(1000, event.getDuration());
364        EXPECT_EQ(3, event.getArgs()[0].as_int);
365        EXPECT_EQ(4, event.getArgs()[1].as_int);
366    });
367
368    TRACE_COMPLETE1("category", "name", start, end, "my_arg1", 3);
369    verifications.emplace_back([](const phosphor::TraceEvent& event) {
370        EXPECT_STREQ("name", event.getName());
371        EXPECT_STREQ("category", event.getCategory());
372        EXPECT_EQ(1000, event.getDuration());
373        EXPECT_EQ(phosphor::TraceEvent::Type::Complete, event.getType());
374        EXPECT_EQ(3, event.getArgs()[0].as_int);
375        EXPECT_STREQ("my_arg1", event.getArgNames()[0]);
376    });
377
378    TRACE_COMPLETE2(
379            "category", "name", start, end, "my_arg1", 3, "my_arg2", variable);
380    verifications.emplace_back([](const phosphor::TraceEvent& event) {
381        EXPECT_STREQ("name", event.getName());
382        EXPECT_STREQ("category", event.getCategory());
383        EXPECT_EQ(1000, event.getDuration());
384        EXPECT_EQ(phosphor::TraceEvent::Type::Complete, event.getType());
385        EXPECT_EQ(3, event.getArgs()[0].as_int);
386        EXPECT_STREQ("my_arg1", event.getArgNames()[0]);
387        EXPECT_EQ(4, event.getArgs()[1].as_int);
388        EXPECT_STREQ("my_arg2", event.getArgNames()[1]);
389    });
390}
391
392TEST_F(MacroTraceEventTest, InlineString) {
393    TRACE_INSTANT("category", "name", PHOSPHOR_INLINE_STR("Hello, World!"));
394    verifications.emplace_back([](const phosphor::TraceEvent& event) {
395        EXPECT_STREQ("name", event.getName());
396        EXPECT_STREQ("category", event.getCategory());
397        EXPECT_EQ(phosphor::TraceEvent::Type::Instant, event.getType());
398        EXPECT_EQ("Hello, W",
399                  std::string(event.getArgs()[0].as_istring));
400    });
401    TRACE_INSTANT("category", "name", PHOSPHOR_INLINE_STR("Hello"));
402    verifications.emplace_back([](const phosphor::TraceEvent& event) {
403        EXPECT_STREQ("name", event.getName());
404        EXPECT_STREQ("category", event.getCategory());
405        EXPECT_EQ(phosphor::TraceEvent::Type::Instant, event.getType());
406        EXPECT_EQ("Hello",
407                  std::string(event.getArgs()[0].as_istring));
408    });
409    TRACE_INSTANT("category", "name", PHOSPHOR_INLINE_STR(""));
410    verifications.emplace_back([](const phosphor::TraceEvent& event) {
411        EXPECT_STREQ("name", event.getName());
412        EXPECT_STREQ("category", event.getCategory());
413        EXPECT_EQ(phosphor::TraceEvent::Type::Instant, event.getType());
414        EXPECT_EQ("",
415                  std::string(event.getArgs()[0].as_istring));
416    });
417}
418
419// Basic smoke test that category filtering works at a macro level,
420// other unit tests should handle the more extensive testing
421TEST_F(MacroTraceEventTest, CategoryFiltering) {
422    TRACE_INSTANT0("excluded", "name");
423    TRACE_INSTANT0("example", "name");
424    verifications.emplace_back([](const phosphor::TraceEvent& event) {
425        EXPECT_STREQ("name", event.getName());
426        EXPECT_STREQ("example", event.getCategory());
427        EXPECT_EQ(phosphor::TraceEvent::Type::Instant, event.getType());
428    });
429    TRACE_INSTANT("excluded", "name", 3, 4);
430    TRACE_INSTANT("example", "name", 3, 4);
431    verifications.emplace_back([](const phosphor::TraceEvent& event) {
432        EXPECT_STREQ("name", event.getName());
433        EXPECT_STREQ("example", event.getCategory());
434        EXPECT_EQ(phosphor::TraceEvent::Type::Instant, event.getType());
435        EXPECT_EQ(3, event.getArgs()[0].as_int);
436        EXPECT_EQ(4, event.getArgs()[1].as_int);
437    });
438}
439