input_playback: Fix blocking_playback sleep time

The blocking_playback function originally calculates the elapsed time
from an event file and did not take into the time spent for replaying
the events by evemu-play. This patch addresses this issue by introducing
another pre-defined overhead latency from invoking the evemu-play to the
time read by Chrome Input Handler thread to prevent almost the same
amount of time wasted in sleep.

BUG=none
TEST=test_that DUT_IP performance_InboxInputLatency; won't sleep
additional 23 seconds after injecting the test key events.

Change-Id: Iff50f20447b91740c24ccec579349d6e2c318e8f
Signed-off-by: Chung-yih Wang <cywang@google.com>
Reviewed-on: https://chromium-review.googlesource.com/472590
Reviewed-by: Katherine Threlkeld <kathrelkeld@chromium.org>
diff --git a/client/cros/input_playback/input_playback.py b/client/cros/input_playback/input_playback.py
index cf76ee6..99a75fd 100644
--- a/client/cros/input_playback/input_playback.py
+++ b/client/cros/input_playback/input_playback.py
@@ -52,6 +52,11 @@
                                'keyboard': 'keyboard.prop'}
     _PLAYBACK_COMMAND = 'evemu-play --insert-slot0 %s < %s'
 
+    # Define the overhead (500 ms) elapsed for launching evemu-play and the
+    # latency from event injection to the first event read by Chrome Input
+    # thread.
+    _PLAYBACK_OVERHEAD_LATENCY = 0.5
+
     # Define a keyboard as anything with any keys #2 to #248 inclusive,
     # as defined in the linux input header.  This definition includes things
     # like the power button, so reserve the "keyboard" label for things with
@@ -450,10 +455,15 @@
             lines = fh.readlines()
             start = float(lines[0].split(' ')[1])
             end = float(lines[-1].split(' ')[1])
-            sleep_time = end - start
+            sleep_time = end - start + self._PLAYBACK_OVERHEAD_LATENCY
+        start_time = time.time()
         self.playback(filepath, input_type)
-        logging.info('Sleeping for %s seconds during playback.', sleep_time)
-        time.sleep(sleep_time)
+        end_time = time.time()
+        elapsed_time = end_time - start_time
+        if elapsed_time < sleep_time:
+            sleep_time -= elapsed_time
+            logging.info('Blocking for %s seconds after playback.', sleep_time)
+            time.sleep(sleep_time)
 
 
     def blocking_playback_of_default_file(self, filename, input_type='mouse'):
diff --git a/client/cros/input_playback/keyboard.py b/client/cros/input_playback/keyboard.py
index cc3b962..bb716a1 100644
--- a/client/cros/input_playback/keyboard.py
+++ b/client/cros/input_playback/keyboard.py
@@ -32,7 +32,8 @@
         if not os.path.exists(event_file):
             raise error.TestError('No such key file keyboard_%s in %s'
                                   % (key, self.dirname))
-        self.keyboard.playback(filepath=event_file, input_type=_KEYBOARD)
+        self.keyboard.blocking_playback(filepath=event_file,
+                                        input_type=_KEYBOARD)
 
     def playback(self, event_file):
         """Replay the specified key events file.
@@ -40,7 +41,8 @@
         @param event_file: the filename of the key events
 
         """
-        self.keyboard.playback(filepath=event_file, input_type=_KEYBOARD)
+        self.keyboard.blocking_playback(filepath=event_file,
+                                        input_type=_KEYBOARD)
 
     def close(self):
         """Clean up the files/handles created in the class."""