Warn when a channel isn't logged and terminates reading a log
The Galactic search path message was forwarded to the roboRIO but wasn't
logged. The end result was that we stopped replaying the log when we
found the first Galactic search path timestamp. It was very confusing
to debug.
The fix is 2 fold.
1) Log the message.
2) Warn in log_reader that this is happening to make it much faster to
debug.
Change-Id: I4ae48311e4e514e941644bd8d42fd30382b38522
diff --git a/aos/configuration.cc b/aos/configuration.cc
index 36868c4..25d59ff 100644
--- a/aos/configuration.cc
+++ b/aos/configuration.cc
@@ -1039,21 +1039,25 @@
}
bool ChannelMessageIsLoggedOnNode(const Channel *channel, const Node *node) {
+ if (channel->logger() == LoggerConfig::LOCAL_LOGGER && node == nullptr) {
+ // Single node world. If there is a local logger, then we want to use
+ // it.
+ return true;
+ }
+ return ChannelMessageIsLoggedOnNode(
+ channel, CHECK_NOTNULL(node)->name()->string_view());
+}
+
+bool ChannelMessageIsLoggedOnNode(const Channel *channel,
+ std::string_view node_name) {
switch (channel->logger()) {
case LoggerConfig::LOCAL_LOGGER:
- if (node == nullptr) {
- // Single node world. If there is a local logger, then we want to use
- // it.
- return true;
- }
- return channel->source_node()->string_view() ==
- node->name()->string_view();
+ return channel->source_node()->string_view() == node_name;
case LoggerConfig::LOCAL_AND_REMOTE_LOGGER:
CHECK(channel->has_logger_nodes());
CHECK_GT(channel->logger_nodes()->size(), 0u);
- if (channel->source_node()->string_view() ==
- CHECK_NOTNULL(node)->name()->string_view()) {
+ if (channel->source_node()->string_view() == node_name) {
return true;
}
@@ -1062,8 +1066,7 @@
CHECK(channel->has_logger_nodes());
CHECK_GT(channel->logger_nodes()->size(), 0u);
for (const flatbuffers::String *logger_node : *channel->logger_nodes()) {
- if (logger_node->string_view() ==
- CHECK_NOTNULL(node)->name()->string_view()) {
+ if (logger_node->string_view() == node_name) {
return true;
}
}
diff --git a/aos/configuration.h b/aos/configuration.h
index 88af5fe..c6d25df 100644
--- a/aos/configuration.h
+++ b/aos/configuration.h
@@ -125,6 +125,8 @@
// Returns true if the message is supposed to be logged on this node.
bool ChannelMessageIsLoggedOnNode(const Channel *channel, const Node *node);
+bool ChannelMessageIsLoggedOnNode(const Channel *channel,
+ std::string_view node_name);
const Connection *ConnectionToNode(const Channel *channel, const Node *node);
// Returns true if the delivery timestamps are supposed to be logged on this
diff --git a/aos/events/logging/log_reader.cc b/aos/events/logging/log_reader.cc
index 91bb93f..2eb3094 100644
--- a/aos/events/logging/log_reader.cc
+++ b/aos/events/logging/log_reader.cc
@@ -649,6 +649,42 @@
VLOG(1) << "Found the last message on channel "
<< timestamped_message.channel_index;
+ // The user might be working with log files from 1 node but forgot to
+ // configure the infrastructure to log data for a remote channel on that
+ // node. That can be very hard to debug, even though the log reader is
+ // doing the right thing. At least log a warning in that case and tell
+ // the user what is happening so they can either update their config to
+ // log the channel or can find a log with the data.
+ {
+ const std::vector<std::string> logger_nodes =
+ FindLoggerNodes(log_files_);
+ if (logger_nodes.size()) {
+ // We have old logs which don't have the logger nodes logged. In
+ // that case, we can't be helpful :(
+ bool data_logged = false;
+ const Channel *channel = logged_configuration()->channels()->Get(
+ timestamped_message.channel_index);
+ for (const std::string &node : logger_nodes) {
+ data_logged |=
+ configuration::ChannelMessageIsLoggedOnNode(channel, node);
+ }
+ if (!data_logged) {
+ LOG(WARNING) << "Got a timestamp without any logfiles which "
+ "could contain data for channel "
+ << configuration::CleanedChannelToString(channel);
+ LOG(WARNING) << "Only have logs logged on ["
+ << absl::StrJoin(logger_nodes, ", ") << "]";
+ LOG(WARNING)
+ << "Dropping the rest of the data on "
+ << state->event_loop()->node()->name()->string_view();
+ LOG(WARNING)
+ << "Consider using --skip_missing_forwarding_entries to "
+ "bypass this, update your config to log it, or add data "
+ "from one of the nodes it is logged on.";
+ }
+ }
+ }
+
// Vector storing if we've seen a nullptr message or not per channel.
std::vector<bool> last_message;
last_message.resize(logged_configuration()->channels()->size(), false);
diff --git a/aos/events/logging/logfile_sorting.cc b/aos/events/logging/logfile_sorting.cc
index 9e406e9..892dd2e 100644
--- a/aos/events/logging/logfile_sorting.cc
+++ b/aos/events/logging/logfile_sorting.cc
@@ -538,6 +538,18 @@
return node_list;
}
+std::vector<std::string> FindLoggerNodes(const std::vector<LogFile> &parts) {
+ std::set<std::string> nodes;
+ for (const LogFile &log_file : parts) {
+ nodes.insert(log_file.logger_node);
+ }
+ std::vector<std::string> node_list;
+ while (!nodes.empty()) {
+ node_list.emplace_back(nodes.extract(nodes.begin()).value());
+ }
+ return node_list;
+}
+
std::vector<LogParts> FilterPartsForNode(const std::vector<LogFile> &parts,
std::string_view node) {
std::vector<LogParts> result;
diff --git a/aos/events/logging/logfile_sorting.h b/aos/events/logging/logfile_sorting.h
index 95a6431..8dee3da 100644
--- a/aos/events/logging/logfile_sorting.h
+++ b/aos/events/logging/logfile_sorting.h
@@ -89,6 +89,9 @@
std::vector<LogParts> FilterPartsForNode(const std::vector<LogFile> &parts,
std::string_view node);
+// Finds all the nodes on which the loggers which generated these log files ran.
+std::vector<std::string> FindLoggerNodes(const std::vector<LogFile> &parts);
+
// Recursively searches the file/folder for .bfbs and .bfbs.xz files and adds
// them to the vector.
void FindLogs(std::vector<std::string> *files, std::string filename);
diff --git a/aos/network/multinode_timestamp_filter.cc b/aos/network/multinode_timestamp_filter.cc
index 3424628..4b6a44b 100644
--- a/aos/network/multinode_timestamp_filter.cc
+++ b/aos/network/multinode_timestamp_filter.cc
@@ -267,7 +267,7 @@
std::vector<monotonic_clock::time_point>>>
next_time = NextTimestamp();
if (!next_time) {
- LOG(INFO) << "Last timestamp, calling it quits";
+ VLOG(1) << "Last timestamp, calling it quits";
at_end_ = true;
break;
}
diff --git a/y2020/y2020_pi_template.json b/y2020/y2020_pi_template.json
index d5c97d3..47d576a 100644
--- a/y2020/y2020_pi_template.json
+++ b/y2020/y2020_pi_template.json
@@ -105,6 +105,8 @@
"name": "/pi{{ NUM }}/camera",
"type": "y2020.vision.GalacticSearchPath",
"source_node": "pi{{ NUM }}",
+ "logger": "LOCAL_AND_REMOTE_LOGGER",
+ "logger_nodes": ["roborio"],
"max_size" : 104,
"destination_nodes": [
{