Log, replay, and solve with transmit timestamps
Now that we have our fancy new transmit timestamps, we can use them to
solve our original ambiguous replay problem. Add them to the logfile
header, read them back, and use them in all the sorting code. We also
want to test the contents carefully to make sure that they get logged
correctly.
Change-Id: I8a284a9d70fab406bf69efd7ca7f7ab4e213a861
Signed-off-by: James Kuszmaul <james.kuszmaul@bluerivertech.com>
diff --git a/aos/events/logging/log_namer.cc b/aos/events/logging/log_namer.cc
index 4f8da91..3d52070 100644
--- a/aos/events/logging/log_namer.cc
+++ b/aos/events/logging/log_namer.cc
@@ -91,6 +91,10 @@
monotonic_clock::max_time;
state.oldest_logger_local_unreliable_monotonic_timestamp =
monotonic_clock::max_time;
+ state.oldest_remote_reliable_monotonic_transmit_timestamp =
+ monotonic_clock::max_time;
+ state.oldest_local_reliable_monotonic_transmit_timestamp =
+ monotonic_clock::max_time;
}
state_[node_index_].boot_uuid = source_node_boot_uuid;
@@ -115,6 +119,7 @@
void NewDataWriter::UpdateRemote(
const size_t remote_node_index, const UUID &remote_node_boot_uuid,
const monotonic_clock::time_point monotonic_remote_time,
+ const monotonic_clock::time_point monotonic_remote_transmit_time,
const monotonic_clock::time_point monotonic_event_time, const bool reliable,
monotonic_clock::time_point monotonic_timestamp_time) {
// Trigger rotation if anything in the header changes.
@@ -140,9 +145,29 @@
monotonic_clock::max_time;
state.oldest_logger_local_unreliable_monotonic_timestamp =
monotonic_clock::max_time;
+ state.oldest_remote_reliable_monotonic_transmit_timestamp =
+ monotonic_clock::max_time;
+ state.oldest_local_reliable_monotonic_transmit_timestamp =
+ monotonic_clock::max_time;
rotate = true;
}
+ if (monotonic_remote_transmit_time != monotonic_clock::min_time) {
+ if (state.oldest_remote_reliable_monotonic_transmit_timestamp >
+ monotonic_remote_transmit_time) {
+ VLOG(1) << name() << " Remote " << remote_node_index
+ << " oldest_remote_reliable_monotonic_transmit_timestamp updated "
+ "from "
+ << state.oldest_remote_reliable_monotonic_transmit_timestamp
+ << " to " << monotonic_remote_transmit_time;
+ state.oldest_remote_reliable_monotonic_transmit_timestamp =
+ monotonic_remote_transmit_time;
+ state.oldest_local_reliable_monotonic_transmit_timestamp =
+ monotonic_event_time;
+ rotate = true;
+ }
+ }
+
// Did the unreliable timestamps change?
if (!reliable) {
if (state.oldest_remote_unreliable_monotonic_timestamp >
@@ -399,8 +424,6 @@
<< ": If you added new fields to the LogFileHeader table, don't forget "
"to add it below!";
;
- // TODO(Mithun): Add oldest_remote_reliable_monotonic_transmit_timestamps,
- // and oldest_local_reliable_monotonic_transmit_timestamps to logfile header.
flatbuffers::FlatBufferBuilder fbb;
fbb.ForceDefaults(true);
@@ -499,6 +522,14 @@
oldest_logger_local_unreliable_monotonic_timestamps_offset =
fbb.CreateUninitializedVector(state.size(), &unused);
+ flatbuffers::Offset<flatbuffers::Vector<int64_t>>
+ oldest_remote_reliable_monotonic_transmit_timestamps_offset =
+ fbb.CreateUninitializedVector(state.size(), &unused);
+
+ flatbuffers::Offset<flatbuffers::Vector<int64_t>>
+ oldest_local_reliable_monotonic_transmit_timestamps_offset =
+ fbb.CreateUninitializedVector(state.size(), &unused);
+
for (size_t i = 0; i < state.size(); ++i) {
if (state[i].boot_uuid != UUID::Zero()) {
boot_uuid_offsets.emplace_back(state[i].boot_uuid.PackString(&fbb));
@@ -522,6 +553,10 @@
monotonic_clock::max_time);
CHECK_EQ(state[i].oldest_logger_local_unreliable_monotonic_timestamp,
monotonic_clock::max_time);
+ CHECK_EQ(state[i].oldest_remote_reliable_monotonic_transmit_timestamp,
+ monotonic_clock::max_time);
+ CHECK_EQ(state[i].oldest_local_reliable_monotonic_transmit_timestamp,
+ monotonic_clock::max_time);
}
flatbuffers::GetMutableTemporaryPointer(
@@ -572,6 +607,19 @@
.oldest_logger_local_unreliable_monotonic_timestamp
.time_since_epoch()
.count());
+
+ flatbuffers::GetMutableTemporaryPointer(
+ fbb, oldest_remote_reliable_monotonic_transmit_timestamps_offset)
+ ->Mutate(i, state[i]
+ .oldest_remote_reliable_monotonic_transmit_timestamp
+ .time_since_epoch()
+ .count());
+ flatbuffers::GetMutableTemporaryPointer(
+ fbb, oldest_local_reliable_monotonic_transmit_timestamps_offset)
+ ->Mutate(i, state[i]
+ .oldest_local_reliable_monotonic_transmit_timestamp
+ .time_since_epoch()
+ .count());
}
flatbuffers::Offset<
@@ -683,6 +731,12 @@
log_file_header_builder
.add_oldest_logger_local_unreliable_monotonic_timestamps(
oldest_logger_local_unreliable_monotonic_timestamps_offset);
+ log_file_header_builder
+ .add_oldest_remote_reliable_monotonic_transmit_timestamps(
+ oldest_remote_reliable_monotonic_transmit_timestamps_offset);
+ log_file_header_builder
+ .add_oldest_local_reliable_monotonic_transmit_timestamps(
+ oldest_local_reliable_monotonic_transmit_timestamps_offset);
log_file_header_builder.add_data_stored(data_stored_offset);
fbb.FinishSizePrefixed(log_file_header_builder.Finish());
diff --git a/aos/events/logging/log_namer.h b/aos/events/logging/log_namer.h
index e0660eb..a0d5857 100644
--- a/aos/events/logging/log_namer.h
+++ b/aos/events/logging/log_namer.h
@@ -70,6 +70,7 @@
// message is from.
void UpdateRemote(size_t remote_node_index, const UUID &remote_node_boot_uuid,
monotonic_clock::time_point monotonic_remote_time,
+ monotonic_clock::time_point monotonic_remote_transmit_time,
monotonic_clock::time_point monotonic_event_time,
bool reliable,
monotonic_clock::time_point monotonic_timestamp_time =
@@ -147,6 +148,17 @@
monotonic_clock::time_point
oldest_logger_local_unreliable_monotonic_timestamp =
monotonic_clock::max_time;
+
+ // Transmit timestamp on the remote monotonic clock of the oldest message
+ // sent to node_index_.
+ monotonic_clock::time_point
+ oldest_remote_reliable_monotonic_transmit_timestamp =
+ monotonic_clock::max_time;
+ // Timestamp on the local monotonic clock of the message in
+ // oldest_remote_reliable_monotonic_transmit_timestamp.
+ monotonic_clock::time_point
+ oldest_local_reliable_monotonic_transmit_timestamp =
+ monotonic_clock::max_time;
};
private:
diff --git a/aos/events/logging/log_reader.cc b/aos/events/logging/log_reader.cc
index 7e448fe..df1ed8c 100644
--- a/aos/events/logging/log_reader.cc
+++ b/aos/events/logging/log_reader.cc
@@ -1521,7 +1521,8 @@
const RawSender::Error err = sender->Send(
SharedSpan(timestamped_message.data, ×tamped_message.data->span),
timestamped_message.monotonic_remote_time.time,
- timestamped_message.realtime_remote_time, monotonic_clock::min_time,
+ timestamped_message.realtime_remote_time,
+ timestamped_message.monotonic_remote_transmit_time.time,
remote_queue_index,
(channel_source_state_[timestamped_message.channel_index] != nullptr
? CHECK_NOTNULL(multinode_filters_)
@@ -1615,6 +1616,10 @@
message_header_builder.add_monotonic_remote_time(
timestamped_message.monotonic_remote_time.time.time_since_epoch()
.count());
+ message_header_builder.add_monotonic_remote_transmit_time(
+ timestamped_message.monotonic_remote_transmit_time.time
+ .time_since_epoch()
+ .count());
message_header_builder.add_realtime_remote_time(
timestamped_message.realtime_remote_time.time_since_epoch().count());
diff --git a/aos/events/logging/log_writer.cc b/aos/events/logging/log_writer.cc
index 1546584..c960ab9 100644
--- a/aos/events/logging/log_writer.cc
+++ b/aos/events/logging/log_writer.cc
@@ -742,6 +742,7 @@
timestamp_writer->UpdateRemote(
f.data_node_index, f.fetcher->context().source_boot_uuid,
f.fetcher->context().monotonic_remote_time,
+ f.fetcher->context().monotonic_remote_transmit_time,
f.fetcher->context().monotonic_event_time, f.reliable_forwarding);
const auto start = event_loop_->monotonic_now();
@@ -796,6 +797,8 @@
monotonic_clock::time_point(
chrono::nanoseconds(msg->monotonic_remote_time())),
monotonic_clock::time_point(
+ chrono::nanoseconds(msg->monotonic_remote_transmit_time())),
+ monotonic_clock::time_point(
chrono::nanoseconds(msg->monotonic_sent_time())),
reliable, monotonic_timestamp_time);
diff --git a/aos/events/logging/logfile_sorting.cc b/aos/events/logging/logfile_sorting.cc
index 8fba5c1..4c859c2 100644
--- a/aos/events/logging/logfile_sorting.cc
+++ b/aos/events/logging/logfile_sorting.cc
@@ -715,17 +715,55 @@
chrono::nanoseconds(
log_header->message().oldest_remote_monotonic_timestamps()->Get(
node_index)));
+
const monotonic_clock::time_point
- oldest_local_unreliable_monotonic_timestamp(chrono::nanoseconds(
+ oldest_local_reliable_monotonic_transmit_timestamp =
+ log_header->message()
+ .has_oldest_local_reliable_monotonic_transmit_timestamps()
+ ? monotonic_clock::time_point(chrono::nanoseconds(
+ log_header->message()
+ .oldest_local_reliable_monotonic_transmit_timestamps()
+ ->Get(node_index)))
+ : monotonic_clock::max_time;
+ const monotonic_clock::time_point
+ oldest_remote_reliable_monotonic_transmit_timestamp =
+ log_header->message()
+ .has_oldest_remote_reliable_monotonic_transmit_timestamps()
+ ? monotonic_clock::time_point(chrono::nanoseconds(
+ log_header->message()
+ .oldest_remote_reliable_monotonic_transmit_timestamps()
+ ->Get(node_index)))
+ : monotonic_clock::max_time;
+ monotonic_clock::time_point oldest_local_unreliable_monotonic_timestamp(
+ chrono::nanoseconds(
log_header->message()
.oldest_local_unreliable_monotonic_timestamps()
->Get(node_index)));
- const monotonic_clock::time_point
+ monotonic_clock::time_point
oldest_remote_unreliable_monotonic_timestamp(chrono::nanoseconds(
log_header->message()
.oldest_remote_unreliable_monotonic_timestamps()
->Get(node_index)));
+ // Treat transmit timestamps like unreliable timestamps. Update
+ // oldest_remote_unreliable_monotonic_timestamp accordingly to keep the
+ // logic after it simple and similar.
+ if (oldest_remote_reliable_monotonic_transmit_timestamp <
+ oldest_remote_unreliable_monotonic_timestamp) {
+ VLOG(1)
+ << "Updating oldest_remote_unreliable_monotonic_timestamp from "
+ << oldest_remote_unreliable_monotonic_timestamp << " to "
+ << oldest_remote_reliable_monotonic_transmit_timestamp
+ << " and oldest_local_unreliable_monotonic_timestamp from "
+ << oldest_local_unreliable_monotonic_timestamp << " to "
+ << oldest_local_reliable_monotonic_transmit_timestamp;
+
+ oldest_remote_unreliable_monotonic_timestamp =
+ oldest_remote_reliable_monotonic_transmit_timestamp;
+ oldest_local_unreliable_monotonic_timestamp =
+ oldest_local_reliable_monotonic_transmit_timestamp;
+ }
+
const monotonic_clock::time_point
oldest_logger_local_unreliable_monotonic_timestamp =
log_header->message()
diff --git a/aos/events/logging/logfile_utils.cc b/aos/events/logging/logfile_utils.cc
index 551e69d..2e19f3c 100644
--- a/aos/events/logging/logfile_utils.cc
+++ b/aos/events/logging/logfile_utils.cc
@@ -316,14 +316,17 @@
message_header_builder.add_monotonic_sent_time(msg->monotonic_sent_time());
message_header_builder.add_realtime_sent_time(msg->realtime_sent_time());
+ message_header_builder.add_monotonic_timestamp_time(
+ monotonic_timestamp_time.time_since_epoch().count());
+
+ message_header_builder.add_monotonic_remote_transmit_time(
+ msg->monotonic_remote_transmit_time());
+
message_header_builder.add_monotonic_remote_time(
msg->monotonic_remote_time());
message_header_builder.add_realtime_remote_time(msg->realtime_remote_time());
message_header_builder.add_remote_queue_index(msg->remote_queue_index());
- message_header_builder.add_monotonic_timestamp_time(
- monotonic_timestamp_time.time_since_epoch().count());
-
return message_header_builder.Finish();
}
@@ -345,119 +348,116 @@
}
// clang-format off
// header:
- // +0x00 | 5C 00 00 00 | UOffset32 | 0x0000005C (92) Loc: +0x5C | size prefix
+ // +0x00 | 5C 00 00 00 | UOffset32 | 0x0000005C (92) Loc: +0x5C | size prefix
+
buffer = Push<flatbuffers::uoffset_t>(
buffer, message_size - sizeof(flatbuffers::uoffset_t));
- // +0x04 | 20 00 00 00 | UOffset32 | 0x00000020 (32) Loc: +0x24 | offset to root table `aos.logger.MessageHeader`
- buffer = Push<flatbuffers::uoffset_t>(buffer, 0x20);
+ // +0x04 | 1C 00 00 00 | UOffset32 | 0x0000001C (28) Loc: +0x20 | offset to root table `aos.logger.MessageHeader`
+ buffer = Push<flatbuffers::uoffset_t>(buffer, 0x1C);
[[fallthrough]];
case 0x08u:
if ((end_byte) == 0x08u) {
break;
}
//
- // padding:
- // +0x08 | 00 00 00 00 00 00 | uint8_t[6] | ...... | padding
- buffer = Pad(buffer, 6);
- //
// vtable (aos.logger.MessageHeader):
- // +0x0E | 16 00 | uint16_t | 0x0016 (22) | size of this vtable
- buffer = Push<flatbuffers::voffset_t>(buffer, 0x16);
+ // +0x08 | 18 00 | uint16_t | 0x0018 (24) | size of this vtable
+ buffer = Push<flatbuffers::voffset_t>(buffer, 0x18);
+ // +0x0A | 40 00 | uint16_t | 0x0040 (64) | size of referring table
+ buffer = Push<flatbuffers::voffset_t>(buffer, 0x40);
+ // +0x0C | 3C 00 | VOffset16 | 0x003C (60) | offset to field `channel_index` (id: 0)
+ buffer = Push<flatbuffers::voffset_t>(buffer, 0x3c);
+ // +0x0E | 30 00 | VOffset16 | 0x0030 (48) | offset to field `monotonic_sent_time` (id: 1)
+ buffer = Push<flatbuffers::voffset_t>(buffer, 0x30);
[[fallthrough]];
case 0x10u:
if ((end_byte) == 0x10u) {
break;
}
- // +0x10 | 3C 00 | uint16_t | 0x003C (60) | size of referring table
- buffer = Push<flatbuffers::voffset_t>(buffer, 0x3c);
- // +0x12 | 38 00 | VOffset16 | 0x0038 (56) | offset to field `channel_index` (id: 0)
+ // +0x10 | 28 00 | VOffset16 | 0x0028 (40) | offset to field `realtime_sent_time` (id: 2)
+ buffer = Push<flatbuffers::voffset_t>(buffer, 0x28);
+ // +0x12 | 38 00 | VOffset16 | 0x0038 (56) | offset to field `queue_index` (id: 3)
buffer = Push<flatbuffers::voffset_t>(buffer, 0x38);
- // +0x14 | 2C 00 | VOffset16 | 0x002C (44) | offset to field `monotonic_sent_time` (id: 1)
- buffer = Push<flatbuffers::voffset_t>(buffer, 0x2c);
- // +0x16 | 24 00 | VOffset16 | 0x0024 (36) | offset to field `realtime_sent_time` (id: 2)
- buffer = Push<flatbuffers::voffset_t>(buffer, 0x24);
+ // +0x14 | 00 00 | VOffset16 | 0x0000 (0) | offset to field `data` (id: 4) <null> (Vector)
+ buffer = Push<flatbuffers::voffset_t>(buffer, 0x00);
+ // +0x16 | 10 00 | VOffset16 | 0x0010 (16) | offset to field `monotonic_remote_time` (id: 5)
+ buffer = Push<flatbuffers::voffset_t>(buffer, 0x10);
[[fallthrough]];
case 0x18u:
if ((end_byte) == 0x18u) {
break;
}
- // +0x18 | 34 00 | VOffset16 | 0x0034 (52) | offset to field `queue_index` (id: 3)
- buffer = Push<flatbuffers::voffset_t>(buffer, 0x34);
- // +0x1A | 00 00 | VOffset16 | 0x0000 (0) | offset to field `data` (id: 4) <null> (Vector)
- buffer = Push<flatbuffers::voffset_t>(buffer, 0x00);
- // +0x1C | 1C 00 | VOffset16 | 0x001C (28) | offset to field `monotonic_remote_time` (id: 5)
- buffer = Push<flatbuffers::voffset_t>(buffer, 0x1c);
- // +0x1E | 14 00 | VOffset16 | 0x0014 (20) | offset to field `realtime_remote_time` (id: 6)
- buffer = Push<flatbuffers::voffset_t>(buffer, 0x14);
+ // +0x18 | 08 00 | VOffset16 | 0x0008 (8) | offset to field `realtime_remote_time` (id: 6)
+ buffer = Push<flatbuffers::voffset_t>(buffer, 0x08);
+ // +0x1A | 04 00 | VOffset16 | 0x0004 (4) | offset to field `remote_queue_index` (id: 7)
+ buffer = Push<flatbuffers::voffset_t>(buffer, 0x04);
+ // +0x1C | 20 00 | VOffset16 | 0x0020 (32) | offset to field `monotonic_timestamp_time` (id: 8)
+ buffer = Push<flatbuffers::voffset_t>(buffer, 0x20);
+ // +0x1E | 18 00 | VOffset16 | 0x0018 (24) | offset to field `monotonic_remote_transmit_time` (id: 9)
+ buffer = Push<flatbuffers::voffset_t>(buffer, 0x18);
[[fallthrough]];
case 0x20u:
if ((end_byte) == 0x20u) {
break;
}
- // +0x20 | 10 00 | VOffset16 | 0x0010 (16) | offset to field `remote_queue_index` (id: 7)
- buffer = Push<flatbuffers::voffset_t>(buffer, 0x10);
- // +0x22 | 04 00 | VOffset16 | 0x0004 (4) | offset to field `monotonic_timestamp_time` (id: 8)
- buffer = Push<flatbuffers::voffset_t>(buffer, 0x04);
- //
+
+
// root_table (aos.logger.MessageHeader):
- // +0x24 | 16 00 00 00 | SOffset32 | 0x00000016 (22) Loc: +0x0E | offset to vtable
- buffer = Push<flatbuffers::uoffset_t>(buffer, 0x16);
+ // +0x20 | 18 00 00 00 | SOffset32 | 0x00000018 (24) Loc: +0x08 | offset to vtable
+ buffer = Push<flatbuffers::uoffset_t>(buffer, 0x18);
+ // +0x24 | 8B 00 00 00 | uint32_t | 0x0000008B (139) | table field `remote_queue_index` (UInt)
+ buffer = Push<uint32_t>(buffer, msg->remote_queue_index());
[[fallthrough]];
case 0x28u:
if ((end_byte) == 0x28u) {
break;
}
- // +0x28 | F6 0B D8 11 A4 A8 B1 71 | int64_t | 0x71B1A8A411D80BF6 (8192514619791117302) | table field `monotonic_timestamp_time` (Long)
- buffer = Push<int64_t>(buffer,
- monotonic_timestamp_time.time_since_epoch().count());
+ // +0x28 | D4 C9 48 86 92 8B 6A AF | int64_t | 0xAF6A8B928648C9D4 (-5806675308106429996) | table field `realtime_remote_time` (Long)
+ buffer = Push<int64_t>(buffer, msg->realtime_remote_time());
[[fallthrough]];
case 0x30u:
if ((end_byte) == 0x30u) {
break;
}
- // +0x30 | 00 00 00 00 | uint8_t[4] | .... | padding
- // TODO(austin): Can we re-arrange the order to ditch the padding?
- // (Answer is yes, but what is the impact elsewhere? It will change the
- // binary format)
- buffer = Pad(buffer, 4);
- // +0x34 | 75 00 00 00 | uint32_t | 0x00000075 (117) | table field `remote_queue_index` (UInt)
- buffer = Push<uint32_t>(buffer, msg->remote_queue_index());
+ // +0x30 | 65 B1 32 50 FE 54 50 6B | int64_t | 0x6B5054FE5032B165 (7732774011439067493) | table field `monotonic_remote_time` (Long)
+ buffer = Push<int64_t>(buffer, msg->monotonic_remote_time());
[[fallthrough]];
case 0x38u:
if ((end_byte) == 0x38u) {
break;
}
- // +0x38 | AA B0 43 0A 35 BE FA D2 | int64_t | 0xD2FABE350A43B0AA (-3244071446552268630) | table field `realtime_remote_time` (Long)
- buffer = Push<int64_t>(buffer, msg->realtime_remote_time());
+ // +0x38 | EA 4D CC E0 FC 20 86 71 | int64_t | 0x718620FCE0CC4DEA (8180262043640417770) | table field `monotonic_remote_transmit_time` (Long)
+ buffer = Push<int64_t>(buffer, msg->monotonic_remote_transmit_time());
[[fallthrough]];
case 0x40u:
if ((end_byte) == 0x40u) {
break;
}
- // +0x40 | D5 40 30 F3 C1 A7 26 1D | int64_t | 0x1D26A7C1F33040D5 (2100550727665467605) | table field `monotonic_remote_time` (Long)
- buffer = Push<int64_t>(buffer, msg->monotonic_remote_time());
+ // +0x40 | 8E 59 CF 88 9D DF 02 07 | int64_t | 0x0702DF9D88CF598E (505211975917066638) | table field `monotonic_timestamp_time` (Long)
+ buffer = Push<int64_t>(buffer,
+ monotonic_timestamp_time.time_since_epoch().count());
[[fallthrough]];
case 0x48u:
if ((end_byte) == 0x48u) {
break;
}
- // +0x48 | 5B 25 32 A1 4A E8 46 CA | int64_t | 0xCA46E84AA132255B (-3871151422448720549) | table field `realtime_sent_time` (Long)
+ // +0x48 | 14 D5 A7 D8 B2 E4 EF 89 | int64_t | 0x89EFE4B2D8A7D514 (-8507329714289388268) | table field `realtime_sent_time` (Long)
buffer = Push<int64_t>(buffer, msg->realtime_sent_time());
[[fallthrough]];
case 0x50u:
if ((end_byte) == 0x50u) {
break;
}
- // +0x50 | 49 7D 45 1F 8C 36 6B A3 | int64_t | 0xA36B368C1F457D49 (-6671178447571288759) | table field `monotonic_sent_time` (Long)
+ // +0x50 | 19 7D 7F EF 86 8D 92 65 | int64_t | 0x65928D86EF7F7D19 (7319067955113721113) | table field `monotonic_sent_time` (Long)
buffer = Push<int64_t>(buffer, msg->monotonic_sent_time());
[[fallthrough]];
case 0x58u:
if ((end_byte) == 0x58u) {
break;
}
- // +0x58 | 33 00 00 00 | uint32_t | 0x00000033 (51) | table field `queue_index` (UInt)
+ // +0x58 | FC 00 00 00 | uint32_t | 0x000000FC (252) | table field `queue_index` (UInt)
buffer = Push<uint32_t>(buffer, msg->queue_index());
- // +0x5C | 76 00 00 00 | uint32_t | 0x00000076 (118) | table field `channel_index` (UInt)
+ // +0x5C | 9C 00 00 00 | uint32_t | 0x0000009C (156) | table field `channel_index` (UInt)
buffer = Push<uint32_t>(buffer, channel_index);
// clang-format on
[[fallthrough]];
@@ -524,6 +524,8 @@
context.monotonic_remote_time.time_since_epoch().count());
message_header_builder.add_realtime_remote_time(
context.realtime_remote_time.time_since_epoch().count());
+ message_header_builder.add_monotonic_remote_transmit_time(
+ context.monotonic_remote_transmit_time.time_since_epoch().count());
message_header_builder.add_remote_queue_index(context.remote_queue_index);
break;
@@ -565,19 +567,17 @@
return
// Root table size + offset.
sizeof(flatbuffers::uoffset_t) * 2 +
- // 6 padding bytes to pad the header out properly.
- 4 +
// vtable header (size + size of table)
sizeof(flatbuffers::voffset_t) * 2 +
// offsets to all the fields.
- sizeof(flatbuffers::voffset_t) * 8 +
+ sizeof(flatbuffers::voffset_t) * 10 +
// pointer to vtable
sizeof(flatbuffers::soffset_t) +
// remote_queue_index
sizeof(uint32_t) +
// realtime_remote_time, monotonic_remote_time, realtime_sent_time,
// monotonic_sent_time
- sizeof(int64_t) * 4 +
+ sizeof(int64_t) * 5 +
// queue_index, channel_index
sizeof(uint32_t) * 2;
@@ -786,10 +786,10 @@
}
// clang-format off
// header:
- // +0x00 | 4C 00 00 00 | UOffset32 | 0x0000004C (76) Loc: +0x4C | size prefix
+ // +0x00 | 54 00 00 00 | UOffset32 | 0x00000054 (84) Loc: +0x54 | size prefix
buffer = Push<flatbuffers::uoffset_t>(
buffer, message_size - sizeof(flatbuffers::uoffset_t));
- // +0x04 | 1C 00 00 00 | UOffset32 | 0x0000001C (28) Loc: +0x20 | offset to root table `aos.logger.MessageHeader`
+ // +0x04 | 1C 00 00 00 | UOffset32 | 0x0000001C (28) Loc: +0x20 | offset to root table `aos.logger.MessageHeader`
buffer = Push<flatbuffers::uoffset_t>(buffer, 0x1c);
[[fallthrough]];
@@ -798,88 +798,94 @@
break;
}
//
- // padding:
- // +0x08 | 00 00 00 00 | uint8_t[4] | .... | padding
- buffer = Pad(buffer, 4);
- //
// vtable (aos.logger.MessageHeader):
- // +0x0C | 14 00 | uint16_t | 0x0014 (20) | size of this vtable
- buffer = Push<flatbuffers::voffset_t>(buffer, 0x14);
- // +0x0E | 30 00 | uint16_t | 0x0030 (48) | size of referring table
- buffer = Push<flatbuffers::voffset_t>(buffer, 0x30);
+ // +0x08 | 18 00 | uint16_t | 0x0018 (24) | size of this vtable
+ buffer = Push<flatbuffers::voffset_t>(buffer, 0x18);
+ // +0x0A | 38 00 | uint16_t | 0x0038 (56) | size of referring table
+ buffer = Push<flatbuffers::voffset_t>(buffer, 0x38);
+ // +0x0C | 34 00 | VOffset16 | 0x0034 (52) | offset to field `channel_index` (id: 0)
+ buffer = Push<flatbuffers::voffset_t>(buffer, 0x34);
+ // +0x0E | 28 00 | VOffset16 | 0x0028 (40) | offset to field `monotonic_sent_time` (id: 1)
+ buffer = Push<flatbuffers::voffset_t>(buffer, 0x28);
[[fallthrough]];
case 0x10u:
if ((end_byte) == 0x10u) {
break;
}
- // +0x10 | 2C 00 | VOffset16 | 0x002C (44) | offset to field `channel_index` (id: 0)
- buffer = Push<flatbuffers::voffset_t>(buffer, 0x2c);
- // +0x12 | 20 00 | VOffset16 | 0x0020 (32) | offset to field `monotonic_sent_time` (id: 1)
+ // +0x10 | 20 00 | VOffset16 | 0x0020 (32) | offset to field `realtime_sent_time` (id: 2)
buffer = Push<flatbuffers::voffset_t>(buffer, 0x20);
- // +0x14 | 18 00 | VOffset16 | 0x0018 (24) | offset to field `realtime_sent_time` (id: 2)
+ // +0x12 | 30 00 | VOffset16 | 0x0030 (48) | offset to field `queue_index` (id: 3)
+ buffer = Push<flatbuffers::voffset_t>(buffer, 0x30);
+ // +0x14 | 00 00 | VOffset16 | 0x0000 (0) | offset to field `data` (id: 4) <null> (Vector)
+ buffer = Push<flatbuffers::voffset_t>(buffer, 0x00);
+ // +0x16 | 18 00 | VOffset16 | 0x0018 (24) | offset to field `monotonic_remote_time` (id: 5)
buffer = Push<flatbuffers::voffset_t>(buffer, 0x18);
- // +0x16 | 28 00 | VOffset16 | 0x0028 (40) | offset to field `queue_index` (id: 3)
- buffer = Push<flatbuffers::voffset_t>(buffer, 0x28);
[[fallthrough]];
case 0x18u:
if ((end_byte) == 0x18u) {
break;
}
- // +0x18 | 00 00 | VOffset16 | 0x0000 (0) | offset to field `data` (id: 4) <null> (Vector)
- buffer = Push<flatbuffers::voffset_t>(buffer, 0x00);
- // +0x1A | 10 00 | VOffset16 | 0x0010 (16) | offset to field `monotonic_remote_time` (id: 5)
+ // +0x18 | 10 00 | VOffset16 | 0x0010 (16) | offset to field `realtime_remote_time` (id: 6)
buffer = Push<flatbuffers::voffset_t>(buffer, 0x10);
- // +0x1C | 08 00 | VOffset16 | 0x0008 (8) | offset to field `realtime_remote_time` (id: 6)
- buffer = Push<flatbuffers::voffset_t>(buffer, 0x08);
- // +0x1E | 04 00 | VOffset16 | 0x0004 (4) | offset to field `remote_queue_index` (id: 7)
+ // +0x1A | 04 00 | VOffset16 | 0x0004 (4) | offset to field `remote_queue_index` (id: 7)
buffer = Push<flatbuffers::voffset_t>(buffer, 0x04);
+ // +0x1C | 00 00 | VOffset16 | 0x0000 (0) | offset to field `monotonic_timestamp_time` (id: 8) <defaults to -9223372036854775808> (Long)
+ buffer = Push<flatbuffers::voffset_t>(buffer, 0x00);
+ // +0x1E | 08 00 | VOffset16 | 0x0008 (8) | offset to field `monotonic_remote_transmit_time` (id: 9)
+ buffer = Push<flatbuffers::voffset_t>(buffer, 0x08);
[[fallthrough]];
case 0x20u:
if ((end_byte) == 0x20u) {
break;
}
- //
// root_table (aos.logger.MessageHeader):
- // +0x20 | 14 00 00 00 | SOffset32 | 0x00000014 (20) Loc: +0x0C | offset to vtable
- buffer = Push<flatbuffers::uoffset_t>(buffer, 0x14);
- // +0x24 | 69 00 00 00 | uint32_t | 0x00000069 (105) | table field `remote_queue_index` (UInt)
+ // +0x20 | 18 00 00 00 | SOffset32 | 0x00000018 (24) Loc: +0x08 | offset to vtable
+ buffer = Push<flatbuffers::uoffset_t>(buffer, 0x18);
+ // +0x24 | 3F 9A 69 37 | uint32_t | 0x37699A3F (929667647) | table field `remote_queue_index` (UInt)
buffer = Push<uint32_t>(buffer, context.remote_queue_index);
[[fallthrough]];
case 0x28u:
if ((end_byte) == 0x28u) {
break;
}
- // +0x28 | C6 85 F1 AB 83 B5 CD EB | int64_t | 0xEBCDB583ABF185C6 (-1455307527440726586) | table field `realtime_remote_time` (Long)
- buffer = Push<int64_t>(buffer, context.realtime_remote_time.time_since_epoch().count());
+ // +0x28 | 00 00 00 00 00 00 00 80 | int64_t | 0x8000000000000000 (-9223372036854775808) | table field `monotonic_remote_transmit_time` (Long)
+ buffer = Push<int64_t>(buffer, context.monotonic_remote_transmit_time.time_since_epoch().count());
[[fallthrough]];
case 0x30u:
if ((end_byte) == 0x30u) {
break;
}
- // +0x30 | 47 24 D3 97 1E 42 2D 99 | int64_t | 0x992D421E97D32447 (-7409193112790948793) | table field `monotonic_remote_time` (Long)
- buffer = Push<int64_t>(buffer, context.monotonic_remote_time.time_since_epoch().count());
+ // +0x30 | 1D CE 4A 38 54 33 C9 F8 | int64_t | 0xF8C93354384ACE1D (-519827845169885667) | table field `realtime_remote_time` (Long)
+ buffer = Push<int64_t>(buffer, context.realtime_remote_time.time_since_epoch().count());
[[fallthrough]];
case 0x38u:
if ((end_byte) == 0x38u) {
break;
}
- // +0x38 | C8 B9 A7 AB 79 F2 CD 60 | int64_t | 0x60CDF279ABA7B9C8 (6975498002251626952) | table field `realtime_sent_time` (Long)
- buffer = Push<int64_t>(buffer, context.realtime_event_time.time_since_epoch().count());
+ // +0x38 | FE EA DF 1D C7 3F C6 03 | int64_t | 0x03C63FC71DDFEAFE (271974951934749438) | table field `monotonic_remote_time` (Long)
+ buffer = Push<int64_t>(buffer, context.monotonic_remote_time.time_since_epoch().count());
[[fallthrough]];
case 0x40u:
if ((end_byte) == 0x40u) {
break;
}
- // +0x40 | EA 8F 2A 0F AF 01 7A AB | int64_t | 0xAB7A01AF0F2A8FEA (-6090553694679822358) | table field `monotonic_sent_time` (Long)
- buffer = Push<int64_t>(buffer, context.monotonic_event_time.time_since_epoch().count());
+ // +0x40 | 4E 0C 96 6E FB B5 CE 12 | int64_t | 0x12CEB5FB6E960C4E (1355220629381844046) | table field `realtime_sent_time` (Long)
+ buffer = Push<int64_t>(buffer, context.realtime_event_time.time_since_epoch().count());
[[fallthrough]];
case 0x48u:
if ((end_byte) == 0x48u) {
break;
}
- // +0x48 | F5 00 00 00 | uint32_t | 0x000000F5 (245) | table field `queue_index` (UInt)
+ // +0x48 | 51 56 56 F9 0A 0B 0F 12 | int64_t | 0x120F0B0AF9565651 (1301270959094126161) | table field `monotonic_sent_time` (Long)
+ buffer = Push<int64_t>(buffer, context.monotonic_event_time.time_since_epoch().count());
+ [[fallthrough]];
+ case 0x50u:
+ if ((end_byte) == 0x50u) {
+ break;
+ }
+ // +0x50 | 0C A5 42 18 | uint32_t | 0x1842A50C (407020812) | table field `queue_index` (UInt)
buffer = Push<uint32_t>(buffer, context.queue_index);
- // +0x4C | 88 00 00 00 | uint32_t | 0x00000088 (136) | table field `channel_index` (UInt)
+ // +0x54 | 87 10 7C D7 | uint32_t | 0xD77C1087 (3615232135) | table field `channel_index` (UInt)
buffer = Push<uint32_t>(buffer, channel_index);
// clang-format on
@@ -1361,6 +1367,9 @@
realtime_remote_time = realtime_clock::time_point(
chrono::nanoseconds(message.realtime_remote_time()));
}
+ aos::monotonic_clock::time_point monotonic_remote_transmit_time =
+ aos::monotonic_clock::time_point(
+ std::chrono::nanoseconds(message.monotonic_remote_transmit_time()));
std::optional<uint32_t> remote_queue_index;
if (message.has_remote_queue_index()) {
@@ -1374,7 +1383,7 @@
realtime_clock::time_point(
chrono::nanoseconds(message.realtime_sent_time())),
message.queue_index(), monotonic_remote_time, realtime_remote_time,
- remote_queue_index,
+ monotonic_remote_transmit_time, remote_queue_index,
monotonic_clock::time_point(
std::chrono::nanoseconds(message.monotonic_timestamp_time())),
message.has_monotonic_timestamp_time(), span);
@@ -1582,6 +1591,10 @@
if (msg.realtime_remote_time != realtime_clock::min_time) {
os << ", .realtime_remote_time=" << msg.realtime_remote_time;
}
+ if (msg.monotonic_remote_transmit_time != BootTimestamp::min_time()) {
+ os << ", .monotonic_remote_transmit_time="
+ << msg.monotonic_remote_transmit_time;
+ }
if (msg.monotonic_timestamp_time != BootTimestamp::min_time()) {
os << ", .monotonic_timestamp_time=" << msg.monotonic_timestamp_time;
}
@@ -2019,6 +2032,9 @@
.monotonic_remote_time = {msg->monotonic_remote_boot,
msg->data->monotonic_remote_time.value()},
.realtime_remote_time = msg->data->realtime_remote_time.value(),
+ .monotonic_remote_transmit_time =
+ {msg->monotonic_remote_boot,
+ msg->data->monotonic_remote_transmit_time},
.monotonic_timestamp_time = {msg->monotonic_timestamp_boot,
msg->data->monotonic_timestamp_time},
.data = std::move(msg->data)});
@@ -2207,16 +2223,17 @@
}
void TimestampMapper::QueueMessage(const Message *msg) {
- matched_messages_.emplace_back(
- TimestampedMessage{.channel_index = msg->channel_index,
- .queue_index = msg->queue_index,
- .monotonic_event_time = msg->timestamp,
- .realtime_event_time = msg->data->realtime_sent_time,
- .remote_queue_index = BootQueueIndex::Invalid(),
- .monotonic_remote_time = BootTimestamp::min_time(),
- .realtime_remote_time = realtime_clock::min_time,
- .monotonic_timestamp_time = BootTimestamp::min_time(),
- .data = std::move(msg->data)});
+ matched_messages_.emplace_back(TimestampedMessage{
+ .channel_index = msg->channel_index,
+ .queue_index = msg->queue_index,
+ .monotonic_event_time = msg->timestamp,
+ .realtime_event_time = msg->data->realtime_sent_time,
+ .remote_queue_index = BootQueueIndex::Invalid(),
+ .monotonic_remote_time = BootTimestamp::min_time(),
+ .realtime_remote_time = realtime_clock::min_time,
+ .monotonic_remote_transmit_time = BootTimestamp::min_time(),
+ .monotonic_timestamp_time = BootTimestamp::min_time(),
+ .data = std::move(msg->data)});
VLOG(1) << node_name() << " Inserted " << matched_messages_.back();
}
@@ -2339,6 +2356,9 @@
.monotonic_remote_time = {msg->monotonic_remote_boot,
msg->data->monotonic_remote_time.value()},
.realtime_remote_time = msg->data->realtime_remote_time.value(),
+ .monotonic_remote_transmit_time =
+ {msg->monotonic_remote_boot,
+ msg->data->monotonic_remote_transmit_time},
.monotonic_timestamp_time = {msg->monotonic_timestamp_boot,
msg->data->monotonic_timestamp_time},
.data = std::move(data.data)});
diff --git a/aos/events/logging/logfile_utils.h b/aos/events/logging/logfile_utils.h
index ff48898..d781a20 100644
--- a/aos/events/logging/logfile_utils.h
+++ b/aos/events/logging/logfile_utils.h
@@ -441,6 +441,7 @@
realtime_clock::time_point realtime_sent_time, uint32_t queue_index,
std::optional<monotonic_clock::time_point> monotonic_remote_time,
std::optional<realtime_clock::time_point> realtime_remote_time,
+ monotonic_clock::time_point monotonic_remote_transmit_time,
std::optional<uint32_t> remote_queue_index,
monotonic_clock::time_point monotonic_timestamp_time,
bool has_monotonic_timestamp_time, absl::Span<const uint8_t> span)
@@ -450,6 +451,7 @@
queue_index(queue_index),
monotonic_remote_time(monotonic_remote_time),
realtime_remote_time(realtime_remote_time),
+ monotonic_remote_transmit_time(monotonic_remote_transmit_time),
remote_queue_index(remote_queue_index),
monotonic_timestamp_time(monotonic_timestamp_time),
has_monotonic_timestamp_time(has_monotonic_timestamp_time),
@@ -469,6 +471,7 @@
std::optional<aos::monotonic_clock::time_point> monotonic_remote_time;
std::optional<realtime_clock::time_point> realtime_remote_time;
+ aos::monotonic_clock::time_point monotonic_remote_transmit_time;
std::optional<uint32_t> remote_queue_index;
// This field is defaulted in the flatbuffer, so we need to store both the
@@ -546,6 +549,8 @@
BootTimestamp monotonic_remote_time;
realtime_clock::time_point realtime_remote_time = realtime_clock::min_time;
+ BootTimestamp monotonic_remote_transmit_time;
+
BootTimestamp monotonic_timestamp_time;
std::shared_ptr<UnpackedMessageHeader> data;
diff --git a/aos/events/logging/logfile_utils_test.cc b/aos/events/logging/logfile_utils_test.cc
index cba74ed..0c1cafd 100644
--- a/aos/events/logging/logfile_utils_test.cc
+++ b/aos/events/logging/logfile_utils_test.cc
@@ -3070,6 +3070,10 @@
aos::realtime_clock::epoch() +
chrono::nanoseconds(time_distribution(random_number_generator_));
+ context.monotonic_remote_transmit_time =
+ aos::monotonic_clock::epoch() +
+ chrono::nanoseconds(time_distribution(random_number_generator_));
+
context.queue_index = uint32_distribution(random_number_generator_);
context.remote_queue_index = uint32_distribution(random_number_generator_);
context.size = data_.size();
@@ -3109,6 +3113,9 @@
builder.add_remote_queue_index(
uint8_distribution(random_number_generator_));
+ builder.add_monotonic_remote_transmit_time(
+ time_distribution(random_number_generator_));
+
fbb.FinishSizePrefixed(builder.Finish());
return fbb.Release();
}
@@ -3282,11 +3289,18 @@
repacked_message.size(),
PackMessageInline(repacked_message.data(), context, channel_index,
type, 0u, repacked_message.size()));
- EXPECT_EQ(absl::Span<uint8_t>(repacked_message),
+ for (size_t i = 0; i < fbb.GetBufferSpan().size(); ++i) {
+ ASSERT_EQ(absl::Span<uint8_t>(repacked_message)[i],
+ absl::Span<uint8_t>(fbb.GetBufferSpan().data(),
+ fbb.GetBufferSpan().size())[i])
+ << ": On index " << i;
+ }
+ ASSERT_EQ(absl::Span<uint8_t>(repacked_message),
absl::Span<uint8_t>(fbb.GetBufferSpan().data(),
fbb.GetBufferSpan().size()))
<< AnnotateBinaries(schema, "aos/events/logging/logger.bfbs",
- fbb.GetBufferSpan());
+ fbb.GetBufferSpan())
+ << " for log type " << static_cast<int>(type);
// Ok, now we want to confirm that we can build up arbitrary pieces of
// said flatbuffer. Try all of them since it is cheap.
diff --git a/aos/events/logging/multinode_logger_test.cc b/aos/events/logging/multinode_logger_test.cc
index 5dddc60..2cf8ffe 100644
--- a/aos/events/logging/multinode_logger_test.cc
+++ b/aos/events/logging/multinode_logger_test.cc
@@ -474,6 +474,8 @@
pi1_event_loop->context().monotonic_event_time);
EXPECT_EQ(pi1_event_loop->context().realtime_remote_time,
pi1_event_loop->context().realtime_event_time);
+ EXPECT_EQ(pi1_event_loop->context().monotonic_remote_transmit_time,
+ monotonic_clock::min_time);
++pi1_ping_count;
});
@@ -501,6 +503,9 @@
}
EXPECT_EQ(pi2_event_loop->context().monotonic_remote_time + offset,
pi2_event_loop->context().monotonic_event_time);
+ EXPECT_EQ(pi2_event_loop->context().monotonic_event_time -
+ chrono::microseconds(100),
+ pi2_event_loop->context().monotonic_remote_transmit_time);
EXPECT_EQ(pi2_event_loop->context().realtime_remote_time + offset,
pi2_event_loop->context().realtime_event_time);
++pi2_ping_count;
@@ -540,6 +545,9 @@
EXPECT_EQ(pi1_event_loop->context().realtime_remote_time +
chrono::microseconds(150),
pi1_event_loop->context().realtime_event_time);
+ EXPECT_EQ(pi1_event_loop->context().monotonic_remote_transmit_time,
+ pi1_event_loop->context().monotonic_event_time -
+ chrono::microseconds(100));
EXPECT_EQ(pong.value(), pi1_pong_count + 1);
++pi1_pong_count;
@@ -574,6 +582,8 @@
pi2_event_loop->context().monotonic_event_time);
EXPECT_EQ(pi2_event_loop->context().realtime_remote_time,
pi2_event_loop->context().realtime_event_time);
+ EXPECT_EQ(pi2_event_loop->context().monotonic_remote_transmit_time,
+ monotonic_clock::min_time);
EXPECT_EQ(pong.value(), pi2_pong_count + 1);
++pi2_pong_count;
@@ -1913,6 +1923,9 @@
chrono::nanoseconds(header.realtime_sent_time()));
const aos::monotonic_clock::time_point header_monotonic_remote_time(
chrono::nanoseconds(header.monotonic_remote_time()));
+ const aos::monotonic_clock::time_point
+ header_monotonic_remote_transmit_time(
+ chrono::nanoseconds(header.monotonic_remote_transmit_time()));
const aos::realtime_clock::time_point header_realtime_remote_time(
chrono::nanoseconds(header.realtime_remote_time()));
@@ -1974,6 +1987,8 @@
header_realtime_remote_time);
EXPECT_EQ(pi2_context->monotonic_remote_time,
header_monotonic_remote_time);
+ EXPECT_EQ(pi2_context->monotonic_remote_transmit_time,
+ header_monotonic_remote_transmit_time);
EXPECT_EQ(pi1_context->realtime_event_time,
header_realtime_remote_time);
@@ -2003,6 +2018,9 @@
chrono::nanoseconds(header.realtime_sent_time()));
const aos::monotonic_clock::time_point header_monotonic_remote_time(
chrono::nanoseconds(header.monotonic_remote_time()));
+ const aos::monotonic_clock::time_point
+ header_monotonic_remote_transmit_time(
+ chrono::nanoseconds(header.monotonic_remote_transmit_time()));
const aos::realtime_clock::time_point header_realtime_remote_time(
chrono::nanoseconds(header.realtime_remote_time()));
@@ -2056,6 +2074,8 @@
header_realtime_remote_time);
EXPECT_EQ(pi1_context->monotonic_remote_time,
header_monotonic_remote_time);
+ EXPECT_EQ(pi1_context->monotonic_remote_transmit_time,
+ header_monotonic_remote_transmit_time);
EXPECT_EQ(pi2_context->realtime_event_time,
header_realtime_remote_time);
@@ -2390,6 +2410,18 @@
.oldest_local_unreliable_monotonic_timestamps()
->Get(1)));
const monotonic_clock::time_point
+ oldest_remote_reliable_monotonic_transmit_timestamps =
+ monotonic_clock::time_point(chrono::nanoseconds(
+ log_header->message()
+ .oldest_remote_reliable_monotonic_transmit_timestamps()
+ ->Get(1)));
+ const monotonic_clock::time_point
+ oldest_local_reliable_monotonic_transmit_timestamps =
+ monotonic_clock::time_point(chrono::nanoseconds(
+ log_header->message()
+ .oldest_local_reliable_monotonic_transmit_timestamps()
+ ->Get(1)));
+ const monotonic_clock::time_point
oldest_remote_reliable_monotonic_timestamps =
monotonic_clock::time_point(chrono::nanoseconds(
log_header->message()
@@ -2432,6 +2464,10 @@
monotonic_clock::max_time);
EXPECT_EQ(oldest_local_reliable_monotonic_timestamps,
monotonic_clock::max_time);
+ EXPECT_EQ(oldest_remote_reliable_monotonic_transmit_timestamps,
+ monotonic_clock::max_time);
+ EXPECT_EQ(oldest_local_reliable_monotonic_transmit_timestamps,
+ monotonic_clock::max_time);
break;
default:
FAIL();
@@ -2453,6 +2489,10 @@
monotonic_clock::max_time);
EXPECT_EQ(oldest_local_reliable_monotonic_timestamps,
monotonic_clock::max_time);
+ EXPECT_EQ(oldest_remote_reliable_monotonic_transmit_timestamps,
+ monotonic_clock::time_point(chrono::microseconds(90250)));
+ EXPECT_EQ(oldest_local_reliable_monotonic_transmit_timestamps,
+ monotonic_clock::time_point(chrono::microseconds(90350)));
break;
case 1:
ASSERT_EQ(oldest_remote_monotonic_timestamps,
@@ -2473,6 +2513,12 @@
EXPECT_EQ(oldest_local_reliable_monotonic_timestamps,
monotonic_clock::time_point(chrono::microseconds(100100)))
<< file;
+ EXPECT_EQ(oldest_remote_reliable_monotonic_transmit_timestamps,
+ monotonic_clock::time_point(chrono::microseconds(90250)))
+ << file;
+ EXPECT_EQ(oldest_local_reliable_monotonic_transmit_timestamps,
+ monotonic_clock::time_point(chrono::microseconds(90350)))
+ << file;
break;
case 2:
ASSERT_EQ(oldest_remote_monotonic_timestamps,
@@ -2493,6 +2539,13 @@
EXPECT_EQ(oldest_local_reliable_monotonic_timestamps,
monotonic_clock::max_time)
<< file;
+ EXPECT_EQ(oldest_remote_reliable_monotonic_transmit_timestamps,
+ monotonic_clock::time_point(chrono::milliseconds(1323) +
+ chrono::microseconds(250)))
+ << file;
+ EXPECT_EQ(oldest_local_reliable_monotonic_transmit_timestamps,
+ monotonic_clock::time_point(chrono::microseconds(10100350)))
+ << file;
break;
case 3:
ASSERT_EQ(oldest_remote_monotonic_timestamps,
@@ -2513,6 +2566,13 @@
EXPECT_EQ(oldest_local_reliable_monotonic_timestamps,
monotonic_clock::time_point(chrono::microseconds(10200100)))
<< file;
+ EXPECT_EQ(oldest_remote_reliable_monotonic_transmit_timestamps,
+ monotonic_clock::time_point(chrono::milliseconds(1323) +
+ chrono::microseconds(250)))
+ << file;
+ EXPECT_EQ(oldest_local_reliable_monotonic_transmit_timestamps,
+ monotonic_clock::time_point(chrono::microseconds(10100350)))
+ << file;
break;
default:
FAIL();
@@ -4761,7 +4821,7 @@
//
// Note: this is disabled since it doesn't work yet. Un-disable this when the
// code is fixed!
-TEST(MultinodeLoggerLoopTest, DISABLED_ReliableOnlyTimestamps) {
+TEST(MultinodeLoggerLoopTest, ReliableOnlyTimestamps) {
util::UnlinkRecursive(aos::testing::TestTmpDir() + "/logs");
std::filesystem::create_directory(aos::testing::TestTmpDir() + "/logs");
diff --git a/aos/network/multinode_timestamp_filter.cc b/aos/network/multinode_timestamp_filter.cc
index 91d7854..cae9e1f 100644
--- a/aos/network/multinode_timestamp_filter.cc
+++ b/aos/network/multinode_timestamp_filter.cc
@@ -2016,10 +2016,21 @@
CHECK_NOTNULL(filter);
const Node *node = configuration()->nodes()->Get(node_index);
+ // The remote time could be from a reliable message long ago,
+ // whereas the transmit time is the latest timestamp we have on
+ // the far side. Use that for recovering time when we have it.
+ // There are a ton of logs from before that timestamp was added.
+ // Fall back to the remote time in those.
+ const BootTimestamp monotonic_remote_time =
+ msg->monotonic_remote_transmit_time.time !=
+ monotonic_clock::min_time
+ ? msg->monotonic_remote_transmit_time
+ : msg->monotonic_remote_time;
+
// Call the correct method depending on if we are the forward or
// reverse direction here.
filter->Sample(node, msg->monotonic_event_time,
- msg->monotonic_remote_time);
+ monotonic_remote_time);
if (!node_samples_.empty()) {
const size_t sending_node_index =
@@ -2029,8 +2040,8 @@
// and monotonic_event_time was the time it was received.
node_samples_[node_index]
.nodes[sending_node_index]
- .messages.emplace(std::make_pair(
- msg->monotonic_event_time, msg->monotonic_remote_time));
+ .messages.emplace(std::make_pair(msg->monotonic_event_time,
+ monotonic_remote_time));
}
if (msg->monotonic_timestamp_time != BootTimestamp::min_time()) {
@@ -2044,7 +2055,7 @@
const size_t sending_node_index =
source_node_index_[msg->channel_index];
// The timestamp then went back from node node_index to
- // sending_node_index. monotonic_event_time is the time it
+ // sending_node_index. monotonic_transmit_time is the time it
// was sent, and monotonic_timestamp_time was the time it was
// received.
node_samples_[sending_node_index]
diff --git a/aos/network/timestamp_filter.cc b/aos/network/timestamp_filter.cc
index fb89a41..f3aea62 100644
--- a/aos/network/timestamp_filter.cc
+++ b/aos/network/timestamp_filter.cc
@@ -1632,20 +1632,16 @@
removed = true;
}
- if (timestamps_size == 2) {
+ if (timestamps_size <= 2) {
if (pop_filter_ + 1u >= filters_.size()) {
return removed;
}
- // There is 1 more filter, see if there is enough data in it to switch
- // over to it.
- if (filters_[pop_filter_ + 1]->filter.timestamps_size() < 2u) {
- return removed;
- }
if (time <
- BootTimestamp{.boot = static_cast<size_t>(boot_filter->boot.first),
+ BootTimestamp{.boot = static_cast<size_t>(
+ filters_[pop_filter_ + 1]->boot.first),
.time = std::get<0>(
- filters_[pop_filter_ + 1]->filter.timestamp(1))}) {
+ filters_[pop_filter_ + 1]->filter.timestamp(0))}) {
return removed;
}
}