Switch Logger over to using the new context UUID
We got a lovely kersplat when Jim rebooted one of the pi's and I tried
to restart the logger. We've seen this occasionally in a bunch of
spots randomly.
F0313 17:40:26.905807 1893 log_writer.cc:677] Check failed: node_state_[f.data_node_index].header_valid : Can't write data before the header on channel { "name": "/pi2/aos", "type": "aos.message_bridge.Timestamp", "frequency": 10, "max_size": 200, "num_senders": 2, "source_node": "pi2", "destination_nodes": [ { "name": "roborio", "timestamp_logger": "LOCAL_AND_REMOTE_LOGGER", "timestamp_logger_nodes": [ "roborio" ], "priority": 1, "time_to_live": 5000000 }, { "name": "laptop", "priority": 1, "time_to_live": 5000000 } ], "logger": "LOCAL_AND_REMOTE_LOGGER", "logger_nodes": [ "roborio", "laptop" ] }
*** Check failure stack trace: ***
@ 0x53c888 google::LogMessage::Fail()
@ 0x53e418 google::LogMessage::SendToLog()
@ 0x53c508 google::LogMessage::Flush()
@ 0x53cbec google::LogMessageFatal::~LogMessageFatal()
@ 0x4e2f00 aos::logger::Logger::LogUntil()
@ 0x4e5784 aos::logger::Logger::StartLogging()
@ 0x4d90f0 _ZNSt17_Function_handlerIFvvEZ4mainEUlvE_E9_M_invokeERKSt9_Any_data
@ 0x4f6cac aos::ShmEventLoop::Run()
@ 0x4d4288 main
@ 0xb6c1e580 __libc_start_main
This is because we are using the ServerStatistics message for the boot
UUID of a node. If the logger starts up and there is data on a channel
from a node which isn't currently active, we don't have a way of telling
which boot that data is from. That means we can't log the header, so we
can't log the data.
Instead of using the ServerStatistics message, use the new
remote_boot_uuid for the message. That tells us exactly which boot is
is from reliably. Since it is attached to the message, it can never get
out of sync.
The downside here is that we are adding another 16 bytes to each message
that is being sent. That is close to doubling our overhead, but should
be significantly less than a simple flatbuffer.
Another option could have been to drop the data. But, in the case of
parameters messages from other nodes which are low frequency and
critical for operating the system, we would not be able to reproduce the
state reliably.
Alternatives could also be to make the ServerStatistics message
complicated enough to track what messages came from what boot. This
would likely end up being wack-a-mole to try to figure out how to
describe which messages from a bunch of vintages could be from which
boots in the queues.
Change-Id: Idc531ca1ff1628c38efc4877661f121c94641e78
diff --git a/aos/events/logging/logger_test.cc b/aos/events/logging/logger_test.cc
index 6ffa16c..17078dc 100644
--- a/aos/events/logging/logger_test.cc
+++ b/aos/events/logging/logger_test.cc
@@ -419,7 +419,7 @@
// channel.
bool shared;
// sha256 of the config.
- std::string sha256;
+ std::string_view sha256;
};
class MultinodeLoggerTest : public ::testing::TestWithParam<struct Param> {
@@ -1900,8 +1900,8 @@
}
ASSERT_TRUE(header.has_boot_uuid());
- EXPECT_EQ(header.boot_uuid()->string_view(),
- pi2_event_loop->boot_uuid().ToString());
+ EXPECT_EQ(UUID::FromVector(header.boot_uuid()),
+ pi2_event_loop->boot_uuid());
EXPECT_EQ(pi1_context->queue_index, header.remote_queue_index());
EXPECT_EQ(pi2_context->remote_queue_index,
@@ -1980,8 +1980,8 @@
}
ASSERT_TRUE(header.has_boot_uuid());
- EXPECT_EQ(header.boot_uuid()->string_view(),
- pi1_event_loop->boot_uuid().ToString());
+ EXPECT_EQ(UUID::FromVector(header.boot_uuid()),
+ pi1_event_loop->boot_uuid());
EXPECT_EQ(pi2_context->queue_index, header.remote_queue_index());
EXPECT_EQ(pi1_context->remote_queue_index,
@@ -2199,25 +2199,24 @@
ConfirmReadable(pi1_single_direction_logfiles_);
}
+constexpr std::string_view kCombinedConfigSha1(
+ "8d17eb7c2347fd4a8a9a2e0f171a91338fe4d5dd705829c39497608075a8d6fc");
+constexpr std::string_view kSplitConfigSha1(
+ "a6235491429b7b062e5da35c1d0d279c7e7e33cd70787f231d420ab831959744");
+
INSTANTIATE_TEST_CASE_P(
All, MultinodeLoggerTest,
- ::testing::Values(
- Param{
- "multinode_pingpong_combined_config.json", true,
- "47511a1906dbb59cf9f8ad98ad08e568c718a4deb204c8bbce81ff76cef9095c"},
- Param{"multinode_pingpong_split_config.json", false,
- "ce3ec411a089e5b80d6868bdb2ff8ce86467053b41469e50a09edf3c0110d80"
- "f"}));
+ ::testing::Values(Param{"multinode_pingpong_combined_config.json", true,
+ kCombinedConfigSha1},
+ Param{"multinode_pingpong_split_config.json", false,
+ kSplitConfigSha1}));
INSTANTIATE_TEST_CASE_P(
All, MultinodeLoggerDeathTest,
- ::testing::Values(
- Param{
- "multinode_pingpong_combined_config.json", true,
- "47511a1906dbb59cf9f8ad98ad08e568c718a4deb204c8bbce81ff76cef9095c"},
- Param{"multinode_pingpong_split_config.json", false,
- "ce3ec411a089e5b80d6868bdb2ff8ce86467053b41469e50a09edf3c0110d80"
- "f"}));
+ ::testing::Values(Param{"multinode_pingpong_combined_config.json", true,
+ kCombinedConfigSha1},
+ Param{"multinode_pingpong_split_config.json", false,
+ kSplitConfigSha1}));
// TODO(austin): Make a log file where the remote node has no start time.