diff options
-rwxr-xr-x | scripts/analyze_suspend.py | 565 |
1 files changed, 300 insertions, 265 deletions
diff --git a/scripts/analyze_suspend.py b/scripts/analyze_suspend.py index baf5a080cc4c..01268593b7e3 100755 --- a/scripts/analyze_suspend.py +++ b/scripts/analyze_suspend.py | |||
@@ -67,7 +67,7 @@ from datetime import datetime | |||
67 | import struct | 67 | import struct |
68 | import ConfigParser | 68 | import ConfigParser |
69 | from threading import Thread | 69 | from threading import Thread |
70 | import subprocess | 70 | from subprocess import call, Popen, PIPE |
71 | 71 | ||
72 | # ----------------- CLASSES -------------------- | 72 | # ----------------- CLASSES -------------------- |
73 | 73 | ||
@@ -77,11 +77,13 @@ import subprocess | |||
77 | # store system values and test parameters | 77 | # store system values and test parameters |
78 | class SystemValues: | 78 | class SystemValues: |
79 | ansi = False | 79 | ansi = False |
80 | version = '4.3' | 80 | version = '4.4' |
81 | verbose = False | 81 | verbose = False |
82 | addlogs = False | 82 | addlogs = False |
83 | mindevlen = 0.001 | 83 | mindevlen = 0.001 |
84 | mincglen = 1.0 | 84 | mincglen = 1.0 |
85 | callloopmaxgap = 0.0001 | ||
86 | callloopmaxlen = 0.005 | ||
85 | srgap = 0 | 87 | srgap = 0 |
86 | cgexp = False | 88 | cgexp = False |
87 | outdir = '' | 89 | outdir = '' |
@@ -132,9 +134,6 @@ class SystemValues: | |||
132 | stampfmt = '# suspend-(?P<m>[0-9]{2})(?P<d>[0-9]{2})(?P<y>[0-9]{2})-'+\ | 134 | stampfmt = '# suspend-(?P<m>[0-9]{2})(?P<d>[0-9]{2})(?P<y>[0-9]{2})-'+\ |
133 | '(?P<H>[0-9]{2})(?P<M>[0-9]{2})(?P<S>[0-9]{2})'+\ | 135 | '(?P<H>[0-9]{2})(?P<M>[0-9]{2})(?P<S>[0-9]{2})'+\ |
134 | ' (?P<host>.*) (?P<mode>.*) (?P<kernel>.*)$' | 136 | ' (?P<host>.*) (?P<mode>.*) (?P<kernel>.*)$' |
135 | kprobecolor = 'rgba(204,204,204,0.5)' | ||
136 | synccolor = 'rgba(204,204,204,0.5)' | ||
137 | debugfuncs = [] | ||
138 | tracefuncs = { | 137 | tracefuncs = { |
139 | 'sys_sync': dict(), | 138 | 'sys_sync': dict(), |
140 | 'pm_prepare_console': dict(), | 139 | 'pm_prepare_console': dict(), |
@@ -213,6 +212,7 @@ class SystemValues: | |||
213 | self.embedded = True | 212 | self.embedded = True |
214 | self.addlogs = True | 213 | self.addlogs = True |
215 | self.htmlfile = os.environ['LOG_FILE'] | 214 | self.htmlfile = os.environ['LOG_FILE'] |
215 | self.archargs = 'args_'+platform.machine() | ||
216 | self.hostname = platform.node() | 216 | self.hostname = platform.node() |
217 | if(self.hostname == ''): | 217 | if(self.hostname == ''): |
218 | self.hostname = 'localhost' | 218 | self.hostname = 'localhost' |
@@ -282,7 +282,7 @@ class SystemValues: | |||
282 | for i in value: | 282 | for i in value: |
283 | self.devicefilter.append(i.strip()) | 283 | self.devicefilter.append(i.strip()) |
284 | def rtcWakeAlarmOn(self): | 284 | def rtcWakeAlarmOn(self): |
285 | os.system('echo 0 > '+self.rtcpath+'/wakealarm') | 285 | call('echo 0 > '+self.rtcpath+'/wakealarm', shell=True) |
286 | outD = open(self.rtcpath+'/date', 'r').read().strip() | 286 | outD = open(self.rtcpath+'/date', 'r').read().strip() |
287 | outT = open(self.rtcpath+'/time', 'r').read().strip() | 287 | outT = open(self.rtcpath+'/time', 'r').read().strip() |
288 | mD = re.match('^(?P<y>[0-9]*)-(?P<m>[0-9]*)-(?P<d>[0-9]*)', outD) | 288 | mD = re.match('^(?P<y>[0-9]*)-(?P<m>[0-9]*)-(?P<d>[0-9]*)', outD) |
@@ -298,12 +298,12 @@ class SystemValues: | |||
298 | # if hardware time fails, use the software time | 298 | # if hardware time fails, use the software time |
299 | nowtime = int(datetime.now().strftime('%s')) | 299 | nowtime = int(datetime.now().strftime('%s')) |
300 | alarm = nowtime + self.rtcwaketime | 300 | alarm = nowtime + self.rtcwaketime |
301 | os.system('echo %d > %s/wakealarm' % (alarm, self.rtcpath)) | 301 | call('echo %d > %s/wakealarm' % (alarm, self.rtcpath), shell=True) |
302 | def rtcWakeAlarmOff(self): | 302 | def rtcWakeAlarmOff(self): |
303 | os.system('echo 0 > %s/wakealarm' % self.rtcpath) | 303 | call('echo 0 > %s/wakealarm' % self.rtcpath, shell=True) |
304 | def initdmesg(self): | 304 | def initdmesg(self): |
305 | # get the latest time stamp from the dmesg log | 305 | # get the latest time stamp from the dmesg log |
306 | fp = os.popen('dmesg') | 306 | fp = Popen('dmesg', stdout=PIPE).stdout |
307 | ktime = '0' | 307 | ktime = '0' |
308 | for line in fp: | 308 | for line in fp: |
309 | line = line.replace('\r\n', '') | 309 | line = line.replace('\r\n', '') |
@@ -317,7 +317,7 @@ class SystemValues: | |||
317 | self.dmesgstart = float(ktime) | 317 | self.dmesgstart = float(ktime) |
318 | def getdmesg(self): | 318 | def getdmesg(self): |
319 | # store all new dmesg lines since initdmesg was called | 319 | # store all new dmesg lines since initdmesg was called |
320 | fp = os.popen('dmesg') | 320 | fp = Popen('dmesg', stdout=PIPE).stdout |
321 | op = open(self.dmesgfile, 'a') | 321 | op = open(self.dmesgfile, 'a') |
322 | for line in fp: | 322 | for line in fp: |
323 | line = line.replace('\r\n', '') | 323 | line = line.replace('\r\n', '') |
@@ -343,25 +343,18 @@ class SystemValues: | |||
343 | def getFtraceFilterFunctions(self, current): | 343 | def getFtraceFilterFunctions(self, current): |
344 | rootCheck(True) | 344 | rootCheck(True) |
345 | if not current: | 345 | if not current: |
346 | os.system('cat '+self.tpath+'available_filter_functions') | 346 | call('cat '+self.tpath+'available_filter_functions', shell=True) |
347 | return | 347 | return |
348 | fp = open(self.tpath+'available_filter_functions') | 348 | fp = open(self.tpath+'available_filter_functions') |
349 | master = fp.read().split('\n') | 349 | master = fp.read().split('\n') |
350 | fp.close() | 350 | fp.close() |
351 | if len(self.debugfuncs) > 0: | 351 | for i in self.tracefuncs: |
352 | for i in self.debugfuncs: | 352 | if 'func' in self.tracefuncs[i]: |
353 | if i in master: | 353 | i = self.tracefuncs[i]['func'] |
354 | print i | 354 | if i in master: |
355 | else: | 355 | print i |
356 | print self.colorText(i) | 356 | else: |
357 | else: | 357 | print self.colorText(i) |
358 | for i in self.tracefuncs: | ||
359 | if 'func' in self.tracefuncs[i]: | ||
360 | i = self.tracefuncs[i]['func'] | ||
361 | if i in master: | ||
362 | print i | ||
363 | else: | ||
364 | print self.colorText(i) | ||
365 | def setFtraceFilterFunctions(self, list): | 358 | def setFtraceFilterFunctions(self, list): |
366 | fp = open(self.tpath+'available_filter_functions') | 359 | fp = open(self.tpath+'available_filter_functions') |
367 | master = fp.read().split('\n') | 360 | master = fp.read().split('\n') |
@@ -384,9 +377,8 @@ class SystemValues: | |||
384 | for field in ['name', 'format', 'func']: | 377 | for field in ['name', 'format', 'func']: |
385 | if field not in k: | 378 | if field not in k: |
386 | k[field] = name | 379 | k[field] = name |
387 | archargs = 'args_'+platform.machine() | 380 | if self.archargs in k: |
388 | if archargs in k: | 381 | k['args'] = k[self.archargs] |
389 | k['args'] = k[archargs] | ||
390 | else: | 382 | else: |
391 | k['args'] = dict() | 383 | k['args'] = dict() |
392 | k['format'] = name | 384 | k['format'] = name |
@@ -423,8 +415,19 @@ class SystemValues: | |||
423 | out = fmt.format(**arglist) | 415 | out = fmt.format(**arglist) |
424 | out = out.replace(' ', '_').replace('"', '') | 416 | out = out.replace(' ', '_').replace('"', '') |
425 | return out | 417 | return out |
426 | def kprobeText(self, kprobe): | 418 | def kprobeText(self, kname, kprobe): |
427 | name, fmt, func, args = kprobe['name'], kprobe['format'], kprobe['func'], kprobe['args'] | 419 | name = fmt = func = kname |
420 | args = dict() | ||
421 | if 'name' in kprobe: | ||
422 | name = kprobe['name'] | ||
423 | if 'format' in kprobe: | ||
424 | fmt = kprobe['format'] | ||
425 | if 'func' in kprobe: | ||
426 | func = kprobe['func'] | ||
427 | if self.archargs in kprobe: | ||
428 | args = kprobe[self.archargs] | ||
429 | if 'args' in kprobe: | ||
430 | args = kprobe['args'] | ||
428 | if re.findall('{(?P<n>[a-z,A-Z,0-9]*)}', func): | 431 | if re.findall('{(?P<n>[a-z,A-Z,0-9]*)}', func): |
429 | doError('Kprobe "%s" has format info in the function name "%s"' % (name, func), False) | 432 | doError('Kprobe "%s" has format info in the function name "%s"' % (name, func), False) |
430 | for arg in re.findall('{(?P<n>[a-z,A-Z,0-9]*)}', fmt): | 433 | for arg in re.findall('{(?P<n>[a-z,A-Z,0-9]*)}', fmt): |
@@ -440,7 +443,7 @@ class SystemValues: | |||
440 | print('INITIALIZING KPROBES...') | 443 | print('INITIALIZING KPROBES...') |
441 | rejects = [] | 444 | rejects = [] |
442 | for name in sorted(self.kprobes): | 445 | for name in sorted(self.kprobes): |
443 | if not self.testKprobe(self.kprobes[name]): | 446 | if not self.testKprobe(name, self.kprobes[name]): |
444 | rejects.append(name) | 447 | rejects.append(name) |
445 | # remove all failed ones from the list | 448 | # remove all failed ones from the list |
446 | for name in rejects: | 449 | for name in rejects: |
@@ -450,9 +453,9 @@ class SystemValues: | |||
450 | kprobeevents = '' | 453 | kprobeevents = '' |
451 | # set the kprobes all at once | 454 | # set the kprobes all at once |
452 | for kp in self.kprobes: | 455 | for kp in self.kprobes: |
453 | val = self.kprobeText(self.kprobes[kp]) | 456 | val = self.kprobeText(kp, self.kprobes[kp]) |
454 | vprint('Adding KPROBE: %s\n%s' % (kp, val.strip())) | 457 | vprint('Adding KPROBE: %s\n%s' % (kp, val.strip())) |
455 | kprobeevents += self.kprobeText(self.kprobes[kp]) | 458 | kprobeevents += self.kprobeText(kp, self.kprobes[kp]) |
456 | self.fsetVal(kprobeevents, 'kprobe_events') | 459 | self.fsetVal(kprobeevents, 'kprobe_events') |
457 | # verify that the kprobes were set as ordered | 460 | # verify that the kprobes were set as ordered |
458 | check = self.fgetVal('kprobe_events') | 461 | check = self.fgetVal('kprobe_events') |
@@ -461,11 +464,11 @@ class SystemValues: | |||
461 | if linesack < linesout: | 464 | if linesack < linesout: |
462 | # if not, try appending the kprobes 1 by 1 | 465 | # if not, try appending the kprobes 1 by 1 |
463 | for kp in self.kprobes: | 466 | for kp in self.kprobes: |
464 | kprobeevents = self.kprobeText(self.kprobes[kp]) | 467 | kprobeevents = self.kprobeText(kp, self.kprobes[kp]) |
465 | self.fsetVal(kprobeevents, 'kprobe_events', 'a') | 468 | self.fsetVal(kprobeevents, 'kprobe_events', 'a') |
466 | self.fsetVal('1', 'events/kprobes/enable') | 469 | self.fsetVal('1', 'events/kprobes/enable') |
467 | def testKprobe(self, kprobe): | 470 | def testKprobe(self, kname, kprobe): |
468 | kprobeevents = self.kprobeText(kprobe) | 471 | kprobeevents = self.kprobeText(kname, kprobe) |
469 | if not kprobeevents: | 472 | if not kprobeevents: |
470 | return False | 473 | return False |
471 | try: | 474 | try: |
@@ -511,18 +514,15 @@ class SystemValues: | |||
511 | for name in self.dev_tracefuncs: | 514 | for name in self.dev_tracefuncs: |
512 | self.defaultKprobe(name, self.dev_tracefuncs[name]) | 515 | self.defaultKprobe(name, self.dev_tracefuncs[name]) |
513 | def isCallgraphFunc(self, name): | 516 | def isCallgraphFunc(self, name): |
514 | if len(self.debugfuncs) < 1 and self.suspendmode == 'command': | 517 | if len(self.tracefuncs) < 1 and self.suspendmode == 'command': |
515 | return True | ||
516 | if name in self.debugfuncs: | ||
517 | return True | 518 | return True |
518 | funclist = [] | ||
519 | for i in self.tracefuncs: | 519 | for i in self.tracefuncs: |
520 | if 'func' in self.tracefuncs[i]: | 520 | if 'func' in self.tracefuncs[i]: |
521 | funclist.append(self.tracefuncs[i]['func']) | 521 | f = self.tracefuncs[i]['func'] |
522 | else: | 522 | else: |
523 | funclist.append(i) | 523 | f = i |
524 | if name in funclist: | 524 | if name == f: |
525 | return True | 525 | return True |
526 | return False | 526 | return False |
527 | def initFtrace(self, testing=False): | 527 | def initFtrace(self, testing=False): |
528 | tp = self.tpath | 528 | tp = self.tpath |
@@ -538,18 +538,7 @@ class SystemValues: | |||
538 | # go no further if this is just a status check | 538 | # go no further if this is just a status check |
539 | if testing: | 539 | if testing: |
540 | return | 540 | return |
541 | if self.usekprobes: | 541 | # initialize the callgraph trace |
542 | # add tracefunc kprobes so long as were not using full callgraph | ||
543 | if(not self.usecallgraph or len(self.debugfuncs) > 0): | ||
544 | for name in self.tracefuncs: | ||
545 | self.defaultKprobe(name, self.tracefuncs[name]) | ||
546 | if self.usedevsrc: | ||
547 | for name in self.dev_tracefuncs: | ||
548 | self.defaultKprobe(name, self.dev_tracefuncs[name]) | ||
549 | else: | ||
550 | self.usedevsrc = False | ||
551 | self.addKprobes() | ||
552 | # initialize the callgraph trace, unless this is an x2 run | ||
553 | if(self.usecallgraph): | 542 | if(self.usecallgraph): |
554 | # set trace type | 543 | # set trace type |
555 | self.fsetVal('function_graph', 'current_tracer') | 544 | self.fsetVal('function_graph', 'current_tracer') |
@@ -565,20 +554,23 @@ class SystemValues: | |||
565 | self.fsetVal('context-info', 'trace_options') | 554 | self.fsetVal('context-info', 'trace_options') |
566 | self.fsetVal('graph-time', 'trace_options') | 555 | self.fsetVal('graph-time', 'trace_options') |
567 | self.fsetVal('0', 'max_graph_depth') | 556 | self.fsetVal('0', 'max_graph_depth') |
568 | if len(self.debugfuncs) > 0: | 557 | cf = ['dpm_run_callback'] |
569 | self.setFtraceFilterFunctions(self.debugfuncs) | 558 | if(self.usetraceeventsonly): |
570 | elif self.suspendmode == 'command': | 559 | cf += ['dpm_prepare', 'dpm_complete'] |
571 | self.fsetVal('', 'set_graph_function') | 560 | for fn in self.tracefuncs: |
572 | else: | 561 | if 'func' in self.tracefuncs[fn]: |
573 | cf = ['dpm_run_callback'] | 562 | cf.append(self.tracefuncs[fn]['func']) |
574 | if(self.usetraceeventsonly): | 563 | else: |
575 | cf += ['dpm_prepare', 'dpm_complete'] | 564 | cf.append(fn) |
576 | for fn in self.tracefuncs: | 565 | self.setFtraceFilterFunctions(cf) |
577 | if 'func' in self.tracefuncs[fn]: | 566 | # initialize the kprobe trace |
578 | cf.append(self.tracefuncs[fn]['func']) | 567 | elif self.usekprobes: |
579 | else: | 568 | for name in self.tracefuncs: |
580 | cf.append(fn) | 569 | self.defaultKprobe(name, self.tracefuncs[name]) |
581 | self.setFtraceFilterFunctions(cf) | 570 | if self.usedevsrc: |
571 | for name in self.dev_tracefuncs: | ||
572 | self.defaultKprobe(name, self.dev_tracefuncs[name]) | ||
573 | self.addKprobes() | ||
582 | if(self.usetraceevents): | 574 | if(self.usetraceevents): |
583 | # turn trace events on | 575 | # turn trace events on |
584 | events = iter(self.traceevents) | 576 | events = iter(self.traceevents) |
@@ -791,25 +783,22 @@ class Data: | |||
791 | break | 783 | break |
792 | return tgtdev | 784 | return tgtdev |
793 | def addDeviceFunctionCall(self, displayname, kprobename, proc, pid, start, end, cdata, rdata): | 785 | def addDeviceFunctionCall(self, displayname, kprobename, proc, pid, start, end, cdata, rdata): |
794 | tgtphase = self.sourcePhase(start, end) | ||
795 | # try to place the call in a device | 786 | # try to place the call in a device |
796 | tgtdev = self.sourceDevice(self.phases, start, end, pid, 'device') | 787 | tgtdev = self.sourceDevice(self.phases, start, end, pid, 'device') |
797 | # calls with device pids that occur outside dev bounds are dropped | 788 | # calls with device pids that occur outside device bounds are dropped |
789 | # TODO: include these somehow | ||
798 | if not tgtdev and pid in self.devpids: | 790 | if not tgtdev and pid in self.devpids: |
799 | return False | 791 | return False |
800 | # try to place the call in a thread | 792 | # try to place the call in a thread |
801 | if not tgtdev: | 793 | if not tgtdev: |
802 | tgtdev = self.sourceDevice([tgtphase], start, end, pid, 'thread') | 794 | tgtdev = self.sourceDevice(self.phases, start, end, pid, 'thread') |
803 | # create new thread blocks, expand as new calls are found | 795 | # create new thread blocks, expand as new calls are found |
804 | if not tgtdev: | 796 | if not tgtdev: |
805 | if proc == '<...>': | 797 | if proc == '<...>': |
806 | threadname = 'kthread-%d' % (pid) | 798 | threadname = 'kthread-%d' % (pid) |
807 | else: | 799 | else: |
808 | threadname = '%s-%d' % (proc, pid) | 800 | threadname = '%s-%d' % (proc, pid) |
809 | if(start < self.start): | 801 | tgtphase = self.sourcePhase(start, end) |
810 | self.setStart(start) | ||
811 | if(end > self.end): | ||
812 | self.setEnd(end) | ||
813 | self.newAction(tgtphase, threadname, pid, '', start, end, '', ' kth', '') | 802 | self.newAction(tgtphase, threadname, pid, '', start, end, '', ' kth', '') |
814 | return self.addDeviceFunctionCall(displayname, kprobename, proc, pid, start, end, cdata, rdata) | 803 | return self.addDeviceFunctionCall(displayname, kprobename, proc, pid, start, end, cdata, rdata) |
815 | # this should not happen | 804 | # this should not happen |
@@ -836,7 +825,8 @@ class Data: | |||
836 | r = 'ret=%s ' % r | 825 | r = 'ret=%s ' % r |
837 | if ubiquitous and c in self.dev_ubiquitous: | 826 | if ubiquitous and c in self.dev_ubiquitous: |
838 | return False | 827 | return False |
839 | e = DevFunction(displayname, a, c, r, start, end, ubiquitous, proc, pid) | 828 | color = sysvals.kprobeColor(kprobename) |
829 | e = DevFunction(displayname, a, c, r, start, end, ubiquitous, proc, pid, color) | ||
840 | tgtdev['src'].append(e) | 830 | tgtdev['src'].append(e) |
841 | return True | 831 | return True |
842 | def overflowDevices(self): | 832 | def overflowDevices(self): |
@@ -866,6 +856,30 @@ class Data: | |||
866 | continue | 856 | continue |
867 | dev['src'] += tdev['src'] | 857 | dev['src'] += tdev['src'] |
868 | del list[devname] | 858 | del list[devname] |
859 | def usurpTouchingThread(self, name, dev): | ||
860 | # the caller test has priority of this thread, give it to him | ||
861 | for phase in self.phases: | ||
862 | list = self.dmesg[phase]['list'] | ||
863 | if name in list: | ||
864 | tdev = list[name] | ||
865 | if tdev['start'] - dev['end'] < 0.1: | ||
866 | dev['end'] = tdev['end'] | ||
867 | if 'src' not in dev: | ||
868 | dev['src'] = [] | ||
869 | if 'src' in tdev: | ||
870 | dev['src'] += tdev['src'] | ||
871 | del list[name] | ||
872 | break | ||
873 | def stitchTouchingThreads(self, testlist): | ||
874 | # merge any threads between tests that touch | ||
875 | for phase in self.phases: | ||
876 | list = self.dmesg[phase]['list'] | ||
877 | for devname in list: | ||
878 | dev = list[devname] | ||
879 | if 'htmlclass' not in dev or 'kth' not in dev['htmlclass']: | ||
880 | continue | ||
881 | for data in testlist: | ||
882 | data.usurpTouchingThread(devname, dev) | ||
869 | def optimizeDevSrc(self): | 883 | def optimizeDevSrc(self): |
870 | # merge any src call loops to reduce timeline size | 884 | # merge any src call loops to reduce timeline size |
871 | for phase in self.phases: | 885 | for phase in self.phases: |
@@ -962,29 +976,18 @@ class Data: | |||
962 | break | 976 | break |
963 | vprint('%s (%s): callback didnt return' % (devname, phase)) | 977 | vprint('%s (%s): callback didnt return' % (devname, phase)) |
964 | def deviceFilter(self, devicefilter): | 978 | def deviceFilter(self, devicefilter): |
965 | # get a list of all devices related to the filter devices | 979 | # check each device name & driver name |
966 | filter = [] | 980 | # remove it if it does not include one of the filter strings |
967 | for phase in self.phases: | ||
968 | list = self.dmesg[phase]['list'] | ||
969 | for name in devicefilter: | ||
970 | dev = name | ||
971 | # loop up to the top level parent of this dev | ||
972 | while(dev in list): | ||
973 | if(dev not in filter): | ||
974 | filter.append(dev) | ||
975 | dev = list[dev]['par'] | ||
976 | # now get the full tree of related devices | ||
977 | children = self.deviceDescendants(name, phase) | ||
978 | for dev in children: | ||
979 | if(dev not in filter): | ||
980 | filter.append(dev) | ||
981 | # remove all devices not in the filter list | ||
982 | for phase in self.phases: | 981 | for phase in self.phases: |
983 | list = self.dmesg[phase]['list'] | 982 | list = self.dmesg[phase]['list'] |
984 | rmlist = [] | 983 | rmlist = [] |
985 | for name in list: | 984 | for name in list: |
986 | pid = list[name]['pid'] | 985 | keep = False |
987 | if(name not in filter): | 986 | for filter in devicefilter: |
987 | if filter in name or \ | ||
988 | ('drv' in list[name] and filter in list[name]['drv']): | ||
989 | keep = True | ||
990 | if not keep: | ||
988 | rmlist.append(name) | 991 | rmlist.append(name) |
989 | for name in rmlist: | 992 | for name in rmlist: |
990 | del list[name] | 993 | del list[name] |
@@ -992,10 +995,6 @@ class Data: | |||
992 | # if any calls never returned, clip them at system resume end | 995 | # if any calls never returned, clip them at system resume end |
993 | for phase in self.phases: | 996 | for phase in self.phases: |
994 | self.fixupInitcalls(phase, self.end) | 997 | self.fixupInitcalls(phase, self.end) |
995 | def isInsideTimeline(self, start, end): | ||
996 | if(self.start <= start and self.end > start): | ||
997 | return True | ||
998 | return False | ||
999 | def phaseOverlap(self, phases): | 998 | def phaseOverlap(self, phases): |
1000 | rmgroups = [] | 999 | rmgroups = [] |
1001 | newgroup = [] | 1000 | newgroup = [] |
@@ -1012,12 +1011,6 @@ class Data: | |||
1012 | self.devicegroups.remove(group) | 1011 | self.devicegroups.remove(group) |
1013 | self.devicegroups.append(newgroup) | 1012 | self.devicegroups.append(newgroup) |
1014 | def newActionGlobal(self, name, start, end, pid=-1, color=''): | 1013 | def newActionGlobal(self, name, start, end, pid=-1, color=''): |
1015 | # if event starts before timeline start, expand timeline | ||
1016 | if(start < self.start): | ||
1017 | self.setStart(start) | ||
1018 | # if event ends after timeline end, expand the timeline | ||
1019 | if(end > self.end): | ||
1020 | self.setEnd(end) | ||
1021 | # which phase is this device callback or action in | 1014 | # which phase is this device callback or action in |
1022 | targetphase = 'none' | 1015 | targetphase = 'none' |
1023 | htmlclass = '' | 1016 | htmlclass = '' |
@@ -1036,13 +1029,12 @@ class Data: | |||
1036 | continue | 1029 | continue |
1037 | targetphase = phase | 1030 | targetphase = phase |
1038 | overlap = o | 1031 | overlap = o |
1039 | # if no target phase was found, check for pre/post resume | 1032 | # if no target phase was found, pin it to the edge |
1040 | if targetphase == 'none': | 1033 | if targetphase == 'none': |
1041 | o = max(0, min(end, self.tKernSus) - max(start, self.start)) | 1034 | p0start = self.dmesg[self.phases[0]]['start'] |
1042 | if o > 0: | 1035 | if start <= p0start: |
1043 | targetphase = self.phases[0] | 1036 | targetphase = self.phases[0] |
1044 | o = max(0, min(end, self.end) - max(start, self.tKernRes)) | 1037 | else: |
1045 | if o > 0: | ||
1046 | targetphase = self.phases[-1] | 1038 | targetphase = self.phases[-1] |
1047 | if pid == -2: | 1039 | if pid == -2: |
1048 | htmlclass = ' bg' | 1040 | htmlclass = ' bg' |
@@ -1195,6 +1187,15 @@ class Data: | |||
1195 | if width != '0.000000' and length >= mindevlen: | 1187 | if width != '0.000000' and length >= mindevlen: |
1196 | devlist.append(dev) | 1188 | devlist.append(dev) |
1197 | self.tdevlist[phase] = devlist | 1189 | self.tdevlist[phase] = devlist |
1190 | def addHorizontalDivider(self, devname, devend): | ||
1191 | phase = 'suspend_prepare' | ||
1192 | self.newAction(phase, devname, -2, '', \ | ||
1193 | self.start, devend, '', ' sec', '') | ||
1194 | if phase not in self.tdevlist: | ||
1195 | self.tdevlist[phase] = [] | ||
1196 | self.tdevlist[phase].append(devname) | ||
1197 | d = DevItem(0, phase, self.dmesg[phase]['list'][devname]) | ||
1198 | return d | ||
1198 | def addProcessUsageEvent(self, name, times): | 1199 | def addProcessUsageEvent(self, name, times): |
1199 | # get the start and end times for this process | 1200 | # get the start and end times for this process |
1200 | maxC = 0 | 1201 | maxC = 0 |
@@ -1273,7 +1274,7 @@ class Data: | |||
1273 | class DevFunction: | 1274 | class DevFunction: |
1274 | row = 0 | 1275 | row = 0 |
1275 | count = 1 | 1276 | count = 1 |
1276 | def __init__(self, name, args, caller, ret, start, end, u, proc, pid): | 1277 | def __init__(self, name, args, caller, ret, start, end, u, proc, pid, color): |
1277 | self.name = name | 1278 | self.name = name |
1278 | self.args = args | 1279 | self.args = args |
1279 | self.caller = caller | 1280 | self.caller = caller |
@@ -1284,17 +1285,18 @@ class DevFunction: | |||
1284 | self.ubiquitous = u | 1285 | self.ubiquitous = u |
1285 | self.proc = proc | 1286 | self.proc = proc |
1286 | self.pid = pid | 1287 | self.pid = pid |
1288 | self.color = color | ||
1287 | def title(self): | 1289 | def title(self): |
1288 | cnt = '' | 1290 | cnt = '' |
1289 | if self.count > 1: | 1291 | if self.count > 1: |
1290 | cnt = '(x%d)' % self.count | 1292 | cnt = '(x%d)' % self.count |
1291 | l = '%0.3fms' % (self.length * 1000) | 1293 | l = '%0.3fms' % (self.length * 1000) |
1292 | if self.ubiquitous: | 1294 | if self.ubiquitous: |
1293 | title = '%s(%s) <- %s, %s%s(%s)' % \ | 1295 | title = '%s(%s)%s <- %s, %s(%s)' % \ |
1294 | (self.name, self.args, self.caller, self.ret, cnt, l) | 1296 | (self.name, self.args, cnt, self.caller, self.ret, l) |
1295 | else: | 1297 | else: |
1296 | title = '%s(%s) %s%s(%s)' % (self.name, self.args, self.ret, cnt, l) | 1298 | title = '%s(%s) %s%s(%s)' % (self.name, self.args, self.ret, cnt, l) |
1297 | return title | 1299 | return title.replace('"', '') |
1298 | def text(self): | 1300 | def text(self): |
1299 | if self.count > 1: | 1301 | if self.count > 1: |
1300 | text = '%s(x%d)' % (self.name, self.count) | 1302 | text = '%s(x%d)' % (self.name, self.count) |
@@ -1302,12 +1304,15 @@ class DevFunction: | |||
1302 | text = self.name | 1304 | text = self.name |
1303 | return text | 1305 | return text |
1304 | def repeat(self, tgt): | 1306 | def repeat(self, tgt): |
1307 | # is the tgt call just a repeat of this call (e.g. are we in a loop) | ||
1305 | dt = self.time - tgt.end | 1308 | dt = self.time - tgt.end |
1309 | # only combine calls if -all- attributes are identical | ||
1306 | if tgt.caller == self.caller and \ | 1310 | if tgt.caller == self.caller and \ |
1307 | tgt.name == self.name and tgt.args == self.args and \ | 1311 | tgt.name == self.name and tgt.args == self.args and \ |
1308 | tgt.proc == self.proc and tgt.pid == self.pid and \ | 1312 | tgt.proc == self.proc and tgt.pid == self.pid and \ |
1309 | tgt.ret == self.ret and dt >= 0 and dt <= 0.000100 and \ | 1313 | tgt.ret == self.ret and dt >= 0 and \ |
1310 | self.length < 0.001: | 1314 | dt <= sysvals.callloopmaxgap and \ |
1315 | self.length < sysvals.callloopmaxlen: | ||
1311 | return True | 1316 | return True |
1312 | return False | 1317 | return False |
1313 | 1318 | ||
@@ -1698,6 +1703,10 @@ class DevItem: | |||
1698 | self.test = test | 1703 | self.test = test |
1699 | self.phase = phase | 1704 | self.phase = phase |
1700 | self.dev = dev | 1705 | self.dev = dev |
1706 | def isa(self, cls): | ||
1707 | if 'htmlclass' in self.dev and cls in self.dev['htmlclass']: | ||
1708 | return True | ||
1709 | return False | ||
1701 | 1710 | ||
1702 | # Class: Timeline | 1711 | # Class: Timeline |
1703 | # Description: | 1712 | # Description: |
@@ -1767,11 +1776,10 @@ class Timeline: | |||
1767 | # devlist: the list of devices/actions in a group of contiguous phases | 1776 | # devlist: the list of devices/actions in a group of contiguous phases |
1768 | # Output: | 1777 | # Output: |
1769 | # The total number of rows needed to display this phase of the timeline | 1778 | # The total number of rows needed to display this phase of the timeline |
1770 | def getPhaseRows(self, devlist): | 1779 | def getPhaseRows(self, devlist, row=0): |
1771 | # clear all rows and set them to undefined | 1780 | # clear all rows and set them to undefined |
1772 | remaining = len(devlist) | 1781 | remaining = len(devlist) |
1773 | rowdata = dict() | 1782 | rowdata = dict() |
1774 | row = 0 | ||
1775 | sortdict = dict() | 1783 | sortdict = dict() |
1776 | myphases = [] | 1784 | myphases = [] |
1777 | # initialize all device rows to -1 and calculate devrows | 1785 | # initialize all device rows to -1 and calculate devrows |
@@ -1825,8 +1833,14 @@ class Timeline: | |||
1825 | if p not in self.rowlines[t] or p not in self.rowheight[t]: | 1833 | if p not in self.rowlines[t] or p not in self.rowheight[t]: |
1826 | self.rowlines[t][p] = dict() | 1834 | self.rowlines[t][p] = dict() |
1827 | self.rowheight[t][p] = dict() | 1835 | self.rowheight[t][p] = dict() |
1836 | rh = self.rowH | ||
1837 | # section headers should use a different row height | ||
1838 | if len(rowdata[row]) == 1 and \ | ||
1839 | 'htmlclass' in rowdata[row][0].dev and \ | ||
1840 | 'sec' in rowdata[row][0].dev['htmlclass']: | ||
1841 | rh = 15 | ||
1828 | self.rowlines[t][p][row] = rowheight | 1842 | self.rowlines[t][p][row] = rowheight |
1829 | self.rowheight[t][p][row] = rowheight * self.rowH | 1843 | self.rowheight[t][p][row] = rowheight * rh |
1830 | row += 1 | 1844 | row += 1 |
1831 | if(row > self.rows): | 1845 | if(row > self.rows): |
1832 | self.rows = int(row) | 1846 | self.rows = int(row) |
@@ -1952,7 +1966,7 @@ class ProcessMonitor: | |||
1952 | running = False | 1966 | running = False |
1953 | def procstat(self): | 1967 | def procstat(self): |
1954 | c = ['cat /proc/[1-9]*/stat 2>/dev/null'] | 1968 | c = ['cat /proc/[1-9]*/stat 2>/dev/null'] |
1955 | process = subprocess.Popen(c, shell=True, stdout=subprocess.PIPE) | 1969 | process = Popen(c, shell=True, stdout=PIPE) |
1956 | running = dict() | 1970 | running = dict() |
1957 | for line in process.stdout: | 1971 | for line in process.stdout: |
1958 | data = line.split() | 1972 | data = line.split() |
@@ -2027,7 +2041,8 @@ def parseStamp(line, data): | |||
2027 | sysvals.suspendmode = data.stamp['mode'] | 2041 | sysvals.suspendmode = data.stamp['mode'] |
2028 | if sysvals.suspendmode == 'command' and sysvals.ftracefile != '': | 2042 | if sysvals.suspendmode == 'command' and sysvals.ftracefile != '': |
2029 | modes = ['on', 'freeze', 'standby', 'mem'] | 2043 | modes = ['on', 'freeze', 'standby', 'mem'] |
2030 | out = os.popen('grep suspend_enter '+sysvals.ftracefile).read() | 2044 | out = Popen(['grep', 'suspend_enter', sysvals.ftracefile], |
2045 | stderr=PIPE, stdout=PIPE).stdout.read() | ||
2031 | m = re.match('.* suspend_enter\[(?P<mode>.*)\]', out) | 2046 | m = re.match('.* suspend_enter\[(?P<mode>.*)\]', out) |
2032 | if m and m.group('mode') in ['1', '2', '3']: | 2047 | if m and m.group('mode') in ['1', '2', '3']: |
2033 | sysvals.suspendmode = modes[int(m.group('mode'))] | 2048 | sysvals.suspendmode = modes[int(m.group('mode'))] |
@@ -2065,14 +2080,15 @@ def doesTraceLogHaveTraceEvents(): | |||
2065 | 2080 | ||
2066 | # check for kprobes | 2081 | # check for kprobes |
2067 | sysvals.usekprobes = False | 2082 | sysvals.usekprobes = False |
2068 | out = os.system('grep -q "_cal: (" '+sysvals.ftracefile) | 2083 | out = call('grep -q "_cal: (" '+sysvals.ftracefile, shell=True) |
2069 | if(out == 0): | 2084 | if(out == 0): |
2070 | sysvals.usekprobes = True | 2085 | sysvals.usekprobes = True |
2071 | # check for callgraph data on trace event blocks | 2086 | # check for callgraph data on trace event blocks |
2072 | out = os.system('grep -q "_cpu_down()" '+sysvals.ftracefile) | 2087 | out = call('grep -q "_cpu_down()" '+sysvals.ftracefile, shell=True) |
2073 | if(out == 0): | 2088 | if(out == 0): |
2074 | sysvals.usekprobes = True | 2089 | sysvals.usekprobes = True |
2075 | out = os.popen('head -1 '+sysvals.ftracefile).read().replace('\n', '') | 2090 | out = Popen(['head', '-1', sysvals.ftracefile], |
2091 | stderr=PIPE, stdout=PIPE).stdout.read().replace('\n', '') | ||
2076 | m = re.match(sysvals.stampfmt, out) | 2092 | m = re.match(sysvals.stampfmt, out) |
2077 | if m and m.group('mode') == 'command': | 2093 | if m and m.group('mode') == 'command': |
2078 | sysvals.usetraceeventsonly = True | 2094 | sysvals.usetraceeventsonly = True |
@@ -2082,14 +2098,14 @@ def doesTraceLogHaveTraceEvents(): | |||
2082 | sysvals.usetraceeventsonly = True | 2098 | sysvals.usetraceeventsonly = True |
2083 | sysvals.usetraceevents = False | 2099 | sysvals.usetraceevents = False |
2084 | for e in sysvals.traceevents: | 2100 | for e in sysvals.traceevents: |
2085 | out = os.system('grep -q "'+e+': " '+sysvals.ftracefile) | 2101 | out = call('grep -q "'+e+': " '+sysvals.ftracefile, shell=True) |
2086 | if(out != 0): | 2102 | if(out != 0): |
2087 | sysvals.usetraceeventsonly = False | 2103 | sysvals.usetraceeventsonly = False |
2088 | if(e == 'suspend_resume' and out == 0): | 2104 | if(e == 'suspend_resume' and out == 0): |
2089 | sysvals.usetraceevents = True | 2105 | sysvals.usetraceevents = True |
2090 | # determine is this log is properly formatted | 2106 | # determine is this log is properly formatted |
2091 | for e in ['SUSPEND START', 'RESUME COMPLETE']: | 2107 | for e in ['SUSPEND START', 'RESUME COMPLETE']: |
2092 | out = os.system('grep -q "'+e+'" '+sysvals.ftracefile) | 2108 | out = call('grep -q "'+e+'" '+sysvals.ftracefile, shell=True) |
2093 | if(out != 0): | 2109 | if(out != 0): |
2094 | sysvals.usetracemarkers = False | 2110 | sysvals.usetracemarkers = False |
2095 | 2111 | ||
@@ -2617,14 +2633,14 @@ def parseTraceLog(): | |||
2617 | if sysvals.suspendmode == 'command': | 2633 | if sysvals.suspendmode == 'command': |
2618 | for test in testruns: | 2634 | for test in testruns: |
2619 | for p in test.data.phases: | 2635 | for p in test.data.phases: |
2620 | if p == 'resume_complete': | 2636 | if p == 'suspend_prepare': |
2621 | test.data.dmesg[p]['start'] = test.data.start | 2637 | test.data.dmesg[p]['start'] = test.data.start |
2622 | test.data.dmesg[p]['end'] = test.data.end | 2638 | test.data.dmesg[p]['end'] = test.data.end |
2623 | else: | 2639 | else: |
2624 | test.data.dmesg[p]['start'] = test.data.start | 2640 | test.data.dmesg[p]['start'] = test.data.end |
2625 | test.data.dmesg[p]['end'] = test.data.start | 2641 | test.data.dmesg[p]['end'] = test.data.end |
2626 | test.data.tSuspended = test.data.start | 2642 | test.data.tSuspended = test.data.end |
2627 | test.data.tResumed = test.data.start | 2643 | test.data.tResumed = test.data.end |
2628 | test.data.tLow = 0 | 2644 | test.data.tLow = 0 |
2629 | test.data.fwValid = False | 2645 | test.data.fwValid = False |
2630 | 2646 | ||
@@ -2632,16 +2648,22 @@ def parseTraceLog(): | |||
2632 | if sysvals.usedevsrc or sysvals.useprocmon: | 2648 | if sysvals.usedevsrc or sysvals.useprocmon: |
2633 | sysvals.mixedphaseheight = False | 2649 | sysvals.mixedphaseheight = False |
2634 | 2650 | ||
2635 | for test in testruns: | 2651 | for i in range(len(testruns)): |
2652 | test = testruns[i] | ||
2653 | data = test.data | ||
2654 | # find the total time range for this test (begin, end) | ||
2655 | tlb, tle = data.start, data.end | ||
2656 | if i < len(testruns) - 1: | ||
2657 | tle = testruns[i+1].data.start | ||
2636 | # add the process usage data to the timeline | 2658 | # add the process usage data to the timeline |
2637 | if sysvals.useprocmon: | 2659 | if sysvals.useprocmon: |
2638 | test.data.createProcessUsageEvents() | 2660 | data.createProcessUsageEvents() |
2639 | # add the traceevent data to the device hierarchy | 2661 | # add the traceevent data to the device hierarchy |
2640 | if(sysvals.usetraceevents): | 2662 | if(sysvals.usetraceevents): |
2641 | # add actual trace funcs | 2663 | # add actual trace funcs |
2642 | for name in test.ttemp: | 2664 | for name in test.ttemp: |
2643 | for event in test.ttemp[name]: | 2665 | for event in test.ttemp[name]: |
2644 | test.data.newActionGlobal(name, event['begin'], event['end'], event['pid']) | 2666 | data.newActionGlobal(name, event['begin'], event['end'], event['pid']) |
2645 | # add the kprobe based virtual tracefuncs as actual devices | 2667 | # add the kprobe based virtual tracefuncs as actual devices |
2646 | for key in tp.ktemp: | 2668 | for key in tp.ktemp: |
2647 | name, pid = key | 2669 | name, pid = key |
@@ -2649,25 +2671,21 @@ def parseTraceLog(): | |||
2649 | continue | 2671 | continue |
2650 | for e in tp.ktemp[key]: | 2672 | for e in tp.ktemp[key]: |
2651 | kb, ke = e['begin'], e['end'] | 2673 | kb, ke = e['begin'], e['end'] |
2652 | if kb == ke or not test.data.isInsideTimeline(kb, ke): | 2674 | if kb == ke or tlb > kb or tle <= kb: |
2653 | continue | 2675 | continue |
2654 | test.data.newActionGlobal(e['name'], kb, ke, pid) | 2676 | color = sysvals.kprobeColor(name) |
2677 | data.newActionGlobal(e['name'], kb, ke, pid, color) | ||
2655 | # add config base kprobes and dev kprobes | 2678 | # add config base kprobes and dev kprobes |
2656 | for key in tp.ktemp: | 2679 | if sysvals.usedevsrc: |
2657 | name, pid = key | 2680 | for key in tp.ktemp: |
2658 | if name in sysvals.tracefuncs: | 2681 | name, pid = key |
2659 | continue | 2682 | if name in sysvals.tracefuncs or name not in sysvals.dev_tracefuncs: |
2660 | for e in tp.ktemp[key]: | ||
2661 | kb, ke = e['begin'], e['end'] | ||
2662 | if kb == ke or not test.data.isInsideTimeline(kb, ke): | ||
2663 | continue | 2683 | continue |
2664 | color = sysvals.kprobeColor(e['name']) | 2684 | for e in tp.ktemp[key]: |
2665 | if name not in sysvals.dev_tracefuncs: | 2685 | kb, ke = e['begin'], e['end'] |
2666 | # custom user kprobe from the config | 2686 | if kb == ke or tlb > kb or tle <= kb: |
2667 | test.data.newActionGlobal(e['name'], kb, ke, -2, color) | 2687 | continue |
2668 | elif sysvals.usedevsrc: | 2688 | data.addDeviceFunctionCall(e['name'], name, e['proc'], pid, kb, |
2669 | # dev kprobe | ||
2670 | test.data.addDeviceFunctionCall(e['name'], name, e['proc'], pid, kb, | ||
2671 | ke, e['cdata'], e['rdata']) | 2689 | ke, e['cdata'], e['rdata']) |
2672 | if sysvals.usecallgraph: | 2690 | if sysvals.usecallgraph: |
2673 | # add the callgraph data to the device hierarchy | 2691 | # add the callgraph data to the device hierarchy |
@@ -2683,7 +2701,7 @@ def parseTraceLog(): | |||
2683 | id+', ignoring this callback') | 2701 | id+', ignoring this callback') |
2684 | continue | 2702 | continue |
2685 | # match cg data to devices | 2703 | # match cg data to devices |
2686 | if sysvals.suspendmode == 'command' or not cg.deviceMatch(pid, test.data): | 2704 | if sysvals.suspendmode == 'command' or not cg.deviceMatch(pid, data): |
2687 | sortkey = '%f%f%d' % (cg.start, cg.end, pid) | 2705 | sortkey = '%f%f%d' % (cg.start, cg.end, pid) |
2688 | sortlist[sortkey] = cg | 2706 | sortlist[sortkey] = cg |
2689 | # create blocks for orphan cg data | 2707 | # create blocks for orphan cg data |
@@ -2692,7 +2710,7 @@ def parseTraceLog(): | |||
2692 | name = cg.list[0].name | 2710 | name = cg.list[0].name |
2693 | if sysvals.isCallgraphFunc(name): | 2711 | if sysvals.isCallgraphFunc(name): |
2694 | vprint('Callgraph found for task %d: %.3fms, %s' % (cg.pid, (cg.end - cg.start)*1000, name)) | 2712 | vprint('Callgraph found for task %d: %.3fms, %s' % (cg.pid, (cg.end - cg.start)*1000, name)) |
2695 | cg.newActionFromFunction(test.data) | 2713 | cg.newActionFromFunction(data) |
2696 | 2714 | ||
2697 | if sysvals.suspendmode == 'command': | 2715 | if sysvals.suspendmode == 'command': |
2698 | if(sysvals.verbose): | 2716 | if(sysvals.verbose): |
@@ -2724,14 +2742,14 @@ def parseTraceLog(): | |||
2724 | if sysvals.verbose: | 2742 | if sysvals.verbose: |
2725 | data.printDetails() | 2743 | data.printDetails() |
2726 | 2744 | ||
2727 | # merge any overlapping devices between test runs | 2745 | # x2: merge any overlapping devices between test runs |
2728 | if sysvals.usedevsrc and len(testdata) > 1: | 2746 | if sysvals.usedevsrc and len(testdata) > 1: |
2729 | tc = len(testdata) | 2747 | tc = len(testdata) |
2730 | for i in range(tc - 1): | 2748 | for i in range(tc - 1): |
2731 | devlist = testdata[i].overflowDevices() | 2749 | devlist = testdata[i].overflowDevices() |
2732 | for j in range(i + 1, tc): | 2750 | for j in range(i + 1, tc): |
2733 | testdata[j].mergeOverlapDevices(devlist) | 2751 | testdata[j].mergeOverlapDevices(devlist) |
2734 | 2752 | testdata[0].stitchTouchingThreads(testdata[1:]) | |
2735 | return testdata | 2753 | return testdata |
2736 | 2754 | ||
2737 | # Function: loadRawKernelLog | 2755 | # Function: loadRawKernelLog |
@@ -3300,29 +3318,29 @@ def createHTML(testruns): | |||
3300 | html_timeline = '<div id="dmesgzoombox" class="zoombox">\n<div id="{0}" class="timeline" style="height:{1}px">\n' | 3318 | html_timeline = '<div id="dmesgzoombox" class="zoombox">\n<div id="{0}" class="timeline" style="height:{1}px">\n' |
3301 | html_tblock = '<div id="block{0}" class="tblock" style="left:{1}%;width:{2}%;"><div class="tback" style="height:{3}px"></div>\n' | 3319 | html_tblock = '<div id="block{0}" class="tblock" style="left:{1}%;width:{2}%;"><div class="tback" style="height:{3}px"></div>\n' |
3302 | html_device = '<div id="{0}" title="{1}" class="thread{7}" style="left:{2}%;top:{3}px;height:{4}px;width:{5}%;{8}">{6}</div>\n' | 3320 | html_device = '<div id="{0}" title="{1}" class="thread{7}" style="left:{2}%;top:{3}px;height:{4}px;width:{5}%;{8}">{6}</div>\n' |
3303 | html_traceevent = '<div title="{0}" class="traceevent{6}" style="left:{1}%;top:{2}px;height:{3}px;width:{4}%;line-height:{3}px;">{5}</div>\n' | 3321 | html_traceevent = '<div title="{0}" class="traceevent{6}" style="left:{1}%;top:{2}px;height:{3}px;width:{4}%;line-height:{3}px;{7}">{5}</div>\n' |
3304 | html_cpuexec = '<div class="jiffie" style="left:{0}%;top:{1}px;height:{2}px;width:{3}%;background:{4};"></div>\n' | 3322 | html_cpuexec = '<div class="jiffie" style="left:{0}%;top:{1}px;height:{2}px;width:{3}%;background:{4};"></div>\n' |
3305 | html_phase = '<div class="phase" style="left:{0}%;width:{1}%;top:{2}px;height:{3}px;background-color:{4}">{5}</div>\n' | 3323 | html_phase = '<div class="phase" style="left:{0}%;width:{1}%;top:{2}px;height:{3}px;background-color:{4}">{5}</div>\n' |
3306 | html_phaselet = '<div id="{0}" class="phaselet" style="left:{1}%;width:{2}%;background:{3}"></div>\n' | 3324 | html_phaselet = '<div id="{0}" class="phaselet" style="left:{1}%;width:{2}%;background:{3}"></div>\n' |
3307 | html_legend = '<div id="p{3}" class="square" style="left:{0}%;background-color:{1}"> {2}</div>\n' | 3325 | html_legend = '<div id="p{3}" class="square" style="left:{0}%;background-color:{1}"> {2}</div>\n' |
3308 | html_timetotal = '<table class="time1">\n<tr>'\ | 3326 | html_timetotal = '<table class="time1">\n<tr>'\ |
3309 | '<td class="green">{2} Suspend Time: <b>{0} ms</b></td>'\ | 3327 | '<td class="green" title="{3}">{2} Suspend Time: <b>{0} ms</b></td>'\ |
3310 | '<td class="yellow">{2} Resume Time: <b>{1} ms</b></td>'\ | 3328 | '<td class="yellow" title="{4}">{2} Resume Time: <b>{1} ms</b></td>'\ |
3311 | '</tr>\n</table>\n' | 3329 | '</tr>\n</table>\n' |
3312 | html_timetotal2 = '<table class="time1">\n<tr>'\ | 3330 | html_timetotal2 = '<table class="time1">\n<tr>'\ |
3313 | '<td class="green">{3} Suspend Time: <b>{0} ms</b></td>'\ | 3331 | '<td class="green" title="{4}">{3} Suspend Time: <b>{0} ms</b></td>'\ |
3314 | '<td class="gray">'+sysvals.suspendmode+' time: <b>{1} ms</b></td>'\ | 3332 | '<td class="gray" title="time spent in low-power mode with clock running">'+sysvals.suspendmode+' time: <b>{1} ms</b></td>'\ |
3315 | '<td class="yellow">{3} Resume Time: <b>{2} ms</b></td>'\ | 3333 | '<td class="yellow" title="{5}">{3} Resume Time: <b>{2} ms</b></td>'\ |
3316 | '</tr>\n</table>\n' | 3334 | '</tr>\n</table>\n' |
3317 | html_timetotal3 = '<table class="time1">\n<tr>'\ | 3335 | html_timetotal3 = '<table class="time1">\n<tr>'\ |
3318 | '<td class="green">Execution Time: <b>{0} ms</b></td>'\ | 3336 | '<td class="green">Execution Time: <b>{0} ms</b></td>'\ |
3319 | '<td class="yellow">Command: <b>{1}</b></td>'\ | 3337 | '<td class="yellow">Command: <b>{1}</b></td>'\ |
3320 | '</tr>\n</table>\n' | 3338 | '</tr>\n</table>\n' |
3321 | html_timegroups = '<table class="time2">\n<tr>'\ | 3339 | html_timegroups = '<table class="time2">\n<tr>'\ |
3322 | '<td class="green">{4}Kernel Suspend: {0} ms</td>'\ | 3340 | '<td class="green" title="time from kernel enter_state({5}) to firmware mode [kernel time only]">{4}Kernel Suspend: {0} ms</td>'\ |
3323 | '<td class="purple">{4}Firmware Suspend: {1} ms</td>'\ | 3341 | '<td class="purple">{4}Firmware Suspend: {1} ms</td>'\ |
3324 | '<td class="purple">{4}Firmware Resume: {2} ms</td>'\ | 3342 | '<td class="purple">{4}Firmware Resume: {2} ms</td>'\ |
3325 | '<td class="yellow">{4}Kernel Resume: {3} ms</td>'\ | 3343 | '<td class="yellow" title="time from firmware mode to return from kernel enter_state({5}) [kernel time only]">{4}Kernel Resume: {3} ms</td>'\ |
3326 | '</tr>\n</table>\n' | 3344 | '</tr>\n</table>\n' |
3327 | 3345 | ||
3328 | # html format variables | 3346 | # html format variables |
@@ -3338,6 +3356,10 @@ def createHTML(testruns): | |||
3338 | # Generate the header for this timeline | 3356 | # Generate the header for this timeline |
3339 | for data in testruns: | 3357 | for data in testruns: |
3340 | tTotal = data.end - data.start | 3358 | tTotal = data.end - data.start |
3359 | sktime = (data.dmesg['suspend_machine']['end'] - \ | ||
3360 | data.tKernSus) * 1000 | ||
3361 | rktime = (data.dmesg['resume_complete']['end'] - \ | ||
3362 | data.dmesg['resume_machine']['start']) * 1000 | ||
3341 | if(tTotal == 0): | 3363 | if(tTotal == 0): |
3342 | print('ERROR: No timeline data') | 3364 | print('ERROR: No timeline data') |
3343 | sys.exit() | 3365 | sys.exit() |
@@ -3354,42 +3376,40 @@ def createHTML(testruns): | |||
3354 | thtml = html_timetotal3.format(run_time, testdesc) | 3376 | thtml = html_timetotal3.format(run_time, testdesc) |
3355 | devtl.html['header'] += thtml | 3377 | devtl.html['header'] += thtml |
3356 | elif data.fwValid: | 3378 | elif data.fwValid: |
3357 | suspend_time = '%.0f'%((data.tSuspended-data.start)*1000 + \ | 3379 | suspend_time = '%.0f'%(sktime + (data.fwSuspend/1000000.0)) |
3358 | (data.fwSuspend/1000000.0)) | 3380 | resume_time = '%.0f'%(rktime + (data.fwResume/1000000.0)) |
3359 | resume_time = '%.0f'%((data.end-data.tSuspended)*1000 + \ | ||
3360 | (data.fwResume/1000000.0)) | ||
3361 | testdesc1 = 'Total' | 3381 | testdesc1 = 'Total' |
3362 | testdesc2 = '' | 3382 | testdesc2 = '' |
3383 | stitle = 'time from kernel enter_state(%s) to low-power mode [kernel & firmware time]' % sysvals.suspendmode | ||
3384 | rtitle = 'time from low-power mode to return from kernel enter_state(%s) [firmware & kernel time]' % sysvals.suspendmode | ||
3363 | if(len(testruns) > 1): | 3385 | if(len(testruns) > 1): |
3364 | testdesc1 = testdesc2 = ordinal(data.testnumber+1) | 3386 | testdesc1 = testdesc2 = ordinal(data.testnumber+1) |
3365 | testdesc2 += ' ' | 3387 | testdesc2 += ' ' |
3366 | if(data.tLow == 0): | 3388 | if(data.tLow == 0): |
3367 | thtml = html_timetotal.format(suspend_time, \ | 3389 | thtml = html_timetotal.format(suspend_time, \ |
3368 | resume_time, testdesc1) | 3390 | resume_time, testdesc1, stitle, rtitle) |
3369 | else: | 3391 | else: |
3370 | thtml = html_timetotal2.format(suspend_time, low_time, \ | 3392 | thtml = html_timetotal2.format(suspend_time, low_time, \ |
3371 | resume_time, testdesc1) | 3393 | resume_time, testdesc1, stitle, rtitle) |
3372 | devtl.html['header'] += thtml | 3394 | devtl.html['header'] += thtml |
3373 | sktime = '%.3f'%((data.dmesg['suspend_machine']['end'] - \ | ||
3374 | data.tKernSus)*1000) | ||
3375 | sftime = '%.3f'%(data.fwSuspend / 1000000.0) | 3395 | sftime = '%.3f'%(data.fwSuspend / 1000000.0) |
3376 | rftime = '%.3f'%(data.fwResume / 1000000.0) | 3396 | rftime = '%.3f'%(data.fwResume / 1000000.0) |
3377 | rktime = '%.3f'%((data.dmesg['resume_complete']['end'] - \ | 3397 | devtl.html['header'] += html_timegroups.format('%.3f'%sktime, \ |
3378 | data.dmesg['resume_machine']['start'])*1000) | 3398 | sftime, rftime, '%.3f'%rktime, testdesc2, sysvals.suspendmode) |
3379 | devtl.html['header'] += html_timegroups.format(sktime, \ | ||
3380 | sftime, rftime, rktime, testdesc2) | ||
3381 | else: | 3399 | else: |
3382 | suspend_time = '%.0f'%((data.tSuspended-data.start)*1000) | 3400 | suspend_time = '%.3f' % sktime |
3383 | resume_time = '%.0f'%((data.end-data.tSuspended)*1000) | 3401 | resume_time = '%.3f' % rktime |
3384 | testdesc = 'Kernel' | 3402 | testdesc = 'Kernel' |
3403 | stitle = 'time from kernel enter_state(%s) to firmware mode [kernel time only]' % sysvals.suspendmode | ||
3404 | rtitle = 'time from firmware mode to return from kernel enter_state(%s) [kernel time only]' % sysvals.suspendmode | ||
3385 | if(len(testruns) > 1): | 3405 | if(len(testruns) > 1): |
3386 | testdesc = ordinal(data.testnumber+1)+' '+testdesc | 3406 | testdesc = ordinal(data.testnumber+1)+' '+testdesc |
3387 | if(data.tLow == 0): | 3407 | if(data.tLow == 0): |
3388 | thtml = html_timetotal.format(suspend_time, \ | 3408 | thtml = html_timetotal.format(suspend_time, \ |
3389 | resume_time, testdesc) | 3409 | resume_time, testdesc, stitle, rtitle) |
3390 | else: | 3410 | else: |
3391 | thtml = html_timetotal2.format(suspend_time, low_time, \ | 3411 | thtml = html_timetotal2.format(suspend_time, low_time, \ |
3392 | resume_time, testdesc) | 3412 | resume_time, testdesc, stitle, rtitle) |
3393 | devtl.html['header'] += thtml | 3413 | devtl.html['header'] += thtml |
3394 | 3414 | ||
3395 | # time scale for potentially multiple datasets | 3415 | # time scale for potentially multiple datasets |
@@ -3400,6 +3420,9 @@ def createHTML(testruns): | |||
3400 | 3420 | ||
3401 | # determine the maximum number of rows we need to draw | 3421 | # determine the maximum number of rows we need to draw |
3402 | fulllist = [] | 3422 | fulllist = [] |
3423 | threadlist = [] | ||
3424 | pscnt = 0 | ||
3425 | devcnt = 0 | ||
3403 | for data in testruns: | 3426 | for data in testruns: |
3404 | data.selectTimelineDevices('%f', tTotal, sysvals.mindevlen) | 3427 | data.selectTimelineDevices('%f', tTotal, sysvals.mindevlen) |
3405 | for group in data.devicegroups: | 3428 | for group in data.devicegroups: |
@@ -3408,11 +3431,31 @@ def createHTML(testruns): | |||
3408 | for devname in data.tdevlist[phase]: | 3431 | for devname in data.tdevlist[phase]: |
3409 | d = DevItem(data.testnumber, phase, data.dmesg[phase]['list'][devname]) | 3432 | d = DevItem(data.testnumber, phase, data.dmesg[phase]['list'][devname]) |
3410 | devlist.append(d) | 3433 | devlist.append(d) |
3411 | fulllist.append(d) | 3434 | if d.isa('kth'): |
3435 | threadlist.append(d) | ||
3436 | else: | ||
3437 | if d.isa('ps'): | ||
3438 | pscnt += 1 | ||
3439 | else: | ||
3440 | devcnt += 1 | ||
3441 | fulllist.append(d) | ||
3412 | if sysvals.mixedphaseheight: | 3442 | if sysvals.mixedphaseheight: |
3413 | devtl.getPhaseRows(devlist) | 3443 | devtl.getPhaseRows(devlist) |
3414 | if not sysvals.mixedphaseheight: | 3444 | if not sysvals.mixedphaseheight: |
3445 | if len(threadlist) > 0 and len(fulllist) > 0: | ||
3446 | if pscnt > 0 and devcnt > 0: | ||
3447 | msg = 'user processes & device pm callbacks' | ||
3448 | elif pscnt > 0: | ||
3449 | msg = 'user processes' | ||
3450 | else: | ||
3451 | msg = 'device pm callbacks' | ||
3452 | d = testruns[0].addHorizontalDivider(msg, testruns[-1].end) | ||
3453 | fulllist.insert(0, d) | ||
3415 | devtl.getPhaseRows(fulllist) | 3454 | devtl.getPhaseRows(fulllist) |
3455 | if len(threadlist) > 0: | ||
3456 | d = testruns[0].addHorizontalDivider('asynchronous kernel threads', testruns[-1].end) | ||
3457 | threadlist.insert(0, d) | ||
3458 | devtl.getPhaseRows(threadlist, devtl.rows) | ||
3416 | devtl.calcTotalRows() | 3459 | devtl.calcTotalRows() |
3417 | 3460 | ||
3418 | # create bounding box, add buttons | 3461 | # create bounding box, add buttons |
@@ -3494,7 +3537,7 @@ def createHTML(testruns): | |||
3494 | length = ' (%0.3f ms) ' % ((dev['end']-dev['start'])*1000) | 3537 | length = ' (%0.3f ms) ' % ((dev['end']-dev['start'])*1000) |
3495 | title = name+drv+xtrainfo+length | 3538 | title = name+drv+xtrainfo+length |
3496 | if sysvals.suspendmode == 'command': | 3539 | if sysvals.suspendmode == 'command': |
3497 | title += 'cmdexec' | 3540 | title += sysvals.testcommand |
3498 | elif xtraclass == ' ps': | 3541 | elif xtraclass == ' ps': |
3499 | if 'suspend' in b: | 3542 | if 'suspend' in b: |
3500 | title += 'pre_suspend_process' | 3543 | title += 'pre_suspend_process' |
@@ -3526,12 +3569,12 @@ def createHTML(testruns): | |||
3526 | top = '%.3f' % (rowtop + devtl.scaleH + (e.row*devtl.rowH)) | 3569 | top = '%.3f' % (rowtop + devtl.scaleH + (e.row*devtl.rowH)) |
3527 | left = '%f' % (((e.time-m0)*100)/mTotal) | 3570 | left = '%f' % (((e.time-m0)*100)/mTotal) |
3528 | width = '%f' % (e.length*100/mTotal) | 3571 | width = '%f' % (e.length*100/mTotal) |
3529 | sleepclass = '' | 3572 | xtrastyle = '' |
3530 | if e.ubiquitous: | 3573 | if e.color: |
3531 | sleepclass = ' sleep' | 3574 | xtrastyle = 'background:%s;' % e.color |
3532 | devtl.html['timeline'] += \ | 3575 | devtl.html['timeline'] += \ |
3533 | html_traceevent.format(e.title(), \ | 3576 | html_traceevent.format(e.title(), \ |
3534 | left, top, height, width, e.text(), sleepclass) | 3577 | left, top, height, width, e.text(), '', xtrastyle) |
3535 | # draw the time scale, try to make the number of labels readable | 3578 | # draw the time scale, try to make the number of labels readable |
3536 | devtl.html['timeline'] += devtl.createTimeScale(m0, mMax, tTotal, dir) | 3579 | devtl.html['timeline'] += devtl.createTimeScale(m0, mMax, tTotal, dir) |
3537 | devtl.html['timeline'] += '</div>\n' | 3580 | devtl.html['timeline'] += '</div>\n' |
@@ -3601,17 +3644,15 @@ def createHTML(testruns): | |||
3601 | .zoombox {position:relative;width:100%;overflow-x:scroll;-webkit-user-select:none;-moz-user-select:none;user-select:none;}\n\ | 3644 | .zoombox {position:relative;width:100%;overflow-x:scroll;-webkit-user-select:none;-moz-user-select:none;user-select:none;}\n\ |
3602 | .timeline {position:relative;font-size:14px;cursor:pointer;width:100%; overflow:hidden;background:linear-gradient(#cccccc, white);}\n\ | 3645 | .timeline {position:relative;font-size:14px;cursor:pointer;width:100%; overflow:hidden;background:linear-gradient(#cccccc, white);}\n\ |
3603 | .thread {position:absolute;height:0%;overflow:hidden;z-index:7;line-height:30px;font-size:14px;border:1px solid;text-align:center;white-space:nowrap;}\n\ | 3646 | .thread {position:absolute;height:0%;overflow:hidden;z-index:7;line-height:30px;font-size:14px;border:1px solid;text-align:center;white-space:nowrap;}\n\ |
3604 | .thread.sync {background-color:'+sysvals.synccolor+';}\n\ | ||
3605 | .thread.bg {background-color:'+sysvals.kprobecolor+';}\n\ | ||
3606 | .thread.ps {border-radius:3px;background:linear-gradient(to top, #ccc, #eee);}\n\ | 3647 | .thread.ps {border-radius:3px;background:linear-gradient(to top, #ccc, #eee);}\n\ |
3607 | .thread:hover {background-color:white;border:1px solid red;'+hoverZ+'}\n\ | 3648 | .thread:hover {background-color:white;border:1px solid red;'+hoverZ+'}\n\ |
3649 | .thread.sec,.thread.sec:hover {background-color:black;border:0;color:white;line-height:15px;font-size:10px;}\n\ | ||
3608 | .hover {background-color:white;border:1px solid red;'+hoverZ+'}\n\ | 3650 | .hover {background-color:white;border:1px solid red;'+hoverZ+'}\n\ |
3609 | .hover.sync {background-color:white;}\n\ | 3651 | .hover.sync {background-color:white;}\n\ |
3610 | .hover.bg,.hover.kth,.hover.sync,.hover.ps {background-color:white;}\n\ | 3652 | .hover.bg,.hover.kth,.hover.sync,.hover.ps {background-color:white;}\n\ |
3611 | .jiffie {position:absolute;pointer-events: none;z-index:8;}\n\ | 3653 | .jiffie {position:absolute;pointer-events: none;z-index:8;}\n\ |
3612 | .traceevent {position:absolute;font-size:10px;z-index:7;overflow:hidden;color:black;text-align:center;white-space:nowrap;border-radius:5px;border:1px solid black;background:linear-gradient(to bottom right,rgb(204,204,204),rgb(150,150,150));}\n\ | 3654 | .traceevent {position:absolute;font-size:10px;z-index:7;overflow:hidden;color:black;text-align:center;white-space:nowrap;border-radius:5px;border:1px solid black;background:linear-gradient(to bottom right,#CCC,#969696);}\n\ |
3613 | .traceevent.sleep {font-style:normal;}\n\ | 3655 | .traceevent:hover {color:white;font-weight:bold;border:1px solid white;}\n\ |
3614 | .traceevent:hover {background:white;}\n\ | ||
3615 | .phase {position:absolute;overflow:hidden;border:0px;text-align:center;}\n\ | 3656 | .phase {position:absolute;overflow:hidden;border:0px;text-align:center;}\n\ |
3616 | .phaselet {position:absolute;overflow:hidden;border:0px;text-align:center;height:100px;font-size:24px;}\n\ | 3657 | .phaselet {position:absolute;overflow:hidden;border:0px;text-align:center;height:100px;font-size:24px;}\n\ |
3617 | .t {position:absolute;pointer-events:none;top:0%;height:100%;border-right:1px solid black;z-index:6;}\n\ | 3658 | .t {position:absolute;pointer-events:none;top:0%;height:100%;border-right:1px solid black;z-index:6;}\n\ |
@@ -4108,7 +4149,7 @@ def executeSuspend(): | |||
4108 | time.sleep(sysvals.predelay/1000.0) | 4149 | time.sleep(sysvals.predelay/1000.0) |
4109 | # initiate suspend or command | 4150 | # initiate suspend or command |
4110 | if sysvals.testcommand != '': | 4151 | if sysvals.testcommand != '': |
4111 | os.system(sysvals.testcommand+' 2>&1'); | 4152 | call(sysvals.testcommand+' 2>&1', shell=True); |
4112 | else: | 4153 | else: |
4113 | pf = open(sysvals.powerfile, 'w') | 4154 | pf = open(sysvals.powerfile, 'w') |
4114 | pf.write(sysvals.suspendmode) | 4155 | pf.write(sysvals.suspendmode) |
@@ -4135,7 +4176,7 @@ def executeSuspend(): | |||
4135 | sysvals.fsetVal('0', 'tracing_on') | 4176 | sysvals.fsetVal('0', 'tracing_on') |
4136 | print('CAPTURING TRACE') | 4177 | print('CAPTURING TRACE') |
4137 | writeDatafileHeader(sysvals.ftracefile, fwdata) | 4178 | writeDatafileHeader(sysvals.ftracefile, fwdata) |
4138 | os.system('cat '+tp+'trace >> '+sysvals.ftracefile) | 4179 | call('cat '+tp+'trace >> '+sysvals.ftracefile, shell=True) |
4139 | sysvals.fsetVal('', 'trace') | 4180 | sysvals.fsetVal('', 'trace') |
4140 | devProps() | 4181 | devProps() |
4141 | # grab a copy of the dmesg output | 4182 | # grab a copy of the dmesg output |
@@ -4167,12 +4208,12 @@ def setUSBDevicesAuto(): | |||
4167 | for dirname, dirnames, filenames in os.walk('/sys/devices'): | 4208 | for dirname, dirnames, filenames in os.walk('/sys/devices'): |
4168 | if(re.match('.*/usb[0-9]*.*', dirname) and | 4209 | if(re.match('.*/usb[0-9]*.*', dirname) and |
4169 | 'idVendor' in filenames and 'idProduct' in filenames): | 4210 | 'idVendor' in filenames and 'idProduct' in filenames): |
4170 | os.system('echo auto > %s/power/control' % dirname) | 4211 | call('echo auto > %s/power/control' % dirname, shell=True) |
4171 | name = dirname.split('/')[-1] | 4212 | name = dirname.split('/')[-1] |
4172 | desc = os.popen('cat %s/product 2>/dev/null' % \ | 4213 | desc = Popen(['cat', '%s/product' % dirname], |
4173 | dirname).read().replace('\n', '') | 4214 | stderr=PIPE, stdout=PIPE).stdout.read().replace('\n', '') |
4174 | ctrl = os.popen('cat %s/power/control 2>/dev/null' % \ | 4215 | ctrl = Popen(['cat', '%s/power/control' % dirname], |
4175 | dirname).read().replace('\n', '') | 4216 | stderr=PIPE, stdout=PIPE).stdout.read().replace('\n', '') |
4176 | print('control is %s for %6s: %s' % (ctrl, name, desc)) | 4217 | print('control is %s for %6s: %s' % (ctrl, name, desc)) |
4177 | 4218 | ||
4178 | # Function: yesno | 4219 | # Function: yesno |
@@ -4236,12 +4277,12 @@ def detectUSB(): | |||
4236 | if(re.match('.*/usb[0-9]*.*', dirname) and | 4277 | if(re.match('.*/usb[0-9]*.*', dirname) and |
4237 | 'idVendor' in filenames and 'idProduct' in filenames): | 4278 | 'idVendor' in filenames and 'idProduct' in filenames): |
4238 | for i in field: | 4279 | for i in field: |
4239 | field[i] = os.popen('cat %s/%s 2>/dev/null' % \ | 4280 | field[i] = Popen(['cat', '%s/%s' % (dirname, i)], |
4240 | (dirname, i)).read().replace('\n', '') | 4281 | stderr=PIPE, stdout=PIPE).stdout.read().replace('\n', '') |
4241 | name = dirname.split('/')[-1] | 4282 | name = dirname.split('/')[-1] |
4242 | for i in power: | 4283 | for i in power: |
4243 | power[i] = os.popen('cat %s/power/%s 2>/dev/null' % \ | 4284 | power[i] = Popen(['cat', '%s/power/%s' % (dirname, i)], |
4244 | (dirname, i)).read().replace('\n', '') | 4285 | stderr=PIPE, stdout=PIPE).stdout.read().replace('\n', '') |
4245 | if(re.match('usb[0-9]*', name)): | 4286 | if(re.match('usb[0-9]*', name)): |
4246 | first = '%-8s' % name | 4287 | first = '%-8s' % name |
4247 | else: | 4288 | else: |
@@ -4619,35 +4660,19 @@ def statusCheck(probecheck=False): | |||
4619 | if not probecheck: | 4660 | if not probecheck: |
4620 | return status | 4661 | return status |
4621 | 4662 | ||
4622 | if (sysvals.usecallgraph and len(sysvals.debugfuncs) > 0) or len(sysvals.kprobes) > 0: | 4663 | # verify kprobes |
4623 | sysvals.initFtrace(True) | 4664 | if sysvals.usekprobes and len(sysvals.tracefuncs) > 0: |
4624 | 4665 | print(' verifying timeline kprobes work:') | |
4625 | # verify callgraph debugfuncs | 4666 | for name in sorted(sysvals.tracefuncs): |
4626 | if sysvals.usecallgraph and len(sysvals.debugfuncs) > 0: | ||
4627 | print(' verifying these ftrace callgraph functions work:') | ||
4628 | sysvals.setFtraceFilterFunctions(sysvals.debugfuncs) | ||
4629 | fp = open(sysvals.tpath+'set_graph_function', 'r') | ||
4630 | flist = fp.read().split('\n') | ||
4631 | fp.close() | ||
4632 | for func in sysvals.debugfuncs: | ||
4633 | res = sysvals.colorText('NO') | 4667 | res = sysvals.colorText('NO') |
4634 | if func in flist: | 4668 | if sysvals.testKprobe(name, sysvals.tracefuncs[name]): |
4635 | res = 'YES' | 4669 | res = 'YES' |
4636 | else: | 4670 | print(' %s: %s' % (name, res)) |
4637 | for i in flist: | 4671 | if sysvals.usedevsrc and sysvals.usekprobes and len(sysvals.dev_tracefuncs) > 0: |
4638 | if ' [' in i and func == i.split(' ')[0]: | 4672 | print(' verifying dev kprobes work:') |
4639 | res = 'YES' | 4673 | for name in sorted(sysvals.dev_tracefuncs): |
4640 | break | ||
4641 | print(' %s: %s' % (func, res)) | ||
4642 | |||
4643 | # verify kprobes | ||
4644 | if len(sysvals.kprobes) > 0: | ||
4645 | print(' verifying these kprobes work:') | ||
4646 | for name in sorted(sysvals.kprobes): | ||
4647 | if name in sysvals.tracefuncs: | ||
4648 | continue | ||
4649 | res = sysvals.colorText('NO') | 4674 | res = sysvals.colorText('NO') |
4650 | if sysvals.testKprobe(sysvals.kprobes[name]): | 4675 | if sysvals.testKprobe(name, sysvals.dev_tracefuncs[name]): |
4651 | res = 'YES' | 4676 | res = 'YES' |
4652 | print(' %s: %s' % (name, res)) | 4677 | print(' %s: %s' % (name, res)) |
4653 | 4678 | ||
@@ -4786,6 +4811,11 @@ def runTest(subdir, testpath=''): | |||
4786 | if(sysvals.usecallgraph or sysvals.usetraceevents): | 4811 | if(sysvals.usecallgraph or sysvals.usetraceevents): |
4787 | appendIncompleteTraceLog(testruns) | 4812 | appendIncompleteTraceLog(testruns) |
4788 | createHTML(testruns) | 4813 | createHTML(testruns) |
4814 | # if running as root, change output dir owner to sudo_user | ||
4815 | if os.path.isdir(sysvals.testdir) and os.getuid() == 0 and \ | ||
4816 | 'SUDO_USER' in os.environ: | ||
4817 | cmd = 'chown -R {0}:{0} {1} > /dev/null 2>&1' | ||
4818 | call(cmd.format(os.environ['SUDO_USER'], sysvals.testdir), shell=True) | ||
4789 | 4819 | ||
4790 | # Function: runSummary | 4820 | # Function: runSummary |
4791 | # Description: | 4821 | # Description: |
@@ -4851,9 +4881,10 @@ def configFromFile(file): | |||
4851 | global sysvals | 4881 | global sysvals |
4852 | Config = ConfigParser.ConfigParser() | 4882 | Config = ConfigParser.ConfigParser() |
4853 | 4883 | ||
4854 | ignorekprobes = False | ||
4855 | Config.read(file) | 4884 | Config.read(file) |
4856 | sections = Config.sections() | 4885 | sections = Config.sections() |
4886 | overridekprobes = False | ||
4887 | overridedevkprobes = False | ||
4857 | if 'Settings' in sections: | 4888 | if 'Settings' in sections: |
4858 | for opt in Config.options('Settings'): | 4889 | for opt in Config.options('Settings'): |
4859 | value = Config.get('Settings', opt).lower() | 4890 | value = Config.get('Settings', opt).lower() |
@@ -4865,19 +4896,15 @@ def configFromFile(file): | |||
4865 | sysvals.usedevsrc = checkArgBool(value) | 4896 | sysvals.usedevsrc = checkArgBool(value) |
4866 | elif(opt.lower() == 'proc'): | 4897 | elif(opt.lower() == 'proc'): |
4867 | sysvals.useprocmon = checkArgBool(value) | 4898 | sysvals.useprocmon = checkArgBool(value) |
4868 | elif(opt.lower() == 'ignorekprobes'): | ||
4869 | ignorekprobes = checkArgBool(value) | ||
4870 | elif(opt.lower() == 'x2'): | 4899 | elif(opt.lower() == 'x2'): |
4871 | if checkArgBool(value): | 4900 | if checkArgBool(value): |
4872 | sysvals.execcount = 2 | 4901 | sysvals.execcount = 2 |
4873 | elif(opt.lower() == 'callgraph'): | 4902 | elif(opt.lower() == 'callgraph'): |
4874 | sysvals.usecallgraph = checkArgBool(value) | 4903 | sysvals.usecallgraph = checkArgBool(value) |
4875 | elif(opt.lower() == 'callgraphfunc'): | 4904 | elif(opt.lower() == 'override-timeline-functions'): |
4876 | sysvals.debugfuncs = [] | 4905 | overridekprobes = checkArgBool(value) |
4877 | if value: | 4906 | elif(opt.lower() == 'override-dev-timeline-functions'): |
4878 | value = value.split(',') | 4907 | overridedevkprobes = checkArgBool(value) |
4879 | for i in value: | ||
4880 | sysvals.debugfuncs.append(i.strip()) | ||
4881 | elif(opt.lower() == 'devicefilter'): | 4908 | elif(opt.lower() == 'devicefilter'): |
4882 | sysvals.setDeviceFilter(value) | 4909 | sysvals.setDeviceFilter(value) |
4883 | elif(opt.lower() == 'expandcg'): | 4910 | elif(opt.lower() == 'expandcg'): |
@@ -4902,20 +4929,12 @@ def configFromFile(file): | |||
4902 | sysvals.setPrecision(getArgInt('-timeprec', value, 0, 6, False)) | 4929 | sysvals.setPrecision(getArgInt('-timeprec', value, 0, 6, False)) |
4903 | elif(opt.lower() == 'mindev'): | 4930 | elif(opt.lower() == 'mindev'): |
4904 | sysvals.mindevlen = getArgFloat('-mindev', value, 0.0, 10000.0, False) | 4931 | sysvals.mindevlen = getArgFloat('-mindev', value, 0.0, 10000.0, False) |
4932 | elif(opt.lower() == 'callloop-maxgap'): | ||
4933 | sysvals.callloopmaxgap = getArgFloat('-callloop-maxgap', value, 0.0, 1.0, False) | ||
4934 | elif(opt.lower() == 'callloop-maxlen'): | ||
4935 | sysvals.callloopmaxgap = getArgFloat('-callloop-maxlen', value, 0.0, 1.0, False) | ||
4905 | elif(opt.lower() == 'mincg'): | 4936 | elif(opt.lower() == 'mincg'): |
4906 | sysvals.mincglen = getArgFloat('-mincg', value, 0.0, 10000.0, False) | 4937 | sysvals.mincglen = getArgFloat('-mincg', value, 0.0, 10000.0, False) |
4907 | elif(opt.lower() == 'kprobecolor'): | ||
4908 | try: | ||
4909 | val = int(value, 16) | ||
4910 | sysvals.kprobecolor = '#'+value | ||
4911 | except: | ||
4912 | sysvals.kprobecolor = value | ||
4913 | elif(opt.lower() == 'synccolor'): | ||
4914 | try: | ||
4915 | val = int(value, 16) | ||
4916 | sysvals.synccolor = '#'+value | ||
4917 | except: | ||
4918 | sysvals.synccolor = value | ||
4919 | elif(opt.lower() == 'output-dir'): | 4938 | elif(opt.lower() == 'output-dir'): |
4920 | sysvals.setOutputFolder(value) | 4939 | sysvals.setOutputFolder(value) |
4921 | 4940 | ||
@@ -4930,24 +4949,32 @@ def configFromFile(file): | |||
4930 | if sysvals.usecallgraph and sysvals.useprocmon: | 4949 | if sysvals.usecallgraph and sysvals.useprocmon: |
4931 | doError('-proc is not compatible with -f', False) | 4950 | doError('-proc is not compatible with -f', False) |
4932 | 4951 | ||
4933 | if ignorekprobes: | 4952 | if overridekprobes: |
4934 | return | 4953 | sysvals.tracefuncs = dict() |
4954 | if overridedevkprobes: | ||
4955 | sysvals.dev_tracefuncs = dict() | ||
4935 | 4956 | ||
4936 | kprobes = dict() | 4957 | kprobes = dict() |
4937 | archkprobe = 'Kprobe_'+platform.machine() | 4958 | kprobesec = 'dev_timeline_functions_'+platform.machine() |
4938 | if archkprobe in sections: | 4959 | if kprobesec in sections: |
4939 | for name in Config.options(archkprobe): | 4960 | for name in Config.options(kprobesec): |
4940 | kprobes[name] = Config.get(archkprobe, name) | 4961 | text = Config.get(kprobesec, name) |
4941 | if 'Kprobe' in sections: | 4962 | kprobes[name] = (text, True) |
4942 | for name in Config.options('Kprobe'): | 4963 | kprobesec = 'timeline_functions_'+platform.machine() |
4943 | kprobes[name] = Config.get('Kprobe', name) | 4964 | if kprobesec in sections: |
4965 | for name in Config.options(kprobesec): | ||
4966 | if name in kprobes: | ||
4967 | doError('Duplicate timeline function found "%s"' % (name), False) | ||
4968 | text = Config.get(kprobesec, name) | ||
4969 | kprobes[name] = (text, False) | ||
4944 | 4970 | ||
4945 | for name in kprobes: | 4971 | for name in kprobes: |
4946 | function = name | 4972 | function = name |
4947 | format = name | 4973 | format = name |
4948 | color = '' | 4974 | color = '' |
4949 | args = dict() | 4975 | args = dict() |
4950 | data = kprobes[name].split() | 4976 | text, dev = kprobes[name] |
4977 | data = text.split() | ||
4951 | i = 0 | 4978 | i = 0 |
4952 | for val in data: | 4979 | for val in data: |
4953 | # bracketted strings are special formatting, read them separately | 4980 | # bracketted strings are special formatting, read them separately |
@@ -4974,17 +5001,21 @@ def configFromFile(file): | |||
4974 | for arg in re.findall('{(?P<n>[a-z,A-Z,0-9]*)}', format): | 5001 | for arg in re.findall('{(?P<n>[a-z,A-Z,0-9]*)}', format): |
4975 | if arg not in args: | 5002 | if arg not in args: |
4976 | doError('Kprobe "%s" is missing argument "%s"' % (name, arg), False) | 5003 | doError('Kprobe "%s" is missing argument "%s"' % (name, arg), False) |
4977 | if name in sysvals.kprobes: | 5004 | if (dev and name in sysvals.dev_tracefuncs) or (not dev and name in sysvals.tracefuncs): |
4978 | doError('Duplicate kprobe found "%s"' % (name), False) | 5005 | doError('Duplicate timeline function found "%s"' % (name), False) |
4979 | vprint('Adding KPROBE: %s %s %s %s' % (name, function, format, args)) | 5006 | |
4980 | sysvals.kprobes[name] = { | 5007 | kp = { |
4981 | 'name': name, | 5008 | 'name': name, |
4982 | 'func': function, | 5009 | 'func': function, |
4983 | 'format': format, | 5010 | 'format': format, |
4984 | 'args': args | 5011 | sysvals.archargs: args |
4985 | } | 5012 | } |
4986 | if color: | 5013 | if color: |
4987 | sysvals.kprobes[name]['color'] = color | 5014 | kp['color'] = color |
5015 | if dev: | ||
5016 | sysvals.dev_tracefuncs[name] = kp | ||
5017 | else: | ||
5018 | sysvals.tracefuncs[name] = kp | ||
4988 | 5019 | ||
4989 | # Function: printHelp | 5020 | # Function: printHelp |
4990 | # Description: | 5021 | # Description: |
@@ -5108,6 +5139,10 @@ if __name__ == '__main__': | |||
5108 | sysvals.mindevlen = getArgFloat('-mindev', args, 0.0, 10000.0) | 5139 | sysvals.mindevlen = getArgFloat('-mindev', args, 0.0, 10000.0) |
5109 | elif(arg == '-mincg'): | 5140 | elif(arg == '-mincg'): |
5110 | sysvals.mincglen = getArgFloat('-mincg', args, 0.0, 10000.0) | 5141 | sysvals.mincglen = getArgFloat('-mincg', args, 0.0, 10000.0) |
5142 | elif(arg == '-callloop-maxgap'): | ||
5143 | sysvals.callloopmaxgap = getArgFloat('-callloop-maxgap', args, 0.0, 1.0) | ||
5144 | elif(arg == '-callloop-maxlen'): | ||
5145 | sysvals.callloopmaxlen = getArgFloat('-callloop-maxlen', args, 0.0, 1.0) | ||
5111 | elif(arg == '-cmd'): | 5146 | elif(arg == '-cmd'): |
5112 | try: | 5147 | try: |
5113 | val = args.next() | 5148 | val = args.next() |