blob: 781d6728f691a12ef239ee55c9bee465b8ee2185 [file] [log] [blame]
Primiano Tucci4f9b6d72017-12-05 20:59:16 +00001/*
2 * Copyright (C) 2017 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 * http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16
Florian Mayer6a1a4d52018-06-08 16:47:07 +010017#include "src/tracing/core/tracing_service_impl.h"
Primiano Tucci4f9b6d72017-12-05 20:59:16 +000018
19#include <string.h>
20
21#include "gmock/gmock.h"
22#include "gtest/gtest.h"
Primiano Tucci2ffd1a52018-03-27 01:01:30 +010023#include "perfetto/base/file_utils.h"
24#include "perfetto/base/temp_file.h"
Primiano Tucci1a1951d2018-04-04 21:08:16 +020025#include "perfetto/base/utils.h"
Sami Kyostila06487a22018-02-27 13:48:38 +000026#include "perfetto/tracing/core/consumer.h"
Primiano Tucci4f9b6d72017-12-05 20:59:16 +000027#include "perfetto/tracing/core/data_source_config.h"
28#include "perfetto/tracing/core/data_source_descriptor.h"
29#include "perfetto/tracing/core/producer.h"
30#include "perfetto/tracing/core/shared_memory.h"
Sami Kyostila06487a22018-02-27 13:48:38 +000031#include "perfetto/tracing/core/trace_packet.h"
Primiano Tucci2ffd1a52018-03-27 01:01:30 +010032#include "perfetto/tracing/core/trace_writer.h"
Primiano Tucci4f9b6d72017-12-05 20:59:16 +000033#include "src/base/test/test_task_runner.h"
Eric Secklera01e28a2019-01-08 11:21:04 +000034#include "src/tracing/core/shared_memory_arbiter_impl.h"
Eric Secklerf3f524b2018-12-13 09:09:34 +000035#include "src/tracing/core/trace_writer_impl.h"
Primiano Tuccidca727d2018-04-04 11:31:55 +020036#include "src/tracing/test/mock_consumer.h"
37#include "src/tracing/test/mock_producer.h"
Primiano Tucci4f9b6d72017-12-05 20:59:16 +000038#include "src/tracing/test/test_shared_memory.h"
39
Primiano Tucci2ffd1a52018-03-27 01:01:30 +010040#include "perfetto/trace/test_event.pbzero.h"
41#include "perfetto/trace/trace.pb.h"
Primiano Tuccidca727d2018-04-04 11:31:55 +020042#include "perfetto/trace/trace_packet.pb.h"
Primiano Tucci2ffd1a52018-03-27 01:01:30 +010043#include "perfetto/trace/trace_packet.pbzero.h"
44
Primiano Tucci4f9b6d72017-12-05 20:59:16 +000045using ::testing::_;
Primiano Tuccidca727d2018-04-04 11:31:55 +020046using ::testing::Contains;
Primiano Tucci1a1951d2018-04-04 21:08:16 +020047using ::testing::ElementsAreArray;
Primiano Tuccidca727d2018-04-04 11:31:55 +020048using ::testing::Eq;
Primiano Tucci4f9b6d72017-12-05 20:59:16 +000049using ::testing::InSequence;
Primiano Tucci081d46a2018-02-28 11:09:43 +000050using ::testing::Invoke;
Primiano Tuccidca727d2018-04-04 11:31:55 +020051using ::testing::InvokeWithoutArgs;
Primiano Tucci4f9b6d72017-12-05 20:59:16 +000052using ::testing::Mock;
Eric Secklerdd0ad102018-12-06 11:32:04 +000053using ::testing::Not;
Primiano Tuccidca727d2018-04-04 11:31:55 +020054using ::testing::Property;
55using ::testing::StrictMock;
Primiano Tucci4f9b6d72017-12-05 20:59:16 +000056
Primiano Tuccidca727d2018-04-04 11:31:55 +020057namespace perfetto {
Sami Kyostila32e0b542018-02-14 08:55:43 +000058
Primiano Tucci1a1951d2018-04-04 21:08:16 +020059namespace {
Florian Mayer6a1a4d52018-06-08 16:47:07 +010060constexpr size_t kDefaultShmSizeKb = TracingServiceImpl::kDefaultShmSize / 1024;
61constexpr size_t kMaxShmSizeKb = TracingServiceImpl::kMaxShmSize / 1024;
Stephen Nusko1393ffd2019-03-22 13:54:58 +000062
63::testing::AssertionResult HasTriggerModeInternal(
64 const std::vector<protos::TracePacket>& packets,
65 protos::TraceConfig::TriggerConfig::TriggerMode mode) {
66 ::testing::StringMatchResultListener matcher_result_string;
67 bool contains = ::testing::ExplainMatchResult(
68 Contains(Property(
69 &protos::TracePacket::trace_config,
70 Property(&protos::TraceConfig::trigger_config,
71 Property(&protos::TraceConfig::TriggerConfig::trigger_mode,
72 Eq(mode))))),
73 packets, &matcher_result_string);
74 if (contains) {
75 return ::testing::AssertionSuccess();
76 }
77 return ::testing::AssertionFailure() << matcher_result_string.str();
78}
79
80MATCHER_P(HasTriggerMode, mode, "") {
81 return HasTriggerModeInternal(arg, mode);
82}
83
Primiano Tucci1a1951d2018-04-04 21:08:16 +020084} // namespace
85
Florian Mayer6a1a4d52018-06-08 16:47:07 +010086class TracingServiceImplTest : public testing::Test {
Sami Kyostila06487a22018-02-27 13:48:38 +000087 public:
Eric Seckler4ff03e52019-03-15 10:10:30 +000088 using DataSourceInstanceState =
89 TracingServiceImpl::DataSourceInstance::DataSourceInstanceState;
90
Florian Mayer6a1a4d52018-06-08 16:47:07 +010091 TracingServiceImplTest() {
Sami Kyostila06487a22018-02-27 13:48:38 +000092 auto shm_factory =
93 std::unique_ptr<SharedMemory::Factory>(new TestSharedMemory::Factory());
Florian Mayer6a1a4d52018-06-08 16:47:07 +010094 svc.reset(static_cast<TracingServiceImpl*>(
95 TracingService::CreateInstance(std::move(shm_factory), &task_runner)
Sami Kyostila06487a22018-02-27 13:48:38 +000096 .release()));
Primiano Tucci9754d0d2018-09-15 12:41:46 +010097 svc->min_write_period_ms_ = 1;
Sami Kyostila06487a22018-02-27 13:48:38 +000098 }
99
Primiano Tuccidca727d2018-04-04 11:31:55 +0200100 std::unique_ptr<MockProducer> CreateMockProducer() {
101 return std::unique_ptr<MockProducer>(
102 new StrictMock<MockProducer>(&task_runner));
103 }
104
105 std::unique_ptr<MockConsumer> CreateMockConsumer() {
106 return std::unique_ptr<MockConsumer>(
107 new StrictMock<MockConsumer>(&task_runner));
108 }
109
Primiano Tucci1a1951d2018-04-04 21:08:16 +0200110 ProducerID* last_producer_id() { return &svc->last_producer_id_; }
111
112 uid_t GetProducerUid(ProducerID producer_id) {
113 return svc->GetProducer(producer_id)->uid_;
114 }
115
Stephen Nusko1393ffd2019-03-22 13:54:58 +0000116 TracingServiceImpl::TracingSession* GetTracingSession(TracingSessionID tsid) {
117 auto* session = svc->GetTracingSession(tsid);
Primiano Tucci9754d0d2018-09-15 12:41:46 +0100118 EXPECT_NE(nullptr, session);
119 return session;
120 }
121
Stephen Nusko1393ffd2019-03-22 13:54:58 +0000122 TracingServiceImpl::TracingSession* tracing_session() {
123 return GetTracingSession(GetTracingSessionID());
124 }
125
126 TracingSessionID GetTracingSessionID() {
127 return svc->last_tracing_session_id_;
128 }
129
Eric Seckler6dc23592018-11-30 10:59:06 +0000130 const std::set<BufferID>& GetAllowedTargetBuffers(ProducerID producer_id) {
131 return svc->GetProducer(producer_id)->allowed_target_buffers_;
132 }
133
Eric Secklerf3f524b2018-12-13 09:09:34 +0000134 const std::map<WriterID, BufferID>& GetWriters(ProducerID producer_id) {
135 return svc->GetProducer(producer_id)->writers_;
136 }
137
Eric Secklera01e28a2019-01-08 11:21:04 +0000138 std::unique_ptr<SharedMemoryArbiterImpl> TakeShmemArbiterForProducer(
139 ProducerID producer_id) {
140 return std::move(svc->GetProducer(producer_id)->inproc_shmem_arbiter_);
141 }
142
Primiano Tuccid52e6272018-04-06 19:06:53 +0200143 size_t GetNumPendingFlushes() {
Primiano Tucci9754d0d2018-09-15 12:41:46 +0100144 return tracing_session()->pending_flushes.size();
145 }
146
147 void WaitForNextSyncMarker() {
148 tracing_session()->last_snapshot_time = base::TimeMillis(0);
149 static int attempt = 0;
150 while (tracing_session()->last_snapshot_time == base::TimeMillis(0)) {
151 auto checkpoint_name = "wait_snapshot_" + std::to_string(attempt++);
152 auto timer_expired = task_runner.CreateCheckpoint(checkpoint_name);
153 task_runner.PostDelayedTask([timer_expired] { timer_expired(); }, 1);
154 task_runner.RunUntilCheckpoint(checkpoint_name);
155 }
Primiano Tuccid52e6272018-04-06 19:06:53 +0200156 }
157
Eric Secklerf3f524b2018-12-13 09:09:34 +0000158 void WaitForTraceWritersChanged(ProducerID producer_id) {
159 static int i = 0;
160 auto checkpoint_name = "writers_changed_" + std::to_string(producer_id) +
161 "_" + std::to_string(i++);
162 auto writers_changed = task_runner.CreateCheckpoint(checkpoint_name);
163 auto writers = GetWriters(producer_id);
164 std::function<void()> task;
165 task = [&task, writers, writers_changed, producer_id, this]() {
166 if (writers != GetWriters(producer_id)) {
167 writers_changed();
168 return;
169 }
170 task_runner.PostDelayedTask(task, 1);
171 };
172 task_runner.PostDelayedTask(task, 1);
173 task_runner.RunUntilCheckpoint(checkpoint_name);
174 }
175
Eric Seckler4ff03e52019-03-15 10:10:30 +0000176 DataSourceInstanceState GetDataSourceInstanceState(const std::string& name) {
177 for (const auto& kv : tracing_session()->data_source_instances) {
178 if (kv.second.data_source_name == name)
179 return kv.second.state;
180 }
181 PERFETTO_FATAL("Can't find data source instance with name %s",
182 name.c_str());
183 }
184
Primiano Tucci4f9b6d72017-12-05 20:59:16 +0000185 base::TestTaskRunner task_runner;
Florian Mayer6a1a4d52018-06-08 16:47:07 +0100186 std::unique_ptr<TracingServiceImpl> svc;
Sami Kyostila06487a22018-02-27 13:48:38 +0000187};
188
Florian Mayer6a1a4d52018-06-08 16:47:07 +0100189TEST_F(TracingServiceImplTest, RegisterAndUnregister) {
Primiano Tuccidca727d2018-04-04 11:31:55 +0200190 std::unique_ptr<MockProducer> mock_producer_1 = CreateMockProducer();
191 std::unique_ptr<MockProducer> mock_producer_2 = CreateMockProducer();
Primiano Tucci4f9b6d72017-12-05 20:59:16 +0000192
Primiano Tuccidca727d2018-04-04 11:31:55 +0200193 mock_producer_1->Connect(svc.get(), "mock_producer_1", 123u /* uid */);
194 mock_producer_2->Connect(svc.get(), "mock_producer_2", 456u /* uid */);
Primiano Tucci4f9b6d72017-12-05 20:59:16 +0000195
196 ASSERT_EQ(2u, svc->num_producers());
Primiano Tuccidca727d2018-04-04 11:31:55 +0200197 ASSERT_EQ(mock_producer_1->endpoint(), svc->GetProducer(1));
198 ASSERT_EQ(mock_producer_2->endpoint(), svc->GetProducer(2));
Primiano Tucci1a1951d2018-04-04 21:08:16 +0200199 ASSERT_EQ(123u, GetProducerUid(1));
200 ASSERT_EQ(456u, GetProducerUid(2));
Primiano Tucci4f9b6d72017-12-05 20:59:16 +0000201
Primiano Tuccidca727d2018-04-04 11:31:55 +0200202 mock_producer_1->RegisterDataSource("foo");
203 mock_producer_2->RegisterDataSource("bar");
Primiano Tucci4f9b6d72017-12-05 20:59:16 +0000204
Primiano Tuccidca727d2018-04-04 11:31:55 +0200205 mock_producer_1->UnregisterDataSource("foo");
206 mock_producer_2->UnregisterDataSource("bar");
Primiano Tucci9daa4832018-03-28 23:28:17 +0100207
Primiano Tuccidca727d2018-04-04 11:31:55 +0200208 mock_producer_1.reset();
Primiano Tucci4f9b6d72017-12-05 20:59:16 +0000209 ASSERT_EQ(1u, svc->num_producers());
210 ASSERT_EQ(nullptr, svc->GetProducer(1));
211
Primiano Tuccidca727d2018-04-04 11:31:55 +0200212 mock_producer_2.reset();
213 ASSERT_EQ(nullptr, svc->GetProducer(2));
Primiano Tucci4f9b6d72017-12-05 20:59:16 +0000214
215 ASSERT_EQ(0u, svc->num_producers());
216}
Primiano Tucci2ffd1a52018-03-27 01:01:30 +0100217
Florian Mayer6a1a4d52018-06-08 16:47:07 +0100218TEST_F(TracingServiceImplTest, EnableAndDisableTracing) {
Primiano Tuccidca727d2018-04-04 11:31:55 +0200219 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
220 consumer->Connect(svc.get());
Sami Kyostila06487a22018-02-27 13:48:38 +0000221
Primiano Tuccidca727d2018-04-04 11:31:55 +0200222 std::unique_ptr<MockProducer> producer = CreateMockProducer();
223 producer->Connect(svc.get(), "mock_producer");
224 producer->RegisterDataSource("data_source");
Sami Kyostila06487a22018-02-27 13:48:38 +0000225
Sami Kyostila06487a22018-02-27 13:48:38 +0000226 TraceConfig trace_config;
Primiano Tuccidca727d2018-04-04 11:31:55 +0200227 trace_config.add_buffers()->set_size_kb(128);
Sami Kyostila06487a22018-02-27 13:48:38 +0000228 auto* ds_config = trace_config.add_data_sources()->mutable_config();
Primiano Tuccidca727d2018-04-04 11:31:55 +0200229 ds_config->set_name("data_source");
230 consumer->EnableTracing(trace_config);
Sami Kyostila06487a22018-02-27 13:48:38 +0000231
Primiano Tuccidca727d2018-04-04 11:31:55 +0200232 producer->WaitForTracingSetup();
Primiano Tucci674076d2018-10-01 10:41:09 +0100233 producer->WaitForDataSourceSetup("data_source");
Primiano Tuccidca727d2018-04-04 11:31:55 +0200234 producer->WaitForDataSourceStart("data_source");
235
Primiano Tucci674076d2018-10-01 10:41:09 +0100236 // Calling StartTracing() should be a noop (% a DLOG statement) because the
237 // trace config didn't have the |deferred_start| flag set.
238 consumer->StartTracing();
239
Primiano Tuccidca727d2018-04-04 11:31:55 +0200240 consumer->DisableTracing();
241 producer->WaitForDataSourceStop("data_source");
242 consumer->WaitForTracingDisabled();
Sami Kyostila06487a22018-02-27 13:48:38 +0000243}
244
Stephen Nusko1393ffd2019-03-22 13:54:58 +0000245// Creates a tracing session with a START_TRACING trigger and checks that data
246// sources are started only after the service receives a trigger.
247TEST_F(TracingServiceImplTest, StartTracingTriggerDeferredStart) {
248 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
249 consumer->Connect(svc.get());
250
251 std::unique_ptr<MockProducer> producer = CreateMockProducer();
252 producer->Connect(svc.get(), "mock_producer");
253
254 // Create two data sources but enable only one of them.
255 producer->RegisterDataSource("ds_1");
256 producer->RegisterDataSource("ds_2");
257
258 TraceConfig trace_config;
259 trace_config.add_buffers()->set_size_kb(128);
260 trace_config.add_data_sources()->mutable_config()->set_name("ds_1");
261 auto* trigger_config = trace_config.mutable_trigger_config();
262 trigger_config->set_trigger_mode(TraceConfig::TriggerConfig::START_TRACING);
263 auto* trigger = trigger_config->add_triggers();
264 trigger->set_name("trigger_name");
265 trigger->set_stop_delay_ms(1);
266
267 trigger_config->set_trigger_timeout_ms(8.64e+7);
268
269 // Make sure we don't get unexpected DataSourceStart() notifications yet.
270 EXPECT_CALL(*producer, StartDataSource(_, _)).Times(0);
271
272 consumer->EnableTracing(trace_config);
273 producer->WaitForTracingSetup();
274
275 producer->WaitForDataSourceSetup("ds_1");
276
277 // The trace won't start until we send the trigger. since we have a
278 // START_TRACING trigger defined.
279 std::vector<std::string> req;
280 req.push_back("trigger_name");
281 producer->endpoint()->ActivateTriggers(req);
282
283 producer->WaitForDataSourceStart("ds_1");
284
285 auto writer1 = producer->CreateTraceWriter("ds_1");
286 producer->WaitForFlush(writer1.get());
287
288 producer->WaitForDataSourceStop("ds_1");
289 consumer->WaitForTracingDisabled();
290
291 ASSERT_EQ(1u, tracing_session()->received_triggers.size());
292 EXPECT_EQ("trigger_name",
Stephen Nusko70ea3302019-04-01 19:44:40 +0100293 tracing_session()->received_triggers[0].trigger_name);
Stephen Nusko1393ffd2019-03-22 13:54:58 +0000294
295 EXPECT_THAT(
296 consumer->ReadBuffers(),
297 HasTriggerMode(protos::TraceConfig::TriggerConfig::START_TRACING));
298}
299
300// Creates a tracing session with a START_TRACING trigger and checks that the
301// session is cleaned up when no trigger is received after |trigger_timeout_ms|.
302TEST_F(TracingServiceImplTest, StartTracingTriggerTimeOut) {
303 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
304 consumer->Connect(svc.get());
305
306 std::unique_ptr<MockProducer> producer = CreateMockProducer();
307 producer->Connect(svc.get(), "mock_producer");
308
309 // Create two data sources but enable only one of them.
310 producer->RegisterDataSource("ds_1");
311 producer->RegisterDataSource("ds_2");
312
313 TraceConfig trace_config;
314 trace_config.add_buffers()->set_size_kb(128);
315 trace_config.add_data_sources()->mutable_config()->set_name("ds_1");
316 auto* trigger_config = trace_config.mutable_trigger_config();
317 trigger_config->set_trigger_mode(TraceConfig::TriggerConfig::START_TRACING);
318 auto* trigger = trigger_config->add_triggers();
319 trigger->set_name("trigger_name");
320 trigger->set_stop_delay_ms(8.64e+7);
321
322 trigger_config->set_trigger_timeout_ms(1);
323
324 // Make sure we don't get unexpected DataSourceStart() notifications yet.
325 EXPECT_CALL(*producer, StartDataSource(_, _)).Times(0);
326
327 consumer->EnableTracing(trace_config);
328 producer->WaitForTracingSetup();
329
330 producer->WaitForDataSourceSetup("ds_1");
331
332 // The trace won't start until we send the trigger. since we have a
333 // START_TRACING trigger defined. This is where we'd expect to have an
334 // ActivateTriggers call to the producer->endpoint().
335
336 producer->WaitForDataSourceStop("ds_1");
337 consumer->WaitForTracingDisabled();
338 EXPECT_THAT(consumer->ReadBuffers(), ::testing::IsEmpty());
339}
340
341// Creates a tracing session with a START_TRACING trigger and checks that
342// the session is not started when the configured trigger producer is different
343// than the producer that sent the trigger.
344TEST_F(TracingServiceImplTest, StartTracingTriggerDifferentProducer) {
345 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
346 consumer->Connect(svc.get());
347
348 std::unique_ptr<MockProducer> producer = CreateMockProducer();
349 producer->Connect(svc.get(), "mock_producer");
350
351 // Create two data sources but enable only one of them.
352 producer->RegisterDataSource("ds_1");
353 producer->RegisterDataSource("ds_2");
354
355 TraceConfig trace_config;
356 trace_config.add_buffers()->set_size_kb(128);
357 trace_config.add_data_sources()->mutable_config()->set_name("ds_1");
358 auto* trigger_config = trace_config.mutable_trigger_config();
359 trigger_config->set_trigger_mode(TraceConfig::TriggerConfig::START_TRACING);
360 auto* trigger = trigger_config->add_triggers();
361 trigger->set_name("trigger_name");
362 trigger->set_stop_delay_ms(8.64e+7);
363 trigger->set_producer_name_regex("correct_name");
364
365 trigger_config->set_trigger_timeout_ms(1);
366
367 // Make sure we don't get unexpected DataSourceStart() notifications yet.
368 EXPECT_CALL(*producer, StartDataSource(_, _)).Times(0);
369
370 consumer->EnableTracing(trace_config);
371 producer->WaitForTracingSetup();
372
373 producer->WaitForDataSourceSetup("ds_1");
374
375 // The trace won't start until we send the trigger called "trigger_name"
376 // coming from a producer called "correct_name", since we have a
377 // START_TRACING trigger defined. This is where we'd expect to have an
378 // ActivateTriggers call to the producer->endpoint(), but we send the trigger
379 // from a different producer so it is ignored.
380 std::vector<std::string> req;
381 req.push_back("trigger_name");
382 producer->endpoint()->ActivateTriggers(req);
383
384 producer->WaitForDataSourceStop("ds_1");
385 consumer->WaitForTracingDisabled();
386 EXPECT_THAT(consumer->ReadBuffers(), ::testing::IsEmpty());
387}
388
389// Creates a tracing session with a START_TRACING trigger and checks that the
390// session is started when the trigger is received from the correct producer.
391TEST_F(TracingServiceImplTest, StartTracingTriggerCorrectProducer) {
392 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
393 consumer->Connect(svc.get());
394
395 std::unique_ptr<MockProducer> producer = CreateMockProducer();
396 producer->Connect(svc.get(), "mock_producer");
397
398 // Create two data sources but enable only one of them.
399 producer->RegisterDataSource("ds_1");
400 producer->RegisterDataSource("ds_2");
401
402 TraceConfig trace_config;
403 trace_config.add_buffers()->set_size_kb(128);
404 trace_config.add_data_sources()->mutable_config()->set_name("ds_1");
405 auto* trigger_config = trace_config.mutable_trigger_config();
406 trigger_config->set_trigger_mode(TraceConfig::TriggerConfig::START_TRACING);
407 auto* trigger = trigger_config->add_triggers();
408 trigger->set_name("trigger_name");
409 trigger->set_stop_delay_ms(1);
410 trigger->set_producer_name_regex("mock_produc[e-r]+");
411
412 trigger_config->set_trigger_timeout_ms(8.64e+7);
413
414 consumer->EnableTracing(trace_config);
415 producer->WaitForTracingSetup();
416
417 producer->WaitForDataSourceSetup("ds_1");
418
419 // Start the trace at this point with ActivateTriggers.
420 std::vector<std::string> req;
421 req.push_back("trigger_name");
422 producer->endpoint()->ActivateTriggers(req);
423
424 producer->WaitForDataSourceStart("ds_1");
425
426 auto writer = producer->CreateTraceWriter("ds_1");
427 producer->WaitForFlush(writer.get());
428
429 producer->WaitForDataSourceStop("ds_1");
430 consumer->WaitForTracingDisabled();
431 EXPECT_THAT(
432 consumer->ReadBuffers(),
433 HasTriggerMode(protos::TraceConfig::TriggerConfig::START_TRACING));
434}
435
436// Creates a tracing session with a START_TRACING trigger and checks that the
437// session is cleaned up even when a different trigger is received.
438TEST_F(TracingServiceImplTest, StartTracingTriggerDifferentTrigger) {
439 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
440 consumer->Connect(svc.get());
441
442 std::unique_ptr<MockProducer> producer = CreateMockProducer();
443 producer->Connect(svc.get(), "mock_producer");
444
445 // Create two data sources but enable only one of them.
446 producer->RegisterDataSource("ds_1");
447 producer->RegisterDataSource("ds_2");
448
449 TraceConfig trace_config;
450 trace_config.add_buffers()->set_size_kb(128);
451 trace_config.add_data_sources()->mutable_config()->set_name("ds_1");
452 auto* trigger_config = trace_config.mutable_trigger_config();
453 trigger_config->set_trigger_mode(TraceConfig::TriggerConfig::START_TRACING);
454 auto* trigger = trigger_config->add_triggers();
455 trigger->set_name("trigger_name");
456 trigger->set_stop_delay_ms(8.64e+7);
457
458 trigger_config->set_trigger_timeout_ms(1);
459
460 // Make sure we don't get unexpected DataSourceStart() notifications yet.
461 EXPECT_CALL(*producer, StartDataSource(_, _)).Times(0);
462
463 consumer->EnableTracing(trace_config);
464 producer->WaitForTracingSetup();
465
466 producer->WaitForDataSourceSetup("ds_1");
467
468 // The trace won't start until we send the trigger called "trigger_name",
469 // since we have a START_TRACING trigger defined. This is where we'd expect to
470 // have an ActivateTriggers call to the producer->endpoint(), but we send a
471 // different trigger.
472 std::vector<std::string> req;
473 req.push_back("not_correct_trigger");
474 producer->endpoint()->ActivateTriggers(req);
475
476 producer->WaitForDataSourceStop("ds_1");
477 consumer->WaitForTracingDisabled();
478 EXPECT_THAT(consumer->ReadBuffers(), ::testing::IsEmpty());
479}
480
481// Creates a tracing session with a START_TRACING trigger and checks that any
482// trigger can start the TracingSession.
483TEST_F(TracingServiceImplTest, StartTracingTriggerMultipleTriggers) {
484 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
485 consumer->Connect(svc.get());
486
487 std::unique_ptr<MockProducer> producer = CreateMockProducer();
488 producer->Connect(svc.get(), "mock_producer");
489
490 // Create two data sources but enable only one of them.
491 producer->RegisterDataSource("ds_1");
492 producer->RegisterDataSource("ds_2");
493
494 TraceConfig trace_config;
495 trace_config.add_buffers()->set_size_kb(128);
496 trace_config.add_data_sources()->mutable_config()->set_name("ds_1");
497 auto* trigger_config = trace_config.mutable_trigger_config();
498 trigger_config->set_trigger_mode(TraceConfig::TriggerConfig::START_TRACING);
499 auto* trigger = trigger_config->add_triggers();
500 trigger->set_name("trigger_name");
501 trigger->set_stop_delay_ms(1);
502
503 trigger_config->set_trigger_timeout_ms(8.64e+7);
504
505 consumer->EnableTracing(trace_config);
506 producer->WaitForTracingSetup();
507
508 producer->WaitForDataSourceSetup("ds_1");
509
Stephen Nusko1393ffd2019-03-22 13:54:58 +0000510 std::vector<std::string> req;
511 req.push_back("not_correct_trigger");
512 req.push_back("trigger_name");
513 producer->endpoint()->ActivateTriggers(req);
514
515 producer->WaitForDataSourceStart("ds_1");
516
517 auto writer = producer->CreateTraceWriter("ds_1");
518 producer->WaitForFlush(writer.get());
519
520 producer->WaitForDataSourceStop("ds_1");
521 consumer->WaitForTracingDisabled();
522 EXPECT_THAT(
523 consumer->ReadBuffers(),
524 HasTriggerMode(protos::TraceConfig::TriggerConfig::START_TRACING));
525}
526
527// Creates two tracing sessions with a START_TRACING trigger and checks that
528// both are able to be triggered simultaneously.
529TEST_F(TracingServiceImplTest, StartTracingTriggerMultipleTraces) {
530 std::unique_ptr<MockConsumer> consumer_1 = CreateMockConsumer();
531 consumer_1->Connect(svc.get());
532 std::unique_ptr<MockConsumer> consumer_2 = CreateMockConsumer();
533 consumer_2->Connect(svc.get());
534
535 std::unique_ptr<MockProducer> producer = CreateMockProducer();
536 producer->Connect(svc.get(), "mock_producer");
537
538 // Create two data sources but each TracingSession will only enable one of
539 // them.
540 producer->RegisterDataSource("ds_1");
541 producer->RegisterDataSource("ds_2");
542
543 TraceConfig trace_config;
544 trace_config.add_buffers()->set_size_kb(128);
545 trace_config.add_data_sources()->mutable_config()->set_name("ds_1");
546 auto* trigger_config = trace_config.mutable_trigger_config();
547 trigger_config->set_trigger_mode(TraceConfig::TriggerConfig::START_TRACING);
548 auto* trigger = trigger_config->add_triggers();
549 trigger->set_name("trigger_name");
550 trigger->set_stop_delay_ms(1);
551
552 trigger_config->set_trigger_timeout_ms(8.64e+7);
553
554 consumer_1->EnableTracing(trace_config);
555 producer->WaitForTracingSetup();
556
557 producer->WaitForDataSourceSetup("ds_1");
558
Stephen Nusko1393ffd2019-03-22 13:54:58 +0000559 auto tracing_session_1_id = GetTracingSessionID();
560
561 (*trace_config.mutable_data_sources())[0].mutable_config()->set_name("ds_2");
562 trigger = trace_config.mutable_trigger_config()->add_triggers();
563 trigger->set_name("trigger_name_2");
564 trigger->set_stop_delay_ms(8.64e+7);
565
566 consumer_2->EnableTracing(trace_config);
567
568 producer->WaitForDataSourceSetup("ds_2");
569
Stephen Nusko1393ffd2019-03-22 13:54:58 +0000570 auto tracing_session_2_id = GetTracingSessionID();
571 EXPECT_NE(tracing_session_1_id, tracing_session_2_id);
572
573 const DataSourceInstanceID id1 = producer->GetDataSourceInstanceId("ds_1");
574 const DataSourceInstanceID id2 = producer->GetDataSourceInstanceId("ds_2");
575
576 std::vector<std::string> req;
577 req.push_back("not_correct_trigger");
578 req.push_back("trigger_name");
579 req.push_back("trigger_name_2");
580 producer->endpoint()->ActivateTriggers(req);
581
582 // The order has to be the same as the triggers or else we're incorrectly wait
583 // on the wrong checkpoint in the |task_runner|.
584 producer->WaitForDataSourceStart("ds_1");
585 producer->WaitForDataSourceStart("ds_2");
586
587 // Now that they've started we can check the triggers they've seen.
588 auto* tracing_session_1 = GetTracingSession(tracing_session_1_id);
589 ASSERT_EQ(1u, tracing_session_1->received_triggers.size());
590 EXPECT_EQ("trigger_name",
Stephen Nusko70ea3302019-04-01 19:44:40 +0100591 tracing_session_1->received_triggers[0].trigger_name);
Stephen Nusko1393ffd2019-03-22 13:54:58 +0000592
593 // This is actually dependent on the order in which the triggers were received
594 // but there isn't really a better way than iteration order so probably not to
595 // brittle of a test. And this caught a real bug in implementation.
596 auto* tracing_session_2 = GetTracingSession(tracing_session_2_id);
597 ASSERT_EQ(2u, tracing_session_2->received_triggers.size());
598
599 EXPECT_EQ("trigger_name",
Stephen Nusko70ea3302019-04-01 19:44:40 +0100600 tracing_session_2->received_triggers[0].trigger_name);
Stephen Nusko1393ffd2019-03-22 13:54:58 +0000601
602 EXPECT_EQ("trigger_name_2",
Stephen Nusko70ea3302019-04-01 19:44:40 +0100603 tracing_session_2->received_triggers[1].trigger_name);
Stephen Nusko1393ffd2019-03-22 13:54:58 +0000604
605 auto writer1 = producer->CreateTraceWriter("ds_1");
606 auto writer2 = producer->CreateTraceWriter("ds_2");
607
608 // We can't use the standard WaitForX in the MockProducer and MockConsumer
609 // because they assume only a single trace is going on. So we perform our own
610 // expectations and wait at the end for the two consumers to receive
611 // OnTracingDisabled.
612 bool flushed_writer_1 = false;
613 bool flushed_writer_2 = false;
614 auto flush_correct_writer = [&](FlushRequestID flush_req_id,
615 const DataSourceInstanceID* id, size_t) {
616 if (*id == id1) {
617 flushed_writer_1 = true;
618 writer1->Flush();
619 producer->endpoint()->NotifyFlushComplete(flush_req_id);
620 } else if (*id == id2) {
621 flushed_writer_2 = true;
622 writer2->Flush();
623 producer->endpoint()->NotifyFlushComplete(flush_req_id);
624 }
625 };
626 EXPECT_CALL(*producer, Flush(_, _, _))
627 .WillOnce(Invoke(flush_correct_writer))
628 .WillOnce(Invoke(flush_correct_writer));
629
630 auto checkpoint_name = "on_tracing_disabled_consumer_1_and_2";
631 auto on_tracing_disabled = task_runner.CreateCheckpoint(checkpoint_name);
632 std::atomic<size_t> counter(0);
633 EXPECT_CALL(*consumer_1, OnTracingDisabled()).WillOnce(Invoke([&]() {
634 if (++counter == 2u) {
635 on_tracing_disabled();
636 }
637 }));
638 EXPECT_CALL(*consumer_2, OnTracingDisabled()).WillOnce(Invoke([&]() {
639 if (++counter == 2u) {
640 on_tracing_disabled();
641 }
642 }));
643
644 EXPECT_CALL(*producer, StopDataSource(id1));
645 EXPECT_CALL(*producer, StopDataSource(id2));
646
647 task_runner.RunUntilCheckpoint(checkpoint_name, 1000);
648
649 EXPECT_TRUE(flushed_writer_1);
650 EXPECT_TRUE(flushed_writer_2);
651 EXPECT_THAT(
652 consumer_1->ReadBuffers(),
653 HasTriggerMode(protos::TraceConfig::TriggerConfig::START_TRACING));
654 EXPECT_THAT(
655 consumer_2->ReadBuffers(),
656 HasTriggerMode(protos::TraceConfig::TriggerConfig::START_TRACING));
657}
658
Stephen Nusko70ea3302019-04-01 19:44:40 +0100659// Creates a tracing session with a START_TRACING trigger and checks that the
660// received_triggers are emitted as packets.
661TEST_F(TracingServiceImplTest, EmitTriggersWithStartTracingTrigger) {
662 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
663 consumer->Connect(svc.get());
664
665 std::unique_ptr<MockProducer> producer = CreateMockProducer();
666 producer->Connect(svc.get(), "mock_producer", /* uid = */ 123u);
667
668 producer->RegisterDataSource("ds_1");
669
670 TraceConfig trace_config;
671 trace_config.add_buffers()->set_size_kb(128);
672 trace_config.add_data_sources()->mutable_config()->set_name("ds_1");
673 auto* trigger_config = trace_config.mutable_trigger_config();
674 trigger_config->set_trigger_mode(TraceConfig::TriggerConfig::START_TRACING);
675 auto* trigger = trigger_config->add_triggers();
676 trigger->set_name("trigger_name");
677 trigger->set_stop_delay_ms(1);
678 trigger->set_producer_name_regex("mock_produc[e-r]+");
679
680 trigger_config->set_trigger_timeout_ms(30000);
681
682 consumer->EnableTracing(trace_config);
683 producer->WaitForTracingSetup();
684 producer->WaitForDataSourceSetup("ds_1");
685
686 // The trace won't start until we send the trigger since we have a
687 // START_TRACING trigger defined.
688 std::vector<std::string> req;
689 req.push_back("trigger_name");
690 req.push_back("trigger_name_2");
691 req.push_back("trigger_name_3");
692 producer->endpoint()->ActivateTriggers(req);
693
694 producer->WaitForDataSourceStart("ds_1");
695 auto writer1 = producer->CreateTraceWriter("ds_1");
696 producer->WaitForFlush(writer1.get());
697 producer->WaitForDataSourceStop("ds_1");
698 consumer->WaitForTracingDisabled();
699
700 ASSERT_EQ(1u, tracing_session()->received_triggers.size());
701 EXPECT_EQ("trigger_name",
702 tracing_session()->received_triggers[0].trigger_name);
703
704 auto packets = consumer->ReadBuffers();
705 EXPECT_THAT(
706 packets,
707 Contains(Property(
708 &protos::TracePacket::trace_config,
709 Property(
710 &protos::TraceConfig::trigger_config,
711 Property(
712 &protos::TraceConfig::TriggerConfig::trigger_mode,
713 Eq(protos::TraceConfig::TriggerConfig::START_TRACING))))));
714 auto expect_received_trigger = [&](const std::string& name) {
715 return Contains(AllOf(
716 Property(
717 &protos::TracePacket::trigger,
718 AllOf(Property(&protos::Trigger::trigger_name, Eq(name)),
Eric Secklerc4024b22019-04-02 15:37:08 +0000719 Property(&protos::Trigger::trusted_producer_uid, Eq(123)),
Stephen Nusko70ea3302019-04-01 19:44:40 +0100720 Property(&protos::Trigger::producer_name,
721 Eq("mock_producer")))),
722 Property(&protos::TracePacket::trusted_packet_sequence_id,
723 Eq(kServicePacketSequenceID))));
724 };
725 EXPECT_THAT(packets, expect_received_trigger("trigger_name"));
726 EXPECT_THAT(packets,
727 ::testing::Not(expect_received_trigger("trigger_name_2")));
728 EXPECT_THAT(packets,
729 ::testing::Not(expect_received_trigger("trigger_name_3")));
730}
731
732// Creates a tracing session with a START_TRACING trigger and checks that the
733// received_triggers are emitted as packets.
734TEST_F(TracingServiceImplTest, EmitTriggersWithStopTracingTrigger) {
735 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
736 consumer->Connect(svc.get());
737
738 std::unique_ptr<MockProducer> producer = CreateMockProducer();
739 producer->Connect(svc.get(), "mock_producer", /* uid = */ 321u);
740
741 producer->RegisterDataSource("ds_1");
742
743 TraceConfig trace_config;
744 trace_config.add_buffers()->set_size_kb(128);
745 trace_config.add_data_sources()->mutable_config()->set_name("ds_1");
746 auto* trigger_config = trace_config.mutable_trigger_config();
747 trigger_config->set_trigger_mode(TraceConfig::TriggerConfig::STOP_TRACING);
748 auto* trigger = trigger_config->add_triggers();
749 trigger->set_name("trigger_name");
750 trigger->set_stop_delay_ms(1);
751 trigger = trigger_config->add_triggers();
752 trigger->set_name("trigger_name_3");
753 trigger->set_stop_delay_ms(30000);
754
755 trigger_config->set_trigger_timeout_ms(30000);
756
757 consumer->EnableTracing(trace_config);
758 producer->WaitForTracingSetup();
759 producer->WaitForDataSourceSetup("ds_1");
760 producer->WaitForDataSourceStart("ds_1");
761
762 // The trace won't start until we send the trigger since we have a
763 // START_TRACING trigger defined.
764 std::vector<std::string> req;
765 req.push_back("trigger_name");
766 req.push_back("trigger_name_2");
767 req.push_back("trigger_name_3");
768 producer->endpoint()->ActivateTriggers(req);
769
770 auto writer1 = producer->CreateTraceWriter("ds_1");
771 producer->WaitForFlush(writer1.get());
772 producer->WaitForDataSourceStop("ds_1");
773 consumer->WaitForTracingDisabled();
774
775 ASSERT_EQ(2u, tracing_session()->received_triggers.size());
776 EXPECT_EQ("trigger_name",
777 tracing_session()->received_triggers[0].trigger_name);
778 EXPECT_EQ("trigger_name_3",
779 tracing_session()->received_triggers[1].trigger_name);
780
781 auto packets = consumer->ReadBuffers();
782 EXPECT_THAT(
783 packets,
784 Contains(Property(
785 &protos::TracePacket::trace_config,
786 Property(
787 &protos::TraceConfig::trigger_config,
788 Property(
789 &protos::TraceConfig::TriggerConfig::trigger_mode,
790 Eq(protos::TraceConfig::TriggerConfig::STOP_TRACING))))));
791
792 auto expect_received_trigger = [&](const std::string& name) {
793 return Contains(AllOf(
794 Property(
795 &protos::TracePacket::trigger,
796 AllOf(Property(&protos::Trigger::trigger_name, Eq(name)),
Eric Secklerc4024b22019-04-02 15:37:08 +0000797 Property(&protos::Trigger::trusted_producer_uid, Eq(321)),
Stephen Nusko70ea3302019-04-01 19:44:40 +0100798 Property(&protos::Trigger::producer_name,
799 Eq("mock_producer")))),
800 Property(&protos::TracePacket::trusted_packet_sequence_id,
801 Eq(kServicePacketSequenceID))));
802 };
803 EXPECT_THAT(packets, expect_received_trigger("trigger_name"));
804 EXPECT_THAT(packets,
805 ::testing::Not(expect_received_trigger("trigger_name_2")));
806 EXPECT_THAT(packets, expect_received_trigger("trigger_name_3"));
807}
808
809// Creates a tracing session with a START_TRACING trigger and checks that the
810// received_triggers are emitted as packets even ones after the initial
811// ReadBuffers() call.
812TEST_F(TracingServiceImplTest, EmitTriggersRepeatedly) {
813 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
814 consumer->Connect(svc.get());
815
816 std::unique_ptr<MockProducer> producer = CreateMockProducer();
817 producer->Connect(svc.get(), "mock_producer");
818
819 // Create two data sources but enable only one of them.
820 producer->RegisterDataSource("ds_1");
821 producer->RegisterDataSource("ds_2");
822
823 TraceConfig trace_config;
824 trace_config.add_buffers()->set_size_kb(128);
825 trace_config.add_data_sources()->mutable_config()->set_name("ds_1");
826 auto* trigger_config = trace_config.mutable_trigger_config();
827 trigger_config->set_trigger_mode(TraceConfig::TriggerConfig::STOP_TRACING);
828 auto* trigger = trigger_config->add_triggers();
829 trigger->set_name("trigger_name");
830 trigger->set_stop_delay_ms(1);
831 trigger = trigger_config->add_triggers();
832 trigger->set_name("trigger_name_2");
833 trigger->set_stop_delay_ms(1);
834
835 trigger_config->set_trigger_timeout_ms(30000);
836
837 auto expect_received_trigger = [&](const std::string& name) {
838 return Contains(
839 AllOf(Property(&protos::TracePacket::trigger,
840 AllOf(Property(&protos::Trigger::trigger_name, Eq(name)),
841 Property(&protos::Trigger::producer_name,
842 Eq("mock_producer")))),
843 Property(&protos::TracePacket::trusted_packet_sequence_id,
844 Eq(kServicePacketSequenceID))));
845 };
846
847 consumer->EnableTracing(trace_config);
848 producer->WaitForTracingSetup();
849 producer->WaitForDataSourceSetup("ds_1");
850 producer->WaitForDataSourceStart("ds_1");
851
852 // The trace won't start until we send the trigger. since we have a
853 // START_TRACING trigger defined.
854 producer->endpoint()->ActivateTriggers({"trigger_name"});
855
856 auto packets = consumer->ReadBuffers();
857 EXPECT_THAT(
858 packets,
859 Contains(Property(
860 &protos::TracePacket::trace_config,
861 Property(
862 &protos::TraceConfig::trigger_config,
863 Property(
864 &protos::TraceConfig::TriggerConfig::trigger_mode,
865 Eq(protos::TraceConfig::TriggerConfig::STOP_TRACING))))));
866 EXPECT_THAT(packets, expect_received_trigger("trigger_name"));
867 EXPECT_THAT(packets,
868 ::testing::Not(expect_received_trigger("trigger_name_2")));
869
870 // Send a new trigger.
871 producer->endpoint()->ActivateTriggers({"trigger_name_2"});
872
873 auto writer1 = producer->CreateTraceWriter("ds_1");
874 producer->WaitForFlush(writer1.get());
875 producer->WaitForDataSourceStop("ds_1");
876 consumer->WaitForTracingDisabled();
877
878 ASSERT_EQ(2u, tracing_session()->received_triggers.size());
879 EXPECT_EQ("trigger_name",
880 tracing_session()->received_triggers[0].trigger_name);
881 EXPECT_EQ("trigger_name_2",
882 tracing_session()->received_triggers[1].trigger_name);
883
884 packets = consumer->ReadBuffers();
885 // We don't rewrite the old trigger.
886 EXPECT_THAT(packets, ::testing::Not(expect_received_trigger("trigger_name")));
887 EXPECT_THAT(packets, expect_received_trigger("trigger_name_2"));
888}
889
Stephen Nuskod95a7512019-03-22 13:59:39 +0000890// Creates a tracing session with a STOP_TRACING trigger and checks that the
891// session is cleaned up after |trigger_timeout_ms|.
892TEST_F(TracingServiceImplTest, StopTracingTriggerTimeout) {
893 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
894 consumer->Connect(svc.get());
895
896 std::unique_ptr<MockProducer> producer = CreateMockProducer();
897 producer->Connect(svc.get(), "mock_producer");
898
899 // Create two data sources but enable only one of them.
900 producer->RegisterDataSource("ds_1");
901 producer->RegisterDataSource("ds_2");
902
903 TraceConfig trace_config;
904 trace_config.add_buffers()->set_size_kb(128);
905 trace_config.add_data_sources()->mutable_config()->set_name("ds_1");
906 auto* trigger_config = trace_config.mutable_trigger_config();
907 trigger_config->set_trigger_mode(TraceConfig::TriggerConfig::STOP_TRACING);
908 auto* trigger = trigger_config->add_triggers();
909 trigger->set_name("trigger_name");
910 trigger->set_stop_delay_ms(8.64e+7);
911
912 trigger_config->set_trigger_timeout_ms(1);
913
914 // Make sure we don't get unexpected DataSourceStart() notifications yet.
915 EXPECT_CALL(*producer, StartDataSource(_, _)).Times(0);
916
917 consumer->EnableTracing(trace_config);
918 producer->WaitForTracingSetup();
919
920 producer->WaitForDataSourceSetup("ds_1");
921 producer->WaitForDataSourceStart("ds_1");
922
923 // The trace won't return data until unless we send a trigger at this point.
924 EXPECT_THAT(consumer->ReadBuffers(), ::testing::IsEmpty());
925
926 auto writer = producer->CreateTraceWriter("ds_1");
927 producer->WaitForFlush(writer.get());
928
929 ASSERT_EQ(0u, tracing_session()->received_triggers.size());
930
931 producer->WaitForDataSourceStop("ds_1");
932 consumer->WaitForTracingDisabled();
933 EXPECT_THAT(consumer->ReadBuffers(), ::testing::IsEmpty());
934}
935
936// Creates a tracing session with a STOP_TRACING trigger and checks that the
937// session returns data after a trigger is received, but only what is currently
938// in the buffer.
939TEST_F(TracingServiceImplTest, StopTracingTriggerRingBuffer) {
940 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
941 consumer->Connect(svc.get());
942
943 std::unique_ptr<MockProducer> producer = CreateMockProducer();
944 producer->Connect(svc.get(), "mock_producer");
945
946 // Create two data sources but enable only one of them.
947 producer->RegisterDataSource("ds_1");
948 producer->RegisterDataSource("ds_2");
949
950 TraceConfig trace_config;
951 trace_config.add_buffers()->set_size_kb(128);
952 trace_config.add_data_sources()->mutable_config()->set_name("ds_1");
953 auto* trigger_config = trace_config.mutable_trigger_config();
954 trigger_config->set_trigger_mode(TraceConfig::TriggerConfig::STOP_TRACING);
955 auto* trigger = trigger_config->add_triggers();
956 trigger->set_name("trigger_name");
957 trigger->set_stop_delay_ms(1);
958
959 trigger_config->set_trigger_timeout_ms(8.64e+7);
960
961 consumer->EnableTracing(trace_config);
962 producer->WaitForTracingSetup();
963
964 producer->WaitForDataSourceSetup("ds_1");
965 producer->WaitForDataSourceStart("ds_1");
966
Stephen Nuskod95a7512019-03-22 13:59:39 +0000967 // The trace won't return data until unless we send a trigger at this point.
968 EXPECT_THAT(consumer->ReadBuffers(), ::testing::IsEmpty());
969
970 // We write into the buffer a large packet which takes up the whole buffer. We
971 // then add a bunch of smaller ones which causes the larger packet to be
972 // dropped. After we activate the session we should only see a bunch of the
973 // smaller ones.
Eric Secklera883e5f2019-04-02 22:51:29 +0000974 static const size_t kNumTestPackets = 10;
Stephen Nuskod95a7512019-03-22 13:59:39 +0000975 static const char kPayload[] = "1234567890abcdef-";
976
977 auto writer = producer->CreateTraceWriter("ds_1");
978 // Buffer is 1kb so we write a packet which is slightly smaller so it fits in
979 // the buffer.
980 const std::string large_payload(1024 * 128 - 20, 'a');
981 {
982 auto tp = writer->NewTracePacket();
983 tp->set_for_testing()->set_str(large_payload.c_str(), large_payload.size());
984 }
985
986 // Now we add a bunch of data before the trigger and after.
Eric Secklera883e5f2019-04-02 22:51:29 +0000987 for (size_t i = 0; i < kNumTestPackets; i++) {
Stephen Nuskod95a7512019-03-22 13:59:39 +0000988 if (i == kNumTestPackets / 2) {
989 std::vector<std::string> req;
990 req.push_back("trigger_name");
991 producer->endpoint()->ActivateTriggers(req);
992 }
993 auto tp = writer->NewTracePacket();
994 std::string payload(kPayload);
995 payload.append(std::to_string(i));
996 tp->set_for_testing()->set_str(payload.c_str(), payload.size());
997 }
998 producer->WaitForFlush(writer.get());
999
1000 ASSERT_EQ(1u, tracing_session()->received_triggers.size());
1001 EXPECT_EQ("trigger_name",
Stephen Nusko70ea3302019-04-01 19:44:40 +01001002 tracing_session()->received_triggers[0].trigger_name);
Stephen Nuskod95a7512019-03-22 13:59:39 +00001003
1004 producer->WaitForDataSourceStop("ds_1");
1005 consumer->WaitForTracingDisabled();
Stephen Nusko70ea3302019-04-01 19:44:40 +01001006
Stephen Nuskod95a7512019-03-22 13:59:39 +00001007 auto packets = consumer->ReadBuffers();
Stephen Nusko70ea3302019-04-01 19:44:40 +01001008 EXPECT_LT(kNumTestPackets, packets.size());
Stephen Nuskod95a7512019-03-22 13:59:39 +00001009 // We expect for the TraceConfig preamble packet to be there correctly and
1010 // then we expect each payload to be there, but not the |large_payload|
1011 // packet.
1012 EXPECT_THAT(packets,
1013 HasTriggerMode(protos::TraceConfig::TriggerConfig::STOP_TRACING));
Eric Secklera883e5f2019-04-02 22:51:29 +00001014 for (size_t i = 0; i < kNumTestPackets; i++) {
Stephen Nuskod95a7512019-03-22 13:59:39 +00001015 std::string payload = kPayload;
1016 payload += std::to_string(i);
1017 EXPECT_THAT(packets, Contains(Property(
1018 &protos::TracePacket::for_testing,
1019 Property(&protos::TestEvent::str, Eq(payload)))));
1020 }
1021
1022 // The large payload was overwritten before we trigger and ReadBuffers so it
1023 // should not be in the returned data.
1024 EXPECT_THAT(packets,
1025 ::testing::Not(Contains(Property(
1026 &protos::TracePacket::for_testing,
1027 Property(&protos::TestEvent::str, Eq(large_payload))))));
1028}
1029
1030// Creates a tracing session with a STOP_TRACING trigger and checks that the
1031// session only cleans up once even with multiple triggers.
1032TEST_F(TracingServiceImplTest, StopTracingTriggerMultipleTriggers) {
1033 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
1034 consumer->Connect(svc.get());
1035
1036 std::unique_ptr<MockProducer> producer = CreateMockProducer();
1037 producer->Connect(svc.get(), "mock_producer");
1038
1039 // Create two data sources but enable only one of them.
1040 producer->RegisterDataSource("ds_1");
1041 producer->RegisterDataSource("ds_2");
1042
1043 TraceConfig trace_config;
1044 trace_config.add_buffers()->set_size_kb(128);
1045 trace_config.add_data_sources()->mutable_config()->set_name("ds_1");
1046 auto* trigger_config = trace_config.mutable_trigger_config();
1047 trigger_config->set_trigger_mode(TraceConfig::TriggerConfig::STOP_TRACING);
1048 auto* trigger = trigger_config->add_triggers();
1049 trigger->set_name("trigger_name");
1050 trigger->set_stop_delay_ms(1);
1051 trigger = trigger_config->add_triggers();
1052 trigger->set_name("trigger_name_2");
1053 trigger->set_stop_delay_ms(8.64e+7);
1054
1055 trigger_config->set_trigger_timeout_ms(8.64e+7);
1056
1057 consumer->EnableTracing(trace_config);
1058 producer->WaitForTracingSetup();
1059
1060 producer->WaitForDataSourceSetup("ds_1");
1061 producer->WaitForDataSourceStart("ds_1");
1062
Stephen Nuskod95a7512019-03-22 13:59:39 +00001063 // The trace won't return data until unless we send a trigger at this point.
1064 EXPECT_THAT(consumer->ReadBuffers(), ::testing::IsEmpty());
1065
1066 std::vector<std::string> req;
1067 req.push_back("trigger_name");
1068 req.push_back("trigger_name_3");
1069 req.push_back("trigger_name_2");
1070 producer->endpoint()->ActivateTriggers(req);
1071
1072 auto writer = producer->CreateTraceWriter("ds_1");
1073 producer->WaitForFlush(writer.get());
1074
1075 ASSERT_EQ(2u, tracing_session()->received_triggers.size());
1076 EXPECT_EQ("trigger_name",
Stephen Nusko70ea3302019-04-01 19:44:40 +01001077 tracing_session()->received_triggers[0].trigger_name);
Stephen Nuskod95a7512019-03-22 13:59:39 +00001078 EXPECT_EQ("trigger_name_2",
Stephen Nusko70ea3302019-04-01 19:44:40 +01001079 tracing_session()->received_triggers[1].trigger_name);
Stephen Nuskod95a7512019-03-22 13:59:39 +00001080
1081 producer->WaitForDataSourceStop("ds_1");
1082 consumer->WaitForTracingDisabled();
1083 EXPECT_THAT(consumer->ReadBuffers(),
1084 HasTriggerMode(protos::TraceConfig::TriggerConfig::STOP_TRACING));
1085}
1086
Florian Mayer6a1a4d52018-06-08 16:47:07 +01001087TEST_F(TracingServiceImplTest, LockdownMode) {
Primiano Tuccidca727d2018-04-04 11:31:55 +02001088 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
1089 consumer->Connect(svc.get());
1090
1091 std::unique_ptr<MockProducer> producer = CreateMockProducer();
1092 producer->Connect(svc.get(), "mock_producer_sameuid", geteuid());
1093 producer->RegisterDataSource("data_source");
Florian Mayer61c55482018-03-06 14:43:54 +00001094
1095 TraceConfig trace_config;
Primiano Tuccidca727d2018-04-04 11:31:55 +02001096 trace_config.add_buffers()->set_size_kb(128);
1097 auto* ds_config = trace_config.add_data_sources()->mutable_config();
1098 ds_config->set_name("data_source");
Florian Mayer61c55482018-03-06 14:43:54 +00001099 trace_config.set_lockdown_mode(
1100 TraceConfig::LockdownModeOperation::LOCKDOWN_SET);
Primiano Tuccidca727d2018-04-04 11:31:55 +02001101 consumer->EnableTracing(trace_config);
1102
1103 producer->WaitForTracingSetup();
Primiano Tucci674076d2018-10-01 10:41:09 +01001104 producer->WaitForDataSourceSetup("data_source");
Primiano Tuccidca727d2018-04-04 11:31:55 +02001105 producer->WaitForDataSourceStart("data_source");
1106
1107 std::unique_ptr<MockProducer> producer_otheruid = CreateMockProducer();
1108 auto x = svc->ConnectProducer(producer_otheruid.get(), geteuid() + 1,
1109 "mock_producer_ouid");
1110 EXPECT_CALL(*producer_otheruid, OnConnect()).Times(0);
Florian Mayer61c55482018-03-06 14:43:54 +00001111 task_runner.RunUntilIdle();
Primiano Tuccidca727d2018-04-04 11:31:55 +02001112 Mock::VerifyAndClearExpectations(producer_otheruid.get());
Florian Mayer61c55482018-03-06 14:43:54 +00001113
Primiano Tuccidca727d2018-04-04 11:31:55 +02001114 consumer->DisableTracing();
1115 consumer->FreeBuffers();
1116 producer->WaitForDataSourceStop("data_source");
1117 consumer->WaitForTracingDisabled();
Florian Mayer61c55482018-03-06 14:43:54 +00001118
1119 trace_config.set_lockdown_mode(
1120 TraceConfig::LockdownModeOperation::LOCKDOWN_CLEAR);
Primiano Tuccidca727d2018-04-04 11:31:55 +02001121 consumer->EnableTracing(trace_config);
Primiano Tucci674076d2018-10-01 10:41:09 +01001122 producer->WaitForDataSourceSetup("data_source");
Primiano Tuccidca727d2018-04-04 11:31:55 +02001123 producer->WaitForDataSourceStart("data_source");
Florian Mayer61c55482018-03-06 14:43:54 +00001124
Primiano Tuccidca727d2018-04-04 11:31:55 +02001125 std::unique_ptr<MockProducer> producer_otheruid2 = CreateMockProducer();
1126 producer_otheruid->Connect(svc.get(), "mock_producer_ouid2", geteuid() + 1);
Florian Mayer61c55482018-03-06 14:43:54 +00001127
Primiano Tuccidca727d2018-04-04 11:31:55 +02001128 consumer->DisableTracing();
1129 producer->WaitForDataSourceStop("data_source");
1130 consumer->WaitForTracingDisabled();
Florian Mayer61c55482018-03-06 14:43:54 +00001131}
1132
Oystein Eftevaagcb6e4c82019-03-06 15:38:26 -08001133TEST_F(TracingServiceImplTest, ProducerNameFilterChange) {
1134 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
1135 consumer->Connect(svc.get());
1136
1137 std::unique_ptr<MockProducer> producer1 = CreateMockProducer();
1138 producer1->Connect(svc.get(), "mock_producer_1");
1139 producer1->RegisterDataSource("data_source");
1140
1141 std::unique_ptr<MockProducer> producer2 = CreateMockProducer();
1142 producer2->Connect(svc.get(), "mock_producer_2");
1143 producer2->RegisterDataSource("data_source");
1144
1145 std::unique_ptr<MockProducer> producer3 = CreateMockProducer();
1146 producer3->Connect(svc.get(), "mock_producer_3");
1147 producer3->RegisterDataSource("data_source");
1148 producer3->RegisterDataSource("unused_data_source");
1149
1150 TraceConfig trace_config;
1151 trace_config.add_buffers()->set_size_kb(128);
1152 auto* data_source = trace_config.add_data_sources();
1153 data_source->mutable_config()->set_name("data_source");
1154 *data_source->add_producer_name_filter() = "mock_producer_1";
1155
1156 // Enable tracing with only mock_producer_1 enabled;
1157 // the rest should not start up.
1158 consumer->EnableTracing(trace_config);
1159
1160 producer1->WaitForTracingSetup();
1161 producer1->WaitForDataSourceSetup("data_source");
1162 producer1->WaitForDataSourceStart("data_source");
1163
1164 EXPECT_CALL(*producer2, OnConnect()).Times(0);
1165 EXPECT_CALL(*producer3, OnConnect()).Times(0);
1166 task_runner.RunUntilIdle();
1167 Mock::VerifyAndClearExpectations(producer2.get());
1168 Mock::VerifyAndClearExpectations(producer3.get());
1169
1170 // Enable mock_producer_2, the third one should still
1171 // not get connected.
1172 *data_source->add_producer_name_filter() = "mock_producer_2";
1173 consumer->ChangeTraceConfig(trace_config);
1174
1175 producer2->WaitForTracingSetup();
1176 producer2->WaitForDataSourceSetup("data_source");
1177 producer2->WaitForDataSourceStart("data_source");
1178
1179 // Enable mock_producer_3 but also try to do an
1180 // unsupported change (adding a new data source);
1181 // mock_producer_3 should get enabled but not
1182 // for the new data source.
1183 *data_source->add_producer_name_filter() = "mock_producer_3";
1184 auto* dummy_data_source = trace_config.add_data_sources();
1185 dummy_data_source->mutable_config()->set_name("unused_data_source");
1186 *dummy_data_source->add_producer_name_filter() = "mock_producer_3";
1187
1188 consumer->ChangeTraceConfig(trace_config);
1189
1190 producer3->WaitForTracingSetup();
1191 EXPECT_CALL(*producer3, SetupDataSource(_, _)).Times(1);
1192 EXPECT_CALL(*producer3, StartDataSource(_, _)).Times(1);
1193 task_runner.RunUntilIdle();
1194 Mock::VerifyAndClearExpectations(producer3.get());
1195
1196 consumer->DisableTracing();
1197 consumer->FreeBuffers();
1198 producer1->WaitForDataSourceStop("data_source");
1199 producer2->WaitForDataSourceStop("data_source");
1200
1201 EXPECT_CALL(*producer3, StopDataSource(_)).Times(1);
1202
1203 consumer->WaitForTracingDisabled();
1204
1205 task_runner.RunUntilIdle();
1206 Mock::VerifyAndClearExpectations(producer3.get());
1207}
1208
Florian Mayer6a1a4d52018-06-08 16:47:07 +01001209TEST_F(TracingServiceImplTest, DisconnectConsumerWhileTracing) {
Primiano Tuccidca727d2018-04-04 11:31:55 +02001210 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
1211 consumer->Connect(svc.get());
Sami Kyostila06487a22018-02-27 13:48:38 +00001212
Primiano Tuccidca727d2018-04-04 11:31:55 +02001213 std::unique_ptr<MockProducer> producer = CreateMockProducer();
1214 producer->Connect(svc.get(), "mock_producer");
1215 producer->RegisterDataSource("data_source");
Sami Kyostila06487a22018-02-27 13:48:38 +00001216
Primiano Tuccidca727d2018-04-04 11:31:55 +02001217 TraceConfig trace_config;
1218 trace_config.add_buffers()->set_size_kb(128);
1219 auto* ds_config = trace_config.add_data_sources()->mutable_config();
1220 ds_config->set_name("data_source");
1221 consumer->EnableTracing(trace_config);
1222
1223 producer->WaitForTracingSetup();
Primiano Tucci674076d2018-10-01 10:41:09 +01001224 producer->WaitForDataSourceSetup("data_source");
Primiano Tuccidca727d2018-04-04 11:31:55 +02001225 producer->WaitForDataSourceStart("data_source");
Sami Kyostila06487a22018-02-27 13:48:38 +00001226
1227 // Disconnecting the consumer while tracing should trigger data source
1228 // teardown.
Primiano Tuccidca727d2018-04-04 11:31:55 +02001229 consumer.reset();
1230 producer->WaitForDataSourceStop("data_source");
Sami Kyostila06487a22018-02-27 13:48:38 +00001231}
1232
Florian Mayer6a1a4d52018-06-08 16:47:07 +01001233TEST_F(TracingServiceImplTest, ReconnectProducerWhileTracing) {
Primiano Tuccidca727d2018-04-04 11:31:55 +02001234 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
1235 consumer->Connect(svc.get());
Sami Kyostila06487a22018-02-27 13:48:38 +00001236
Primiano Tuccidca727d2018-04-04 11:31:55 +02001237 std::unique_ptr<MockProducer> producer = CreateMockProducer();
1238 producer->Connect(svc.get(), "mock_producer");
1239 producer->RegisterDataSource("data_source");
Sami Kyostila06487a22018-02-27 13:48:38 +00001240
Sami Kyostila06487a22018-02-27 13:48:38 +00001241 TraceConfig trace_config;
Primiano Tuccidca727d2018-04-04 11:31:55 +02001242 trace_config.add_buffers()->set_size_kb(128);
Sami Kyostila06487a22018-02-27 13:48:38 +00001243 auto* ds_config = trace_config.add_data_sources()->mutable_config();
Primiano Tuccidca727d2018-04-04 11:31:55 +02001244 ds_config->set_name("data_source");
1245 consumer->EnableTracing(trace_config);
Sami Kyostila06487a22018-02-27 13:48:38 +00001246
Primiano Tuccidca727d2018-04-04 11:31:55 +02001247 producer->WaitForTracingSetup();
Primiano Tucci674076d2018-10-01 10:41:09 +01001248 producer->WaitForDataSourceSetup("data_source");
Primiano Tuccidca727d2018-04-04 11:31:55 +02001249 producer->WaitForDataSourceStart("data_source");
Sami Kyostila06487a22018-02-27 13:48:38 +00001250
Primiano Tuccidca727d2018-04-04 11:31:55 +02001251 // Disconnecting and reconnecting a producer with a matching data source.
1252 // The Producer should see that data source getting enabled again.
1253 producer.reset();
1254 producer = CreateMockProducer();
1255 producer->Connect(svc.get(), "mock_producer_2");
1256 producer->RegisterDataSource("data_source");
1257 producer->WaitForTracingSetup();
Primiano Tucci674076d2018-10-01 10:41:09 +01001258 producer->WaitForDataSourceSetup("data_source");
Primiano Tuccidca727d2018-04-04 11:31:55 +02001259 producer->WaitForDataSourceStart("data_source");
Sami Kyostila06487a22018-02-27 13:48:38 +00001260}
1261
Florian Mayer6a1a4d52018-06-08 16:47:07 +01001262TEST_F(TracingServiceImplTest, ProducerIDWrapping) {
Primiano Tuccidca727d2018-04-04 11:31:55 +02001263 std::vector<std::unique_ptr<MockProducer>> producers;
1264 producers.push_back(nullptr);
Primiano Tucci081d46a2018-02-28 11:09:43 +00001265
Primiano Tuccidca727d2018-04-04 11:31:55 +02001266 auto connect_producer_and_get_id = [&producers,
1267 this](const std::string& name) {
1268 producers.emplace_back(CreateMockProducer());
1269 producers.back()->Connect(svc.get(), "mock_producer_" + name);
Primiano Tucci1a1951d2018-04-04 21:08:16 +02001270 return *last_producer_id();
Primiano Tucci081d46a2018-02-28 11:09:43 +00001271 };
1272
1273 // Connect producers 1-4.
1274 for (ProducerID i = 1; i <= 4; i++)
Primiano Tuccidca727d2018-04-04 11:31:55 +02001275 ASSERT_EQ(i, connect_producer_and_get_id(std::to_string(i)));
Primiano Tucci081d46a2018-02-28 11:09:43 +00001276
1277 // Disconnect producers 1,3.
Primiano Tuccidca727d2018-04-04 11:31:55 +02001278 producers[1].reset();
1279 producers[3].reset();
Primiano Tucci081d46a2018-02-28 11:09:43 +00001280
Primiano Tucci1a1951d2018-04-04 21:08:16 +02001281 *last_producer_id() = kMaxProducerID - 1;
Primiano Tuccidca727d2018-04-04 11:31:55 +02001282 ASSERT_EQ(kMaxProducerID, connect_producer_and_get_id("maxid"));
1283 ASSERT_EQ(1u, connect_producer_and_get_id("1_again"));
1284 ASSERT_EQ(3u, connect_producer_and_get_id("3_again"));
1285 ASSERT_EQ(5u, connect_producer_and_get_id("5"));
1286 ASSERT_EQ(6u, connect_producer_and_get_id("6"));
Primiano Tucci081d46a2018-02-28 11:09:43 +00001287}
1288
Ryan Savitskicc28cbf2018-11-09 22:55:12 +00001289// Note: file_write_period_ms is set to a large enough to have exactly one flush
1290// of the tracing buffers (and therefore at most one synchronization section),
1291// unless the test runs unrealistically slowly, or the implementation of the
1292// tracing snapshot packets changes.
Florian Mayer6a1a4d52018-06-08 16:47:07 +01001293TEST_F(TracingServiceImplTest, WriteIntoFileAndStopOnMaxSize) {
Primiano Tuccidca727d2018-04-04 11:31:55 +02001294 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
1295 consumer->Connect(svc.get());
Primiano Tucci2ffd1a52018-03-27 01:01:30 +01001296
Primiano Tuccidca727d2018-04-04 11:31:55 +02001297 std::unique_ptr<MockProducer> producer = CreateMockProducer();
1298 producer->Connect(svc.get(), "mock_producer");
1299 producer->RegisterDataSource("data_source");
Primiano Tucci2ffd1a52018-03-27 01:01:30 +01001300
Primiano Tucci2ffd1a52018-03-27 01:01:30 +01001301 TraceConfig trace_config;
1302 trace_config.add_buffers()->set_size_kb(4096);
1303 auto* ds_config = trace_config.add_data_sources()->mutable_config();
Primiano Tuccidca727d2018-04-04 11:31:55 +02001304 ds_config->set_name("data_source");
Primiano Tucci2ffd1a52018-03-27 01:01:30 +01001305 ds_config->set_target_buffer(0);
1306 trace_config.set_write_into_file(true);
Ryan Savitskicc28cbf2018-11-09 22:55:12 +00001307 trace_config.set_file_write_period_ms(100000); // 100s
1308 const uint64_t kMaxFileSize = 1024;
Primiano Tucci2ffd1a52018-03-27 01:01:30 +01001309 trace_config.set_max_file_size_bytes(kMaxFileSize);
1310 base::TempFile tmp_file = base::TempFile::Create();
Primiano Tuccidca727d2018-04-04 11:31:55 +02001311 consumer->EnableTracing(trace_config, base::ScopedFile(dup(tmp_file.fd())));
1312
1313 producer->WaitForTracingSetup();
Primiano Tucci674076d2018-10-01 10:41:09 +01001314 producer->WaitForDataSourceSetup("data_source");
Primiano Tuccidca727d2018-04-04 11:31:55 +02001315 producer->WaitForDataSourceStart("data_source");
1316
Hector Dearman685f7522019-03-12 14:28:56 +00001317 // The preamble packets are:
Hector Dearmane004a572019-05-13 17:51:43 +01001318 // Trace start clocksnapshot
Hector Dearman685f7522019-03-12 14:28:56 +00001319 // Config
1320 // SystemInfo
Hector Dearmane004a572019-05-13 17:51:43 +01001321 // Trace read clocksnapshot
1322 // Trace synchronisation
1323 // Trace stats
1324 static const int kNumPreamblePackets = 6;
1325 static const int kNumTestPackets = 9;
Primiano Tuccidca727d2018-04-04 11:31:55 +02001326 static const char kPayload[] = "1234567890abcdef-";
Primiano Tucci2ffd1a52018-03-27 01:01:30 +01001327
1328 std::unique_ptr<TraceWriter> writer =
Primiano Tuccidca727d2018-04-04 11:31:55 +02001329 producer->CreateTraceWriter("data_source");
Ryan Savitskicc28cbf2018-11-09 22:55:12 +00001330 // Tracing service will emit a preamble of packets (a synchronization section,
1331 // followed by a tracing config packet). The preamble and these test packets
1332 // should fit within kMaxFileSize.
1333 for (int i = 0; i < kNumTestPackets; i++) {
Primiano Tucci2ffd1a52018-03-27 01:01:30 +01001334 auto tp = writer->NewTracePacket();
1335 std::string payload(kPayload);
1336 payload.append(std::to_string(i));
1337 tp->set_for_testing()->set_str(payload.c_str(), payload.size());
1338 }
1339
1340 // Finally add a packet that overflows kMaxFileSize. This should cause the
1341 // implicit stop of the trace and should *not* be written in the trace.
1342 {
1343 auto tp = writer->NewTracePacket();
1344 char big_payload[kMaxFileSize] = "BIG!";
1345 tp->set_for_testing()->set_str(big_payload, sizeof(big_payload));
1346 }
1347 writer->Flush();
1348 writer.reset();
1349
Primiano Tuccidca727d2018-04-04 11:31:55 +02001350 consumer->DisableTracing();
1351 producer->WaitForDataSourceStop("data_source");
1352 consumer->WaitForTracingDisabled();
Primiano Tucci2ffd1a52018-03-27 01:01:30 +01001353
1354 // Verify the contents of the file.
1355 std::string trace_raw;
1356 ASSERT_TRUE(base::ReadFile(tmp_file.path().c_str(), &trace_raw));
1357 protos::Trace trace;
1358 ASSERT_TRUE(trace.ParseFromString(trace_raw));
Ryan Savitskicc28cbf2018-11-09 22:55:12 +00001359
1360 ASSERT_EQ(trace.packet_size(), kNumPreamblePackets + kNumTestPackets);
1361 for (int i = 0; i < kNumTestPackets; i++) {
1362 const protos::TracePacket& tp = trace.packet(kNumPreamblePackets + i);
1363 ASSERT_EQ(kPayload + std::to_string(i++), tp.for_testing().str());
Primiano Tucci2ffd1a52018-03-27 01:01:30 +01001364 }
Primiano Tuccidca727d2018-04-04 11:31:55 +02001365}
Primiano Tucci2ffd1a52018-03-27 01:01:30 +01001366
Primiano Tucci1a1951d2018-04-04 21:08:16 +02001367// Test the logic that allows the trace config to set the shm total size and
1368// page size from the trace config. Also check that, if the config doesn't
1369// specify a value we fall back on the hint provided by the producer.
Florian Mayer6a1a4d52018-06-08 16:47:07 +01001370TEST_F(TracingServiceImplTest, ProducerShmAndPageSizeOverriddenByTraceConfig) {
Primiano Tucci1a1951d2018-04-04 21:08:16 +02001371 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
1372 consumer->Connect(svc.get());
1373 const size_t kConfigPageSizesKb[] = /****/ {16, 16, 4, 0, 16, 8, 3, 4096, 4};
1374 const size_t kExpectedPageSizesKb[] = /**/ {16, 16, 4, 4, 16, 8, 4, 64, 4};
1375
1376 const size_t kConfigSizesKb[] = /**/ {0, 16, 0, 20, 32, 7, 0, 96, 4096000};
1377 const size_t kHintSizesKb[] = /****/ {0, 0, 16, 32, 16, 0, 7, 96, 4096000};
1378 const size_t kExpectedSizesKb[] = {
1379 kDefaultShmSizeKb, // Both hint and config are 0, use default.
1380 16, // Hint is 0, use config.
1381 16, // Config is 0, use hint.
1382 20, // Hint is takes precedence over the config.
1383 32, // Ditto, even if config is higher than hint.
1384 kDefaultShmSizeKb, // Config is invalid and hint is 0, use default.
1385 kDefaultShmSizeKb, // Config is 0 and hint is invalid, use default.
1386 kDefaultShmSizeKb, // 96 KB isn't a multiple of the page size (64 KB).
1387 kMaxShmSizeKb // Too big, cap at kMaxShmSize.
1388 };
1389
1390 const size_t kNumProducers = base::ArraySize(kHintSizesKb);
1391 std::unique_ptr<MockProducer> producer[kNumProducers];
1392 for (size_t i = 0; i < kNumProducers; i++) {
1393 auto name = "mock_producer_" + std::to_string(i);
1394 producer[i] = CreateMockProducer();
1395 producer[i]->Connect(svc.get(), name, geteuid(), kHintSizesKb[i] * 1024);
1396 producer[i]->RegisterDataSource("data_source");
1397 }
1398
1399 TraceConfig trace_config;
1400 trace_config.add_buffers()->set_size_kb(128);
1401 auto* ds_config = trace_config.add_data_sources()->mutable_config();
1402 ds_config->set_name("data_source");
1403 for (size_t i = 0; i < kNumProducers; i++) {
1404 auto* producer_config = trace_config.add_producers();
1405 producer_config->set_producer_name("mock_producer_" + std::to_string(i));
Primiano Tucci3cbb10a2018-04-10 17:52:40 +01001406 producer_config->set_shm_size_kb(static_cast<uint32_t>(kConfigSizesKb[i]));
1407 producer_config->set_page_size_kb(
1408 static_cast<uint32_t>(kConfigPageSizesKb[i]));
Primiano Tucci1a1951d2018-04-04 21:08:16 +02001409 }
1410
1411 consumer->EnableTracing(trace_config);
1412 size_t actual_shm_sizes_kb[kNumProducers]{};
1413 size_t actual_page_sizes_kb[kNumProducers]{};
1414 for (size_t i = 0; i < kNumProducers; i++) {
1415 producer[i]->WaitForTracingSetup();
Primiano Tucci674076d2018-10-01 10:41:09 +01001416 producer[i]->WaitForDataSourceSetup("data_source");
Primiano Tucci1a1951d2018-04-04 21:08:16 +02001417 actual_shm_sizes_kb[i] =
1418 producer[i]->endpoint()->shared_memory()->size() / 1024;
1419 actual_page_sizes_kb[i] =
1420 producer[i]->endpoint()->shared_buffer_page_size_kb();
1421 }
Primiano Tucci674076d2018-10-01 10:41:09 +01001422 for (size_t i = 0; i < kNumProducers; i++) {
1423 producer[i]->WaitForDataSourceStart("data_source");
1424 }
Primiano Tucci1a1951d2018-04-04 21:08:16 +02001425 ASSERT_THAT(actual_page_sizes_kb, ElementsAreArray(kExpectedPageSizesKb));
1426 ASSERT_THAT(actual_shm_sizes_kb, ElementsAreArray(kExpectedSizesKb));
1427}
1428
Florian Mayer6a1a4d52018-06-08 16:47:07 +01001429TEST_F(TracingServiceImplTest, ExplicitFlush) {
Primiano Tuccid52e6272018-04-06 19:06:53 +02001430 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
1431 consumer->Connect(svc.get());
1432
1433 std::unique_ptr<MockProducer> producer = CreateMockProducer();
1434 producer->Connect(svc.get(), "mock_producer");
1435 producer->RegisterDataSource("data_source");
1436
1437 TraceConfig trace_config;
1438 trace_config.add_buffers()->set_size_kb(128);
1439 auto* ds_config = trace_config.add_data_sources()->mutable_config();
1440 ds_config->set_name("data_source");
1441
1442 consumer->EnableTracing(trace_config);
1443 producer->WaitForTracingSetup();
Primiano Tucci674076d2018-10-01 10:41:09 +01001444 producer->WaitForDataSourceSetup("data_source");
Primiano Tuccid52e6272018-04-06 19:06:53 +02001445 producer->WaitForDataSourceStart("data_source");
1446
1447 std::unique_ptr<TraceWriter> writer =
1448 producer->CreateTraceWriter("data_source");
1449 {
1450 auto tp = writer->NewTracePacket();
1451 tp->set_for_testing()->set_str("payload");
1452 }
1453
1454 auto flush_request = consumer->Flush();
1455 producer->WaitForFlush(writer.get());
1456 ASSERT_TRUE(flush_request.WaitForReply());
1457
1458 consumer->DisableTracing();
1459 producer->WaitForDataSourceStop("data_source");
1460 consumer->WaitForTracingDisabled();
1461 EXPECT_THAT(
1462 consumer->ReadBuffers(),
1463 Contains(Property(&protos::TracePacket::for_testing,
1464 Property(&protos::TestEvent::str, Eq("payload")))));
1465}
1466
Florian Mayer6a1a4d52018-06-08 16:47:07 +01001467TEST_F(TracingServiceImplTest, ImplicitFlushOnTimedTraces) {
Primiano Tuccid52e6272018-04-06 19:06:53 +02001468 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
1469 consumer->Connect(svc.get());
1470
1471 std::unique_ptr<MockProducer> producer = CreateMockProducer();
1472 producer->Connect(svc.get(), "mock_producer");
1473 producer->RegisterDataSource("data_source");
1474
1475 TraceConfig trace_config;
1476 trace_config.add_buffers()->set_size_kb(128);
1477 auto* ds_config = trace_config.add_data_sources()->mutable_config();
1478 ds_config->set_name("data_source");
1479 trace_config.set_duration_ms(1);
1480
1481 consumer->EnableTracing(trace_config);
1482 producer->WaitForTracingSetup();
Primiano Tucci674076d2018-10-01 10:41:09 +01001483 producer->WaitForDataSourceSetup("data_source");
Primiano Tuccid52e6272018-04-06 19:06:53 +02001484 producer->WaitForDataSourceStart("data_source");
1485
1486 std::unique_ptr<TraceWriter> writer =
1487 producer->CreateTraceWriter("data_source");
1488 {
1489 auto tp = writer->NewTracePacket();
1490 tp->set_for_testing()->set_str("payload");
1491 }
1492
1493 producer->WaitForFlush(writer.get());
1494
1495 producer->WaitForDataSourceStop("data_source");
1496 consumer->WaitForTracingDisabled();
1497
1498 EXPECT_THAT(
1499 consumer->ReadBuffers(),
1500 Contains(Property(&protos::TracePacket::for_testing,
1501 Property(&protos::TestEvent::str, Eq("payload")))));
1502}
1503
1504// Tests the monotonic semantic of flush request IDs, i.e., once a producer
1505// acks flush request N, all flush requests <= N are considered successful and
1506// acked to the consumer.
Florian Mayer6a1a4d52018-06-08 16:47:07 +01001507TEST_F(TracingServiceImplTest, BatchFlushes) {
Primiano Tuccid52e6272018-04-06 19:06:53 +02001508 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
1509 consumer->Connect(svc.get());
1510
1511 std::unique_ptr<MockProducer> producer = CreateMockProducer();
1512 producer->Connect(svc.get(), "mock_producer");
1513 producer->RegisterDataSource("data_source");
1514
1515 TraceConfig trace_config;
1516 trace_config.add_buffers()->set_size_kb(128);
1517 auto* ds_config = trace_config.add_data_sources()->mutable_config();
1518 ds_config->set_name("data_source");
1519
1520 consumer->EnableTracing(trace_config);
1521 producer->WaitForTracingSetup();
Primiano Tucci674076d2018-10-01 10:41:09 +01001522 producer->WaitForDataSourceSetup("data_source");
Primiano Tuccid52e6272018-04-06 19:06:53 +02001523 producer->WaitForDataSourceStart("data_source");
1524
1525 std::unique_ptr<TraceWriter> writer =
1526 producer->CreateTraceWriter("data_source");
1527 {
1528 auto tp = writer->NewTracePacket();
1529 tp->set_for_testing()->set_str("payload");
1530 }
1531
1532 auto flush_req_1 = consumer->Flush();
1533 auto flush_req_2 = consumer->Flush();
1534 auto flush_req_3 = consumer->Flush();
1535
1536 // We'll deliberately let the 4th flush request timeout. Use a lower timeout
1537 // to keep test time short.
1538 auto flush_req_4 = consumer->Flush(/*timeout_ms=*/10);
1539 ASSERT_EQ(4u, GetNumPendingFlushes());
1540
1541 // Make the producer reply only to the 3rd flush request.
1542 testing::InSequence seq;
Eric Secklera01e28a2019-01-08 11:21:04 +00001543 producer->WaitForFlush(nullptr, /*reply=*/false); // Do NOT reply to flush 1.
1544 producer->WaitForFlush(nullptr, /*reply=*/false); // Do NOT reply to flush 2.
1545 producer->WaitForFlush(writer.get()); // Reply only to flush 3.
1546 producer->WaitForFlush(nullptr, /*reply=*/false); // Do NOT reply to flush 4.
Primiano Tuccid52e6272018-04-06 19:06:53 +02001547
1548 // Even if the producer explicily replied only to flush ID == 3, all the
1549 // previous flushed < 3 should be implicitly acked.
1550 ASSERT_TRUE(flush_req_1.WaitForReply());
1551 ASSERT_TRUE(flush_req_2.WaitForReply());
1552 ASSERT_TRUE(flush_req_3.WaitForReply());
1553
1554 // At this point flush id == 4 should still be pending and should fail because
1555 // of reaching its timeout.
Primiano Tuccid52e6272018-04-06 19:06:53 +02001556 ASSERT_FALSE(flush_req_4.WaitForReply());
1557
1558 consumer->DisableTracing();
1559 producer->WaitForDataSourceStop("data_source");
1560 consumer->WaitForTracingDisabled();
1561 EXPECT_THAT(
1562 consumer->ReadBuffers(),
1563 Contains(Property(&protos::TracePacket::for_testing,
1564 Property(&protos::TestEvent::str, Eq("payload")))));
1565}
1566
Primiano Tuccicaa57802018-11-25 11:07:07 +00001567TEST_F(TracingServiceImplTest, PeriodicFlush) {
1568 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
1569 consumer->Connect(svc.get());
1570
1571 std::unique_ptr<MockProducer> producer = CreateMockProducer();
1572 producer->Connect(svc.get(), "mock_producer");
1573 producer->RegisterDataSource("data_source");
1574
1575 TraceConfig trace_config;
1576 trace_config.add_buffers()->set_size_kb(128);
1577 trace_config.set_flush_period_ms(1);
1578 auto* ds_config = trace_config.add_data_sources()->mutable_config();
1579 ds_config->set_name("data_source");
1580
1581 consumer->EnableTracing(trace_config);
1582 producer->WaitForTracingSetup();
1583 producer->WaitForDataSourceSetup("data_source");
1584 producer->WaitForDataSourceStart("data_source");
1585
1586 std::unique_ptr<TraceWriter> writer =
1587 producer->CreateTraceWriter("data_source");
1588
1589 const int kNumFlushes = 3;
1590 auto checkpoint = task_runner.CreateCheckpoint("all_flushes_done");
1591 int flushes_seen = 0;
1592 EXPECT_CALL(*producer, Flush(_, _, _))
1593 .WillRepeatedly(Invoke([&producer, &writer, &flushes_seen, checkpoint](
1594 FlushRequestID flush_req_id,
1595 const DataSourceInstanceID*, size_t) {
1596 {
1597 auto tp = writer->NewTracePacket();
1598 char payload[32];
1599 sprintf(payload, "f_%d", flushes_seen);
1600 tp->set_for_testing()->set_str(payload);
1601 }
1602 writer->Flush();
1603 producer->endpoint()->NotifyFlushComplete(flush_req_id);
1604 if (++flushes_seen == kNumFlushes)
1605 checkpoint();
1606 }));
1607 task_runner.RunUntilCheckpoint("all_flushes_done");
1608
1609 consumer->DisableTracing();
1610 producer->WaitForDataSourceStop("data_source");
1611 consumer->WaitForTracingDisabled();
1612 auto trace_packets = consumer->ReadBuffers();
1613 for (int i = 0; i < kNumFlushes; i++) {
1614 EXPECT_THAT(trace_packets,
1615 Contains(Property(&protos::TracePacket::for_testing,
1616 Property(&protos::TestEvent::str,
1617 Eq("f_" + std::to_string(i))))));
1618 }
1619}
1620
Ryan Savitski33868d52019-05-13 10:56:14 +01001621TEST_F(TracingServiceImplTest, PeriodicClearIncrementalState) {
1622 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
1623 consumer->Connect(svc.get());
1624 std::unique_ptr<MockProducer> producer = CreateMockProducer();
1625 producer->Connect(svc.get(), "mock_producer");
1626
1627 // Incremental data source that expects to receive the clear.
1628 producer->RegisterDataSource("ds_incremental1", false, false,
1629 /*handles_incremental_state_clear=*/true);
1630
1631 // Incremental data source that expects to receive the clear.
1632 producer->RegisterDataSource("ds_incremental2", false, false,
1633 /*handles_incremental_state_clear=*/true);
1634
1635 // Data source that does *not* advertise itself as support incremental state
1636 // clears.
1637 producer->RegisterDataSource("ds_selfcontained", false, false,
1638 /*handles_incremental_state_clear=*/false);
1639
1640 // Incremental data source that is registered, but won't be active within the
1641 // test's tracing session.
1642 producer->RegisterDataSource("ds_inactive", false, false,
1643 /*handles_incremental_state_clear=*/true);
1644
1645 TraceConfig trace_config;
1646 trace_config.add_buffers()->set_size_kb(128);
1647 trace_config.mutable_incremental_state_config()->set_clear_period_ms(1);
1648 trace_config.add_data_sources()->mutable_config()->set_name(
1649 "ds_selfcontained");
1650 trace_config.add_data_sources()->mutable_config()->set_name(
1651 "ds_incremental1");
1652 trace_config.add_data_sources()->mutable_config()->set_name(
1653 "ds_incremental2");
1654
1655 // note: the mocking is very brittle, and has to assume a specific order of
1656 // the data sources' setup/start.
1657 consumer->EnableTracing(trace_config);
1658 producer->WaitForTracingSetup();
1659 producer->WaitForDataSourceSetup("ds_selfcontained");
1660 producer->WaitForDataSourceSetup("ds_incremental1");
1661 producer->WaitForDataSourceSetup("ds_incremental2");
1662 producer->WaitForDataSourceStart("ds_selfcontained");
1663 producer->WaitForDataSourceStart("ds_incremental1");
1664 producer->WaitForDataSourceStart("ds_incremental2");
1665
1666 DataSourceInstanceID ds_incremental1 =
1667 producer->GetDataSourceInstanceId("ds_incremental1");
1668 DataSourceInstanceID ds_incremental2 =
1669 producer->GetDataSourceInstanceId("ds_incremental2");
1670
1671 const int kNumClears = 3;
1672 std::function<void()> checkpoint =
1673 task_runner.CreateCheckpoint("clears_received");
1674 std::vector<std::vector<DataSourceInstanceID>> clears_seen;
1675 EXPECT_CALL(*producer, ClearIncrementalState(_, _))
1676 .WillRepeatedly(Invoke([&clears_seen, &checkpoint](
1677 const DataSourceInstanceID* data_source_ids,
1678 size_t num_data_sources) {
1679 std::vector<DataSourceInstanceID> ds_ids;
1680 for (size_t i = 0; i < num_data_sources; i++) {
1681 ds_ids.push_back(*data_source_ids++);
1682 }
1683 clears_seen.push_back(ds_ids);
1684 if (clears_seen.size() >= kNumClears)
1685 checkpoint();
1686 }));
1687 task_runner.RunUntilCheckpoint("clears_received");
1688
1689 consumer->DisableTracing();
1690
1691 // Assert that the clears were only for the active incremental data sources.
1692 ASSERT_EQ(clears_seen.size(), kNumClears);
1693 for (const std::vector<DataSourceInstanceID>& ds_ids : clears_seen) {
1694 ASSERT_THAT(ds_ids, ElementsAreArray({ds_incremental1, ds_incremental2}));
1695 }
1696}
1697
Primiano Tuccibaeecf12018-07-25 12:02:20 +01001698// Creates a tracing session where some of the data sources set the
1699// |will_notify_on_stop| flag and checks that the OnTracingDisabled notification
1700// to the consumer is delayed until the acks are received.
1701TEST_F(TracingServiceImplTest, OnTracingDisabledWaitsForDataSourceStopAcks) {
1702 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
1703 consumer->Connect(svc.get());
1704
1705 std::unique_ptr<MockProducer> producer = CreateMockProducer();
1706 producer->Connect(svc.get(), "mock_producer");
Eric Seckler4ff03e52019-03-15 10:10:30 +00001707 producer->RegisterDataSource("ds_will_ack_1", /*ack_stop=*/true,
1708 /*ack_start=*/true);
Primiano Tuccibaeecf12018-07-25 12:02:20 +01001709 producer->RegisterDataSource("ds_wont_ack");
Eric Seckler4ff03e52019-03-15 10:10:30 +00001710 producer->RegisterDataSource("ds_will_ack_2", /*ack_stop=*/true,
1711 /*ack_start=*/false);
Primiano Tuccibaeecf12018-07-25 12:02:20 +01001712
1713 TraceConfig trace_config;
1714 trace_config.add_buffers()->set_size_kb(128);
1715 trace_config.add_data_sources()->mutable_config()->set_name("ds_will_ack_1");
1716 trace_config.add_data_sources()->mutable_config()->set_name("ds_wont_ack");
1717 trace_config.add_data_sources()->mutable_config()->set_name("ds_will_ack_2");
1718 trace_config.set_duration_ms(1);
Eric Seckler4ff03e52019-03-15 10:10:30 +00001719 trace_config.set_deferred_start(true);
Primiano Tuccibaeecf12018-07-25 12:02:20 +01001720
1721 consumer->EnableTracing(trace_config);
Eric Seckler4ff03e52019-03-15 10:10:30 +00001722
1723 EXPECT_EQ(GetDataSourceInstanceState("ds_will_ack_1"),
1724 DataSourceInstanceState::CONFIGURED);
1725 EXPECT_EQ(GetDataSourceInstanceState("ds_wont_ack"),
1726 DataSourceInstanceState::CONFIGURED);
1727 EXPECT_EQ(GetDataSourceInstanceState("ds_will_ack_2"),
1728 DataSourceInstanceState::CONFIGURED);
1729
Primiano Tuccibaeecf12018-07-25 12:02:20 +01001730 producer->WaitForTracingSetup();
Primiano Tucci674076d2018-10-01 10:41:09 +01001731
1732 producer->WaitForDataSourceSetup("ds_will_ack_1");
1733 producer->WaitForDataSourceSetup("ds_wont_ack");
1734 producer->WaitForDataSourceSetup("ds_will_ack_2");
1735
Eric Seckler4ff03e52019-03-15 10:10:30 +00001736 DataSourceInstanceID id1 = producer->GetDataSourceInstanceId("ds_will_ack_1");
1737 DataSourceInstanceID id2 = producer->GetDataSourceInstanceId("ds_will_ack_2");
1738
1739 consumer->StartTracing();
1740
1741 EXPECT_EQ(GetDataSourceInstanceState("ds_will_ack_1"),
1742 DataSourceInstanceState::STARTING);
1743 EXPECT_EQ(GetDataSourceInstanceState("ds_wont_ack"),
1744 DataSourceInstanceState::STARTED);
1745 EXPECT_EQ(GetDataSourceInstanceState("ds_will_ack_2"),
1746 DataSourceInstanceState::STARTED);
1747
Primiano Tuccibaeecf12018-07-25 12:02:20 +01001748 producer->WaitForDataSourceStart("ds_will_ack_1");
1749 producer->WaitForDataSourceStart("ds_wont_ack");
1750 producer->WaitForDataSourceStart("ds_will_ack_2");
1751
Eric Seckler4ff03e52019-03-15 10:10:30 +00001752 producer->endpoint()->NotifyDataSourceStarted(id1);
1753
1754 EXPECT_EQ(GetDataSourceInstanceState("ds_will_ack_1"),
1755 DataSourceInstanceState::STARTED);
1756
Primiano Tuccibaeecf12018-07-25 12:02:20 +01001757 std::unique_ptr<TraceWriter> writer =
1758 producer->CreateTraceWriter("ds_wont_ack");
1759 producer->WaitForFlush(writer.get());
1760
Primiano Tuccibaeecf12018-07-25 12:02:20 +01001761 producer->WaitForDataSourceStop("ds_will_ack_1");
1762 producer->WaitForDataSourceStop("ds_wont_ack");
1763 producer->WaitForDataSourceStop("ds_will_ack_2");
1764
Eric Seckler4ff03e52019-03-15 10:10:30 +00001765 EXPECT_EQ(GetDataSourceInstanceState("ds_will_ack_1"),
1766 DataSourceInstanceState::STOPPING);
1767 EXPECT_EQ(GetDataSourceInstanceState("ds_wont_ack"),
1768 DataSourceInstanceState::STOPPED);
1769 EXPECT_EQ(GetDataSourceInstanceState("ds_will_ack_2"),
1770 DataSourceInstanceState::STOPPING);
1771
Primiano Tuccibaeecf12018-07-25 12:02:20 +01001772 producer->endpoint()->NotifyDataSourceStopped(id1);
1773 producer->endpoint()->NotifyDataSourceStopped(id2);
1774
Eric Seckler4ff03e52019-03-15 10:10:30 +00001775 EXPECT_EQ(GetDataSourceInstanceState("ds_will_ack_1"),
1776 DataSourceInstanceState::STOPPED);
1777 EXPECT_EQ(GetDataSourceInstanceState("ds_will_ack_2"),
1778 DataSourceInstanceState::STOPPED);
1779
Primiano Tuccibaeecf12018-07-25 12:02:20 +01001780 // Wait for at most half of the service timeout, so that this test fails if
1781 // the service falls back on calling the OnTracingDisabled() because some of
1782 // the expected acks weren't received.
1783 consumer->WaitForTracingDisabled(
1784 TracingServiceImpl::kDataSourceStopTimeoutMs / 2);
1785}
1786
Oystein Eftevaagf250e1c2018-08-23 16:10:52 -07001787// Creates a tracing session where a second data source
1788// is added while the service is waiting for DisableTracing
1789// acks; the service should not enable the new datasource
1790// and should not hit any asserts when the consumer is
1791// subsequently destroyed.
1792TEST_F(TracingServiceImplTest, OnDataSourceAddedWhilePendingDisableAcks) {
1793 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
1794 consumer->Connect(svc.get());
1795
1796 std::unique_ptr<MockProducer> producer = CreateMockProducer();
1797 producer->Connect(svc.get(), "mock_producer");
1798 producer->RegisterDataSource("ds_will_ack", /*ack_stop=*/true);
1799
1800 TraceConfig trace_config;
1801 trace_config.add_buffers()->set_size_kb(128);
1802 trace_config.add_data_sources()->mutable_config()->set_name("ds_will_ack");
1803 trace_config.add_data_sources()->mutable_config()->set_name("ds_wont_ack");
1804
1805 consumer->EnableTracing(trace_config);
1806 producer->WaitForTracingSetup();
1807
1808 consumer->DisableTracing();
1809
1810 producer->RegisterDataSource("ds_wont_ack");
1811
1812 consumer.reset();
1813}
1814
Primiano Tuccibaeecf12018-07-25 12:02:20 +01001815// Similar to OnTracingDisabledWaitsForDataSourceStopAcks, but deliberately
1816// skips the ack and checks that the service invokes the OnTracingDisabled()
1817// after the timeout.
1818TEST_F(TracingServiceImplTest, OnTracingDisabledCalledAnywaysInCaseOfTimeout) {
1819 svc->override_data_source_test_timeout_ms_for_testing = 1;
1820 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
1821 consumer->Connect(svc.get());
1822
1823 std::unique_ptr<MockProducer> producer = CreateMockProducer();
1824 producer->Connect(svc.get(), "mock_producer");
1825 producer->RegisterDataSource("data_source", /*ack_stop=*/true);
1826
1827 TraceConfig trace_config;
1828 trace_config.add_buffers()->set_size_kb(128);
1829 trace_config.add_data_sources()->mutable_config()->set_name("data_source");
1830 trace_config.set_duration_ms(1);
1831
1832 consumer->EnableTracing(trace_config);
1833 producer->WaitForTracingSetup();
Primiano Tucci674076d2018-10-01 10:41:09 +01001834 producer->WaitForDataSourceSetup("data_source");
Primiano Tuccibaeecf12018-07-25 12:02:20 +01001835 producer->WaitForDataSourceStart("data_source");
1836
1837 std::unique_ptr<TraceWriter> writer =
1838 producer->CreateTraceWriter("data_source");
1839 producer->WaitForFlush(writer.get());
1840
1841 producer->WaitForDataSourceStop("data_source");
1842 consumer->WaitForTracingDisabled();
1843}
1844
Primiano Tucci03de28f2018-08-01 11:29:46 +01001845// Tests the session_id logic. Two data sources in the same tracing session
1846// should see the same session id.
1847TEST_F(TracingServiceImplTest, SessionId) {
1848 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
1849 consumer->Connect(svc.get());
1850
1851 std::unique_ptr<MockProducer> producer1 = CreateMockProducer();
1852 producer1->Connect(svc.get(), "mock_producer1");
1853 producer1->RegisterDataSource("ds_1A");
1854 producer1->RegisterDataSource("ds_1B");
1855
1856 std::unique_ptr<MockProducer> producer2 = CreateMockProducer();
1857 producer2->Connect(svc.get(), "mock_producer2");
1858 producer2->RegisterDataSource("ds_2A");
1859
1860 testing::InSequence seq;
1861 TracingSessionID last_session_id = 0;
1862 for (int i = 0; i < 3; i++) {
1863 TraceConfig trace_config;
1864 trace_config.add_buffers()->set_size_kb(128);
1865 trace_config.add_data_sources()->mutable_config()->set_name("ds_1A");
1866 trace_config.add_data_sources()->mutable_config()->set_name("ds_1B");
1867 trace_config.add_data_sources()->mutable_config()->set_name("ds_2A");
1868 trace_config.set_duration_ms(1);
1869
1870 consumer->EnableTracing(trace_config);
1871
1872 if (i == 0)
1873 producer1->WaitForTracingSetup();
Primiano Tucci03de28f2018-08-01 11:29:46 +01001874
Primiano Tucci674076d2018-10-01 10:41:09 +01001875 producer1->WaitForDataSourceSetup("ds_1A");
1876 producer1->WaitForDataSourceSetup("ds_1B");
Primiano Tucci03de28f2018-08-01 11:29:46 +01001877 if (i == 0)
1878 producer2->WaitForTracingSetup();
Primiano Tucci674076d2018-10-01 10:41:09 +01001879 producer2->WaitForDataSourceSetup("ds_2A");
1880
1881 producer1->WaitForDataSourceStart("ds_1A");
1882 producer1->WaitForDataSourceStart("ds_1B");
Primiano Tucci03de28f2018-08-01 11:29:46 +01001883 producer2->WaitForDataSourceStart("ds_2A");
1884
1885 auto* ds1 = producer1->GetDataSourceInstance("ds_1A");
1886 auto* ds2 = producer1->GetDataSourceInstance("ds_1B");
1887 auto* ds3 = producer2->GetDataSourceInstance("ds_2A");
1888 ASSERT_EQ(ds1->session_id, ds2->session_id);
1889 ASSERT_EQ(ds1->session_id, ds3->session_id);
1890 ASSERT_NE(ds1->session_id, last_session_id);
1891 last_session_id = ds1->session_id;
1892
1893 auto writer1 = producer1->CreateTraceWriter("ds_1A");
1894 producer1->WaitForFlush(writer1.get());
1895
1896 auto writer2 = producer2->CreateTraceWriter("ds_2A");
1897 producer2->WaitForFlush(writer2.get());
1898
1899 producer1->WaitForDataSourceStop("ds_1A");
1900 producer1->WaitForDataSourceStop("ds_1B");
1901 producer2->WaitForDataSourceStop("ds_2A");
1902 consumer->WaitForTracingDisabled();
1903 consumer->FreeBuffers();
1904 }
1905}
Primiano Tucci9754d0d2018-09-15 12:41:46 +01001906
1907// Writes a long trace and then tests that the trace parsed in partitions
1908// derived by the synchronization markers is identical to the whole trace parsed
1909// in one go.
1910TEST_F(TracingServiceImplTest, ResynchronizeTraceStreamUsingSyncMarker) {
1911 // Setup tracing.
1912 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
1913 consumer->Connect(svc.get());
1914 std::unique_ptr<MockProducer> producer = CreateMockProducer();
1915 producer->Connect(svc.get(), "mock_producer");
1916 producer->RegisterDataSource("data_source");
1917 TraceConfig trace_config;
1918 trace_config.add_buffers()->set_size_kb(4096);
1919 auto* ds_config = trace_config.add_data_sources()->mutable_config();
1920 ds_config->set_name("data_source");
1921 trace_config.set_write_into_file(true);
1922 trace_config.set_file_write_period_ms(1);
1923 base::TempFile tmp_file = base::TempFile::Create();
1924 consumer->EnableTracing(trace_config, base::ScopedFile(dup(tmp_file.fd())));
1925 producer->WaitForTracingSetup();
Primiano Tucci674076d2018-10-01 10:41:09 +01001926 producer->WaitForDataSourceSetup("data_source");
Primiano Tucci9754d0d2018-09-15 12:41:46 +01001927 producer->WaitForDataSourceStart("data_source");
1928
1929 // Write some variable length payload, waiting for sync markers every now
1930 // and then.
1931 const int kNumMarkers = 5;
1932 auto writer = producer->CreateTraceWriter("data_source");
1933 for (int i = 1; i <= 100; i++) {
Florian Mayereff98042018-12-10 17:44:44 +00001934 std::string payload(static_cast<size_t>(i), 'A' + (i % 25));
Primiano Tucci9754d0d2018-09-15 12:41:46 +01001935 writer->NewTracePacket()->set_for_testing()->set_str(payload.c_str());
1936 if (i % (100 / kNumMarkers) == 0) {
1937 writer->Flush();
1938 WaitForNextSyncMarker();
1939 }
1940 }
1941 writer->Flush();
1942 writer.reset();
1943 consumer->DisableTracing();
1944 producer->WaitForDataSourceStop("data_source");
1945 consumer->WaitForTracingDisabled();
1946
1947 std::string trace_raw;
1948 ASSERT_TRUE(base::ReadFile(tmp_file.path().c_str(), &trace_raw));
1949
1950 const auto kMarkerSize = sizeof(TracingServiceImpl::kSyncMarker);
1951 const std::string kSyncMarkerStr(
1952 reinterpret_cast<const char*>(TracingServiceImpl::kSyncMarker),
1953 kMarkerSize);
1954
1955 // Read back the trace in partitions derived from the marker.
1956 // The trace should look like this:
1957 // [uid, marker] [event] [event] [uid, marker] [event] [event]
1958 size_t num_markers = 0;
1959 size_t start = 0;
1960 size_t end = 0;
1961 protos::Trace merged_trace;
1962 for (size_t pos = 0; pos != std::string::npos; start = end) {
1963 pos = trace_raw.find(kSyncMarkerStr, pos + 1);
1964 num_markers++;
1965 end = (pos == std::string::npos) ? trace_raw.size() : pos + kMarkerSize;
1966 int size = static_cast<int>(end - start);
1967 ASSERT_GT(size, 0);
1968 protos::Trace trace_partition;
1969 ASSERT_TRUE(trace_partition.ParseFromArray(trace_raw.data() + start, size));
1970 merged_trace.MergeFrom(trace_partition);
1971 }
Lalit Maganti9bdc7ce2018-09-17 15:25:11 +01001972 EXPECT_GE(num_markers, static_cast<size_t>(kNumMarkers));
Primiano Tucci9754d0d2018-09-15 12:41:46 +01001973
1974 protos::Trace whole_trace;
1975 ASSERT_TRUE(whole_trace.ParseFromString(trace_raw));
1976
1977 ASSERT_EQ(whole_trace.packet_size(), merged_trace.packet_size());
1978 EXPECT_EQ(whole_trace.SerializeAsString(), merged_trace.SerializeAsString());
1979}
1980
Primiano Tucci674076d2018-10-01 10:41:09 +01001981// Creates a tracing session with |deferred_start| and checks that data sources
1982// are started only after calling StartTracing().
1983TEST_F(TracingServiceImplTest, DeferredStart) {
1984 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
1985 consumer->Connect(svc.get());
1986
1987 std::unique_ptr<MockProducer> producer = CreateMockProducer();
1988 producer->Connect(svc.get(), "mock_producer");
1989
1990 // Create two data sources but enable only one of them.
1991 producer->RegisterDataSource("ds_1");
1992 producer->RegisterDataSource("ds_2");
1993
1994 TraceConfig trace_config;
1995 trace_config.add_buffers()->set_size_kb(128);
1996 trace_config.add_data_sources()->mutable_config()->set_name("ds_1");
1997 trace_config.set_deferred_start(true);
1998 trace_config.set_duration_ms(1);
1999
2000 consumer->EnableTracing(trace_config);
2001 producer->WaitForTracingSetup();
2002
2003 producer->WaitForDataSourceSetup("ds_1");
2004
2005 // Make sure we don't get unexpected DataSourceStart() notifications yet.
2006 task_runner.RunUntilIdle();
2007
2008 consumer->StartTracing();
2009
2010 producer->WaitForDataSourceStart("ds_1");
2011
Stephen Nusko1393ffd2019-03-22 13:54:58 +00002012 auto writer = producer->CreateTraceWriter("ds_1");
2013 producer->WaitForFlush(writer.get());
Primiano Tucci674076d2018-10-01 10:41:09 +01002014
2015 producer->WaitForDataSourceStop("ds_1");
2016 consumer->WaitForTracingDisabled();
2017}
2018
Eric Secklerd0ac7ca2019-02-06 09:13:45 +00002019TEST_F(TracingServiceImplTest, ProducerUIDsAndPacketSequenceIDs) {
2020 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
2021 consumer->Connect(svc.get());
2022
2023 std::unique_ptr<MockProducer> producer1 = CreateMockProducer();
2024 producer1->Connect(svc.get(), "mock_producer1", 123u /* uid */);
2025 producer1->RegisterDataSource("data_source");
2026
2027 std::unique_ptr<MockProducer> producer2 = CreateMockProducer();
2028 producer2->Connect(svc.get(), "mock_producer2", 456u /* uid */);
2029 producer2->RegisterDataSource("data_source");
2030
2031 TraceConfig trace_config;
2032 trace_config.add_buffers()->set_size_kb(128);
2033 auto* ds_config = trace_config.add_data_sources()->mutable_config();
2034 ds_config->set_name("data_source");
2035
2036 consumer->EnableTracing(trace_config);
2037 producer1->WaitForTracingSetup();
2038 producer1->WaitForDataSourceSetup("data_source");
2039 producer2->WaitForTracingSetup();
2040 producer2->WaitForDataSourceSetup("data_source");
2041 producer1->WaitForDataSourceStart("data_source");
2042 producer2->WaitForDataSourceStart("data_source");
2043
2044 std::unique_ptr<TraceWriter> writer1a =
2045 producer1->CreateTraceWriter("data_source");
2046 std::unique_ptr<TraceWriter> writer1b =
2047 producer1->CreateTraceWriter("data_source");
2048 std::unique_ptr<TraceWriter> writer2a =
2049 producer2->CreateTraceWriter("data_source");
2050 {
2051 auto tp = writer1a->NewTracePacket();
2052 tp->set_for_testing()->set_str("payload1a1");
2053 tp = writer1b->NewTracePacket();
2054 tp->set_for_testing()->set_str("payload1b1");
2055 tp = writer1a->NewTracePacket();
2056 tp->set_for_testing()->set_str("payload1a2");
2057 tp = writer2a->NewTracePacket();
2058 tp->set_for_testing()->set_str("payload2a1");
2059 tp = writer1b->NewTracePacket();
2060 tp->set_for_testing()->set_str("payload1b2");
2061 }
2062
2063 auto flush_request = consumer->Flush();
2064 producer1->WaitForFlush({writer1a.get(), writer1b.get()});
2065 producer2->WaitForFlush(writer2a.get());
2066 ASSERT_TRUE(flush_request.WaitForReply());
2067
2068 consumer->DisableTracing();
2069 producer1->WaitForDataSourceStop("data_source");
2070 producer2->WaitForDataSourceStop("data_source");
2071 consumer->WaitForTracingDisabled();
2072 auto packets = consumer->ReadBuffers();
2073 EXPECT_THAT(
2074 packets,
2075 Contains(AllOf(
2076 Property(&protos::TracePacket::for_testing,
2077 Property(&protos::TestEvent::str, Eq("payload1a1"))),
2078 Property(&protos::TracePacket::trusted_uid, Eq(123)),
2079 Property(&protos::TracePacket::trusted_packet_sequence_id, Eq(2u)))));
2080 EXPECT_THAT(
2081 packets,
2082 Contains(AllOf(
2083 Property(&protos::TracePacket::for_testing,
2084 Property(&protos::TestEvent::str, Eq("payload1a2"))),
2085 Property(&protos::TracePacket::trusted_uid, Eq(123)),
2086 Property(&protos::TracePacket::trusted_packet_sequence_id, Eq(2u)))));
2087 EXPECT_THAT(
2088 packets,
2089 Contains(AllOf(
2090 Property(&protos::TracePacket::for_testing,
2091 Property(&protos::TestEvent::str, Eq("payload1b1"))),
2092 Property(&protos::TracePacket::trusted_uid, Eq(123)),
2093 Property(&protos::TracePacket::trusted_packet_sequence_id, Eq(3u)))));
2094 EXPECT_THAT(
2095 packets,
2096 Contains(AllOf(
2097 Property(&protos::TracePacket::for_testing,
2098 Property(&protos::TestEvent::str, Eq("payload1b2"))),
2099 Property(&protos::TracePacket::trusted_uid, Eq(123)),
2100 Property(&protos::TracePacket::trusted_packet_sequence_id, Eq(3u)))));
2101 EXPECT_THAT(
2102 packets,
2103 Contains(AllOf(
2104 Property(&protos::TracePacket::for_testing,
2105 Property(&protos::TestEvent::str, Eq("payload2a1"))),
2106 Property(&protos::TracePacket::trusted_uid, Eq(456)),
2107 Property(&protos::TracePacket::trusted_packet_sequence_id, Eq(4u)))));
2108}
2109
Eric Seckler6dc23592018-11-30 10:59:06 +00002110TEST_F(TracingServiceImplTest, AllowedBuffers) {
2111 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
2112 consumer->Connect(svc.get());
2113
2114 std::unique_ptr<MockProducer> producer1 = CreateMockProducer();
2115 producer1->Connect(svc.get(), "mock_producer1");
2116 ProducerID producer1_id = *last_producer_id();
2117 producer1->RegisterDataSource("data_source1");
2118 std::unique_ptr<MockProducer> producer2 = CreateMockProducer();
2119 producer2->Connect(svc.get(), "mock_producer2");
2120 ProducerID producer2_id = *last_producer_id();
2121 producer2->RegisterDataSource("data_source2.1");
2122 producer2->RegisterDataSource("data_source2.2");
2123 producer2->RegisterDataSource("data_source2.3");
2124
2125 EXPECT_EQ(std::set<BufferID>(), GetAllowedTargetBuffers(producer1_id));
2126 EXPECT_EQ(std::set<BufferID>(), GetAllowedTargetBuffers(producer2_id));
2127
2128 TraceConfig trace_config;
2129 trace_config.add_buffers()->set_size_kb(128);
2130 trace_config.add_buffers()->set_size_kb(128);
2131 trace_config.add_buffers()->set_size_kb(128);
2132 auto* ds_config1 = trace_config.add_data_sources()->mutable_config();
2133 ds_config1->set_name("data_source1");
2134 ds_config1->set_target_buffer(0);
2135 auto* ds_config21 = trace_config.add_data_sources()->mutable_config();
2136 ds_config21->set_name("data_source2.1");
2137 ds_config21->set_target_buffer(1);
2138 auto* ds_config22 = trace_config.add_data_sources()->mutable_config();
2139 ds_config22->set_name("data_source2.2");
2140 ds_config22->set_target_buffer(2);
2141 auto* ds_config23 = trace_config.add_data_sources()->mutable_config();
2142 ds_config23->set_name("data_source2.3");
2143 ds_config23->set_target_buffer(2); // same buffer as data_source2.2.
2144 consumer->EnableTracing(trace_config);
2145
Primiano Tucci2abd1152018-12-03 17:00:02 +01002146 ASSERT_EQ(3u, tracing_session()->num_buffers());
Eric Seckler6dc23592018-11-30 10:59:06 +00002147 std::set<BufferID> expected_buffers_producer1 = {
2148 tracing_session()->buffers_index[0]};
2149 std::set<BufferID> expected_buffers_producer2 = {
2150 tracing_session()->buffers_index[1], tracing_session()->buffers_index[2]};
2151 EXPECT_EQ(expected_buffers_producer1, GetAllowedTargetBuffers(producer1_id));
2152 EXPECT_EQ(expected_buffers_producer2, GetAllowedTargetBuffers(producer2_id));
2153
2154 producer1->WaitForTracingSetup();
2155 producer1->WaitForDataSourceSetup("data_source1");
2156
2157 producer2->WaitForTracingSetup();
2158 producer2->WaitForDataSourceSetup("data_source2.1");
2159 producer2->WaitForDataSourceSetup("data_source2.2");
2160 producer2->WaitForDataSourceSetup("data_source2.3");
2161
2162 producer1->WaitForDataSourceStart("data_source1");
2163 producer2->WaitForDataSourceStart("data_source2.1");
2164 producer2->WaitForDataSourceStart("data_source2.2");
2165 producer2->WaitForDataSourceStart("data_source2.3");
2166
2167 producer2->UnregisterDataSource("data_source2.3");
2168 producer2->WaitForDataSourceStop("data_source2.3");
2169
2170 // Should still be allowed to write to buffers 1 (data_source2.1) and 2
2171 // (data_source2.2).
2172 EXPECT_EQ(expected_buffers_producer2, GetAllowedTargetBuffers(producer2_id));
2173
2174 // Calling StartTracing() should be a noop (% a DLOG statement) because the
2175 // trace config didn't have the |deferred_start| flag set.
2176 consumer->StartTracing();
2177
2178 consumer->DisableTracing();
2179 producer1->WaitForDataSourceStop("data_source1");
2180 producer2->WaitForDataSourceStop("data_source2.1");
2181 producer2->WaitForDataSourceStop("data_source2.2");
2182 consumer->WaitForTracingDisabled();
2183
2184 consumer->FreeBuffers();
2185 EXPECT_EQ(std::set<BufferID>(), GetAllowedTargetBuffers(producer1_id));
2186 EXPECT_EQ(std::set<BufferID>(), GetAllowedTargetBuffers(producer2_id));
2187}
2188
Eric Seckler6aa9ece2018-12-06 16:40:12 +00002189#if !PERFETTO_DCHECK_IS_ON()
Eric Secklerdd0ad102018-12-06 11:32:04 +00002190TEST_F(TracingServiceImplTest, CommitToForbiddenBufferIsDiscarded) {
2191 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
2192 consumer->Connect(svc.get());
2193
2194 std::unique_ptr<MockProducer> producer = CreateMockProducer();
2195 producer->Connect(svc.get(), "mock_producer");
2196 ProducerID producer_id = *last_producer_id();
2197 producer->RegisterDataSource("data_source");
2198
2199 EXPECT_EQ(std::set<BufferID>(), GetAllowedTargetBuffers(producer_id));
2200
2201 TraceConfig trace_config;
2202 trace_config.add_buffers()->set_size_kb(128);
2203 trace_config.add_buffers()->set_size_kb(128);
2204 auto* ds_config = trace_config.add_data_sources()->mutable_config();
2205 ds_config->set_name("data_source");
2206 ds_config->set_target_buffer(0);
2207 consumer->EnableTracing(trace_config);
2208
2209 ASSERT_EQ(2u, tracing_session()->num_buffers());
2210 std::set<BufferID> expected_buffers = {tracing_session()->buffers_index[0]};
2211 EXPECT_EQ(expected_buffers, GetAllowedTargetBuffers(producer_id));
2212
2213 producer->WaitForTracingSetup();
2214 producer->WaitForDataSourceSetup("data_source");
2215 producer->WaitForDataSourceStart("data_source");
2216
2217 // Calling StartTracing() should be a noop (% a DLOG statement) because the
2218 // trace config didn't have the |deferred_start| flag set.
2219 consumer->StartTracing();
2220
2221 // Try to write to the correct buffer.
2222 std::unique_ptr<TraceWriter> writer = producer->endpoint()->CreateTraceWriter(
2223 tracing_session()->buffers_index[0]);
2224 {
2225 auto tp = writer->NewTracePacket();
2226 tp->set_for_testing()->set_str("good_payload");
2227 }
2228
2229 auto flush_request = consumer->Flush();
2230 producer->WaitForFlush(writer.get());
2231 ASSERT_TRUE(flush_request.WaitForReply());
2232
2233 // Try to write to the wrong buffer.
2234 writer = producer->endpoint()->CreateTraceWriter(
2235 tracing_session()->buffers_index[1]);
2236 {
2237 auto tp = writer->NewTracePacket();
2238 tp->set_for_testing()->set_str("bad_payload");
2239 }
2240
2241 flush_request = consumer->Flush();
2242 producer->WaitForFlush(writer.get());
2243 ASSERT_TRUE(flush_request.WaitForReply());
2244
2245 consumer->DisableTracing();
2246 producer->WaitForDataSourceStop("data_source");
2247 consumer->WaitForTracingDisabled();
2248
2249 auto packets = consumer->ReadBuffers();
2250 EXPECT_THAT(packets, Contains(Property(&protos::TracePacket::for_testing,
2251 Property(&protos::TestEvent::str,
2252 Eq("good_payload")))));
2253 EXPECT_THAT(packets, Not(Contains(Property(&protos::TracePacket::for_testing,
2254 Property(&protos::TestEvent::str,
2255 Eq("bad_payload"))))));
2256
2257 consumer->FreeBuffers();
2258 EXPECT_EQ(std::set<BufferID>(), GetAllowedTargetBuffers(producer_id));
2259}
Eric Seckler6aa9ece2018-12-06 16:40:12 +00002260#endif // !PERFETTO_DCHECK_IS_ON()
Eric Secklerdd0ad102018-12-06 11:32:04 +00002261
Eric Secklerf3f524b2018-12-13 09:09:34 +00002262TEST_F(TracingServiceImplTest, RegisterAndUnregisterTraceWriter) {
2263 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
2264 consumer->Connect(svc.get());
2265
2266 std::unique_ptr<MockProducer> producer = CreateMockProducer();
2267 producer->Connect(svc.get(), "mock_producer");
2268 ProducerID producer_id = *last_producer_id();
2269 producer->RegisterDataSource("data_source");
2270
2271 EXPECT_TRUE(GetWriters(producer_id).empty());
2272
2273 TraceConfig trace_config;
2274 trace_config.add_buffers()->set_size_kb(128);
2275 auto* ds_config = trace_config.add_data_sources()->mutable_config();
2276 ds_config->set_name("data_source");
2277 ds_config->set_target_buffer(0);
2278 consumer->EnableTracing(trace_config);
2279
2280 producer->WaitForTracingSetup();
2281 producer->WaitForDataSourceSetup("data_source");
2282 producer->WaitForDataSourceStart("data_source");
2283
2284 // Calling StartTracing() should be a noop (% a DLOG statement) because the
2285 // trace config didn't have the |deferred_start| flag set.
2286 consumer->StartTracing();
2287
2288 // Creating the trace writer should register it with the service.
2289 std::unique_ptr<TraceWriter> writer = producer->endpoint()->CreateTraceWriter(
2290 tracing_session()->buffers_index[0]);
2291
2292 WaitForTraceWritersChanged(producer_id);
2293
2294 std::map<WriterID, BufferID> expected_writers;
2295 expected_writers[writer->writer_id()] = tracing_session()->buffers_index[0];
2296 EXPECT_EQ(expected_writers, GetWriters(producer_id));
2297
2298 // Verify writing works.
2299 {
2300 auto tp = writer->NewTracePacket();
2301 tp->set_for_testing()->set_str("payload");
2302 }
2303
2304 auto flush_request = consumer->Flush();
2305 producer->WaitForFlush(writer.get());
2306 ASSERT_TRUE(flush_request.WaitForReply());
2307
2308 // Destroying the writer should unregister it.
2309 writer.reset();
2310 WaitForTraceWritersChanged(producer_id);
2311 EXPECT_TRUE(GetWriters(producer_id).empty());
2312
2313 consumer->DisableTracing();
2314 producer->WaitForDataSourceStop("data_source");
2315 consumer->WaitForTracingDisabled();
2316
2317 auto packets = consumer->ReadBuffers();
2318 EXPECT_THAT(packets, Contains(Property(
2319 &protos::TracePacket::for_testing,
2320 Property(&protos::TestEvent::str, Eq("payload")))));
2321}
2322
Eric Secklera01e28a2019-01-08 11:21:04 +00002323TEST_F(TracingServiceImplTest, ScrapeBuffersOnFlush) {
2324 svc->SetSMBScrapingEnabled(true);
2325
2326 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
2327 consumer->Connect(svc.get());
2328
2329 std::unique_ptr<MockProducer> producer = CreateMockProducer();
2330 producer->Connect(svc.get(), "mock_producer");
2331 ProducerID producer_id = *last_producer_id();
2332 producer->RegisterDataSource("data_source");
2333
2334 TraceConfig trace_config;
2335 trace_config.add_buffers()->set_size_kb(128);
2336 auto* ds_config = trace_config.add_data_sources()->mutable_config();
2337 ds_config->set_name("data_source");
2338 ds_config->set_target_buffer(0);
2339 consumer->EnableTracing(trace_config);
2340
2341 producer->WaitForTracingSetup();
2342 producer->WaitForDataSourceSetup("data_source");
2343 producer->WaitForDataSourceStart("data_source");
2344
2345 // Calling StartTracing() should be a noop (% a DLOG statement) because the
2346 // trace config didn't have the |deferred_start| flag set.
2347 consumer->StartTracing();
2348
2349 std::unique_ptr<TraceWriter> writer = producer->endpoint()->CreateTraceWriter(
2350 tracing_session()->buffers_index[0]);
2351 WaitForTraceWritersChanged(producer_id);
2352
2353 // Write a few trace packets.
2354 writer->NewTracePacket()->set_for_testing()->set_str("payload1");
2355 writer->NewTracePacket()->set_for_testing()->set_str("payload2");
2356 writer->NewTracePacket()->set_for_testing()->set_str("payload3");
2357
2358 // Flush but don't actually flush the chunk from TraceWriter.
2359 auto flush_request = consumer->Flush();
2360 producer->WaitForFlush(nullptr, /*reply=*/true);
2361 ASSERT_TRUE(flush_request.WaitForReply());
2362
2363 // Chunk with the packets should have been scraped. The service can't know
2364 // whether the last packet was completed, so shouldn't read it.
2365 auto packets = consumer->ReadBuffers();
2366 EXPECT_THAT(packets, Contains(Property(
2367 &protos::TracePacket::for_testing,
2368 Property(&protos::TestEvent::str, Eq("payload1")))));
2369 EXPECT_THAT(packets, Contains(Property(
2370 &protos::TracePacket::for_testing,
2371 Property(&protos::TestEvent::str, Eq("payload2")))));
2372 EXPECT_THAT(packets, Not(Contains(Property(&protos::TracePacket::for_testing,
2373 Property(&protos::TestEvent::str,
2374 Eq("payload3"))))));
2375
2376 // Write some more packets.
2377 writer->NewTracePacket()->set_for_testing()->set_str("payload4");
2378 writer->NewTracePacket()->set_for_testing()->set_str("payload5");
2379
2380 // Don't reply to flush, causing a timeout. This should scrape again.
2381 flush_request = consumer->Flush(/*timeout=*/100);
2382 producer->WaitForFlush(nullptr, /*reply=*/false);
2383 ASSERT_FALSE(flush_request.WaitForReply());
2384
2385 // Chunk with the packets should have been scraped again, overriding the
2386 // original one. Again, the last packet should be ignored and the first two
2387 // should not be read twice.
2388 packets = consumer->ReadBuffers();
2389 EXPECT_THAT(packets, Not(Contains(Property(&protos::TracePacket::for_testing,
2390 Property(&protos::TestEvent::str,
2391 Eq("payload1"))))));
2392 EXPECT_THAT(packets, Not(Contains(Property(&protos::TracePacket::for_testing,
2393 Property(&protos::TestEvent::str,
2394 Eq("payload2"))))));
2395 EXPECT_THAT(packets, Contains(Property(
2396 &protos::TracePacket::for_testing,
2397 Property(&protos::TestEvent::str, Eq("payload3")))));
2398 EXPECT_THAT(packets, Contains(Property(
2399 &protos::TracePacket::for_testing,
2400 Property(&protos::TestEvent::str, Eq("payload4")))));
2401 EXPECT_THAT(packets, Not(Contains(Property(&protos::TracePacket::for_testing,
2402 Property(&protos::TestEvent::str,
2403 Eq("payload5"))))));
2404
2405 consumer->DisableTracing();
2406 producer->WaitForDataSourceStop("data_source");
2407 consumer->WaitForTracingDisabled();
2408}
2409
2410// Test scraping on producer disconnect.
2411TEST_F(TracingServiceImplTest, ScrapeBuffersOnProducerDisconnect) {
2412 svc->SetSMBScrapingEnabled(true);
2413
2414 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
2415 consumer->Connect(svc.get());
2416
2417 std::unique_ptr<MockProducer> producer = CreateMockProducer();
2418 producer->Connect(svc.get(), "mock_producer");
2419 ProducerID producer_id = *last_producer_id();
2420 producer->RegisterDataSource("data_source");
2421
2422 TraceConfig trace_config;
2423 trace_config.add_buffers()->set_size_kb(128);
2424 auto* ds_config = trace_config.add_data_sources()->mutable_config();
2425 ds_config->set_name("data_source");
2426 ds_config->set_target_buffer(0);
2427 consumer->EnableTracing(trace_config);
2428
2429 producer->WaitForTracingSetup();
2430 producer->WaitForDataSourceSetup("data_source");
2431 producer->WaitForDataSourceStart("data_source");
2432
2433 // Calling StartTracing() should be a noop (% a DLOG statement) because the
2434 // trace config didn't have the |deferred_start| flag set.
2435 consumer->StartTracing();
2436
2437 std::unique_ptr<TraceWriter> writer = producer->endpoint()->CreateTraceWriter(
2438 tracing_session()->buffers_index[0]);
2439 WaitForTraceWritersChanged(producer_id);
2440
2441 // Write a few trace packets.
2442 writer->NewTracePacket()->set_for_testing()->set_str("payload1");
2443 writer->NewTracePacket()->set_for_testing()->set_str("payload2");
2444 writer->NewTracePacket()->set_for_testing()->set_str("payload3");
2445
2446 // Disconnect the producer without committing the chunk. This should cause a
2447 // scrape of the SMB. Avoid destroying the ShmemArbiter until writer is
2448 // destroyed.
2449 auto shmem_arbiter = TakeShmemArbiterForProducer(producer_id);
2450 producer.reset();
2451
2452 // Chunk with the packets should have been scraped. The service can't know
2453 // whether the last packet was completed, so shouldn't read it.
2454 auto packets = consumer->ReadBuffers();
2455 EXPECT_THAT(packets, Contains(Property(
2456 &protos::TracePacket::for_testing,
2457 Property(&protos::TestEvent::str, Eq("payload1")))));
2458 EXPECT_THAT(packets, Contains(Property(
2459 &protos::TracePacket::for_testing,
2460 Property(&protos::TestEvent::str, Eq("payload2")))));
2461 EXPECT_THAT(packets, Not(Contains(Property(&protos::TracePacket::for_testing,
2462 Property(&protos::TestEvent::str,
2463 Eq("payload3"))))));
2464
2465 // Cleanup writer without causing a crash because the producer already went
2466 // away.
2467 static_cast<TraceWriterImpl*>(writer.get())->ResetChunkForTesting();
2468 writer.reset();
2469 shmem_arbiter.reset();
2470
2471 consumer->DisableTracing();
2472 consumer->WaitForTracingDisabled();
2473}
2474
2475TEST_F(TracingServiceImplTest, ScrapeBuffersOnDisable) {
2476 svc->SetSMBScrapingEnabled(true);
2477
2478 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
2479 consumer->Connect(svc.get());
2480
2481 std::unique_ptr<MockProducer> producer = CreateMockProducer();
2482 producer->Connect(svc.get(), "mock_producer");
2483 ProducerID producer_id = *last_producer_id();
2484 producer->RegisterDataSource("data_source");
2485
2486 TraceConfig trace_config;
2487 trace_config.add_buffers()->set_size_kb(128);
2488 auto* ds_config = trace_config.add_data_sources()->mutable_config();
2489 ds_config->set_name("data_source");
2490 ds_config->set_target_buffer(0);
2491 consumer->EnableTracing(trace_config);
2492
2493 producer->WaitForTracingSetup();
2494 producer->WaitForDataSourceSetup("data_source");
2495 producer->WaitForDataSourceStart("data_source");
2496
2497 // Calling StartTracing() should be a noop (% a DLOG statement) because the
2498 // trace config didn't have the |deferred_start| flag set.
2499 consumer->StartTracing();
2500
2501 std::unique_ptr<TraceWriter> writer = producer->endpoint()->CreateTraceWriter(
2502 tracing_session()->buffers_index[0]);
2503 WaitForTraceWritersChanged(producer_id);
2504
2505 // Write a few trace packets.
2506 writer->NewTracePacket()->set_for_testing()->set_str("payload1");
2507 writer->NewTracePacket()->set_for_testing()->set_str("payload2");
2508 writer->NewTracePacket()->set_for_testing()->set_str("payload3");
2509
2510 consumer->DisableTracing();
2511 producer->WaitForDataSourceStop("data_source");
2512 consumer->WaitForTracingDisabled();
2513
2514 // Chunk with the packets should have been scraped. The service can't know
2515 // whether the last packet was completed, so shouldn't read it.
2516 auto packets = consumer->ReadBuffers();
2517 EXPECT_THAT(packets, Contains(Property(
2518 &protos::TracePacket::for_testing,
2519 Property(&protos::TestEvent::str, Eq("payload1")))));
2520 EXPECT_THAT(packets, Contains(Property(
2521 &protos::TracePacket::for_testing,
2522 Property(&protos::TestEvent::str, Eq("payload2")))));
2523 EXPECT_THAT(packets, Not(Contains(Property(&protos::TracePacket::for_testing,
2524 Property(&protos::TestEvent::str,
2525 Eq("payload3"))))));
2526}
2527
Primiano Tucciff7beab2019-01-09 21:49:20 +00002528TEST_F(TracingServiceImplTest, AbortIfTraceDurationIsTooLong) {
2529 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
2530 consumer->Connect(svc.get());
2531
2532 std::unique_ptr<MockProducer> producer = CreateMockProducer();
2533 producer->Connect(svc.get(), "mock_producer");
2534 producer->RegisterDataSource("datasource");
2535
2536 TraceConfig trace_config;
2537 trace_config.add_buffers()->set_size_kb(128);
2538 trace_config.add_data_sources()->mutable_config()->set_name("datasource");
2539 trace_config.set_duration_ms(0x7fffffff);
2540
2541 EXPECT_CALL(*producer, SetupDataSource(_, _)).Times(0);
2542 consumer->EnableTracing(trace_config);
2543
2544 // The trace is aborted immediately, 5s here is just some slack for the thread
2545 // ping-pongs for slow devices.
2546 consumer->WaitForTracingDisabled(5000);
2547}
2548
Eric Secklereaf29ed2019-01-23 09:53:55 +00002549TEST_F(TracingServiceImplTest, GetTraceStats) {
2550 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
2551 consumer->Connect(svc.get());
2552
2553 consumer->GetTraceStats();
2554 consumer->WaitForTraceStats(false);
2555
2556 std::unique_ptr<MockProducer> producer = CreateMockProducer();
2557 producer->Connect(svc.get(), "mock_producer");
2558 producer->RegisterDataSource("data_source");
2559
2560 TraceConfig trace_config;
2561 trace_config.add_buffers()->set_size_kb(128);
2562 auto* ds_config = trace_config.add_data_sources()->mutable_config();
2563 ds_config->set_name("data_source");
2564
2565 consumer->EnableTracing(trace_config);
2566 producer->WaitForTracingSetup();
2567 producer->WaitForDataSourceSetup("data_source");
2568 producer->WaitForDataSourceStart("data_source");
2569
2570 consumer->GetTraceStats();
2571 consumer->WaitForTraceStats(true);
2572
2573 consumer->DisableTracing();
2574 producer->WaitForDataSourceStop("data_source");
2575 consumer->WaitForTracingDisabled();
2576}
2577
Eric Seckler7b0c9452019-03-18 13:14:36 +00002578TEST_F(TracingServiceImplTest, ObserveEventsDataSourceInstances) {
2579 std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
2580 consumer->Connect(svc.get());
2581
2582 std::unique_ptr<MockProducer> producer = CreateMockProducer();
2583 producer->Connect(svc.get(), "mock_producer");
2584 producer->RegisterDataSource("data_source");
2585
2586 TraceConfig trace_config;
2587 trace_config.add_buffers()->set_size_kb(128);
2588 auto* ds_config = trace_config.add_data_sources()->mutable_config();
2589 ds_config->set_name("data_source");
2590
2591 // Start tracing before the consumer is interested in events. The consumer's
2592 // OnObservableEvents() should not be called yet.
2593 consumer->EnableTracing(trace_config);
2594 producer->WaitForTracingSetup();
2595 producer->WaitForDataSourceSetup("data_source");
2596 producer->WaitForDataSourceStart("data_source");
2597
2598 // Calling ObserveEvents should cause an event for the initial instance state.
2599 consumer->ObserveEvents(TracingService::ConsumerEndpoint::
2600 ObservableEventType::kDataSourceInstances);
2601 {
2602 auto events = consumer->WaitForObservableEvents();
2603
2604 ObservableEvents::DataSourceInstanceStateChange change;
2605 change.set_producer_name("mock_producer");
2606 change.set_data_source_name("data_source");
2607 change.set_state(ObservableEvents::DataSourceInstanceStateChange::
2608 DATA_SOURCE_INSTANCE_STATE_STARTED);
2609 EXPECT_EQ(events.instance_state_changes_size(), 1);
2610 EXPECT_THAT(events.instance_state_changes(), Contains(Eq(change)));
2611 }
2612
2613 // Disabling should cause an instance state change to STOPPED.
2614 consumer->DisableTracing();
2615
2616 {
2617 auto events = consumer->WaitForObservableEvents();
2618
2619 ObservableEvents::DataSourceInstanceStateChange change;
2620 change.set_producer_name("mock_producer");
2621 change.set_data_source_name("data_source");
2622 change.set_state(ObservableEvents::DataSourceInstanceStateChange::
2623 DATA_SOURCE_INSTANCE_STATE_STOPPED);
2624 EXPECT_EQ(events.instance_state_changes_size(), 1);
2625 EXPECT_THAT(events.instance_state_changes(), Contains(Eq(change)));
2626 }
2627
2628 producer->WaitForDataSourceStop("data_source");
2629 consumer->WaitForTracingDisabled();
2630 consumer->FreeBuffers();
2631
2632 // Enable again, this should cause a state change for a new instance to
2633 // its initial state STOPPED.
2634 trace_config.set_deferred_start(true);
2635 consumer->EnableTracing(trace_config);
2636
2637 {
2638 auto events = consumer->WaitForObservableEvents();
2639
2640 ObservableEvents::DataSourceInstanceStateChange change;
2641 change.set_producer_name("mock_producer");
2642 change.set_data_source_name("data_source");
2643 change.set_state(ObservableEvents::DataSourceInstanceStateChange::
2644 DATA_SOURCE_INSTANCE_STATE_STOPPED);
2645 EXPECT_EQ(events.instance_state_changes_size(), 1);
2646 EXPECT_THAT(events.instance_state_changes(), Contains(Eq(change)));
2647 }
2648
2649 producer->WaitForDataSourceSetup("data_source");
2650
2651 // Should move the instance into STARTED state and thus cause an event.
2652 consumer->StartTracing();
2653
2654 {
2655 auto events = consumer->WaitForObservableEvents();
2656
2657 ObservableEvents::DataSourceInstanceStateChange change;
2658 change.set_producer_name("mock_producer");
2659 change.set_data_source_name("data_source");
2660 change.set_state(ObservableEvents::DataSourceInstanceStateChange::
2661 DATA_SOURCE_INSTANCE_STATE_STARTED);
2662 EXPECT_EQ(events.instance_state_changes_size(), 1);
2663 EXPECT_THAT(events.instance_state_changes(), Contains(Eq(change)));
2664 }
2665
2666 producer->WaitForDataSourceStart("data_source");
2667
2668 // Stop observing events.
2669 consumer->ObserveEvents(
2670 TracingService::ConsumerEndpoint::ObservableEventType::kNone);
2671
2672 // Disabling should now no longer cause events to be sent to the consumer.
2673 consumer->DisableTracing();
2674 producer->WaitForDataSourceStop("data_source");
2675 consumer->WaitForTracingDisabled();
2676}
2677
Primiano Tucci4f9b6d72017-12-05 20:59:16 +00002678} // namespace perfetto