Re-enable event logging when a gesture prop is set

A new gesture property, "Event Logging Enable", can now be set to true
to make the gestures library log events into its buffer. Since touch
event reporting is disabled in Chromium currently, these events don't
get added to feedback reports, so further work is needed there. However,
this will fix the touch tests once they set the new property.

Some chunks of this CL are just reverts of https://crrev.com/c/2818205.

BUG=b:185411893
TEST=install a Chrome build with https://crrev.com/c/2818722 reverted;
     use touchpad, set the new property to true, use touchpad, and check
     only the events from after enabling appear in system logs ZIP

Change-Id: I417f968b2041cbd3464933614b67d41d99e17fa5
Reviewed-on: https://chromium-review.googlesource.com/c/chromiumos/platform/gestures/+/2830216
Commit-Queue: Harry Cutts <hcutts@chromium.org>
Tested-by: Harry Cutts <hcutts@chromium.org>
Reviewed-by: Sean O'Brien <seobrien@chromium.org>
diff --git a/include/filter_interpreter.h b/include/filter_interpreter.h
index 32f3dd6..f31416d 100644
--- a/include/filter_interpreter.h
+++ b/include/filter_interpreter.h
@@ -29,8 +29,8 @@
   FilterInterpreter(PropRegistry* prop_reg,
                     Interpreter* next,
                     Tracer* tracer,
-                    bool force_logging)
-      : Interpreter(prop_reg, tracer, force_logging) { next_.reset(next); }
+                    bool force_log_creation)
+      : Interpreter(prop_reg, tracer, force_log_creation) { next_.reset(next); }
   virtual ~FilterInterpreter() {}
 
   Json::Value EncodeCommonInfo();
diff --git a/include/interpreter.h b/include/interpreter.h
index d899ad4..9a5bf94 100644
--- a/include/interpreter.h
+++ b/include/interpreter.h
@@ -34,10 +34,12 @@
 // A synchronous interpreter will return  0 or 1 Gestures for each passed in
 // HardwareState.
 class Interpreter {
+  FRIEND_TEST(InterpreterTest, SimpleTest);
   FRIEND_TEST(InterpreterTest, ResetLogTest);
+  FRIEND_TEST(InterpreterTest, LoggingDisabledByDefault);
   FRIEND_TEST(LoggingFilterInterpreterTest, LogResetHandlerTest);
  public:
-  Interpreter(PropRegistry* prop_reg, Tracer* tracer, bool force_logging);
+  Interpreter(PropRegistry* prop_reg, Tracer* tracer, bool force_log_creation);
   virtual ~Interpreter();
 
   // Called to interpret the current state.
@@ -88,9 +90,14 @@
                                  stime_t* timeout) {}
   virtual void HandleTimerImpl(stime_t now, stime_t* timeout) {}
 
+  void SetEventLoggingEnabled(bool enabled);
+
  private:
   const char* name_;
   Tracer* tracer_;
+  bool enable_event_logging_ = false;
+
+  void LogOutputs(const Gesture* result, stime_t* timeout, const char* action);
 };
 }  // namespace gestures
 
diff --git a/include/logging_filter_interpreter.h b/include/logging_filter_interpreter.h
index bddac1b..1720e15 100644
--- a/include/logging_filter_interpreter.h
+++ b/include/logging_filter_interpreter.h
@@ -28,6 +28,7 @@
                            Tracer* tracer);
   virtual ~LoggingFilterInterpreter() {}
 
+  virtual void BoolWasWritten(BoolProperty* prop);
   virtual void IntWasWritten(IntProperty* prop);
 
   std::string EncodeActivityLog();
@@ -35,6 +36,7 @@
  private:
   void Dump(const char* filename);
 
+  BoolProperty event_logging_enable_;
   IntProperty logging_notify_;
   // Reset the log by setting the property value.
   IntProperty logging_reset_;
