Do less work when skipping timing reports
For some tests, the overhead of building up the table during startup is
a significant part of the runtime of the test. This speeds up one test
by 57% for example.
Change-Id: I370237510f8fcfe1c8a18395293f25fe44932f9e
Signed-off-by: Brian Silverman <brian.silverman@bluerivertech.com>
diff --git a/aos/events/event_loop.cc b/aos/events/event_loop.cc
index 644d998..51341bb 100644
--- a/aos/events/event_loop.cc
+++ b/aos/events/event_loop.cc
@@ -93,7 +93,7 @@
configuration_(configuration) {}
EventLoop::~EventLoop() {
- if(!senders_.empty()) {
+ if (!senders_.empty()) {
for (const RawSender *sender : senders_) {
LOG(ERROR) << " Sender "
<< configuration::StrippedChannelToString(sender->channel())
@@ -104,6 +104,31 @@
CHECK_EQ(events_.size(), 0u) << ": Not all events unregistered";
}
+void EventLoop::SkipTimingReport() {
+ skip_timing_report_ = true;
+ timing_report_ = flatbuffers::DetachedBuffer();
+
+ for (size_t i = 0; i < timers_.size(); ++i) {
+ timers_[i]->timing_.set_timing_report(nullptr);
+ }
+
+ for (size_t i = 0; i < phased_loops_.size(); ++i) {
+ phased_loops_[i]->timing_.set_timing_report(nullptr);
+ }
+
+ for (size_t i = 0; i < watchers_.size(); ++i) {
+ watchers_[i]->set_timing_report(nullptr);
+ }
+
+ for (size_t i = 0; i < senders_.size(); ++i) {
+ senders_[i]->timing_.set_timing_report(nullptr);
+ }
+
+ for (size_t i = 0; i < fetchers_.size(); ++i) {
+ fetchers_[i]->timing_.set_timing_report(nullptr);
+ }
+}
+
int EventLoop::ChannelIndex(const Channel *channel) {
return configuration::ChannelIndex(configuration_, channel);
}
@@ -240,6 +265,10 @@
}
void EventLoop::UpdateTimingReport() {
+ if (skip_timing_report_) {
+ return;
+ }
+
// We need to support senders and fetchers changing while we are setting up
// the event loop. Otherwise we can't fetch or send until the loop runs. This
// means that on each change, we need to redo all this work. This makes setup
@@ -528,13 +557,21 @@
}
void WatcherState::set_timing_report(timing::Watcher *watcher) {
- CHECK_NOTNULL(watcher);
watcher_ = watcher;
- wakeup_latency_.set_statistic(watcher->mutable_wakeup_latency());
- handler_time_.set_statistic(watcher->mutable_handler_time());
+ if (!watcher) {
+ wakeup_latency_.set_statistic(nullptr);
+ handler_time_.set_statistic(nullptr);
+ } else {
+ wakeup_latency_.set_statistic(watcher->mutable_wakeup_latency());
+ handler_time_.set_statistic(watcher->mutable_handler_time());
+ }
}
void WatcherState::ResetReport() {
+ if (!watcher_) {
+ return;
+ }
+
wakeup_latency_.Reset();
handler_time_.Reset();
watcher_->mutate_count(0);
diff --git a/aos/events/event_loop.h b/aos/events/event_loop.h
index 6f51fb0..cf17c2e 100644
--- a/aos/events/event_loop.h
+++ b/aos/events/event_loop.h
@@ -666,7 +666,7 @@
const Configuration *configuration() const { return configuration_; }
// Prevents the event loop from sending a timing report.
- void SkipTimingReport() { skip_timing_report_ = true; }
+ void SkipTimingReport();
// Prevents AOS_LOG being sent to message on /aos.
void SkipAosLog() { skip_logger_ = true; }
diff --git a/aos/events/event_loop_param_test.cc b/aos/events/event_loop_param_test.cc
index b976d8f..34d1c65 100644
--- a/aos/events/event_loop_param_test.cc
+++ b/aos/events/event_loop_param_test.cc
@@ -1958,6 +1958,57 @@
}
// Tests that a raw watcher and raw fetcher can receive messages from a raw
+// sender without messing up offsets, using the RawSpan overload.
+TEST_P(AbstractEventLoopTest, RawBasicSharedSpan) {
+ auto loop1 = Make();
+ auto loop2 = MakePrimary();
+ auto loop3 = Make();
+
+ const FlatbufferDetachedBuffer<TestMessage> kMessage =
+ JsonToFlatbuffer<TestMessage>("{}");
+
+ std::unique_ptr<aos::RawSender> sender =
+ loop1->MakeRawSender(configuration::GetChannel(
+ loop1->configuration(), "/test", "aos.TestMessage", "", nullptr));
+
+ std::unique_ptr<aos::RawFetcher> fetcher =
+ loop3->MakeRawFetcher(configuration::GetChannel(
+ loop3->configuration(), "/test", "aos.TestMessage", "", nullptr));
+
+ loop2->OnRun([&]() {
+ EXPECT_TRUE(sender->Send(std::make_shared<absl::Span<const uint8_t>>(
+ kMessage.span().data(), kMessage.span().size())));
+ });
+
+ bool happened = false;
+ loop2->MakeRawWatcher(
+ configuration::GetChannel(loop2->configuration(), "/test",
+ "aos.TestMessage", "", nullptr),
+ [this, &kMessage, &fetcher, &happened](const Context &context,
+ const void *message) {
+ happened = true;
+ EXPECT_EQ(
+ kMessage.span(),
+ absl::Span<const uint8_t>(
+ reinterpret_cast<const uint8_t *>(message), context.size));
+ EXPECT_EQ(message, context.data);
+
+ ASSERT_TRUE(fetcher->Fetch());
+
+ EXPECT_EQ(kMessage.span(),
+ absl::Span<const uint8_t>(reinterpret_cast<const uint8_t *>(
+ fetcher->context().data),
+ fetcher->context().size));
+
+ this->Exit();
+ });
+
+ EXPECT_FALSE(happened);
+ Run();
+ EXPECT_TRUE(happened);
+}
+
+// Tests that a raw watcher and raw fetcher can receive messages from a raw
// sender with remote times filled out.
TEST_P(AbstractEventLoopTest, RawRemoteTimes) {
auto loop1 = Make();
diff --git a/aos/events/event_loop_tmpl.h b/aos/events/event_loop_tmpl.h
index 7e560fe..1a02495 100644
--- a/aos/events/event_loop_tmpl.h
+++ b/aos/events/event_loop_tmpl.h
@@ -75,7 +75,9 @@
inline bool RawFetcher::FetchNext() {
const auto result = DoFetchNext();
if (result.first) {
- timing_.fetcher->mutate_count(timing_.fetcher->count() + 1);
+ if (timing_.fetcher) {
+ timing_.fetcher->mutate_count(timing_.fetcher->count() + 1);
+ }
const monotonic_clock::time_point monotonic_time = result.second;
ftrace_.FormatMessage(
"%.*s: fetch next: now=%" PRId64 " event=%" PRId64 " queue=%" PRIu32,
@@ -103,7 +105,9 @@
inline bool RawFetcher::Fetch() {
const auto result = DoFetch();
if (result.first) {
- timing_.fetcher->mutate_count(timing_.fetcher->count() + 1);
+ if (timing_.fetcher) {
+ timing_.fetcher->mutate_count(timing_.fetcher->count() + 1);
+ }
const monotonic_clock::time_point monotonic_time = result.second;
ftrace_.FormatMessage(
"%.*s: fetch latest: now=%" PRId64 " event=%" PRId64 " queue=%" PRIu32,
@@ -139,8 +143,10 @@
uint32_t remote_queue_index, const UUID &uuid) {
if (DoSend(size, monotonic_remote_time, realtime_remote_time,
remote_queue_index, uuid)) {
- timing_.size.Add(size);
- timing_.sender->mutate_count(timing_.sender->count() + 1);
+ if (timing_.sender) {
+ timing_.size.Add(size);
+ timing_.sender->mutate_count(timing_.sender->count() + 1);
+ }
ftrace_.FormatMessage(
"%.*s: sent internal: event=%" PRId64 " queue=%" PRIu32,
static_cast<int>(ftrace_prefix_.size()), ftrace_prefix_.data(),
@@ -163,8 +169,10 @@
uint32_t remote_queue_index, const UUID &uuid) {
if (DoSend(data, size, monotonic_remote_time, realtime_remote_time,
remote_queue_index, uuid)) {
- timing_.size.Add(size);
- timing_.sender->mutate_count(timing_.sender->count() + 1);
+ if (timing_.sender) {
+ timing_.size.Add(size);
+ timing_.sender->mutate_count(timing_.sender->count() + 1);
+ }
ftrace_.FormatMessage(
"%.*s: sent external: event=%" PRId64 " queue=%" PRIu32,
static_cast<int>(ftrace_prefix_.size()), ftrace_prefix_.data(),
@@ -188,8 +196,10 @@
const size_t size = data->size();
if (DoSend(std::move(data), monotonic_remote_time, realtime_remote_time,
remote_queue_index, uuid)) {
- timing_.size.Add(size);
- timing_.sender->mutate_count(timing_.sender->count() + 1);
+ if (timing_.sender) {
+ timing_.size.Add(size);
+ timing_.sender->mutate_count(timing_.sender->count() + 1);
+ }
ftrace_.FormatMessage(
"%.*s: sent shared: event=%" PRId64 " queue=%" PRIu32,
static_cast<int>(ftrace_prefix_.size()), ftrace_prefix_.data(),
@@ -203,7 +213,6 @@
inline monotonic_clock::time_point TimerHandler::Call(
std::function<monotonic_clock::time_point()> get_time,
monotonic_clock::time_point event_time) {
- CHECK_NOTNULL(timing_.timer);
const monotonic_clock::time_point monotonic_start_time = get_time();
event_loop_->SetTimerContext(event_time);
@@ -213,14 +222,14 @@
static_cast<int>(name_.size()), name_.data(),
static_cast<int64_t>(monotonic_start_time.time_since_epoch().count()),
static_cast<int64_t>(event_time.time_since_epoch().count()));
- {
+ if (timing_.timer) {
const float start_latency =
std::chrono::duration_cast<std::chrono::duration<float>>(
monotonic_start_time - event_time)
.count();
timing_.wakeup_latency.Add(start_latency);
+ timing_.timer->mutate_count(timing_.timer->count() + 1);
}
- timing_.timer->mutate_count(timing_.timer->count() + 1);
fn_();
const monotonic_clock::time_point monotonic_end_time = get_time();
@@ -256,14 +265,14 @@
static_cast<int64_t>(
phased_loop_.sleep_time().time_since_epoch().count()),
cycles_elapsed_);
- {
+ if (timing_.timer) {
const float start_latency =
std::chrono::duration_cast<std::chrono::duration<float>>(
monotonic_start_time - event_loop_->context_.monotonic_event_time)
.count();
timing_.wakeup_latency.Add(start_latency);
+ timing_.timer->mutate_count(timing_.timer->count() + 1);
}
- timing_.timer->mutate_count(timing_.timer->count() + 1);
// Call the function with the elapsed cycles.
fn_(cycles_elapsed_);
@@ -318,14 +327,14 @@
static_cast<int64_t>(
context.monotonic_event_time.time_since_epoch().count()),
context.queue_index);
- {
+ if (watcher_) {
const float start_latency =
std::chrono::duration_cast<std::chrono::duration<float>>(
monotonic_start_time - context.monotonic_event_time)
.count();
wakeup_latency_.Add(start_latency);
+ watcher_->mutate_count(watcher_->count() + 1);
}
- watcher_->mutate_count(watcher_->count() + 1);
fn_(context, context.data);
const monotonic_clock::time_point monotonic_end_time = get_time();
diff --git a/aos/events/timing_statistics.cc b/aos/events/timing_statistics.cc
index cdeb588..52f2048 100644
--- a/aos/events/timing_statistics.cc
+++ b/aos/events/timing_statistics.cc
@@ -7,35 +7,57 @@
namespace internal {
void RawFetcherTiming::set_timing_report(timing::Fetcher *new_fetcher) {
- CHECK_NOTNULL(new_fetcher);
fetcher = new_fetcher;
- latency.set_statistic(fetcher->mutable_latency());
+ if (!new_fetcher) {
+ latency.set_statistic(nullptr);
+ } else {
+ latency.set_statistic(fetcher->mutable_latency());
+ }
}
void RawFetcherTiming::ResetTimingReport() {
+ if (!fetcher) {
+ return;
+ }
+
latency.Reset();
fetcher->mutate_count(0);
}
void RawSenderTiming::set_timing_report(timing::Sender *new_sender) {
- CHECK_NOTNULL(new_sender);
sender = new_sender;
- size.set_statistic(sender->mutable_size());
+ if (!sender) {
+ size.set_statistic(nullptr);
+ } else {
+ size.set_statistic(sender->mutable_size());
+ }
}
void RawSenderTiming::ResetTimingReport() {
+ if (!sender) {
+ return;
+ }
+
size.Reset();
sender->mutate_count(0);
}
void TimerTiming::set_timing_report(timing::Timer *new_timer) {
- CHECK_NOTNULL(new_timer);
timer = new_timer;
- wakeup_latency.set_statistic(timer->mutable_wakeup_latency());
- handler_time.set_statistic(timer->mutable_handler_time());
+ if (!timer) {
+ wakeup_latency.set_statistic(nullptr);
+ handler_time.set_statistic(nullptr);
+ } else {
+ wakeup_latency.set_statistic(timer->mutable_wakeup_latency());
+ handler_time.set_statistic(timer->mutable_handler_time());
+ }
}
void TimerTiming::ResetTimingReport() {
+ if (!timer) {
+ return;
+ }
+
wakeup_latency.Reset();
handler_time.Reset();
timer->mutate_count(0);
diff --git a/aos/events/timing_statistics.h b/aos/events/timing_statistics.h
index ad0534a..4d9a524 100644
--- a/aos/events/timing_statistics.h
+++ b/aos/events/timing_statistics.h
@@ -18,6 +18,10 @@
// Adds a sample to the statistic.
void Add(float sample) {
+ if (!statistic_) {
+ return;
+ }
+
++count_;
if (count_ == 1) {
statistic_->mutate_average(sample);
@@ -39,6 +43,10 @@
// Clears any accumulated statistics.
void Reset() {
+ if (!statistic_) {
+ return;
+ }
+
statistic_->mutate_average(std::numeric_limits<float>::quiet_NaN());
statistic_->mutate_min(std::numeric_limits<float>::quiet_NaN());
statistic_->mutate_max(std::numeric_limits<float>::quiet_NaN());