src/third_party/trace-viewer/src/tracing/importer/linux_perf_importer_test.js

   1 // Copyright (c) 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 'use strict';
   6
   7 tvcm.require('tracing.test_utils');
   8 tvcm.require('tracing.importer.linux_perf_importer');
   9
  10 tvcm.unittest.testSuite('tracing.importer.linux_perf_importer_test', function() { // @suppress longLineCheck
  11   test('lineParserWithLegacyFmt', function() {
  12     var p = tracing.importer._LinuxPerfImporterTestExports.lineParserWithLegacyFmt; // @suppress longLineCheck
  13     var x = p('   <idle>-0     [001]  4467.843475: sched_switch: ' +
  14         'prev_comm=swapper prev_pid=0 prev_prio=120 prev_state=R ==> ' +
  15         'next_comm=SurfaceFlinger next_pid=178 next_prio=112');
  16     assertNotNull(x);
  17     assertEquals('<idle>', x.threadName);
  18     assertEquals('0', x.pid);
  19     assertEquals('001', x.cpuNumber);
  20     assertEquals('4467.843475', x.timestamp);
  21     assertEquals('sched_switch', x.eventName);
  22     assertEquals('prev_comm=swapper prev_pid=0 prev_prio=120 prev_state=R' +
  23         ' ==> next_comm=SurfaceFlinger next_pid=178 next_prio=112', x.details);
  24
  25     var x = p('Binder-Thread #-647   [001]   260.464294: sched_switch: ' +
  26         'prev_comm=Binder Thread # prev_pid=647 prev_prio=120 prev_state=D ' +
  27         ' ==> next_comm=.android.chrome next_pid=1562 next_prio=120');
  28     assertNotNull(x);
  29     assertEquals('Binder-Thread #', x.threadName);
  30     assertEquals('647', x.pid);
  31   });
  32
  33   test('lineParserWithIRQInfo', function() {
  34     var p = tracing.importer._LinuxPerfImporterTestExports.lineParserWithIRQInfo; // @suppress longLineCheck
  35     var x = p('     systrace.sh-5441  [001] d...  1031.091570: ' +
  36         'sched_wakeup: comm=debugd pid=4978 prio=120 success=1 target_cpu=000');
  37     assertNotNull(x);
  38     assertEquals('systrace.sh', x.threadName);
  39     assertEquals('5441', x.pid);
  40     assertEquals('001', x.cpuNumber);
  41     assertEquals('1031.091570', x.timestamp);
  42     assertEquals('sched_wakeup', x.eventName);
  43     assertEquals('comm=debugd pid=4978 prio=120 success=1 target_cpu=000', x.details); // @suppress longLineCheck
  44   });
  45
  46   test('lineParserWithTGID', function() {
  47     var p = tracing.importer._LinuxPerfImporterTestExports.lineParserWithTGID;
  48     var x = p('     systrace.sh-5441  (54321) [001] d...  1031.091570: ' +
  49         'sched_wakeup: comm=debugd pid=4978 prio=120 success=1 target_cpu=000');
  50     assertNotNull(x);
  51     assertEquals('systrace.sh', x.threadName);
  52     assertEquals('5441', x.pid);
  53     assertEquals('54321', x.tgid);
  54     assertEquals('001', x.cpuNumber);
  55     assertEquals('1031.091570', x.timestamp);
  56     assertEquals('sched_wakeup', x.eventName);
  57     assertEquals('comm=debugd pid=4978 prio=120 success=1 target_cpu=000', x.details); // @suppress longLineCheck
  58
  59     var x = p('     systrace.sh-5441  (  321) [001] d...  1031.091570: ' +
  60         'sched_wakeup: comm=debugd pid=4978 prio=120 success=1 target_cpu=000');
  61     assertNotNull(x);
  62     assertEquals('321', x.tgid);
  63
  64     var x = p('     systrace.sh-5441  (-----) [001] d...  1031.091570: ' +
  65         'sched_wakeup: comm=debugd pid=4978 prio=120 success=1 target_cpu=000');
  66     assertNotNull(x);
  67     assertEquals(undefined, x.tgid);
  68   });
  69
  70   test('autodetectLineCornerCases', function() {
  71     var detectParser =
  72         tracing.importer._LinuxPerfImporterTestExports.autoDetectLineParser;
  73     var lineParserWithLegacyFmt =
  74         tracing.importer._LinuxPerfImporterTestExports.lineParserWithLegacyFmt;
  75     var lineParserWithIRQInfo =
  76         tracing.importer._LinuxPerfImporterTestExports.lineParserWithIRQInfo;
  77     var lineParserWithTGID =
  78         tracing.importer._LinuxPerfImporterTestExports.lineParserWithTGID;
  79
  80     var lineWithLegacyFmt =
  81         'systrace.sh-8170  [001] 15180.978813: sched_switch: ' +
  82         'prev_comm=systrace.sh prev_pid=8170 prev_prio=120 ' +
  83         'prev_state=x ==> next_comm=kworker/1:0 next_pid=7873 ' +
  84         'next_prio=120';
  85     var detected = detectParser(lineWithLegacyFmt);
  86     assertEquals(detected, lineParserWithLegacyFmt);
  87
  88     var lineWithIRQInfo =
  89         'systrace.sh-8170  [001] d... 15180.978813: sched_switch: ' +
  90         'prev_comm=systrace.sh prev_pid=8170 prev_prio=120 ' +
  91         'prev_state=x ==> next_comm=kworker/1:0 next_pid=7873 ' +
  92         'next_prio=120';
  93     var detected = detectParser(lineWithIRQInfo);
  94     assertEquals(detected, lineParserWithIRQInfo);
  95
  96     var lineWithTGID =
  97         'systrace.sh-8170  (54321) [001] d... 15180.978813: sched_switch: ' +
  98         'prev_comm=systrace.sh prev_pid=8170 prev_prio=120 ' +
  99         'prev_state=x ==> next_comm=kworker/1:0 next_pid=7873 ' +
 100         'next_prio=120';
 101     var detected = detectParser(lineWithTGID);
 102     assertEquals(detected, lineParserWithTGID);
 103   });
 104
 105   test('traceEventClockSyncRE', function() {
 106     var re = tracing.importer._LinuxPerfImporterTestExports.traceEventClockSyncRE; // @suppress longLineCheck
 107     var x = re.exec('trace_event_clock_sync: parent_ts=19581477508');
 108     assertNotNull(x);
 109     assertEquals('19581477508', x[1]);
 110
 111     var x = re.exec('trace_event_clock_sync: parent_ts=123.456');
 112     assertNotNull(x);
 113     assertEquals('123.456', x[1]);
 114   });
 115
 116   test('canImport', function() {
 117     var lines = [
 118       '# tracer: nop',
 119       '#',
 120       '#           TASK-PID    CPU#    TIMESTAMP  FUNCTION',
 121       '#              | |       |          |         |',
 122       '          <idle>-0     [001]  4467.843475: sched_switch: ' +
 123           'prev_comm=swapper prev_pid=0 prev_prio=120 prev_state=R ==> ' +
 124           'next_comm=SurfaceFlinger next_pid=178 next_prio=112',
 125
 126       '  SurfaceFlinger-178   [001]  4467.843536: sched_switch: ' +
 127           'prev_comm=SurfaceFlinger prev_pid=178 prev_prio=112 prev_state=S ' +
 128           '==> next_comm=kworker/u:2 next_pid=2844 next_prio=120',
 129
 130       '     kworker/u:2-2844  [001]  4467.843567: sched_switch: ' +
 131           'prev_comm=kworker/u:2 prev_pid=2844 prev_prio=120 prev_state=S ' +
 132           '==> next_comm=swapper next_pid=0 next_prio=120',
 133
 134       '          <idle>-0     [001]  4467.844208: sched_switch: ' +
 135           'prev_comm=swapper prev_pid=0 prev_prio=120 prev_state=R ==> ' +
 136           'next_comm=kworker/u:2 next_pid=2844 next_prio=120'
 137     ];
 138     assertTrue(tracing.importer.LinuxPerfImporter.canImport(lines.join('\n')));
 139
 140     var lines = [
 141       '          <idle>-0     [001]  4467.843475: sched_switch: ' +
 142           'prev_comm=swapper prev_pid=0 prev_prio=120 prev_state=R ==> ' +
 143               'next_comm=SurfaceFlinger next_pid=178 next_prio=112'
 144     ];
 145     assertTrue(tracing.importer.LinuxPerfImporter.canImport(lines.join('\n')));
 146
 147     var lines = [
 148       '          <idle>-0     [001]  4467.843475: sched_switch: ' +
 149           'prev_comm=swapper prev_pid=0 prev_prio=120 prev_state=R ==> ' +
 150           'next_comm=SurfaceFlinger next_pid=178 next_prio=112',
 151
 152       '  SurfaceFlinger-178   [001]  4467.843536: sched_switch: ' +
 153           'prev_comm=SurfaceFlinger prev_pid=178 prev_prio=112 ' +
 154           'prev_state=S ==> next_comm=kworker/u:2 next_pid=2844 ' +
 155           'next_prio=120'
 156     ];
 157     assertTrue(tracing.importer.LinuxPerfImporter.canImport(lines.join('\n')));
 158
 159     var lines = [
 160       'SomeRandomText',
 161       'More random text'
 162     ];
 163     assertFalse(tracing.importer.LinuxPerfImporter.canImport(lines.join('\n')));
 164   });
 165
 166   test('canImport34AndLater', function() {
 167     var lines = [
 168       '# tracer: nop',
 169       '#',
 170       '# entries-in-buffer/entries-written: 55191/55191   #P:2',
 171       '#',
 172       '#                              _-----=> irqs-off',
 173       '#                             / _----=> need-resched',
 174       '#                            | / _---=> hardirq/softirq',
 175       '#                            || / _--=> preempt-depth',
 176       '#                            ||| /     delay',
 177       '#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION',
 178       '#              | |       |   ||||       |         |',
 179       '     systrace.sh-5441  [001] d...  1031.091570: sched_wakeup: ' +
 180           'comm=debugd pid=4978 prio=120 success=1 target_cpu=000',
 181       '     systrace.sh-5441  [001] d...  1031.091584: sched_switch: ' +
 182           'prev_comm=systrace.sh prev_pid=5441 prev_prio=120 prev_state=x ' +
 183           '==> next_comm=chrome next_pid=5418 next_prio=120'
 184     ];
 185     assertTrue(tracing.importer.LinuxPerfImporter.canImport(lines.join('\n')));
 186
 187     var lines = [
 188       '     systrace.sh-5441  [001] d...  1031.091570: sched_wakeup: ' +
 189           'comm=debugd pid=4978 prio=120 success=1 target_cpu=000',
 190       '     systrace.sh-5441  [001] d...  1031.091584: sched_switch: ' +
 191           'prev_comm=systrace.sh prev_pid=5441 prev_prio=120 prev_state=x ' +
 192           '==> next_comm=chrome next_pid=5418 next_prio=120'
 193     ];
 194     assertTrue(tracing.importer.LinuxPerfImporter.canImport(lines.join('\n')));
 195   });
 196
 197   test('canImportSystraceFile', function() {
 198     var html_lines = [
 199       '<!DOCTYPE HTML>',
 200       '<html>',
 201       '<head i18n-values="dir:textdirection;">',
 202       '<title>Android System Trace</title>',
 203       '<style type="text/css">tabbox{-webkit-box-orient:vertical;display:-webkit-box;}tabs{-webkit-padding-start</style>', // @suppress longLineCheck
 204       '<script language="javascript">function onLoad(){reload()}function reload(){if(linuxPerfData){var g=new tracing.TraceModel;g.importEvents("[]",!0,[linuxPerfData]);var e=document.querySelector(".view");cr.ui.decorate(e,tracing.View);e.model=g;e.tabIndex=1;e.timeline.focusElement=e}}document.addEventListener("DOMContentLoaded",onLoad);var global=this;', // @suppress longLineCheck
 205       'this.cr=function(){function g(a,b,c,f){var e=new cr.Event(b+"Change");e.propertyName=b;e.newValue=c;e.oldValue=f;a.dispatchEvent(e)}function e(a){return a.replace(/([A-Z])/g,"-$1").toLowerCase()}function c(b,c){switch(c){case a.JS:var f=b+"_";return function(){return this[f]};case a.ATTR:var h=e(b);return function(){return this.getAttribute(h)};case a.BOOL_ATTR:return h=e(b),function(){return this.hasAttribute(h)}}}function f(b,c,f){switch(c){case a.JS:var h=b+"_";return function(a){var c=this[h];', // @suppress longLineCheck
 206       '  </div>',
 207       '  <script>',
 208       '  var linuxPerfData = "\\',
 209       '# tracer: nop\\n\\',
 210       '#\\n\\',
 211       '#           TASK-PID    CPU#    TIMESTAMP  FUNCTION\\n\\',
 212       '#              | |       |          |         |\\n\\',
 213       '          atrace-14662 [000] 50260.647576: sched_switch: prev_comm=atrace prev_pid=14662 prev_prio=120 prev_state=S ==> next_comm=kworker/0:0 next_pid=13696 next_prio=120\\n\\', // @suppress longLineCheck
 214       '     kworker/0:0-13696 [000] 50260.647590: sched_wakeup: comm=mmcqd/0 pid=95 prio=120 success=1 target_cpu=000\\n\\', // @suppress longLineCheck
 215       '     kworker/0:0-13696 [000] 50260.647602: sched_wakeup: comm=adbd pid=14582 prio=120 success=1 target_cpu=000\\n\\', // @suppress longLineCheck
 216       '     kworker/0:0-13696 [000] 50260.647610: sched_switch: prev_comm=kworker/0:0 prev_pid=13696 prev_prio=120 prev_state=S ==> next_comm=adbd next_pid=14582 next_prio=120\\n\\', // @suppress longLineCheck
 217       '            adbd-14582 [000] 50260.647722: sched_wakeup: comm=adbd pid=14584 prio=120 success=1 target_cpu=000\\n\\', // @suppress longLineCheck
 218       '            adbd-14582 [000] 50260.647756: sched_switch: prev_comm=adbd prev_pid=14582 prev_prio=120 prev_state=S ==> next_comm=adbd next_pid=14584 next_prio=120\\n\\', // @suppress longLineCheck
 219       '            adbd-14584 [000] 50260.647833: sched_switch: prev_comm=adbd prev_pid=14584 prev_prio=120 prev_state=S ==> next_comm=mmcqd/0 next_pid=95 next_prio=120\\n\\', // @suppress longLineCheck
 220       '         mmcqd/0-95    [000] 50260.647846: sched_switch: prev_comm=mmcqd/0 prev_pid=95 prev_prio=120 prev_state=S ==> next_comm=WebViewCoreThre next_pid=11043 next_prio=120\\n\\', // @suppress longLineCheck
 221       ' WebViewCoreThre-11043 [000] 50260.648275: sched_switch: prev_comm=WebViewCoreThre prev_pid=11043 prev_prio=120 prev_state=S ==> next_comm=swapper next_pid=0 next_prio=120\\n";', // @suppress longLineCheck
 222       '  <\/script>',
 223       '<\/body>',
 224       '<\/html>'
 225     ];
 226     var html_text = html_lines.join('\n');
 227     assertTrue(tracing.importer.LinuxPerfImporter.canImport(html_text));
 228
 229     var expected_event_lines = [
 230       '# tracer: nop',
 231       '#',
 232       '#           TASK-PID    CPU#    TIMESTAMP  FUNCTION',
 233       '#              | |       |          |         |',
 234       '          atrace-14662 [000] 50260.647576: sched_switch: prev_comm=atrace prev_pid=14662 prev_prio=120 prev_state=S ==> next_comm=kworker/0:0 next_pid=13696 next_prio=120', // @suppress longLineCheck
 235       '     kworker/0:0-13696 [000] 50260.647590: sched_wakeup: comm=mmcqd/0 pid=95 prio=120 success=1 target_cpu=000', // @suppress longLineCheck
 236       '     kworker/0:0-13696 [000] 50260.647602: sched_wakeup: comm=adbd pid=14582 prio=120 success=1 target_cpu=000', // @suppress longLineCheck
 237       '     kworker/0:0-13696 [000] 50260.647610: sched_switch: prev_comm=kworker/0:0 prev_pid=13696 prev_prio=120 prev_state=S ==> next_comm=adbd next_pid=14582 next_prio=120', // @suppress longLineCheck
 238       '            adbd-14582 [000] 50260.647722: sched_wakeup: comm=adbd pid=14584 prio=120 success=1 target_cpu=000', // @suppress longLineCheck
 239       '            adbd-14582 [000] 50260.647756: sched_switch: prev_comm=adbd prev_pid=14582 prev_prio=120 prev_state=S ==> next_comm=adbd next_pid=14584 next_prio=120', // @suppress longLineCheck
 240       '            adbd-14584 [000] 50260.647833: sched_switch: prev_comm=adbd prev_pid=14584 prev_prio=120 prev_state=S ==> next_comm=mmcqd/0 next_pid=95 next_prio=120', // @suppress longLineCheck
 241       '         mmcqd/0-95    [000] 50260.647846: sched_switch: prev_comm=mmcqd/0 prev_pid=95 prev_prio=120 prev_state=S ==> next_comm=WebViewCoreThre next_pid=11043 next_prio=120', // @suppress longLineCheck
 242       ' WebViewCoreThre-11043 [000] 50260.648275: sched_switch: prev_comm=WebViewCoreThre prev_pid=11043 prev_prio=120 prev_state=S ==> next_comm=swapper next_pid=0 next_prio=120' // @suppress longLineCheck
 243     ];
 244     var expected_event_text = expected_event_lines.join('\n');
 245     var res =
 246         tracing.importer.LinuxPerfImporter._extractEventsFromSystraceHTML(
 247             html_text, true);
 248     var actual_event_text = res.lines.join('\n');
 249     assertEquals(actual_event_text, expected_event_text);
 250   });
 251
 252   test('importOneSequence', function() {
 253     var lines = [
 254       '          <idle>-0     [001]  4467.843475: sched_switch: ' +
 255           'prev_comm=swapper prev_pid=0 prev_prio=120 prev_state=R ==> ' +
 256           'next_comm=SurfaceFlinger next_pid=178 next_prio=112',
 257
 258       '  SurfaceFlinger-178   [001]  4467.843536: sched_switch: ' +
 259           'prev_comm=SurfaceFlinger prev_pid=178 prev_prio=112 ' +
 260           'prev_state=S ==> next_comm=kworker/u:2 next_pid=2844 ' +
 261           'next_prio=120',
 262
 263       '     kworker/u:2-2844  [001]  4467.843567: sched_switch: ' +
 264           'prev_comm=kworker/u:2 prev_pid=2844 prev_prio=120 ' +
 265           'prev_state=S ==> next_comm=swapper next_pid=0 next_prio=120'
 266     ];
 267     var m = new tracing.TraceModel(lines.join('\n'), false);
 268     assertFalse(m.hasImportWarnings);
 269
 270     var c = m.kernel.cpus[1];
 271     assertEquals(2, c.slices.length);
 272
 273     assertEquals('SurfaceFlinger', c.slices[0].title);
 274     assertEquals(4467843.475, c.slices[0].start);
 275     assertAlmostEquals(.536 - .475, c.slices[0].duration);
 276   });
 277
 278   test('importOneSequenceWithSpacyThreadName', function() {
 279     var lines = [
 280       '          <idle>-0     [001]  4467.843475: sched_switch: ' +
 281           'prev_comm=swapper prev_pid=0 prev_prio=120 prev_state=R ==> ' +
 282           'next_comm=Surface Flinger  next_pid=178 next_prio=112',
 283
 284       'Surface Flinger -178   [001]  4467.843536: sched_switch: ' +
 285           'prev_comm=Surface Flinger  prev_pid=178 prev_prio=112 ' +
 286           'prev_state=S ==> next_comm=kworker/u:2 next_pid=2844 ' +
 287           'next_prio=120',
 288
 289       '     kworker/u:2-2844  [001]  4467.843567: sched_switch: ' +
 290           'prev_comm=kworker/u:2 prev_pid=2844 prev_prio=120 ' +
 291           'prev_state=S ==> next_comm=swapper next_pid=0 next_prio=120'
 292     ];
 293     var m = new tracing.TraceModel(lines.join('\n'), false);
 294     assertFalse(m.hasImportWarnings);
 295
 296     var c = m.kernel.cpus[1];
 297     assertEquals(2, c.slices.length);
 298
 299     assertEquals('Surface Flinger ', c.slices[0].title);
 300     assertEquals(4467843.475, c.slices[0].start);
 301     assertAlmostEquals(.536 - .475, c.slices[0].duration);
 302   });
 303
 304   test('importWithNewline', function() {
 305     var lines = [
 306       ''
 307     ];
 308     var m = new tracing.TraceModel(lines.join('\n'));
 309     assertFalse(m.hasImportWarnings);
 310   });
 311
 312   test('clockSync', function() {
 313     var lines = [
 314       '          <idle>-0     [001]  4467.843475: sched_switch: ' +
 315           'prev_comm=swapper prev_pid=0 prev_prio=120 prev_state=R ' +
 316           '==> next_comm=SurfaceFlinger next_pid=178 next_prio=112',
 317       '  SurfaceFlinger-178   [001]  4467.843536: sched_switch: ' +
 318           'prev_comm=SurfaceFlinger prev_pid=178 prev_prio=112 ' +
 319           'prev_state=S ==> next_comm=kworker/u:2 next_pid=2844 ' +
 320           'next_prio=120',
 321       '     kworker/u:2-2844  [001]  4467.843567: sched_switch: ' +
 322           'prev_comm=kworker/u:2 prev_pid=2844 prev_prio=120 ' +
 323           'prev_state=S ==> next_comm=swapper next_pid=0 ' +
 324           'next_prio=120',
 325       '     kworker/u:2-2844  [001]  4467.843000: 0: ' +
 326           'trace_event_clock_sync: parent_ts=0.1'
 327     ];
 328     var m = new tracing.TraceModel(lines.join('\n'), false);
 329     assertFalse(m.hasImportWarnings);
 330
 331     var c = m.kernel.cpus[1];
 332     assertEquals(2, c.slices.length);
 333
 334     assertAlmostEquals((467.843475 - (467.843 - 0.1)) * 1000,
 335                        c.slices[0].start);
 336   });
 337
 338   test('clockSyncMarkWrite', function() {
 339     var lines = [
 340       'systrace.sh-8170  [001] 15180.978813: sched_switch: ' +
 341           'prev_comm=systrace.sh prev_pid=8170 prev_prio=120 ' +
 342           'prev_state=x ==> next_comm=kworker/1:0 next_pid=7873 ' +
 343           'next_prio=120',
 344       ' kworker/1:0-7873  [001] 15180.978836: sched_switch: ' +
 345           'prev_comm=kworker/1:0 prev_pid=7873 prev_prio=120 ' +
 346           'prev_state=S ==> next_comm=debugd next_pid=4404 next_prio=120',
 347       '     debugd-4404  [001] 15180.979010: sched_switch: prev_comm=debugd ' +
 348           'prev_pid=4404 prev_prio=120 prev_state=S ==> ' +
 349           'next_comm=dbus-daemon next_pid=510 next_prio=120',
 350       'systrace.sh-8182  [000] 15186.203900: tracing_mark_write: ' +
 351           'trace_event_clock_sync: parent_ts=0'
 352     ];
 353     var m = new tracing.TraceModel(lines.join('\n'), false);
 354     assertFalse(m.hasImportWarnings);
 355
 356     var c = m.kernel.cpus[1];
 357     assertEquals(2, c.slices.length);
 358
 359     assertAlmostEquals((15180.978813 - 0) * 1000, c.slices[0].start);
 360   });
 361 });