diff --git a/src/interpreter.cc b/src/interpreter.cc
index 3098fbb..bea2ab1 100644
--- a/src/interpreter.cc
+++ b/src/interpreter.cc
@@ -22,7 +22,7 @@
 
 Interpreter::Interpreter(PropRegistry* prop_reg,
                          Tracer* tracer,
-                         bool force_logging)
+                         bool force_log_creation)
     : requires_metrics_(false),
       initialized_(false),
       name_(NULL),
@@ -30,7 +30,7 @@
 #ifdef DEEP_LOGS
   bool logging_enabled = true;
 #else
-  bool logging_enabled = force_logging;
+  bool logging_enabled = force_log_creation;
 #endif
   if (logging_enabled)
     log_.reset(new ActivityLog(prop_reg));
@@ -49,23 +49,36 @@
 void Interpreter::SyncInterpret(HardwareState* hwstate,
                                     stime_t* timeout) {
   AssertWithReturn(initialized_);
+  if (enable_event_logging_ && log_.get() && hwstate) {
+    Trace("log: start: ", "LogHardwareState");
+    log_->LogHardwareState(*hwstate);
+    Trace("log: end: ", "LogHardwareState");
+  }
   if (own_metrics_)
     own_metrics_->Update(*hwstate);
 
   Trace("SyncInterpret: start: ", name());
   SyncInterpretImpl(hwstate, timeout);
   Trace("SyncInterpret: end: ", name());
+  LogOutputs(NULL, timeout, "SyncLogOutputs");
 }
 
 void Interpreter::HandleTimer(stime_t now, stime_t* timeout) {
   AssertWithReturn(initialized_);
+  if (enable_event_logging_ && log_.get()) {
+    Trace("log: start: ", "LogTimerCallback");
+    log_->LogTimerCallback(now);
+    Trace("log: end: ", "LogTimerCallback");
+  }
   Trace("HandleTimer: start: ", name());
   HandleTimerImpl(now, timeout);
   Trace("HandleTimer: end: ", name());
+  LogOutputs(NULL, timeout, "TimerLogOutputs");
 }
 
 void Interpreter::ProduceGesture(const Gesture& gesture) {
   AssertWithReturn(initialized_);
+  LogOutputs(&gesture, NULL, "ProduceGesture");
   consumer_->ConsumeGesture(gesture);
 }
 
@@ -130,4 +143,22 @@
     free(full_name);
   }
 }
+
+void Interpreter::SetEventLoggingEnabled(bool enabled) {
+  // TODO(b/185844310): log an event when touch logging is enabled or disabled.
+  enable_event_logging_ = enabled;
+}
+
+void Interpreter::LogOutputs(const Gesture* result,
+                             stime_t* timeout,
+                             const char* action) {
+  if (!enable_event_logging_ || !log_.get())
+    return;
+  Trace("log: start: ", action);
+  if (result)
+    log_->LogGesture(*result);
+  if (timeout && *timeout >= 0.0)
+    log_->LogCallbackRequest(*timeout);
+  Trace("log: end: ", action);
+}
 }  // namespace gestures
diff --git a/src/interpreter_unittest.cc b/src/interpreter_unittest.cc
index 9ad77e3..b57f005 100644
--- a/src/interpreter_unittest.cc
+++ b/src/interpreter_unittest.cc
@@ -75,6 +75,7 @@
   PropRegistry prop_reg;
   InterpreterTestInterpreter* base_interpreter =
       new InterpreterTestInterpreter(&prop_reg);
