Handle local messages sent before remote messages after reboot
We only generate points in the time interpolation function (and
therefore only discover reboots, since a reboot can only happen at a
point). When there is data in a log before remote data, we don't
generate these points, and therefore can't replay the log.
F1118 00:05:39.808653 14 log_reader.cc:690] Check failed: monotonic_now == timestamped_message.monotonic_event_time.time : { "name": "pi2", "hostname": "raspberrypi2", "port": 9971 } Now 107.005000000sec trying to send {.boot=1, .time=107.000000000sec} failure node 1 (pi2) [
] queued_until {.boot=1, .time=109.210150000sec}
node 0 remote_data [
channel 0 [
{.channel_index=3, .queue_index={.boot=0, .index=91}, .timestamp={.boot=0, .time=9.200000000sec}, .data=0x555c65f23f80}
]
channel 1 [
{.channel_index=20, .queue_index={.boot=0, .index=622}, .timestamp={.boot=0, .time=9.210000000sec}, .data=0x555c66126a90}
]
] queued_until {.boot=0, .time=9.210350000sec}
*** Check failure stack trace: ***
@ 0x7fd804015aef google::LogMessageFatal::~LogMessageFatal()
@ 0x7fd8045a7069 aos::logger::LogReader::RegisterDuringStartup()::$_3::operator()()
@ 0x7fd804258119 aos::TimerHandler::Call()
@ 0x7fd804257ead aos::SimulatedTimerHandler::HandleEvent()
@ 0x7fd804263fb1 std::_Function_handler<>::_M_invoke()
@ 0x7fd804252c18 aos::EventScheduler::CallOldestEvent()
@ 0x7fd804253f54 aos::EventSchedulerScheduler::Run()
@ 0x7fd80425b472 aos::SimulatedEventLoopFactory::Run()
@ 0x555c641e780f aos::logger::testing::ConfirmReadable()
@ 0x555c6421507f aos::logger::testing::MultinodeRebootLoggerTest_LocalMessageBeforeRemoteBeforeStartAfterReboot_Test::TestBody()
@ 0x7fd803fa0ce4 testing::internal::HandleExceptionsInMethodIfSupported<>()
@ 0x7fd803fa0c21 testing::Test::Run()
@ 0x7fd803fa1fdf testing::TestInfo::Run()
@ 0x7fd803fa2b07 testing::TestSuite::Run()
@ 0x7fd803fb4d17 testing::internal::UnitTestImpl::RunAllTests()
@ 0x7fd803fb4634 testing::internal::HandleExceptionsInMethodIfSupported<>()
@ 0x7fd803fb44bb testing::UnitTest::Run()
@ 0x7fd804065010 main
@ 0x7fd803aa4d0a __libc_start_main
@ 0x555c641e132a _start
The fix is to generate a point for the first local timestamp too.
Change-Id: Ic1090d35375fce295d91bccc53f0d3ca8e472770
Signed-off-by: Austin Schuh <austin.linux@gmail.com>
diff --git a/aos/events/logging/logfile_utils.h b/aos/events/logging/logfile_utils.h
index 4c82e4d..ccd8bd7 100644
--- a/aos/events/logging/logfile_utils.h
+++ b/aos/events/logging/logfile_utils.h
@@ -550,6 +550,9 @@
realtime_clock::time_point realtime_start_time() const {
return realtime_start_time_;
}
+ monotonic_clock::time_point monotonic_oldest_time() const {
+ return monotonic_oldest_time_;
+ }
// The time this data is sorted until.
monotonic_clock::time_point sorted_until() const { return sorted_until_; }
@@ -579,6 +582,7 @@
realtime_clock::time_point realtime_start_time_ = realtime_clock::max_time;
monotonic_clock::time_point monotonic_start_time_ = monotonic_clock::max_time;
+ monotonic_clock::time_point monotonic_oldest_time_ = monotonic_clock::max_time;
};
// Class to concatenate multiple boots worth of logs into a single per-node
@@ -612,6 +616,10 @@
CHECK_LT(boot, node_mergers_.size());
return node_mergers_[boot]->realtime_start_time();
}
+ monotonic_clock::time_point monotonic_oldest_time(size_t boot) const {
+ CHECK_LT(boot, node_mergers_.size());
+ return node_mergers_[boot]->monotonic_oldest_time();
+ }
bool started() const {
return node_mergers_[index_]->sorted_until() != monotonic_clock::min_time ||
@@ -665,6 +673,10 @@
realtime_clock::time_point realtime_start_time(size_t boot) const {
return boot_merger_.realtime_start_time(boot);
}
+ // Returns the oldest timestamp on a message on this boot.
+ monotonic_clock::time_point monotonic_oldest_time(size_t boot) const {
+ return boot_merger_.monotonic_oldest_time(boot);
+ }
// Uses timestamp_mapper as the peer for its node. Only one mapper may be set
// for each node. Peers are used to look up the data for timestamps on this