Deflake TracingServiceImplTest.WriteIntoFileAndStopOnMaxSize.
The test was asserting the wrong properties and passing for the wrong reasons.
It independently checked that: (a) there's at least 10 packets in the file, (b)
a prefix of the test packets has the expected payloads (but not that all test
packets are accounted for).
What was happening in practice is that in the passing case, the 512 bytes were
filled with the 4 preamble packets (sync marker, clock snapshot, trace stats,
trace config), followed by 6 (out of 10 expected) test packets.
The test became flaky as that combined size of these 10 packets became very
close to 512 bytes in practice, s.t. sometimes the 6th test packet could not
fit (-> there would only be 9 packets in the file). A possible explanation of
why the issue manifested as being timing dependent - varint encoding of
timestamps, slower test execution -> over the threshold for fitting the 10th
packet in 512 bytes.
I've decided to assert the number of preamble packets strictly (making this a bit of a
change-detector test), erring on the side of eager and obvious failures if someone
changes the preamble format significantly.
(Credit for most of the debugging goes to Lalit)
Change-Id: I13951dc4756d76327a1bbf611828fe5c91201700
diff --git a/src/tracing/core/service_impl_unittest.cc b/src/tracing/core/service_impl_unittest.cc
index 5a0ca16..77d49e5 100644
--- a/src/tracing/core/service_impl_unittest.cc
+++ b/src/tracing/core/service_impl_unittest.cc
@@ -292,6 +292,10 @@
ASSERT_EQ(6u, connect_producer_and_get_id("6"));
}
+// Note: file_write_period_ms is set to a large enough to have exactly one flush
+// of the tracing buffers (and therefore at most one synchronization section),
+// unless the test runs unrealistically slowly, or the implementation of the
+// tracing snapshot packets changes.
TEST_F(TracingServiceImplTest, WriteIntoFileAndStopOnMaxSize) {
std::unique_ptr<MockConsumer> consumer = CreateMockConsumer();
consumer->Connect(svc.get());
@@ -306,8 +310,8 @@
ds_config->set_name("data_source");
ds_config->set_target_buffer(0);
trace_config.set_write_into_file(true);
- trace_config.set_file_write_period_ms(1);
- const uint64_t kMaxFileSize = 512;
+ trace_config.set_file_write_period_ms(100000); // 100s
+ const uint64_t kMaxFileSize = 1024;
trace_config.set_max_file_size_bytes(kMaxFileSize);
base::TempFile tmp_file = base::TempFile::Create();
consumer->EnableTracing(trace_config, base::ScopedFile(dup(tmp_file.fd())));
@@ -316,13 +320,16 @@
producer->WaitForDataSourceSetup("data_source");
producer->WaitForDataSourceStart("data_source");
+ static const int kNumPreamblePackets = 4;
+ static const int kNumTestPackets = 10;
static const char kPayload[] = "1234567890abcdef-";
- static const int kNumPackets = 10;
std::unique_ptr<TraceWriter> writer =
producer->CreateTraceWriter("data_source");
- // All these packets should fit within kMaxFileSize.
- for (int i = 0; i < kNumPackets; i++) {
+ // Tracing service will emit a preamble of packets (a synchronization section,
+ // followed by a tracing config packet). The preamble and these test packets
+ // should fit within kMaxFileSize.
+ for (int i = 0; i < kNumTestPackets; i++) {
auto tp = writer->NewTracePacket();
std::string payload(kPayload);
payload.append(std::to_string(i));
@@ -348,14 +355,11 @@
ASSERT_TRUE(base::ReadFile(tmp_file.path().c_str(), &trace_raw));
protos::Trace trace;
ASSERT_TRUE(trace.ParseFromString(trace_raw));
- ASSERT_GE(trace.packet_size(), kNumPackets);
- int num_testing_packet = 0;
- for (int i = 0; i < trace.packet_size(); i++) {
- const protos::TracePacket& tp = trace.packet(i);
- if (!tp.has_for_testing())
- continue;
- ASSERT_EQ(kPayload + std::to_string(num_testing_packet++),
- tp.for_testing().str());
+
+ ASSERT_EQ(trace.packet_size(), kNumPreamblePackets + kNumTestPackets);
+ for (int i = 0; i < kNumTestPackets; i++) {
+ const protos::TracePacket& tp = trace.packet(kNumPreamblePackets + i);
+ ASSERT_EQ(kPayload + std::to_string(i++), tp.for_testing().str());
}
}