+  base_interpreter->SetEventLoggingEnabled(true);
   MetricsProperties mprops(&prop_reg);
 
   HardwareProperties hwprops = {
@@ -125,5 +126,85 @@
   ASSERT_LT(timeout, 0);
   EXPECT_EQ(1, base_interpreter->interpret_call_count_);
   EXPECT_EQ(1, base_interpreter->handle_timer_call_count_);
+
+  // Now, get the log
+  string initial_log = base_interpreter->Encode();
+  // Make a new interpreter and push the log through it
+  PropRegistry prop_reg2;
+  InterpreterTestInterpreter* base_interpreter2 =
+      new InterpreterTestInterpreter(&prop_reg2);
+  base_interpreter2->SetEventLoggingEnabled(true);
+  base_interpreter2->return_value_ = base_interpreter->return_value_;
+  base_interpreter2->expected_interpreter_name_ = interpreter_name;
+  MetricsProperties mprops2(&prop_reg2);
+
+  ActivityReplay replay(&prop_reg2);
+  replay.Parse(initial_log);
+
+  base_interpreter2->expected_hwstate_ = &hardware_state;
+
+  replay.Replay(base_interpreter2, &mprops2);
+  string final_log = base_interpreter2->Encode();
+  EXPECT_EQ(initial_log, final_log);
+  EXPECT_EQ(1, base_interpreter2->interpret_call_count_);
+  EXPECT_EQ(1, base_interpreter2->handle_timer_call_count_);
+}
+
+class InterpreterResetLogTestInterpreter : public Interpreter {
+ public:
+  InterpreterResetLogTestInterpreter() : Interpreter(NULL, NULL, true) {
+    log_.reset(new ActivityLog(NULL));
+  }
+ protected:
+  virtual void SyncInterpretImpl(HardwareState* hwstate,
+                                     stime_t* timeout) {}
+
+  virtual void HandleTimerImpl(stime_t now, stime_t* timeout) {}
+};
+
+TEST(InterpreterTest, ResetLogTest) {
+  PropRegistry prop_reg;
+  InterpreterResetLogTestInterpreter* base_interpreter =
+      new InterpreterResetLogTestInterpreter();
+  base_interpreter->SetEventLoggingEnabled(true);
+  TestInterpreterWrapper wrapper(base_interpreter);
+
+  FingerState finger_state = {
+    // TM, Tm, WM, Wm, Press, Orientation, X, Y, TrID
+    0, 0, 0, 0, 10, 0, 50, 50, 1, 0
+  };
+  HardwareState hardware_state = make_hwstate(200000, 0, 1, 1, &finger_state);
+  stime_t timeout = NO_DEADLINE;
+  wrapper.SyncInterpret(&hardware_state, &timeout);
+  EXPECT_EQ(base_interpreter->log_->size(), 1);
+
+  wrapper.SyncInterpret(&hardware_state, &timeout);
+  EXPECT_EQ(base_interpreter->log_->size(), 2);
+
+  // Assume the ResetLog property is set.
+  base_interpreter->Clear();
+  EXPECT_EQ(base_interpreter->log_->size(), 0);
+
+  wrapper.SyncInterpret(&hardware_state, &timeout);
+  EXPECT_EQ(base_interpreter->log_->size(), 1);
+}
+
+TEST(InterpreterTest, LoggingDisabledByDefault) {
+  PropRegistry prop_reg;
+  InterpreterResetLogTestInterpreter* base_interpreter =
+      new InterpreterResetLogTestInterpreter();
+  TestInterpreterWrapper wrapper(base_interpreter);
+
+  FingerState finger_state = {
+    // TM, Tm, WM, Wm, Press, Orientation, X, Y, TrID
+    0, 0, 0, 0, 10, 0, 50, 50, 1, 0
+  };
+  HardwareState hardware_state = make_hwstate(200000, 0, 1, 1, &finger_state);
+  stime_t timeout = NO_DEADLINE;
+  wrapper.SyncInterpret(&hardware_state, &timeout);
+  EXPECT_EQ(base_interpreter->log_->size(), 0);
+
+  wrapper.SyncInterpret(&hardware_state, &timeout);
+  EXPECT_EQ(base_interpreter->log_->size(), 0);
 }
 }  // namespace gestures
diff --git a/src/logging_filter_interpreter.cc b/src/logging_filter_interpreter.cc
index 8ead2ec..3606988 100644
--- a/src/logging_filter_interpreter.cc
+++ b/src/logging_filter_interpreter.cc
@@ -17,6 +17,7 @@
                                                    Interpreter* next,
                                                    Tracer* tracer)
     : FilterInterpreter(prop_reg, next, tracer, true),
