sdk/platform-tools/systrace/catapult/telemetry/telemetry/internal/backends/chrome_inspector/tracing_backend_unittest.py

   1 # Copyright 2013 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
   5 import timeit
   6 import unittest
   7
   8 from telemetry import decorators
   9 from telemetry.internal.backends.chrome_inspector import tracing_backend
  10 from telemetry.internal.backends.chrome_inspector.tracing_backend import _DevToolsStreamReader
  11 from telemetry.testing import fakes
  12 from telemetry.testing import tab_test_case
  13 from telemetry.timeline import chrome_trace_config
  14 from telemetry.timeline import model as model_module
  15 from telemetry.timeline import tracing_config
  16 from tracing.trace_data import trace_data
  17
  18
  19 class TracingBackendTest(tab_test_case.TabTestCase):
  20
  21   # Number of consecutively requested memory dumps.
  22   _REQUESTED_DUMP_COUNT = 3
  23
  24   @classmethod
  25   def CustomizeBrowserOptions(cls, options):
  26     options.logging_verbosity = options.VERBOSE_LOGGING
  27     options.AppendExtraBrowserArgs([
  28         # Memory maps currently cannot be retrieved on sandboxed processes.
  29         # See crbug.com/461788.
  30         '--no-sandbox',
  31     ])
  32
  33   def setUp(self):
  34     super(TracingBackendTest, self).setUp()
  35     self._tracing_controller = self._browser.platform.tracing_controller
  36     if not self._tracing_controller.IsChromeTracingSupported():
  37       self.skipTest('Browser does not support tracing, skipping test.')
  38     if not self._browser.supports_memory_dumping:
  39       self.skipTest('Browser does not support memory dumping, skipping test.')
  40
  41   # win: https://github.com/catapult-project/catapult/issues/3131.
  42   # chromeos: http://crbug.com/622836.
  43   @decorators.Disabled('win', 'chromeos')
  44   def testDumpMemorySuccess(self):
  45     # Check that dumping memory before tracing starts raises an exception.
  46     self.assertRaises(Exception, self._browser.DumpMemory)
  47
  48     # Start tracing with memory dumps enabled.
  49     config = tracing_config.TracingConfig()
  50     config.chrome_trace_config.category_filter.AddDisabledByDefault(
  51         'disabled-by-default-memory-infra')
  52     config.chrome_trace_config.SetMemoryDumpConfig(
  53         chrome_trace_config.MemoryDumpConfig())
  54     config.enable_chrome_trace = True
  55     self._tracing_controller.StartTracing(config)
  56
  57     # Request several memory dumps in a row and test that they were all
  58     # successfully created with unique IDs.
  59     expected_dump_ids = []
  60     for _ in xrange(self._REQUESTED_DUMP_COUNT):
  61       dump_id = self._browser.DumpMemory()
  62       self.assertIsNotNone(dump_id)
  63       self.assertNotIn(dump_id, expected_dump_ids)
  64       expected_dump_ids.append(dump_id)
  65
  66     tracing_data = self._tracing_controller.StopTracing()
  67
  68     # Check that clock sync data is in tracing data.
  69     clock_sync_found = False
  70     trace = tracing_data.GetTraceFor(trace_data.CHROME_TRACE_PART)
  71     for event in trace['traceEvents']:
  72       if event['name'] == 'clock_sync' or 'ClockSyncEvent' in event['name']:
  73         clock_sync_found = True
  74         break
  75     self.assertTrue(clock_sync_found)
  76
  77     # Check that dumping memory after tracing stopped raises an exception.
  78     self.assertRaises(Exception, self._browser.DumpMemory)
  79
  80     # Test that trace data is parsable.
  81     model = model_module.TimelineModel(tracing_data)
  82     self.assertGreater(len(model.processes), 0)
  83
  84     # Test that the resulting model contains the requested memory dumps in the
  85     # correct order (and nothing more).
  86     actual_dump_ids = [d.dump_id for d in model.IterGlobalMemoryDumps()]
  87     self.assertEqual(actual_dump_ids, expected_dump_ids)
  88
  89   def testDumpMemoryFailure(self):
  90     # Check that dumping memory before tracing starts raises an exception.
  91     self.assertRaises(Exception, self._browser.DumpMemory)
  92
  93     # Start tracing with memory dumps disabled.
  94     config = tracing_config.TracingConfig()
  95     config.enable_chrome_trace = True
  96     self._tracing_controller.StartTracing(config)
  97
  98     # Check that the method returns None if the dump was not successful.
  99     self.assertIsNone(self._browser.DumpMemory())
 100
 101     tracing_data = self._tracing_controller.StopTracing()
 102
 103     # Check that dumping memory after tracing stopped raises an exception.
 104     self.assertRaises(Exception, self._browser.DumpMemory)
 105
 106     # Test that trace data is parsable.
 107     model = model_module.TimelineModel(tracing_data)
 108     self.assertGreater(len(model.processes), 0)
 109
 110     # Test that the resulting model contains no memory dumps.
 111     self.assertEqual(len(list(model.IterGlobalMemoryDumps())), 0)
 112
 113
 114 class TracingBackendUnittest(unittest.TestCase):
 115   def setUp(self):
 116     self._fake_timer = fakes.FakeTimer(tracing_backend)
 117     self._inspector_socket = fakes.FakeInspectorWebsocket(self._fake_timer)
 118
 119   def tearDown(self):
 120     self._fake_timer.Restore()
 121
 122   def _GetRawChromeTracesFor(self, trace_data_builder):
 123     data = trace_data_builder.AsData().GetTracesFor(
 124         trace_data.CHROME_TRACE_PART)
 125     traces = []
 126     for d in data:
 127       traces.append(d)
 128     return traces
 129
 130   def testCollectTracingDataTimeout(self):
 131     self._inspector_socket.AddEvent(
 132         'Tracing.dataCollected', {'value': {'traceEvents': [{'ph': 'B'}]}}, 9)
 133     self._inspector_socket.AddEvent(
 134         'Tracing.dataCollected', {'value': {'traceEvents': [{'ph': 'E'}]}}, 19)
 135     self._inspector_socket.AddEvent('Tracing.tracingComplete', {}, 35)
 136     backend = tracing_backend.TracingBackend(self._inspector_socket)
 137
 138     trace_data_builder = trace_data.TraceDataBuilder()
 139     # The third response is 16 seconds after the second response, so we expect
 140     # a TracingTimeoutException.
 141     with self.assertRaises(tracing_backend.TracingTimeoutException):
 142       backend._CollectTracingData(trace_data_builder, 10)
 143     traces = self._GetRawChromeTracesFor(trace_data_builder)
 144     self.assertEqual(2, len(traces))
 145     self.assertEqual(1, len(traces[0].get('traceEvents', [])))
 146     self.assertEqual(1, len(traces[1].get('traceEvents', [])))
 147     self.assertFalse(backend._has_received_all_tracing_data)
 148
 149   def testCollectTracingDataNoTimeout(self):
 150     self._inspector_socket.AddEvent(
 151         'Tracing.dataCollected', {'value': {'traceEvents': [{'ph': 'B'}]}}, 9)
 152     self._inspector_socket.AddEvent(
 153         'Tracing.dataCollected', {'value': {'traceEvents': [{'ph': 'E'}]}}, 14)
 154     self._inspector_socket.AddEvent('Tracing.tracingComplete', {}, 19)
 155     backend = tracing_backend.TracingBackend(self._inspector_socket)
 156     trace_data_builder = trace_data.TraceDataBuilder()
 157     backend._CollectTracingData(trace_data_builder, 10)
 158     traces = self._GetRawChromeTracesFor(trace_data_builder)
 159     self.assertEqual(2, len(traces))
 160     self.assertEqual(1, len(traces[0].get('traceEvents', [])))
 161     self.assertEqual(1, len(traces[1].get('traceEvents', [])))
 162     self.assertTrue(backend._has_received_all_tracing_data)
 163
 164   def testCollectTracingDataFromStreamNoContainer(self):
 165     self._inspector_socket.AddEvent(
 166         'Tracing.tracingComplete', {'stream': '42'}, 1)
 167     self._inspector_socket.AddAsyncResponse(
 168         'IO.read', {'data': '{"traceEvents": [{},{},{'}, 2)
 169     self._inspector_socket.AddAsyncResponse(
 170         'IO.read', {'data': '},{},{}]}', 'eof': True}, 3)
 171     backend = tracing_backend.TracingBackend(self._inspector_socket)
 172     trace_data_builder = trace_data.TraceDataBuilder()
 173     backend._CollectTracingData(trace_data_builder, 10)
 174     trace_events = self._GetRawChromeTracesFor(trace_data_builder)[0].get(
 175         'traceEvents', [])
 176     self.assertEqual(5, len(trace_events))
 177     self.assertTrue(backend._has_received_all_tracing_data)
 178
 179   def testCollectTracingDataFromStreamJSONContainer(self):
 180     self._inspector_socket.AddEvent(
 181         'Tracing.tracingComplete', {'stream': '42'}, 1)
 182     self._inspector_socket.AddAsyncResponse(
 183         'IO.read', {'data': '{"traceEvents": [{},{},{}],'}, 2)
 184     self._inspector_socket.AddAsyncResponse(
 185         'IO.read', {'data': '"metadata": {"a": "b"}'}, 3)
 186     self._inspector_socket.AddAsyncResponse(
 187         'IO.read', {'data': '}', 'eof': True}, 4)
 188     backend = tracing_backend.TracingBackend(self._inspector_socket)
 189     trace_data_builder = trace_data.TraceDataBuilder()
 190     backend._CollectTracingData(trace_data_builder, 10)
 191     chrome_trace = self._GetRawChromeTracesFor(trace_data_builder)[0]
 192
 193     self.assertEqual(3, len(chrome_trace.get('traceEvents', [])))
 194     self.assertEqual(dict, type(chrome_trace.get('metadata')))
 195     self.assertTrue(backend._has_received_all_tracing_data)
 196
 197   def testDumpMemorySuccess(self):
 198     self._inspector_socket.AddResponseHandler(
 199         'Tracing.requestMemoryDump',
 200         lambda req: {'result': {'success': True, 'dumpGuid': '42abc'}})
 201     backend = tracing_backend.TracingBackend(self._inspector_socket)
 202
 203     self.assertEqual(backend.DumpMemory(), '42abc')
 204
 205   def testDumpMemoryFailure(self):
 206     self._inspector_socket.AddResponseHandler(
 207         'Tracing.requestMemoryDump',
 208         lambda req: {'result': {'success': False, 'dumpGuid': '42abc'}})
 209     backend = tracing_backend.TracingBackend(self._inspector_socket)
 210
 211     self.assertIsNone(backend.DumpMemory())
 212
 213   def testStartTracingFailure(self):
 214     self._inspector_socket.AddResponseHandler(
 215         'Tracing.start',
 216         lambda req: {'error': {'message': 'Tracing is already started'}})
 217     self._inspector_socket.AddResponseHandler(
 218         'Tracing.hasCompleted', lambda req: {})
 219     backend = tracing_backend.TracingBackend(self._inspector_socket)
 220     config = tracing_config.TracingConfig()
 221     self.assertRaisesRegexp(
 222         tracing_backend.TracingUnexpectedResponseException,
 223         'Tracing is already started',
 224         backend.StartTracing, config.chrome_trace_config)
 225
 226   def testStartTracingWithoutCollection(self):
 227     self._inspector_socket.AddResponseHandler('Tracing.start', lambda req: {})
 228     self._inspector_socket.AddEvent(
 229         'Tracing.dataCollected', {'value': [{'ph': 'B'}]}, 1)
 230     self._inspector_socket.AddEvent(
 231         'Tracing.dataCollected', {'value': [{'ph': 'E'}]}, 2)
 232     self._inspector_socket.AddEvent('Tracing.tracingComplete', {}, 3)
 233     self._inspector_socket.AddResponseHandler(
 234         'Tracing.hasCompleted', lambda req: {})
 235
 236     backend = tracing_backend.TracingBackend(self._inspector_socket)
 237     config = tracing_config.TracingConfig()
 238     backend.StartTracing(config._chrome_trace_config)
 239     backend.StopTracing()
 240     with self.assertRaisesRegexp(AssertionError, 'Data not collected from .*'):
 241       backend.StartTracing(config._chrome_trace_config)
 242
 243
 244 class DevToolsStreamPerformanceTest(unittest.TestCase):
 245   def setUp(self):
 246     self._fake_timer = fakes.FakeTimer(tracing_backend)
 247     self._inspector_socket = fakes.FakeInspectorWebsocket(self._fake_timer)
 248
 249   def _MeasureReadTime(self, count):
 250     fake_time = self._fake_timer.time() + 1
 251     payload = ','.join(['{}'] * 5000)
 252     self._inspector_socket.AddAsyncResponse('IO.read', {'data': '[' + payload},
 253                                             fake_time)
 254     startClock = timeit.default_timer()
 255
 256     done = {'done': False}
 257     def mark_done(data):
 258       del data  # unused
 259       done['done'] = True
 260
 261     reader = _DevToolsStreamReader(self._inspector_socket, 'dummy')
 262     reader.Read(mark_done)
 263     while not done['done']:
 264       fake_time += 1
 265       if count > 0:
 266         self._inspector_socket.AddAsyncResponse('IO.read', {'data': payload},
 267             fake_time)
 268       elif count == 0:
 269         self._inspector_socket.AddAsyncResponse('IO.read',
 270             {'data': payload + ']', 'eof': True}, fake_time)
 271       count -= 1
 272       self._inspector_socket.DispatchNotifications(10)
 273     return timeit.default_timer() - startClock
 274
 275   def testReadTime(self):
 276     n1 = 1000
 277     while True:
 278       t1 = self._MeasureReadTime(n1)
 279       if t1 > 0.01:
 280         break
 281       n1 *= 5
 282     t2 = self._MeasureReadTime(n1 * 10)
 283     # Time is an illusion, CPU time is doubly so, allow great deal of tolerance.
 284     toleranceFactor = 5
 285     self.assertLess(t2, t1 * 10 * toleranceFactor)