1# Copyright 2014 The Chromium Authors. All rights reserved.
2# Use of this source code is governed by a BSD-style license that can be
3# found in the LICENSE file.
4
5import re
6
7from telemetry import decorators
8import telemetry.timeline.bounds as timeline_bounds
9
10# Allows multiple duplicate interactions of the same type
11REPEATABLE = 'repeatable'
12
13FLAGS = [REPEATABLE]
14
15
16class ThreadTimeRangeOverlappedException(Exception):
17  """Exception that can be thrown when computing overlapped thread time range
18  with other events.
19  """
20
21class NoThreadTimeDataException(ThreadTimeRangeOverlappedException):
22  """Exception that can be thrown if there is not sufficient thread time data
23  to compute the overlapped thread time range."""
24
25def IsTimelineInteractionRecord(event_name):
26  return event_name.startswith('Interaction.')
27
28def _AssertFlagsAreValid(flags):
29  assert isinstance(flags, list)
30  for f in flags:
31    if f not in FLAGS:
32      raise AssertionError(
33          'Unrecognized flag for a timeline interaction record: %s' % f)
34
35def GetJavaScriptMarker(label, flags):
36  """Computes the marker string of an interaction record.
37
38  This marker string can be used with JavaScript API console.time()
39  and console.timeEnd() to mark the beginning and end of the
40  interaction record..
41
42  Args:
43    label: The label used to identify the interaction record.
44    flags: the flags for the interaction record see FLAGS above.
45
46  Returns:
47    The interaction record marker string (e.g., Interaction.Label/flag1,flag2).
48
49  Raises:
50    AssertionError: If one or more of the flags is unrecognized.
51  """
52  _AssertFlagsAreValid(flags)
53  marker = 'Interaction.%s' % label
54  if flags:
55    marker += '/%s' % (','.join(flags))
56  return marker
57
58class TimelineInteractionRecord(object):
59  """Represents an interaction that took place during a timeline recording.
60
61  As a page runs, typically a number of different (simulated) user interactions
62  take place. For instance, a user might click a button in a mail app causing a
63  popup to animate in. Then they might press another button that sends data to a
64  server and simultaneously closes the popup without an animation. These are two
65  interactions.
66
67  From the point of view of the page, each interaction might have a different
68  label: ClickComposeButton and SendEmail, for instance. From the point
69  of view of the benchmarking harness, the labels aren't so interesting as what
70  the performance expectations are for that interaction: was it loading
71  resources from the network? was there an animation?
72
73  Determining these things is hard to do, simply by observing the state given to
74  a page from javascript. There are hints, for instance if network requests are
75  sent, or if a CSS animation is pending. But this is by no means a complete
76  story.
77
78  Instead, we expect pages to mark up the timeline what they are doing, with
79  label and flags indicating the semantics of that interaction. This
80  is currently done by pushing markers into the console.time/timeEnd API: this
81  for instance can be issued in JS:
82
83     var str = 'Interaction.SendEmail';
84     console.time(str);
85     setTimeout(function() {
86       console.timeEnd(str);
87     }, 1000);
88
89  When run with perf.measurements.timeline_based_measurement running, this will
90  then cause a TimelineInteractionRecord to be created for this range with
91  all metrics reported for the marked up 1000ms time-range.
92
93  The valid interaction flags are:
94     * repeatable: Allows other interactions to use the same label
95  """
96
97  def __init__(self, label, start, end, async_event=None, flags=None):
98    assert label
99    self._label = label
100    self._start = start
101    self._end = end
102    self._async_event = async_event
103    self._flags = flags if flags is not None else []
104    _AssertFlagsAreValid(self._flags)
105
106  @property
107  def label(self):
108    return self._label
109
110  @property
111  def start(self):
112    return self._start
113
114  @property
115  def end(self):
116    return self._end
117
118  @property
119  def repeatable(self):
120    return REPEATABLE in self._flags
121
122  # TODO(nednguyen): After crbug.com/367175 is marked fixed, we should be able
123  # to get rid of perf.measurements.smooth_gesture_util and make this the only
124  # constructor method for TimelineInteractionRecord.
125  @classmethod
126  def FromAsyncEvent(cls, async_event):
127    """Construct an timeline_interaction_record from an async event.
128    Args:
129      async_event: An instance of
130        telemetry.timeline.async_slices.AsyncSlice
131    """
132    assert async_event.start_thread == async_event.end_thread, (
133        'Start thread of this record\'s async event is not the same as its '
134        'end thread')
135    m = re.match(r'Interaction\.(?P<label>.+?)(/(?P<flags>[^/]+))?$',
136                 async_event.name)
137    assert m, "Async event is not an interaction record."
138    label = m.group('label')
139    flags = m.group('flags').split(',') if m.group('flags') is not None else []
140    return cls(label, async_event.start, async_event.end, async_event, flags)
141
142  @decorators.Cache
143  def GetBounds(self):
144    bounds = timeline_bounds.Bounds()
145    bounds.AddValue(self.start)
146    bounds.AddValue(self.end)
147    return bounds
148
149  def GetOverlappedThreadTimeForSlice(self, timeline_slice):
150    """Get the thread duration of timeline_slice that overlaps with this record.
151
152    There are two cases :
153
154    Case 1: timeline_slice runs in the same thread as the record.
155
156                  |    [       timeline_slice         ]
157      THREAD 1    |                  |                              |
158                  |            record starts                    record ends
159
160                      (relative order in thread time)
161
162      As the thread timestamps in timeline_slice and record are consistent, we
163      simply use them to compute the overlap.
164
165    Case 2: timeline_slice runs in a different thread from the record's.
166
167                  |
168      THREAD 2    |    [       timeline_slice         ]
169                  |
170
171                  |
172      THREAD 1    |               |                               |
173                  |          record starts                      record ends
174
175                      (relative order in wall-time)
176
177      Unlike case 1, thread timestamps of a thread are measured by its
178      thread-specific clock, which is inconsistent with that of the other
179      thread, and thus can't be used to compute the overlapped thread duration.
180      Hence, we use a heuristic to compute the overlap (see
181      _GetOverlappedThreadTimeForSliceInDifferentThread for more details)
182
183    Args:
184      timeline_slice: An instance of telemetry.timeline.slice.Slice
185    """
186    if not self._async_event:
187      raise ThreadTimeRangeOverlappedException(
188          'This record was not constructed from async event')
189    if not self._async_event.has_thread_timestamps:
190      raise NoThreadTimeDataException(
191          'This record\'s async_event does not contain thread time data. '
192          'Event data: %s' % repr(self._async_event))
193    if not timeline_slice.has_thread_timestamps:
194      raise NoThreadTimeDataException(
195          'slice does not contain thread time data')
196
197    if timeline_slice.parent_thread == self._async_event.start_thread:
198      return self._GetOverlappedThreadTimeForSliceInSameThread(
199          timeline_slice)
200    else:
201      return self._GetOverlappedThreadTimeForSliceInDifferentThread(
202          timeline_slice)
203
204  def _GetOverlappedThreadTimeForSliceInSameThread(self, timeline_slice):
205    return timeline_bounds.Bounds.GetOverlap(
206        timeline_slice.thread_start, timeline_slice.thread_end,
207        self._async_event.thread_start, self._async_event.thread_end)
208
209  def _GetOverlappedThreadTimeForSliceInDifferentThread(self, timeline_slice):
210    # In case timeline_slice's parent thread is not the parent thread of the
211    # async slice that issues this record, we assume that events are descheduled
212    # uniformly. The overlap duration in thread time is then computed by
213    # multiplying the overlap wall-time duration of timeline_slice and the
214    # record's async slice with their thread_duration/duration ratios.
215    overlapped_walltime_duration = timeline_bounds.Bounds.GetOverlap(
216        timeline_slice.start, timeline_slice.end,
217        self.start, self.end)
218    if timeline_slice.duration == 0 or self._async_event.duration == 0:
219      return 0
220    timeline_slice_scheduled_ratio = (
221        timeline_slice.thread_duration / float(timeline_slice.duration))
222    record_scheduled_ratio = (
223        self._async_event.thread_duration / float(self._async_event.duration))
224    return (overlapped_walltime_duration * timeline_slice_scheduled_ratio *
225            record_scheduled_ratio)
226
227  def __repr__(self):
228    flags_str = ','.join(self._flags)
229    return ('TimelineInteractionRecord(label=\'%s\', start=%f, end=%f,' +
230            ' flags=%s, async_event=%s)') % (
231                self.label,
232                self.start,
233                self.end,
234                flags_str,
235                repr(self._async_event))
236