Track matching forwarded times for log file sorting
Previously, the only thing we knew was a loose ordering based on part
index. That isn't very conclusive. This now provides us with
corresponding timestamps for when things cross the network boundary in a
way that we think should tell us definitively what came first.
There are 2 main problem cases. Let's say we have 2 channels. /a which
is reliable, and /b which isn't, both sent from the same remote node.
case 1: /a -> boot 0 received on boot 0.
/b -> boot 1 received on boot 0.
We start logging after both messages arrive.
case 2: /a -> boot 0 received on boot 0.
/b -> boot 0 received on boot 0.
We log for a bit, then reboot. More messages show up when we reconnect.
/a -> boot 0 received on boot 1.
/b -> boot 0 received on boot 1.
In case 1: we only have a reliable timestamp from boot 0, but that
reliable timestamp makes it clear that /a was before /b, so boot 0 was
before boot 1.
In case 2: we have the same reliable timestamp, so that tells us nothing.
The unreliable timestamps though tell a different story. /b will be after
/a, since any messages on /b generated before the reboot won't get
delivered. So, we get an ordering constraint saying that any sent /b's
on the second boot were after /b on the first boot.
We believe that any other cases are covered by the same mechanism.
Without fully implementing and debugging the sorting code, we won't know
for certain. Sanjay and I have been unable to break the logic so far.
Change-Id: I990bf249b18bf43072997cdb099ac66c2fa8fc57
Signed-off-by: Austin Schuh <austin.schuh@bluerivertech.com>
diff --git a/aos/events/logging/log_writer.cc b/aos/events/logging/log_writer.cc
index 4bc4448..bc04f83 100644
--- a/aos/events/logging/log_writer.cc
+++ b/aos/events/logging/log_writer.cc
@@ -92,8 +92,19 @@
bool log_delivery_times = false;
if (event_loop_->node() != nullptr) {
+ const aos::Connection *connection =
+ configuration::ConnectionToNode(channel, event_loop_->node());
+
log_delivery_times = configuration::ConnectionDeliveryTimeIsLoggedOnNode(
- channel, event_loop_->node(), event_loop_->node());
+ connection, event_loop_->node());
+
+ CHECK_EQ(log_delivery_times,
+ configuration::ConnectionDeliveryTimeIsLoggedOnNode(
+ channel, event_loop_->node(), event_loop_->node()));
+
+ if (connection) {
+ fs.reliable_forwarding = (connection->time_to_live() == 0);
+ }
}
// Now, detect a RemoteMessage timestamp logger where we should just log the
@@ -620,8 +631,10 @@
fbb.GetBufferPointer()));
// Tell our writer that we know something about the remote boot.
- f.timestamp_writer->UpdateRemote(f.data_node_index,
- f.fetcher->context().source_boot_uuid);
+ f.timestamp_writer->UpdateRemote(
+ f.data_node_index, f.fetcher->context().source_boot_uuid,
+ f.fetcher->context().monotonic_remote_time,
+ f.fetcher->context().monotonic_event_time, f.reliable_forwarding);
f.timestamp_writer->QueueMessage(&fbb, event_loop_->boot_uuid(), end);
}