blob: 3d997570d22072df672a4abb49336c56b962cf40 [file] [log] [blame]
Austin Schuhc243b422020-10-11 15:35:08 -07001#include "aos/events/logging/logfile_utils.h"
2
Austin Schuhe243aaf2020-10-11 15:46:02 -07003#include <chrono>
Austin Schuhfa30c352022-10-16 11:12:02 -07004#include <random>
Austin Schuhe243aaf2020-10-11 15:46:02 -07005#include <string>
Austin Schuhc243b422020-10-11 15:35:08 -07006
Austin Schuhfa30c352022-10-16 11:12:02 -07007#include "absl/strings/escaping.h"
Austin Schuhc41603c2020-10-11 16:17:37 -07008#include "aos/events/logging/logfile_sorting.h"
Austin Schuhc243b422020-10-11 15:35:08 -07009#include "aos/events/logging/test_message_generated.h"
Austin Schuh4b5c22a2020-11-30 22:58:43 -080010#include "aos/flatbuffer_merge.h"
Austin Schuhe243aaf2020-10-11 15:46:02 -070011#include "aos/flatbuffers.h"
Austin Schuhc243b422020-10-11 15:35:08 -070012#include "aos/json_to_flatbuffer.h"
Austin Schuhfa30c352022-10-16 11:12:02 -070013#include "aos/testing/path.h"
14#include "aos/testing/random_seed.h"
Austin Schuhc243b422020-10-11 15:35:08 -070015#include "aos/testing/tmpdir.h"
Austin Schuhfa30c352022-10-16 11:12:02 -070016#include "aos/util/file.h"
17#include "external/com_github_google_flatbuffers/src/annotated_binary_text_gen.h"
18#include "external/com_github_google_flatbuffers/src/binary_annotator.h"
19#include "flatbuffers/reflection_generated.h"
Brian Smarttea913d42021-12-10 15:02:38 -080020#include "gflags/gflags.h"
Austin Schuhe243aaf2020-10-11 15:46:02 -070021#include "gtest/gtest.h"
Austin Schuhc243b422020-10-11 15:35:08 -070022
23namespace aos {
24namespace logger {
25namespace testing {
Austin Schuhe243aaf2020-10-11 15:46:02 -070026namespace chrono = std::chrono;
Austin Schuhfa30c352022-10-16 11:12:02 -070027using aos::testing::ArtifactPath;
Austin Schuhf2d0e682022-10-16 14:20:58 -070028using aos::message_bridge::RemoteMessage;
Austin Schuhc243b422020-10-11 15:35:08 -070029
Austin Schuhd863e6e2022-10-16 15:44:50 -070030// Adapter class to make it easy to test DetachedBufferWriter without adding
31// test only boilerplate to DetachedBufferWriter.
32class TestDetachedBufferWriter : public DetachedBufferWriter {
33 public:
Austin Schuh48d10d62022-10-16 22:19:23 -070034 // Pick a max size that is rather conservative.
35 static constexpr size_t kMaxMessageSize = 128 * 1024;
Austin Schuhd863e6e2022-10-16 15:44:50 -070036 TestDetachedBufferWriter(std::string_view filename)
Austin Schuh48d10d62022-10-16 22:19:23 -070037 : DetachedBufferWriter(filename,
38 std::make_unique<DummyEncoder>(kMaxMessageSize)) {}
Austin Schuhd863e6e2022-10-16 15:44:50 -070039 void WriteSizedFlatbuffer(flatbuffers::DetachedBuffer &&buffer) {
40 QueueSpan(absl::Span<const uint8_t>(buffer.data(), buffer.size()));
41 }
42};
43
Austin Schuhe243aaf2020-10-11 15:46:02 -070044// Creates a size prefixed flatbuffer from json.
Austin Schuhc243b422020-10-11 15:35:08 -070045template <typename T>
46SizePrefixedFlatbufferDetachedBuffer<T> JsonToSizedFlatbuffer(
47 const std::string_view data) {
48 flatbuffers::FlatBufferBuilder fbb;
49 fbb.ForceDefaults(true);
50 fbb.FinishSizePrefixed(JsonToFlatbuffer<T>(data, &fbb));
51 return fbb.Release();
52}
53
Austin Schuhe243aaf2020-10-11 15:46:02 -070054// Tests that we can write and read 2 flatbuffers to file.
Austin Schuhc243b422020-10-11 15:35:08 -070055TEST(SpanReaderTest, ReadWrite) {
56 const std::string logfile = aos::testing::TestTmpDir() + "/log.bfbs";
57 unlink(logfile.c_str());
58
59 const aos::SizePrefixedFlatbufferDetachedBuffer<TestMessage> m1 =
Austin Schuh4b5c22a2020-11-30 22:58:43 -080060 JsonToSizedFlatbuffer<TestMessage>(R"({ "value": 1 })");
Austin Schuhc243b422020-10-11 15:35:08 -070061 const aos::SizePrefixedFlatbufferDetachedBuffer<TestMessage> m2 =
Austin Schuh4b5c22a2020-11-30 22:58:43 -080062 JsonToSizedFlatbuffer<TestMessage>(R"({ "value": 2 })");
Austin Schuhc243b422020-10-11 15:35:08 -070063
64 {
Austin Schuhd863e6e2022-10-16 15:44:50 -070065 TestDetachedBufferWriter writer(logfile);
Austin Schuhadd6eb32020-11-09 21:24:26 -080066 writer.QueueSpan(m1.span());
67 writer.QueueSpan(m2.span());
Austin Schuhc243b422020-10-11 15:35:08 -070068 }
69
70 SpanReader reader(logfile);
71
72 EXPECT_EQ(reader.filename(), logfile);
Austin Schuhcf5f6442021-07-06 10:43:28 -070073 EXPECT_EQ(reader.PeekMessage(), m1.span());
74 EXPECT_EQ(reader.PeekMessage(), m1.span());
Austin Schuhadd6eb32020-11-09 21:24:26 -080075 EXPECT_EQ(reader.ReadMessage(), m1.span());
76 EXPECT_EQ(reader.ReadMessage(), m2.span());
Austin Schuhcf5f6442021-07-06 10:43:28 -070077 EXPECT_EQ(reader.PeekMessage(), absl::Span<const uint8_t>());
Austin Schuhc243b422020-10-11 15:35:08 -070078 EXPECT_EQ(reader.ReadMessage(), absl::Span<const uint8_t>());
79}
80
Austin Schuhe243aaf2020-10-11 15:46:02 -070081// Tests that we can actually parse the resulting messages at a basic level
82// through MessageReader.
83TEST(MessageReaderTest, ReadWrite) {
84 const std::string logfile = aos::testing::TestTmpDir() + "/log.bfbs";
85 unlink(logfile.c_str());
86
87 const aos::SizePrefixedFlatbufferDetachedBuffer<LogFileHeader> config =
88 JsonToSizedFlatbuffer<LogFileHeader>(
89 R"({ "max_out_of_order_duration": 100000000 })");
90 const aos::SizePrefixedFlatbufferDetachedBuffer<MessageHeader> m1 =
91 JsonToSizedFlatbuffer<MessageHeader>(
92 R"({ "channel_index": 0, "monotonic_sent_time": 1 })");
93 const aos::SizePrefixedFlatbufferDetachedBuffer<MessageHeader> m2 =
94 JsonToSizedFlatbuffer<MessageHeader>(
95 R"({ "channel_index": 0, "monotonic_sent_time": 2 })");
96
97 {
Austin Schuhd863e6e2022-10-16 15:44:50 -070098 TestDetachedBufferWriter writer(logfile);
Austin Schuhadd6eb32020-11-09 21:24:26 -080099 writer.QueueSpan(config.span());
100 writer.QueueSpan(m1.span());
101 writer.QueueSpan(m2.span());
Austin Schuhe243aaf2020-10-11 15:46:02 -0700102 }
103
104 MessageReader reader(logfile);
105
106 EXPECT_EQ(reader.filename(), logfile);
107
108 EXPECT_EQ(
109 reader.max_out_of_order_duration(),
110 std::chrono::nanoseconds(config.message().max_out_of_order_duration()));
111 EXPECT_EQ(reader.newest_timestamp(), monotonic_clock::min_time);
112 EXPECT_TRUE(reader.ReadMessage());
113 EXPECT_EQ(reader.newest_timestamp(),
114 monotonic_clock::time_point(chrono::nanoseconds(1)));
115 EXPECT_TRUE(reader.ReadMessage());
116 EXPECT_EQ(reader.newest_timestamp(),
117 monotonic_clock::time_point(chrono::nanoseconds(2)));
118 EXPECT_FALSE(reader.ReadMessage());
119}
120
Austin Schuh32f68492020-11-08 21:45:51 -0800121// Tests that we explode when messages are too far out of order.
122TEST(PartsMessageReaderDeathTest, TooFarOutOfOrder) {
123 const std::string logfile0 = aos::testing::TestTmpDir() + "/log0.bfbs";
124 unlink(logfile0.c_str());
125
126 const aos::SizePrefixedFlatbufferDetachedBuffer<LogFileHeader> config0 =
127 JsonToSizedFlatbuffer<LogFileHeader>(
128 R"({
129 "max_out_of_order_duration": 100000000,
Austin Schuh0ca51f32020-12-25 21:51:45 -0800130 "configuration": {},
Austin Schuh32f68492020-11-08 21:45:51 -0800131 "log_event_uuid": "30ef1283-81d7-4004-8c36-1c162dbcb2b2",
132 "parts_uuid": "2a05d725-5d5c-4c0b-af42-88de2f3c3876",
133 "parts_index": 0
134})");
135
136 const aos::SizePrefixedFlatbufferDetachedBuffer<MessageHeader> m1 =
137 JsonToSizedFlatbuffer<MessageHeader>(
138 R"({ "channel_index": 0, "monotonic_sent_time": 100000000 })");
139 const aos::SizePrefixedFlatbufferDetachedBuffer<MessageHeader> m2 =
140 JsonToSizedFlatbuffer<MessageHeader>(
141 R"({ "channel_index": 0, "monotonic_sent_time": 0 })");
142 const aos::SizePrefixedFlatbufferDetachedBuffer<MessageHeader> m3 =
143 JsonToSizedFlatbuffer<MessageHeader>(
144 R"({ "channel_index": 0, "monotonic_sent_time": -1 })");
145
146 {
Austin Schuhd863e6e2022-10-16 15:44:50 -0700147 TestDetachedBufferWriter writer(logfile0);
Austin Schuhadd6eb32020-11-09 21:24:26 -0800148 writer.QueueSpan(config0.span());
149 writer.QueueSpan(m1.span());
150 writer.QueueSpan(m2.span());
151 writer.QueueSpan(m3.span());
Austin Schuh32f68492020-11-08 21:45:51 -0800152 }
153
154 const std::vector<LogFile> parts = SortParts({logfile0});
155
156 PartsMessageReader reader(parts[0].parts[0]);
157
158 EXPECT_TRUE(reader.ReadMessage());
159 EXPECT_TRUE(reader.ReadMessage());
160 EXPECT_DEATH({ reader.ReadMessage(); }, "-0.000000001sec vs. 0.000000000sec");
161}
162
Austin Schuhc41603c2020-10-11 16:17:37 -0700163// Tests that we can transparently re-assemble part files with a
164// PartsMessageReader.
165TEST(PartsMessageReaderTest, ReadWrite) {
166 const std::string logfile0 = aos::testing::TestTmpDir() + "/log0.bfbs";
167 const std::string logfile1 = aos::testing::TestTmpDir() + "/log1.bfbs";
168 unlink(logfile0.c_str());
169 unlink(logfile1.c_str());
170
171 const aos::SizePrefixedFlatbufferDetachedBuffer<LogFileHeader> config0 =
172 JsonToSizedFlatbuffer<LogFileHeader>(
173 R"({
174 "max_out_of_order_duration": 100000000,
Austin Schuh0ca51f32020-12-25 21:51:45 -0800175 "configuration": {},
Austin Schuhc41603c2020-10-11 16:17:37 -0700176 "log_event_uuid": "30ef1283-81d7-4004-8c36-1c162dbcb2b2",
177 "parts_uuid": "2a05d725-5d5c-4c0b-af42-88de2f3c3876",
178 "parts_index": 0
179})");
180 const aos::SizePrefixedFlatbufferDetachedBuffer<LogFileHeader> config1 =
181 JsonToSizedFlatbuffer<LogFileHeader>(
182 R"({
183 "max_out_of_order_duration": 200000000,
184 "monotonic_start_time": 0,
185 "realtime_start_time": 0,
Austin Schuh0ca51f32020-12-25 21:51:45 -0800186 "configuration": {},
Austin Schuhc41603c2020-10-11 16:17:37 -0700187 "log_event_uuid": "30ef1283-81d7-4004-8c36-1c162dbcb2b2",
188 "parts_uuid": "2a05d725-5d5c-4c0b-af42-88de2f3c3876",
189 "parts_index": 1
190})");
191
192 const aos::SizePrefixedFlatbufferDetachedBuffer<MessageHeader> m1 =
193 JsonToSizedFlatbuffer<MessageHeader>(
194 R"({ "channel_index": 0, "monotonic_sent_time": 1 })");
195 const aos::SizePrefixedFlatbufferDetachedBuffer<MessageHeader> m2 =
196 JsonToSizedFlatbuffer<MessageHeader>(
197 R"({ "channel_index": 0, "monotonic_sent_time": 2 })");
198
199 {
Austin Schuhd863e6e2022-10-16 15:44:50 -0700200 TestDetachedBufferWriter writer(logfile0);
Austin Schuhadd6eb32020-11-09 21:24:26 -0800201 writer.QueueSpan(config0.span());
202 writer.QueueSpan(m1.span());
Austin Schuhc41603c2020-10-11 16:17:37 -0700203 }
204 {
Austin Schuhd863e6e2022-10-16 15:44:50 -0700205 TestDetachedBufferWriter writer(logfile1);
Austin Schuhadd6eb32020-11-09 21:24:26 -0800206 writer.QueueSpan(config1.span());
207 writer.QueueSpan(m2.span());
Austin Schuhc41603c2020-10-11 16:17:37 -0700208 }
209
210 const std::vector<LogFile> parts = SortParts({logfile0, logfile1});
211
212 PartsMessageReader reader(parts[0].parts[0]);
213
214 EXPECT_EQ(reader.filename(), logfile0);
215
216 // Confirm that the timestamps track, and the filename also updates.
217 // Read the first message.
218 EXPECT_EQ(reader.newest_timestamp(), monotonic_clock::min_time);
219 EXPECT_EQ(
220 reader.max_out_of_order_duration(),
221 std::chrono::nanoseconds(config0.message().max_out_of_order_duration()));
222 EXPECT_TRUE(reader.ReadMessage());
223 EXPECT_EQ(reader.filename(), logfile0);
224 EXPECT_EQ(reader.newest_timestamp(),
225 monotonic_clock::time_point(chrono::nanoseconds(1)));
226 EXPECT_EQ(
227 reader.max_out_of_order_duration(),
228 std::chrono::nanoseconds(config0.message().max_out_of_order_duration()));
229
230 // Read the second message.
231 EXPECT_TRUE(reader.ReadMessage());
232 EXPECT_EQ(reader.filename(), logfile1);
233 EXPECT_EQ(reader.newest_timestamp(),
234 monotonic_clock::time_point(chrono::nanoseconds(2)));
235 EXPECT_EQ(
236 reader.max_out_of_order_duration(),
237 std::chrono::nanoseconds(config1.message().max_out_of_order_duration()));
238
239 // And then confirm that reading again returns no message.
240 EXPECT_FALSE(reader.ReadMessage());
241 EXPECT_EQ(reader.filename(), logfile1);
242 EXPECT_EQ(
243 reader.max_out_of_order_duration(),
244 std::chrono::nanoseconds(config1.message().max_out_of_order_duration()));
Austin Schuh32f68492020-11-08 21:45:51 -0800245 EXPECT_EQ(reader.newest_timestamp(), monotonic_clock::max_time);
Austin Schuhc41603c2020-10-11 16:17:37 -0700246}
Austin Schuh32f68492020-11-08 21:45:51 -0800247
Austin Schuh1be0ce42020-11-29 22:43:26 -0800248// Tests that Message's operator < works as expected.
249TEST(MessageTest, Sorting) {
250 const aos::monotonic_clock::time_point e = monotonic_clock::epoch();
251
252 Message m1{.channel_index = 0,
Austin Schuh58646e22021-08-23 23:51:46 -0700253 .queue_index = BootQueueIndex{.boot = 0, .index = 0u},
Austin Schuh2dc8c7d2021-07-01 17:41:28 -0700254 .timestamp =
255 BootTimestamp{.boot = 0, .time = e + chrono::milliseconds(1)},
Austin Schuh48507722021-07-17 17:29:24 -0700256 .monotonic_remote_boot = 0xffffff,
257 .monotonic_timestamp_boot = 0xffffff,
Tyler Chatowb7c6eba2021-07-28 14:43:23 -0700258 .data = nullptr};
Austin Schuh1be0ce42020-11-29 22:43:26 -0800259 Message m2{.channel_index = 0,
Austin Schuh58646e22021-08-23 23:51:46 -0700260 .queue_index = BootQueueIndex{.boot = 0, .index = 0u},
Austin Schuh2dc8c7d2021-07-01 17:41:28 -0700261 .timestamp =
262 BootTimestamp{.boot = 0, .time = e + chrono::milliseconds(2)},
Austin Schuh48507722021-07-17 17:29:24 -0700263 .monotonic_remote_boot = 0xffffff,
264 .monotonic_timestamp_boot = 0xffffff,
Tyler Chatowb7c6eba2021-07-28 14:43:23 -0700265 .data = nullptr};
Austin Schuh1be0ce42020-11-29 22:43:26 -0800266
267 EXPECT_LT(m1, m2);
268 EXPECT_GE(m2, m1);
269
Austin Schuh2dc8c7d2021-07-01 17:41:28 -0700270 m1.timestamp.time = e;
271 m2.timestamp.time = e;
Austin Schuh1be0ce42020-11-29 22:43:26 -0800272
273 m1.channel_index = 1;
274 m2.channel_index = 2;
275
276 EXPECT_LT(m1, m2);
277 EXPECT_GE(m2, m1);
278
279 m1.channel_index = 0;
280 m2.channel_index = 0;
Austin Schuh58646e22021-08-23 23:51:46 -0700281 m1.queue_index.index = 0u;
282 m2.queue_index.index = 1u;
Austin Schuh1be0ce42020-11-29 22:43:26 -0800283
284 EXPECT_LT(m1, m2);
285 EXPECT_GE(m2, m1);
286}
287
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800288aos::SizePrefixedFlatbufferDetachedBuffer<LogFileHeader> MakeHeader(
289 const aos::FlatbufferDetachedBuffer<Configuration> &config,
290 const std::string_view json) {
291 flatbuffers::FlatBufferBuilder fbb;
Austin Schuh1034a832021-03-31 21:53:26 -0700292 fbb.ForceDefaults(true);
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800293 flatbuffers::Offset<Configuration> config_offset =
294 aos::CopyFlatBuffer(config, &fbb);
295 LogFileHeader::Builder header_builder(fbb);
296 header_builder.add_configuration(config_offset);
297 fbb.Finish(header_builder.Finish());
298 aos::FlatbufferDetachedBuffer<LogFileHeader> config_header(fbb.Release());
299
300 aos::FlatbufferDetachedBuffer<LogFileHeader> header_updates(
301 JsonToFlatbuffer<LogFileHeader>(json));
302 CHECK(header_updates.Verify());
303 flatbuffers::FlatBufferBuilder fbb2;
Austin Schuh1034a832021-03-31 21:53:26 -0700304 fbb2.ForceDefaults(true);
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800305 fbb2.FinishSizePrefixed(
306 aos::MergeFlatBuffers(config_header, header_updates, &fbb2));
307 return fbb2.Release();
308}
309
310class SortingElementTest : public ::testing::Test {
311 public:
312 SortingElementTest()
313 : config_(JsonToFlatbuffer<Configuration>(
314 R"({
315 "channels": [
316 {
317 "name": "/a",
318 "type": "aos.logger.testing.TestMessage",
319 "source_node": "pi1",
320 "destination_nodes": [
321 {
322 "name": "pi2"
323 },
324 {
325 "name": "pi3"
326 }
327 ]
328 },
329 {
330 "name": "/b",
331 "type": "aos.logger.testing.TestMessage",
332 "source_node": "pi1"
333 },
334 {
335 "name": "/c",
336 "type": "aos.logger.testing.TestMessage",
337 "source_node": "pi1"
Austin Schuh48507722021-07-17 17:29:24 -0700338 },
339 {
340 "name": "/d",
341 "type": "aos.logger.testing.TestMessage",
342 "source_node": "pi2",
343 "destination_nodes": [
344 {
345 "name": "pi1"
346 }
347 ]
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800348 }
349 ],
350 "nodes": [
351 {
352 "name": "pi1"
353 },
354 {
355 "name": "pi2"
356 },
357 {
358 "name": "pi3"
359 }
360 ]
361}
362)")),
363 config0_(MakeHeader(config_, R"({
364 /* 100ms */
365 "max_out_of_order_duration": 100000000,
366 "node": {
367 "name": "pi1"
368 },
369 "logger_node": {
370 "name": "pi1"
371 },
Austin Schuhd2f96102020-12-01 20:27:29 -0800372 "monotonic_start_time": 1000000,
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800373 "realtime_start_time": 1000000000000,
374 "log_event_uuid": "30ef1283-81d7-4004-8c36-1c162dbcb2b2",
Austin Schuh48507722021-07-17 17:29:24 -0700375 "source_node_boot_uuid": "1d782c63-b3c7-466e-bea9-a01308b43333",
376 "logger_node_boot_uuid": "1d782c63-b3c7-466e-bea9-a01308b43333",
377 "boot_uuids": [
378 "1d782c63-b3c7-466e-bea9-a01308b43333",
379 "",
380 ""
381 ],
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800382 "parts_uuid": "2a05d725-5d5c-4c0b-af42-88de2f3c3876",
383 "parts_index": 0
384})")),
385 config1_(MakeHeader(config_,
386 R"({
387 /* 100ms */
388 "max_out_of_order_duration": 100000000,
389 "node": {
390 "name": "pi1"
391 },
392 "logger_node": {
393 "name": "pi1"
394 },
Austin Schuhd2f96102020-12-01 20:27:29 -0800395 "monotonic_start_time": 1000000,
396 "realtime_start_time": 1000000000000,
397 "log_event_uuid": "30ef1283-81d7-4004-8c36-1c162dbcb2b2",
Austin Schuh48507722021-07-17 17:29:24 -0700398 "source_node_boot_uuid": "1d782c63-b3c7-466e-bea9-a01308b43333",
399 "logger_node_boot_uuid": "1d782c63-b3c7-466e-bea9-a01308b43333",
400 "boot_uuids": [
401 "1d782c63-b3c7-466e-bea9-a01308b43333",
402 "",
403 ""
404 ],
Austin Schuhd2f96102020-12-01 20:27:29 -0800405 "parts_uuid": "bafe9f8e-7dea-4bd9-95f5-3d8390e49208",
406 "parts_index": 0
407})")),
408 config2_(MakeHeader(config_,
409 R"({
410 /* 100ms */
411 "max_out_of_order_duration": 100000000,
412 "node": {
413 "name": "pi2"
414 },
415 "logger_node": {
416 "name": "pi2"
417 },
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800418 "monotonic_start_time": 0,
419 "realtime_start_time": 1000000000000,
Austin Schuh48507722021-07-17 17:29:24 -0700420 "source_node_boot_uuid": "6f4269ec-547f-4a1a-8281-37aca7fe5dc2",
421 "logger_node_boot_uuid": "6f4269ec-547f-4a1a-8281-37aca7fe5dc2",
422 "boot_uuids": [
423 "",
424 "6f4269ec-547f-4a1a-8281-37aca7fe5dc2",
425 ""
426 ],
Austin Schuhd2f96102020-12-01 20:27:29 -0800427 "log_event_uuid": "cb89a1ce-c4b6-4747-a647-051f09ac888c",
428 "parts_uuid": "e6bff6c6-757f-4675-90d8-3bfb642870e6",
429 "parts_index": 0
430})")),
431 config3_(MakeHeader(config_,
432 R"({
433 /* 100ms */
434 "max_out_of_order_duration": 100000000,
435 "node": {
436 "name": "pi1"
437 },
438 "logger_node": {
439 "name": "pi1"
440 },
441 "monotonic_start_time": 2000000,
442 "realtime_start_time": 1000000000,
443 "log_event_uuid": "cb26b86a-473e-4f74-8403-50eb92ed60ad",
Austin Schuh48507722021-07-17 17:29:24 -0700444 "source_node_boot_uuid": "1d782c63-b3c7-466e-bea9-a01308b43333",
445 "logger_node_boot_uuid": "1d782c63-b3c7-466e-bea9-a01308b43333",
446 "boot_uuids": [
447 "1d782c63-b3c7-466e-bea9-a01308b43333",
448 "",
449 ""
450 ],
Austin Schuhd2f96102020-12-01 20:27:29 -0800451 "parts_uuid": "1f098701-949f-4392-81f9-be463e2d7bd4",
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800452 "parts_index": 0
Austin Schuh8bf1e632021-01-02 22:41:04 -0800453})")),
454 config4_(MakeHeader(config_,
455 R"({
456 /* 100ms */
457 "max_out_of_order_duration": 100000000,
458 "node": {
459 "name": "pi2"
460 },
461 "logger_node": {
462 "name": "pi1"
463 },
464 "monotonic_start_time": 2000000,
465 "realtime_start_time": 1000000000,
466 "log_event_uuid": "30ef1283-81d7-4004-8c36-1c162dbcb2b2",
467 "parts_uuid": "4e560a47-e2a6-4ce3-a925-490bebc947c5",
Austin Schuh48507722021-07-17 17:29:24 -0700468 "source_node_boot_uuid": "6f4269ec-547f-4a1a-8281-37aca7fe5dc2",
469 "logger_node_boot_uuid": "1d782c63-b3c7-466e-bea9-a01308b43333",
470 "boot_uuids": [
471 "1d782c63-b3c7-466e-bea9-a01308b43333",
472 "6f4269ec-547f-4a1a-8281-37aca7fe5dc2",
473 ""
474 ],
Austin Schuh8bf1e632021-01-02 22:41:04 -0800475 "parts_index": 0
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800476})")) {
477 unlink(logfile0_.c_str());
478 unlink(logfile1_.c_str());
Austin Schuhd2f96102020-12-01 20:27:29 -0800479 unlink(logfile2_.c_str());
Austin Schuh48507722021-07-17 17:29:24 -0700480 unlink(logfile3_.c_str());
Austin Schuh921b2562021-07-31 19:37:03 -0700481 queue_index_.resize(config_.message().channels()->size());
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800482 }
483
484 protected:
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800485 flatbuffers::DetachedBuffer MakeLogMessage(
486 const aos::monotonic_clock::time_point monotonic_now, int channel_index,
487 int value) {
488 flatbuffers::FlatBufferBuilder message_fbb;
489 message_fbb.ForceDefaults(true);
490 TestMessage::Builder test_message_builder(message_fbb);
491 test_message_builder.add_value(value);
492 message_fbb.Finish(test_message_builder.Finish());
493
494 aos::Context context;
495 context.monotonic_event_time = monotonic_now;
496 context.realtime_event_time = aos::realtime_clock::epoch() +
497 chrono::seconds(1000) +
498 monotonic_now.time_since_epoch();
Austin Schuh921b2562021-07-31 19:37:03 -0700499 CHECK_LT(static_cast<size_t>(channel_index), queue_index_.size());
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800500 context.queue_index = queue_index_[channel_index];
501 context.size = message_fbb.GetSize();
502 context.data = message_fbb.GetBufferPointer();
503
504 ++queue_index_[channel_index];
505
506 flatbuffers::FlatBufferBuilder fbb;
Austin Schuh53e3a812021-11-03 16:57:23 -0700507 fbb.ForceDefaults(true);
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800508 fbb.FinishSizePrefixed(
509 PackMessage(&fbb, context, channel_index, LogType::kLogMessage));
510
511 return fbb.Release();
512 }
513
514 flatbuffers::DetachedBuffer MakeTimestampMessage(
515 const aos::monotonic_clock::time_point sender_monotonic_now,
Austin Schuh8bf1e632021-01-02 22:41:04 -0800516 int channel_index, chrono::nanoseconds receiver_monotonic_offset,
517 monotonic_clock::time_point monotonic_timestamp_time =
518 monotonic_clock::min_time) {
519 const monotonic_clock::time_point monotonic_sent_time =
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800520 sender_monotonic_now + receiver_monotonic_offset;
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800521
522 flatbuffers::FlatBufferBuilder fbb;
Austin Schuh8bf1e632021-01-02 22:41:04 -0800523 fbb.ForceDefaults(true);
524
525 logger::MessageHeader::Builder message_header_builder(fbb);
526
527 message_header_builder.add_channel_index(channel_index);
528
529 message_header_builder.add_queue_index(queue_index_[channel_index] - 1 +
530 100);
531 message_header_builder.add_monotonic_sent_time(
532 monotonic_sent_time.time_since_epoch().count());
533 message_header_builder.add_realtime_sent_time(
534 (aos::realtime_clock::epoch() + chrono::seconds(1000) +
535 monotonic_sent_time.time_since_epoch())
536 .time_since_epoch()
537 .count());
538
539 message_header_builder.add_monotonic_remote_time(
540 sender_monotonic_now.time_since_epoch().count());
541 message_header_builder.add_realtime_remote_time(
542 (aos::realtime_clock::epoch() + chrono::seconds(1000) +
543 sender_monotonic_now.time_since_epoch())
544 .time_since_epoch()
545 .count());
546 message_header_builder.add_remote_queue_index(queue_index_[channel_index] -
547 1);
548
549 if (monotonic_timestamp_time != monotonic_clock::min_time) {
550 message_header_builder.add_monotonic_timestamp_time(
551 monotonic_timestamp_time.time_since_epoch().count());
552 }
553
554 fbb.FinishSizePrefixed(message_header_builder.Finish());
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800555 LOG(INFO) << aos::FlatbufferToJson(
556 aos::SizePrefixedFlatbufferSpan<MessageHeader>(
557 absl::Span<uint8_t>(fbb.GetBufferPointer(), fbb.GetSize())));
558
559 return fbb.Release();
560 }
561
562 const std::string logfile0_ = aos::testing::TestTmpDir() + "/log0.bfbs";
563 const std::string logfile1_ = aos::testing::TestTmpDir() + "/log1.bfbs";
Austin Schuhd2f96102020-12-01 20:27:29 -0800564 const std::string logfile2_ = aos::testing::TestTmpDir() + "/log2.bfbs";
Austin Schuh48507722021-07-17 17:29:24 -0700565 const std::string logfile3_ = aos::testing::TestTmpDir() + "/log3.bfbs";
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800566
567 const aos::FlatbufferDetachedBuffer<Configuration> config_;
568 const aos::SizePrefixedFlatbufferDetachedBuffer<LogFileHeader> config0_;
569 const aos::SizePrefixedFlatbufferDetachedBuffer<LogFileHeader> config1_;
Austin Schuhd2f96102020-12-01 20:27:29 -0800570 const aos::SizePrefixedFlatbufferDetachedBuffer<LogFileHeader> config2_;
571 const aos::SizePrefixedFlatbufferDetachedBuffer<LogFileHeader> config3_;
Austin Schuh8bf1e632021-01-02 22:41:04 -0800572 const aos::SizePrefixedFlatbufferDetachedBuffer<LogFileHeader> config4_;
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800573
574 std::vector<uint32_t> queue_index_;
575};
576
577using LogPartsSorterTest = SortingElementTest;
578using LogPartsSorterDeathTest = LogPartsSorterTest;
Austin Schuh8f52ed52020-11-30 23:12:39 -0800579using NodeMergerTest = SortingElementTest;
Austin Schuhd2f96102020-12-01 20:27:29 -0800580using TimestampMapperTest = SortingElementTest;
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800581
582// Tests that we can pull messages out of a log sorted in order.
583TEST_F(LogPartsSorterTest, Pull) {
584 const aos::monotonic_clock::time_point e = monotonic_clock::epoch();
585 {
Austin Schuhd863e6e2022-10-16 15:44:50 -0700586 TestDetachedBufferWriter writer(logfile0_);
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800587 writer.QueueSpan(config0_.span());
Austin Schuhd863e6e2022-10-16 15:44:50 -0700588 writer.WriteSizedFlatbuffer(
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800589 MakeLogMessage(e + chrono::milliseconds(1000), 0, 0x005));
Austin Schuhd863e6e2022-10-16 15:44:50 -0700590 writer.WriteSizedFlatbuffer(
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800591 MakeLogMessage(e + chrono::milliseconds(1000), 1, 0x105));
Austin Schuhd863e6e2022-10-16 15:44:50 -0700592 writer.WriteSizedFlatbuffer(
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800593 MakeLogMessage(e + chrono::milliseconds(2000), 0, 0x006));
Austin Schuhd863e6e2022-10-16 15:44:50 -0700594 writer.WriteSizedFlatbuffer(
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800595 MakeLogMessage(e + chrono::milliseconds(1901), 1, 0x107));
596 }
597
598 const std::vector<LogFile> parts = SortParts({logfile0_});
599
600 LogPartsSorter parts_sorter(parts[0].parts[0]);
601
602 // Confirm we aren't sorted until any time until the message is popped.
603 // Peeking shouldn't change the sorted until time.
604 EXPECT_EQ(parts_sorter.sorted_until(), monotonic_clock::min_time);
605
606 std::deque<Message> output;
607
608 ASSERT_TRUE(parts_sorter.Front() != nullptr);
609 output.emplace_back(std::move(*parts_sorter.Front()));
610 parts_sorter.PopFront();
611 EXPECT_EQ(parts_sorter.sorted_until(), e + chrono::milliseconds(1900));
612
613 ASSERT_TRUE(parts_sorter.Front() != nullptr);
614 output.emplace_back(std::move(*parts_sorter.Front()));
615 parts_sorter.PopFront();
616 EXPECT_EQ(parts_sorter.sorted_until(), e + chrono::milliseconds(1900));
617
618 ASSERT_TRUE(parts_sorter.Front() != nullptr);
619 output.emplace_back(std::move(*parts_sorter.Front()));
620 parts_sorter.PopFront();
621 EXPECT_EQ(parts_sorter.sorted_until(), monotonic_clock::max_time);
622
623 ASSERT_TRUE(parts_sorter.Front() != nullptr);
624 output.emplace_back(std::move(*parts_sorter.Front()));
625 parts_sorter.PopFront();
626 EXPECT_EQ(parts_sorter.sorted_until(), monotonic_clock::max_time);
627
628 ASSERT_TRUE(parts_sorter.Front() == nullptr);
629
Austin Schuh2dc8c7d2021-07-01 17:41:28 -0700630 EXPECT_EQ(output[0].timestamp.boot, 0);
631 EXPECT_EQ(output[0].timestamp.time, e + chrono::milliseconds(1000));
632 EXPECT_EQ(output[1].timestamp.boot, 0);
633 EXPECT_EQ(output[1].timestamp.time, e + chrono::milliseconds(1000));
634 EXPECT_EQ(output[2].timestamp.boot, 0);
635 EXPECT_EQ(output[2].timestamp.time, e + chrono::milliseconds(1901));
636 EXPECT_EQ(output[3].timestamp.boot, 0);
637 EXPECT_EQ(output[3].timestamp.time, e + chrono::milliseconds(2000));
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800638}
639
Austin Schuhb000de62020-12-03 22:00:40 -0800640// Tests that we can pull messages out of a log sorted in order.
641TEST_F(LogPartsSorterTest, WayBeforeStart) {
642 const aos::monotonic_clock::time_point e = monotonic_clock::epoch();
643 {
Austin Schuhd863e6e2022-10-16 15:44:50 -0700644 TestDetachedBufferWriter writer(logfile0_);
Austin Schuhb000de62020-12-03 22:00:40 -0800645 writer.QueueSpan(config0_.span());
Austin Schuhd863e6e2022-10-16 15:44:50 -0700646 writer.WriteSizedFlatbuffer(
Austin Schuhb000de62020-12-03 22:00:40 -0800647 MakeLogMessage(e - chrono::milliseconds(500), 0, 0x005));
Austin Schuhd863e6e2022-10-16 15:44:50 -0700648 writer.WriteSizedFlatbuffer(
Austin Schuhb000de62020-12-03 22:00:40 -0800649 MakeLogMessage(e - chrono::milliseconds(10), 2, 0x005));
Austin Schuhd863e6e2022-10-16 15:44:50 -0700650 writer.WriteSizedFlatbuffer(
Austin Schuhb000de62020-12-03 22:00:40 -0800651 MakeLogMessage(e - chrono::milliseconds(1000), 1, 0x105));
Austin Schuhd863e6e2022-10-16 15:44:50 -0700652 writer.WriteSizedFlatbuffer(
Austin Schuhb000de62020-12-03 22:00:40 -0800653 MakeLogMessage(e + chrono::milliseconds(2000), 0, 0x006));
Austin Schuhd863e6e2022-10-16 15:44:50 -0700654 writer.WriteSizedFlatbuffer(
Austin Schuhb000de62020-12-03 22:00:40 -0800655 MakeLogMessage(e + chrono::milliseconds(1901), 1, 0x107));
656 }
657
658 const std::vector<LogFile> parts = SortParts({logfile0_});
659
660 LogPartsSorter parts_sorter(parts[0].parts[0]);
661
662 // Confirm we aren't sorted until any time until the message is popped.
663 // Peeking shouldn't change the sorted until time.
664 EXPECT_EQ(parts_sorter.sorted_until(), monotonic_clock::min_time);
665
666 std::deque<Message> output;
667
668 for (monotonic_clock::time_point t :
669 {e + chrono::milliseconds(1900), e + chrono::milliseconds(1900),
670 e + chrono::milliseconds(1900), monotonic_clock::max_time,
671 monotonic_clock::max_time}) {
672 ASSERT_TRUE(parts_sorter.Front() != nullptr);
673 output.emplace_back(std::move(*parts_sorter.Front()));
674 parts_sorter.PopFront();
675 EXPECT_EQ(parts_sorter.sorted_until(), t);
676 }
677
678 ASSERT_TRUE(parts_sorter.Front() == nullptr);
679
Austin Schuh2dc8c7d2021-07-01 17:41:28 -0700680 EXPECT_EQ(output[0].timestamp.boot, 0u);
681 EXPECT_EQ(output[0].timestamp.time, e - chrono::milliseconds(1000));
682 EXPECT_EQ(output[1].timestamp.boot, 0u);
683 EXPECT_EQ(output[1].timestamp.time, e - chrono::milliseconds(500));
684 EXPECT_EQ(output[2].timestamp.boot, 0u);
685 EXPECT_EQ(output[2].timestamp.time, e - chrono::milliseconds(10));
686 EXPECT_EQ(output[3].timestamp.boot, 0u);
687 EXPECT_EQ(output[3].timestamp.time, e + chrono::milliseconds(1901));
688 EXPECT_EQ(output[4].timestamp.boot, 0u);
689 EXPECT_EQ(output[4].timestamp.time, e + chrono::milliseconds(2000));
Austin Schuhb000de62020-12-03 22:00:40 -0800690}
691
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800692// Tests that messages too far out of order trigger death.
693TEST_F(LogPartsSorterDeathTest, Pull) {
694 const aos::monotonic_clock::time_point e = monotonic_clock::epoch();
695 {
Austin Schuhd863e6e2022-10-16 15:44:50 -0700696 TestDetachedBufferWriter writer(logfile0_);
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800697 writer.QueueSpan(config0_.span());
Austin Schuhd863e6e2022-10-16 15:44:50 -0700698 writer.WriteSizedFlatbuffer(
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800699 MakeLogMessage(e + chrono::milliseconds(1000), 0, 0x005));
Austin Schuhd863e6e2022-10-16 15:44:50 -0700700 writer.WriteSizedFlatbuffer(
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800701 MakeLogMessage(e + chrono::milliseconds(1000), 1, 0x105));
Austin Schuhd863e6e2022-10-16 15:44:50 -0700702 writer.WriteSizedFlatbuffer(
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800703 MakeLogMessage(e + chrono::milliseconds(2001), 0, 0x006));
704 // The following message is too far out of order and will trigger the CHECK.
Austin Schuhd863e6e2022-10-16 15:44:50 -0700705 writer.WriteSizedFlatbuffer(
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800706 MakeLogMessage(e + chrono::milliseconds(1900), 1, 0x107));
707 }
708
709 const std::vector<LogFile> parts = SortParts({logfile0_});
710
711 LogPartsSorter parts_sorter(parts[0].parts[0]);
712
713 // Confirm we aren't sorted until any time until the message is popped.
714 // Peeking shouldn't change the sorted until time.
715 EXPECT_EQ(parts_sorter.sorted_until(), monotonic_clock::min_time);
716 std::deque<Message> output;
717
718 ASSERT_TRUE(parts_sorter.Front() != nullptr);
719 parts_sorter.PopFront();
720 ASSERT_TRUE(parts_sorter.Front() != nullptr);
721 ASSERT_TRUE(parts_sorter.Front() != nullptr);
722 parts_sorter.PopFront();
723
Austin Schuh58646e22021-08-23 23:51:46 -0700724 EXPECT_DEATH({ parts_sorter.Front(); },
725 "Max out of order of 100000000ns exceeded.");
Austin Schuh4b5c22a2020-11-30 22:58:43 -0800726}
727
Austin Schuh8f52ed52020-11-30 23:12:39 -0800728// Tests that we can merge data from 2 separate files, including duplicate data.
729TEST_F(NodeMergerTest, TwoFileMerger) {
730 const aos::monotonic_clock::time_point e = monotonic_clock::epoch();
731 {
Austin Schuhd863e6e2022-10-16 15:44:50 -0700732 TestDetachedBufferWriter writer0(logfile0_);
Austin Schuh8f52ed52020-11-30 23:12:39 -0800733 writer0.QueueSpan(config0_.span());
Austin Schuhd863e6e2022-10-16 15:44:50 -0700734 TestDetachedBufferWriter writer1(logfile1_);
Austin Schuh8f52ed52020-11-30 23:12:39 -0800735 writer1.QueueSpan(config1_.span());
736
Austin Schuhd863e6e2022-10-16 15:44:50 -0700737 writer0.WriteSizedFlatbuffer(
Austin Schuh8f52ed52020-11-30 23:12:39 -0800738 MakeLogMessage(e + chrono::milliseconds(1000), 0, 0x005));
Austin Schuhd863e6e2022-10-16 15:44:50 -0700739 writer1.WriteSizedFlatbuffer(
Austin Schuh8f52ed52020-11-30 23:12:39 -0800740 MakeLogMessage(e + chrono::milliseconds(1001), 1, 0x105));
741
Austin Schuhd863e6e2022-10-16 15:44:50 -0700742 writer0.WriteSizedFlatbuffer(
Austin Schuh8f52ed52020-11-30 23:12:39 -0800743 MakeLogMessage(e + chrono::milliseconds(2000), 0, 0x006));
Austin Schuhd863e6e2022-10-16 15:44:50 -0700744 writer1.WriteSizedFlatbuffer(
Austin Schuh8f52ed52020-11-30 23:12:39 -0800745 MakeLogMessage(e + chrono::milliseconds(1002), 1, 0x106));
746
747 // Make a duplicate!
748 SizePrefixedFlatbufferDetachedBuffer<MessageHeader> msg(
749 MakeLogMessage(e + chrono::milliseconds(3000), 0, 0x007));
750 writer0.QueueSpan(msg.span());
751 writer1.QueueSpan(msg.span());
752
Austin Schuhd863e6e2022-10-16 15:44:50 -0700753 writer1.WriteSizedFlatbuffer(
Austin Schuh8f52ed52020-11-30 23:12:39 -0800754 MakeLogMessage(e + chrono::milliseconds(3002), 1, 0x107));
755 }
756
757 const std::vector<LogFile> parts = SortParts({logfile0_, logfile1_});
Austin Schuhd2f96102020-12-01 20:27:29 -0800758 ASSERT_EQ(parts.size(), 1u);
Austin Schuh8f52ed52020-11-30 23:12:39 -0800759
Austin Schuhd2f96102020-12-01 20:27:29 -0800760 NodeMerger merger(FilterPartsForNode(parts, "pi1"));
Austin Schuh8f52ed52020-11-30 23:12:39 -0800761
762 EXPECT_EQ(merger.sorted_until(), monotonic_clock::min_time);
763
764 std::deque<Message> output;
765
766 EXPECT_EQ(merger.sorted_until(), monotonic_clock::min_time);
767 ASSERT_TRUE(merger.Front() != nullptr);
768 EXPECT_EQ(merger.sorted_until(), e + chrono::milliseconds(1900));
769
770 output.emplace_back(std::move(*merger.Front()));
771 merger.PopFront();
772 EXPECT_EQ(merger.sorted_until(), e + chrono::milliseconds(1900));
773
774 ASSERT_TRUE(merger.Front() != nullptr);
775 output.emplace_back(std::move(*merger.Front()));
776 merger.PopFront();
777 EXPECT_EQ(merger.sorted_until(), e + chrono::milliseconds(2900));
778
779 ASSERT_TRUE(merger.Front() != nullptr);
780 output.emplace_back(std::move(*merger.Front()));
781 merger.PopFront();
782 EXPECT_EQ(merger.sorted_until(), e + chrono::milliseconds(2900));
783
784 ASSERT_TRUE(merger.Front() != nullptr);
785 output.emplace_back(std::move(*merger.Front()));
786 merger.PopFront();
787 EXPECT_EQ(merger.sorted_until(), e + chrono::milliseconds(2900));
788
789 ASSERT_TRUE(merger.Front() != nullptr);
790 output.emplace_back(std::move(*merger.Front()));
791 merger.PopFront();
792 EXPECT_EQ(merger.sorted_until(), monotonic_clock::max_time);
793
794 ASSERT_TRUE(merger.Front() != nullptr);
795 output.emplace_back(std::move(*merger.Front()));
796 merger.PopFront();
797 EXPECT_EQ(merger.sorted_until(), monotonic_clock::max_time);
798
799 ASSERT_TRUE(merger.Front() == nullptr);
800
Austin Schuh2dc8c7d2021-07-01 17:41:28 -0700801 EXPECT_EQ(output[0].timestamp.boot, 0u);
802 EXPECT_EQ(output[0].timestamp.time, e + chrono::milliseconds(1000));
803 EXPECT_EQ(output[1].timestamp.boot, 0u);
804 EXPECT_EQ(output[1].timestamp.time, e + chrono::milliseconds(1001));
805 EXPECT_EQ(output[2].timestamp.boot, 0u);
806 EXPECT_EQ(output[2].timestamp.time, e + chrono::milliseconds(1002));
807 EXPECT_EQ(output[3].timestamp.boot, 0u);
808 EXPECT_EQ(output[3].timestamp.time, e + chrono::milliseconds(2000));
809 EXPECT_EQ(output[4].timestamp.boot, 0u);
810 EXPECT_EQ(output[4].timestamp.time, e + chrono::milliseconds(3000));
811 EXPECT_EQ(output[5].timestamp.boot, 0u);
812 EXPECT_EQ(output[5].timestamp.time, e + chrono::milliseconds(3002));
Austin Schuh8f52ed52020-11-30 23:12:39 -0800813}
814
Austin Schuh8bf1e632021-01-02 22:41:04 -0800815// Tests that we can merge timestamps with various combinations of
816// monotonic_timestamp_time.
817TEST_F(NodeMergerTest, TwoFileTimestampMerger) {
818 const aos::monotonic_clock::time_point e = monotonic_clock::epoch();
819 {
Austin Schuhd863e6e2022-10-16 15:44:50 -0700820 TestDetachedBufferWriter writer0(logfile0_);
Austin Schuh8bf1e632021-01-02 22:41:04 -0800821 writer0.QueueSpan(config0_.span());
Austin Schuhd863e6e2022-10-16 15:44:50 -0700822 TestDetachedBufferWriter writer1(logfile1_);
Austin Schuh8bf1e632021-01-02 22:41:04 -0800823 writer1.QueueSpan(config1_.span());
824
825 // Neither has it.
826 MakeLogMessage(e + chrono::milliseconds(1000), 0, 0x005);
Austin Schuhd863e6e2022-10-16 15:44:50 -0700827 writer0.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuh8bf1e632021-01-02 22:41:04 -0800828 e + chrono::milliseconds(1000), 0, chrono::seconds(100)));
Austin Schuhd863e6e2022-10-16 15:44:50 -0700829 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuh8bf1e632021-01-02 22:41:04 -0800830 e + chrono::milliseconds(1000), 0, chrono::seconds(100)));
831
832 // First only has it.
833 MakeLogMessage(e + chrono::milliseconds(1001), 0, 0x006);
Austin Schuhd863e6e2022-10-16 15:44:50 -0700834 writer0.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuh8bf1e632021-01-02 22:41:04 -0800835 e + chrono::milliseconds(1001), 0, chrono::seconds(100),
836 e + chrono::nanoseconds(971)));
Austin Schuhd863e6e2022-10-16 15:44:50 -0700837 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuh8bf1e632021-01-02 22:41:04 -0800838 e + chrono::milliseconds(1001), 0, chrono::seconds(100)));
839
840 // Second only has it.
841 MakeLogMessage(e + chrono::milliseconds(1002), 0, 0x007);
Austin Schuhd863e6e2022-10-16 15:44:50 -0700842 writer0.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuh8bf1e632021-01-02 22:41:04 -0800843 e + chrono::milliseconds(1002), 0, chrono::seconds(100)));
Austin Schuhd863e6e2022-10-16 15:44:50 -0700844 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuh8bf1e632021-01-02 22:41:04 -0800845 e + chrono::milliseconds(1002), 0, chrono::seconds(100),
846 e + chrono::nanoseconds(972)));
847
848 // Both have it.
849 MakeLogMessage(e + chrono::milliseconds(1003), 0, 0x008);
Austin Schuhd863e6e2022-10-16 15:44:50 -0700850 writer0.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuh8bf1e632021-01-02 22:41:04 -0800851 e + chrono::milliseconds(1003), 0, chrono::seconds(100),
852 e + chrono::nanoseconds(973)));
Austin Schuhd863e6e2022-10-16 15:44:50 -0700853 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuh8bf1e632021-01-02 22:41:04 -0800854 e + chrono::milliseconds(1003), 0, chrono::seconds(100),
855 e + chrono::nanoseconds(973)));
856 }
857
858 const std::vector<LogFile> parts = SortParts({logfile0_, logfile1_});
859 ASSERT_EQ(parts.size(), 1u);
860
861 NodeMerger merger(FilterPartsForNode(parts, "pi1"));
862
863 EXPECT_EQ(merger.sorted_until(), monotonic_clock::min_time);
864
865 std::deque<Message> output;
866
867 for (int i = 0; i < 4; ++i) {
868 ASSERT_TRUE(merger.Front() != nullptr);
869 output.emplace_back(std::move(*merger.Front()));
870 merger.PopFront();
871 }
872 ASSERT_TRUE(merger.Front() == nullptr);
873
Austin Schuh2dc8c7d2021-07-01 17:41:28 -0700874 EXPECT_EQ(output[0].timestamp.boot, 0u);
875 EXPECT_EQ(output[0].timestamp.time, e + chrono::milliseconds(101000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -0700876 EXPECT_FALSE(output[0].data->has_monotonic_timestamp_time);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -0700877
878 EXPECT_EQ(output[1].timestamp.boot, 0u);
879 EXPECT_EQ(output[1].timestamp.time, e + chrono::milliseconds(101001));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -0700880 EXPECT_TRUE(output[1].data->has_monotonic_timestamp_time);
881 EXPECT_EQ(output[1].data->monotonic_timestamp_time,
882 monotonic_clock::time_point(std::chrono::nanoseconds(971)));
Austin Schuh2dc8c7d2021-07-01 17:41:28 -0700883
884 EXPECT_EQ(output[2].timestamp.boot, 0u);
885 EXPECT_EQ(output[2].timestamp.time, e + chrono::milliseconds(101002));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -0700886 EXPECT_TRUE(output[2].data->has_monotonic_timestamp_time);
887 EXPECT_EQ(output[2].data->monotonic_timestamp_time,
888 monotonic_clock::time_point(std::chrono::nanoseconds(972)));
Austin Schuh2dc8c7d2021-07-01 17:41:28 -0700889
890 EXPECT_EQ(output[3].timestamp.boot, 0u);
891 EXPECT_EQ(output[3].timestamp.time, e + chrono::milliseconds(101003));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -0700892 EXPECT_TRUE(output[3].data->has_monotonic_timestamp_time);
893 EXPECT_EQ(output[3].data->monotonic_timestamp_time,
894 monotonic_clock::time_point(std::chrono::nanoseconds(973)));
Austin Schuh8bf1e632021-01-02 22:41:04 -0800895}
896
Austin Schuhd2f96102020-12-01 20:27:29 -0800897// Tests that we can match timestamps on delivered messages.
898TEST_F(TimestampMapperTest, ReadNode0First) {
899 const aos::monotonic_clock::time_point e = monotonic_clock::epoch();
900 {
Austin Schuhd863e6e2022-10-16 15:44:50 -0700901 TestDetachedBufferWriter writer0(logfile0_);
Austin Schuhd2f96102020-12-01 20:27:29 -0800902 writer0.QueueSpan(config0_.span());
Austin Schuhd863e6e2022-10-16 15:44:50 -0700903 TestDetachedBufferWriter writer1(logfile1_);
Austin Schuhd2f96102020-12-01 20:27:29 -0800904 writer1.QueueSpan(config2_.span());
905
Austin Schuhd863e6e2022-10-16 15:44:50 -0700906 writer0.WriteSizedFlatbuffer(
Austin Schuhd2f96102020-12-01 20:27:29 -0800907 MakeLogMessage(e + chrono::milliseconds(1000), 0, 0x005));
Austin Schuhd863e6e2022-10-16 15:44:50 -0700908 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuhd2f96102020-12-01 20:27:29 -0800909 e + chrono::milliseconds(1000), 0, chrono::seconds(100)));
910
Austin Schuhd863e6e2022-10-16 15:44:50 -0700911 writer0.WriteSizedFlatbuffer(
Austin Schuhd2f96102020-12-01 20:27:29 -0800912 MakeLogMessage(e + chrono::milliseconds(2000), 0, 0x006));
Austin Schuhd863e6e2022-10-16 15:44:50 -0700913 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuhd2f96102020-12-01 20:27:29 -0800914 e + chrono::milliseconds(2000), 0, chrono::seconds(100)));
915
Austin Schuhd863e6e2022-10-16 15:44:50 -0700916 writer0.WriteSizedFlatbuffer(
Austin Schuhd2f96102020-12-01 20:27:29 -0800917 MakeLogMessage(e + chrono::milliseconds(3000), 0, 0x007));
Austin Schuhd863e6e2022-10-16 15:44:50 -0700918 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuhd2f96102020-12-01 20:27:29 -0800919 e + chrono::milliseconds(3000), 0, chrono::seconds(100)));
920 }
921
922 const std::vector<LogFile> parts = SortParts({logfile0_, logfile1_});
923
924 ASSERT_EQ(parts[0].logger_node, "pi1");
925 ASSERT_EQ(parts[1].logger_node, "pi2");
926
Austin Schuh79b30942021-01-24 22:32:21 -0800927 size_t mapper0_count = 0;
Austin Schuhd2f96102020-12-01 20:27:29 -0800928 TimestampMapper mapper0(FilterPartsForNode(parts, "pi1"));
Austin Schuh79b30942021-01-24 22:32:21 -0800929 mapper0.set_timestamp_callback(
930 [&](TimestampedMessage *) { ++mapper0_count; });
931 size_t mapper1_count = 0;
Austin Schuhd2f96102020-12-01 20:27:29 -0800932 TimestampMapper mapper1(FilterPartsForNode(parts, "pi2"));
Austin Schuh79b30942021-01-24 22:32:21 -0800933 mapper1.set_timestamp_callback(
934 [&](TimestampedMessage *) { ++mapper1_count; });
Austin Schuhd2f96102020-12-01 20:27:29 -0800935
936 mapper0.AddPeer(&mapper1);
937 mapper1.AddPeer(&mapper0);
938
939 {
940 std::deque<TimestampedMessage> output0;
941
Austin Schuh79b30942021-01-24 22:32:21 -0800942 EXPECT_EQ(mapper0_count, 0u);
943 EXPECT_EQ(mapper1_count, 0u);
Austin Schuhd2f96102020-12-01 20:27:29 -0800944 ASSERT_TRUE(mapper0.Front() != nullptr);
Austin Schuh79b30942021-01-24 22:32:21 -0800945 EXPECT_EQ(mapper0_count, 1u);
946 EXPECT_EQ(mapper1_count, 0u);
Austin Schuhd2f96102020-12-01 20:27:29 -0800947 output0.emplace_back(std::move(*mapper0.Front()));
948 mapper0.PopFront();
Austin Schuh24bf4972021-06-29 22:09:08 -0700949 EXPECT_TRUE(mapper0.started());
Austin Schuh79b30942021-01-24 22:32:21 -0800950 EXPECT_EQ(mapper0_count, 1u);
951 EXPECT_EQ(mapper1_count, 0u);
Austin Schuhd2f96102020-12-01 20:27:29 -0800952
953 ASSERT_TRUE(mapper0.Front() != nullptr);
Austin Schuh79b30942021-01-24 22:32:21 -0800954 EXPECT_EQ(mapper0_count, 2u);
955 EXPECT_EQ(mapper1_count, 0u);
Austin Schuhd2f96102020-12-01 20:27:29 -0800956 output0.emplace_back(std::move(*mapper0.Front()));
957 mapper0.PopFront();
Austin Schuh24bf4972021-06-29 22:09:08 -0700958 EXPECT_TRUE(mapper0.started());
Austin Schuhd2f96102020-12-01 20:27:29 -0800959
960 ASSERT_TRUE(mapper0.Front() != nullptr);
961 output0.emplace_back(std::move(*mapper0.Front()));
962 mapper0.PopFront();
Austin Schuh24bf4972021-06-29 22:09:08 -0700963 EXPECT_TRUE(mapper0.started());
Austin Schuhd2f96102020-12-01 20:27:29 -0800964
Austin Schuh79b30942021-01-24 22:32:21 -0800965 EXPECT_EQ(mapper0_count, 3u);
966 EXPECT_EQ(mapper1_count, 0u);
967
Austin Schuhd2f96102020-12-01 20:27:29 -0800968 ASSERT_TRUE(mapper0.Front() == nullptr);
969
Austin Schuh2dc8c7d2021-07-01 17:41:28 -0700970 EXPECT_EQ(output0[0].monotonic_event_time.boot, 0u);
971 EXPECT_EQ(output0[0].monotonic_event_time.time,
972 e + chrono::milliseconds(1000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -0700973 EXPECT_TRUE(output0[0].data != nullptr);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -0700974
975 EXPECT_EQ(output0[1].monotonic_event_time.boot, 0u);
976 EXPECT_EQ(output0[1].monotonic_event_time.time,
977 e + chrono::milliseconds(2000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -0700978 EXPECT_TRUE(output0[1].data != nullptr);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -0700979
980 EXPECT_EQ(output0[2].monotonic_event_time.boot, 0u);
981 EXPECT_EQ(output0[2].monotonic_event_time.time,
982 e + chrono::milliseconds(3000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -0700983 EXPECT_TRUE(output0[2].data != nullptr);
Austin Schuhd2f96102020-12-01 20:27:29 -0800984 }
985
986 {
987 SCOPED_TRACE("Trying node1 now");
988 std::deque<TimestampedMessage> output1;
989
Austin Schuh79b30942021-01-24 22:32:21 -0800990 EXPECT_EQ(mapper0_count, 3u);
991 EXPECT_EQ(mapper1_count, 0u);
992
Austin Schuhd2f96102020-12-01 20:27:29 -0800993 ASSERT_TRUE(mapper1.Front() != nullptr);
Austin Schuh79b30942021-01-24 22:32:21 -0800994 EXPECT_EQ(mapper0_count, 3u);
995 EXPECT_EQ(mapper1_count, 1u);
Austin Schuhd2f96102020-12-01 20:27:29 -0800996 output1.emplace_back(std::move(*mapper1.Front()));
997 mapper1.PopFront();
Austin Schuh24bf4972021-06-29 22:09:08 -0700998 EXPECT_TRUE(mapper1.started());
Austin Schuh79b30942021-01-24 22:32:21 -0800999 EXPECT_EQ(mapper0_count, 3u);
1000 EXPECT_EQ(mapper1_count, 1u);
Austin Schuhd2f96102020-12-01 20:27:29 -08001001
1002 ASSERT_TRUE(mapper1.Front() != nullptr);
Austin Schuh79b30942021-01-24 22:32:21 -08001003 EXPECT_EQ(mapper0_count, 3u);
1004 EXPECT_EQ(mapper1_count, 2u);
Austin Schuhd2f96102020-12-01 20:27:29 -08001005 output1.emplace_back(std::move(*mapper1.Front()));
1006 mapper1.PopFront();
Austin Schuh24bf4972021-06-29 22:09:08 -07001007 EXPECT_TRUE(mapper1.started());
Austin Schuhd2f96102020-12-01 20:27:29 -08001008
1009 ASSERT_TRUE(mapper1.Front() != nullptr);
1010 output1.emplace_back(std::move(*mapper1.Front()));
1011 mapper1.PopFront();
Austin Schuh24bf4972021-06-29 22:09:08 -07001012 EXPECT_TRUE(mapper1.started());
Austin Schuhd2f96102020-12-01 20:27:29 -08001013
Austin Schuh79b30942021-01-24 22:32:21 -08001014 EXPECT_EQ(mapper0_count, 3u);
1015 EXPECT_EQ(mapper1_count, 3u);
1016
Austin Schuhd2f96102020-12-01 20:27:29 -08001017 ASSERT_TRUE(mapper1.Front() == nullptr);
1018
Austin Schuh79b30942021-01-24 22:32:21 -08001019 EXPECT_EQ(mapper0_count, 3u);
1020 EXPECT_EQ(mapper1_count, 3u);
1021
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001022 EXPECT_EQ(output1[0].monotonic_event_time.boot, 0u);
1023 EXPECT_EQ(output1[0].monotonic_event_time.time,
Austin Schuhd2f96102020-12-01 20:27:29 -08001024 e + chrono::seconds(100) + chrono::milliseconds(1000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001025 EXPECT_TRUE(output1[0].data != nullptr);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001026
1027 EXPECT_EQ(output1[1].monotonic_event_time.boot, 0u);
1028 EXPECT_EQ(output1[1].monotonic_event_time.time,
Austin Schuhd2f96102020-12-01 20:27:29 -08001029 e + chrono::seconds(100) + chrono::milliseconds(2000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001030 EXPECT_TRUE(output1[1].data != nullptr);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001031
1032 EXPECT_EQ(output1[2].monotonic_event_time.boot, 0u);
1033 EXPECT_EQ(output1[2].monotonic_event_time.time,
Austin Schuhd2f96102020-12-01 20:27:29 -08001034 e + chrono::seconds(100) + chrono::milliseconds(3000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001035 EXPECT_TRUE(output1[2].data != nullptr);
Austin Schuhd2f96102020-12-01 20:27:29 -08001036 }
1037}
1038
Austin Schuh8bf1e632021-01-02 22:41:04 -08001039// Tests that a MessageHeader with monotonic_timestamp_time set gets properly
1040// returned.
1041TEST_F(TimestampMapperTest, MessageWithTimestampTime) {
1042 const aos::monotonic_clock::time_point e = monotonic_clock::epoch();
1043 {
Austin Schuhd863e6e2022-10-16 15:44:50 -07001044 TestDetachedBufferWriter writer0(logfile0_);
Austin Schuh8bf1e632021-01-02 22:41:04 -08001045 writer0.QueueSpan(config0_.span());
Austin Schuhd863e6e2022-10-16 15:44:50 -07001046 TestDetachedBufferWriter writer1(logfile1_);
Austin Schuh8bf1e632021-01-02 22:41:04 -08001047 writer1.QueueSpan(config4_.span());
1048
Austin Schuhd863e6e2022-10-16 15:44:50 -07001049 writer0.WriteSizedFlatbuffer(
Austin Schuh8bf1e632021-01-02 22:41:04 -08001050 MakeLogMessage(e + chrono::milliseconds(1000), 0, 0x005));
Austin Schuhd863e6e2022-10-16 15:44:50 -07001051 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuh8bf1e632021-01-02 22:41:04 -08001052 e + chrono::milliseconds(1000), 0, chrono::seconds(100),
1053 e + chrono::nanoseconds(971)));
1054
Austin Schuhd863e6e2022-10-16 15:44:50 -07001055 writer0.WriteSizedFlatbuffer(
Austin Schuh8bf1e632021-01-02 22:41:04 -08001056 MakeLogMessage(e + chrono::milliseconds(2000), 0, 0x006));
Austin Schuhd863e6e2022-10-16 15:44:50 -07001057 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuh8bf1e632021-01-02 22:41:04 -08001058 e + chrono::milliseconds(2000), 0, chrono::seconds(100),
1059 e + chrono::nanoseconds(5458)));
1060
Austin Schuhd863e6e2022-10-16 15:44:50 -07001061 writer0.WriteSizedFlatbuffer(
Austin Schuh8bf1e632021-01-02 22:41:04 -08001062 MakeLogMessage(e + chrono::milliseconds(3000), 0, 0x007));
Austin Schuhd863e6e2022-10-16 15:44:50 -07001063 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuh8bf1e632021-01-02 22:41:04 -08001064 e + chrono::milliseconds(3000), 0, chrono::seconds(100)));
1065 }
1066
1067 const std::vector<LogFile> parts = SortParts({logfile0_, logfile1_});
1068
1069 for (const auto &p : parts) {
1070 LOG(INFO) << p;
1071 }
1072
1073 ASSERT_EQ(parts.size(), 1u);
1074
Austin Schuh79b30942021-01-24 22:32:21 -08001075 size_t mapper0_count = 0;
Austin Schuh8bf1e632021-01-02 22:41:04 -08001076 TimestampMapper mapper0(FilterPartsForNode(parts, "pi1"));
Austin Schuh79b30942021-01-24 22:32:21 -08001077 mapper0.set_timestamp_callback(
1078 [&](TimestampedMessage *) { ++mapper0_count; });
1079 size_t mapper1_count = 0;
Austin Schuh8bf1e632021-01-02 22:41:04 -08001080 TimestampMapper mapper1(FilterPartsForNode(parts, "pi2"));
Austin Schuh79b30942021-01-24 22:32:21 -08001081 mapper1.set_timestamp_callback(
1082 [&](TimestampedMessage *) { ++mapper1_count; });
Austin Schuh8bf1e632021-01-02 22:41:04 -08001083
1084 mapper0.AddPeer(&mapper1);
1085 mapper1.AddPeer(&mapper0);
1086
1087 {
1088 std::deque<TimestampedMessage> output0;
1089
1090 for (int i = 0; i < 3; ++i) {
1091 ASSERT_TRUE(mapper0.Front() != nullptr) << ": " << i;
1092 output0.emplace_back(std::move(*mapper0.Front()));
1093 mapper0.PopFront();
1094 }
1095
1096 ASSERT_TRUE(mapper0.Front() == nullptr);
1097
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001098 EXPECT_EQ(output0[0].monotonic_event_time.boot, 0u);
1099 EXPECT_EQ(output0[0].monotonic_event_time.time,
1100 e + chrono::milliseconds(1000));
1101 EXPECT_EQ(output0[0].monotonic_timestamp_time.boot, 0u);
1102 EXPECT_EQ(output0[0].monotonic_timestamp_time.time,
1103 monotonic_clock::min_time);
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001104 EXPECT_TRUE(output0[0].data != nullptr);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001105
1106 EXPECT_EQ(output0[1].monotonic_event_time.boot, 0u);
1107 EXPECT_EQ(output0[1].monotonic_event_time.time,
1108 e + chrono::milliseconds(2000));
1109 EXPECT_EQ(output0[1].monotonic_timestamp_time.boot, 0u);
1110 EXPECT_EQ(output0[1].monotonic_timestamp_time.time,
1111 monotonic_clock::min_time);
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001112 EXPECT_TRUE(output0[1].data != nullptr);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001113
1114 EXPECT_EQ(output0[2].monotonic_event_time.boot, 0u);
1115 EXPECT_EQ(output0[2].monotonic_event_time.time,
1116 e + chrono::milliseconds(3000));
1117 EXPECT_EQ(output0[2].monotonic_timestamp_time.boot, 0u);
1118 EXPECT_EQ(output0[2].monotonic_timestamp_time.time,
1119 monotonic_clock::min_time);
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001120 EXPECT_TRUE(output0[2].data != nullptr);
Austin Schuh8bf1e632021-01-02 22:41:04 -08001121 }
1122
1123 {
1124 SCOPED_TRACE("Trying node1 now");
1125 std::deque<TimestampedMessage> output1;
1126
1127 for (int i = 0; i < 3; ++i) {
1128 ASSERT_TRUE(mapper1.Front() != nullptr);
1129 output1.emplace_back(std::move(*mapper1.Front()));
1130 mapper1.PopFront();
1131 }
1132
1133 ASSERT_TRUE(mapper1.Front() == nullptr);
1134
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001135 EXPECT_EQ(output1[0].monotonic_event_time.boot, 0u);
1136 EXPECT_EQ(output1[0].monotonic_event_time.time,
Austin Schuh8bf1e632021-01-02 22:41:04 -08001137 e + chrono::seconds(100) + chrono::milliseconds(1000));
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001138 EXPECT_EQ(output1[0].monotonic_timestamp_time.boot, 0u);
1139 EXPECT_EQ(output1[0].monotonic_timestamp_time.time,
Austin Schuh8bf1e632021-01-02 22:41:04 -08001140 e + chrono::nanoseconds(971));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001141 EXPECT_TRUE(output1[0].data != nullptr);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001142
1143 EXPECT_EQ(output1[1].monotonic_event_time.boot, 0u);
1144 EXPECT_EQ(output1[1].monotonic_event_time.time,
Austin Schuh8bf1e632021-01-02 22:41:04 -08001145 e + chrono::seconds(100) + chrono::milliseconds(2000));
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001146 EXPECT_EQ(output1[1].monotonic_timestamp_time.boot, 0u);
1147 EXPECT_EQ(output1[1].monotonic_timestamp_time.time,
Austin Schuh8bf1e632021-01-02 22:41:04 -08001148 e + chrono::nanoseconds(5458));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001149 EXPECT_TRUE(output1[1].data != nullptr);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001150
1151 EXPECT_EQ(output1[2].monotonic_event_time.boot, 0u);
1152 EXPECT_EQ(output1[2].monotonic_event_time.time,
Austin Schuh8bf1e632021-01-02 22:41:04 -08001153 e + chrono::seconds(100) + chrono::milliseconds(3000));
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001154 EXPECT_EQ(output1[2].monotonic_timestamp_time.boot, 0u);
1155 EXPECT_EQ(output1[2].monotonic_timestamp_time.time,
1156 monotonic_clock::min_time);
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001157 EXPECT_TRUE(output1[2].data != nullptr);
Austin Schuh8bf1e632021-01-02 22:41:04 -08001158 }
Austin Schuh79b30942021-01-24 22:32:21 -08001159
1160 EXPECT_EQ(mapper0_count, 3u);
1161 EXPECT_EQ(mapper1_count, 3u);
Austin Schuh8bf1e632021-01-02 22:41:04 -08001162}
1163
Austin Schuhd2f96102020-12-01 20:27:29 -08001164// Tests that we can match timestamps on delivered messages. By doing this in
1165// the reverse order, the second node needs to queue data up from the first node
1166// to find the matching timestamp.
1167TEST_F(TimestampMapperTest, ReadNode1First) {
1168 const aos::monotonic_clock::time_point e = monotonic_clock::epoch();
1169 {
Austin Schuhd863e6e2022-10-16 15:44:50 -07001170 TestDetachedBufferWriter writer0(logfile0_);
Austin Schuhd2f96102020-12-01 20:27:29 -08001171 writer0.QueueSpan(config0_.span());
Austin Schuhd863e6e2022-10-16 15:44:50 -07001172 TestDetachedBufferWriter writer1(logfile1_);
Austin Schuhd2f96102020-12-01 20:27:29 -08001173 writer1.QueueSpan(config2_.span());
1174
Austin Schuhd863e6e2022-10-16 15:44:50 -07001175 writer0.WriteSizedFlatbuffer(
Austin Schuhd2f96102020-12-01 20:27:29 -08001176 MakeLogMessage(e + chrono::milliseconds(1000), 0, 0x005));
Austin Schuhd863e6e2022-10-16 15:44:50 -07001177 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuhd2f96102020-12-01 20:27:29 -08001178 e + chrono::milliseconds(1000), 0, chrono::seconds(100)));
1179
Austin Schuhd863e6e2022-10-16 15:44:50 -07001180 writer0.WriteSizedFlatbuffer(
Austin Schuhd2f96102020-12-01 20:27:29 -08001181 MakeLogMessage(e + chrono::milliseconds(2000), 0, 0x006));
Austin Schuhd863e6e2022-10-16 15:44:50 -07001182 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuhd2f96102020-12-01 20:27:29 -08001183 e + chrono::milliseconds(2000), 0, chrono::seconds(100)));
1184
Austin Schuhd863e6e2022-10-16 15:44:50 -07001185 writer0.WriteSizedFlatbuffer(
Austin Schuhd2f96102020-12-01 20:27:29 -08001186 MakeLogMessage(e + chrono::milliseconds(3000), 0, 0x007));
Austin Schuhd863e6e2022-10-16 15:44:50 -07001187 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuhd2f96102020-12-01 20:27:29 -08001188 e + chrono::milliseconds(3000), 0, chrono::seconds(100)));
1189 }
1190
1191 const std::vector<LogFile> parts = SortParts({logfile0_, logfile1_});
1192
1193 ASSERT_EQ(parts[0].logger_node, "pi1");
1194 ASSERT_EQ(parts[1].logger_node, "pi2");
1195
Austin Schuh79b30942021-01-24 22:32:21 -08001196 size_t mapper0_count = 0;
Austin Schuhd2f96102020-12-01 20:27:29 -08001197 TimestampMapper mapper0(FilterPartsForNode(parts, "pi1"));
Austin Schuh79b30942021-01-24 22:32:21 -08001198 mapper0.set_timestamp_callback(
1199 [&](TimestampedMessage *) { ++mapper0_count; });
1200 size_t mapper1_count = 0;
Austin Schuhd2f96102020-12-01 20:27:29 -08001201 TimestampMapper mapper1(FilterPartsForNode(parts, "pi2"));
Austin Schuh79b30942021-01-24 22:32:21 -08001202 mapper1.set_timestamp_callback(
1203 [&](TimestampedMessage *) { ++mapper1_count; });
Austin Schuhd2f96102020-12-01 20:27:29 -08001204
1205 mapper0.AddPeer(&mapper1);
1206 mapper1.AddPeer(&mapper0);
1207
1208 {
1209 SCOPED_TRACE("Trying node1 now");
1210 std::deque<TimestampedMessage> output1;
1211
1212 ASSERT_TRUE(mapper1.Front() != nullptr);
1213 output1.emplace_back(std::move(*mapper1.Front()));
1214 mapper1.PopFront();
Austin Schuh24bf4972021-06-29 22:09:08 -07001215 EXPECT_TRUE(mapper1.started());
Austin Schuhd2f96102020-12-01 20:27:29 -08001216
1217 ASSERT_TRUE(mapper1.Front() != nullptr);
1218 output1.emplace_back(std::move(*mapper1.Front()));
1219 mapper1.PopFront();
Austin Schuh24bf4972021-06-29 22:09:08 -07001220 EXPECT_TRUE(mapper1.started());
Austin Schuhd2f96102020-12-01 20:27:29 -08001221
1222 ASSERT_TRUE(mapper1.Front() != nullptr);
1223 output1.emplace_back(std::move(*mapper1.Front()));
1224 mapper1.PopFront();
Austin Schuh24bf4972021-06-29 22:09:08 -07001225 EXPECT_TRUE(mapper1.started());
Austin Schuhd2f96102020-12-01 20:27:29 -08001226
1227 ASSERT_TRUE(mapper1.Front() == nullptr);
1228
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001229 EXPECT_EQ(output1[0].monotonic_event_time.boot, 0u);
1230 EXPECT_EQ(output1[0].monotonic_event_time.time,
Austin Schuhd2f96102020-12-01 20:27:29 -08001231 e + chrono::seconds(100) + chrono::milliseconds(1000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001232 EXPECT_TRUE(output1[0].data != nullptr);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001233
1234 EXPECT_EQ(output1[1].monotonic_event_time.boot, 0u);
1235 EXPECT_EQ(output1[1].monotonic_event_time.time,
Austin Schuhd2f96102020-12-01 20:27:29 -08001236 e + chrono::seconds(100) + chrono::milliseconds(2000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001237 EXPECT_TRUE(output1[1].data != nullptr);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001238
1239 EXPECT_EQ(output1[2].monotonic_event_time.boot, 0u);
1240 EXPECT_EQ(output1[2].monotonic_event_time.time,
Austin Schuhd2f96102020-12-01 20:27:29 -08001241 e + chrono::seconds(100) + chrono::milliseconds(3000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001242 EXPECT_TRUE(output1[2].data != nullptr);
Austin Schuhd2f96102020-12-01 20:27:29 -08001243 }
1244
1245 {
1246 std::deque<TimestampedMessage> output0;
1247
1248 ASSERT_TRUE(mapper0.Front() != nullptr);
1249 output0.emplace_back(std::move(*mapper0.Front()));
1250 mapper0.PopFront();
Austin Schuh24bf4972021-06-29 22:09:08 -07001251 EXPECT_TRUE(mapper0.started());
Austin Schuhd2f96102020-12-01 20:27:29 -08001252
1253 ASSERT_TRUE(mapper0.Front() != nullptr);
1254 output0.emplace_back(std::move(*mapper0.Front()));
1255 mapper0.PopFront();
Austin Schuh24bf4972021-06-29 22:09:08 -07001256 EXPECT_TRUE(mapper0.started());
Austin Schuhd2f96102020-12-01 20:27:29 -08001257
1258 ASSERT_TRUE(mapper0.Front() != nullptr);
1259 output0.emplace_back(std::move(*mapper0.Front()));
1260 mapper0.PopFront();
Austin Schuh24bf4972021-06-29 22:09:08 -07001261 EXPECT_TRUE(mapper0.started());
Austin Schuhd2f96102020-12-01 20:27:29 -08001262
1263 ASSERT_TRUE(mapper0.Front() == nullptr);
1264
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001265 EXPECT_EQ(output0[0].monotonic_event_time.boot, 0u);
1266 EXPECT_EQ(output0[0].monotonic_event_time.time,
1267 e + chrono::milliseconds(1000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001268 EXPECT_TRUE(output0[0].data != nullptr);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001269
1270 EXPECT_EQ(output0[1].monotonic_event_time.boot, 0u);
1271 EXPECT_EQ(output0[1].monotonic_event_time.time,
1272 e + chrono::milliseconds(2000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001273 EXPECT_TRUE(output0[1].data != nullptr);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001274
1275 EXPECT_EQ(output0[2].monotonic_event_time.boot, 0u);
1276 EXPECT_EQ(output0[2].monotonic_event_time.time,
1277 e + chrono::milliseconds(3000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001278 EXPECT_TRUE(output0[2].data != nullptr);
Austin Schuhd2f96102020-12-01 20:27:29 -08001279 }
Austin Schuh79b30942021-01-24 22:32:21 -08001280
1281 EXPECT_EQ(mapper0_count, 3u);
1282 EXPECT_EQ(mapper1_count, 3u);
Austin Schuhd2f96102020-12-01 20:27:29 -08001283}
1284
1285// Tests that we return just the timestamps if we couldn't find the data and the
1286// missing data was at the beginning of the file.
1287TEST_F(TimestampMapperTest, ReadMissingDataBefore) {
1288 const aos::monotonic_clock::time_point e = monotonic_clock::epoch();
1289 {
Austin Schuhd863e6e2022-10-16 15:44:50 -07001290 TestDetachedBufferWriter writer0(logfile0_);
Austin Schuhd2f96102020-12-01 20:27:29 -08001291 writer0.QueueSpan(config0_.span());
Austin Schuhd863e6e2022-10-16 15:44:50 -07001292 TestDetachedBufferWriter writer1(logfile1_);
Austin Schuhd2f96102020-12-01 20:27:29 -08001293 writer1.QueueSpan(config2_.span());
1294
1295 MakeLogMessage(e + chrono::milliseconds(1000), 0, 0x005);
Austin Schuhd863e6e2022-10-16 15:44:50 -07001296 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuhd2f96102020-12-01 20:27:29 -08001297 e + chrono::milliseconds(1000), 0, chrono::seconds(100)));
1298
Austin Schuhd863e6e2022-10-16 15:44:50 -07001299 writer0.WriteSizedFlatbuffer(
Austin Schuhd2f96102020-12-01 20:27:29 -08001300 MakeLogMessage(e + chrono::milliseconds(2000), 0, 0x006));
Austin Schuhd863e6e2022-10-16 15:44:50 -07001301 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuhd2f96102020-12-01 20:27:29 -08001302 e + chrono::milliseconds(2000), 0, chrono::seconds(100)));
1303
Austin Schuhd863e6e2022-10-16 15:44:50 -07001304 writer0.WriteSizedFlatbuffer(
Austin Schuhd2f96102020-12-01 20:27:29 -08001305 MakeLogMessage(e + chrono::milliseconds(3000), 0, 0x007));
Austin Schuhd863e6e2022-10-16 15:44:50 -07001306 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuhd2f96102020-12-01 20:27:29 -08001307 e + chrono::milliseconds(3000), 0, chrono::seconds(100)));
1308 }
1309
1310 const std::vector<LogFile> parts = SortParts({logfile0_, logfile1_});
1311
1312 ASSERT_EQ(parts[0].logger_node, "pi1");
1313 ASSERT_EQ(parts[1].logger_node, "pi2");
1314
Austin Schuh79b30942021-01-24 22:32:21 -08001315 size_t mapper0_count = 0;
Austin Schuhd2f96102020-12-01 20:27:29 -08001316 TimestampMapper mapper0(FilterPartsForNode(parts, "pi1"));
Austin Schuh79b30942021-01-24 22:32:21 -08001317 mapper0.set_timestamp_callback(
1318 [&](TimestampedMessage *) { ++mapper0_count; });
1319 size_t mapper1_count = 0;
Austin Schuhd2f96102020-12-01 20:27:29 -08001320 TimestampMapper mapper1(FilterPartsForNode(parts, "pi2"));
Austin Schuh79b30942021-01-24 22:32:21 -08001321 mapper1.set_timestamp_callback(
1322 [&](TimestampedMessage *) { ++mapper1_count; });
Austin Schuhd2f96102020-12-01 20:27:29 -08001323
1324 mapper0.AddPeer(&mapper1);
1325 mapper1.AddPeer(&mapper0);
1326
1327 {
1328 SCOPED_TRACE("Trying node1 now");
1329 std::deque<TimestampedMessage> output1;
1330
1331 ASSERT_TRUE(mapper1.Front() != nullptr);
1332 output1.emplace_back(std::move(*mapper1.Front()));
1333 mapper1.PopFront();
Austin Schuh24bf4972021-06-29 22:09:08 -07001334 EXPECT_TRUE(mapper1.started());
Austin Schuhd2f96102020-12-01 20:27:29 -08001335
1336 ASSERT_TRUE(mapper1.Front() != nullptr);
1337 output1.emplace_back(std::move(*mapper1.Front()));
1338 mapper1.PopFront();
Austin Schuh24bf4972021-06-29 22:09:08 -07001339 EXPECT_TRUE(mapper1.started());
Austin Schuhd2f96102020-12-01 20:27:29 -08001340
1341 ASSERT_TRUE(mapper1.Front() != nullptr);
1342 output1.emplace_back(std::move(*mapper1.Front()));
1343 mapper1.PopFront();
Austin Schuh24bf4972021-06-29 22:09:08 -07001344 EXPECT_TRUE(mapper1.started());
Austin Schuhd2f96102020-12-01 20:27:29 -08001345
1346 ASSERT_TRUE(mapper1.Front() == nullptr);
1347
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001348 EXPECT_EQ(output1[0].monotonic_event_time.boot, 0u);
1349 EXPECT_EQ(output1[0].monotonic_event_time.time,
Austin Schuhd2f96102020-12-01 20:27:29 -08001350 e + chrono::seconds(100) + chrono::milliseconds(1000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001351 EXPECT_FALSE(output1[0].data != nullptr);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001352
1353 EXPECT_EQ(output1[1].monotonic_event_time.boot, 0u);
1354 EXPECT_EQ(output1[1].monotonic_event_time.time,
Austin Schuhd2f96102020-12-01 20:27:29 -08001355 e + chrono::seconds(100) + chrono::milliseconds(2000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001356 EXPECT_TRUE(output1[1].data != nullptr);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001357
1358 EXPECT_EQ(output1[2].monotonic_event_time.boot, 0u);
1359 EXPECT_EQ(output1[2].monotonic_event_time.time,
Austin Schuhd2f96102020-12-01 20:27:29 -08001360 e + chrono::seconds(100) + chrono::milliseconds(3000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001361 EXPECT_TRUE(output1[2].data != nullptr);
Austin Schuhd2f96102020-12-01 20:27:29 -08001362 }
Austin Schuh79b30942021-01-24 22:32:21 -08001363
1364 EXPECT_EQ(mapper0_count, 0u);
1365 EXPECT_EQ(mapper1_count, 3u);
Austin Schuhd2f96102020-12-01 20:27:29 -08001366}
1367
1368// Tests that we return just the timestamps if we couldn't find the data and the
1369// missing data was at the end of the file.
1370TEST_F(TimestampMapperTest, ReadMissingDataAfter) {
1371 const aos::monotonic_clock::time_point e = monotonic_clock::epoch();
1372 {
Austin Schuhd863e6e2022-10-16 15:44:50 -07001373 TestDetachedBufferWriter writer0(logfile0_);
Austin Schuhd2f96102020-12-01 20:27:29 -08001374 writer0.QueueSpan(config0_.span());
Austin Schuhd863e6e2022-10-16 15:44:50 -07001375 TestDetachedBufferWriter writer1(logfile1_);
Austin Schuhd2f96102020-12-01 20:27:29 -08001376 writer1.QueueSpan(config2_.span());
1377
Austin Schuhd863e6e2022-10-16 15:44:50 -07001378 writer0.WriteSizedFlatbuffer(
Austin Schuhd2f96102020-12-01 20:27:29 -08001379 MakeLogMessage(e + chrono::milliseconds(1000), 0, 0x005));
Austin Schuhd863e6e2022-10-16 15:44:50 -07001380 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuhd2f96102020-12-01 20:27:29 -08001381 e + chrono::milliseconds(1000), 0, chrono::seconds(100)));
1382
Austin Schuhd863e6e2022-10-16 15:44:50 -07001383 writer0.WriteSizedFlatbuffer(
Austin Schuhd2f96102020-12-01 20:27:29 -08001384 MakeLogMessage(e + chrono::milliseconds(2000), 0, 0x006));
Austin Schuhd863e6e2022-10-16 15:44:50 -07001385 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuhd2f96102020-12-01 20:27:29 -08001386 e + chrono::milliseconds(2000), 0, chrono::seconds(100)));
1387
1388 MakeLogMessage(e + chrono::milliseconds(3000), 0, 0x007);
Austin Schuhd863e6e2022-10-16 15:44:50 -07001389 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuhd2f96102020-12-01 20:27:29 -08001390 e + chrono::milliseconds(3000), 0, chrono::seconds(100)));
1391 }
1392
1393 const std::vector<LogFile> parts = SortParts({logfile0_, logfile1_});
1394
1395 ASSERT_EQ(parts[0].logger_node, "pi1");
1396 ASSERT_EQ(parts[1].logger_node, "pi2");
1397
Austin Schuh79b30942021-01-24 22:32:21 -08001398 size_t mapper0_count = 0;
Austin Schuhd2f96102020-12-01 20:27:29 -08001399 TimestampMapper mapper0(FilterPartsForNode(parts, "pi1"));
Austin Schuh79b30942021-01-24 22:32:21 -08001400 mapper0.set_timestamp_callback(
1401 [&](TimestampedMessage *) { ++mapper0_count; });
1402 size_t mapper1_count = 0;
Austin Schuhd2f96102020-12-01 20:27:29 -08001403 TimestampMapper mapper1(FilterPartsForNode(parts, "pi2"));
Austin Schuh79b30942021-01-24 22:32:21 -08001404 mapper1.set_timestamp_callback(
1405 [&](TimestampedMessage *) { ++mapper1_count; });
Austin Schuhd2f96102020-12-01 20:27:29 -08001406
1407 mapper0.AddPeer(&mapper1);
1408 mapper1.AddPeer(&mapper0);
1409
1410 {
1411 SCOPED_TRACE("Trying node1 now");
1412 std::deque<TimestampedMessage> output1;
1413
1414 ASSERT_TRUE(mapper1.Front() != nullptr);
1415 output1.emplace_back(std::move(*mapper1.Front()));
1416 mapper1.PopFront();
Austin Schuh24bf4972021-06-29 22:09:08 -07001417 EXPECT_TRUE(mapper1.started());
Austin Schuhd2f96102020-12-01 20:27:29 -08001418
1419 ASSERT_TRUE(mapper1.Front() != nullptr);
1420 output1.emplace_back(std::move(*mapper1.Front()));
1421 mapper1.PopFront();
Austin Schuh24bf4972021-06-29 22:09:08 -07001422 EXPECT_TRUE(mapper1.started());
Austin Schuhd2f96102020-12-01 20:27:29 -08001423
1424 ASSERT_TRUE(mapper1.Front() != nullptr);
1425 output1.emplace_back(std::move(*mapper1.Front()));
1426 mapper1.PopFront();
Austin Schuh24bf4972021-06-29 22:09:08 -07001427 EXPECT_TRUE(mapper1.started());
Austin Schuhd2f96102020-12-01 20:27:29 -08001428
1429 ASSERT_TRUE(mapper1.Front() == nullptr);
1430
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001431 EXPECT_EQ(output1[0].monotonic_event_time.boot, 0u);
1432 EXPECT_EQ(output1[0].monotonic_event_time.time,
Austin Schuhd2f96102020-12-01 20:27:29 -08001433 e + chrono::seconds(100) + chrono::milliseconds(1000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001434 EXPECT_TRUE(output1[0].data != nullptr);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001435
1436 EXPECT_EQ(output1[1].monotonic_event_time.boot, 0u);
1437 EXPECT_EQ(output1[1].monotonic_event_time.time,
Austin Schuhd2f96102020-12-01 20:27:29 -08001438 e + chrono::seconds(100) + chrono::milliseconds(2000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001439 EXPECT_TRUE(output1[1].data != nullptr);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001440
1441 EXPECT_EQ(output1[2].monotonic_event_time.boot, 0u);
1442 EXPECT_EQ(output1[2].monotonic_event_time.time,
Austin Schuhd2f96102020-12-01 20:27:29 -08001443 e + chrono::seconds(100) + chrono::milliseconds(3000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001444 EXPECT_FALSE(output1[2].data != nullptr);
Austin Schuhd2f96102020-12-01 20:27:29 -08001445 }
Austin Schuh79b30942021-01-24 22:32:21 -08001446
1447 EXPECT_EQ(mapper0_count, 0u);
1448 EXPECT_EQ(mapper1_count, 3u);
Austin Schuhd2f96102020-12-01 20:27:29 -08001449}
1450
Austin Schuh993ccb52020-12-12 15:59:32 -08001451// Tests that we handle a message which failed to forward or be logged.
1452TEST_F(TimestampMapperTest, ReadMissingDataMiddle) {
1453 const aos::monotonic_clock::time_point e = monotonic_clock::epoch();
1454 {
Austin Schuhd863e6e2022-10-16 15:44:50 -07001455 TestDetachedBufferWriter writer0(logfile0_);
Austin Schuh993ccb52020-12-12 15:59:32 -08001456 writer0.QueueSpan(config0_.span());
Austin Schuhd863e6e2022-10-16 15:44:50 -07001457 TestDetachedBufferWriter writer1(logfile1_);
Austin Schuh993ccb52020-12-12 15:59:32 -08001458 writer1.QueueSpan(config2_.span());
1459
Austin Schuhd863e6e2022-10-16 15:44:50 -07001460 writer0.WriteSizedFlatbuffer(
Austin Schuh993ccb52020-12-12 15:59:32 -08001461 MakeLogMessage(e + chrono::milliseconds(1000), 0, 0x005));
Austin Schuhd863e6e2022-10-16 15:44:50 -07001462 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuh993ccb52020-12-12 15:59:32 -08001463 e + chrono::milliseconds(1000), 0, chrono::seconds(100)));
1464
1465 // Create both the timestamp and message, but don't log them, simulating a
1466 // forwarding drop.
1467 MakeLogMessage(e + chrono::milliseconds(2000), 0, 0x006);
1468 MakeTimestampMessage(e + chrono::milliseconds(2000), 0,
1469 chrono::seconds(100));
1470
Austin Schuhd863e6e2022-10-16 15:44:50 -07001471 writer0.WriteSizedFlatbuffer(
Austin Schuh993ccb52020-12-12 15:59:32 -08001472 MakeLogMessage(e + chrono::milliseconds(3000), 0, 0x007));
Austin Schuhd863e6e2022-10-16 15:44:50 -07001473 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuh993ccb52020-12-12 15:59:32 -08001474 e + chrono::milliseconds(3000), 0, chrono::seconds(100)));
1475 }
1476
1477 const std::vector<LogFile> parts = SortParts({logfile0_, logfile1_});
1478
1479 ASSERT_EQ(parts[0].logger_node, "pi1");
1480 ASSERT_EQ(parts[1].logger_node, "pi2");
1481
Austin Schuh79b30942021-01-24 22:32:21 -08001482 size_t mapper0_count = 0;
Austin Schuh993ccb52020-12-12 15:59:32 -08001483 TimestampMapper mapper0(FilterPartsForNode(parts, "pi1"));
Austin Schuh79b30942021-01-24 22:32:21 -08001484 mapper0.set_timestamp_callback(
1485 [&](TimestampedMessage *) { ++mapper0_count; });
1486 size_t mapper1_count = 0;
Austin Schuh993ccb52020-12-12 15:59:32 -08001487 TimestampMapper mapper1(FilterPartsForNode(parts, "pi2"));
Austin Schuh79b30942021-01-24 22:32:21 -08001488 mapper1.set_timestamp_callback(
1489 [&](TimestampedMessage *) { ++mapper1_count; });
Austin Schuh993ccb52020-12-12 15:59:32 -08001490
1491 mapper0.AddPeer(&mapper1);
1492 mapper1.AddPeer(&mapper0);
1493
1494 {
1495 std::deque<TimestampedMessage> output1;
1496
1497 ASSERT_TRUE(mapper1.Front() != nullptr);
1498 output1.emplace_back(std::move(*mapper1.Front()));
1499 mapper1.PopFront();
1500
1501 ASSERT_TRUE(mapper1.Front() != nullptr);
1502 output1.emplace_back(std::move(*mapper1.Front()));
1503
1504 ASSERT_FALSE(mapper1.Front() == nullptr);
1505
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001506 EXPECT_EQ(output1[0].monotonic_event_time.boot, 0u);
1507 EXPECT_EQ(output1[0].monotonic_event_time.time,
Austin Schuh993ccb52020-12-12 15:59:32 -08001508 e + chrono::seconds(100) + chrono::milliseconds(1000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001509 EXPECT_TRUE(output1[0].data != nullptr);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001510
1511 EXPECT_EQ(output1[1].monotonic_event_time.boot, 0u);
1512 EXPECT_EQ(output1[1].monotonic_event_time.time,
Austin Schuh993ccb52020-12-12 15:59:32 -08001513 e + chrono::seconds(100) + chrono::milliseconds(3000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001514 EXPECT_TRUE(output1[1].data != nullptr);
Austin Schuh993ccb52020-12-12 15:59:32 -08001515 }
Austin Schuh79b30942021-01-24 22:32:21 -08001516
1517 EXPECT_EQ(mapper0_count, 0u);
1518 EXPECT_EQ(mapper1_count, 2u);
Austin Schuh993ccb52020-12-12 15:59:32 -08001519}
1520
Austin Schuhd2f96102020-12-01 20:27:29 -08001521// Tests that we properly sort log files with duplicate timestamps.
1522TEST_F(TimestampMapperTest, ReadSameTimestamp) {
1523 const aos::monotonic_clock::time_point e = monotonic_clock::epoch();
1524 {
Austin Schuhd863e6e2022-10-16 15:44:50 -07001525 TestDetachedBufferWriter writer0(logfile0_);
Austin Schuhd2f96102020-12-01 20:27:29 -08001526 writer0.QueueSpan(config0_.span());
Austin Schuhd863e6e2022-10-16 15:44:50 -07001527 TestDetachedBufferWriter writer1(logfile1_);
Austin Schuhd2f96102020-12-01 20:27:29 -08001528 writer1.QueueSpan(config2_.span());
1529
Austin Schuhd863e6e2022-10-16 15:44:50 -07001530 writer0.WriteSizedFlatbuffer(
Austin Schuhd2f96102020-12-01 20:27:29 -08001531 MakeLogMessage(e + chrono::milliseconds(1000), 0, 0x005));
Austin Schuhd863e6e2022-10-16 15:44:50 -07001532 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuhd2f96102020-12-01 20:27:29 -08001533 e + chrono::milliseconds(1000), 0, chrono::seconds(100)));
1534
Austin Schuhd863e6e2022-10-16 15:44:50 -07001535 writer0.WriteSizedFlatbuffer(
Austin Schuhd2f96102020-12-01 20:27:29 -08001536 MakeLogMessage(e + chrono::milliseconds(2000), 0, 0x006));
Austin Schuhd863e6e2022-10-16 15:44:50 -07001537 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuhd2f96102020-12-01 20:27:29 -08001538 e + chrono::milliseconds(2000), 0, chrono::seconds(100)));
1539
Austin Schuhd863e6e2022-10-16 15:44:50 -07001540 writer0.WriteSizedFlatbuffer(
Austin Schuhd2f96102020-12-01 20:27:29 -08001541 MakeLogMessage(e + chrono::milliseconds(2000), 0, 0x007));
Austin Schuhd863e6e2022-10-16 15:44:50 -07001542 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuhd2f96102020-12-01 20:27:29 -08001543 e + chrono::milliseconds(2000), 0, chrono::seconds(100)));
1544
Austin Schuhd863e6e2022-10-16 15:44:50 -07001545 writer0.WriteSizedFlatbuffer(
Austin Schuhd2f96102020-12-01 20:27:29 -08001546 MakeLogMessage(e + chrono::milliseconds(3000), 0, 0x008));
Austin Schuhd863e6e2022-10-16 15:44:50 -07001547 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuhd2f96102020-12-01 20:27:29 -08001548 e + chrono::milliseconds(3000), 0, chrono::seconds(100)));
1549 }
1550
1551 const std::vector<LogFile> parts = SortParts({logfile0_, logfile1_});
1552
1553 ASSERT_EQ(parts[0].logger_node, "pi1");
1554 ASSERT_EQ(parts[1].logger_node, "pi2");
1555
Austin Schuh79b30942021-01-24 22:32:21 -08001556 size_t mapper0_count = 0;
Austin Schuhd2f96102020-12-01 20:27:29 -08001557 TimestampMapper mapper0(FilterPartsForNode(parts, "pi1"));
Austin Schuh79b30942021-01-24 22:32:21 -08001558 mapper0.set_timestamp_callback(
1559 [&](TimestampedMessage *) { ++mapper0_count; });
1560 size_t mapper1_count = 0;
Austin Schuhd2f96102020-12-01 20:27:29 -08001561 TimestampMapper mapper1(FilterPartsForNode(parts, "pi2"));
Austin Schuh79b30942021-01-24 22:32:21 -08001562 mapper1.set_timestamp_callback(
1563 [&](TimestampedMessage *) { ++mapper1_count; });
Austin Schuhd2f96102020-12-01 20:27:29 -08001564
1565 mapper0.AddPeer(&mapper1);
1566 mapper1.AddPeer(&mapper0);
1567
1568 {
1569 SCOPED_TRACE("Trying node1 now");
1570 std::deque<TimestampedMessage> output1;
1571
1572 for (int i = 0; i < 4; ++i) {
1573 ASSERT_TRUE(mapper1.Front() != nullptr);
1574 output1.emplace_back(std::move(*mapper1.Front()));
1575 mapper1.PopFront();
1576 }
1577 ASSERT_TRUE(mapper1.Front() == nullptr);
1578
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001579 EXPECT_EQ(output1[0].monotonic_event_time.boot, 0u);
1580 EXPECT_EQ(output1[0].monotonic_event_time.time,
Austin Schuhd2f96102020-12-01 20:27:29 -08001581 e + chrono::seconds(100) + chrono::milliseconds(1000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001582 EXPECT_TRUE(output1[0].data != nullptr);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001583
1584 EXPECT_EQ(output1[1].monotonic_event_time.boot, 0u);
1585 EXPECT_EQ(output1[1].monotonic_event_time.time,
Austin Schuhd2f96102020-12-01 20:27:29 -08001586 e + chrono::seconds(100) + chrono::milliseconds(2000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001587 EXPECT_TRUE(output1[1].data != nullptr);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001588
1589 EXPECT_EQ(output1[2].monotonic_event_time.boot, 0u);
1590 EXPECT_EQ(output1[2].monotonic_event_time.time,
Austin Schuhd2f96102020-12-01 20:27:29 -08001591 e + chrono::seconds(100) + chrono::milliseconds(2000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001592 EXPECT_TRUE(output1[2].data != nullptr);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001593
1594 EXPECT_EQ(output1[3].monotonic_event_time.boot, 0u);
1595 EXPECT_EQ(output1[3].monotonic_event_time.time,
Austin Schuhd2f96102020-12-01 20:27:29 -08001596 e + chrono::seconds(100) + chrono::milliseconds(3000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001597 EXPECT_TRUE(output1[3].data != nullptr);
Austin Schuhd2f96102020-12-01 20:27:29 -08001598 }
Austin Schuh79b30942021-01-24 22:32:21 -08001599
1600 EXPECT_EQ(mapper0_count, 0u);
1601 EXPECT_EQ(mapper1_count, 4u);
Austin Schuhd2f96102020-12-01 20:27:29 -08001602}
1603
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001604// Tests that we properly produce a valid start time.
Austin Schuhd2f96102020-12-01 20:27:29 -08001605TEST_F(TimestampMapperTest, StartTime) {
1606 const aos::monotonic_clock::time_point e = monotonic_clock::epoch();
1607 {
Austin Schuhd863e6e2022-10-16 15:44:50 -07001608 TestDetachedBufferWriter writer0(logfile0_);
Austin Schuhd2f96102020-12-01 20:27:29 -08001609 writer0.QueueSpan(config0_.span());
Austin Schuhd863e6e2022-10-16 15:44:50 -07001610 TestDetachedBufferWriter writer1(logfile1_);
Austin Schuhd2f96102020-12-01 20:27:29 -08001611 writer1.QueueSpan(config1_.span());
Austin Schuhd863e6e2022-10-16 15:44:50 -07001612 TestDetachedBufferWriter writer2(logfile2_);
Austin Schuhd2f96102020-12-01 20:27:29 -08001613 writer2.QueueSpan(config3_.span());
1614 }
1615
1616 const std::vector<LogFile> parts =
1617 SortParts({logfile0_, logfile1_, logfile2_});
1618
Austin Schuh79b30942021-01-24 22:32:21 -08001619 size_t mapper0_count = 0;
Austin Schuhd2f96102020-12-01 20:27:29 -08001620 TimestampMapper mapper0(FilterPartsForNode(parts, "pi1"));
Austin Schuh79b30942021-01-24 22:32:21 -08001621 mapper0.set_timestamp_callback(
1622 [&](TimestampedMessage *) { ++mapper0_count; });
Austin Schuhd2f96102020-12-01 20:27:29 -08001623
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001624 EXPECT_EQ(mapper0.monotonic_start_time(0), e + chrono::milliseconds(1));
1625 EXPECT_EQ(mapper0.realtime_start_time(0),
Austin Schuhd2f96102020-12-01 20:27:29 -08001626 realtime_clock::time_point(chrono::seconds(1000)));
Austin Schuh79b30942021-01-24 22:32:21 -08001627 EXPECT_EQ(mapper0_count, 0u);
Austin Schuhd2f96102020-12-01 20:27:29 -08001628}
1629
Austin Schuhfecf1d82020-12-19 16:57:28 -08001630// Tests that when a peer isn't registered, we treat that as if there was no
1631// data available.
1632TEST_F(TimestampMapperTest, NoPeer) {
1633 const aos::monotonic_clock::time_point e = monotonic_clock::epoch();
1634 {
Austin Schuhd863e6e2022-10-16 15:44:50 -07001635 TestDetachedBufferWriter writer0(logfile0_);
Austin Schuhfecf1d82020-12-19 16:57:28 -08001636 writer0.QueueSpan(config0_.span());
Austin Schuhd863e6e2022-10-16 15:44:50 -07001637 TestDetachedBufferWriter writer1(logfile1_);
Austin Schuhfecf1d82020-12-19 16:57:28 -08001638 writer1.QueueSpan(config2_.span());
1639
1640 MakeLogMessage(e + chrono::milliseconds(1000), 0, 0x005);
Austin Schuhd863e6e2022-10-16 15:44:50 -07001641 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuhfecf1d82020-12-19 16:57:28 -08001642 e + chrono::milliseconds(1000), 0, chrono::seconds(100)));
1643
Austin Schuhd863e6e2022-10-16 15:44:50 -07001644 writer0.WriteSizedFlatbuffer(
Austin Schuhfecf1d82020-12-19 16:57:28 -08001645 MakeLogMessage(e + chrono::milliseconds(2000), 0, 0x006));
Austin Schuhd863e6e2022-10-16 15:44:50 -07001646 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuhfecf1d82020-12-19 16:57:28 -08001647 e + chrono::milliseconds(2000), 0, chrono::seconds(100)));
1648
Austin Schuhd863e6e2022-10-16 15:44:50 -07001649 writer0.WriteSizedFlatbuffer(
Austin Schuhfecf1d82020-12-19 16:57:28 -08001650 MakeLogMessage(e + chrono::milliseconds(3000), 0, 0x007));
Austin Schuhd863e6e2022-10-16 15:44:50 -07001651 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuhfecf1d82020-12-19 16:57:28 -08001652 e + chrono::milliseconds(3000), 0, chrono::seconds(100)));
1653 }
1654
1655 const std::vector<LogFile> parts = SortParts({logfile0_, logfile1_});
1656
1657 ASSERT_EQ(parts[0].logger_node, "pi1");
1658 ASSERT_EQ(parts[1].logger_node, "pi2");
1659
Austin Schuh79b30942021-01-24 22:32:21 -08001660 size_t mapper1_count = 0;
Austin Schuhfecf1d82020-12-19 16:57:28 -08001661 TimestampMapper mapper1(FilterPartsForNode(parts, "pi2"));
Austin Schuh79b30942021-01-24 22:32:21 -08001662 mapper1.set_timestamp_callback(
1663 [&](TimestampedMessage *) { ++mapper1_count; });
Austin Schuhfecf1d82020-12-19 16:57:28 -08001664
1665 {
1666 std::deque<TimestampedMessage> output1;
1667
1668 ASSERT_TRUE(mapper1.Front() != nullptr);
1669 output1.emplace_back(std::move(*mapper1.Front()));
1670 mapper1.PopFront();
1671 ASSERT_TRUE(mapper1.Front() != nullptr);
1672 output1.emplace_back(std::move(*mapper1.Front()));
1673 mapper1.PopFront();
1674 ASSERT_TRUE(mapper1.Front() != nullptr);
1675 output1.emplace_back(std::move(*mapper1.Front()));
1676 mapper1.PopFront();
1677 ASSERT_TRUE(mapper1.Front() == nullptr);
1678
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001679 EXPECT_EQ(output1[0].monotonic_event_time.boot, 0u);
1680 EXPECT_EQ(output1[0].monotonic_event_time.time,
Austin Schuhfecf1d82020-12-19 16:57:28 -08001681 e + chrono::seconds(100) + chrono::milliseconds(1000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001682 EXPECT_FALSE(output1[0].data != nullptr);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001683
1684 EXPECT_EQ(output1[1].monotonic_event_time.boot, 0u);
1685 EXPECT_EQ(output1[1].monotonic_event_time.time,
Austin Schuhfecf1d82020-12-19 16:57:28 -08001686 e + chrono::seconds(100) + chrono::milliseconds(2000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001687 EXPECT_FALSE(output1[1].data != nullptr);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001688
1689 EXPECT_EQ(output1[2].monotonic_event_time.boot, 0u);
1690 EXPECT_EQ(output1[2].monotonic_event_time.time,
Austin Schuhfecf1d82020-12-19 16:57:28 -08001691 e + chrono::seconds(100) + chrono::milliseconds(3000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001692 EXPECT_FALSE(output1[2].data != nullptr);
Austin Schuhfecf1d82020-12-19 16:57:28 -08001693 }
Austin Schuh79b30942021-01-24 22:32:21 -08001694 EXPECT_EQ(mapper1_count, 3u);
1695}
1696
1697// Tests that we can queue messages and call the timestamp callback for both
1698// nodes.
1699TEST_F(TimestampMapperTest, QueueUntilNode0) {
1700 const aos::monotonic_clock::time_point e = monotonic_clock::epoch();
1701 {
Austin Schuhd863e6e2022-10-16 15:44:50 -07001702 TestDetachedBufferWriter writer0(logfile0_);
Austin Schuh79b30942021-01-24 22:32:21 -08001703 writer0.QueueSpan(config0_.span());
Austin Schuhd863e6e2022-10-16 15:44:50 -07001704 TestDetachedBufferWriter writer1(logfile1_);
Austin Schuh79b30942021-01-24 22:32:21 -08001705 writer1.QueueSpan(config2_.span());
1706
Austin Schuhd863e6e2022-10-16 15:44:50 -07001707 writer0.WriteSizedFlatbuffer(
Austin Schuh79b30942021-01-24 22:32:21 -08001708 MakeLogMessage(e + chrono::milliseconds(1000), 0, 0x005));
Austin Schuhd863e6e2022-10-16 15:44:50 -07001709 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuh79b30942021-01-24 22:32:21 -08001710 e + chrono::milliseconds(1000), 0, chrono::seconds(100)));
1711
Austin Schuhd863e6e2022-10-16 15:44:50 -07001712 writer0.WriteSizedFlatbuffer(
Austin Schuh79b30942021-01-24 22:32:21 -08001713 MakeLogMessage(e + chrono::milliseconds(1000), 0, 0x006));
Austin Schuhd863e6e2022-10-16 15:44:50 -07001714 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuh79b30942021-01-24 22:32:21 -08001715 e + chrono::milliseconds(1000), 0, chrono::seconds(100)));
1716
Austin Schuhd863e6e2022-10-16 15:44:50 -07001717 writer0.WriteSizedFlatbuffer(
Austin Schuh79b30942021-01-24 22:32:21 -08001718 MakeLogMessage(e + chrono::milliseconds(2000), 0, 0x007));
Austin Schuhd863e6e2022-10-16 15:44:50 -07001719 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuh79b30942021-01-24 22:32:21 -08001720 e + chrono::milliseconds(2000), 0, chrono::seconds(100)));
1721
Austin Schuhd863e6e2022-10-16 15:44:50 -07001722 writer0.WriteSizedFlatbuffer(
Austin Schuh79b30942021-01-24 22:32:21 -08001723 MakeLogMessage(e + chrono::milliseconds(3000), 0, 0x008));
Austin Schuhd863e6e2022-10-16 15:44:50 -07001724 writer1.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuh79b30942021-01-24 22:32:21 -08001725 e + chrono::milliseconds(3000), 0, chrono::seconds(100)));
1726 }
1727
1728 const std::vector<LogFile> parts = SortParts({logfile0_, logfile1_});
1729
1730 ASSERT_EQ(parts[0].logger_node, "pi1");
1731 ASSERT_EQ(parts[1].logger_node, "pi2");
1732
1733 size_t mapper0_count = 0;
1734 TimestampMapper mapper0(FilterPartsForNode(parts, "pi1"));
1735 mapper0.set_timestamp_callback(
1736 [&](TimestampedMessage *) { ++mapper0_count; });
1737 size_t mapper1_count = 0;
1738 TimestampMapper mapper1(FilterPartsForNode(parts, "pi2"));
1739 mapper1.set_timestamp_callback(
1740 [&](TimestampedMessage *) { ++mapper1_count; });
1741
1742 mapper0.AddPeer(&mapper1);
1743 mapper1.AddPeer(&mapper0);
1744
1745 {
1746 std::deque<TimestampedMessage> output0;
1747
1748 EXPECT_EQ(mapper0_count, 0u);
1749 EXPECT_EQ(mapper1_count, 0u);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001750 mapper0.QueueUntil(
1751 BootTimestamp{.boot = 0, .time = e + chrono::milliseconds(1000)});
Austin Schuh79b30942021-01-24 22:32:21 -08001752 EXPECT_EQ(mapper0_count, 3u);
1753 EXPECT_EQ(mapper1_count, 0u);
1754
1755 ASSERT_TRUE(mapper0.Front() != nullptr);
1756 EXPECT_EQ(mapper0_count, 3u);
1757 EXPECT_EQ(mapper1_count, 0u);
1758
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001759 mapper0.QueueUntil(
1760 BootTimestamp{.boot = 0, .time = e + chrono::milliseconds(1500)});
Austin Schuh79b30942021-01-24 22:32:21 -08001761 EXPECT_EQ(mapper0_count, 3u);
1762 EXPECT_EQ(mapper1_count, 0u);
1763
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001764 mapper0.QueueUntil(
1765 BootTimestamp{.boot = 0, .time = e + chrono::milliseconds(2500)});
Austin Schuh79b30942021-01-24 22:32:21 -08001766 EXPECT_EQ(mapper0_count, 4u);
1767 EXPECT_EQ(mapper1_count, 0u);
1768
1769 output0.emplace_back(std::move(*mapper0.Front()));
1770 mapper0.PopFront();
1771 output0.emplace_back(std::move(*mapper0.Front()));
1772 mapper0.PopFront();
1773 output0.emplace_back(std::move(*mapper0.Front()));
1774 mapper0.PopFront();
1775 output0.emplace_back(std::move(*mapper0.Front()));
1776 mapper0.PopFront();
1777
1778 EXPECT_EQ(mapper0_count, 4u);
1779 EXPECT_EQ(mapper1_count, 0u);
1780
1781 ASSERT_TRUE(mapper0.Front() == nullptr);
1782
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001783 EXPECT_EQ(output0[0].monotonic_event_time.boot, 0u);
1784 EXPECT_EQ(output0[0].monotonic_event_time.time,
1785 e + chrono::milliseconds(1000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001786 EXPECT_TRUE(output0[0].data != nullptr);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001787
1788 EXPECT_EQ(output0[1].monotonic_event_time.boot, 0u);
1789 EXPECT_EQ(output0[1].monotonic_event_time.time,
1790 e + chrono::milliseconds(1000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001791 EXPECT_TRUE(output0[1].data != nullptr);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001792
1793 EXPECT_EQ(output0[2].monotonic_event_time.boot, 0u);
1794 EXPECT_EQ(output0[2].monotonic_event_time.time,
1795 e + chrono::milliseconds(2000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001796 EXPECT_TRUE(output0[2].data != nullptr);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001797
1798 EXPECT_EQ(output0[3].monotonic_event_time.boot, 0u);
1799 EXPECT_EQ(output0[3].monotonic_event_time.time,
1800 e + chrono::milliseconds(3000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001801 EXPECT_TRUE(output0[3].data != nullptr);
Austin Schuh79b30942021-01-24 22:32:21 -08001802 }
1803
1804 {
1805 SCOPED_TRACE("Trying node1 now");
1806 std::deque<TimestampedMessage> output1;
1807
1808 EXPECT_EQ(mapper0_count, 4u);
1809 EXPECT_EQ(mapper1_count, 0u);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001810 mapper1.QueueUntil(BootTimestamp{
1811 .boot = 0,
1812 .time = e + chrono::seconds(100) + chrono::milliseconds(1000)});
Austin Schuh79b30942021-01-24 22:32:21 -08001813 EXPECT_EQ(mapper0_count, 4u);
1814 EXPECT_EQ(mapper1_count, 3u);
1815
1816 ASSERT_TRUE(mapper1.Front() != nullptr);
1817 EXPECT_EQ(mapper0_count, 4u);
1818 EXPECT_EQ(mapper1_count, 3u);
1819
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001820 mapper1.QueueUntil(BootTimestamp{
1821 .boot = 0,
1822 .time = e + chrono::seconds(100) + chrono::milliseconds(1500)});
Austin Schuh79b30942021-01-24 22:32:21 -08001823 EXPECT_EQ(mapper0_count, 4u);
1824 EXPECT_EQ(mapper1_count, 3u);
1825
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001826 mapper1.QueueUntil(BootTimestamp{
1827 .boot = 0,
1828 .time = e + chrono::seconds(100) + chrono::milliseconds(2500)});
Austin Schuh79b30942021-01-24 22:32:21 -08001829 EXPECT_EQ(mapper0_count, 4u);
1830 EXPECT_EQ(mapper1_count, 4u);
1831
1832 ASSERT_TRUE(mapper1.Front() != nullptr);
1833 EXPECT_EQ(mapper0_count, 4u);
1834 EXPECT_EQ(mapper1_count, 4u);
1835
1836 output1.emplace_back(std::move(*mapper1.Front()));
1837 mapper1.PopFront();
1838 ASSERT_TRUE(mapper1.Front() != nullptr);
1839 output1.emplace_back(std::move(*mapper1.Front()));
1840 mapper1.PopFront();
1841 ASSERT_TRUE(mapper1.Front() != nullptr);
1842 output1.emplace_back(std::move(*mapper1.Front()));
1843 mapper1.PopFront();
1844 ASSERT_TRUE(mapper1.Front() != nullptr);
1845 output1.emplace_back(std::move(*mapper1.Front()));
1846 mapper1.PopFront();
1847
1848 EXPECT_EQ(mapper0_count, 4u);
1849 EXPECT_EQ(mapper1_count, 4u);
1850
1851 ASSERT_TRUE(mapper1.Front() == nullptr);
1852
1853 EXPECT_EQ(mapper0_count, 4u);
1854 EXPECT_EQ(mapper1_count, 4u);
1855
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001856 EXPECT_EQ(output1[0].monotonic_event_time.boot, 0u);
1857 EXPECT_EQ(output1[0].monotonic_event_time.time,
Austin Schuh79b30942021-01-24 22:32:21 -08001858 e + chrono::seconds(100) + chrono::milliseconds(1000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001859 EXPECT_TRUE(output1[0].data != nullptr);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001860
1861 EXPECT_EQ(output1[1].monotonic_event_time.boot, 0u);
1862 EXPECT_EQ(output1[1].monotonic_event_time.time,
Austin Schuh79b30942021-01-24 22:32:21 -08001863 e + chrono::seconds(100) + chrono::milliseconds(1000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001864 EXPECT_TRUE(output1[1].data != nullptr);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001865
1866 EXPECT_EQ(output1[2].monotonic_event_time.boot, 0u);
1867 EXPECT_EQ(output1[2].monotonic_event_time.time,
Austin Schuh79b30942021-01-24 22:32:21 -08001868 e + chrono::seconds(100) + chrono::milliseconds(2000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001869 EXPECT_TRUE(output1[2].data != nullptr);
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07001870
1871 EXPECT_EQ(output1[3].monotonic_event_time.boot, 0u);
1872 EXPECT_EQ(output1[3].monotonic_event_time.time,
Austin Schuh79b30942021-01-24 22:32:21 -08001873 e + chrono::seconds(100) + chrono::milliseconds(3000));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07001874 EXPECT_TRUE(output1[3].data != nullptr);
Austin Schuh79b30942021-01-24 22:32:21 -08001875 }
Austin Schuhfecf1d82020-12-19 16:57:28 -08001876}
1877
Austin Schuhf16ef6a2021-06-30 21:48:17 -07001878class BootMergerTest : public SortingElementTest {
1879 public:
1880 BootMergerTest()
1881 : SortingElementTest(),
1882 boot0_(MakeHeader(config_, R"({
Austin Schuh8bee6882021-06-28 21:03:28 -07001883 /* 100ms */
1884 "max_out_of_order_duration": 100000000,
1885 "node": {
1886 "name": "pi2"
1887 },
1888 "logger_node": {
1889 "name": "pi1"
1890 },
1891 "monotonic_start_time": 1000000,
1892 "realtime_start_time": 1000000000000,
1893 "logger_monotonic_start_time": 1000000,
1894 "logger_realtime_start_time": 1000000000000,
1895 "log_event_uuid": "30ef1283-81d7-4004-8c36-1c162dbcb2b2",
1896 "parts_uuid": "1a9e5ca2-31b2-475b-8282-88f6d1ce5109",
1897 "parts_index": 0,
1898 "logger_instance_uuid": "1c3142ad-10a5-408d-a760-b63b73d3b904",
1899 "logger_node_boot_uuid": "a570df8b-5cc2-4dbe-89bd-286f9ddd02b7",
Austin Schuh48507722021-07-17 17:29:24 -07001900 "source_node_boot_uuid": "6ba4f28d-21a2-4d7f-83f4-ee365cf86464",
1901 "boot_uuids": [
1902 "a570df8b-5cc2-4dbe-89bd-286f9ddd02b7",
1903 "6ba4f28d-21a2-4d7f-83f4-ee365cf86464",
1904 ""
1905 ]
Austin Schuhf16ef6a2021-06-30 21:48:17 -07001906})")),
1907 boot1_(MakeHeader(config_, R"({
Austin Schuh8bee6882021-06-28 21:03:28 -07001908 /* 100ms */
1909 "max_out_of_order_duration": 100000000,
1910 "node": {
1911 "name": "pi2"
1912 },
1913 "logger_node": {
1914 "name": "pi1"
1915 },
1916 "monotonic_start_time": 1000000,
1917 "realtime_start_time": 1000000000000,
1918 "logger_monotonic_start_time": 1000000,
1919 "logger_realtime_start_time": 1000000000000,
1920 "log_event_uuid": "30ef1283-81d7-4004-8c36-1c162dbcb2b2",
1921 "parts_uuid": "2a05d725-5d5c-4c0b-af42-88de2f3c3876",
1922 "parts_index": 1,
1923 "logger_instance_uuid": "1c3142ad-10a5-408d-a760-b63b73d3b904",
1924 "logger_node_boot_uuid": "a570df8b-5cc2-4dbe-89bd-286f9ddd02b7",
Austin Schuh48507722021-07-17 17:29:24 -07001925 "source_node_boot_uuid": "b728d27a-9181-4eac-bfc1-5d09b80469d2",
1926 "boot_uuids": [
1927 "a570df8b-5cc2-4dbe-89bd-286f9ddd02b7",
1928 "b728d27a-9181-4eac-bfc1-5d09b80469d2",
1929 ""
1930 ]
Austin Schuhf16ef6a2021-06-30 21:48:17 -07001931})")) {}
Austin Schuh8bee6882021-06-28 21:03:28 -07001932
Austin Schuhf16ef6a2021-06-30 21:48:17 -07001933 protected:
1934 const aos::SizePrefixedFlatbufferDetachedBuffer<LogFileHeader> boot0_;
1935 const aos::SizePrefixedFlatbufferDetachedBuffer<LogFileHeader> boot1_;
1936};
1937
1938// This tests that we can properly sort a multi-node log file which has the old
1939// (and buggy) timestamps in the header, and the non-resetting parts_index.
1940// These make it so we can just bairly figure out what happened first and what
1941// happened second, but not in a way that is robust to multiple nodes rebooting.
1942TEST_F(BootMergerTest, OldReboot) {
Austin Schuh8bee6882021-06-28 21:03:28 -07001943 {
Austin Schuhd863e6e2022-10-16 15:44:50 -07001944 TestDetachedBufferWriter writer(logfile0_);
Austin Schuhf16ef6a2021-06-30 21:48:17 -07001945 writer.QueueSpan(boot0_.span());
Austin Schuh8bee6882021-06-28 21:03:28 -07001946 }
1947 {
Austin Schuhd863e6e2022-10-16 15:44:50 -07001948 TestDetachedBufferWriter writer(logfile1_);
Austin Schuhf16ef6a2021-06-30 21:48:17 -07001949 writer.QueueSpan(boot1_.span());
Austin Schuh8bee6882021-06-28 21:03:28 -07001950 }
1951
1952 const std::vector<LogFile> parts = SortParts({logfile0_, logfile1_});
1953
1954 ASSERT_EQ(parts.size(), 1u);
1955 ASSERT_EQ(parts[0].parts.size(), 2u);
1956
1957 EXPECT_EQ(parts[0].parts[0].boot_count, 0);
1958 EXPECT_EQ(parts[0].parts[0].source_boot_uuid,
Austin Schuhf16ef6a2021-06-30 21:48:17 -07001959 boot0_.message().source_node_boot_uuid()->string_view());
Austin Schuh8bee6882021-06-28 21:03:28 -07001960
1961 EXPECT_EQ(parts[0].parts[1].boot_count, 1);
1962 EXPECT_EQ(parts[0].parts[1].source_boot_uuid,
Austin Schuhf16ef6a2021-06-30 21:48:17 -07001963 boot1_.message().source_node_boot_uuid()->string_view());
1964}
1965
1966// This tests that we can produce messages ordered across a reboot.
1967TEST_F(BootMergerTest, SortAcrossReboot) {
1968 const aos::monotonic_clock::time_point e = monotonic_clock::epoch();
1969 {
Austin Schuhd863e6e2022-10-16 15:44:50 -07001970 TestDetachedBufferWriter writer(logfile0_);
Austin Schuhf16ef6a2021-06-30 21:48:17 -07001971 writer.QueueSpan(boot0_.span());
Austin Schuhd863e6e2022-10-16 15:44:50 -07001972 writer.WriteSizedFlatbuffer(
Austin Schuhf16ef6a2021-06-30 21:48:17 -07001973 MakeLogMessage(e + chrono::milliseconds(1000), 0, 0x005));
Austin Schuhd863e6e2022-10-16 15:44:50 -07001974 writer.WriteSizedFlatbuffer(
Austin Schuhf16ef6a2021-06-30 21:48:17 -07001975 MakeLogMessage(e + chrono::milliseconds(2000), 1, 0x105));
1976 }
1977 {
Austin Schuhd863e6e2022-10-16 15:44:50 -07001978 TestDetachedBufferWriter writer(logfile1_);
Austin Schuhf16ef6a2021-06-30 21:48:17 -07001979 writer.QueueSpan(boot1_.span());
Austin Schuhd863e6e2022-10-16 15:44:50 -07001980 writer.WriteSizedFlatbuffer(
Austin Schuhf16ef6a2021-06-30 21:48:17 -07001981 MakeLogMessage(e + chrono::milliseconds(100), 0, 0x006));
Austin Schuhd863e6e2022-10-16 15:44:50 -07001982 writer.WriteSizedFlatbuffer(
Austin Schuhf16ef6a2021-06-30 21:48:17 -07001983 MakeLogMessage(e + chrono::milliseconds(200), 1, 0x106));
1984 }
1985
1986 const std::vector<LogFile> parts = SortParts({logfile0_, logfile1_});
1987 ASSERT_EQ(parts.size(), 1u);
1988 ASSERT_EQ(parts[0].parts.size(), 2u);
1989
1990 BootMerger merger(FilterPartsForNode(parts, "pi2"));
1991
1992 EXPECT_EQ(merger.node(), 1u);
1993
1994 std::vector<Message> output;
1995 for (int i = 0; i < 4; ++i) {
1996 ASSERT_TRUE(merger.Front() != nullptr);
1997 output.emplace_back(std::move(*merger.Front()));
1998 merger.PopFront();
1999 }
2000
2001 ASSERT_TRUE(merger.Front() == nullptr);
2002
Austin Schuh2dc8c7d2021-07-01 17:41:28 -07002003 EXPECT_EQ(output[0].timestamp.boot, 0u);
2004 EXPECT_EQ(output[0].timestamp.time, e + chrono::milliseconds(1000));
2005 EXPECT_EQ(output[1].timestamp.boot, 0u);
2006 EXPECT_EQ(output[1].timestamp.time, e + chrono::milliseconds(2000));
2007
2008 EXPECT_EQ(output[2].timestamp.boot, 1u);
2009 EXPECT_EQ(output[2].timestamp.time, e + chrono::milliseconds(100));
2010 EXPECT_EQ(output[3].timestamp.boot, 1u);
2011 EXPECT_EQ(output[3].timestamp.time, e + chrono::milliseconds(200));
Austin Schuh8bee6882021-06-28 21:03:28 -07002012}
2013
Austin Schuh48507722021-07-17 17:29:24 -07002014class RebootTimestampMapperTest : public SortingElementTest {
2015 public:
2016 RebootTimestampMapperTest()
2017 : SortingElementTest(),
2018 boot0a_(MakeHeader(config_, R"({
2019 /* 100ms */
2020 "max_out_of_order_duration": 100000000,
2021 "node": {
2022 "name": "pi1"
2023 },
2024 "logger_node": {
2025 "name": "pi1"
2026 },
2027 "monotonic_start_time": 1000000,
2028 "realtime_start_time": 1000000000000,
2029 "logger_monotonic_start_time": 1000000,
2030 "logger_realtime_start_time": 1000000000000,
2031 "log_event_uuid": "30ef1283-81d7-4004-8c36-1c162dbcb2b2",
2032 "parts_uuid": "ee4f5a98-77d0-4e01-af2f-bbb29e098ede",
2033 "parts_index": 0,
2034 "logger_instance_uuid": "1c3142ad-10a5-408d-a760-b63b73d3b904",
2035 "logger_node_boot_uuid": "a570df8b-5cc2-4dbe-89bd-286f9ddd02b7",
2036 "source_node_boot_uuid": "a570df8b-5cc2-4dbe-89bd-286f9ddd02b7",
2037 "boot_uuids": [
2038 "a570df8b-5cc2-4dbe-89bd-286f9ddd02b7",
2039 "6ba4f28d-21a2-4d7f-83f4-ee365cf86464",
2040 ""
2041 ]
2042})")),
2043 boot0b_(MakeHeader(config_, R"({
2044 /* 100ms */
2045 "max_out_of_order_duration": 100000000,
2046 "node": {
2047 "name": "pi1"
2048 },
2049 "logger_node": {
2050 "name": "pi1"
2051 },
2052 "monotonic_start_time": 1000000,
2053 "realtime_start_time": 1000000000000,
2054 "logger_monotonic_start_time": 1000000,
2055 "logger_realtime_start_time": 1000000000000,
2056 "log_event_uuid": "30ef1283-81d7-4004-8c36-1c162dbcb2b2",
2057 "parts_uuid": "ee4f5a98-77d0-4e01-af2f-bbb29e098ede",
2058 "parts_index": 1,
2059 "logger_instance_uuid": "1c3142ad-10a5-408d-a760-b63b73d3b904",
2060 "logger_node_boot_uuid": "a570df8b-5cc2-4dbe-89bd-286f9ddd02b7",
2061 "source_node_boot_uuid": "a570df8b-5cc2-4dbe-89bd-286f9ddd02b7",
2062 "boot_uuids": [
2063 "a570df8b-5cc2-4dbe-89bd-286f9ddd02b7",
2064 "b728d27a-9181-4eac-bfc1-5d09b80469d2",
2065 ""
2066 ]
2067})")),
2068 boot1a_(MakeHeader(config_, R"({
2069 /* 100ms */
2070 "max_out_of_order_duration": 100000000,
2071 "node": {
2072 "name": "pi2"
2073 },
2074 "logger_node": {
2075 "name": "pi1"
2076 },
2077 "monotonic_start_time": 1000000,
2078 "realtime_start_time": 1000000000000,
2079 "logger_monotonic_start_time": 1000000,
2080 "logger_realtime_start_time": 1000000000000,
2081 "log_event_uuid": "30ef1283-81d7-4004-8c36-1c162dbcb2b2",
2082 "parts_uuid": "f6ab0cdc-a654-456d-bfd9-2bbc09098edf",
2083 "parts_index": 0,
2084 "logger_instance_uuid": "1c3142ad-10a5-408d-a760-b63b73d3b904",
2085 "logger_node_boot_uuid": "a570df8b-5cc2-4dbe-89bd-286f9ddd02b7",
2086 "source_node_boot_uuid": "6ba4f28d-21a2-4d7f-83f4-ee365cf86464",
2087 "boot_uuids": [
2088 "a570df8b-5cc2-4dbe-89bd-286f9ddd02b7",
2089 "6ba4f28d-21a2-4d7f-83f4-ee365cf86464",
2090 ""
2091 ]
2092})")),
2093 boot1b_(MakeHeader(config_, R"({
2094 /* 100ms */
2095 "max_out_of_order_duration": 100000000,
2096 "node": {
2097 "name": "pi2"
2098 },
2099 "logger_node": {
2100 "name": "pi1"
2101 },
2102 "monotonic_start_time": 1000000,
2103 "realtime_start_time": 1000000000000,
2104 "logger_monotonic_start_time": 1000000,
2105 "logger_realtime_start_time": 1000000000000,
2106 "log_event_uuid": "30ef1283-81d7-4004-8c36-1c162dbcb2b2",
2107 "parts_uuid": "3a9d0445-f520-43ca-93f5-e2cc7f54d40a",
2108 "parts_index": 1,
2109 "logger_instance_uuid": "1c3142ad-10a5-408d-a760-b63b73d3b904",
2110 "logger_node_boot_uuid": "a570df8b-5cc2-4dbe-89bd-286f9ddd02b7",
2111 "source_node_boot_uuid": "b728d27a-9181-4eac-bfc1-5d09b80469d2",
2112 "boot_uuids": [
2113 "a570df8b-5cc2-4dbe-89bd-286f9ddd02b7",
2114 "b728d27a-9181-4eac-bfc1-5d09b80469d2",
2115 ""
2116 ]
2117})")) {}
2118
2119 protected:
2120 const aos::SizePrefixedFlatbufferDetachedBuffer<LogFileHeader> boot0a_;
2121 const aos::SizePrefixedFlatbufferDetachedBuffer<LogFileHeader> boot0b_;
2122 const aos::SizePrefixedFlatbufferDetachedBuffer<LogFileHeader> boot1a_;
2123 const aos::SizePrefixedFlatbufferDetachedBuffer<LogFileHeader> boot1b_;
2124};
2125
Austin Schuh48507722021-07-17 17:29:24 -07002126// Tests that we can match timestamps on delivered messages in the presence of
2127// reboots on the node receiving timestamps.
2128TEST_F(RebootTimestampMapperTest, ReadNode0First) {
2129 const aos::monotonic_clock::time_point e = monotonic_clock::epoch();
2130 {
Austin Schuhd863e6e2022-10-16 15:44:50 -07002131 TestDetachedBufferWriter writer0a(logfile0_);
Austin Schuh48507722021-07-17 17:29:24 -07002132 writer0a.QueueSpan(boot0a_.span());
Austin Schuhd863e6e2022-10-16 15:44:50 -07002133 TestDetachedBufferWriter writer0b(logfile1_);
Austin Schuh48507722021-07-17 17:29:24 -07002134 writer0b.QueueSpan(boot0b_.span());
Austin Schuhd863e6e2022-10-16 15:44:50 -07002135 TestDetachedBufferWriter writer1a(logfile2_);
Austin Schuh48507722021-07-17 17:29:24 -07002136 writer1a.QueueSpan(boot1a_.span());
Austin Schuhd863e6e2022-10-16 15:44:50 -07002137 TestDetachedBufferWriter writer1b(logfile3_);
Austin Schuh48507722021-07-17 17:29:24 -07002138 writer1b.QueueSpan(boot1b_.span());
2139
Austin Schuhd863e6e2022-10-16 15:44:50 -07002140 writer0a.WriteSizedFlatbuffer(
Austin Schuh48507722021-07-17 17:29:24 -07002141 MakeLogMessage(e + chrono::milliseconds(1000), 0, 0x005));
Austin Schuhd863e6e2022-10-16 15:44:50 -07002142 writer1a.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuh48507722021-07-17 17:29:24 -07002143 e + chrono::milliseconds(1000), 0, chrono::seconds(100),
2144 e + chrono::milliseconds(1001)));
2145
Austin Schuhd863e6e2022-10-16 15:44:50 -07002146 writer1b.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuh58646e22021-08-23 23:51:46 -07002147 e + chrono::milliseconds(1000), 0, chrono::seconds(21),
2148 e + chrono::milliseconds(2001)));
2149
Austin Schuhd863e6e2022-10-16 15:44:50 -07002150 writer0b.WriteSizedFlatbuffer(
Austin Schuh48507722021-07-17 17:29:24 -07002151 MakeLogMessage(e + chrono::milliseconds(2000), 0, 0x006));
Austin Schuhd863e6e2022-10-16 15:44:50 -07002152 writer1b.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuh48507722021-07-17 17:29:24 -07002153 e + chrono::milliseconds(2000), 0, chrono::seconds(20),
2154 e + chrono::milliseconds(2001)));
2155
Austin Schuhd863e6e2022-10-16 15:44:50 -07002156 writer0b.WriteSizedFlatbuffer(
Austin Schuh48507722021-07-17 17:29:24 -07002157 MakeLogMessage(e + chrono::milliseconds(3000), 0, 0x007));
Austin Schuhd863e6e2022-10-16 15:44:50 -07002158 writer1b.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuh48507722021-07-17 17:29:24 -07002159 e + chrono::milliseconds(3000), 0, chrono::seconds(20),
2160 e + chrono::milliseconds(3001)));
2161 }
2162
Austin Schuh58646e22021-08-23 23:51:46 -07002163 const std::vector<LogFile> parts =
2164 SortParts({logfile0_, logfile1_, logfile2_, logfile3_});
Austin Schuh48507722021-07-17 17:29:24 -07002165
2166 for (const auto &x : parts) {
2167 LOG(INFO) << x;
2168 }
2169 ASSERT_EQ(parts.size(), 1u);
2170 ASSERT_EQ(parts[0].logger_node, "pi1");
2171
2172 size_t mapper0_count = 0;
2173 TimestampMapper mapper0(FilterPartsForNode(parts, "pi1"));
2174 mapper0.set_timestamp_callback(
2175 [&](TimestampedMessage *) { ++mapper0_count; });
2176 size_t mapper1_count = 0;
2177 TimestampMapper mapper1(FilterPartsForNode(parts, "pi2"));
2178 mapper1.set_timestamp_callback(
2179 [&](TimestampedMessage *) { ++mapper1_count; });
2180
2181 mapper0.AddPeer(&mapper1);
2182 mapper1.AddPeer(&mapper0);
2183
2184 {
2185 std::deque<TimestampedMessage> output0;
2186
2187 EXPECT_EQ(mapper0_count, 0u);
2188 EXPECT_EQ(mapper1_count, 0u);
2189 ASSERT_TRUE(mapper0.Front() != nullptr);
2190 EXPECT_EQ(mapper0_count, 1u);
2191 EXPECT_EQ(mapper1_count, 0u);
2192 output0.emplace_back(std::move(*mapper0.Front()));
2193 mapper0.PopFront();
2194 EXPECT_TRUE(mapper0.started());
2195 EXPECT_EQ(mapper0_count, 1u);
2196 EXPECT_EQ(mapper1_count, 0u);
2197
2198 ASSERT_TRUE(mapper0.Front() != nullptr);
2199 EXPECT_EQ(mapper0_count, 2u);
2200 EXPECT_EQ(mapper1_count, 0u);
2201 output0.emplace_back(std::move(*mapper0.Front()));
2202 mapper0.PopFront();
2203 EXPECT_TRUE(mapper0.started());
2204
2205 ASSERT_TRUE(mapper0.Front() != nullptr);
2206 output0.emplace_back(std::move(*mapper0.Front()));
2207 mapper0.PopFront();
2208 EXPECT_TRUE(mapper0.started());
2209
2210 EXPECT_EQ(mapper0_count, 3u);
2211 EXPECT_EQ(mapper1_count, 0u);
2212
2213 ASSERT_TRUE(mapper0.Front() == nullptr);
2214
2215 LOG(INFO) << output0[0];
2216 LOG(INFO) << output0[1];
2217 LOG(INFO) << output0[2];
2218
2219 EXPECT_EQ(output0[0].monotonic_event_time.boot, 0u);
2220 EXPECT_EQ(output0[0].monotonic_event_time.time,
2221 e + chrono::milliseconds(1000));
Austin Schuh58646e22021-08-23 23:51:46 -07002222 EXPECT_EQ(output0[0].queue_index,
2223 (BootQueueIndex{.boot = 0u, .index = 0u}));
Austin Schuh48507722021-07-17 17:29:24 -07002224 EXPECT_EQ(output0[0].monotonic_remote_time, BootTimestamp::min_time());
2225 EXPECT_EQ(output0[0].monotonic_timestamp_time, BootTimestamp::min_time());
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07002226 EXPECT_TRUE(output0[0].data != nullptr);
Austin Schuh48507722021-07-17 17:29:24 -07002227
2228 EXPECT_EQ(output0[1].monotonic_event_time.boot, 0u);
2229 EXPECT_EQ(output0[1].monotonic_event_time.time,
2230 e + chrono::milliseconds(2000));
Austin Schuh58646e22021-08-23 23:51:46 -07002231 EXPECT_EQ(output0[1].queue_index,
2232 (BootQueueIndex{.boot = 0u, .index = 1u}));
Austin Schuh48507722021-07-17 17:29:24 -07002233 EXPECT_EQ(output0[1].monotonic_remote_time, BootTimestamp::min_time());
2234 EXPECT_EQ(output0[1].monotonic_timestamp_time, BootTimestamp::min_time());
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07002235 EXPECT_TRUE(output0[1].data != nullptr);
Austin Schuh48507722021-07-17 17:29:24 -07002236
2237 EXPECT_EQ(output0[2].monotonic_event_time.boot, 0u);
2238 EXPECT_EQ(output0[2].monotonic_event_time.time,
2239 e + chrono::milliseconds(3000));
Austin Schuh58646e22021-08-23 23:51:46 -07002240 EXPECT_EQ(output0[2].queue_index,
2241 (BootQueueIndex{.boot = 0u, .index = 2u}));
Austin Schuh48507722021-07-17 17:29:24 -07002242 EXPECT_EQ(output0[2].monotonic_remote_time, BootTimestamp::min_time());
2243 EXPECT_EQ(output0[2].monotonic_timestamp_time, BootTimestamp::min_time());
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07002244 EXPECT_TRUE(output0[2].data != nullptr);
Austin Schuh48507722021-07-17 17:29:24 -07002245 }
2246
2247 {
2248 SCOPED_TRACE("Trying node1 now");
2249 std::deque<TimestampedMessage> output1;
2250
2251 EXPECT_EQ(mapper0_count, 3u);
2252 EXPECT_EQ(mapper1_count, 0u);
2253
2254 ASSERT_TRUE(mapper1.Front() != nullptr);
2255 EXPECT_EQ(mapper0_count, 3u);
2256 EXPECT_EQ(mapper1_count, 1u);
2257 output1.emplace_back(std::move(*mapper1.Front()));
2258 mapper1.PopFront();
2259 EXPECT_TRUE(mapper1.started());
2260 EXPECT_EQ(mapper0_count, 3u);
2261 EXPECT_EQ(mapper1_count, 1u);
2262
2263 ASSERT_TRUE(mapper1.Front() != nullptr);
2264 EXPECT_EQ(mapper0_count, 3u);
2265 EXPECT_EQ(mapper1_count, 2u);
2266 output1.emplace_back(std::move(*mapper1.Front()));
2267 mapper1.PopFront();
2268 EXPECT_TRUE(mapper1.started());
2269
2270 ASSERT_TRUE(mapper1.Front() != nullptr);
2271 output1.emplace_back(std::move(*mapper1.Front()));
2272 mapper1.PopFront();
2273 EXPECT_TRUE(mapper1.started());
2274
Austin Schuh58646e22021-08-23 23:51:46 -07002275 ASSERT_TRUE(mapper1.Front() != nullptr);
2276 output1.emplace_back(std::move(*mapper1.Front()));
2277 mapper1.PopFront();
2278 EXPECT_TRUE(mapper1.started());
2279
Austin Schuh48507722021-07-17 17:29:24 -07002280 EXPECT_EQ(mapper0_count, 3u);
Austin Schuh58646e22021-08-23 23:51:46 -07002281 EXPECT_EQ(mapper1_count, 4u);
Austin Schuh48507722021-07-17 17:29:24 -07002282
2283 ASSERT_TRUE(mapper1.Front() == nullptr);
2284
2285 EXPECT_EQ(mapper0_count, 3u);
Austin Schuh58646e22021-08-23 23:51:46 -07002286 EXPECT_EQ(mapper1_count, 4u);
Austin Schuh48507722021-07-17 17:29:24 -07002287
2288 EXPECT_EQ(output1[0].monotonic_event_time.boot, 0u);
2289 EXPECT_EQ(output1[0].monotonic_event_time.time,
2290 e + chrono::seconds(100) + chrono::milliseconds(1000));
2291 EXPECT_EQ(output1[0].monotonic_remote_time.boot, 0u);
2292 EXPECT_EQ(output1[0].monotonic_remote_time.time,
2293 e + chrono::milliseconds(1000));
Austin Schuh58646e22021-08-23 23:51:46 -07002294 EXPECT_EQ(output1[0].remote_queue_index,
2295 (BootQueueIndex{.boot = 0u, .index = 0u}));
Austin Schuh48507722021-07-17 17:29:24 -07002296 EXPECT_EQ(output1[0].monotonic_timestamp_time.boot, 0u);
2297 EXPECT_EQ(output1[0].monotonic_timestamp_time.time,
2298 e + chrono::milliseconds(1001));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07002299 EXPECT_TRUE(output1[0].data != nullptr);
Austin Schuh48507722021-07-17 17:29:24 -07002300
2301 EXPECT_EQ(output1[1].monotonic_event_time.boot, 1u);
2302 EXPECT_EQ(output1[1].monotonic_event_time.time,
2303 e + chrono::seconds(20) + chrono::milliseconds(2000));
Austin Schuh58646e22021-08-23 23:51:46 -07002304 EXPECT_EQ(output1[1].remote_queue_index,
2305 (BootQueueIndex{.boot = 0u, .index = 0u}));
Austin Schuh48507722021-07-17 17:29:24 -07002306 EXPECT_EQ(output1[1].monotonic_remote_time.boot, 0u);
2307 EXPECT_EQ(output1[1].monotonic_remote_time.time,
Austin Schuh58646e22021-08-23 23:51:46 -07002308 e + chrono::milliseconds(1000));
Austin Schuh48507722021-07-17 17:29:24 -07002309 EXPECT_EQ(output1[1].monotonic_timestamp_time.boot, 0u);
2310 EXPECT_EQ(output1[1].monotonic_timestamp_time.time,
2311 e + chrono::milliseconds(2001));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07002312 EXPECT_TRUE(output1[1].data != nullptr);
Austin Schuh48507722021-07-17 17:29:24 -07002313
2314 EXPECT_EQ(output1[2].monotonic_event_time.boot, 1u);
2315 EXPECT_EQ(output1[2].monotonic_event_time.time,
Austin Schuh58646e22021-08-23 23:51:46 -07002316 e + chrono::seconds(20) + chrono::milliseconds(2000));
Austin Schuh48507722021-07-17 17:29:24 -07002317 EXPECT_EQ(output1[2].monotonic_remote_time.boot, 0u);
2318 EXPECT_EQ(output1[2].monotonic_remote_time.time,
Austin Schuh58646e22021-08-23 23:51:46 -07002319 e + chrono::milliseconds(2000));
2320 EXPECT_EQ(output1[2].remote_queue_index,
2321 (BootQueueIndex{.boot = 0u, .index = 1u}));
Austin Schuh48507722021-07-17 17:29:24 -07002322 EXPECT_EQ(output1[2].monotonic_timestamp_time.boot, 0u);
2323 EXPECT_EQ(output1[2].monotonic_timestamp_time.time,
Austin Schuh58646e22021-08-23 23:51:46 -07002324 e + chrono::milliseconds(2001));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07002325 EXPECT_TRUE(output1[2].data != nullptr);
Austin Schuh48507722021-07-17 17:29:24 -07002326
Austin Schuh58646e22021-08-23 23:51:46 -07002327 EXPECT_EQ(output1[3].monotonic_event_time.boot, 1u);
2328 EXPECT_EQ(output1[3].monotonic_event_time.time,
2329 e + chrono::seconds(20) + chrono::milliseconds(3000));
2330 EXPECT_EQ(output1[3].monotonic_remote_time.boot, 0u);
2331 EXPECT_EQ(output1[3].monotonic_remote_time.time,
2332 e + chrono::milliseconds(3000));
2333 EXPECT_EQ(output1[3].remote_queue_index,
2334 (BootQueueIndex{.boot = 0u, .index = 2u}));
2335 EXPECT_EQ(output1[3].monotonic_timestamp_time.boot, 0u);
2336 EXPECT_EQ(output1[3].monotonic_timestamp_time.time,
2337 e + chrono::milliseconds(3001));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07002338 EXPECT_TRUE(output1[3].data != nullptr);
Austin Schuh58646e22021-08-23 23:51:46 -07002339
Austin Schuh48507722021-07-17 17:29:24 -07002340 LOG(INFO) << output1[0];
2341 LOG(INFO) << output1[1];
2342 LOG(INFO) << output1[2];
Austin Schuh58646e22021-08-23 23:51:46 -07002343 LOG(INFO) << output1[3];
Austin Schuh48507722021-07-17 17:29:24 -07002344 }
2345}
2346
2347TEST_F(RebootTimestampMapperTest, Node2Reboot) {
2348 const aos::monotonic_clock::time_point e = monotonic_clock::epoch();
2349 {
Austin Schuhd863e6e2022-10-16 15:44:50 -07002350 TestDetachedBufferWriter writer0a(logfile0_);
Austin Schuh48507722021-07-17 17:29:24 -07002351 writer0a.QueueSpan(boot0a_.span());
Austin Schuhd863e6e2022-10-16 15:44:50 -07002352 TestDetachedBufferWriter writer0b(logfile1_);
Austin Schuh48507722021-07-17 17:29:24 -07002353 writer0b.QueueSpan(boot0b_.span());
Austin Schuhd863e6e2022-10-16 15:44:50 -07002354 TestDetachedBufferWriter writer1a(logfile2_);
Austin Schuh48507722021-07-17 17:29:24 -07002355 writer1a.QueueSpan(boot1a_.span());
Austin Schuhd863e6e2022-10-16 15:44:50 -07002356 TestDetachedBufferWriter writer1b(logfile3_);
Austin Schuh48507722021-07-17 17:29:24 -07002357 writer1b.QueueSpan(boot1b_.span());
2358
Austin Schuhd863e6e2022-10-16 15:44:50 -07002359 writer1a.WriteSizedFlatbuffer(MakeLogMessage(
Austin Schuh48507722021-07-17 17:29:24 -07002360 e + chrono::seconds(100) + chrono::milliseconds(1000), 3, 0x005));
Austin Schuhd863e6e2022-10-16 15:44:50 -07002361 writer0a.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuh48507722021-07-17 17:29:24 -07002362 e + chrono::seconds(100) + chrono::milliseconds(1000), 3,
2363 chrono::seconds(-100),
2364 e + chrono::seconds(100) + chrono::milliseconds(1001)));
2365
Austin Schuhd863e6e2022-10-16 15:44:50 -07002366 writer1b.WriteSizedFlatbuffer(MakeLogMessage(
Austin Schuh48507722021-07-17 17:29:24 -07002367 e + chrono::seconds(20) + chrono::milliseconds(2000), 3, 0x006));
Austin Schuhd863e6e2022-10-16 15:44:50 -07002368 writer0b.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuh48507722021-07-17 17:29:24 -07002369 e + chrono::seconds(20) + chrono::milliseconds(2000), 3,
2370 chrono::seconds(-20),
2371 e + chrono::seconds(20) + chrono::milliseconds(2001)));
2372
Austin Schuhd863e6e2022-10-16 15:44:50 -07002373 writer1b.WriteSizedFlatbuffer(MakeLogMessage(
Austin Schuh48507722021-07-17 17:29:24 -07002374 e + chrono::seconds(20) + chrono::milliseconds(3000), 3, 0x007));
Austin Schuhd863e6e2022-10-16 15:44:50 -07002375 writer0b.WriteSizedFlatbuffer(MakeTimestampMessage(
Austin Schuh48507722021-07-17 17:29:24 -07002376 e + chrono::seconds(20) + chrono::milliseconds(3000), 3,
2377 chrono::seconds(-20),
2378 e + chrono::seconds(20) + chrono::milliseconds(3001)));
2379 }
2380
2381 const std::vector<LogFile> parts =
2382 SortParts({logfile0_, logfile1_, logfile2_, logfile3_});
2383
2384 for (const auto &x : parts) {
2385 LOG(INFO) << x;
2386 }
2387 ASSERT_EQ(parts.size(), 1u);
2388 ASSERT_EQ(parts[0].logger_node, "pi1");
2389
2390 size_t mapper0_count = 0;
2391 TimestampMapper mapper0(FilterPartsForNode(parts, "pi1"));
2392 mapper0.set_timestamp_callback(
2393 [&](TimestampedMessage *) { ++mapper0_count; });
2394 size_t mapper1_count = 0;
2395 TimestampMapper mapper1(FilterPartsForNode(parts, "pi2"));
2396 mapper1.set_timestamp_callback(
2397 [&](TimestampedMessage *) { ++mapper1_count; });
2398
2399 mapper0.AddPeer(&mapper1);
2400 mapper1.AddPeer(&mapper0);
2401
2402 {
2403 std::deque<TimestampedMessage> output0;
2404
2405 EXPECT_EQ(mapper0_count, 0u);
2406 EXPECT_EQ(mapper1_count, 0u);
2407 ASSERT_TRUE(mapper0.Front() != nullptr);
2408 EXPECT_EQ(mapper0_count, 1u);
2409 EXPECT_EQ(mapper1_count, 0u);
2410 output0.emplace_back(std::move(*mapper0.Front()));
2411 mapper0.PopFront();
2412 EXPECT_TRUE(mapper0.started());
2413 EXPECT_EQ(mapper0_count, 1u);
2414 EXPECT_EQ(mapper1_count, 0u);
2415
2416 ASSERT_TRUE(mapper0.Front() != nullptr);
2417 EXPECT_EQ(mapper0_count, 2u);
2418 EXPECT_EQ(mapper1_count, 0u);
2419 output0.emplace_back(std::move(*mapper0.Front()));
2420 mapper0.PopFront();
2421 EXPECT_TRUE(mapper0.started());
2422
2423 ASSERT_TRUE(mapper0.Front() != nullptr);
2424 output0.emplace_back(std::move(*mapper0.Front()));
2425 mapper0.PopFront();
2426 EXPECT_TRUE(mapper0.started());
2427
2428 EXPECT_EQ(mapper0_count, 3u);
2429 EXPECT_EQ(mapper1_count, 0u);
2430
2431 ASSERT_TRUE(mapper0.Front() == nullptr);
2432
2433 LOG(INFO) << output0[0];
2434 LOG(INFO) << output0[1];
2435 LOG(INFO) << output0[2];
2436
2437 EXPECT_EQ(output0[0].monotonic_event_time.boot, 0u);
2438 EXPECT_EQ(output0[0].monotonic_event_time.time,
2439 e + chrono::milliseconds(1000));
2440 EXPECT_EQ(output0[0].monotonic_remote_time.boot, 0u);
2441 EXPECT_EQ(output0[0].monotonic_remote_time.time,
2442 e + chrono::seconds(100) + chrono::milliseconds(1000));
2443 EXPECT_EQ(output0[0].monotonic_timestamp_time.boot, 0u);
2444 EXPECT_EQ(output0[0].monotonic_timestamp_time.time,
2445 e + chrono::seconds(100) + chrono::milliseconds(1001));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07002446 EXPECT_TRUE(output0[0].data != nullptr);
Austin Schuh48507722021-07-17 17:29:24 -07002447
2448 EXPECT_EQ(output0[1].monotonic_event_time.boot, 0u);
2449 EXPECT_EQ(output0[1].monotonic_event_time.time,
2450 e + chrono::milliseconds(2000));
2451 EXPECT_EQ(output0[1].monotonic_remote_time.boot, 1u);
2452 EXPECT_EQ(output0[1].monotonic_remote_time.time,
2453 e + chrono::seconds(20) + chrono::milliseconds(2000));
2454 EXPECT_EQ(output0[1].monotonic_timestamp_time.boot, 0u);
2455 EXPECT_EQ(output0[1].monotonic_timestamp_time.time,
2456 e + chrono::seconds(20) + chrono::milliseconds(2001));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07002457 EXPECT_TRUE(output0[1].data != nullptr);
Austin Schuh48507722021-07-17 17:29:24 -07002458
2459 EXPECT_EQ(output0[2].monotonic_event_time.boot, 0u);
2460 EXPECT_EQ(output0[2].monotonic_event_time.time,
2461 e + chrono::milliseconds(3000));
2462 EXPECT_EQ(output0[2].monotonic_remote_time.boot, 1u);
2463 EXPECT_EQ(output0[2].monotonic_remote_time.time,
2464 e + chrono::seconds(20) + chrono::milliseconds(3000));
2465 EXPECT_EQ(output0[2].monotonic_timestamp_time.boot, 0u);
2466 EXPECT_EQ(output0[2].monotonic_timestamp_time.time,
2467 e + chrono::seconds(20) + chrono::milliseconds(3001));
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07002468 EXPECT_TRUE(output0[2].data != nullptr);
Austin Schuh48507722021-07-17 17:29:24 -07002469 }
2470
2471 {
2472 SCOPED_TRACE("Trying node1 now");
2473 std::deque<TimestampedMessage> output1;
2474
2475 EXPECT_EQ(mapper0_count, 3u);
2476 EXPECT_EQ(mapper1_count, 0u);
2477
2478 ASSERT_TRUE(mapper1.Front() != nullptr);
2479 EXPECT_EQ(mapper0_count, 3u);
2480 EXPECT_EQ(mapper1_count, 1u);
2481 output1.emplace_back(std::move(*mapper1.Front()));
2482 mapper1.PopFront();
2483 EXPECT_TRUE(mapper1.started());
2484 EXPECT_EQ(mapper0_count, 3u);
2485 EXPECT_EQ(mapper1_count, 1u);
2486
2487 ASSERT_TRUE(mapper1.Front() != nullptr);
2488 EXPECT_EQ(mapper0_count, 3u);
2489 EXPECT_EQ(mapper1_count, 2u);
2490 output1.emplace_back(std::move(*mapper1.Front()));
2491 mapper1.PopFront();
2492 EXPECT_TRUE(mapper1.started());
2493
2494 ASSERT_TRUE(mapper1.Front() != nullptr);
2495 output1.emplace_back(std::move(*mapper1.Front()));
2496 mapper1.PopFront();
2497 EXPECT_TRUE(mapper1.started());
2498
2499 EXPECT_EQ(mapper0_count, 3u);
2500 EXPECT_EQ(mapper1_count, 3u);
2501
2502 ASSERT_TRUE(mapper1.Front() == nullptr);
2503
2504 EXPECT_EQ(mapper0_count, 3u);
2505 EXPECT_EQ(mapper1_count, 3u);
2506
2507 EXPECT_EQ(output1[0].monotonic_event_time.boot, 0u);
2508 EXPECT_EQ(output1[0].monotonic_event_time.time,
2509 e + chrono::seconds(100) + chrono::milliseconds(1000));
2510 EXPECT_EQ(output1[0].monotonic_remote_time, BootTimestamp::min_time());
2511 EXPECT_EQ(output1[0].monotonic_timestamp_time, BootTimestamp::min_time());
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07002512 EXPECT_TRUE(output1[0].data != nullptr);
Austin Schuh48507722021-07-17 17:29:24 -07002513
2514 EXPECT_EQ(output1[1].monotonic_event_time.boot, 1u);
2515 EXPECT_EQ(output1[1].monotonic_event_time.time,
2516 e + chrono::seconds(20) + chrono::milliseconds(2000));
2517 EXPECT_EQ(output1[1].monotonic_remote_time, BootTimestamp::min_time());
2518 EXPECT_EQ(output1[1].monotonic_timestamp_time, BootTimestamp::min_time());
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07002519 EXPECT_TRUE(output1[1].data != nullptr);
Austin Schuh48507722021-07-17 17:29:24 -07002520
2521 EXPECT_EQ(output1[2].monotonic_event_time.boot, 1u);
2522 EXPECT_EQ(output1[2].monotonic_event_time.time,
2523 e + chrono::seconds(20) + chrono::milliseconds(3000));
2524 EXPECT_EQ(output1[2].monotonic_remote_time, BootTimestamp::min_time());
2525 EXPECT_EQ(output1[2].monotonic_timestamp_time, BootTimestamp::min_time());
Tyler Chatowb7c6eba2021-07-28 14:43:23 -07002526 EXPECT_TRUE(output1[2].data != nullptr);
Austin Schuh48507722021-07-17 17:29:24 -07002527
2528 LOG(INFO) << output1[0];
2529 LOG(INFO) << output1[1];
2530 LOG(INFO) << output1[2];
2531 }
2532}
2533
Austin Schuh44c61472021-11-22 21:04:10 -08002534class SortingDeathTest : public SortingElementTest {
2535 public:
2536 SortingDeathTest()
2537 : SortingElementTest(),
2538 part0_(MakeHeader(config_, R"({
2539 /* 100ms */
2540 "max_out_of_order_duration": 100000000,
2541 "node": {
2542 "name": "pi1"
2543 },
2544 "logger_node": {
2545 "name": "pi1"
2546 },
2547 "monotonic_start_time": 1000000,
2548 "realtime_start_time": 1000000000000,
2549 "logger_monotonic_start_time": 1000000,
2550 "logger_realtime_start_time": 1000000000000,
2551 "log_event_uuid": "30ef1283-81d7-4004-8c36-1c162dbcb2b2",
2552 "parts_uuid": "ee4f5a98-77d0-4e01-af2f-bbb29e098ede",
2553 "parts_index": 0,
2554 "logger_instance_uuid": "1c3142ad-10a5-408d-a760-b63b73d3b904",
2555 "logger_node_boot_uuid": "a570df8b-5cc2-4dbe-89bd-286f9ddd02b7",
2556 "source_node_boot_uuid": "a570df8b-5cc2-4dbe-89bd-286f9ddd02b7",
2557 "boot_uuids": [
2558 "a570df8b-5cc2-4dbe-89bd-286f9ddd02b7",
2559 "6ba4f28d-21a2-4d7f-83f4-ee365cf86464",
2560 ""
2561 ],
2562 "oldest_remote_monotonic_timestamps": [
2563 9223372036854775807,
2564 9223372036854775807,
2565 9223372036854775807
2566 ],
2567 "oldest_local_monotonic_timestamps": [
2568 9223372036854775807,
2569 9223372036854775807,
2570 9223372036854775807
2571 ],
2572 "oldest_remote_unreliable_monotonic_timestamps": [
2573 9223372036854775807,
2574 0,
2575 9223372036854775807
2576 ],
2577 "oldest_local_unreliable_monotonic_timestamps": [
2578 9223372036854775807,
2579 0,
2580 9223372036854775807
2581 ]
2582})")),
2583 part1_(MakeHeader(config_, R"({
2584 /* 100ms */
2585 "max_out_of_order_duration": 100000000,
2586 "node": {
2587 "name": "pi1"
2588 },
2589 "logger_node": {
2590 "name": "pi1"
2591 },
2592 "monotonic_start_time": 1000000,
2593 "realtime_start_time": 1000000000000,
2594 "logger_monotonic_start_time": 1000000,
2595 "logger_realtime_start_time": 1000000000000,
2596 "log_event_uuid": "30ef1283-81d7-4004-8c36-1c162dbcb2b2",
2597 "parts_uuid": "ee4f5a98-77d0-4e01-af2f-bbb29e098ede",
2598 "parts_index": 1,
2599 "logger_instance_uuid": "1c3142ad-10a5-408d-a760-b63b73d3b904",
2600 "logger_node_boot_uuid": "a570df8b-5cc2-4dbe-89bd-286f9ddd02b7",
2601 "source_node_boot_uuid": "a570df8b-5cc2-4dbe-89bd-286f9ddd02b7",
2602 "boot_uuids": [
2603 "a570df8b-5cc2-4dbe-89bd-286f9ddd02b7",
2604 "b728d27a-9181-4eac-bfc1-5d09b80469d2",
2605 ""
2606 ],
2607 "oldest_remote_monotonic_timestamps": [
2608 9223372036854775807,
2609 9223372036854775807,
2610 9223372036854775807
2611 ],
2612 "oldest_local_monotonic_timestamps": [
2613 9223372036854775807,
2614 9223372036854775807,
2615 9223372036854775807
2616 ],
2617 "oldest_remote_unreliable_monotonic_timestamps": [
2618 9223372036854775807,
2619 100000,
2620 9223372036854775807
2621 ],
2622 "oldest_local_unreliable_monotonic_timestamps": [
2623 9223372036854775807,
2624 100000,
2625 9223372036854775807
2626 ]
2627})")),
2628 part2_(MakeHeader(config_, R"({
2629 /* 100ms */
2630 "max_out_of_order_duration": 100000000,
2631 "node": {
2632 "name": "pi1"
2633 },
2634 "logger_node": {
2635 "name": "pi1"
2636 },
2637 "monotonic_start_time": 1000000,
2638 "realtime_start_time": 1000000000000,
2639 "logger_monotonic_start_time": 1000000,
2640 "logger_realtime_start_time": 1000000000000,
2641 "log_event_uuid": "30ef1283-81d7-4004-8c36-1c162dbcb2b2",
2642 "parts_uuid": "ee4f5a98-77d0-4e01-af2f-bbb29e098ede",
2643 "parts_index": 2,
2644 "logger_instance_uuid": "1c3142ad-10a5-408d-a760-b63b73d3b904",
2645 "logger_node_boot_uuid": "a570df8b-5cc2-4dbe-89bd-286f9ddd02b7",
2646 "source_node_boot_uuid": "a570df8b-5cc2-4dbe-89bd-286f9ddd02b7",
2647 "boot_uuids": [
2648 "a570df8b-5cc2-4dbe-89bd-286f9ddd02b7",
2649 "6ba4f28d-21a2-4d7f-83f4-ee365cf86464",
2650 ""
2651 ],
2652 "oldest_remote_monotonic_timestamps": [
2653 9223372036854775807,
2654 9223372036854775807,
2655 9223372036854775807
2656 ],
2657 "oldest_local_monotonic_timestamps": [
2658 9223372036854775807,
2659 9223372036854775807,
2660 9223372036854775807
2661 ],
2662 "oldest_remote_unreliable_monotonic_timestamps": [
2663 9223372036854775807,
2664 200000,
2665 9223372036854775807
2666 ],
2667 "oldest_local_unreliable_monotonic_timestamps": [
2668 9223372036854775807,
2669 200000,
2670 9223372036854775807
2671 ]
2672})")),
2673 part3_(MakeHeader(config_, R"({
2674 /* 100ms */
2675 "max_out_of_order_duration": 100000000,
2676 "node": {
2677 "name": "pi1"
2678 },
2679 "logger_node": {
2680 "name": "pi1"
2681 },
2682 "monotonic_start_time": 1000000,
2683 "realtime_start_time": 1000000000000,
2684 "logger_monotonic_start_time": 1000000,
2685 "logger_realtime_start_time": 1000000000000,
2686 "log_event_uuid": "30ef1283-81d7-4004-8c36-1c162dbcb2b2",
2687 "parts_uuid": "ee4f5a98-77d0-4e01-af2f-bbb29e098ede",
2688 "parts_index": 3,
2689 "logger_instance_uuid": "1c3142ad-10a5-408d-a760-b63b73d3b904",
2690 "logger_node_boot_uuid": "a570df8b-5cc2-4dbe-89bd-286f9ddd02b7",
2691 "source_node_boot_uuid": "a570df8b-5cc2-4dbe-89bd-286f9ddd02b7",
2692 "boot_uuids": [
2693 "a570df8b-5cc2-4dbe-89bd-286f9ddd02b7",
2694 "b728d27a-9181-4eac-bfc1-5d09b80469d2",
2695 ""
2696 ],
2697 "oldest_remote_monotonic_timestamps": [
2698 9223372036854775807,
2699 9223372036854775807,
2700 9223372036854775807
2701 ],
2702 "oldest_local_monotonic_timestamps": [
2703 9223372036854775807,
2704 9223372036854775807,
2705 9223372036854775807
2706 ],
2707 "oldest_remote_unreliable_monotonic_timestamps": [
2708 9223372036854775807,
2709 300000,
2710 9223372036854775807
2711 ],
2712 "oldest_local_unreliable_monotonic_timestamps": [
2713 9223372036854775807,
2714 300000,
2715 9223372036854775807
2716 ]
2717})")) {}
2718
2719 protected:
2720 const aos::SizePrefixedFlatbufferDetachedBuffer<LogFileHeader> part0_;
2721 const aos::SizePrefixedFlatbufferDetachedBuffer<LogFileHeader> part1_;
2722 const aos::SizePrefixedFlatbufferDetachedBuffer<LogFileHeader> part2_;
2723 const aos::SizePrefixedFlatbufferDetachedBuffer<LogFileHeader> part3_;
2724};
2725
2726// Tests that if 2 computers go back and forth trying to be the same node, we
2727// die in sorting instead of failing to estimate time.
2728TEST_F(SortingDeathTest, FightingNodes) {
2729 {
Austin Schuhd863e6e2022-10-16 15:44:50 -07002730 TestDetachedBufferWriter writer0(logfile0_);
Austin Schuh44c61472021-11-22 21:04:10 -08002731 writer0.QueueSpan(part0_.span());
Austin Schuhd863e6e2022-10-16 15:44:50 -07002732 TestDetachedBufferWriter writer1(logfile1_);
Austin Schuh44c61472021-11-22 21:04:10 -08002733 writer1.QueueSpan(part1_.span());
Austin Schuhd863e6e2022-10-16 15:44:50 -07002734 TestDetachedBufferWriter writer2(logfile2_);
Austin Schuh44c61472021-11-22 21:04:10 -08002735 writer2.QueueSpan(part2_.span());
Austin Schuhd863e6e2022-10-16 15:44:50 -07002736 TestDetachedBufferWriter writer3(logfile3_);
Austin Schuh44c61472021-11-22 21:04:10 -08002737 writer3.QueueSpan(part3_.span());
2738 }
2739
2740 EXPECT_DEATH(
2741 {
2742 const std::vector<LogFile> parts =
2743 SortParts({logfile0_, logfile1_, logfile2_, logfile3_});
2744 },
Austin Schuh22cf7862022-09-19 19:09:42 -07002745 "found overlapping boots on");
Austin Schuh44c61472021-11-22 21:04:10 -08002746}
2747
Brian Smarttea913d42021-12-10 15:02:38 -08002748// Tests that we MessageReader blows up on a bad message.
2749TEST(MessageReaderConfirmCrash, ReadWrite) {
2750 const std::string logfile = aos::testing::TestTmpDir() + "/log.bfbs";
2751 unlink(logfile.c_str());
2752
2753 const aos::SizePrefixedFlatbufferDetachedBuffer<LogFileHeader> config =
2754 JsonToSizedFlatbuffer<LogFileHeader>(
2755 R"({ "max_out_of_order_duration": 100000000 })");
2756 const aos::SizePrefixedFlatbufferDetachedBuffer<MessageHeader> m1 =
2757 JsonToSizedFlatbuffer<MessageHeader>(
2758 R"({ "channel_index": 0, "monotonic_sent_time": 1 })");
2759 const aos::SizePrefixedFlatbufferDetachedBuffer<MessageHeader> m2 =
2760 JsonToSizedFlatbuffer<MessageHeader>(
2761 R"({ "channel_index": 0, "monotonic_sent_time": 2 })");
2762 const aos::SizePrefixedFlatbufferDetachedBuffer<MessageHeader> m4 =
2763 JsonToSizedFlatbuffer<MessageHeader>(
2764 R"({ "channel_index": 0, "monotonic_sent_time": 4 })");
2765
2766 // Starts out like a proper flat buffer header, but it breaks down ...
2767 std::vector<uint8_t> garbage{8, 0, 0, 0, 16, 0, 0, 0, 4, 0, 0, 0};
2768 absl::Span<uint8_t> m3_span(garbage);
2769
2770 {
Austin Schuhd863e6e2022-10-16 15:44:50 -07002771 TestDetachedBufferWriter writer(logfile);
Brian Smarttea913d42021-12-10 15:02:38 -08002772 writer.QueueSpan(config.span());
2773 writer.QueueSpan(m1.span());
2774 writer.QueueSpan(m2.span());
2775 writer.QueueSpan(m3_span);
2776 writer.QueueSpan(m4.span()); // This message is "hidden"
2777 }
2778
2779 {
2780 MessageReader reader(logfile);
2781
2782 EXPECT_EQ(reader.filename(), logfile);
2783
2784 EXPECT_EQ(
2785 reader.max_out_of_order_duration(),
2786 std::chrono::nanoseconds(config.message().max_out_of_order_duration()));
2787 EXPECT_EQ(reader.newest_timestamp(), monotonic_clock::min_time);
2788 EXPECT_TRUE(reader.ReadMessage());
2789 EXPECT_EQ(reader.newest_timestamp(),
2790 monotonic_clock::time_point(chrono::nanoseconds(1)));
2791 EXPECT_TRUE(reader.ReadMessage());
2792 EXPECT_EQ(reader.newest_timestamp(),
2793 monotonic_clock::time_point(chrono::nanoseconds(2)));
2794 // Confirm default crashing behavior
2795 EXPECT_DEATH(reader.ReadMessage(), "Corrupted message at offset");
2796 }
2797
2798 {
2799 gflags::FlagSaver fs;
2800
2801 MessageReader reader(logfile);
2802 reader.set_crash_on_corrupt_message_flag(false);
2803
2804 EXPECT_EQ(reader.filename(), logfile);
2805
2806 EXPECT_EQ(
2807 reader.max_out_of_order_duration(),
2808 std::chrono::nanoseconds(config.message().max_out_of_order_duration()));
2809 EXPECT_EQ(reader.newest_timestamp(), monotonic_clock::min_time);
2810 EXPECT_TRUE(reader.ReadMessage());
2811 EXPECT_EQ(reader.newest_timestamp(),
2812 monotonic_clock::time_point(chrono::nanoseconds(1)));
2813 EXPECT_TRUE(reader.ReadMessage());
2814 EXPECT_EQ(reader.newest_timestamp(),
2815 monotonic_clock::time_point(chrono::nanoseconds(2)));
2816 // Confirm avoiding the corrupted message crash, stopping instead.
2817 EXPECT_FALSE(reader.ReadMessage());
2818 }
2819
2820 {
2821 gflags::FlagSaver fs;
2822
2823 MessageReader reader(logfile);
2824 reader.set_crash_on_corrupt_message_flag(false);
2825 reader.set_ignore_corrupt_messages_flag(true);
2826
2827 EXPECT_EQ(reader.filename(), logfile);
2828
2829 EXPECT_EQ(
2830 reader.max_out_of_order_duration(),
2831 std::chrono::nanoseconds(config.message().max_out_of_order_duration()));
2832 EXPECT_EQ(reader.newest_timestamp(), monotonic_clock::min_time);
2833 EXPECT_TRUE(reader.ReadMessage());
2834 EXPECT_EQ(reader.newest_timestamp(),
2835 monotonic_clock::time_point(chrono::nanoseconds(1)));
2836 EXPECT_TRUE(reader.ReadMessage());
2837 EXPECT_EQ(reader.newest_timestamp(),
2838 monotonic_clock::time_point(chrono::nanoseconds(2)));
2839 // Confirm skipping of the corrupted message to read the hidden one.
2840 EXPECT_TRUE(reader.ReadMessage());
2841 EXPECT_EQ(reader.newest_timestamp(),
2842 monotonic_clock::time_point(chrono::nanoseconds(4)));
2843 EXPECT_FALSE(reader.ReadMessage());
2844 }
2845}
2846
Austin Schuhfa30c352022-10-16 11:12:02 -07002847class InlinePackMessage : public ::testing::Test {
2848 protected:
2849 aos::Context RandomContext() {
2850 data_ = RandomData();
2851 std::uniform_int_distribution<uint32_t> uint32_distribution(
2852 std::numeric_limits<uint32_t>::min(),
2853 std::numeric_limits<uint32_t>::max());
2854
2855 std::uniform_int_distribution<int64_t> time_distribution(
2856 std::numeric_limits<int64_t>::min(),
2857 std::numeric_limits<int64_t>::max());
2858
2859 aos::Context context;
2860 context.monotonic_event_time =
2861 aos::monotonic_clock::epoch() +
2862 chrono::nanoseconds(time_distribution(random_number_generator_));
2863 context.realtime_event_time =
2864 aos::realtime_clock::epoch() +
2865 chrono::nanoseconds(time_distribution(random_number_generator_));
2866
2867 context.monotonic_remote_time =
2868 aos::monotonic_clock::epoch() +
2869 chrono::nanoseconds(time_distribution(random_number_generator_));
2870 context.realtime_remote_time =
2871 aos::realtime_clock::epoch() +
2872 chrono::nanoseconds(time_distribution(random_number_generator_));
2873
2874 context.queue_index = uint32_distribution(random_number_generator_);
2875 context.remote_queue_index = uint32_distribution(random_number_generator_);
2876 context.size = data_.size();
2877 context.data = data_.data();
2878 return context;
2879 }
2880
Austin Schuhf2d0e682022-10-16 14:20:58 -07002881 aos::monotonic_clock::time_point RandomMonotonic() {
2882 std::uniform_int_distribution<int64_t> time_distribution(
2883 0, std::numeric_limits<int64_t>::max());
2884 return aos::monotonic_clock::epoch() +
2885 chrono::nanoseconds(time_distribution(random_number_generator_));
2886 }
2887
2888 aos::SizePrefixedFlatbufferDetachedBuffer<message_bridge::RemoteMessage>
2889 RandomRemoteMessage() {
2890 std::uniform_int_distribution<uint8_t> uint8_distribution(
2891 std::numeric_limits<uint8_t>::min(),
2892 std::numeric_limits<uint8_t>::max());
2893
2894 std::uniform_int_distribution<int64_t> time_distribution(
2895 std::numeric_limits<int64_t>::min(),
2896 std::numeric_limits<int64_t>::max());
2897
2898 flatbuffers::FlatBufferBuilder fbb;
2899 message_bridge::RemoteMessage::Builder builder(fbb);
2900 builder.add_queue_index(uint8_distribution(random_number_generator_));
2901
2902 builder.add_monotonic_sent_time(
2903 time_distribution(random_number_generator_));
2904 builder.add_realtime_sent_time(time_distribution(random_number_generator_));
2905 builder.add_monotonic_remote_time(
2906 time_distribution(random_number_generator_));
2907 builder.add_realtime_remote_time(
2908 time_distribution(random_number_generator_));
2909
2910 builder.add_remote_queue_index(
2911 uint8_distribution(random_number_generator_));
2912
2913 fbb.FinishSizePrefixed(builder.Finish());
2914 return fbb.Release();
2915 }
2916
Austin Schuhfa30c352022-10-16 11:12:02 -07002917 std::vector<uint8_t> RandomData() {
2918 std::vector<uint8_t> result;
2919 std::uniform_int_distribution<int> length_distribution(1, 32);
2920 std::uniform_int_distribution<uint8_t> data_distribution(
2921 std::numeric_limits<uint8_t>::min(),
2922 std::numeric_limits<uint8_t>::max());
2923
2924 const size_t length = length_distribution(random_number_generator_);
2925
2926 result.reserve(length);
2927 for (size_t i = 0; i < length; ++i) {
2928 result.emplace_back(data_distribution(random_number_generator_));
2929 }
2930 return result;
2931 }
2932
2933 std::mt19937 random_number_generator_{
2934 std::mt19937(::aos::testing::RandomSeed())};
2935
2936 std::vector<uint8_t> data_;
2937};
2938
2939// Uses the binary schema to annotate a provided flatbuffer. Returns the
2940// annotated flatbuffer.
2941std::string AnnotateBinaries(
2942 const aos::NonSizePrefixedFlatbuffer<reflection::Schema> &schema,
2943 const std::string &schema_filename,
2944 flatbuffers::span<uint8_t> binary_data) {
2945 flatbuffers::BinaryAnnotator binary_annotator(
2946 schema.span().data(), schema.span().size(), binary_data.data(),
2947 binary_data.size());
2948
2949 auto annotations = binary_annotator.Annotate();
2950
2951 flatbuffers::AnnotatedBinaryTextGenerator text_generator(
2952 flatbuffers::AnnotatedBinaryTextGenerator::Options{}, annotations,
2953 binary_data.data(), binary_data.size());
2954
2955 text_generator.Generate(aos::testing::TestTmpDir() + "/foo.bfbs",
2956 schema_filename);
2957
2958 return aos::util::ReadFileToStringOrDie(aos::testing::TestTmpDir() +
2959 "/foo.afb");
2960}
2961
2962// Tests that all variations of PackMessage are equivalent to the inline
2963// PackMessage used to avoid allocations.
2964TEST_F(InlinePackMessage, Equivilent) {
2965 std::uniform_int_distribution<uint32_t> uint32_distribution(
2966 std::numeric_limits<uint32_t>::min(),
2967 std::numeric_limits<uint32_t>::max());
2968 aos::FlatbufferVector<reflection::Schema> schema =
2969 FileToFlatbuffer<reflection::Schema>(
2970 ArtifactPath("aos/events/logging/logger.bfbs"));
2971
2972 for (const LogType type :
2973 {LogType::kLogMessage, LogType::kLogDeliveryTimeOnly,
2974 LogType::kLogMessageAndDeliveryTime, LogType::kLogRemoteMessage}) {
2975 for (int i = 0; i < 100; ++i) {
2976 aos::Context context = RandomContext();
2977 const uint32_t channel_index =
2978 uint32_distribution(random_number_generator_);
2979
2980 flatbuffers::FlatBufferBuilder fbb;
2981 fbb.ForceDefaults(true);
2982 fbb.FinishSizePrefixed(PackMessage(&fbb, context, channel_index, type));
2983
2984 VLOG(1) << absl::BytesToHexString(std::string_view(
2985 reinterpret_cast<const char *>(fbb.GetBufferSpan().data()),
2986 fbb.GetBufferSpan().size()));
2987
2988 // Make sure that both the builder and inline method agree on sizes.
Austin Schuh48d10d62022-10-16 22:19:23 -07002989 ASSERT_EQ(fbb.GetSize(), PackMessageSize(type, context.size))
Austin Schuhfa30c352022-10-16 11:12:02 -07002990 << "log type " << static_cast<int>(type);
2991
2992 // Initialize the buffer to something nonzero to make sure all the padding
2993 // bytes are set to 0.
Austin Schuh48d10d62022-10-16 22:19:23 -07002994 std::vector<uint8_t> repacked_message(PackMessageSize(type, context.size),
2995 67);
Austin Schuhfa30c352022-10-16 11:12:02 -07002996
2997 // And verify packing inline works as expected.
2998 EXPECT_EQ(repacked_message.size(),
2999 PackMessageInline(repacked_message.data(), context,
3000 channel_index, type));
3001 EXPECT_EQ(absl::Span<uint8_t>(repacked_message),
3002 absl::Span<uint8_t>(fbb.GetBufferSpan().data(),
3003 fbb.GetBufferSpan().size()))
3004 << AnnotateBinaries(schema, "aos/events/logging/logger.bfbs",
3005 fbb.GetBufferSpan());
3006 }
3007 }
3008}
3009
Austin Schuhf2d0e682022-10-16 14:20:58 -07003010// Tests that all variations of PackMessage are equivilent to the inline
3011// PackMessage used to avoid allocations.
3012TEST_F(InlinePackMessage, RemoteEquivilent) {
3013 aos::FlatbufferVector<reflection::Schema> schema =
3014 FileToFlatbuffer<reflection::Schema>(
3015 ArtifactPath("aos/events/logging/logger.bfbs"));
3016 std::uniform_int_distribution<uint8_t> uint8_distribution(
3017 std::numeric_limits<uint8_t>::min(), std::numeric_limits<uint8_t>::max());
3018
3019 for (int i = 0; i < 100; ++i) {
3020 aos::SizePrefixedFlatbufferDetachedBuffer<RemoteMessage> random_msg =
3021 RandomRemoteMessage();
3022 const size_t channel_index = uint8_distribution(random_number_generator_);
3023 const monotonic_clock::time_point monotonic_timestamp_time =
3024 RandomMonotonic();
3025
3026 flatbuffers::FlatBufferBuilder fbb;
3027 fbb.ForceDefaults(true);
3028 fbb.FinishSizePrefixed(PackRemoteMessage(
3029 &fbb, &random_msg.message(), channel_index, monotonic_timestamp_time));
3030
3031 VLOG(1) << absl::BytesToHexString(std::string_view(
3032 reinterpret_cast<const char *>(fbb.GetBufferSpan().data()),
3033 fbb.GetBufferSpan().size()));
3034
3035 // Make sure that both the builder and inline method agree on sizes.
3036 ASSERT_EQ(fbb.GetSize(), PackRemoteMessageSize());
3037
3038 // Initialize the buffer to something nonzer to make sure all the padding
3039 // bytes are set to 0.
3040 std::vector<uint8_t> repacked_message(PackRemoteMessageSize(), 67);
3041
3042 // And verify packing inline works as expected.
3043 EXPECT_EQ(
3044 repacked_message.size(),
3045 PackRemoteMessageInline(repacked_message.data(), &random_msg.message(),
3046 channel_index, monotonic_timestamp_time));
3047 EXPECT_EQ(absl::Span<uint8_t>(repacked_message),
3048 absl::Span<uint8_t>(fbb.GetBufferSpan().data(),
3049 fbb.GetBufferSpan().size()))
3050 << AnnotateBinaries(schema, "aos/events/logging/logger.bfbs",
3051 fbb.GetBufferSpan());
3052 }
3053}
Austin Schuhfa30c352022-10-16 11:12:02 -07003054
Austin Schuhc243b422020-10-11 15:35:08 -07003055} // namespace testing
3056} // namespace logger
3057} // namespace aos