+      event_logging_enable_(prop_reg, "Event Logging Enable", false, this),
       logging_notify_(prop_reg, "Logging Notify", 0, this),
       logging_reset_(prop_reg, "Logging Reset", 0, this),
       log_location_(prop_reg, "Log Path",
@@ -34,6 +35,14 @@
     Clear();
 };
 
+void LoggingFilterInterpreter::BoolWasWritten(BoolProperty* prop) {
+  if (prop == &event_logging_enable_) {
+    Log("Event logging %s",
+        event_logging_enable_.val_ ? "enabled" : "disabled");
+    SetEventLoggingEnabled(event_logging_enable_.val_);
+  }
+}
+
 std::string LoggingFilterInterpreter::EncodeActivityLog() {
   return Encode();
 }
diff --git a/src/logging_filter_interpreter_unittest.cc b/src/logging_filter_interpreter_unittest.cc
index 3e190c0..f69eca0 100644
--- a/src/logging_filter_interpreter_unittest.cc
+++ b/src/logging_filter_interpreter_unittest.cc
@@ -18,4 +18,57 @@
 
 class LoggingFilterInterpreterTest : public ::testing::Test {};
 
+class LoggingFilterInterpreterResetLogTestInterpreter : public Interpreter {
+ public:
+  LoggingFilterInterpreterResetLogTestInterpreter()
+      : Interpreter(NULL, NULL, false) {}
+ protected:
+  virtual void SyncInterpretImpl(HardwareState* hwstate,
+                                     stime_t* timeout) {}
+  virtual void SetHardwarePropertiesImpl(const HardwareProperties& hw_props) {
+  }
+  virtual void HandleTimerImpl(stime_t now, stime_t* timeout) {}
+};
+
+TEST(LoggingFilterInterpreterTest, LogResetHandlerTest) {
+  PropRegistry prop_reg;
+  LoggingFilterInterpreterResetLogTestInterpreter* base_interpreter =
+      new LoggingFilterInterpreterResetLogTestInterpreter();
+  LoggingFilterInterpreter interpreter(&prop_reg, base_interpreter, NULL);
+
+  interpreter.event_logging_enable_.SetValue(Json::Value(true));
+  interpreter.BoolWasWritten(&interpreter.event_logging_enable_);
+
+  HardwareProperties hwprops = {
+    0, 0, 100, 100,  // left, top, right, bottom
+    10,  // x res (pixels/mm)
+    10,  // y res (pixels/mm)
+    133, 133,  // scrn DPI X, Y
+    -1,  // orientation minimum
+    2,   // orientation maximum
+    2, 5,  // max fingers, max_touch,
+    1, 0, 0,  // t5r2, semi, button pad
+    0, 0,  // has wheel, vertical wheel is high resolution
+  };
+
+  TestInterpreterWrapper wrapper(&interpreter, &hwprops);
+  FingerState finger_state = {
+    // TM, Tm, WM, Wm, Press, Orientation, X, Y, TrID
+    0, 0, 0, 0, 10, 0, 50, 50, 1, 0
+  };
+  HardwareState hardware_state = make_hwstate(200000, 0, 1, 1, &finger_state);
+  stime_t timeout = NO_DEADLINE;
+  wrapper.SyncInterpret(&hardware_state, &timeout);
+  EXPECT_EQ(interpreter.log_->size(), 1);
+
+  wrapper.SyncInterpret(&hardware_state, &timeout);
+  EXPECT_EQ(interpreter.log_->size(), 2);
+
+  // Assume the ResetLog property is set.
+  interpreter.logging_reset_.HandleGesturesPropWritten();
+  EXPECT_EQ(interpreter.log_->size(), 0);
+
+  wrapper.SyncInterpret(&hardware_state, &timeout);
+  EXPECT_EQ(interpreter.log_->size(), 1);
+}
 }  // namespace gestures