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
7base.require('tracing.test_utils');
8base.require('tracing.importer.linux_perf_importer');
9
10base.unittest.testSuite('tracing.importer.linux_perf_importer', function() {
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    assertEquals(0, m.importErrors.length);
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    assertEquals(0, m.importErrors.length);
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    assertEquals(0, m.importErrors.length);
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    assertEquals(0, m.importErrors.length);
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    assertEquals(0, m.importErrors.length);
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});
362