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