1 //===-- TraceTests.cpp - Tracing unit tests ---------------------*- C++ -*-===//
2 //
3 // Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions.
4 // See https://llvm.org/LICENSE.txt for license information.
5 // SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception
6 //
7 //===----------------------------------------------------------------------===//
8
9 #include "TestTracer.h"
10 #include "support/Trace.h"
11 #include "llvm/ADT/SmallString.h"
12 #include "llvm/ADT/StringRef.h"
13 #include "llvm/Support/SourceMgr.h"
14 #include "llvm/Support/Threading.h"
15 #include "llvm/Support/YAMLParser.h"
16 #include "gmock/gmock.h"
17 #include "gtest/gtest.h"
18
19 namespace clang {
20 namespace clangd {
21 namespace {
22
23 using testing::_;
24 using testing::ElementsAre;
25 using testing::SizeIs;
26 using testing::StartsWith;
27
28 MATCHER_P(stringNode, Val, "") {
29 if (arg->getType() != llvm::yaml::Node::NK_Scalar) {
30 *result_listener << "is a " << arg->getVerbatimTag();
31 return false;
32 }
33 llvm::SmallString<32> S;
34 return Val == static_cast<llvm::yaml::ScalarNode *>(arg)->getValue(S);
35 }
36
37 // Checks that N is a Mapping (JS object) with the expected scalar properties.
38 // The object must have all the Expected properties, but may have others.
verifyObject(llvm::yaml::Node & N,std::map<std::string,std::string> Expected)39 bool verifyObject(llvm::yaml::Node &N,
40 std::map<std::string, std::string> Expected) {
41 auto *M = llvm::dyn_cast<llvm::yaml::MappingNode>(&N);
42 if (!M) {
43 ADD_FAILURE() << "Not an object";
44 return false;
45 }
46 bool Match = true;
47 llvm::SmallString<32> Tmp;
48 for (auto &Prop : *M) {
49 auto *K = llvm::dyn_cast_or_null<llvm::yaml::ScalarNode>(Prop.getKey());
50 if (!K)
51 continue;
52 std::string KS = K->getValue(Tmp).str();
53 auto I = Expected.find(KS);
54 if (I == Expected.end())
55 continue; // Ignore properties with no assertion.
56
57 auto *V = llvm::dyn_cast_or_null<llvm::yaml::ScalarNode>(Prop.getValue());
58 if (!V) {
59 ADD_FAILURE() << KS << " is not a string";
60 Match = false;
61 continue;
62 }
63 std::string VS = V->getValue(Tmp).str();
64 if (VS != I->second) {
65 ADD_FAILURE() << KS << " expected " << I->second << " but actual " << VS;
66 Match = false;
67 }
68 Expected.erase(I);
69 }
70 for (const auto &P : Expected) {
71 ADD_FAILURE() << P.first << " missing, expected " << P.second;
72 Match = false;
73 }
74 return Match;
75 }
76
TEST(TraceTest,SmokeTest)77 TEST(TraceTest, SmokeTest) {
78 // Capture some events.
79 std::string JSON;
80 {
81 llvm::raw_string_ostream OS(JSON);
82 auto JSONTracer = trace::createJSONTracer(OS);
83 trace::Session Session(*JSONTracer);
84 {
85 trace::Span Tracer("A");
86 trace::log("B");
87 }
88 }
89
90 // Get the root JSON object using the YAML parser.
91 llvm::SourceMgr SM;
92 llvm::yaml::Stream Stream(JSON, SM);
93 auto Doc = Stream.begin();
94 ASSERT_NE(Doc, Stream.end());
95 auto *Root = llvm::dyn_cast_or_null<llvm::yaml::MappingNode>(Doc->getRoot());
96 ASSERT_NE(Root, nullptr) << "Root should be an object";
97
98 // Check whether we expect thread name events on this platform.
99 llvm::SmallString<32> ThreadName;
100 get_thread_name(ThreadName);
101 bool ThreadsHaveNames = !ThreadName.empty();
102
103 // We expect in order:
104 // displayTimeUnit: "ns"
105 // traceEvents: [process name, thread name, start span, log, end span]
106 // (The order doesn't matter, but the YAML parser is awkward to use otherwise)
107 auto Prop = Root->begin();
108 ASSERT_NE(Prop, Root->end()) << "Expected displayTimeUnit property";
109 ASSERT_THAT(Prop->getKey(), stringNode("displayTimeUnit"));
110 EXPECT_THAT(Prop->getValue(), stringNode("ns"));
111 ASSERT_NE(++Prop, Root->end()) << "Expected traceEvents property";
112 EXPECT_THAT(Prop->getKey(), stringNode("traceEvents"));
113 auto *Events =
114 llvm::dyn_cast_or_null<llvm::yaml::SequenceNode>(Prop->getValue());
115 ASSERT_NE(Events, nullptr) << "traceEvents should be an array";
116 auto Event = Events->begin();
117 ASSERT_NE(Event, Events->end()) << "Expected process name";
118 EXPECT_TRUE(verifyObject(*Event, {{"ph", "M"}, {"name", "process_name"}}));
119 if (ThreadsHaveNames) {
120 ASSERT_NE(++Event, Events->end()) << "Expected thread name";
121 EXPECT_TRUE(verifyObject(*Event, {{"ph", "M"}, {"name", "thread_name"}}));
122 }
123 ASSERT_NE(++Event, Events->end()) << "Expected log message";
124 EXPECT_TRUE(verifyObject(*Event, {{"ph", "i"}, {"name", "Log"}}));
125 ASSERT_NE(++Event, Events->end()) << "Expected span end";
126 EXPECT_TRUE(verifyObject(*Event, {{"ph", "X"}, {"name", "A"}}));
127 ASSERT_EQ(++Event, Events->end());
128 ASSERT_EQ(++Prop, Root->end());
129 }
130
TEST(MetricsTracer,LatencyTest)131 TEST(MetricsTracer, LatencyTest) {
132 trace::TestTracer Tracer;
133 constexpr llvm::StringLiteral MetricName = "span_latency";
134 constexpr llvm::StringLiteral OpName = "op_name";
135 {
136 // A span should record latencies to span_latency by default.
137 trace::Span SpanWithLat(OpName);
138 EXPECT_THAT(Tracer.takeMetric(MetricName, OpName), SizeIs(0));
139 }
140 EXPECT_THAT(Tracer.takeMetric(MetricName, OpName), SizeIs(1));
141 }
142
143 class CSVMetricsTracerTest : public ::testing::Test {
144 protected:
CSVMetricsTracerTest()145 CSVMetricsTracerTest()
146 : OS(Output), Tracer(trace::createCSVMetricTracer(OS)), Session(*Tracer) {
147 }
148 trace::Metric Dist = {"dist", trace::Metric::Distribution, "lbl"};
149 trace::Metric Counter = {"cnt", trace::Metric::Counter};
150
outputLines()151 std::vector<std::string> outputLines() {
152 // Deliberately don't flush output stream, the tracer should do that.
153 // This is important when clangd crashes.
154 llvm::SmallVector<llvm::StringRef> Lines;
155 llvm::StringRef(Output).split(Lines, "\r\n");
156 return {Lines.begin(), Lines.end()};
157 }
158
159 std::string Output;
160 llvm::raw_string_ostream OS;
161 std::unique_ptr<trace::EventTracer> Tracer;
162 trace::Session Session;
163 };
164
TEST_F(CSVMetricsTracerTest,RecordsValues)165 TEST_F(CSVMetricsTracerTest, RecordsValues) {
166 Dist.record(1, "x");
167 Counter.record(1, "");
168 Dist.record(2, "y");
169
170 ASSERT_THAT(outputLines(),
171 ElementsAre("Kind,Metric,Label,Value,Timestamp",
172 StartsWith("d,dist,x,1.000000e+00,"),
173 StartsWith("c,cnt,,1.000000e+00,"),
174 StartsWith("d,dist,y,2.000000e+00,"), ""));
175 }
176
TEST_F(CSVMetricsTracerTest,Escaping)177 TEST_F(CSVMetricsTracerTest, Escaping) {
178 Dist.record(1, ",");
179 Dist.record(1, "a\"b");
180 Dist.record(1, "a\nb");
181
182 EXPECT_THAT(outputLines(), ElementsAre(_, StartsWith(R"(d,dist,",",1)"),
183 StartsWith(R"(d,dist,"a""b",1)"),
184 StartsWith("d,dist,\"a\nb\",1"), ""));
185 }
186
TEST_F(CSVMetricsTracerTest,IgnoresArgs)187 TEST_F(CSVMetricsTracerTest, IgnoresArgs) {
188 trace::Span Tracer("Foo");
189 EXPECT_EQ(nullptr, Tracer.Args);
190 }
191
192 } // namespace
193 } // namespace clangd
194 } // namespace clang
195