Set NodeEventLoopFactory boot_uuid to logged boot_uuid
Previously, we couldn't replay relogged logfiles because they
did not correctly track the boot uuid from the ServerStatistics message,
which was very unfortunate. Since the goal of replay is to reproduce
the state of the world when we were running, set the simulated boot UUID
to match what was logged.
I still don't seem to be able to fully replay relogged files (see
comments in drivetrain_replay.cc), but I think that those issues are
likely independent of this particular problem and I haven't yet written
a test to conveniently reproduce it.
Change-Id: I121ea4001e6fee7595b4fe1a2b200ffa1ae9bd40
diff --git a/aos/events/logging/logger.cc b/aos/events/logging/logger.cc
index 2e0f5db..5f01aab 100644
--- a/aos/events/logging/logger.cc
+++ b/aos/events/logging/logger.cc
@@ -998,6 +998,9 @@
CHECK(!HasChannel<RemoteMessage>(channel, node))
<< ": Can't have both a MessageHeader and RemoteMessage remote "
"timestamp channel.";
+ // In theory, we should check NOT_LOGGED like RemoteMessage and be more
+ // careful about updating the config, but there are fewer and fewer logs
+ // with MessageHeader remote messages, so it isn't worth the effort.
RemapLoggedChannel<MessageHeader>(channel, node, "/original",
"aos.message_bridge.RemoteMessage");
} else {
@@ -1005,7 +1008,13 @@
<< ": Failed to find {\"name\": \"" << channel << "\", \"type\": \""
<< RemoteMessage::GetFullyQualifiedName() << "\"} for node "
<< node->name()->string_view();
- RemapLoggedChannel<RemoteMessage>(channel, node);
+ // Only bother to remap if there's something on the channel. We can
+ // tell if the channel was marked NOT_LOGGED or not. This makes the
+ // config not change un-necesarily when we replay a log with NOT_LOGGED
+ // messages.
+ if (HasLoggedChannel<RemoteMessage>(channel, node)) {
+ RemapLoggedChannel<RemoteMessage>(channel, node);
+ }
}
}
}
@@ -1119,6 +1128,10 @@
<< ": Found parts from different boots "
<< LogFileVectorToString(log_files_);
}
+ if (!filtered_parts[0].source_boot_uuid.empty()) {
+ event_loop_factory_->GetNodeEventLoopFactory(node)->set_boot_uuid(
+ filtered_parts[0].source_boot_uuid);
+ }
}
states_[node_index] = std::make_unique<State>(
diff --git a/aos/events/logging/logger.h b/aos/events/logging/logger.h
index 4213066..4b83654 100644
--- a/aos/events/logging/logger.h
+++ b/aos/events/logging/logger.h
@@ -460,6 +460,16 @@
true) != nullptr;
}
+ // Returns true if the channel exists on the node and was logged.
+ template <typename T>
+ bool HasLoggedChannel(std::string_view name, const Node *node = nullptr) {
+ const Channel *channel = configuration::GetChannel(logged_configuration(), name,
+ T::GetFullyQualifiedName(), "", node,
+ true);
+ if (channel == nullptr) return false;
+ return channel->logger() != LoggerConfig::NOT_LOGGED;
+ }
+
SimulatedEventLoopFactory *event_loop_factory() {
return event_loop_factory_;
}
diff --git a/aos/events/logging/logger_test.cc b/aos/events/logging/logger_test.cc
index 16fb2ab..56c3bb0 100644
--- a/aos/events/logging/logger_test.cc
+++ b/aos/events/logging/logger_test.cc
@@ -30,7 +30,7 @@
constexpr std::string_view kSingleConfigSha1(
"bc8c9c2e31589eae6f0e36d766f6a437643e861d9568b7483106841cf7504dea");
constexpr std::string_view kConfigSha1(
- "0000c81e444ac470b8d29fb864621ae93a0e294a7e90c0dc4840d0f0d40fd72e");
+ "f59be0b208c3feab512abac12720b53166303b382b39806e2beeb46e3b9d2a4a");
class LoggerTest : public ::testing::Test {
public:
@@ -805,6 +805,10 @@
CountChannelsData(config, logfiles_[0]),
UnorderedElementsAre(
std::make_tuple("/pi1/aos", "aos.message_bridge.Timestamp", 200),
+ std::make_tuple("/pi1/aos", "aos.message_bridge.ServerStatistics",
+ 21),
+ std::make_tuple("/pi1/aos", "aos.message_bridge.ClientStatistics",
+ 200),
std::make_tuple("/pi1/aos", "aos.timing.Report", 40),
std::make_tuple("/test", "aos.examples.Ping", 2001)))
<< " : " << logfiles_[0];
@@ -839,6 +843,10 @@
CountChannelsData(config, logfiles_[3]),
UnorderedElementsAre(
std::make_tuple("/pi2/aos", "aos.message_bridge.Timestamp", 200),
+ std::make_tuple("/pi2/aos", "aos.message_bridge.ServerStatistics",
+ 21),
+ std::make_tuple("/pi2/aos", "aos.message_bridge.ClientStatistics",
+ 200),
std::make_tuple("/pi2/aos", "aos.timing.Report", 40),
std::make_tuple("/test", "aos.examples.Pong", 2001)))
<< " : " << logfiles_[3];
@@ -1595,11 +1603,6 @@
std::unique_ptr<EventLoop> pi2_event_loop =
log_reader_factory.MakeEventLoop("test", pi2);
- MessageCounter<RemoteMessage> pi1_original_message_header_counter(
- pi1_event_loop.get(), "/original/aos/remote_timestamps/pi2");
- MessageCounter<RemoteMessage> pi2_original_message_header_counter(
- pi2_event_loop.get(), "/original/aos/remote_timestamps/pi1");
-
aos::Fetcher<message_bridge::Timestamp> pi1_timestamp_on_pi1_fetcher =
pi1_event_loop->MakeFetcher<message_bridge::Timestamp>("/pi1/aos");
aos::Fetcher<message_bridge::Timestamp> pi1_timestamp_on_pi2_fetcher =
@@ -1772,10 +1775,17 @@
log_reader_factory.Run();
}
- EXPECT_EQ(pi2_original_message_header_counter.count(), 0u);
- EXPECT_EQ(pi1_original_message_header_counter.count(), 0u);
-
reader.Deregister();
+
+ // And verify that we can run the LogReader over the relogged files without
+ // hitting any fatal errors.
+ {
+ LogReader relogged_reader(SortParts(
+ MakeLogFiles(tmp_dir_ + "/relogged1", tmp_dir_ + "/relogged2")));
+ relogged_reader.Register();
+
+ relogged_reader.event_loop_factory()->Run();
+ }
}
// Tests that we properly populate and extract the logger_start time by setting
diff --git a/aos/events/logging/multinode_pingpong.json b/aos/events/logging/multinode_pingpong.json
index fde7525..9b502cf 100644
--- a/aos/events/logging/multinode_pingpong.json
+++ b/aos/events/logging/multinode_pingpong.json
@@ -36,25 +36,25 @@
{
"name": "/pi1/aos",
"type": "aos.message_bridge.ServerStatistics",
- "logger": "NOT_LOGGED",
+ "logger": "LOCAL_LOGGER",
"source_node": "pi1"
},
{
"name": "/pi2/aos",
"type": "aos.message_bridge.ServerStatistics",
- "logger": "NOT_LOGGED",
+ "logger": "LOCAL_LOGGER",
"source_node": "pi2"
},
{
"name": "/pi1/aos",
"type": "aos.message_bridge.ClientStatistics",
- "logger": "NOT_LOGGED",
+ "logger": "LOCAL_LOGGER",
"source_node": "pi1"
},
{
"name": "/pi2/aos",
"type": "aos.message_bridge.ClientStatistics",
- "logger": "NOT_LOGGED",
+ "logger": "LOCAL_LOGGER",
"source_node": "pi2"
},
{
diff --git a/aos/events/simulated_event_loop.cc b/aos/events/simulated_event_loop.cc
index 750df39..61888e7 100644
--- a/aos/events/simulated_event_loop.cc
+++ b/aos/events/simulated_event_loop.cc
@@ -120,9 +120,12 @@
latest_message_.reset();
CHECK_EQ(static_cast<size_t>(number_buffers()),
available_buffer_indices_.size());
- CHECK_EQ(0u, fetchers_.size());
- CHECK_EQ(0u, watchers_.size());
- CHECK_EQ(0, sender_count_);
+ CHECK_EQ(0u, fetchers_.size())
+ << configuration::StrippedChannelToString(channel());
+ CHECK_EQ(0u, watchers_.size())
+ << configuration::StrippedChannelToString(channel());
+ CHECK_EQ(0, sender_count_)
+ << configuration::StrippedChannelToString(channel());
}
// The number of messages we pretend to have in the queue.
diff --git a/aos/events/simulated_event_loop.h b/aos/events/simulated_event_loop.h
index 4a2b289..b0e52bc 100644
--- a/aos/events/simulated_event_loop.h
+++ b/aos/events/simulated_event_loop.h
@@ -184,6 +184,11 @@
time_converter);
}
+ // Sets the boot UUID for this node. This typically should only be used by
+ // the log reader.
+ void set_boot_uuid(std::string_view uuid) {
+ boot_uuid_ = UUID::FromString(uuid);
+ }
// Returns the boot UUID for this node.
const UUID &boot_uuid() const { return boot_uuid_; }
diff --git a/y2020/control_loops/drivetrain/drivetrain_replay.cc b/y2020/control_loops/drivetrain/drivetrain_replay.cc
index 59c2a52..1acdce4 100644
--- a/y2020/control_loops/drivetrain/drivetrain_replay.cc
+++ b/y2020/control_loops/drivetrain/drivetrain_replay.cc
@@ -17,9 +17,35 @@
DEFINE_string(config, "y2020/config.json",
"Name of the config file to replay using.");
-DEFINE_string(output_file, "/tmp/replayed.bfbs",
- "Name of the logfile to write replayed data to.");
+DEFINE_string(output_file, "/tmp/replayed",
+ "Name of the folder to write replayed logs to.");
DEFINE_int32(team, 971, "Team number to use for logfile replay.");
+
+class LoggerState {
+ public:
+ LoggerState(aos::logger::LogReader *reader, const aos::Node *node)
+ : event_loop_(
+ reader->event_loop_factory()->MakeEventLoop("logger", node)),
+ namer_(std::make_unique<aos::logger::MultiNodeLogNamer>(
+ absl::StrCat(FLAGS_output_file, "/", node->name()->string_view(),
+ "/"),
+ event_loop_->configuration(), node)),
+ logger_(std::make_unique<aos::logger::Logger>(event_loop_.get())) {
+ event_loop_->SkipTimingReport();
+ event_loop_->OnRun([this]() {
+ logger_->StartLogging(std::move(namer_), aos::UUID::Zero().string_view());
+ });
+ }
+
+ private:
+ std::unique_ptr<aos::EventLoop> event_loop_;
+ std::unique_ptr<aos::logger::LogNamer> namer_;
+ std::unique_ptr<aos::logger::Logger> logger_;
+};
+
+// TODO(james): Currently, this replay produces logfiles that can't be read due
+// to time estimation issues. Pending the active refactorings of the
+// timestamp-related code, fix this.
int main(int argc, char **argv) {
aos::InitGoogle(&argc, &argv);
@@ -33,7 +59,8 @@
aos::logger::FindLogs(argc, argv);
// sort logfiles
- const std::vector<aos::logger::LogFile> logfiles = aos::logger::SortParts(unsorted_logfiles);
+ const std::vector<aos::logger::LogFile> logfiles =
+ aos::logger::SortParts(unsorted_logfiles);
// open logfiles
aos::logger::LogReader reader(logfiles, &config.message());
@@ -45,28 +72,22 @@
"frc971.control_loops.drivetrain.Output");
reader.Register();
+ // List of nodes to create loggers for (note: currently just roborio; this
+ // code was refactored to allow easily adding new loggers to accommodate
+ // debugging and potential future changes).
+ const std::vector<std::string> nodes_to_log = {"roborio"};
+ std::vector<std::unique_ptr<LoggerState>> loggers;
+ for (const std::string& node : nodes_to_log) {
+ loggers.emplace_back(std::make_unique<LoggerState>(
+ &reader,
+ aos::configuration::GetNode(reader.configuration(), node)));
+ }
+
const aos::Node *node = nullptr;
if (aos::configuration::MultiNode(reader.configuration())) {
node = aos::configuration::GetNode(reader.configuration(), "roborio");
}
- std::unique_ptr<aos::EventLoop> log_writer_event_loop =
- reader.event_loop_factory()->MakeEventLoop("log_writer", node);
- log_writer_event_loop->SkipTimingReport();
- aos::logger::Logger writer(log_writer_event_loop.get());
-
-
- std::unique_ptr<aos::logger::LogNamer> log_namer;
- log_namer = std::make_unique<aos::logger::MultiNodeLogNamer>(
- absl::StrCat(FLAGS_output_file, "/"),
- log_writer_event_loop->configuration(),
- log_writer_event_loop->node());
-
- aos::logger::Logger logger(log_writer_event_loop.get());
- log_writer_event_loop->OnRun([&log_namer, &logger]() {
- logger.StartLogging(std::move(log_namer));
- });
-
std::unique_ptr<aos::EventLoop> drivetrain_event_loop =
reader.event_loop_factory()->MakeEventLoop("drivetrain", node);
drivetrain_event_loop->SkipTimingReport();