Handle offset change in PhasedLoop and PhasedLoopHandler

When the PhasedLoop offset_ is changed, the last_time_ must be adjusted
to have an even interval. Additionally, in the PhaseLoopHandler Call
method, schedule has to be called after fn_ because if fn_ changes
the offset then it will not be updated on the next callback since
schedule has already scheduled the next time.

Change-Id: I12110134f00ee948f986e0df9f8304fbc2b08c31
Signed-off-by: milind <milind.upadhyay@gmail.com>
diff --git a/aos/events/event_loop.cc b/aos/events/event_loop.cc
index 08fa7fd..29e4c22 100644
--- a/aos/events/event_loop.cc
+++ b/aos/events/event_loop.cc
@@ -70,9 +70,9 @@
           Schedule(sleep_time);
         },
         monotonic_now);
-    // The first time, we'll double count.  Reschedule here will count cycles
-    // elapsed before now, and then the reschedule before runing the handler
-    // will count the time that elapsed then.  So clear the count here.
+    // Reschedule here will count cycles elapsed before now, and then the
+    // reschedule before running the handler will count the time that elapsed
+    // then. So clear the count here.
     cycles_elapsed_ = 0;
   });
 }
diff --git a/aos/events/event_loop_param_test.cc b/aos/events/event_loop_param_test.cc
index ee77b8a..0e9ad4c 100644
--- a/aos/events/event_loop_param_test.cc
+++ b/aos/events/event_loop_param_test.cc
@@ -1549,6 +1549,103 @@
   }
 }
 
+// Tests that a phased loop responds correctly to a changing offset.
+TEST_P(AbstractEventLoopTest, PhasedLoopChangingOffsetTest) {
+  // Force a slower rate so we are guaranteed to have reports for our phased
+  // loop.
+  FLAGS_timing_report_ms = 2000;
+
+  const chrono::milliseconds kOffset = chrono::milliseconds(400);
+  const chrono::milliseconds kInterval = chrono::milliseconds(1000);
+  const int kCount = 5;
+
+  auto loop1 = MakePrimary();
+
+  // Collect up a couple of samples.
+  ::std::vector<::aos::monotonic_clock::time_point> times;
+  ::std::vector<::aos::monotonic_clock::time_point> expected_times;
+
+  PhasedLoopHandler *phased_loop;
+
+  // Run kCount iterations.
+  phased_loop = loop1->AddPhasedLoop(
+      [&phased_loop, &times, &expected_times, &loop1, this, kOffset,
+       kInterval](int count) {
+        EXPECT_EQ(count, 1);
+        times.push_back(loop1->monotonic_now());
+
+        expected_times.push_back(loop1->context().monotonic_event_time);
+
+        phased_loop->set_interval_and_offset(
+            kInterval, kOffset - chrono::milliseconds(times.size()));
+        LOG(INFO) << "new offset: "
+                  << (kOffset - chrono::milliseconds(times.size())).count();
+
+        if (times.size() == kCount) {
+          LOG(INFO) << "Exiting";
+          this->Exit();
+        }
+      },
+      kInterval, kOffset);
+  phased_loop->set_name("Test loop");
+
+  // Add a delay to make sure that delay during startup doesn't result in a
+  // "missed cycle".
+  SleepFor(chrono::seconds(2));
+
+  Run();
+  // Confirm that we got both the right number of samples, and it's odd.
+  EXPECT_EQ(times.size(), static_cast<size_t>(kCount));
+  EXPECT_EQ(times.size(), expected_times.size());
+  EXPECT_EQ((times.size() % 2), 1);
+
+  // Grab the middle sample.
+  ::aos::monotonic_clock::time_point average_time = times[times.size() / 2];
+
+  // Add up all the delays of all the times.
+  ::aos::monotonic_clock::duration sum = chrono::seconds(0);
+  for (const ::aos::monotonic_clock::time_point time : times) {
+    sum += time - average_time;
+  }
+
+  // Average and add to the middle to find the average time.
+  sum /= times.size();
+  average_time += sum;
+
+  // Compute the offset from the start of the second of the average time.  This
+  // should be pretty close to the offset.
+  const ::aos::monotonic_clock::duration remainder =
+      average_time.time_since_epoch() -
+      chrono::duration_cast<chrono::seconds>(average_time.time_since_epoch());
+
+  const chrono::milliseconds kEpsilon(100);
+  EXPECT_LT(remainder, kOffset + kEpsilon);
+  EXPECT_GT(remainder, kOffset - kEpsilon);
+
+  // Make sure that the average duration is close to 1 second.
+  EXPECT_NEAR(chrono::duration_cast<chrono::duration<double>>(times.back() -
+                                                              times.front())
+                      .count() /
+                  static_cast<double>(times.size() - 1),
+              1.0, 0.1);
+
+  // Confirm that the ideal wakeup times increment correctly.
+  for (size_t i = 1; i < expected_times.size(); ++i) {
+    LOG(INFO) << i - 1 << ": " << expected_times[i - 1] << ", " << i << ": "
+              << expected_times[i];
+    EXPECT_EQ(expected_times[i], expected_times[i - 1] + chrono::seconds(1) -
+                                     chrono::milliseconds(1));
+  }
+
+  for (size_t i = 0; i < expected_times.size(); ++i) {
+    EXPECT_EQ(expected_times[i].time_since_epoch() % chrono::seconds(1),
+              kOffset - chrono::milliseconds(i));
+  }
+
+  EXPECT_LT(expected_times[expected_times.size() / 2], average_time + kEpsilon);
+  EXPECT_GT(expected_times[expected_times.size() / 2], average_time - kEpsilon);
+}
+
 // Tests that senders count correctly in the timing report.
 TEST_P(AbstractEventLoopTest, SenderTimingReport) {
   FLAGS_timing_report_ms = 1000;
diff --git a/aos/events/event_loop_tmpl.h b/aos/events/event_loop_tmpl.h
index d6922de..c7f7c01 100644
--- a/aos/events/event_loop_tmpl.h
+++ b/aos/events/event_loop_tmpl.h
@@ -238,8 +238,8 @@
   event_loop_->context_.buffer_index = -1;
   event_loop_->context_.remote_boot_uuid = event_loop_->boot_uuid();
 
-  // Compute how many cycles elapsed and schedule the next wakeup.
-  Reschedule(schedule, monotonic_start_time);
+  // Compute how many cycles elapsed
+  cycles_elapsed_ += phased_loop_.Iterate(monotonic_start_time);
 
   ftrace_.FormatMessage(
       "phased: %.*s: start now=%" PRId64 " event=%" PRId64 " cycles=%d",
@@ -261,6 +261,9 @@
   fn_(cycles_elapsed_);
   cycles_elapsed_ = 0;
 
+  // Schedule the next wakeup.
+  schedule(phased_loop_.sleep_time());
+
   const monotonic_clock::time_point monotonic_end_time = get_time();
   ftrace_.FormatMessage(
       "phased: %.*s: end now=%" PRId64, static_cast<int>(name_.size()),
diff --git a/aos/util/phased_loop.cc b/aos/util/phased_loop.cc
index 1e520b1..53f6f4d 100644
--- a/aos/util/phased_loop.cc
+++ b/aos/util/phased_loop.cc
@@ -18,6 +18,9 @@
 void PhasedLoop::set_interval_and_offset(
     const monotonic_clock::duration interval,
     const monotonic_clock::duration offset) {
+  // Update last_time_ to the new offset so that we have an even interval
+  last_time_ += offset - offset_;
+
   interval_ = interval;
   offset_ = offset;
   CHECK(offset_ >= monotonic_clock::duration(0));
@@ -55,6 +58,7 @@
   next_time += offset_;
 
   const monotonic_clock::duration difference = next_time - last_time_;
+
   const int result = difference / interval_;
   CHECK_EQ(
       0, (next_time - offset_).time_since_epoch().count() % interval_.count());
@@ -64,5 +68,5 @@
   return result;
 }
 
-}  // namespace timing
+}  // namespace time
 }  // namespace aos
