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.
7 tvcm.require('tracing.test_utils');
8 tvcm.require('tracing.importer.linux_perf_importer');
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');
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);
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');
29 assertEquals('Binder-Thread #', x.threadName);
30 assertEquals('647', x.pid);
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');
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
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');
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
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');
62 assertEquals('321', x.tgid);
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');
67 assertEquals(undefined, x.tgid);
70 test('autodetectLineCornerCases', function() {
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;
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 ' +
85 var detected = detectParser(lineWithLegacyFmt);
86 assertEquals(detected, lineParserWithLegacyFmt);
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 ' +
93 var detected = detectParser(lineWithIRQInfo);
94 assertEquals(detected, lineParserWithIRQInfo);
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 ' +
101 var detected = detectParser(lineWithTGID);
102 assertEquals(detected, lineParserWithTGID);
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');
109 assertEquals('19581477508', x[1]);
111 var x = re.exec('trace_event_clock_sync: parent_ts=123.456');
113 assertEquals('123.456', x[1]);
116 test('canImport', function() {
120 '# TASK-PID CPU# TIMESTAMP FUNCTION',
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',
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',
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',
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'
138 assertTrue(tracing.importer.LinuxPerfImporter.canImport(lines.join('\n')));
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'
145 assertTrue(tracing.importer.LinuxPerfImporter.canImport(lines.join('\n')));
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',
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 ' +
157 assertTrue(tracing.importer.LinuxPerfImporter.canImport(lines.join('\n')));
163 assertFalse(tracing.importer.LinuxPerfImporter.canImport(lines.join('\n')));
166 test('canImport34AndLater', function() {
170 '# entries-in-buffer/entries-written: 55191/55191 #P:2',
172 '# _-----=> irqs-off',
173 '# / _----=> need-resched',
174 '# | / _---=> hardirq/softirq',
175 '# || / _--=> preempt-depth',
177 '# TASK-PID CPU# |||| TIMESTAMP FUNCTION',
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'
185 assertTrue(tracing.importer.LinuxPerfImporter.canImport(lines.join('\n')));
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'
194 assertTrue(tracing.importer.LinuxPerfImporter.canImport(lines.join('\n')));
197 test('canImportSystraceFile', function() {
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
208 ' var linuxPerfData = "\\',
209 '# tracer: nop\\n\\',
211 '# TASK-PID CPU# TIMESTAMP FUNCTION\\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
226 var html_text = html_lines.join('\n');
227 assertTrue(tracing.importer.LinuxPerfImporter.canImport(html_text));
229 var expected_event_lines = [
232 '# TASK-PID CPU# TIMESTAMP FUNCTION',
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
244 var expected_event_text = expected_event_lines.join('\n');
246 tracing.importer.LinuxPerfImporter._extractEventsFromSystraceHTML(
248 var actual_event_text = res.lines.join('\n');
249 assertEquals(actual_event_text, expected_event_text);
252 test('importOneSequence', function() {
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',
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 ' +
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'
267 var m = new tracing.TraceModel(lines.join('\n'), false);
268 assertFalse(m.hasImportWarnings);
270 var c = m.kernel.cpus[1];
271 assertEquals(2, c.slices.length);
273 assertEquals('SurfaceFlinger', c.slices[0].title);
274 assertEquals(4467843.475, c.slices[0].start);
275 assertAlmostEquals(.536 - .475, c.slices[0].duration);
278 test('importOneSequenceWithSpacyThreadName', function() {
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',
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 ' +
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'
293 var m = new tracing.TraceModel(lines.join('\n'), false);
294 assertFalse(m.hasImportWarnings);
296 var c = m.kernel.cpus[1];
297 assertEquals(2, c.slices.length);
299 assertEquals('Surface Flinger ', c.slices[0].title);
300 assertEquals(4467843.475, c.slices[0].start);
301 assertAlmostEquals(.536 - .475, c.slices[0].duration);
304 test('importWithNewline', function() {
308 var m = new tracing.TraceModel(lines.join('\n'));
309 assertFalse(m.hasImportWarnings);
312 test('clockSync', function() {
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 ' +
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 ' +
325 ' kworker/u:2-2844 [001] 4467.843000: 0: ' +
326 'trace_event_clock_sync: parent_ts=0.1'
328 var m = new tracing.TraceModel(lines.join('\n'), false);
329 assertFalse(m.hasImportWarnings);
331 var c = m.kernel.cpus[1];
332 assertEquals(2, c.slices.length);
334 assertAlmostEquals((467.843475 - (467.843 - 0.1)) * 1000,
338 test('clockSyncMarkWrite', function() {
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 ' +
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'
353 var m = new tracing.TraceModel(lines.join('\n'), false);
354 assertFalse(m.hasImportWarnings);
356 var c = m.kernel.cpus[1];
357 assertEquals(2, c.slices.length);
359 assertAlmostEquals((15180.978813 - 0) * 1000, c.slices[0].start);