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 json
6import unittest
7
8import telemetry.timeline.counter as tracing_counter
9import telemetry.timeline.model as timeline_model
10from telemetry.timeline import trace_event_importer
11from telemetry.timeline import tracing_timeline_data
12
13
14def FindEventNamed(events, name):
15  for event in events:
16    if event.name == name:
17      return event
18  raise ValueError('No event found with name %s' % name)
19
20class TraceEventTimelineImporterTest(unittest.TestCase):
21  def testCanImportEmpty(self):
22    # TraceEventTimelineImporter needs to return false for empty lists and
23    # strings, because it assumes that they are >0 in len. But, TimelineMode can
24    # still import empty lists and strings (wrapped in a TimelineData object)
25    # via EmptyTimelineDataImporter.
26    self.assertFalse(
27        trace_event_importer.TraceEventTimelineImporter.CanImport(
28            tracing_timeline_data.TracingTimelineData([])))
29    self.assertFalse(
30        trace_event_importer.TraceEventTimelineImporter.CanImport(
31            tracing_timeline_data.TracingTimelineData('')))
32
33  def testBasicSingleThreadNonnestedParsing(self):
34    events = [
35      {'name': 'a', 'args': {}, 'pid': 52, 'ts': 520, 'tts': 280, 'cat': 'foo',
36       'tid': 53, 'ph': 'B'},
37      {'name': 'a', 'args': {}, 'pid': 52, 'ts': 560, 'tts': 310, 'cat': 'foo',
38       'tid': 53, 'ph': 'E'},
39      {'name': 'b', 'args': {}, 'pid': 52, 'ts': 629, 'tts': 356, 'cat': 'bar',
40       'tid': 53, 'ph': 'B'},
41      {'name': 'b', 'args': {}, 'pid': 52, 'ts': 631, 'tts': 357, 'cat': 'bar',
42       'tid': 53, 'ph': 'E'},
43      {'name': 'c', 'args': {}, 'pid': 52, 'ts': 633, 'cat': 'baz',
44       'tid': 53, 'ph': 'B'},
45      {'name': 'c', 'args': {}, 'pid': 52, 'ts': 637, 'cat': 'baz',
46       'tid': 53, 'ph': 'E'}
47    ]
48
49    timeline_data = tracing_timeline_data.TracingTimelineData(events)
50    m = timeline_model.TimelineModel(timeline_data=timeline_data)
51    processes = m.GetAllProcesses()
52    self.assertEqual(1, len(processes))
53    p = processes[0]
54    self.assertEqual(52, p.pid)
55
56    self.assertEqual(1, len(p.threads))
57    t = p.threads[53]
58    self.assertEqual(3, len(t.all_slices))
59    self.assertEqual(53, t.tid)
60    slice_event = t.all_slices[0]
61    self.assertEqual('a', slice_event.name)
62    self.assertEqual('foo', slice_event.category)
63    self.assertAlmostEqual(0, slice_event.start)
64    self.assertAlmostEqual((560 - 520) / 1000.0, slice_event.duration)
65    self.assertAlmostEqual((560 - 520) / 1000.0, slice_event.end)
66    self.assertAlmostEqual(280 / 1000.0, slice_event.thread_start)
67    self.assertAlmostEqual((310 - 280) / 1000.0, slice_event.thread_duration)
68    self.assertAlmostEqual(310 / 1000.0, slice_event.thread_end)
69    self.assertEqual(0, len(slice_event.sub_slices))
70
71    slice_event = t.all_slices[1]
72    self.assertEqual('b', slice_event.name)
73    self.assertEqual('bar', slice_event.category)
74    self.assertAlmostEqual((629 - 520) / 1000.0, slice_event.start)
75    self.assertAlmostEqual((631 - 629) / 1000.0, slice_event.duration)
76    self.assertAlmostEqual((631 - 520) / 1000.0, slice_event.end)
77    self.assertAlmostEqual(356 / 1000.0, slice_event.thread_start)
78    self.assertAlmostEqual((357 - 356) / 1000.0, slice_event.thread_duration)
79    self.assertAlmostEqual(357 / 1000.0, slice_event.thread_end)
80    self.assertEqual(0, len(slice_event.sub_slices))
81
82    slice_event = t.all_slices[2]
83    self.assertEqual('c', slice_event.name)
84    self.assertEqual('baz', slice_event.category)
85    self.assertAlmostEqual((633 - 520) / 1000.0, slice_event.start)
86    self.assertAlmostEqual((637 - 633) / 1000.0, slice_event.duration)
87    self.assertEqual(None, slice_event.thread_start)
88    self.assertEqual(None, slice_event.thread_duration)
89    self.assertEqual(None, slice_event.thread_end)
90    self.assertEqual(0, len(slice_event.sub_slices))
91
92
93  def testArgumentDupeCreatesNonFailingImportError(self):
94    events = [
95      {'name': 'a', 'args': {'x': 1}, 'pid': 1, 'ts': 520, 'cat': 'foo',
96       'tid': 1, 'ph': 'B'},
97      {'name': 'a', 'args': {'x': 2}, 'pid': 1, 'ts': 560, 'cat': 'foo',
98       'tid': 1, 'ph': 'E'}
99    ]
100
101    timeline_data = tracing_timeline_data.TracingTimelineData(events)
102    m = timeline_model.TimelineModel(timeline_data=timeline_data)
103    processes = m.GetAllProcesses()
104    t = processes[0].threads[1]
105    slice_a = FindEventNamed(t.all_slices, 'a')
106
107    self.assertEqual(2, slice_a.args['x'])
108    self.assertEqual(1, len(m.import_errors))
109
110  def testCategoryBeginEndMismatchPreferslice_begin(self):
111    events = [
112      {'name': 'a', 'args': {}, 'pid': 52, 'ts': 520, 'cat': 'foo',
113       'tid': 53, 'ph': 'B'},
114      {'name': 'a', 'args': {}, 'pid': 52, 'ts': 560, 'cat': 'bar',
115       'tid': 53, 'ph': 'E'}
116    ]
117
118    timeline_data = tracing_timeline_data.TracingTimelineData(events)
119    m = timeline_model.TimelineModel(timeline_data=timeline_data)
120    processes = m.GetAllProcesses()
121    self.assertEqual(1, len(processes))
122    p = processes[0]
123    self.assertEqual(52, p.pid)
124
125    self.assertEqual(1, len(p.threads))
126    t = p.threads[53]
127    self.assertEqual(1, len(t.all_slices))
128    self.assertEqual(53, t.tid)
129    slice_event = t.all_slices[0]
130    self.assertEqual('a', slice_event.name)
131    self.assertEqual('foo', slice_event.category)
132
133  def testNestedParsing(self):
134    events = [
135      {'name': 'a', 'args': {}, 'pid': 1, 'ts': 1, 'tts': 2, 'cat': 'foo',
136       'tid': 1, 'ph': 'B'},
137      {'name': 'b', 'args': {}, 'pid': 1, 'ts': 3, 'tts': 3, 'cat': 'bar',
138       'tid': 1, 'ph': 'B'},
139      {'name': 'b', 'args': {}, 'pid': 1, 'ts': 5, 'tts': 4, 'cat': 'bar',
140       'tid': 1, 'ph': 'E'},
141      {'name': 'a', 'args': {}, 'pid': 1, 'ts': 7, 'tts': 5, 'cat': 'foo',
142       'tid': 1, 'ph': 'E'}
143    ]
144    timeline_data = tracing_timeline_data.TracingTimelineData(events)
145    m = timeline_model.TimelineModel(timeline_data=timeline_data,
146                                     shift_world_to_zero=False)
147    t = m.GetAllProcesses()[0].threads[1]
148
149    slice_a = FindEventNamed(t.all_slices, 'a')
150    slice_b = FindEventNamed(t.all_slices, 'b')
151
152    self.assertEqual('a', slice_a.name)
153    self.assertEqual('foo', slice_a.category)
154    self.assertAlmostEqual(0.001, slice_a.start)
155    self.assertAlmostEqual(0.006, slice_a.duration)
156    self.assertAlmostEqual(0.002, slice_a.thread_start)
157    self.assertAlmostEqual(0.003, slice_a.thread_duration)
158
159    self.assertEqual('b', slice_b.name)
160    self.assertEqual('bar', slice_b.category)
161    self.assertAlmostEqual(0.003, slice_b.start)
162    self.assertAlmostEqual(0.002, slice_b.duration)
163    self.assertAlmostEqual(0.003, slice_b.thread_start)
164    self.assertAlmostEqual(0.001, slice_b.thread_duration)
165
166  def testAutoclosing(self):
167    events = [
168      # Slices that don't finish.
169      {'name': 'a', 'args': {}, 'pid': 1, 'ts': 1, 'tts': 1, 'cat': 'foo',
170       'tid': 1, 'ph': 'B'},
171      {'name': 'b', 'args': {}, 'pid': 1, 'ts': 2, 'tts': 2, 'cat': 'foo',
172       'tid': 2, 'ph': 'B'},
173
174      # Slices on thread 1 and 2 that do finish to give an 'end time' to make
175      # autoclosing work.
176      {'name': 'c', 'args': {}, 'pid': 1, 'ts': 2, 'tts': 1.5, 'cat': 'bar',
177       'tid': 1, 'ph': 'B'},
178      {'name': 'c', 'args': {}, 'pid': 1, 'ts': 4, 'tts': 3, 'cat': 'bar',
179       'tid': 1, 'ph': 'E'},
180      {'name': 'd', 'args': {}, 'pid': 1, 'ts': 3, 'tts': 2.5, 'cat': 'bar',
181       'tid': 2, 'ph': 'B'},
182      {'name': 'd', 'args': {}, 'pid': 1, 'ts': 7, 'tts': 5, 'cat': 'bar',
183       'tid': 2, 'ph': 'E'}
184    ]
185    timeline_data = tracing_timeline_data.TracingTimelineData(events)
186    m = timeline_model.TimelineModel(timeline_data=timeline_data)
187    p = m.GetAllProcesses()[0]
188    t1 = p.threads[1]
189    slice_event = FindEventNamed(t1.all_slices, 'a')
190    self.assertEqual('a', slice_event.name)
191    self.assertEqual('foo', slice_event.category)
192    self.assertTrue(slice_event.did_not_finish)
193    self.assertAlmostEqual(0, slice_event.start)
194    self.assertAlmostEqual((7 - 1) / 1000.0, slice_event.duration)
195    self.assertAlmostEqual(1 / 1000.0, slice_event.thread_start)
196    self.assertAlmostEqual((3 - 1) / 1000.0, slice_event.thread_duration)
197
198    t2 = p.threads[2]
199    slice_event = FindEventNamed(t2.all_slices, 'b')
200    self.assertEqual('b', slice_event.name)
201    self.assertEqual('foo', slice_event.category)
202    self.assertTrue(slice_event.did_not_finish)
203    self.assertAlmostEqual((2 - 1) / 1000.0, slice_event.start)
204    self.assertAlmostEqual((7 - 2) / 1000.0, slice_event.duration)
205    self.assertAlmostEqual(2 / 1000.0, slice_event.thread_start)
206    self.assertAlmostEqual((5 - 2) / 1000.0, slice_event.thread_duration)
207
208  def testAutoclosingLoneBegin(self):
209    events = [
210      # Slice that doesn't finish.
211      {'name': 'a', 'args': {}, 'pid': 1, 'ts': 1, 'tts': 1, 'cat': 'foo',
212       'tid': 1, 'ph': 'B'}
213    ]
214    timeline_data = tracing_timeline_data.TracingTimelineData(events)
215    m = timeline_model.TimelineModel(timeline_data=timeline_data)
216    p = m.GetAllProcesses()[0]
217    t = p.threads[1]
218    slice_event = t.all_slices[0]
219    self.assertEqual('a', slice_event.name)
220    self.assertEqual('foo', slice_event.category)
221    self.assertTrue(slice_event.did_not_finish)
222    self.assertAlmostEqual(0, slice_event.start)
223    self.assertAlmostEqual(0, slice_event.duration)
224    self.assertAlmostEqual(1 / 1000.0, slice_event.thread_start)
225    self.assertAlmostEqual(0, slice_event.thread_duration)
226
227  def testAutoclosingWithSubTasks(self):
228    events = [
229      {'name': 'a', 'args': {}, 'pid': 1, 'ts': 1, 'cat': 'foo',
230       'tid': 1, 'ph': 'B'},
231      {'name': 'b1', 'args': {}, 'pid': 1, 'ts': 2, 'cat': 'foo',
232       'tid': 1, 'ph': 'B'},
233      {'name': 'b1', 'args': {}, 'pid': 1, 'ts': 3, 'cat': 'foo',
234       'tid': 1, 'ph': 'E'},
235      {'name': 'b2', 'args': {}, 'pid': 1, 'ts': 3, 'cat': 'foo',
236       'tid': 1, 'ph': 'B'}
237    ]
238    timeline_data = tracing_timeline_data.TracingTimelineData(events)
239    m = timeline_model.TimelineModel(timeline_data=timeline_data,
240                                     shift_world_to_zero=False)
241    t = m.GetAllProcesses()[0].threads[1]
242
243    slice_a = FindEventNamed(t.all_slices, 'a')
244    slice_b1 = FindEventNamed(t.all_slices, 'b1')
245    slice_b2 = FindEventNamed(t.all_slices, 'b2')
246
247    self.assertAlmostEqual(0.003, slice_a.end)
248    self.assertAlmostEqual(0.003, slice_b1.end)
249    self.assertAlmostEqual(0.003, slice_b2.end)
250
251  def testAutoclosingWithEventsOutsideBounds(self):
252    events = [
253      # Slice that begins before min and ends after max of the other threads.
254      {'name': 'a', 'args': {}, 'pid': 1, 'ts': 0, 'tts': 0, 'cat': 'foo',
255       'tid': 1, 'ph': 'B'},
256      {'name': 'b', 'args': {}, 'pid': 1, 'ts': 6, 'tts': 3, 'cat': 'foo',
257       'tid': 1, 'ph': 'B'},
258
259      # Slice that does finish to give an 'end time' to establish a basis
260      {'name': 'c', 'args': {}, 'pid': 1, 'ts': 2, 'tts': 1, 'cat': 'bar',
261       'tid': 2, 'ph': 'B'},
262      {'name': 'c', 'args': {}, 'pid': 1, 'ts': 4, 'tts': 2, 'cat': 'bar',
263       'tid': 2, 'ph': 'E'}
264    ]
265    timeline_data = tracing_timeline_data.TracingTimelineData(events)
266    m = timeline_model.TimelineModel(timeline_data=timeline_data,
267                                     shift_world_to_zero=False)
268    p = m.GetAllProcesses()[0]
269    t1 = p.threads[1]
270    t1_thread_time_bounds = m._thread_time_bounds[t1] # pylint: disable=W0212
271    self.assertAlmostEqual(0.000, t1_thread_time_bounds.min)
272    self.assertAlmostEqual(0.003, t1_thread_time_bounds.max)
273    self.assertEqual(2, len(t1.all_slices))
274
275    slice_event = FindEventNamed(t1.all_slices, 'a')
276    self.assertEqual('a', slice_event.name)
277    self.assertEqual('foo', slice_event.category)
278    self.assertAlmostEqual(0, slice_event.start)
279    self.assertAlmostEqual(0.006, slice_event.duration)
280    self.assertAlmostEqual(0, slice_event.thread_start)
281    self.assertAlmostEqual(0.003, slice_event.thread_duration)
282
283    t2 = p.threads[2]
284    t2_thread_time_bounds = m._thread_time_bounds[t2] # pylint: disable=W0212
285    self.assertAlmostEqual(0.001, t2_thread_time_bounds.min)
286    self.assertAlmostEqual(0.002, t2_thread_time_bounds.max)
287    slice2 = FindEventNamed(t2.all_slices, 'c')
288    self.assertEqual('c', slice2.name)
289    self.assertEqual('bar', slice2.category)
290    self.assertAlmostEqual(0.002, slice2.start)
291    self.assertAlmostEqual(0.002, slice2.duration)
292    self.assertAlmostEqual(0.001, slice2.thread_start)
293    self.assertAlmostEqual(0.001, slice2.thread_duration)
294
295    self.assertAlmostEqual(0.000, m.bounds.min)
296    self.assertAlmostEqual(0.006, m.bounds.max)
297
298  def testNestedAutoclosing(self):
299    events = [
300      # Tasks that don't finish.
301      {'name': 'a1', 'args': {}, 'pid': 1, 'ts': 1, 'cat': 'foo',
302       'tid': 1, 'ph': 'B'},
303      {'name': 'a2', 'args': {}, 'pid': 1, 'ts': 1.5, 'cat': 'foo',
304       'tid': 1, 'ph': 'B'},
305
306      # Slice that does finish to give an 'end time' to make autoclosing work.
307      {'name': 'b', 'args': {}, 'pid': 1, 'ts': 1, 'cat': 'foo',
308       'tid': 2, 'ph': 'B'},
309      {'name': 'b', 'args': {}, 'pid': 1, 'ts': 2, 'cat': 'foo',
310       'tid': 2, 'ph': 'E'}
311    ]
312    timeline_data = tracing_timeline_data.TracingTimelineData(events)
313    m = timeline_model.TimelineModel(timeline_data=timeline_data,
314                                     shift_world_to_zero=False)
315    t1 = m.GetAllProcesses()[0].threads[1]
316    t2 = m.GetAllProcesses()[0].threads[2]
317
318    slice_a1 = FindEventNamed(t1.all_slices, 'a1')
319    slice_a2 = FindEventNamed(t1.all_slices, 'a2')
320    FindEventNamed(t2.all_slices, 'b')
321
322    self.assertAlmostEqual(0.002, slice_a1.end)
323    self.assertAlmostEqual(0.002, slice_a2.end)
324
325  def testMultipleThreadParsing(self):
326    events = [
327      {'name': 'a', 'args': {}, 'pid': 1, 'ts': 2, 'tts': 1, 'cat': 'foo',
328       'tid': 1, 'ph': 'B'},
329      {'name': 'a', 'args': {}, 'pid': 1, 'ts': 4, 'tts': 2, 'cat': 'foo',
330       'tid': 1, 'ph': 'E'},
331      {'name': 'b', 'args': {}, 'pid': 1, 'ts': 6, 'tts': 3, 'cat': 'bar',
332       'tid': 2, 'ph': 'B'},
333      {'name': 'b', 'args': {}, 'pid': 1, 'ts': 8, 'tts': 4, 'cat': 'bar',
334       'tid': 2, 'ph': 'E'}
335    ]
336    timeline_data = tracing_timeline_data.TracingTimelineData(events)
337    m = timeline_model.TimelineModel(timeline_data=timeline_data)
338    processes = m.GetAllProcesses()
339    self.assertEqual(1, len(processes))
340    p = processes[0]
341
342    self.assertEqual(2, len(p.threads))
343
344    # Check thread 1.
345    t = p.threads[1]
346    self.assertAlmostEqual(1, len(t.all_slices))
347    self.assertAlmostEqual(1, t.tid)
348
349    slice_event = t.all_slices[0]
350    self.assertEqual('a', slice_event.name)
351    self.assertEqual('foo', slice_event.category)
352    self.assertAlmostEqual(0, slice_event.start)
353    self.assertAlmostEqual((4 - 2) / 1000.0, slice_event.duration)
354    self.assertAlmostEqual(1 / 1000.0, slice_event.thread_start)
355    self.assertAlmostEqual((2 - 1) / 1000.0, slice_event.thread_duration)
356
357    # Check thread 2.
358    t = p.threads[2]
359    self.assertAlmostEqual(1, len(t.all_slices))
360    self.assertAlmostEqual(2, t.tid)
361
362    slice_event = t.all_slices[0]
363    self.assertEqual('b', slice_event.name)
364    self.assertEqual('bar', slice_event.category)
365    self.assertAlmostEqual((6 - 2) / 1000.0, slice_event.start)
366    self.assertAlmostEqual((8 - 6) / 1000.0, slice_event.duration)
367    self.assertAlmostEqual(3 / 1000.0, slice_event.thread_start)
368    self.assertAlmostEqual((4 - 3) / 1000.0, slice_event.thread_duration)
369
370  def testMultiplePidParsing(self):
371    events = [
372      {'name': 'a', 'args': {}, 'pid': 1, 'ts': 2, 'tts': 1, 'cat': 'foo',
373       'tid': 1, 'ph': 'B'},
374      {'name': 'a', 'args': {}, 'pid': 1, 'ts': 4, 'tts': 2, 'cat': 'foo',
375       'tid': 1, 'ph': 'E'},
376      {'name': 'b', 'args': {}, 'pid': 2, 'ts': 6, 'tts': 3, 'cat': 'bar',
377       'tid': 2, 'ph': 'B'},
378      {'name': 'b', 'args': {}, 'pid': 2, 'ts': 8, 'tts': 4, 'cat': 'bar',
379       'tid': 2, 'ph': 'E'}
380    ]
381
382    timeline_data = tracing_timeline_data.TracingTimelineData(events)
383    m = timeline_model.TimelineModel(timeline_data=timeline_data)
384    processes = m.GetAllProcesses()
385    self.assertEqual(2, len(processes))
386
387    p = processes[0]
388    self.assertEqual(1, p.pid)
389    self.assertEqual(1, len(p.threads))
390
391    # Check process 1 thread 1.
392    t = p.threads[1]
393    self.assertEqual(1, len(t.all_slices))
394    self.assertEqual(1, t.tid)
395
396    slice_event = t.all_slices[0]
397    self.assertEqual('a', slice_event.name)
398    self.assertEqual('foo', slice_event.category)
399    self.assertAlmostEqual(0, slice_event.start)
400    self.assertAlmostEqual((4 - 2) / 1000.0, slice_event.duration)
401    self.assertAlmostEqual(1 / 1000.0, slice_event.thread_start)
402    self.assertAlmostEqual((2 - 1) / 1000.0, slice_event.thread_duration)
403
404    # Check process 2 thread 2.
405    # TODO: will this be in deterministic order?
406    p = processes[1]
407    self.assertEqual(2, p.pid)
408    self.assertEqual(1, len(p.threads))
409    t = p.threads[2]
410    self.assertEqual(1, len(t.all_slices))
411    self.assertEqual(2, t.tid)
412
413    slice_event = t.all_slices[0]
414    self.assertEqual('b', slice_event.name)
415    self.assertEqual('bar', slice_event.category)
416    self.assertAlmostEqual((6 - 2) / 1000.0, slice_event.start)
417    self.assertAlmostEqual((8 - 6) / 1000.0, slice_event.duration)
418    self.assertAlmostEqual(3 / 1000.0, slice_event.thread_start)
419    self.assertAlmostEqual((4 - 3) / 1000.0, slice_event.thread_duration)
420
421    # Check getAllThreads.
422    self.assertEqual([processes[0].threads[1],
423                      processes[1].threads[2]],
424                      m.GetAllThreads())
425
426  def testThreadNames(self):
427    events = [
428      {'name': 'thread_name', 'args': {'name': 'Thread 1'},
429        'pid': 1, 'ts': 0, 'tid': 1, 'ph': 'M'},
430      {'name': 'a', 'args': {}, 'pid': 1, 'ts': 1, 'cat': 'foo',
431       'tid': 1, 'ph': 'B'},
432      {'name': 'a', 'args': {}, 'pid': 1, 'ts': 2, 'cat': 'foo',
433       'tid': 1, 'ph': 'E'},
434      {'name': 'b', 'args': {}, 'pid': 2, 'ts': 3, 'cat': 'foo',
435       'tid': 2, 'ph': 'B'},
436      {'name': 'b', 'args': {}, 'pid': 2, 'ts': 4, 'cat': 'foo',
437       'tid': 2, 'ph': 'E'},
438      {'name': 'thread_name', 'args': {'name': 'Thread 2'},
439        'pid': 2, 'ts': 0, 'tid': 2, 'ph': 'M'}
440    ]
441    timeline_data = tracing_timeline_data.TracingTimelineData(events)
442    m = timeline_model.TimelineModel(timeline_data=timeline_data)
443    processes = m.GetAllProcesses()
444    self.assertEqual('Thread 1', processes[0].threads[1].name)
445    self.assertEqual('Thread 2', processes[1].threads[2].name)
446
447  def testParsingWhenEndComesFirst(self):
448    events = [
449      {'name': 'a', 'args': {}, 'pid': 1, 'ts': 1, 'tts': 1, 'cat': 'foo',
450       'tid': 1, 'ph': 'E'},
451      {'name': 'a', 'args': {}, 'pid': 1, 'ts': 4, 'tts': 4, 'cat': 'foo',
452       'tid': 1, 'ph': 'B'},
453      {'name': 'a', 'args': {}, 'pid': 1, 'ts': 5, 'tts': 5, 'cat': 'foo',
454       'tid': 1, 'ph': 'E'}
455    ]
456    timeline_data = tracing_timeline_data.TracingTimelineData(events)
457    m = timeline_model.TimelineModel(timeline_data=timeline_data,
458                                     shift_world_to_zero=False)
459    p = m.GetAllProcesses()[0]
460    t = p.threads[1]
461    self.assertEqual(1, len(t.all_slices))
462    self.assertEqual('a', t.all_slices[0].name)
463    self.assertEqual('foo', t.all_slices[0].category)
464    self.assertEqual(0.004, t.all_slices[0].start)
465    self.assertEqual(0.001, t.all_slices[0].duration)
466    self.assertEqual(0.004, t.all_slices[0].thread_start)
467    self.assertEqual(0.001, t.all_slices[0].thread_duration)
468    self.assertEqual(1, len(m.import_errors))
469
470  def testImmediateParsing(self):
471    events = [
472      # Need to include immediates inside a task so the timeline
473      # recentering/zeroing doesn't clobber their timestamp.
474      {'name': 'a', 'args': {}, 'pid': 1, 'ts': 2, 'tts': 1, 'cat': 'foo',
475       'tid': 1, 'ph': 'B'},
476      {'name': 'immediate', 'args': {}, 'pid': 1, 'ts': 4, 'cat': 'bar',
477       'tid': 1, 'ph': 'I'},
478      {'name': 'slower', 'args': {}, 'pid': 1, 'ts': 8, 'cat': 'baz',
479       'tid': 1, 'ph': 'i'},
480      {'name': 'a', 'args': {}, 'pid': 1, 'ts': 8, 'tts': 4, 'cat': 'foo',
481       'tid': 1, 'ph': 'E'}
482    ]
483    timeline_data = tracing_timeline_data.TracingTimelineData(events)
484    m = timeline_model.TimelineModel(timeline_data=timeline_data,
485                                     shift_world_to_zero=False)
486    p = m.GetAllProcesses()[0]
487    t = p.threads[1]
488    self.assertEqual(3, len(t.all_slices))
489
490    i = m.GetAllEventsOfName('immediate')[0]
491    self.assertEqual('immediate', i.name)
492    self.assertEqual('bar', i.category)
493    self.assertAlmostEqual(0.004, i.start)
494    self.assertAlmostEqual(0, i.duration)
495
496    slower = m.GetAllEventsOfName('slower')[0]
497    self.assertEqual('slower', slower.name)
498    self.assertEqual('baz', slower.category)
499    self.assertAlmostEqual(0.008, slower.start)
500    self.assertAlmostEqual(0, slower.duration)
501
502    a = m.GetAllEventsOfName('a')[0]
503    self.assertEqual('a', a.name)
504    self.assertEqual('foo', a.category)
505    self.assertAlmostEqual(0.002, a.start)
506    self.assertAlmostEqual(0.006, a.duration)
507    self.assertAlmostEqual(0.001, a.thread_start)
508    self.assertAlmostEqual(0.003, a.thread_duration)
509
510
511  def testSimpleCounter(self):
512    events = [
513      {'name': 'ctr', 'args': {'value': 0}, 'pid': 1, 'ts': 0, 'cat': 'foo',
514       'tid': 1, 'ph': 'C'},
515      {'name': 'ctr', 'args': {'value': 10}, 'pid': 1, 'ts': 10, 'cat': 'foo',
516       'tid': 1, 'ph': 'C'},
517      {'name': 'ctr', 'args': {'value': 0}, 'pid': 1, 'ts': 20, 'cat': 'foo',
518       'tid': 1, 'ph': 'C'}
519    ]
520    timeline_data = tracing_timeline_data.TracingTimelineData(events)
521    m = timeline_model.TimelineModel(timeline_data=timeline_data)
522    p = m.GetAllProcesses()[0]
523    ctr = p.counters['foo.ctr']
524
525    self.assertEqual('ctr', ctr.name)
526    self.assertEqual('foo', ctr.category)
527    self.assertEqual(3, ctr.num_samples)
528    self.assertEqual(1, ctr.num_series)
529
530    self.assertEqual(['value'], ctr.series_names)
531    self.assertEqual([0, 0.01, 0.02], ctr.timestamps)
532    self.assertEqual([0, 10, 0], ctr.samples)
533    self.assertEqual([0, 10, 0], ctr.totals)
534    self.assertEqual(10, ctr.max_total)
535
536  def testInstanceCounter(self):
537    events = [
538      {'name': 'ctr', 'args': {'value': 0}, 'pid': 1, 'ts': 0, 'cat': 'foo',
539       'tid': 1,
540       'ph': 'C', 'id': 0},
541      {'name': 'ctr', 'args': {'value': 10}, 'pid': 1, 'ts': 10, 'cat': 'foo',
542       'tid': 1,
543       'ph': 'C', 'id': 0},
544      {'name': 'ctr', 'args': {'value': 10}, 'pid': 1, 'ts': 10, 'cat': 'foo',
545       'tid': 1,
546       'ph': 'C', 'id': 1},
547      {'name': 'ctr', 'args': {'value': 20}, 'pid': 1, 'ts': 15, 'cat': 'foo',
548       'tid': 1,
549       'ph': 'C', 'id': 1},
550      {'name': 'ctr', 'args': {'value': 30}, 'pid': 1, 'ts': 18, 'cat': 'foo',
551       'tid': 1,
552       'ph': 'C', 'id': 1},
553      {'name': 'ctr', 'args': {'value': 40}, 'pid': 1, 'ts': 20, 'cat': 'bar',
554       'tid': 1,
555       'ph': 'C', 'id': 2}
556    ]
557    timeline_data = tracing_timeline_data.TracingTimelineData(events)
558    m = timeline_model.TimelineModel(timeline_data=timeline_data)
559    p = m.GetAllProcesses()[0]
560    ctr = p.counters['foo.ctr[0]']
561    self.assertEqual('ctr[0]', ctr.name)
562    self.assertEqual('foo', ctr.category)
563    self.assertEqual(2, ctr.num_samples)
564    self.assertEqual(1, ctr.num_series)
565    self.assertEqual([0, 0.01], ctr.timestamps)
566    self.assertEqual([0, 10], ctr.samples)
567
568    ctr = m.GetAllProcesses()[0].counters['foo.ctr[1]']
569    self.assertEqual('ctr[1]', ctr.name)
570    self.assertEqual('foo', ctr.category)
571    self.assertEqual(3, ctr.num_samples)
572    self.assertEqual(1, ctr.num_series)
573    self.assertEqual([0.01, 0.015, 0.018], ctr.timestamps)
574    self.assertEqual([10, 20, 30], ctr.samples)
575
576    ctr = m.GetAllProcesses()[0].counters['bar.ctr[2]']
577    self.assertEqual('ctr[2]', ctr.name)
578    self.assertEqual('bar', ctr.category)
579    self.assertEqual(1, ctr.num_samples)
580    self.assertEqual(1, ctr.num_series)
581    self.assertEqual([0.02], ctr.timestamps)
582    self.assertEqual([40], ctr.samples)
583
584  def testMultiCounterUpdateBounds(self):
585    ctr = tracing_counter.Counter(None, 'testBasicCounter',
586        'testBasicCounter')
587    ctr.series_names = ['value1', 'value2']
588    ctr.timestamps = [0, 1, 2, 3, 4, 5, 6, 7]
589    ctr.samples = [0, 0,
590                   1, 0,
591                   1, 1,
592                   2, 1.1,
593                   3, 0,
594                   1, 7,
595                   3, 0,
596                   3.1, 0.5]
597    ctr.FinalizeImport()
598    self.assertEqual(8, ctr.max_total)
599    self.assertEqual([0, 0,
600                       1, 1,
601                       1, 2,
602                       2, 3.1,
603                       3, 3,
604                       1, 8,
605                       3, 3,
606                       3.1, 3.6], ctr.totals)
607
608  def testMultiCounter(self):
609    events = [
610      {'name': 'ctr', 'args': {'value1': 0, 'value2': 7}, 'pid': 1, 'ts': 0,
611       'cat': 'foo', 'tid': 1, 'ph': 'C'},
612      {'name': 'ctr', 'args': {'value1': 10, 'value2': 4}, 'pid': 1, 'ts': 10,
613       'cat': 'foo', 'tid': 1, 'ph': 'C'},
614      {'name': 'ctr', 'args': {'value1': 0, 'value2': 1 }, 'pid': 1, 'ts': 20,
615       'cat': 'foo', 'tid': 1, 'ph': 'C'}
616    ]
617    timeline_data = tracing_timeline_data.TracingTimelineData(events)
618    m = timeline_model.TimelineModel(timeline_data=timeline_data)
619    p = m.GetAllProcesses()[0]
620    ctr = p.counters['foo.ctr']
621    self.assertEqual('ctr', ctr.name)
622
623    self.assertEqual('ctr', ctr.name)
624    self.assertEqual('foo', ctr.category)
625    self.assertEqual(3, ctr.num_samples)
626    self.assertEqual(2, ctr.num_series)
627
628    self.assertEqual(sorted(['value1', 'value2']), sorted(ctr.series_names))
629    self.assertEqual(sorted([0, 0.01, 0.02]), sorted(ctr.timestamps))
630    self.assertEqual(sorted([0, 7, 10, 4, 0, 1]), sorted(ctr.samples))
631    # We can't check ctr.totals here because it can change depending on
632    # the order in which the series names are added.
633    self.assertEqual(14, ctr.max_total)
634
635  def testImportObjectInsteadOfArray(self):
636    events = { 'traceEvents': [
637      {'name': 'a', 'args': {}, 'pid': 52, 'ts': 524, 'cat': 'foo',
638       'tid': 53, 'ph': 'B'},
639      {'name': 'a', 'args': {}, 'pid': 52, 'ts': 560, 'cat': 'foo',
640       'tid': 53, 'ph': 'E'}
641    ] }
642
643    timeline_data = tracing_timeline_data.TracingTimelineData(events)
644    m = timeline_model.TimelineModel(timeline_data=timeline_data)
645    self.assertEqual(1, len(m.GetAllProcesses()))
646
647  def testImportString(self):
648    events = [
649      {'name': 'a', 'args': {}, 'pid': 52, 'ts': 524, 'cat': 'foo',
650       'tid': 53, 'ph': 'B'},
651      {'name': 'a', 'args': {}, 'pid': 52, 'ts': 560, 'cat': 'foo',
652       'tid': 53, 'ph': 'E'}
653    ]
654
655    timeline_data = tracing_timeline_data.TracingTimelineData(
656        json.dumps(events))
657    m = timeline_model.TimelineModel(timeline_data=timeline_data)
658    self.assertEqual(1, len(m.GetAllProcesses()))
659
660  def testImportStringWithTrailingNewLine(self):
661    events = [
662      {'name': 'a', 'args': {}, 'pid': 52, 'ts': 524, 'cat': 'foo',
663       'tid': 53, 'ph': 'B'},
664      {'name': 'a', 'args': {}, 'pid': 52, 'ts': 560, 'cat': 'foo',
665       'tid': 53, 'ph': 'E'}
666    ]
667
668    timeline_data = tracing_timeline_data.TracingTimelineData(
669        json.dumps(events) + '\n')
670    m = timeline_model.TimelineModel(timeline_data=timeline_data)
671    self.assertEqual(1, len(m.GetAllProcesses()))
672
673  def testImportStringWithMissingCloseSquareBracket(self):
674    events = [
675      {'name': 'a', 'args': {}, 'pid': 52, 'ts': 524, 'cat': 'foo',
676       'tid': 53, 'ph': 'B'},
677      {'name': 'a', 'args': {}, 'pid': 52, 'ts': 560, 'cat': 'foo',
678       'tid': 53, 'ph': 'E'}
679    ]
680
681    tmp = json.dumps(events)
682    self.assertEqual(']', tmp[-1])
683
684    # Drop off the trailing ]
685    dropped = tmp[:-1]
686    timeline_data = tracing_timeline_data.TracingTimelineData(dropped)
687    m = timeline_model.TimelineModel(timeline_data=timeline_data)
688    self.assertEqual(1, len(m.GetAllProcesses()))
689
690  def testImportStringWithEndingCommaButMissingCloseSquareBracket(self):
691    lines = [
692      '[',
693      '{"name": "a", "args": {}, "pid": 52, "ts": 524, "cat": "foo", '
694        '"tid": 53, "ph": "B"},',
695      '{"name": "a", "args": {}, "pid": 52, "ts": 560, "cat": "foo", '
696        '"tid": 53, "ph": "E"},'
697      ]
698    text = '\n'.join(lines)
699
700    timeline_data = tracing_timeline_data.TracingTimelineData(text)
701    m = timeline_model.TimelineModel(timeline_data=timeline_data)
702    processes = m.GetAllProcesses()
703    self.assertEqual(1, len(processes))
704    self.assertEqual(1, len(processes[0].threads[53].all_slices))
705
706  def testImportStringWithMissingCloseSquareBracketAndNewline(self):
707    events = [
708      {'name': 'a', 'args': {}, 'pid': 52, 'ts': 524, 'cat': 'foo',
709       'tid': 53, 'ph': 'B'},
710      {'name': 'a', 'args': {}, 'pid': 52, 'ts': 560, 'cat': 'foo',
711       'tid': 53, 'ph': 'E'}
712    ]
713
714    tmp = json.dumps(events)
715    self.assertEqual(']', tmp[-1])
716
717    # Drop off the trailing ] and add a newline
718    dropped = tmp[:-1]
719    timeline_data = tracing_timeline_data.TracingTimelineData(dropped + '\n')
720    m = timeline_model.TimelineModel(timeline_data=timeline_data)
721    self.assertEqual(1, len(m.GetAllProcesses()))
722
723  def testImportStringWithEndingCommaButMissingCloseSquareBracketCRLF(self):
724    lines = [
725      '[',
726      '{"name": "a", "args": {}, "pid": 52, "ts": 524, "cat": "foo", '
727        '"tid": 53, "ph": "B"},',
728      '{"name": "a", "args": {}, "pid": 52, "ts": 560, "cat": "foo", '
729        '"tid": 53, "ph": "E"},'
730      ]
731    text = '\r\n'.join(lines)
732
733    timeline_data = tracing_timeline_data.TracingTimelineData(text)
734    m = timeline_model.TimelineModel(timeline_data=timeline_data)
735    processes = m.GetAllProcesses()
736    self.assertEqual(1, len(processes))
737    self.assertEqual(1, len(processes[0].threads[53].all_slices))
738
739  def testImportOldFormat(self):
740    lines = [
741      '[',
742      '{"cat":"a","pid":9,"tid":8,"ts":194,"ph":"E","name":"I","args":{}},',
743      '{"cat":"b","pid":9,"tid":8,"ts":194,"ph":"B","name":"I","args":{}}',
744      ']'
745      ]
746    text = '\n'.join(lines)
747    timeline_data = tracing_timeline_data.TracingTimelineData(text)
748    m = timeline_model.TimelineModel(timeline_data=timeline_data)
749    processes = m.GetAllProcesses()
750    self.assertEqual(1, len(processes))
751    self.assertEqual(1, len(processes[0].threads[8].all_slices))
752
753  def testStartFinishOneSliceOneThread(self):
754    events = [
755      # Time is intentionally out of order.
756      {'name': 'a', 'args': {}, 'pid': 52, 'ts': 560, 'cat': 'cat',
757       'tid': 53,
758         'ph': 'F', 'id': 72},
759      {'name': 'a', 'pid': 52, 'ts': 524, 'cat': 'cat',
760       'tid': 53,
761         'ph': 'S', 'id': 72, 'args': {'foo': 'bar'}}
762    ]
763
764    timeline_data = tracing_timeline_data.TracingTimelineData(events)
765    m = timeline_model.TimelineModel(timeline_data=timeline_data)
766
767    events = list(m.IterAllEvents())
768    self.assertEqual(2, len(events))
769
770    processes = m.GetAllProcesses()
771    t = processes[0].threads[53]
772    slices = t.async_slices
773    self.assertEqual(1, len(slices))
774    self.assertEqual('a', slices[0].name)
775    self.assertEqual('cat', slices[0].category)
776    self.assertEqual(72, slices[0].id)
777    self.assertEqual('bar', slices[0].args['foo'])
778    self.assertEqual(0, slices[0].start)
779    self.assertAlmostEqual((60 - 24) / 1000.0, slices[0].duration)
780    self.assertEqual(t, slices[0].start_thread)
781    self.assertEqual(t, slices[0].end_thread)
782
783  def testEndArgsAddedToSlice(self):
784    events = [
785      {'name': 'a', 'args': {'x': 1}, 'pid': 52, 'ts': 520, 'cat': 'foo',
786       'tid': 53, 'ph': 'B'},
787      {'name': 'a', 'args': {'y': 2}, 'pid': 52, 'ts': 560, 'cat': 'foo',
788       'tid': 53, 'ph': 'E'}
789    ]
790
791    timeline_data = tracing_timeline_data.TracingTimelineData(events)
792    m = timeline_model.TimelineModel(timeline_data=timeline_data)
793    processes = m.GetAllProcesses()
794    self.assertEqual(1, len(processes))
795    p = processes[0]
796
797    self.assertEqual(1, len(p.threads))
798    t = p.threads[53]
799    self.assertEqual(1, len(t.all_slices))
800    self.assertEqual(53, t.tid)
801    slice_event = t.all_slices[0]
802    self.assertEqual('a', slice_event.name)
803    self.assertEqual('foo', slice_event.category)
804    self.assertEqual(0, slice_event.start)
805    self.assertEqual(1, slice_event.args['x'])
806    self.assertEqual(2, slice_event.args['y'])
807
808  def testEndArgOverrwritesOriginalArgValueIfDuplicated(self):
809    events = [
810      {'name': 'b', 'args': {'z': 3}, 'pid': 52, 'ts': 629, 'cat': 'foo',
811       'tid': 53, 'ph': 'B'},
812      {'name': 'b', 'args': {'z': 4}, 'pid': 52, 'ts': 631, 'cat': 'foo',
813       'tid': 53, 'ph': 'E'}
814    ]
815
816    timeline_data = tracing_timeline_data.TracingTimelineData(events)
817    m = timeline_model.TimelineModel(timeline_data=timeline_data)
818    processes = m.GetAllProcesses()
819    self.assertEqual(1, len(processes))
820    p = processes[0]
821
822    self.assertEqual(1, len(p.threads))
823    t = p.threads[53]
824    slice_event = t.all_slices[0]
825    self.assertEqual('b', slice_event.name)
826    self.assertEqual('foo', slice_event.category)
827    self.assertEqual(0, slice_event.start)
828    self.assertEqual(4, slice_event.args['z'])
829
830  def testSliceHierarchy(self):
831    ''' The slice hierarchy should look something like this:
832           [            a            ]
833              [      b      ]  [ d ]
834              [ c ]     [ e ]
835    '''
836    events = [
837      {'name': 'a', 'args': {}, 'pid': 52, 'ts': 100, 'cat': 'foo',
838       'tid': 53, 'ph': 'B'},
839      {'name': 'a', 'args': {}, 'pid': 52, 'ts': 200, 'cat': 'foo',
840       'tid': 53, 'ph': 'E'},
841      {'name': 'b', 'args': {}, 'pid': 52, 'ts': 125, 'cat': 'foo',
842       'tid': 53, 'ph': 'B'},
843      {'name': 'b', 'args': {}, 'pid': 52, 'ts': 165, 'cat': 'foo',
844       'tid': 53, 'ph': 'E'},
845      {'name': 'c', 'args': {}, 'pid': 52, 'ts': 125, 'cat': 'foo',
846       'tid': 53, 'ph': 'B'},
847      {'name': 'c', 'args': {}, 'pid': 52, 'ts': 135, 'cat': 'foo',
848       'tid': 53, 'ph': 'E'},
849      {'name': 'd', 'args': {}, 'pid': 52, 'ts': 175, 'cat': 'foo',
850       'tid': 53, 'ph': 'B'},
851      {'name': 'd', 'args': {}, 'pid': 52, 'ts': 190, 'cat': 'foo',
852       'tid': 53, 'ph': 'E'},
853      {'name': 'e', 'args': {}, 'pid': 52, 'ts': 155, 'cat': 'foo',
854       'tid': 53, 'ph': 'B'},
855      {'name': 'e', 'args': {}, 'pid': 52, 'ts': 165, 'cat': 'foo',
856       'tid': 53, 'ph': 'E'}
857    ]
858    timeline_data = tracing_timeline_data.TracingTimelineData(events)
859    m = timeline_model.TimelineModel(timeline_data=timeline_data,
860                                     shift_world_to_zero=False)
861    processes = m.GetAllProcesses()
862    self.assertEqual(1, len(processes))
863    p = processes[0]
864
865    self.assertEqual(1, len(p.threads))
866    t = p.threads[53]
867
868    slice_a = t.all_slices[0]
869    self.assertEqual(4, len(slice_a.GetAllSubSlices()))
870    self.assertEqual('a', slice_a.name)
871    self.assertEqual(100 / 1000.0, slice_a.start)
872    self.assertEqual(200 / 1000.0, slice_a.end)
873    self.assertEqual(2, len(slice_a.sub_slices))
874
875    slice_b = slice_a.sub_slices[0]
876    self.assertEqual('b', slice_b.name)
877    self.assertEqual(2, len(slice_b.sub_slices))
878    self.assertEqual('c', slice_b.sub_slices[0].name)
879    self.assertEqual('e', slice_b.sub_slices[1].name)
880
881    slice_d = slice_a.sub_slices[1]
882    self.assertEqual('d', slice_d.name)
883    self.assertEqual(0, len(slice_d.sub_slices))
884
885  def testAsyncEndArgAddedToSlice(self):
886    events = [
887      # Time is intentionally out of order.
888      {'name': 'c', 'args': {'y': 2}, 'pid': 52, 'ts': 560, 'cat': 'foo',
889       'tid': 53,
890         'ph': 'F', 'id': 72},
891      {'name': 'c', 'args': {'x': 1}, 'pid': 52, 'ts': 524, 'cat': 'foo',
892       'tid': 53,
893         'ph': 'S', 'id': 72}
894    ]
895
896    timeline_data = tracing_timeline_data.TracingTimelineData(events)
897    m = timeline_model.TimelineModel(timeline_data=timeline_data)
898    t = m.GetAllProcesses()[0].threads[53]
899    self.assertEqual(1, len(t.async_slices))
900    parent_slice = t.async_slices[0]
901    self.assertEqual('c', parent_slice.name)
902    self.assertEqual('foo', parent_slice.category)
903
904    self.assertEqual(1, len(parent_slice.sub_slices))
905    sub_slice = parent_slice.sub_slices[0]
906    self.assertEqual(1, sub_slice.args['x'])
907    self.assertEqual(2, sub_slice.args['y'])
908
909  def testAsyncEndArgOverrwritesOriginalArgValueIfDuplicated(self):
910    events = [
911      # Time is intentionally out of order.
912      {'name': 'd', 'args': {'z': 4}, 'pid': 52, 'ts': 560, 'cat': 'foo',
913       'tid': 53,
914         'ph': 'F', 'id': 72},
915      {'name': 'd', 'args': {'z': 3}, 'pid': 52, 'ts': 524, 'cat': 'foo',
916       'tid': 53,
917         'ph': 'S', 'id': 72}
918    ]
919
920    timeline_data = tracing_timeline_data.TracingTimelineData(events)
921    m = timeline_model.TimelineModel(timeline_data=timeline_data)
922    t = m.GetAllProcesses()[0].threads[53]
923    self.assertEqual(1, len(t.async_slices))
924    parent_slice = t.async_slices[0]
925    self.assertEqual('d', parent_slice.name)
926    self.assertEqual('foo', parent_slice.category)
927
928    self.assertEqual(1, len(parent_slice.sub_slices))
929    sub_slice = parent_slice.sub_slices[0]
930    self.assertEqual(4, sub_slice.args['z'])
931
932  def testAsyncStepsInOneThread(self):
933    events = [
934      # Time is intentionally out of order.
935      {'name': 'a', 'args': {'z': 3}, 'pid': 52, 'ts': 560, 'cat': 'foo',
936       'tid': 53, 'ph': 'F', 'id': 72, 'tts': 25},
937      {'name': 'a', 'args': {'step': 's1', 'y': 2}, 'pid': 52, 'ts': 548,
938       'cat': 'foo', 'tid': 53, 'ph': 'T', 'id': 72, 'tts': 20},
939      {'name': 'a', 'args': {'x': 1}, 'pid': 52, 'ts': 524, 'cat': 'foo',
940       'tid': 53, 'ph': 'S', 'id': 72, 'tts': 17}
941    ]
942
943    timeline_data = tracing_timeline_data.TracingTimelineData(events)
944    m = timeline_model.TimelineModel(timeline_data=timeline_data)
945    t = m.GetAllProcesses()[0].threads[53]
946    self.assertEqual(1, len(t.async_slices))
947    parent_slice = t.async_slices[0]
948    self.assertEqual('a', parent_slice.name)
949    self.assertEqual('foo', parent_slice.category)
950    self.assertEqual(0, parent_slice.start)
951    self.assertAlmostEqual(17/1000.0, parent_slice.thread_start)
952    self.assertAlmostEqual(25/1000.0, parent_slice.thread_end)
953
954    self.assertEqual(2, len(parent_slice.sub_slices))
955    sub_slice = parent_slice.sub_slices[0]
956    self.assertEqual('a', sub_slice.name)
957    self.assertEqual('foo', sub_slice.category)
958    self.assertAlmostEqual(0, sub_slice.start)
959    self.assertAlmostEqual((548 - 524) / 1000.0, sub_slice.duration)
960    self.assertAlmostEqual((20 - 17) / 1000.0, sub_slice.thread_duration)
961    self.assertEqual(1, sub_slice.args['x'])
962
963    sub_slice = parent_slice.sub_slices[1]
964    self.assertEqual('a:s1', sub_slice.name)
965    self.assertEqual('foo', sub_slice.category)
966    self.assertAlmostEqual((548 - 524) / 1000.0, sub_slice.start)
967    self.assertAlmostEqual((560 - 548) / 1000.0, sub_slice.duration)
968    self.assertAlmostEqual((25 - 20) / 1000.0, sub_slice.thread_duration)
969    self.assertEqual(2, sub_slice.args['y'])
970    self.assertEqual(3, sub_slice.args['z'])
971
972  def testAsyncStepsMissingStart(self):
973    events = [
974      # Time is intentionally out of order.
975      {'name': 'a', 'args': {'z': 3}, 'pid': 52, 'ts': 560, 'cat': 'foo',
976       'tid': 53, 'ph': 'F', 'id': 72},
977      {'name': 'a', 'args': {'step': 's1', 'y': 2}, 'pid': 52, 'ts': 548,
978       'cat': 'foo', 'tid': 53, 'ph': 'T', 'id': 72}
979    ]
980
981    timeline_data = tracing_timeline_data.TracingTimelineData(events)
982    m = timeline_model.TimelineModel(timeline_data=timeline_data)
983    t = m.GetAllProcesses()[0].threads[53]
984    self.assertTrue(t is not None)
985
986  def testAsyncStepsMissingFinish(self):
987    events = [
988      # Time is intentionally out of order.
989      {'name': 'a', 'args': {'step': 's1', 'y': 2}, 'pid': 52, 'ts': 548,
990       'cat': 'foo', 'tid': 53, 'ph': 'T', 'id': 72},
991      {'name': 'a', 'args': {'z': 3}, 'pid': 52, 'ts': 560, 'cat': 'foo',
992       'tid': 53, 'ph': 'S', 'id': 72}
993    ]
994
995    timeline_data = tracing_timeline_data.TracingTimelineData(events)
996    m = timeline_model.TimelineModel(timeline_data=timeline_data)
997    t = m.GetAllProcesses()[0].threads[53]
998    self.assertTrue(t is not None)
999
1000  def testImportSamples(self):
1001    events = [
1002      {'name': 'a', 'args': {}, 'pid': 52, 'ts': 548, 'cat': 'test',
1003       'tid': 53, 'ph': 'P'},
1004      {'name': 'b', 'args': {}, 'pid': 52, 'ts': 548, 'cat': 'test',
1005       'tid': 53, 'ph': 'P'},
1006      {'name': 'c', 'args': {}, 'pid': 52, 'ts': 558, 'cat': 'test',
1007       'tid': 53, 'ph': 'P'}
1008    ]
1009    timeline_data = tracing_timeline_data.TracingTimelineData(events)
1010    m = timeline_model.TimelineModel(timeline_data=timeline_data)
1011    p = m.GetAllProcesses()[0]
1012    t = p.threads[53]
1013    self.assertEqual(3, len(t.samples))
1014    self.assertEqual(0.0, t.samples[0].start)
1015    self.assertEqual(0.0, t.samples[1].start)
1016    self.assertAlmostEqual(0.01, t.samples[2].start)
1017    self.assertEqual('a', t.samples[0].name)
1018    self.assertEqual('b', t.samples[1].name)
1019    self.assertEqual('c', t.samples[2].name)
1020    self.assertEqual(0, len(m.import_errors))
1021
1022  def testImportSamplesMissingArgs(self):
1023    events = [
1024      {'name': 'a', 'pid': 52, 'ts': 548, 'cat': 'test',
1025       'tid': 53, 'ph': 'P'},
1026      {'name': 'b', 'pid': 52, 'ts': 548, 'cat': 'test',
1027       'tid': 53, 'ph': 'P'},
1028      {'name': 'c', 'pid': 52, 'ts': 549, 'cat': 'test',
1029       'tid': 53, 'ph': 'P'}
1030    ]
1031    timeline_data = tracing_timeline_data.TracingTimelineData(events)
1032    m = timeline_model.TimelineModel(timeline_data=timeline_data)
1033    p = m.GetAllProcesses()[0]
1034    t = p.threads[53]
1035    self.assertEqual(3, len(t.samples))
1036    self.assertEqual(0, len(m.import_errors))
1037
1038  def testImportCompleteEvent(self):
1039    events = [
1040      {'name': 'a', 'args': {}, 'pid': 52, 'ts': 629, 'tts': 538, 'dur': 1,
1041       'tdur': 1, 'cat': 'baz', 'tid': 53, 'ph': 'X'},
1042      {'name': 'b', 'args': {}, 'pid': 52, 'ts': 730, 'tts': 620, 'dur': 20,
1043       'tdur': 14, 'cat': 'foo', 'tid': 53, 'ph': 'X'},
1044      {'name': 'c', 'args': {}, 'pid': 52, 'ts': 740, 'tts': 625, 'cat': 'baz',
1045       'tid': 53, 'ph': 'X'},
1046    ]
1047    timeline_data = tracing_timeline_data.TracingTimelineData(events)
1048    m = timeline_model.TimelineModel(timeline_data=timeline_data)
1049    p = m.GetAllProcesses()[0]
1050    t = p.threads[53]
1051    self.assertEqual(3, len(t.all_slices))
1052
1053    slice_event = t.all_slices[0]
1054    self.assertEqual('a', slice_event.name)
1055    self.assertAlmostEqual(0.0, slice_event.start)
1056    self.assertAlmostEqual(1 / 1000.0, slice_event.duration)
1057    self.assertAlmostEqual(538 / 1000.0, slice_event.thread_start)
1058    self.assertAlmostEqual(1 / 1000.0, slice_event.thread_duration)
1059    self.assertFalse(slice_event.did_not_finish)
1060    self.assertEqual(0, len(slice_event.sub_slices))
1061
1062    slice_event = t.all_slices[1]
1063    self.assertEqual('b', slice_event.name)
1064    self.assertAlmostEqual((730 - 629) / 1000.0, slice_event.start)
1065    self.assertAlmostEqual(20 / 1000.0, slice_event.duration)
1066    self.assertAlmostEqual(620 / 1000.0, slice_event.thread_start)
1067    self.assertAlmostEqual(14 / 1000.0, slice_event.thread_duration)
1068    self.assertFalse(slice_event.did_not_finish)
1069    self.assertEqual(1, len(slice_event.sub_slices))
1070    self.assertEqual(t.all_slices[2], slice_event.sub_slices[0])
1071
1072    slice_event = t.all_slices[2]
1073    self.assertEqual('c', slice_event.name)
1074    self.assertAlmostEqual((740 - 629) / 1000.0, slice_event.start)
1075    self.assertAlmostEqual(10 / 1000.0, slice_event.duration)
1076    self.assertAlmostEqual(625 / 1000.0, slice_event.thread_start)
1077    self.assertAlmostEqual(9 / 1000.0, slice_event.thread_duration)
1078    self.assertTrue(slice_event.did_not_finish)
1079    self.assertEqual(0, len(slice_event.sub_slices))
1080
1081  def testImportFlowEvent(self):
1082    events = [
1083      {'name': 'a', 'cat': 'foo', 'id': 72, 'pid': 52, 'tid': 53, 'ts': 548,
1084       'ph': 's', 'args': {}},
1085      {'name': 'a', 'cat': 'foo', 'id': 72, 'pid': 52, 'tid': 53, 'ts': 560,
1086       'ph': 't', 'args': {}},
1087      {'name': 'a', 'cat': 'foo', 'id': 72, 'pid': 52, 'tid': 53, 'ts': 580,
1088       'ph': 'f', 'args': {}},
1089    ]
1090
1091    timeline_data = tracing_timeline_data.TracingTimelineData(events)
1092    m = timeline_model.TimelineModel(timeline_data=timeline_data)
1093    p = m.GetAllProcesses()[0]
1094    t = p.threads[53]
1095    self.assertTrue(t is not None)
1096    self.assertEqual(2, len(m.flow_events))
1097
1098    start = m.flow_events[0][0]
1099    step = m.flow_events[0][1]
1100    finish = m.flow_events[1][1]
1101
1102    self.assertEqual('a', start.name)
1103    self.assertEqual('foo', start.category)
1104    self.assertEqual(72, start.event_id)
1105    self.assertEqual(0, start.start)
1106    self.assertEqual(0, start.duration)
1107
1108    self.assertEqual(start.name, step.name)
1109    self.assertEqual(start.category, step.category)
1110    self.assertEqual(start.event_id, step.event_id)
1111    self.assertAlmostEqual(12 / 1000.0, step.start)
1112    self.assertEquals(0, step.duration)
1113
1114    self.assertEqual(start.name, finish.name)
1115    self.assertEqual(start.category, finish.category)
1116    self.assertEqual(start.event_id, finish.event_id)
1117    self.assertAlmostEqual((20 + 12) / 1000.0, finish.start)
1118    self.assertEqual(0, finish.duration)
1119
1120  def testImportOutOfOrderFlowEvent(self):
1121    events = [
1122      {'name': 'a', 'cat': 'foo', 'id': 72, 'pid': 52, 'tid': 53, 'ts': 548,
1123       'ph': 's', 'args': {}},
1124      {'name': 'b', 'cat': 'foo', 'id': 73, 'pid': 52, 'tid': 53, 'ts': 148,
1125       'ph': 's', 'args': {}},
1126      {'name': 'b', 'cat': 'foo', 'id': 73, 'pid': 52, 'tid': 53, 'ts': 570,
1127       'ph': 'f', 'args': {}},
1128      {'name': 'a', 'cat': 'foo', 'id': 72, 'pid': 52, 'tid': 53, 'ts': 560,
1129       'ph': 't', 'args': {}},
1130      {'name': 'a', 'cat': 'foo', 'id': 72, 'pid': 52, 'tid': 53, 'ts': 580,
1131       'ph': 'f', 'args': {}},
1132    ]
1133
1134    expected = [[0.4, 0.412], [0.0, 0.422], [0.412, 0.432]]
1135    timeline_data = tracing_timeline_data.TracingTimelineData(events)
1136    m = timeline_model.TimelineModel(timeline_data=timeline_data)
1137    self.assertEqual(3, len(m.flow_events))
1138
1139    for i in range(len(expected)):
1140      self.assertAlmostEqual(expected[i][0], m.flow_events[i][0].start)
1141      self.assertAlmostEqual(expected[i][1], m.flow_events[i][1].start)
1142
1143  def testImportErrornousFlowEvent(self):
1144    events = [
1145      {'name': 'a', 'cat': 'foo', 'id': 70, 'pid': 52, 'tid': 53, 'ts': 548,
1146       'ph': 's', 'args': {}},
1147      {'name': 'a2', 'cat': 'foo', 'id': 70, 'pid': 52, 'tid': 53, 'ts': 550,
1148       'ph': 's', 'args': {}},
1149      {'name': 'b', 'cat': 'foo', 'id': 73, 'pid': 52, 'tid': 53, 'ts': 570,
1150       'ph': 'f', 'args': {}},
1151      {'name': 'a', 'cat': 'foo', 'id': 72, 'pid': 52, 'tid': 53, 'ts': 560,
1152       'ph': 't', 'args': {}},
1153    ]
1154
1155    timeline_data = tracing_timeline_data.TracingTimelineData(events)
1156    m = timeline_model.TimelineModel(timeline_data=timeline_data)
1157    self.assertEqual(0, len(m.flow_events))
1158
1159  def testImportOverflowedTrace(self):
1160    events = [
1161      {'name': 'a', 'args': {}, 'pid': 1, 'ts': 7, 'cat': 'foo',
1162       'tid': 1, 'ph': 'B'},
1163      {'name': 'a', 'args': {}, 'pid': 1, 'ts': 8, 'cat': 'foo',
1164       'tid': 1, 'ph': 'E'},
1165      {'name': 'b', 'args': {}, 'pid': 2, 'ts': 9, 'cat': 'foo',
1166       'tid': 2, 'ph': 'B'},
1167      {'name': 'b', 'args': {}, 'pid': 2, 'ts': 10, 'cat': 'foo',
1168       'tid': 2, 'ph': 'E'},
1169      {'name': 'trace_buffer_overflowed',
1170       'args': {'overflowed_at_ts': 12},
1171        'pid': 2, 'ts': 0, 'tid': 2, 'ph': 'M'}
1172    ]
1173    timeline_data = tracing_timeline_data.TracingTimelineData(events)
1174
1175    with self.assertRaises(trace_event_importer.TraceBufferOverflowException) \
1176        as context:
1177      timeline_model.TimelineModel(timeline_data=timeline_data)
1178    self.assertTrue(
1179        'Trace buffer of process with pid=2 overflowed at timestamp 12' in
1180        context.exception.message)
1181
1182
1183  def testTraceEventsWithTabIdsMarkers(self):
1184    trace_events = [
1185      {'name': 'a', 'args': {}, 'pid': 1, 'ts': 20, 'tts': 10, 'cat': 'foo',
1186       'tid': 1, 'ph': 'B'},
1187      # tab-id-1
1188      {'name': 'tab-id-1', 'args': {}, 'pid': 1, 'ts': 25, 'cat': 'foo',
1189       'tid': 1,
1190         'ph': 'S', 'id': 72},
1191      {'name': 'a', 'args': {}, 'pid': 1, 'ts': 30, 'tts': 20, 'cat': 'foo',
1192       'tid': 1, 'ph': 'E'},
1193      {'name': 'tab-id-1', 'args': {}, 'pid': 1, 'ts': 35, 'cat': 'foo',
1194       'tid': 1,
1195         'ph': 'F', 'id': 72},
1196      # tab-id-2
1197      {'name': 'tab-id-2', 'args': {}, 'pid': 1, 'ts': 25, 'cat': 'foo',
1198       'tid': 2,
1199         'ph': 'S', 'id': 72},
1200      {'name': 'tab-id-2', 'args': {}, 'pid': 1, 'ts': 26, 'cat': 'foo',
1201       'tid': 2,
1202         'ph': 'F', 'id': 72},
1203     ]
1204    event_data = {'traceEvents': trace_events,
1205                  'tabIds': ['tab-id-1', 'tab-id-2']}
1206    timeline_data = tracing_timeline_data.TracingTimelineData(event_data)
1207    m = timeline_model.TimelineModel(timeline_data=timeline_data)
1208    processes = m.GetAllProcesses()
1209    self.assertEqual(1, len(processes))
1210    self.assertIs(processes[0], m.GetRendererProcessFromTabId('tab-id-1'))
1211    self.assertIs(processes[0], m.GetRendererProcessFromTabId('tab-id-2'))
1212
1213    p = processes[0]
1214    self.assertEqual(2, len(p.threads))
1215    self.assertIs(p.threads[1], m.GetRendererThreadFromTabId('tab-id-1'))
1216    self.assertIs(p.threads[2], m.GetRendererThreadFromTabId('tab-id-2'))
1217