diff --git a/aos/util/phased_loop_test.cc b/aos/util/phased_loop_test.cc
index 1c766c4..96eeb5c 100644
--- a/aos/util/phased_loop_test.cc
+++ b/aos/util/phased_loop_test.cc
@@ -217,6 +217,39 @@
   }
 }
 
+// Tests that the phased loop is correctly adjusting when the offset is
+// decremented multiple times.
+TEST_F(PhasedLoopTest, DecrementingOffset) {
+  constexpr int kCount = 5;
+  constexpr int kIterations = 10;
+  const auto kOffset = milliseconds(400);
+  const auto kInterval = milliseconds(1000);
+  const auto kAllIterationsInterval = kInterval * kIterations;
+
+  PhasedLoop loop(kInterval, monotonic_clock::epoch(), kOffset);
+  auto last_time = monotonic_clock::epoch() + kOffset + (kInterval * 3);
+  ASSERT_EQ(5, loop.Iterate(last_time));
+  for (int i = 1; i < kCount; i++) {
+    const auto offset = kOffset - milliseconds(i);
+    loop.set_interval_and_offset(kInterval, offset);
+    const auto next_time = last_time - milliseconds(1) + kAllIterationsInterval;
+    EXPECT_EQ(kIterations, loop.Iterate(next_time));
+    last_time = next_time;
+  }
+}
+
+// Tests that the phased loop is correctly adjusting when the offset is
+// changed to 0.
+TEST_F(PhasedLoopTest, ChangingOffset) {
+  const auto kOffset = milliseconds(900);
+  const auto kInterval = milliseconds(1000);
+  PhasedLoop loop(kInterval, monotonic_clock::epoch(), kOffset);
+  const auto last_time = monotonic_clock::epoch() + kOffset + (kInterval * 3);
+  ASSERT_EQ(5, loop.Iterate(last_time));
+  loop.set_interval_and_offset(kInterval, milliseconds(0));
+  EXPECT_EQ(4, loop.Iterate((last_time - kOffset) + (kInterval * 4)));
+}
+
 }  // namespace testing
 }  // namespace time
 }  // namespace aos