treewide: Replace GPLv2 boilerplate/reference with SPDX - rule 288
[linux-block.git] / tools / power / pm-graph / sleepgraph.py
1 #!/usr/bin/python2
2 # SPDX-License-Identifier: GPL-2.0-only
3 #
4 # Tool for analyzing suspend/resume timing
5 # Copyright (c) 2013, Intel Corporation.
6 #
7 # Authors:
8 #        Todd Brandt <todd.e.brandt@linux.intel.com>
9 #
10 # Links:
11 #        Home Page
12 #          https://01.org/suspendresume
13 #        Source repo
14 #          git@github.com:01org/pm-graph
15 #
16 # Description:
17 #        This tool is designed to assist kernel and OS developers in optimizing
18 #        their linux stack's suspend/resume time. Using a kernel image built
19 #        with a few extra options enabled, the tool will execute a suspend and
20 #        will capture dmesg and ftrace data until resume is complete. This data
21 #        is transformed into a device timeline and a callgraph to give a quick
22 #        and detailed view of which devices and callbacks are taking the most
23 #        time in suspend/resume. The output is a single html file which can be
24 #        viewed in firefox or chrome.
25 #
26 #        The following kernel build options are required:
27 #                CONFIG_PM_DEBUG=y
28 #                CONFIG_PM_SLEEP_DEBUG=y
29 #                CONFIG_FTRACE=y
30 #                CONFIG_FUNCTION_TRACER=y
31 #                CONFIG_FUNCTION_GRAPH_TRACER=y
32 #                CONFIG_KPROBES=y
33 #                CONFIG_KPROBES_ON_FTRACE=y
34 #
35 #        For kernel versions older than 3.15:
36 #        The following additional kernel parameters are required:
37 #                (e.g. in file /etc/default/grub)
38 #                GRUB_CMDLINE_LINUX_DEFAULT="... initcall_debug log_buf_len=16M ..."
39 #
40
41 # ----------------- LIBRARIES --------------------
42
43 import sys
44 import time
45 import os
46 import string
47 import re
48 import platform
49 import signal
50 from datetime import datetime
51 import struct
52 import ConfigParser
53 import gzip
54 from threading import Thread
55 from subprocess import call, Popen, PIPE
56
57 def pprint(msg):
58         print(msg)
59         sys.stdout.flush()
60
61 # ----------------- CLASSES --------------------
62
63 # Class: SystemValues
64 # Description:
65 #        A global, single-instance container used to
66 #        store system values and test parameters
67 class SystemValues:
68         title = 'SleepGraph'
69         version = '5.2'
70         ansi = False
71         rs = 0
72         display = ''
73         gzip = False
74         sync = False
75         verbose = False
76         testlog = True
77         dmesglog = False
78         ftracelog = False
79         mindevlen = 0.0
80         mincglen = 0.0
81         cgphase = ''
82         cgtest = -1
83         cgskip = ''
84         multitest = {'run': False, 'count': 0, 'delay': 0}
85         max_graph_depth = 0
86         callloopmaxgap = 0.0001
87         callloopmaxlen = 0.005
88         bufsize = 0
89         cpucount = 0
90         memtotal = 204800
91         memfree = 204800
92         srgap = 0
93         cgexp = False
94         testdir = ''
95         outdir = ''
96         tpath = '/sys/kernel/debug/tracing/'
97         fpdtpath = '/sys/firmware/acpi/tables/FPDT'
98         epath = '/sys/kernel/debug/tracing/events/power/'
99         pmdpath = '/sys/power/pm_debug_messages'
100         traceevents = [
101                 'suspend_resume',
102                 'device_pm_callback_end',
103                 'device_pm_callback_start'
104         ]
105         logmsg = ''
106         testcommand = ''
107         mempath = '/dev/mem'
108         powerfile = '/sys/power/state'
109         mempowerfile = '/sys/power/mem_sleep'
110         diskpowerfile = '/sys/power/disk'
111         suspendmode = 'mem'
112         memmode = ''
113         diskmode = ''
114         hostname = 'localhost'
115         prefix = 'test'
116         teststamp = ''
117         sysstamp = ''
118         dmesgstart = 0.0
119         dmesgfile = ''
120         ftracefile = ''
121         htmlfile = 'output.html'
122         result = ''
123         rtcwake = True
124         rtcwaketime = 15
125         rtcpath = ''
126         devicefilter = []
127         cgfilter = []
128         stamp = 0
129         execcount = 1
130         x2delay = 0
131         skiphtml = False
132         usecallgraph = False
133         usetraceevents = False
134         usetracemarkers = True
135         usekprobes = True
136         usedevsrc = False
137         useprocmon = False
138         notestrun = False
139         cgdump = False
140         devdump = False
141         mixedphaseheight = True
142         devprops = dict()
143         predelay = 0
144         postdelay = 0
145         pmdebug = ''
146         tracefuncs = {
147                 'sys_sync': {},
148                 'ksys_sync': {},
149                 '__pm_notifier_call_chain': {},
150                 'pm_prepare_console': {},
151                 'pm_notifier_call_chain': {},
152                 'freeze_processes': {},
153                 'freeze_kernel_threads': {},
154                 'pm_restrict_gfp_mask': {},
155                 'acpi_suspend_begin': {},
156                 'acpi_hibernation_begin': {},
157                 'acpi_hibernation_enter': {},
158                 'acpi_hibernation_leave': {},
159                 'acpi_pm_freeze': {},
160                 'acpi_pm_thaw': {},
161                 'hibernate_preallocate_memory': {},
162                 'create_basic_memory_bitmaps': {},
163                 'swsusp_write': {},
164                 'suspend_console': {},
165                 'acpi_pm_prepare': {},
166                 'syscore_suspend': {},
167                 'arch_enable_nonboot_cpus_end': {},
168                 'syscore_resume': {},
169                 'acpi_pm_finish': {},
170                 'resume_console': {},
171                 'acpi_pm_end': {},
172                 'pm_restore_gfp_mask': {},
173                 'thaw_processes': {},
174                 'pm_restore_console': {},
175                 'CPU_OFF': {
176                         'func':'_cpu_down',
177                         'args_x86_64': {'cpu':'%di:s32'},
178                         'format': 'CPU_OFF[{cpu}]'
179                 },
180                 'CPU_ON': {
181                         'func':'_cpu_up',
182                         'args_x86_64': {'cpu':'%di:s32'},
183                         'format': 'CPU_ON[{cpu}]'
184                 },
185         }
186         dev_tracefuncs = {
187                 # general wait/delay/sleep
188                 'msleep': { 'args_x86_64': {'time':'%di:s32'}, 'ub': 1 },
189                 'schedule_timeout': { 'args_x86_64': {'timeout':'%di:s32'}, 'ub': 1 },
190                 'udelay': { 'func':'__const_udelay', 'args_x86_64': {'loops':'%di:s32'}, 'ub': 1 },
191                 'usleep_range': { 'args_x86_64': {'min':'%di:s32', 'max':'%si:s32'}, 'ub': 1 },
192                 'mutex_lock_slowpath': { 'func':'__mutex_lock_slowpath', 'ub': 1 },
193                 'acpi_os_stall': {'ub': 1},
194                 # ACPI
195                 'acpi_resume_power_resources': {},
196                 'acpi_ps_parse_aml': {},
197                 # filesystem
198                 'ext4_sync_fs': {},
199                 # 80211
200                 'ath10k_bmi_read_memory': { 'args_x86_64': {'length':'%cx:s32'} },
201                 'ath10k_bmi_write_memory': { 'args_x86_64': {'length':'%cx:s32'} },
202                 'ath10k_bmi_fast_download': { 'args_x86_64': {'length':'%cx:s32'} },
203                 'iwlagn_mac_start': {},
204                 'iwlagn_alloc_bcast_station': {},
205                 'iwl_trans_pcie_start_hw': {},
206                 'iwl_trans_pcie_start_fw': {},
207                 'iwl_run_init_ucode': {},
208                 'iwl_load_ucode_wait_alive': {},
209                 'iwl_alive_start': {},
210                 'iwlagn_mac_stop': {},
211                 'iwlagn_mac_suspend': {},
212                 'iwlagn_mac_resume': {},
213                 'iwlagn_mac_add_interface': {},
214                 'iwlagn_mac_remove_interface': {},
215                 'iwlagn_mac_change_interface': {},
216                 'iwlagn_mac_config': {},
217                 'iwlagn_configure_filter': {},
218                 'iwlagn_mac_hw_scan': {},
219                 'iwlagn_bss_info_changed': {},
220                 'iwlagn_mac_channel_switch': {},
221                 'iwlagn_mac_flush': {},
222                 # ATA
223                 'ata_eh_recover': { 'args_x86_64': {'port':'+36(%di):s32'} },
224                 # i915
225                 'i915_gem_resume': {},
226                 'i915_restore_state': {},
227                 'intel_opregion_setup': {},
228                 'g4x_pre_enable_dp': {},
229                 'vlv_pre_enable_dp': {},
230                 'chv_pre_enable_dp': {},
231                 'g4x_enable_dp': {},
232                 'vlv_enable_dp': {},
233                 'intel_hpd_init': {},
234                 'intel_opregion_register': {},
235                 'intel_dp_detect': {},
236                 'intel_hdmi_detect': {},
237                 'intel_opregion_init': {},
238                 'intel_fbdev_set_suspend': {},
239         }
240         cgblacklist = []
241         kprobes = dict()
242         timeformat = '%.3f'
243         cmdline = '%s %s' % \
244                         (os.path.basename(sys.argv[0]), ' '.join(sys.argv[1:]))
245         sudouser = ''
246         def __init__(self):
247                 self.archargs = 'args_'+platform.machine()
248                 self.hostname = platform.node()
249                 if(self.hostname == ''):
250                         self.hostname = 'localhost'
251                 rtc = "rtc0"
252                 if os.path.exists('/dev/rtc'):
253                         rtc = os.readlink('/dev/rtc')
254                 rtc = '/sys/class/rtc/'+rtc
255                 if os.path.exists(rtc) and os.path.exists(rtc+'/date') and \
256                         os.path.exists(rtc+'/time') and os.path.exists(rtc+'/wakealarm'):
257                         self.rtcpath = rtc
258                 if (hasattr(sys.stdout, 'isatty') and sys.stdout.isatty()):
259                         self.ansi = True
260                 self.testdir = datetime.now().strftime('suspend-%y%m%d-%H%M%S')
261                 if os.getuid() == 0 and 'SUDO_USER' in os.environ and \
262                         os.environ['SUDO_USER']:
263                         self.sudouser = os.environ['SUDO_USER']
264         def vprint(self, msg):
265                 self.logmsg += msg+'\n'
266                 if self.verbose or msg.startswith('WARNING:'):
267                         pprint(msg)
268         def signalHandler(self, signum, frame):
269                 if not self.result:
270                         return
271                 signame = self.signames[signum] if signum in self.signames else 'UNKNOWN'
272                 msg = 'Signal %s caused a tool exit, line %d' % (signame, frame.f_lineno)
273                 sysvals.outputResult({'error':msg})
274                 sys.exit(3)
275         def signalHandlerInit(self):
276                 capture = ['BUS', 'SYS', 'XCPU', 'XFSZ', 'PWR', 'HUP', 'INT', 'QUIT',
277                         'ILL', 'ABRT', 'FPE', 'SEGV', 'TERM', 'TSTP']
278                 self.signames = dict()
279                 for i in capture:
280                         s = 'SIG'+i
281                         try:
282                                 signum = getattr(signal, s)
283                                 signal.signal(signum, self.signalHandler)
284                         except:
285                                 continue
286                         self.signames[signum] = s
287         def rootCheck(self, fatal=True):
288                 if(os.access(self.powerfile, os.W_OK)):
289                         return True
290                 if fatal:
291                         msg = 'This command requires sysfs mount and root access'
292                         pprint('ERROR: %s\n' % msg)
293                         self.outputResult({'error':msg})
294                         sys.exit(1)
295                 return False
296         def rootUser(self, fatal=False):
297                 if 'USER' in os.environ and os.environ['USER'] == 'root':
298                         return True
299                 if fatal:
300                         msg = 'This command must be run as root'
301                         pprint('ERROR: %s\n' % msg)
302                         self.outputResult({'error':msg})
303                         sys.exit(1)
304                 return False
305         def getExec(self, cmd):
306                 dirlist = ['/sbin', '/bin', '/usr/sbin', '/usr/bin',
307                         '/usr/local/sbin', '/usr/local/bin']
308                 for path in dirlist:
309                         cmdfull = os.path.join(path, cmd)
310                         if os.path.exists(cmdfull):
311                                 return cmdfull
312                 return ''
313         def setPrecision(self, num):
314                 if num < 0 or num > 6:
315                         return
316                 self.timeformat = '%.{0}f'.format(num)
317         def setOutputFolder(self, value):
318                 args = dict()
319                 n = datetime.now()
320                 args['date'] = n.strftime('%y%m%d')
321                 args['time'] = n.strftime('%H%M%S')
322                 args['hostname'] = args['host'] = self.hostname
323                 return value.format(**args)
324         def setOutputFile(self):
325                 if self.dmesgfile != '':
326                         m = re.match('(?P<name>.*)_dmesg\.txt.*', self.dmesgfile)
327                         if(m):
328                                 self.htmlfile = m.group('name')+'.html'
329                 if self.ftracefile != '':
330                         m = re.match('(?P<name>.*)_ftrace\.txt.*', self.ftracefile)
331                         if(m):
332                                 self.htmlfile = m.group('name')+'.html'
333         def systemInfo(self, info):
334                 p = c = m = b = ''
335                 if 'baseboard-manufacturer' in info:
336                         m = info['baseboard-manufacturer']
337                 elif 'system-manufacturer' in info:
338                         m = info['system-manufacturer']
339                 if 'baseboard-product-name' in info:
340                         p = info['baseboard-product-name']
341                 elif 'system-product-name' in info:
342                         p = info['system-product-name']
343                 if 'processor-version' in info:
344                         c = info['processor-version']
345                 if 'bios-version' in info:
346                         b = info['bios-version']
347                 self.sysstamp = '# sysinfo | man:%s | plat:%s | cpu:%s | bios:%s | numcpu:%d | memsz:%d | memfr:%d' % \
348                         (m, p, c, b, self.cpucount, self.memtotal, self.memfree)
349         def printSystemInfo(self, fatal=False):
350                 self.rootCheck(True)
351                 out = dmidecode(self.mempath, fatal)
352                 if len(out) < 1:
353                         return
354                 fmt = '%-24s: %s'
355                 for name in sorted(out):
356                         print fmt % (name, out[name])
357                 print fmt % ('cpucount', ('%d' % self.cpucount))
358                 print fmt % ('memtotal', ('%d kB' % self.memtotal))
359                 print fmt % ('memfree', ('%d kB' % self.memfree))
360         def cpuInfo(self):
361                 self.cpucount = 0
362                 fp = open('/proc/cpuinfo', 'r')
363                 for line in fp:
364                         if re.match('^processor[ \t]*:[ \t]*[0-9]*', line):
365                                 self.cpucount += 1
366                 fp.close()
367                 fp = open('/proc/meminfo', 'r')
368                 for line in fp:
369                         m = re.match('^MemTotal:[ \t]*(?P<sz>[0-9]*) *kB', line)
370                         if m:
371                                 self.memtotal = int(m.group('sz'))
372                         m = re.match('^MemFree:[ \t]*(?P<sz>[0-9]*) *kB', line)
373                         if m:
374                                 self.memfree = int(m.group('sz'))
375                 fp.close()
376         def initTestOutput(self, name):
377                 self.prefix = self.hostname
378                 v = open('/proc/version', 'r').read().strip()
379                 kver = string.split(v)[2]
380                 fmt = name+'-%m%d%y-%H%M%S'
381                 testtime = datetime.now().strftime(fmt)
382                 self.teststamp = \
383                         '# '+testtime+' '+self.prefix+' '+self.suspendmode+' '+kver
384                 ext = ''
385                 if self.gzip:
386                         ext = '.gz'
387                 self.dmesgfile = \
388                         self.testdir+'/'+self.prefix+'_'+self.suspendmode+'_dmesg.txt'+ext
389                 self.ftracefile = \
390                         self.testdir+'/'+self.prefix+'_'+self.suspendmode+'_ftrace.txt'+ext
391                 self.htmlfile = \
392                         self.testdir+'/'+self.prefix+'_'+self.suspendmode+'.html'
393                 if not os.path.isdir(self.testdir):
394                         os.mkdir(self.testdir)
395         def getValueList(self, value):
396                 out = []
397                 for i in value.split(','):
398                         if i.strip():
399                                 out.append(i.strip())
400                 return out
401         def setDeviceFilter(self, value):
402                 self.devicefilter = self.getValueList(value)
403         def setCallgraphFilter(self, value):
404                 self.cgfilter = self.getValueList(value)
405         def setCallgraphBlacklist(self, file):
406                 self.cgblacklist = self.listFromFile(file)
407         def rtcWakeAlarmOn(self):
408                 call('echo 0 > '+self.rtcpath+'/wakealarm', shell=True)
409                 nowtime = open(self.rtcpath+'/since_epoch', 'r').read().strip()
410                 if nowtime:
411                         nowtime = int(nowtime)
412                 else:
413                         # if hardware time fails, use the software time
414                         nowtime = int(datetime.now().strftime('%s'))
415                 alarm = nowtime + self.rtcwaketime
416                 call('echo %d > %s/wakealarm' % (alarm, self.rtcpath), shell=True)
417         def rtcWakeAlarmOff(self):
418                 call('echo 0 > %s/wakealarm' % self.rtcpath, shell=True)
419         def initdmesg(self):
420                 # get the latest time stamp from the dmesg log
421                 fp = Popen('dmesg', stdout=PIPE).stdout
422                 ktime = '0'
423                 for line in fp:
424                         line = line.replace('\r\n', '')
425                         idx = line.find('[')
426                         if idx > 1:
427                                 line = line[idx:]
428                         m = re.match('[ \t]*(\[ *)(?P<ktime>[0-9\.]*)(\]) (?P<msg>.*)', line)
429                         if(m):
430                                 ktime = m.group('ktime')
431                 fp.close()
432                 self.dmesgstart = float(ktime)
433         def getdmesg(self, testdata):
434                 op = self.writeDatafileHeader(sysvals.dmesgfile, testdata)
435                 # store all new dmesg lines since initdmesg was called
436                 fp = Popen('dmesg', stdout=PIPE).stdout
437                 for line in fp:
438                         line = line.replace('\r\n', '')
439                         idx = line.find('[')
440                         if idx > 1:
441                                 line = line[idx:]
442                         m = re.match('[ \t]*(\[ *)(?P<ktime>[0-9\.]*)(\]) (?P<msg>.*)', line)
443                         if(not m):
444                                 continue
445                         ktime = float(m.group('ktime'))
446                         if ktime > self.dmesgstart:
447                                 op.write(line)
448                 fp.close()
449                 op.close()
450         def listFromFile(self, file):
451                 list = []
452                 fp = open(file)
453                 for i in fp.read().split('\n'):
454                         i = i.strip()
455                         if i and i[0] != '#':
456                                 list.append(i)
457                 fp.close()
458                 return list
459         def addFtraceFilterFunctions(self, file):
460                 for i in self.listFromFile(file):
461                         if len(i) < 2:
462                                 continue
463                         self.tracefuncs[i] = dict()
464         def getFtraceFilterFunctions(self, current):
465                 self.rootCheck(True)
466                 if not current:
467                         call('cat '+self.tpath+'available_filter_functions', shell=True)
468                         return
469                 master = self.listFromFile(self.tpath+'available_filter_functions')
470                 for i in self.tracefuncs:
471                         if 'func' in self.tracefuncs[i]:
472                                 i = self.tracefuncs[i]['func']
473                         if i in master:
474                                 print i
475                         else:
476                                 print self.colorText(i)
477         def setFtraceFilterFunctions(self, list):
478                 master = self.listFromFile(self.tpath+'available_filter_functions')
479                 flist = ''
480                 for i in list:
481                         if i not in master:
482                                 continue
483                         if ' [' in i:
484                                 flist += i.split(' ')[0]+'\n'
485                         else:
486                                 flist += i+'\n'
487                 fp = open(self.tpath+'set_graph_function', 'w')
488                 fp.write(flist)
489                 fp.close()
490         def basicKprobe(self, name):
491                 self.kprobes[name] = {'name': name,'func': name,'args': dict(),'format': name}
492         def defaultKprobe(self, name, kdata):
493                 k = kdata
494                 for field in ['name', 'format', 'func']:
495                         if field not in k:
496                                 k[field] = name
497                 if self.archargs in k:
498                         k['args'] = k[self.archargs]
499                 else:
500                         k['args'] = dict()
501                         k['format'] = name
502                 self.kprobes[name] = k
503         def kprobeColor(self, name):
504                 if name not in self.kprobes or 'color' not in self.kprobes[name]:
505                         return ''
506                 return self.kprobes[name]['color']
507         def kprobeDisplayName(self, name, dataraw):
508                 if name not in self.kprobes:
509                         self.basicKprobe(name)
510                 data = ''
511                 quote=0
512                 # first remvoe any spaces inside quotes, and the quotes
513                 for c in dataraw:
514                         if c == '"':
515                                 quote = (quote + 1) % 2
516                         if quote and c == ' ':
517                                 data += '_'
518                         elif c != '"':
519                                 data += c
520                 fmt, args = self.kprobes[name]['format'], self.kprobes[name]['args']
521                 arglist = dict()
522                 # now process the args
523                 for arg in sorted(args):
524                         arglist[arg] = ''
525                         m = re.match('.* '+arg+'=(?P<arg>.*) ', data);
526                         if m:
527                                 arglist[arg] = m.group('arg')
528                         else:
529                                 m = re.match('.* '+arg+'=(?P<arg>.*)', data);
530                                 if m:
531                                         arglist[arg] = m.group('arg')
532                 out = fmt.format(**arglist)
533                 out = out.replace(' ', '_').replace('"', '')
534                 return out
535         def kprobeText(self, kname, kprobe):
536                 name = fmt = func = kname
537                 args = dict()
538                 if 'name' in kprobe:
539                         name = kprobe['name']
540                 if 'format' in kprobe:
541                         fmt = kprobe['format']
542                 if 'func' in kprobe:
543                         func = kprobe['func']
544                 if self.archargs in kprobe:
545                         args = kprobe[self.archargs]
546                 if 'args' in kprobe:
547                         args = kprobe['args']
548                 if re.findall('{(?P<n>[a-z,A-Z,0-9]*)}', func):
549                         doError('Kprobe "%s" has format info in the function name "%s"' % (name, func))
550                 for arg in re.findall('{(?P<n>[a-z,A-Z,0-9]*)}', fmt):
551                         if arg not in args:
552                                 doError('Kprobe "%s" is missing argument "%s"' % (name, arg))
553                 val = 'p:%s_cal %s' % (name, func)
554                 for i in sorted(args):
555                         val += ' %s=%s' % (i, args[i])
556                 val += '\nr:%s_ret %s $retval\n' % (name, func)
557                 return val
558         def addKprobes(self, output=False):
559                 if len(self.kprobes) < 1:
560                         return
561                 if output:
562                         pprint('    kprobe functions in this kernel:')
563                 # first test each kprobe
564                 rejects = []
565                 # sort kprobes: trace, ub-dev, custom, dev
566                 kpl = [[], [], [], []]
567                 linesout = len(self.kprobes)
568                 for name in sorted(self.kprobes):
569                         res = self.colorText('YES', 32)
570                         if not self.testKprobe(name, self.kprobes[name]):
571                                 res = self.colorText('NO')
572                                 rejects.append(name)
573                         else:
574                                 if name in self.tracefuncs:
575                                         kpl[0].append(name)
576                                 elif name in self.dev_tracefuncs:
577                                         if 'ub' in self.dev_tracefuncs[name]:
578                                                 kpl[1].append(name)
579                                         else:
580                                                 kpl[3].append(name)
581                                 else:
582                                         kpl[2].append(name)
583                         if output:
584                                 pprint('         %s: %s' % (name, res))
585                 kplist = kpl[0] + kpl[1] + kpl[2] + kpl[3]
586                 # remove all failed ones from the list
587                 for name in rejects:
588                         self.kprobes.pop(name)
589                 # set the kprobes all at once
590                 self.fsetVal('', 'kprobe_events')
591                 kprobeevents = ''
592                 for kp in kplist:
593                         kprobeevents += self.kprobeText(kp, self.kprobes[kp])
594                 self.fsetVal(kprobeevents, 'kprobe_events')
595                 if output:
596                         check = self.fgetVal('kprobe_events')
597                         linesack = (len(check.split('\n')) - 1) / 2
598                         pprint('    kprobe functions enabled: %d/%d' % (linesack, linesout))
599                 self.fsetVal('1', 'events/kprobes/enable')
600         def testKprobe(self, kname, kprobe):
601                 self.fsetVal('0', 'events/kprobes/enable')
602                 kprobeevents = self.kprobeText(kname, kprobe)
603                 if not kprobeevents:
604                         return False
605                 try:
606                         self.fsetVal(kprobeevents, 'kprobe_events')
607                         check = self.fgetVal('kprobe_events')
608                 except:
609                         return False
610                 linesout = len(kprobeevents.split('\n'))
611                 linesack = len(check.split('\n'))
612                 if linesack < linesout:
613                         return False
614                 return True
615         def setVal(self, val, file, mode='w'):
616                 if not os.path.exists(file):
617                         return False
618                 try:
619                         fp = open(file, mode, 0)
620                         fp.write(val)
621                         fp.flush()
622                         fp.close()
623                 except:
624                         return False
625                 return True
626         def fsetVal(self, val, path, mode='w'):
627                 return self.setVal(val, self.tpath+path, mode)
628         def getVal(self, file):
629                 res = ''
630                 if not os.path.exists(file):
631                         return res
632                 try:
633                         fp = open(file, 'r')
634                         res = fp.read()
635                         fp.close()
636                 except:
637                         pass
638                 return res
639         def fgetVal(self, path):
640                 return self.getVal(self.tpath+path)
641         def cleanupFtrace(self):
642                 if(self.usecallgraph or self.usetraceevents or self.usedevsrc):
643                         self.fsetVal('0', 'events/kprobes/enable')
644                         self.fsetVal('', 'kprobe_events')
645                         self.fsetVal('1024', 'buffer_size_kb')
646                 if self.pmdebug:
647                         self.setVal(self.pmdebug, self.pmdpath)
648         def setupAllKprobes(self):
649                 for name in self.tracefuncs:
650                         self.defaultKprobe(name, self.tracefuncs[name])
651                 for name in self.dev_tracefuncs:
652                         self.defaultKprobe(name, self.dev_tracefuncs[name])
653         def isCallgraphFunc(self, name):
654                 if len(self.tracefuncs) < 1 and self.suspendmode == 'command':
655                         return True
656                 for i in self.tracefuncs:
657                         if 'func' in self.tracefuncs[i]:
658                                 f = self.tracefuncs[i]['func']
659                         else:
660                                 f = i
661                         if name == f:
662                                 return True
663                 return False
664         def initFtrace(self):
665                 self.printSystemInfo(False)
666                 pprint('INITIALIZING FTRACE...')
667                 # turn trace off
668                 self.fsetVal('0', 'tracing_on')
669                 self.cleanupFtrace()
670                 # pm debug messages
671                 pv = self.getVal(self.pmdpath)
672                 if pv != '1':
673                         self.setVal('1', self.pmdpath)
674                         self.pmdebug = pv
675                 # set the trace clock to global
676                 self.fsetVal('global', 'trace_clock')
677                 self.fsetVal('nop', 'current_tracer')
678                 # set trace buffer to an appropriate value
679                 cpus = max(1, self.cpucount)
680                 if self.bufsize > 0:
681                         tgtsize = self.bufsize
682                 elif self.usecallgraph or self.usedevsrc:
683                         bmax = (1*1024*1024) if self.suspendmode == 'disk' else (3*1024*1024)
684                         tgtsize = min(self.memfree, bmax)
685                 else:
686                         tgtsize = 65536
687                 while not self.fsetVal('%d' % (tgtsize / cpus), 'buffer_size_kb'):
688                         # if the size failed to set, lower it and keep trying
689                         tgtsize -= 65536
690                         if tgtsize < 65536:
691                                 tgtsize = int(self.fgetVal('buffer_size_kb')) * cpus
692                                 break
693                 pprint('Setting trace buffers to %d kB (%d kB per cpu)' % (tgtsize, tgtsize/cpus))
694                 # initialize the callgraph trace
695                 if(self.usecallgraph):
696                         # set trace type
697                         self.fsetVal('function_graph', 'current_tracer')
698                         self.fsetVal('', 'set_ftrace_filter')
699                         # set trace format options
700                         self.fsetVal('print-parent', 'trace_options')
701                         self.fsetVal('funcgraph-abstime', 'trace_options')
702                         self.fsetVal('funcgraph-cpu', 'trace_options')
703                         self.fsetVal('funcgraph-duration', 'trace_options')
704                         self.fsetVal('funcgraph-proc', 'trace_options')
705                         self.fsetVal('funcgraph-tail', 'trace_options')
706                         self.fsetVal('nofuncgraph-overhead', 'trace_options')
707                         self.fsetVal('context-info', 'trace_options')
708                         self.fsetVal('graph-time', 'trace_options')
709                         self.fsetVal('%d' % self.max_graph_depth, 'max_graph_depth')
710                         cf = ['dpm_run_callback']
711                         if(self.usetraceevents):
712                                 cf += ['dpm_prepare', 'dpm_complete']
713                         for fn in self.tracefuncs:
714                                 if 'func' in self.tracefuncs[fn]:
715                                         cf.append(self.tracefuncs[fn]['func'])
716                                 else:
717                                         cf.append(fn)
718                         self.setFtraceFilterFunctions(cf)
719                 # initialize the kprobe trace
720                 elif self.usekprobes:
721                         for name in self.tracefuncs:
722                                 self.defaultKprobe(name, self.tracefuncs[name])
723                         if self.usedevsrc:
724                                 for name in self.dev_tracefuncs:
725                                         self.defaultKprobe(name, self.dev_tracefuncs[name])
726                         pprint('INITIALIZING KPROBES...')
727                         self.addKprobes(self.verbose)
728                 if(self.usetraceevents):
729                         # turn trace events on
730                         events = iter(self.traceevents)
731                         for e in events:
732                                 self.fsetVal('1', 'events/power/'+e+'/enable')
733                 # clear the trace buffer
734                 self.fsetVal('', 'trace')
735         def verifyFtrace(self):
736                 # files needed for any trace data
737                 files = ['buffer_size_kb', 'current_tracer', 'trace', 'trace_clock',
738                                  'trace_marker', 'trace_options', 'tracing_on']
739                 # files needed for callgraph trace data
740                 tp = self.tpath
741                 if(self.usecallgraph):
742                         files += [
743                                 'available_filter_functions',
744                                 'set_ftrace_filter',
745                                 'set_graph_function'
746                         ]
747                 for f in files:
748                         if(os.path.exists(tp+f) == False):
749                                 return False
750                 return True
751         def verifyKprobes(self):
752                 # files needed for kprobes to work
753                 files = ['kprobe_events', 'events']
754                 tp = self.tpath
755                 for f in files:
756                         if(os.path.exists(tp+f) == False):
757                                 return False
758                 return True
759         def colorText(self, str, color=31):
760                 if not self.ansi:
761                         return str
762                 return '\x1B[%d;40m%s\x1B[m' % (color, str)
763         def writeDatafileHeader(self, filename, testdata):
764                 fp = self.openlog(filename, 'w')
765                 fp.write('%s\n%s\n# command | %s\n' % (self.teststamp, self.sysstamp, self.cmdline))
766                 for test in testdata:
767                         if 'fw' in test:
768                                 fw = test['fw']
769                                 if(fw):
770                                         fp.write('# fwsuspend %u fwresume %u\n' % (fw[0], fw[1]))
771                         if 'bat' in test:
772                                 (a1, c1), (a2, c2) = test['bat']
773                                 fp.write('# battery %s %d %s %d\n' % (a1, c1, a2, c2))
774                         if test['error'] or len(testdata) > 1:
775                                 fp.write('# enter_sleep_error %s\n' % test['error'])
776                 return fp
777         def sudoUserchown(self, dir):
778                 if os.path.exists(dir) and self.sudouser:
779                         cmd = 'chown -R {0}:{0} {1} > /dev/null 2>&1'
780                         call(cmd.format(self.sudouser, dir), shell=True)
781         def outputResult(self, testdata, num=0):
782                 if not self.result:
783                         return
784                 n = ''
785                 if num > 0:
786                         n = '%d' % num
787                 fp = open(self.result, 'a')
788                 if 'error' in testdata:
789                         fp.write('result%s: fail\n' % n)
790                         fp.write('error%s: %s\n' % (n, testdata['error']))
791                 else:
792                         fp.write('result%s: pass\n' % n)
793                 for v in ['suspend', 'resume', 'boot', 'lastinit']:
794                         if v in testdata:
795                                 fp.write('%s%s: %.3f\n' % (v, n, testdata[v]))
796                 for v in ['fwsuspend', 'fwresume']:
797                         if v in testdata:
798                                 fp.write('%s%s: %.3f\n' % (v, n, testdata[v] / 1000000.0))
799                 if 'bugurl' in testdata:
800                         fp.write('url%s: %s\n' % (n, testdata['bugurl']))
801                 fp.close()
802                 self.sudoUserchown(self.result)
803         def configFile(self, file):
804                 dir = os.path.dirname(os.path.realpath(__file__))
805                 if os.path.exists(file):
806                         return file
807                 elif os.path.exists(dir+'/'+file):
808                         return dir+'/'+file
809                 elif os.path.exists(dir+'/config/'+file):
810                         return dir+'/config/'+file
811                 return ''
812         def openlog(self, filename, mode):
813                 isgz = self.gzip
814                 if mode == 'r':
815                         try:
816                                 with gzip.open(filename, mode+'b') as fp:
817                                         test = fp.read(64)
818                                 isgz = True
819                         except:
820                                 isgz = False
821                 if isgz:
822                         return gzip.open(filename, mode+'b')
823                 return open(filename, mode)
824
825 sysvals = SystemValues()
826 switchvalues = ['enable', 'disable', 'on', 'off', 'true', 'false', '1', '0']
827 switchoff = ['disable', 'off', 'false', '0']
828 suspendmodename = {
829         'freeze': 'Freeze (S0)',
830         'standby': 'Standby (S1)',
831         'mem': 'Suspend (S3)',
832         'disk': 'Hibernate (S4)'
833 }
834
835 # Class: DevProps
836 # Description:
837 #        Simple class which holds property values collected
838 #        for all the devices used in the timeline.
839 class DevProps:
840         def __init__(self):
841                 self.syspath = ''
842                 self.altname = ''
843                 self.async = True
844                 self.xtraclass = ''
845                 self.xtrainfo = ''
846         def out(self, dev):
847                 return '%s,%s,%d;' % (dev, self.altname, self.async)
848         def debug(self, dev):
849                 pprint('%s:\n\taltname = %s\n\t  async = %s' % (dev, self.altname, self.async))
850         def altName(self, dev):
851                 if not self.altname or self.altname == dev:
852                         return dev
853                 return '%s [%s]' % (self.altname, dev)
854         def xtraClass(self):
855                 if self.xtraclass:
856                         return ' '+self.xtraclass
857                 if not self.async:
858                         return ' sync'
859                 return ''
860         def xtraInfo(self):
861                 if self.xtraclass:
862                         return ' '+self.xtraclass
863                 if self.async:
864                         return ' async_device'
865                 return ' sync_device'
866
867 # Class: DeviceNode
868 # Description:
869 #        A container used to create a device hierachy, with a single root node
870 #        and a tree of child nodes. Used by Data.deviceTopology()
871 class DeviceNode:
872         def __init__(self, nodename, nodedepth):
873                 self.name = nodename
874                 self.children = []
875                 self.depth = nodedepth
876
877 # Class: Data
878 # Description:
879 #        The primary container for suspend/resume test data. There is one for
880 #        each test run. The data is organized into a cronological hierarchy:
881 #        Data.dmesg {
882 #               phases {
883 #                       10 sequential, non-overlapping phases of S/R
884 #                       contents: times for phase start/end, order/color data for html
885 #                       devlist {
886 #                               device callback or action list for this phase
887 #                               device {
888 #                                       a single device callback or generic action
889 #                                       contents: start/stop times, pid/cpu/driver info
890 #                                               parents/children, html id for timeline/callgraph
891 #                                               optionally includes an ftrace callgraph
892 #                                               optionally includes dev/ps data
893 #                               }
894 #                       }
895 #               }
896 #       }
897 #
898 class Data:
899         phasedef = {
900                 'suspend_prepare': {'order': 0, 'color': '#CCFFCC'},
901                         'suspend': {'order': 1, 'color': '#88FF88'},
902                    'suspend_late': {'order': 2, 'color': '#00AA00'},
903                   'suspend_noirq': {'order': 3, 'color': '#008888'},
904                 'suspend_machine': {'order': 4, 'color': '#0000FF'},
905                  'resume_machine': {'order': 5, 'color': '#FF0000'},
906                    'resume_noirq': {'order': 6, 'color': '#FF9900'},
907                    'resume_early': {'order': 7, 'color': '#FFCC00'},
908                          'resume': {'order': 8, 'color': '#FFFF88'},
909                 'resume_complete': {'order': 9, 'color': '#FFFFCC'},
910         }
911         errlist = {
912                 'HWERROR' : '.*\[ *Hardware Error *\].*',
913                 'FWBUG'   : '.*\[ *Firmware Bug *\].*',
914                 'BUG'     : '.*BUG.*',
915                 'ERROR'   : '.*ERROR.*',
916                 'WARNING' : '.*WARNING.*',
917                 'IRQ'     : '.*genirq: .*',
918                 'TASKFAIL': '.*Freezing of tasks failed.*',
919         }
920         def __init__(self, num):
921                 idchar = 'abcdefghij'
922                 self.start = 0.0 # test start
923                 self.end = 0.0   # test end
924                 self.tSuspended = 0.0 # low-level suspend start
925                 self.tResumed = 0.0   # low-level resume start
926                 self.tKernSus = 0.0   # kernel level suspend start
927                 self.tKernRes = 0.0   # kernel level resume end
928                 self.fwValid = False  # is firmware data available
929                 self.fwSuspend = 0    # time spent in firmware suspend
930                 self.fwResume = 0     # time spent in firmware resume
931                 self.html_device_id = 0
932                 self.stamp = 0
933                 self.outfile = ''
934                 self.kerror = False
935                 self.battery = 0
936                 self.enterfail = ''
937                 self.currphase = ''
938                 self.pstl = dict()    # process timeline
939                 self.testnumber = num
940                 self.idstr = idchar[num]
941                 self.dmesgtext = []   # dmesg text file in memory
942                 self.dmesg = dict()   # root data structure
943                 self.errorinfo = {'suspend':[],'resume':[]}
944                 self.tLow = []        # time spent in low-level suspends (standby/freeze)
945                 self.devpids = []
946                 self.devicegroups = 0
947         def sortedPhases(self):
948                 return sorted(self.dmesg, key=lambda k:self.dmesg[k]['order'])
949         def initDevicegroups(self):
950                 # called when phases are all finished being added
951                 for phase in self.dmesg.keys():
952                         if '*' in phase:
953                                 p = phase.split('*')
954                                 pnew = '%s%d' % (p[0], len(p))
955                                 self.dmesg[pnew] = self.dmesg.pop(phase)
956                 self.devicegroups = []
957                 for phase in self.sortedPhases():
958                         self.devicegroups.append([phase])
959         def nextPhase(self, phase, offset):
960                 order = self.dmesg[phase]['order'] + offset
961                 for p in self.dmesg:
962                         if self.dmesg[p]['order'] == order:
963                                 return p
964                 return ''
965         def lastPhase(self):
966                 plist = self.sortedPhases()
967                 if len(plist) < 1:
968                         return ''
969                 return plist[-1]
970         def extractErrorInfo(self):
971                 lf = sysvals.openlog(sysvals.dmesgfile, 'r')
972                 i = 0
973                 list = []
974                 for line in lf:
975                         i += 1
976                         m = re.match('[ \t]*(\[ *)(?P<ktime>[0-9\.]*)(\]) (?P<msg>.*)', line)
977                         if not m:
978                                 continue
979                         t = float(m.group('ktime'))
980                         if t < self.start or t > self.end:
981                                 continue
982                         dir = 'suspend' if t < self.tSuspended else 'resume'
983                         msg = m.group('msg')
984                         for err in self.errlist:
985                                 if re.match(self.errlist[err], msg):
986                                         list.append((err, dir, t, i, i))
987                                         self.kerror = True
988                                         break
989                 for e in list:
990                         type, dir, t, idx1, idx2 = e
991                         sysvals.vprint('kernel %s found in %s at %f' % (type, dir, t))
992                         self.errorinfo[dir].append((type, t, idx1, idx2))
993                 if self.kerror:
994                         sysvals.dmesglog = True
995                 lf.close()
996         def setStart(self, time):
997                 self.start = time
998         def setEnd(self, time):
999                 self.end = time
1000         def isTraceEventOutsideDeviceCalls(self, pid, time):
1001                 for phase in self.sortedPhases():
1002                         list = self.dmesg[phase]['list']
1003                         for dev in list:
1004                                 d = list[dev]
1005                                 if(d['pid'] == pid and time >= d['start'] and
1006                                         time < d['end']):
1007                                         return False
1008                 return True
1009         def sourcePhase(self, start):
1010                 for phase in self.sortedPhases():
1011                         if 'machine' in phase:
1012                                 continue
1013                         pend = self.dmesg[phase]['end']
1014                         if start <= pend:
1015                                 return phase
1016                 return 'resume_complete'
1017         def sourceDevice(self, phaselist, start, end, pid, type):
1018                 tgtdev = ''
1019                 for phase in phaselist:
1020                         list = self.dmesg[phase]['list']
1021                         for devname in list:
1022                                 dev = list[devname]
1023                                 # pid must match
1024                                 if dev['pid'] != pid:
1025                                         continue
1026                                 devS = dev['start']
1027                                 devE = dev['end']
1028                                 if type == 'device':
1029                                         # device target event is entirely inside the source boundary
1030                                         if(start < devS or start >= devE or end <= devS or end > devE):
1031                                                 continue
1032                                 elif type == 'thread':
1033                                         # thread target event will expand the source boundary
1034                                         if start < devS:
1035                                                 dev['start'] = start
1036                                         if end > devE:
1037                                                 dev['end'] = end
1038                                 tgtdev = dev
1039                                 break
1040                 return tgtdev
1041         def addDeviceFunctionCall(self, displayname, kprobename, proc, pid, start, end, cdata, rdata):
1042                 # try to place the call in a device
1043                 phases = self.sortedPhases()
1044                 tgtdev = self.sourceDevice(phases, start, end, pid, 'device')
1045                 # calls with device pids that occur outside device bounds are dropped
1046                 # TODO: include these somehow
1047                 if not tgtdev and pid in self.devpids:
1048                         return False
1049                 # try to place the call in a thread
1050                 if not tgtdev:
1051                         tgtdev = self.sourceDevice(phases, start, end, pid, 'thread')
1052                 # create new thread blocks, expand as new calls are found
1053                 if not tgtdev:
1054                         if proc == '<...>':
1055                                 threadname = 'kthread-%d' % (pid)
1056                         else:
1057                                 threadname = '%s-%d' % (proc, pid)
1058                         tgtphase = self.sourcePhase(start)
1059                         self.newAction(tgtphase, threadname, pid, '', start, end, '', ' kth', '')
1060                         return self.addDeviceFunctionCall(displayname, kprobename, proc, pid, start, end, cdata, rdata)
1061                 # this should not happen
1062                 if not tgtdev:
1063                         sysvals.vprint('[%f - %f] %s-%d %s %s %s' % \
1064                                 (start, end, proc, pid, kprobename, cdata, rdata))
1065                         return False
1066                 # place the call data inside the src element of the tgtdev
1067                 if('src' not in tgtdev):
1068                         tgtdev['src'] = []
1069                 dtf = sysvals.dev_tracefuncs
1070                 ubiquitous = False
1071                 if kprobename in dtf and 'ub' in dtf[kprobename]:
1072                         ubiquitous = True
1073                 title = cdata+' '+rdata
1074                 mstr = '\(.*\) *(?P<args>.*) *\((?P<caller>.*)\+.* arg1=(?P<ret>.*)'
1075                 m = re.match(mstr, title)
1076                 if m:
1077                         c = m.group('caller')
1078                         a = m.group('args').strip()
1079                         r = m.group('ret')
1080                         if len(r) > 6:
1081                                 r = ''
1082                         else:
1083                                 r = 'ret=%s ' % r
1084                         if ubiquitous and c in dtf and 'ub' in dtf[c]:
1085                                 return False
1086                 color = sysvals.kprobeColor(kprobename)
1087                 e = DevFunction(displayname, a, c, r, start, end, ubiquitous, proc, pid, color)
1088                 tgtdev['src'].append(e)
1089                 return True
1090         def overflowDevices(self):
1091                 # get a list of devices that extend beyond the end of this test run
1092                 devlist = []
1093                 for phase in self.sortedPhases():
1094                         list = self.dmesg[phase]['list']
1095                         for devname in list:
1096                                 dev = list[devname]
1097                                 if dev['end'] > self.end:
1098                                         devlist.append(dev)
1099                 return devlist
1100         def mergeOverlapDevices(self, devlist):
1101                 # merge any devices that overlap devlist
1102                 for dev in devlist:
1103                         devname = dev['name']
1104                         for phase in self.sortedPhases():
1105                                 list = self.dmesg[phase]['list']
1106                                 if devname not in list:
1107                                         continue
1108                                 tdev = list[devname]
1109                                 o = min(dev['end'], tdev['end']) - max(dev['start'], tdev['start'])
1110                                 if o <= 0:
1111                                         continue
1112                                 dev['end'] = tdev['end']
1113                                 if 'src' not in dev or 'src' not in tdev:
1114                                         continue
1115                                 dev['src'] += tdev['src']
1116                                 del list[devname]
1117         def usurpTouchingThread(self, name, dev):
1118                 # the caller test has priority of this thread, give it to him
1119                 for phase in self.sortedPhases():
1120                         list = self.dmesg[phase]['list']
1121                         if name in list:
1122                                 tdev = list[name]
1123                                 if tdev['start'] - dev['end'] < 0.1:
1124                                         dev['end'] = tdev['end']
1125                                         if 'src' not in dev:
1126                                                 dev['src'] = []
1127                                         if 'src' in tdev:
1128                                                 dev['src'] += tdev['src']
1129                                         del list[name]
1130                                 break
1131         def stitchTouchingThreads(self, testlist):
1132                 # merge any threads between tests that touch
1133                 for phase in self.sortedPhases():
1134                         list = self.dmesg[phase]['list']
1135                         for devname in list:
1136                                 dev = list[devname]
1137                                 if 'htmlclass' not in dev or 'kth' not in dev['htmlclass']:
1138                                         continue
1139                                 for data in testlist:
1140                                         data.usurpTouchingThread(devname, dev)
1141         def optimizeDevSrc(self):
1142                 # merge any src call loops to reduce timeline size
1143                 for phase in self.sortedPhases():
1144                         list = self.dmesg[phase]['list']
1145                         for dev in list:
1146                                 if 'src' not in list[dev]:
1147                                         continue
1148                                 src = list[dev]['src']
1149                                 p = 0
1150                                 for e in sorted(src, key=lambda event: event.time):
1151                                         if not p or not e.repeat(p):
1152                                                 p = e
1153                                                 continue
1154                                         # e is another iteration of p, move it into p
1155                                         p.end = e.end
1156                                         p.length = p.end - p.time
1157                                         p.count += 1
1158                                         src.remove(e)
1159         def trimTimeVal(self, t, t0, dT, left):
1160                 if left:
1161                         if(t > t0):
1162                                 if(t - dT < t0):
1163                                         return t0
1164                                 return t - dT
1165                         else:
1166                                 return t
1167                 else:
1168                         if(t < t0 + dT):
1169                                 if(t > t0):
1170                                         return t0 + dT
1171                                 return t + dT
1172                         else:
1173                                 return t
1174         def trimTime(self, t0, dT, left):
1175                 self.tSuspended = self.trimTimeVal(self.tSuspended, t0, dT, left)
1176                 self.tResumed = self.trimTimeVal(self.tResumed, t0, dT, left)
1177                 self.start = self.trimTimeVal(self.start, t0, dT, left)
1178                 self.tKernSus = self.trimTimeVal(self.tKernSus, t0, dT, left)
1179                 self.tKernRes = self.trimTimeVal(self.tKernRes, t0, dT, left)
1180                 self.end = self.trimTimeVal(self.end, t0, dT, left)
1181                 for phase in self.sortedPhases():
1182                         p = self.dmesg[phase]
1183                         p['start'] = self.trimTimeVal(p['start'], t0, dT, left)
1184                         p['end'] = self.trimTimeVal(p['end'], t0, dT, left)
1185                         list = p['list']
1186                         for name in list:
1187                                 d = list[name]
1188                                 d['start'] = self.trimTimeVal(d['start'], t0, dT, left)
1189                                 d['end'] = self.trimTimeVal(d['end'], t0, dT, left)
1190                                 d['length'] = d['end'] - d['start']
1191                                 if('ftrace' in d):
1192                                         cg = d['ftrace']
1193                                         cg.start = self.trimTimeVal(cg.start, t0, dT, left)
1194                                         cg.end = self.trimTimeVal(cg.end, t0, dT, left)
1195                                         for line in cg.list:
1196                                                 line.time = self.trimTimeVal(line.time, t0, dT, left)
1197                                 if('src' in d):
1198                                         for e in d['src']:
1199                                                 e.time = self.trimTimeVal(e.time, t0, dT, left)
1200                 for dir in ['suspend', 'resume']:
1201                         list = []
1202                         for e in self.errorinfo[dir]:
1203                                 type, tm, idx1, idx2 = e
1204                                 tm = self.trimTimeVal(tm, t0, dT, left)
1205                                 list.append((type, tm, idx1, idx2))
1206                         self.errorinfo[dir] = list
1207         def trimFreezeTime(self, tZero):
1208                 # trim out any standby or freeze clock time
1209                 lp = ''
1210                 for phase in self.sortedPhases():
1211                         if 'resume_machine' in phase and 'suspend_machine' in lp:
1212                                 tS, tR = self.dmesg[lp]['end'], self.dmesg[phase]['start']
1213                                 tL = tR - tS
1214                                 if tL > 0:
1215                                         left = True if tR > tZero else False
1216                                         self.trimTime(tS, tL, left)
1217                                         self.tLow.append('%.0f'%(tL*1000))
1218                         lp = phase
1219         def getTimeValues(self):
1220                 sktime = (self.tSuspended - self.tKernSus) * 1000
1221                 rktime = (self.tKernRes - self.tResumed) * 1000
1222                 return (sktime, rktime)
1223         def setPhase(self, phase, ktime, isbegin, order=-1):
1224                 if(isbegin):
1225                         # phase start over current phase
1226                         if self.currphase:
1227                                 if 'resume_machine' not in self.currphase:
1228                                         sysvals.vprint('WARNING: phase %s failed to end' % self.currphase)
1229                                 self.dmesg[self.currphase]['end'] = ktime
1230                         phases = self.dmesg.keys()
1231                         color = self.phasedef[phase]['color']
1232                         count = len(phases) if order < 0 else order
1233                         # create unique name for every new phase
1234                         while phase in phases:
1235                                 phase += '*'
1236                         self.dmesg[phase] = {'list': dict(), 'start': -1.0, 'end': -1.0,
1237                                 'row': 0, 'color': color, 'order': count}
1238                         self.dmesg[phase]['start'] = ktime
1239                         self.currphase = phase
1240                 else:
1241                         # phase end without a start
1242                         if phase not in self.currphase:
1243                                 if self.currphase:
1244                                         sysvals.vprint('WARNING: %s ended instead of %s, ftrace corruption?' % (phase, self.currphase))
1245                                 else:
1246                                         sysvals.vprint('WARNING: %s ended without a start, ftrace corruption?' % phase)
1247                                         return phase
1248                         phase = self.currphase
1249                         self.dmesg[phase]['end'] = ktime
1250                         self.currphase = ''
1251                 return phase
1252         def sortedDevices(self, phase):
1253                 list = self.dmesg[phase]['list']
1254                 slist = []
1255                 tmp = dict()
1256                 for devname in list:
1257                         dev = list[devname]
1258                         if dev['length'] == 0:
1259                                 continue
1260                         tmp[dev['start']] = devname
1261                 for t in sorted(tmp):
1262                         slist.append(tmp[t])
1263                 return slist
1264         def fixupInitcalls(self, phase):
1265                 # if any calls never returned, clip them at system resume end
1266                 phaselist = self.dmesg[phase]['list']
1267                 for devname in phaselist:
1268                         dev = phaselist[devname]
1269                         if(dev['end'] < 0):
1270                                 for p in self.sortedPhases():
1271                                         if self.dmesg[p]['end'] > dev['start']:
1272                                                 dev['end'] = self.dmesg[p]['end']
1273                                                 break
1274                                 sysvals.vprint('%s (%s): callback didnt return' % (devname, phase))
1275         def deviceFilter(self, devicefilter):
1276                 for phase in self.sortedPhases():
1277                         list = self.dmesg[phase]['list']
1278                         rmlist = []
1279                         for name in list:
1280                                 keep = False
1281                                 for filter in devicefilter:
1282                                         if filter in name or \
1283                                                 ('drv' in list[name] and filter in list[name]['drv']):
1284                                                 keep = True
1285                                 if not keep:
1286                                         rmlist.append(name)
1287                         for name in rmlist:
1288                                 del list[name]
1289         def fixupInitcallsThatDidntReturn(self):
1290                 # if any calls never returned, clip them at system resume end
1291                 for phase in self.sortedPhases():
1292                         self.fixupInitcalls(phase)
1293         def phaseOverlap(self, phases):
1294                 rmgroups = []
1295                 newgroup = []
1296                 for group in self.devicegroups:
1297                         for phase in phases:
1298                                 if phase not in group:
1299                                         continue
1300                                 for p in group:
1301                                         if p not in newgroup:
1302                                                 newgroup.append(p)
1303                                 if group not in rmgroups:
1304                                         rmgroups.append(group)
1305                 for group in rmgroups:
1306                         self.devicegroups.remove(group)
1307                 self.devicegroups.append(newgroup)
1308         def newActionGlobal(self, name, start, end, pid=-1, color=''):
1309                 # which phase is this device callback or action in
1310                 phases = self.sortedPhases()
1311                 targetphase = 'none'
1312                 htmlclass = ''
1313                 overlap = 0.0
1314                 myphases = []
1315                 for phase in phases:
1316                         pstart = self.dmesg[phase]['start']
1317                         pend = self.dmesg[phase]['end']
1318                         # see if the action overlaps this phase
1319                         o = max(0, min(end, pend) - max(start, pstart))
1320                         if o > 0:
1321                                 myphases.append(phase)
1322                         # set the target phase to the one that overlaps most
1323                         if o > overlap:
1324                                 if overlap > 0 and phase == 'post_resume':
1325                                         continue
1326                                 targetphase = phase
1327                                 overlap = o
1328                 # if no target phase was found, pin it to the edge
1329                 if targetphase == 'none':
1330                         p0start = self.dmesg[phases[0]]['start']
1331                         if start <= p0start:
1332                                 targetphase = phases[0]
1333                         else:
1334                                 targetphase = phases[-1]
1335                 if pid == -2:
1336                         htmlclass = ' bg'
1337                 elif pid == -3:
1338                         htmlclass = ' ps'
1339                 if len(myphases) > 1:
1340                         htmlclass = ' bg'
1341                         self.phaseOverlap(myphases)
1342                 if targetphase in phases:
1343                         newname = self.newAction(targetphase, name, pid, '', start, end, '', htmlclass, color)
1344                         return (targetphase, newname)
1345                 return False
1346         def newAction(self, phase, name, pid, parent, start, end, drv, htmlclass='', color=''):
1347                 # new device callback for a specific phase
1348                 self.html_device_id += 1
1349                 devid = '%s%d' % (self.idstr, self.html_device_id)
1350                 list = self.dmesg[phase]['list']
1351                 length = -1.0
1352                 if(start >= 0 and end >= 0):
1353                         length = end - start
1354                 if pid == -2:
1355                         i = 2
1356                         origname = name
1357                         while(name in list):
1358                                 name = '%s[%d]' % (origname, i)
1359                                 i += 1
1360                 list[name] = {'name': name, 'start': start, 'end': end, 'pid': pid,
1361                         'par': parent, 'length': length, 'row': 0, 'id': devid, 'drv': drv }
1362                 if htmlclass:
1363                         list[name]['htmlclass'] = htmlclass
1364                 if color:
1365                         list[name]['color'] = color
1366                 return name
1367         def deviceChildren(self, devname, phase):
1368                 devlist = []
1369                 list = self.dmesg[phase]['list']
1370                 for child in list:
1371                         if(list[child]['par'] == devname):
1372                                 devlist.append(child)
1373                 return devlist
1374         def maxDeviceNameSize(self, phase):
1375                 size = 0
1376                 for name in self.dmesg[phase]['list']:
1377                         if len(name) > size:
1378                                 size = len(name)
1379                 return size
1380         def printDetails(self):
1381                 sysvals.vprint('Timeline Details:')
1382                 sysvals.vprint('          test start: %f' % self.start)
1383                 sysvals.vprint('kernel suspend start: %f' % self.tKernSus)
1384                 tS = tR = False
1385                 for phase in self.sortedPhases():
1386                         devlist = self.dmesg[phase]['list']
1387                         dc, ps, pe = len(devlist), self.dmesg[phase]['start'], self.dmesg[phase]['end']
1388                         if not tS and ps >= self.tSuspended:
1389                                 sysvals.vprint('   machine suspended: %f' % self.tSuspended)
1390                                 tS = True
1391                         if not tR and ps >= self.tResumed:
1392                                 sysvals.vprint('     machine resumed: %f' % self.tResumed)
1393                                 tR = True
1394                         sysvals.vprint('%20s: %f - %f (%d devices)' % (phase, ps, pe, dc))
1395                         if sysvals.devdump:
1396                                 sysvals.vprint(''.join('-' for i in range(80)))
1397                                 maxname = '%d' % self.maxDeviceNameSize(phase)
1398                                 fmt = '%3d) %'+maxname+'s - %f - %f'
1399                                 c = 1
1400                                 for name in devlist:
1401                                         s = devlist[name]['start']
1402                                         e = devlist[name]['end']
1403                                         sysvals.vprint(fmt % (c, name, s, e))
1404                                         c += 1
1405                                 sysvals.vprint(''.join('-' for i in range(80)))
1406                 sysvals.vprint('   kernel resume end: %f' % self.tKernRes)
1407                 sysvals.vprint('            test end: %f' % self.end)
1408         def deviceChildrenAllPhases(self, devname):
1409                 devlist = []
1410                 for phase in self.sortedPhases():
1411                         list = self.deviceChildren(devname, phase)
1412                         for dev in list:
1413                                 if dev not in devlist:
1414                                         devlist.append(dev)
1415                 return devlist
1416         def masterTopology(self, name, list, depth):
1417                 node = DeviceNode(name, depth)
1418                 for cname in list:
1419                         # avoid recursions
1420                         if name == cname:
1421                                 continue
1422                         clist = self.deviceChildrenAllPhases(cname)
1423                         cnode = self.masterTopology(cname, clist, depth+1)
1424                         node.children.append(cnode)
1425                 return node
1426         def printTopology(self, node):
1427                 html = ''
1428                 if node.name:
1429                         info = ''
1430                         drv = ''
1431                         for phase in self.sortedPhases():
1432                                 list = self.dmesg[phase]['list']
1433                                 if node.name in list:
1434                                         s = list[node.name]['start']
1435                                         e = list[node.name]['end']
1436                                         if list[node.name]['drv']:
1437                                                 drv = ' {'+list[node.name]['drv']+'}'
1438                                         info += ('<li>%s: %.3fms</li>' % (phase, (e-s)*1000))
1439                         html += '<li><b>'+node.name+drv+'</b>'
1440                         if info:
1441                                 html += '<ul>'+info+'</ul>'
1442                         html += '</li>'
1443                 if len(node.children) > 0:
1444                         html += '<ul>'
1445                         for cnode in node.children:
1446                                 html += self.printTopology(cnode)
1447                         html += '</ul>'
1448                 return html
1449         def rootDeviceList(self):
1450                 # list of devices graphed
1451                 real = []
1452                 for phase in self.dmesg:
1453                         list = self.dmesg[phase]['list']
1454                         for dev in list:
1455                                 if list[dev]['pid'] >= 0 and dev not in real:
1456                                         real.append(dev)
1457                 # list of top-most root devices
1458                 rootlist = []
1459                 for phase in self.dmesg:
1460                         list = self.dmesg[phase]['list']
1461                         for dev in list:
1462                                 pdev = list[dev]['par']
1463                                 pid = list[dev]['pid']
1464                                 if(pid < 0 or re.match('[0-9]*-[0-9]*\.[0-9]*[\.0-9]*\:[\.0-9]*$', pdev)):
1465                                         continue
1466                                 if pdev and pdev not in real and pdev not in rootlist:
1467                                         rootlist.append(pdev)
1468                 return rootlist
1469         def deviceTopology(self):
1470                 rootlist = self.rootDeviceList()
1471                 master = self.masterTopology('', rootlist, 0)
1472                 return self.printTopology(master)
1473         def selectTimelineDevices(self, widfmt, tTotal, mindevlen):
1474                 # only select devices that will actually show up in html
1475                 self.tdevlist = dict()
1476                 for phase in self.dmesg:
1477                         devlist = []
1478                         list = self.dmesg[phase]['list']
1479                         for dev in list:
1480                                 length = (list[dev]['end'] - list[dev]['start']) * 1000
1481                                 width = widfmt % (((list[dev]['end']-list[dev]['start'])*100)/tTotal)
1482                                 if width != '0.000000' and length >= mindevlen:
1483                                         devlist.append(dev)
1484                         self.tdevlist[phase] = devlist
1485         def addHorizontalDivider(self, devname, devend):
1486                 phase = 'suspend_prepare'
1487                 self.newAction(phase, devname, -2, '', \
1488                         self.start, devend, '', ' sec', '')
1489                 if phase not in self.tdevlist:
1490                         self.tdevlist[phase] = []
1491                 self.tdevlist[phase].append(devname)
1492                 d = DevItem(0, phase, self.dmesg[phase]['list'][devname])
1493                 return d
1494         def addProcessUsageEvent(self, name, times):
1495                 # get the start and end times for this process
1496                 maxC = 0
1497                 tlast = 0
1498                 start = -1
1499                 end = -1
1500                 for t in sorted(times):
1501                         if tlast == 0:
1502                                 tlast = t
1503                                 continue
1504                         if name in self.pstl[t]:
1505                                 if start == -1 or tlast < start:
1506                                         start = tlast
1507                                 if end == -1 or t > end:
1508                                         end = t
1509                         tlast = t
1510                 if start == -1 or end == -1:
1511                         return 0
1512                 # add a new action for this process and get the object
1513                 out = self.newActionGlobal(name, start, end, -3)
1514                 if not out:
1515                         return 0
1516                 phase, devname = out
1517                 dev = self.dmesg[phase]['list'][devname]
1518                 # get the cpu exec data
1519                 tlast = 0
1520                 clast = 0
1521                 cpuexec = dict()
1522                 for t in sorted(times):
1523                         if tlast == 0 or t <= start or t > end:
1524                                 tlast = t
1525                                 continue
1526                         list = self.pstl[t]
1527                         c = 0
1528                         if name in list:
1529                                 c = list[name]
1530                         if c > maxC:
1531                                 maxC = c
1532                         if c != clast:
1533                                 key = (tlast, t)
1534                                 cpuexec[key] = c
1535                                 tlast = t
1536                                 clast = c
1537                 dev['cpuexec'] = cpuexec
1538                 return maxC
1539         def createProcessUsageEvents(self):
1540                 # get an array of process names
1541                 proclist = []
1542                 for t in self.pstl:
1543                         pslist = self.pstl[t]
1544                         for ps in pslist:
1545                                 if ps not in proclist:
1546                                         proclist.append(ps)
1547                 # get a list of data points for suspend and resume
1548                 tsus = []
1549                 tres = []
1550                 for t in sorted(self.pstl):
1551                         if t < self.tSuspended:
1552                                 tsus.append(t)
1553                         else:
1554                                 tres.append(t)
1555                 # process the events for suspend and resume
1556                 if len(proclist) > 0:
1557                         sysvals.vprint('Process Execution:')
1558                 for ps in proclist:
1559                         c = self.addProcessUsageEvent(ps, tsus)
1560                         if c > 0:
1561                                 sysvals.vprint('%25s (sus): %d' % (ps, c))
1562                         c = self.addProcessUsageEvent(ps, tres)
1563                         if c > 0:
1564                                 sysvals.vprint('%25s (res): %d' % (ps, c))
1565         def handleEndMarker(self, time):
1566                 dm = self.dmesg
1567                 self.setEnd(time)
1568                 self.initDevicegroups()
1569                 # give suspend_prepare an end if needed
1570                 if 'suspend_prepare' in dm and dm['suspend_prepare']['end'] < 0:
1571                         dm['suspend_prepare']['end'] = time
1572                 # assume resume machine ends at next phase start
1573                 if 'resume_machine' in dm and dm['resume_machine']['end'] < 0:
1574                         np = self.nextPhase('resume_machine', 1)
1575                         if np:
1576                                 dm['resume_machine']['end'] = dm[np]['start']
1577                 # if kernel resume end not found, assume its the end marker
1578                 if self.tKernRes == 0.0:
1579                         self.tKernRes = time
1580                 # if kernel suspend start not found, assume its the end marker
1581                 if self.tKernSus == 0.0:
1582                         self.tKernSus = time
1583                 # set resume complete to end at end marker
1584                 if 'resume_complete' in dm:
1585                         dm['resume_complete']['end'] = time
1586         def debugPrint(self):
1587                 for p in self.sortedPhases():
1588                         list = self.dmesg[p]['list']
1589                         for devname in list:
1590                                 dev = list[devname]
1591                                 if 'ftrace' in dev:
1592                                         dev['ftrace'].debugPrint(' [%s]' % devname)
1593
1594 # Class: DevFunction
1595 # Description:
1596 #        A container for kprobe function data we want in the dev timeline
1597 class DevFunction:
1598         def __init__(self, name, args, caller, ret, start, end, u, proc, pid, color):
1599                 self.row = 0
1600                 self.count = 1
1601                 self.name = name
1602                 self.args = args
1603                 self.caller = caller
1604                 self.ret = ret
1605                 self.time = start
1606                 self.length = end - start
1607                 self.end = end
1608                 self.ubiquitous = u
1609                 self.proc = proc
1610                 self.pid = pid
1611                 self.color = color
1612         def title(self):
1613                 cnt = ''
1614                 if self.count > 1:
1615                         cnt = '(x%d)' % self.count
1616                 l = '%0.3fms' % (self.length * 1000)
1617                 if self.ubiquitous:
1618                         title = '%s(%s)%s <- %s, %s(%s)' % \
1619                                 (self.name, self.args, cnt, self.caller, self.ret, l)
1620                 else:
1621                         title = '%s(%s) %s%s(%s)' % (self.name, self.args, self.ret, cnt, l)
1622                 return title.replace('"', '')
1623         def text(self):
1624                 if self.count > 1:
1625                         text = '%s(x%d)' % (self.name, self.count)
1626                 else:
1627                         text = self.name
1628                 return text
1629         def repeat(self, tgt):
1630                 # is the tgt call just a repeat of this call (e.g. are we in a loop)
1631                 dt = self.time - tgt.end
1632                 # only combine calls if -all- attributes are identical
1633                 if tgt.caller == self.caller and \
1634                         tgt.name == self.name and tgt.args == self.args and \
1635                         tgt.proc == self.proc and tgt.pid == self.pid and \
1636                         tgt.ret == self.ret and dt >= 0 and \
1637                         dt <= sysvals.callloopmaxgap and \
1638                         self.length < sysvals.callloopmaxlen:
1639                         return True
1640                 return False
1641
1642 # Class: FTraceLine
1643 # Description:
1644 #        A container for a single line of ftrace data. There are six basic types:
1645 #                callgraph line:
1646 #                         call: "  dpm_run_callback() {"
1647 #                       return: "  }"
1648 #                         leaf: " dpm_run_callback();"
1649 #                trace event:
1650 #                        tracing_mark_write: SUSPEND START or RESUME COMPLETE
1651 #                        suspend_resume: phase or custom exec block data
1652 #                        device_pm_callback: device callback info
1653 class FTraceLine:
1654         def __init__(self, t, m='', d=''):
1655                 self.length = 0.0
1656                 self.fcall = False
1657                 self.freturn = False
1658                 self.fevent = False
1659                 self.fkprobe = False
1660                 self.depth = 0
1661                 self.name = ''
1662                 self.type = ''
1663                 self.time = float(t)
1664                 if not m and not d:
1665                         return
1666                 # is this a trace event
1667                 if(d == 'traceevent' or re.match('^ *\/\* *(?P<msg>.*) \*\/ *$', m)):
1668                         if(d == 'traceevent'):
1669                                 # nop format trace event
1670                                 msg = m
1671                         else:
1672                                 # function_graph format trace event
1673                                 em = re.match('^ *\/\* *(?P<msg>.*) \*\/ *$', m)
1674                                 msg = em.group('msg')
1675
1676                         emm = re.match('^(?P<call>.*?): (?P<msg>.*)', msg)
1677                         if(emm):
1678                                 self.name = emm.group('msg')
1679                                 self.type = emm.group('call')
1680                         else:
1681                                 self.name = msg
1682                         km = re.match('^(?P<n>.*)_cal$', self.type)
1683                         if km:
1684                                 self.fcall = True
1685                                 self.fkprobe = True
1686                                 self.type = km.group('n')
1687                                 return
1688                         km = re.match('^(?P<n>.*)_ret$', self.type)
1689                         if km:
1690                                 self.freturn = True
1691                                 self.fkprobe = True
1692                                 self.type = km.group('n')
1693                                 return
1694                         self.fevent = True
1695                         return
1696                 # convert the duration to seconds
1697                 if(d):
1698                         self.length = float(d)/1000000
1699                 # the indentation determines the depth
1700                 match = re.match('^(?P<d> *)(?P<o>.*)$', m)
1701                 if(not match):
1702                         return
1703                 self.depth = self.getDepth(match.group('d'))
1704                 m = match.group('o')
1705                 # function return
1706                 if(m[0] == '}'):
1707                         self.freturn = True
1708                         if(len(m) > 1):
1709                                 # includes comment with function name
1710                                 match = re.match('^} *\/\* *(?P<n>.*) *\*\/$', m)
1711                                 if(match):
1712                                         self.name = match.group('n').strip()
1713                 # function call
1714                 else:
1715                         self.fcall = True
1716                         # function call with children
1717                         if(m[-1] == '{'):
1718                                 match = re.match('^(?P<n>.*) *\(.*', m)
1719                                 if(match):
1720                                         self.name = match.group('n').strip()
1721                         # function call with no children (leaf)
1722                         elif(m[-1] == ';'):
1723                                 self.freturn = True
1724                                 match = re.match('^(?P<n>.*) *\(.*', m)
1725                                 if(match):
1726                                         self.name = match.group('n').strip()
1727                         # something else (possibly a trace marker)
1728                         else:
1729                                 self.name = m
1730         def isCall(self):
1731                 return self.fcall and not self.freturn
1732         def isReturn(self):
1733                 return self.freturn and not self.fcall
1734         def isLeaf(self):
1735                 return self.fcall and self.freturn
1736         def getDepth(self, str):
1737                 return len(str)/2
1738         def debugPrint(self, info=''):
1739                 if self.isLeaf():
1740                         pprint(' -- %12.6f (depth=%02d): %s(); (%.3f us) %s' % (self.time, \
1741                                 self.depth, self.name, self.length*1000000, info))
1742                 elif self.freturn:
1743                         pprint(' -- %12.6f (depth=%02d): %s} (%.3f us) %s' % (self.time, \
1744                                 self.depth, self.name, self.length*1000000, info))
1745                 else:
1746                         pprint(' -- %12.6f (depth=%02d): %s() { (%.3f us) %s' % (self.time, \
1747                                 self.depth, self.name, self.length*1000000, info))
1748         def startMarker(self):
1749                 # Is this the starting line of a suspend?
1750                 if not self.fevent:
1751                         return False
1752                 if sysvals.usetracemarkers:
1753                         if(self.name == 'SUSPEND START'):
1754                                 return True
1755                         return False
1756                 else:
1757                         if(self.type == 'suspend_resume' and
1758                                 re.match('suspend_enter\[.*\] begin', self.name)):
1759                                 return True
1760                         return False
1761         def endMarker(self):
1762                 # Is this the ending line of a resume?
1763                 if not self.fevent:
1764                         return False
1765                 if sysvals.usetracemarkers:
1766                         if(self.name == 'RESUME COMPLETE'):
1767                                 return True
1768                         return False
1769                 else:
1770                         if(self.type == 'suspend_resume' and
1771                                 re.match('thaw_processes\[.*\] end', self.name)):
1772                                 return True
1773                         return False
1774
1775 # Class: FTraceCallGraph
1776 # Description:
1777 #        A container for the ftrace callgraph of a single recursive function.
1778 #        This can be a dpm_run_callback, dpm_prepare, or dpm_complete callgraph
1779 #        Each instance is tied to a single device in a single phase, and is
1780 #        comprised of an ordered list of FTraceLine objects
1781 class FTraceCallGraph:
1782         vfname = 'missing_function_name'
1783         def __init__(self, pid, sv):
1784                 self.id = ''
1785                 self.invalid = False
1786                 self.name = ''
1787                 self.partial = False
1788                 self.ignore = False
1789                 self.start = -1.0
1790                 self.end = -1.0
1791                 self.list = []
1792                 self.depth = 0
1793                 self.pid = pid
1794                 self.sv = sv
1795         def addLine(self, line):
1796                 # if this is already invalid, just leave
1797                 if(self.invalid):
1798                         if(line.depth == 0 and line.freturn):
1799                                 return 1
1800                         return 0
1801                 # invalidate on bad depth
1802                 if(self.depth < 0):
1803                         self.invalidate(line)
1804                         return 0
1805                 # ignore data til we return to the current depth
1806                 if self.ignore:
1807                         if line.depth > self.depth:
1808                                 return 0
1809                         else:
1810                                 self.list[-1].freturn = True
1811                                 self.list[-1].length = line.time - self.list[-1].time
1812                                 self.ignore = False
1813                                 # if this is a return at self.depth, no more work is needed
1814                                 if line.depth == self.depth and line.isReturn():
1815                                         if line.depth == 0:
1816                                                 self.end = line.time
1817                                                 return 1
1818                                         return 0
1819                 # compare current depth with this lines pre-call depth
1820                 prelinedep = line.depth
1821                 if line.isReturn():
1822                         prelinedep += 1
1823                 last = 0
1824                 lasttime = line.time
1825                 if len(self.list) > 0:
1826                         last = self.list[-1]
1827                         lasttime = last.time
1828                         if last.isLeaf():
1829                                 lasttime += last.length
1830                 # handle low misalignments by inserting returns
1831                 mismatch = prelinedep - self.depth
1832                 warning = self.sv.verbose and abs(mismatch) > 1
1833                 info = []
1834                 if mismatch < 0:
1835                         idx = 0
1836                         # add return calls to get the depth down
1837                         while prelinedep < self.depth:
1838                                 self.depth -= 1
1839                                 if idx == 0 and last and last.isCall():
1840                                         # special case, turn last call into a leaf
1841                                         last.depth = self.depth
1842                                         last.freturn = True
1843                                         last.length = line.time - last.time
1844                                         if warning:
1845                                                 info.append(('[make leaf]', last))
1846                                 else:
1847                                         vline = FTraceLine(lasttime)
1848                                         vline.depth = self.depth
1849                                         vline.name = self.vfname
1850                                         vline.freturn = True
1851                                         self.list.append(vline)
1852                                         if warning:
1853                                                 if idx == 0:
1854                                                         info.append(('', last))
1855                                                 info.append(('[add return]', vline))
1856                                 idx += 1
1857                         if warning:
1858                                 info.append(('', line))
1859                 # handle high misalignments by inserting calls
1860                 elif mismatch > 0:
1861                         idx = 0
1862                         if warning:
1863                                 info.append(('', last))
1864                         # add calls to get the depth up
1865                         while prelinedep > self.depth:
1866                                 if idx == 0 and line.isReturn():
1867                                         # special case, turn this return into a leaf
1868                                         line.fcall = True
1869                                         prelinedep -= 1
1870                                         if warning:
1871                                                 info.append(('[make leaf]', line))
1872                                 else:
1873                                         vline = FTraceLine(lasttime)
1874                                         vline.depth = self.depth
1875                                         vline.name = self.vfname
1876                                         vline.fcall = True
1877                                         self.list.append(vline)
1878                                         self.depth += 1
1879                                         if not last:
1880                                                 self.start = vline.time
1881                                         if warning:
1882                                                 info.append(('[add call]', vline))
1883                                 idx += 1
1884                         if warning and ('[make leaf]', line) not in info:
1885                                 info.append(('', line))
1886                 if warning:
1887                         pprint('WARNING: ftrace data missing, corrections made:')
1888                         for i in info:
1889                                 t, obj = i
1890                                 if obj:
1891                                         obj.debugPrint(t)
1892                 # process the call and set the new depth
1893                 skipadd = False
1894                 md = self.sv.max_graph_depth
1895                 if line.isCall():
1896                         # ignore blacklisted/overdepth funcs
1897                         if (md and self.depth >= md - 1) or (line.name in self.sv.cgblacklist):
1898                                 self.ignore = True
1899                         else:
1900                                 self.depth += 1
1901                 elif line.isReturn():
1902                         self.depth -= 1
1903                         # remove blacklisted/overdepth/empty funcs that slipped through
1904                         if (last and last.isCall() and last.depth == line.depth) or \
1905                                 (md and last and last.depth >= md) or \
1906                                 (line.name in self.sv.cgblacklist):
1907                                 while len(self.list) > 0 and self.list[-1].depth > line.depth:
1908                                         self.list.pop(-1)
1909                                 if len(self.list) == 0:
1910                                         self.invalid = True
1911                                         return 1
1912                                 self.list[-1].freturn = True
1913                                 self.list[-1].length = line.time - self.list[-1].time
1914                                 self.list[-1].name = line.name
1915                                 skipadd = True
1916                 if len(self.list) < 1:
1917                         self.start = line.time
1918                 # check for a mismatch that returned all the way to callgraph end
1919                 res = 1
1920                 if mismatch < 0 and self.list[-1].depth == 0 and self.list[-1].freturn:
1921                         line = self.list[-1]
1922                         skipadd = True
1923                         res = -1
1924                 if not skipadd:
1925                         self.list.append(line)
1926                 if(line.depth == 0 and line.freturn):
1927                         if(self.start < 0):
1928                                 self.start = line.time
1929                         self.end = line.time
1930                         if line.fcall:
1931                                 self.end += line.length
1932                         if self.list[0].name == self.vfname:
1933                                 self.invalid = True
1934                         if res == -1:
1935                                 self.partial = True
1936                         return res
1937                 return 0
1938         def invalidate(self, line):
1939                 if(len(self.list) > 0):
1940                         first = self.list[0]
1941                         self.list = []
1942                         self.list.append(first)
1943                 self.invalid = True
1944                 id = 'task %s' % (self.pid)
1945                 window = '(%f - %f)' % (self.start, line.time)
1946                 if(self.depth < 0):
1947                         pprint('Data misalignment for '+id+\
1948                                 ' (buffer overflow), ignoring this callback')
1949                 else:
1950                         pprint('Too much data for '+id+\
1951                                 ' '+window+', ignoring this callback')
1952         def slice(self, dev):
1953                 minicg = FTraceCallGraph(dev['pid'], self.sv)
1954                 minicg.name = self.name
1955                 mydepth = -1
1956                 good = False
1957                 for l in self.list:
1958                         if(l.time < dev['start'] or l.time > dev['end']):
1959                                 continue
1960                         if mydepth < 0:
1961                                 if l.name == 'mutex_lock' and l.freturn:
1962                                         mydepth = l.depth
1963                                 continue
1964                         elif l.depth == mydepth and l.name == 'mutex_unlock' and l.fcall:
1965                                 good = True
1966                                 break
1967                         l.depth -= mydepth
1968                         minicg.addLine(l)
1969                 if not good or len(minicg.list) < 1:
1970                         return 0
1971                 return minicg
1972         def repair(self, enddepth):
1973                 # bring the depth back to 0 with additional returns
1974                 fixed = False
1975                 last = self.list[-1]
1976                 for i in reversed(range(enddepth)):
1977                         t = FTraceLine(last.time)
1978                         t.depth = i
1979                         t.freturn = True
1980                         fixed = self.addLine(t)
1981                         if fixed != 0:
1982                                 self.end = last.time
1983                                 return True
1984                 return False
1985         def postProcess(self):
1986                 if len(self.list) > 0:
1987                         self.name = self.list[0].name
1988                 stack = dict()
1989                 cnt = 0
1990                 last = 0
1991                 for l in self.list:
1992                         # ftrace bug: reported duration is not reliable
1993                         # check each leaf and clip it at max possible length
1994                         if last and last.isLeaf():
1995                                 if last.length > l.time - last.time:
1996                                         last.length = l.time - last.time
1997                         if l.isCall():
1998                                 stack[l.depth] = l
1999                                 cnt += 1
2000                         elif l.isReturn():
2001                                 if(l.depth not in stack):
2002                                         if self.sv.verbose:
2003                                                 pprint('Post Process Error: Depth missing')
2004                                                 l.debugPrint()
2005                                         return False
2006                                 # calculate call length from call/return lines
2007                                 cl = stack[l.depth]
2008                                 cl.length = l.time - cl.time
2009                                 if cl.name == self.vfname:
2010                                         cl.name = l.name
2011                                 stack.pop(l.depth)
2012                                 l.length = 0
2013                                 cnt -= 1
2014                         last = l
2015                 if(cnt == 0):
2016                         # trace caught the whole call tree
2017                         return True
2018                 elif(cnt < 0):
2019                         if self.sv.verbose:
2020                                 pprint('Post Process Error: Depth is less than 0')
2021                         return False
2022                 # trace ended before call tree finished
2023                 return self.repair(cnt)
2024         def deviceMatch(self, pid, data):
2025                 found = ''
2026                 # add the callgraph data to the device hierarchy
2027                 borderphase = {
2028                         'dpm_prepare': 'suspend_prepare',
2029                         'dpm_complete': 'resume_complete'
2030                 }
2031                 if(self.name in borderphase):
2032                         p = borderphase[self.name]
2033                         list = data.dmesg[p]['list']
2034                         for devname in list:
2035                                 dev = list[devname]
2036                                 if(pid == dev['pid'] and
2037                                         self.start <= dev['start'] and
2038                                         self.end >= dev['end']):
2039                                         cg = self.slice(dev)
2040                                         if cg:
2041                                                 dev['ftrace'] = cg
2042                                         found = devname
2043                         return found
2044                 for p in data.sortedPhases():
2045                         if(data.dmesg[p]['start'] <= self.start and
2046                                 self.start <= data.dmesg[p]['end']):
2047                                 list = data.dmesg[p]['list']
2048                                 for devname in list:
2049                                         dev = list[devname]
2050                                         if(pid == dev['pid'] and
2051                                                 self.start <= dev['start'] and
2052                                                 self.end >= dev['end']):
2053                                                 dev['ftrace'] = self
2054                                                 found = devname
2055                                                 break
2056                                 break
2057                 return found
2058         def newActionFromFunction(self, data):
2059                 name = self.name
2060                 if name in ['dpm_run_callback', 'dpm_prepare', 'dpm_complete']:
2061                         return
2062                 fs = self.start
2063                 fe = self.end
2064                 if fs < data.start or fe > data.end:
2065                         return
2066                 phase = ''
2067                 for p in data.sortedPhases():
2068                         if(data.dmesg[p]['start'] <= self.start and
2069                                 self.start < data.dmesg[p]['end']):
2070                                 phase = p
2071                                 break
2072                 if not phase:
2073                         return
2074                 out = data.newActionGlobal(name, fs, fe, -2)
2075                 if out:
2076                         phase, myname = out
2077                         data.dmesg[phase]['list'][myname]['ftrace'] = self
2078         def debugPrint(self, info=''):
2079                 pprint('%s pid=%d [%f - %f] %.3f us' % \
2080                         (self.name, self.pid, self.start, self.end,
2081                         (self.end - self.start)*1000000))
2082                 for l in self.list:
2083                         if l.isLeaf():
2084                                 pprint('%f (%02d): %s(); (%.3f us)%s' % (l.time, \
2085                                         l.depth, l.name, l.length*1000000, info))
2086                         elif l.freturn:
2087                                 pprint('%f (%02d): %s} (%.3f us)%s' % (l.time, \
2088                                         l.depth, l.name, l.length*1000000, info))
2089                         else:
2090                                 pprint('%f (%02d): %s() { (%.3f us)%s' % (l.time, \
2091                                         l.depth, l.name, l.length*1000000, info))
2092                 pprint(' ')
2093
2094 class DevItem:
2095         def __init__(self, test, phase, dev):
2096                 self.test = test
2097                 self.phase = phase
2098                 self.dev = dev
2099         def isa(self, cls):
2100                 if 'htmlclass' in self.dev and cls in self.dev['htmlclass']:
2101                         return True
2102                 return False
2103
2104 # Class: Timeline
2105 # Description:
2106 #        A container for a device timeline which calculates
2107 #        all the html properties to display it correctly
2108 class Timeline:
2109         html_tblock = '<div id="block{0}" class="tblock" style="left:{1}%;width:{2}%;"><div class="tback" style="height:{3}px"></div>\n'
2110         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'
2111         html_phase = '<div class="phase" style="left:{0}%;width:{1}%;top:{2}px;height:{3}px;background:{4}">{5}</div>\n'
2112         html_phaselet = '<div id="{0}" class="phaselet" style="left:{1}%;width:{2}%;background:{3}"></div>\n'
2113         html_legend = '<div id="p{3}" class="square" style="left:{0}%;background:{1}">&nbsp;{2}</div>\n'
2114         def __init__(self, rowheight, scaleheight):
2115                 self.html = ''
2116                 self.height = 0  # total timeline height
2117                 self.scaleH = scaleheight # timescale (top) row height
2118                 self.rowH = rowheight     # device row height
2119                 self.bodyH = 0   # body height
2120                 self.rows = 0    # total timeline rows
2121                 self.rowlines = dict()
2122                 self.rowheight = dict()
2123         def createHeader(self, sv, stamp):
2124                 if(not stamp['time']):
2125                         return
2126                 self.html += '<div class="version"><a href="https://01.org/suspendresume">%s v%s</a></div>' \
2127                         % (sv.title, sv.version)
2128                 if sv.logmsg and sv.testlog:
2129                         self.html += '<button id="showtest" class="logbtn btnfmt">log</button>'
2130                 if sv.dmesglog:
2131                         self.html += '<button id="showdmesg" class="logbtn btnfmt">dmesg</button>'
2132                 if sv.ftracelog:
2133                         self.html += '<button id="showftrace" class="logbtn btnfmt">ftrace</button>'
2134                 headline_stamp = '<div class="stamp">{0} {1} {2} {3}</div>\n'
2135                 self.html += headline_stamp.format(stamp['host'], stamp['kernel'],
2136                         stamp['mode'], stamp['time'])
2137                 if 'man' in stamp and 'plat' in stamp and 'cpu' in stamp and \
2138                         stamp['man'] and stamp['plat'] and stamp['cpu']:
2139                         headline_sysinfo = '<div class="stamp sysinfo">{0} {1} <i>with</i> {2}</div>\n'
2140                         self.html += headline_sysinfo.format(stamp['man'], stamp['plat'], stamp['cpu'])
2141
2142         # Function: getDeviceRows
2143         # Description:
2144         #    determine how may rows the device funcs will take
2145         # Arguments:
2146         #        rawlist: the list of devices/actions for a single phase
2147         # Output:
2148         #        The total number of rows needed to display this phase of the timeline
2149         def getDeviceRows(self, rawlist):
2150                 # clear all rows and set them to undefined
2151                 sortdict = dict()
2152                 for item in rawlist:
2153                         item.row = -1
2154                         sortdict[item] = item.length
2155                 sortlist = sorted(sortdict, key=sortdict.get, reverse=True)
2156                 remaining = len(sortlist)
2157                 rowdata = dict()
2158                 row = 1
2159                 # try to pack each row with as many ranges as possible
2160                 while(remaining > 0):
2161                         if(row not in rowdata):
2162                                 rowdata[row] = []
2163                         for i in sortlist:
2164                                 if(i.row >= 0):
2165                                         continue
2166                                 s = i.time
2167                                 e = i.time + i.length
2168                                 valid = True
2169                                 for ritem in rowdata[row]:
2170                                         rs = ritem.time
2171                                         re = ritem.time + ritem.length
2172                                         if(not (((s <= rs) and (e <= rs)) or
2173                                                 ((s >= re) and (e >= re)))):
2174                                                 valid = False
2175                                                 break
2176                                 if(valid):
2177                                         rowdata[row].append(i)
2178                                         i.row = row
2179                                         remaining -= 1
2180                         row += 1
2181                 return row
2182         # Function: getPhaseRows
2183         # Description:
2184         #        Organize the timeline entries into the smallest
2185         #        number of rows possible, with no entry overlapping
2186         # Arguments:
2187         #        devlist: the list of devices/actions in a group of contiguous phases
2188         # Output:
2189         #        The total number of rows needed to display this phase of the timeline
2190         def getPhaseRows(self, devlist, row=0, sortby='length'):
2191                 # clear all rows and set them to undefined
2192                 remaining = len(devlist)
2193                 rowdata = dict()
2194                 sortdict = dict()
2195                 myphases = []
2196                 # initialize all device rows to -1 and calculate devrows
2197                 for item in devlist:
2198                         dev = item.dev
2199                         tp = (item.test, item.phase)
2200                         if tp not in myphases:
2201                                 myphases.append(tp)
2202                         dev['row'] = -1
2203                         if sortby == 'start':
2204                                 # sort by start 1st, then length 2nd
2205                                 sortdict[item] = (-1*float(dev['start']), float(dev['end']) - float(dev['start']))
2206                         else:
2207                                 # sort by length 1st, then name 2nd
2208                                 sortdict[item] = (float(dev['end']) - float(dev['start']), item.dev['name'])
2209                         if 'src' in dev:
2210                                 dev['devrows'] = self.getDeviceRows(dev['src'])
2211                 # sort the devlist by length so that large items graph on top
2212                 sortlist = sorted(sortdict, key=sortdict.get, reverse=True)
2213                 orderedlist = []
2214                 for item in sortlist:
2215                         if item.dev['pid'] == -2:
2216                                 orderedlist.append(item)
2217                 for item in sortlist:
2218                         if item not in orderedlist:
2219                                 orderedlist.append(item)
2220                 # try to pack each row with as many devices as possible
2221                 while(remaining > 0):
2222                         rowheight = 1
2223                         if(row not in rowdata):
2224                                 rowdata[row] = []
2225                         for item in orderedlist:
2226                                 dev = item.dev
2227                                 if(dev['row'] < 0):
2228                                         s = dev['start']
2229                                         e = dev['end']
2230                                         valid = True
2231                                         for ritem in rowdata[row]:
2232                                                 rs = ritem.dev['start']
2233                                                 re = ritem.dev['end']
2234                                                 if(not (((s <= rs) and (e <= rs)) or
2235                                                         ((s >= re) and (e >= re)))):
2236                                                         valid = False
2237                                                         break
2238                                         if(valid):
2239                                                 rowdata[row].append(item)
2240                                                 dev['row'] = row
2241                                                 remaining -= 1
2242                                                 if 'devrows' in dev and dev['devrows'] > rowheight:
2243                                                         rowheight = dev['devrows']
2244                         for t, p in myphases:
2245                                 if t not in self.rowlines or t not in self.rowheight:
2246                                         self.rowlines[t] = dict()
2247                                         self.rowheight[t] = dict()
2248                                 if p not in self.rowlines[t] or p not in self.rowheight[t]:
2249                                         self.rowlines[t][p] = dict()
2250                                         self.rowheight[t][p] = dict()
2251                                 rh = self.rowH
2252                                 # section headers should use a different row height
2253                                 if len(rowdata[row]) == 1 and \
2254                                         'htmlclass' in rowdata[row][0].dev and \
2255                                         'sec' in rowdata[row][0].dev['htmlclass']:
2256                                         rh = 15
2257                                 self.rowlines[t][p][row] = rowheight
2258                                 self.rowheight[t][p][row] = rowheight * rh
2259                         row += 1
2260                 if(row > self.rows):
2261                         self.rows = int(row)
2262                 return row
2263         def phaseRowHeight(self, test, phase, row):
2264                 return self.rowheight[test][phase][row]
2265         def phaseRowTop(self, test, phase, row):
2266                 top = 0
2267                 for i in sorted(self.rowheight[test][phase]):
2268                         if i >= row:
2269                                 break
2270                         top += self.rowheight[test][phase][i]
2271                 return top
2272         def calcTotalRows(self):
2273                 # Calculate the heights and offsets for the header and rows
2274                 maxrows = 0
2275                 standardphases = []
2276                 for t in self.rowlines:
2277                         for p in self.rowlines[t]:
2278                                 total = 0
2279                                 for i in sorted(self.rowlines[t][p]):
2280                                         total += self.rowlines[t][p][i]
2281                                 if total > maxrows:
2282                                         maxrows = total
2283                                 if total == len(self.rowlines[t][p]):
2284                                         standardphases.append((t, p))
2285                 self.height = self.scaleH + (maxrows*self.rowH)
2286                 self.bodyH = self.height - self.scaleH
2287                 # if there is 1 line per row, draw them the standard way
2288                 for t, p in standardphases:
2289                         for i in sorted(self.rowheight[t][p]):
2290                                 self.rowheight[t][p][i] = self.bodyH/len(self.rowlines[t][p])
2291         def createZoomBox(self, mode='command', testcount=1):
2292                 # Create bounding box, add buttons
2293                 html_zoombox = '<center><button id="zoomin">ZOOM IN +</button><button id="zoomout">ZOOM OUT -</button><button id="zoomdef">ZOOM 1:1</button></center>\n'
2294                 html_timeline = '<div id="dmesgzoombox" class="zoombox">\n<div id="{0}" class="timeline" style="height:{1}px">\n'
2295                 html_devlist1 = '<button id="devlist1" class="devlist" style="float:left;">Device Detail{0}</button>'
2296                 html_devlist2 = '<button id="devlist2" class="devlist" style="float:right;">Device Detail2</button>\n'
2297                 if mode != 'command':
2298                         if testcount > 1:
2299                                 self.html += html_devlist2
2300                                 self.html += html_devlist1.format('1')
2301                         else:
2302                                 self.html += html_devlist1.format('')
2303                 self.html += html_zoombox
2304                 self.html += html_timeline.format('dmesg', self.height)
2305         # Function: createTimeScale
2306         # Description:
2307         #        Create the timescale for a timeline block
2308         # Arguments:
2309         #        m0: start time (mode begin)
2310         #        mMax: end time (mode end)
2311         #        tTotal: total timeline time
2312         #        mode: suspend or resume
2313         # Output:
2314         #        The html code needed to display the time scale
2315         def createTimeScale(self, m0, mMax, tTotal, mode):
2316                 timescale = '<div class="t" style="right:{0}%">{1}</div>\n'
2317                 rline = '<div class="t" style="left:0;border-left:1px solid black;border-right:0;">{0}</div>\n'
2318                 output = '<div class="timescale">\n'
2319                 # set scale for timeline
2320                 mTotal = mMax - m0
2321                 tS = 0.1
2322                 if(tTotal <= 0):
2323                         return output+'</div>\n'
2324                 if(tTotal > 4):
2325                         tS = 1
2326                 divTotal = int(mTotal/tS) + 1
2327                 divEdge = (mTotal - tS*(divTotal-1))*100/mTotal
2328                 for i in range(divTotal):
2329                         htmlline = ''
2330                         if(mode == 'suspend'):
2331                                 pos = '%0.3f' % (100 - ((float(i)*tS*100)/mTotal) - divEdge)
2332                                 val = '%0.fms' % (float(i-divTotal+1)*tS*1000)
2333                                 if(i == divTotal - 1):
2334                                         val = mode
2335                                 htmlline = timescale.format(pos, val)
2336                         else:
2337                                 pos = '%0.3f' % (100 - ((float(i)*tS*100)/mTotal))
2338                                 val = '%0.fms' % (float(i)*tS*1000)
2339                                 htmlline = timescale.format(pos, val)
2340                                 if(i == 0):
2341                                         htmlline = rline.format(mode)
2342                         output += htmlline
2343                 self.html += output+'</div>\n'
2344
2345 # Class: TestProps
2346 # Description:
2347 #        A list of values describing the properties of these test runs
2348 class TestProps:
2349         stampfmt = '# [a-z]*-(?P<m>[0-9]{2})(?P<d>[0-9]{2})(?P<y>[0-9]{2})-'+\
2350                                 '(?P<H>[0-9]{2})(?P<M>[0-9]{2})(?P<S>[0-9]{2})'+\
2351                                 ' (?P<host>.*) (?P<mode>.*) (?P<kernel>.*)$'
2352         batteryfmt = '^# battery (?P<a1>\w*) (?P<c1>\d*) (?P<a2>\w*) (?P<c2>\d*)'
2353         testerrfmt = '^# enter_sleep_error (?P<e>.*)'
2354         sysinfofmt = '^# sysinfo .*'
2355         cmdlinefmt = '^# command \| (?P<cmd>.*)'
2356         kparamsfmt = '^# kparams \| (?P<kp>.*)'
2357         devpropfmt = '# Device Properties: .*'
2358         tracertypefmt = '# tracer: (?P<t>.*)'
2359         firmwarefmt = '# fwsuspend (?P<s>[0-9]*) fwresume (?P<r>[0-9]*)$'
2360         procexecfmt = 'ps - (?P<ps>.*)$'
2361         ftrace_line_fmt_fg = \
2362                 '^ *(?P<time>[0-9\.]*) *\| *(?P<cpu>[0-9]*)\)'+\
2363                 ' *(?P<proc>.*)-(?P<pid>[0-9]*) *\|'+\
2364                 '[ +!#\*@$]*(?P<dur>[0-9\.]*) .*\|  (?P<msg>.*)'
2365         ftrace_line_fmt_nop = \
2366                 ' *(?P<proc>.*)-(?P<pid>[0-9]*) *\[(?P<cpu>[0-9]*)\] *'+\
2367                 '(?P<flags>.{4}) *(?P<time>[0-9\.]*): *'+\
2368                 '(?P<msg>.*)'
2369         def __init__(self):
2370                 self.stamp = ''
2371                 self.sysinfo = ''
2372                 self.cmdline = ''
2373                 self.kparams = ''
2374                 self.testerror = []
2375                 self.battery = []
2376                 self.fwdata = []
2377                 self.ftrace_line_fmt = self.ftrace_line_fmt_nop
2378                 self.cgformat = False
2379                 self.data = 0
2380                 self.ktemp = dict()
2381         def setTracerType(self, tracer):
2382                 if(tracer == 'function_graph'):
2383                         self.cgformat = True
2384                         self.ftrace_line_fmt = self.ftrace_line_fmt_fg
2385                 elif(tracer == 'nop'):
2386                         self.ftrace_line_fmt = self.ftrace_line_fmt_nop
2387                 else:
2388                         doError('Invalid tracer format: [%s]' % tracer)
2389         def parseStamp(self, data, sv):
2390                 # global test data
2391                 m = re.match(self.stampfmt, self.stamp)
2392                 data.stamp = {'time': '', 'host': '', 'mode': ''}
2393                 dt = datetime(int(m.group('y'))+2000, int(m.group('m')),
2394                         int(m.group('d')), int(m.group('H')), int(m.group('M')),
2395                         int(m.group('S')))
2396                 data.stamp['time'] = dt.strftime('%B %d %Y, %I:%M:%S %p')
2397                 data.stamp['host'] = m.group('host')
2398                 data.stamp['mode'] = m.group('mode')
2399                 data.stamp['kernel'] = m.group('kernel')
2400                 if re.match(self.sysinfofmt, self.sysinfo):
2401                         for f in self.sysinfo.split('|'):
2402                                 if '#' in f:
2403                                         continue
2404                                 tmp = f.strip().split(':', 1)
2405                                 key = tmp[0]
2406                                 val = tmp[1]
2407                                 data.stamp[key] = val
2408                 sv.hostname = data.stamp['host']
2409                 sv.suspendmode = data.stamp['mode']
2410                 if sv.suspendmode == 'command' and sv.ftracefile != '':
2411                         modes = ['on', 'freeze', 'standby', 'mem', 'disk']
2412                         fp = sysvals.openlog(sv.ftracefile, 'r')
2413                         for line in fp:
2414                                 m = re.match('.* machine_suspend\[(?P<mode>.*)\]', line)
2415                                 if m and m.group('mode') in ['1', '2', '3', '4']:
2416                                         sv.suspendmode = modes[int(m.group('mode'))]
2417                                         data.stamp['mode'] = sv.suspendmode
2418                                         break
2419                         fp.close()
2420                 m = re.match(self.cmdlinefmt, self.cmdline)
2421                 if m:
2422                         sv.cmdline = m.group('cmd')
2423                 if self.kparams:
2424                         m = re.match(self.kparamsfmt, self.kparams)
2425                         if m:
2426                                 sv.kparams = m.group('kp')
2427                 if not sv.stamp:
2428                         sv.stamp = data.stamp
2429                 # firmware data
2430                 if sv.suspendmode == 'mem' and len(self.fwdata) > data.testnumber:
2431                         data.fwSuspend, data.fwResume = self.fwdata[data.testnumber]
2432                         if(data.fwSuspend > 0 or data.fwResume > 0):
2433                                 data.fwValid = True
2434                 # battery data
2435                 if len(self.battery) > data.testnumber:
2436                         m = re.match(self.batteryfmt, self.battery[data.testnumber])
2437                         if m:
2438                                 data.battery = m.groups()
2439                 # sleep mode enter errors
2440                 if len(self.testerror) > data.testnumber:
2441                         m = re.match(self.testerrfmt, self.testerror[data.testnumber])
2442                         if m:
2443                                 data.enterfail = m.group('e')
2444
2445 # Class: TestRun
2446 # Description:
2447 #        A container for a suspend/resume test run. This is necessary as
2448 #        there could be more than one, and they need to be separate.
2449 class TestRun:
2450         def __init__(self, dataobj):
2451                 self.data = dataobj
2452                 self.ftemp = dict()
2453                 self.ttemp = dict()
2454
2455 class ProcessMonitor:
2456         def __init__(self):
2457                 self.proclist = dict()
2458                 self.running = False
2459         def procstat(self):
2460                 c = ['cat /proc/[1-9]*/stat 2>/dev/null']
2461                 process = Popen(c, shell=True, stdout=PIPE)
2462                 running = dict()
2463                 for line in process.stdout:
2464                         data = line.split()
2465                         pid = data[0]
2466                         name = re.sub('[()]', '', data[1])
2467                         user = int(data[13])
2468                         kern = int(data[14])
2469                         kjiff = ujiff = 0
2470                         if pid not in self.proclist:
2471                                 self.proclist[pid] = {'name' : name, 'user' : user, 'kern' : kern}
2472                         else:
2473                                 val = self.proclist[pid]
2474                                 ujiff = user - val['user']
2475                                 kjiff = kern - val['kern']
2476                                 val['user'] = user
2477                                 val['kern'] = kern
2478                         if ujiff > 0 or kjiff > 0:
2479                                 running[pid] = ujiff + kjiff
2480                 process.wait()
2481                 out = ''
2482                 for pid in running:
2483                         jiffies = running[pid]
2484                         val = self.proclist[pid]
2485                         if out:
2486                                 out += ','
2487                         out += '%s-%s %d' % (val['name'], pid, jiffies)
2488                 return 'ps - '+out
2489         def processMonitor(self, tid):
2490                 while self.running:
2491                         out = self.procstat()
2492                         if out:
2493                                 sysvals.fsetVal(out, 'trace_marker')
2494         def start(self):
2495                 self.thread = Thread(target=self.processMonitor, args=(0,))
2496                 self.running = True
2497                 self.thread.start()
2498         def stop(self):
2499                 self.running = False
2500
2501 # ----------------- FUNCTIONS --------------------
2502
2503 # Function: doesTraceLogHaveTraceEvents
2504 # Description:
2505 #        Quickly determine if the ftrace log has all of the trace events,
2506 #        markers, and/or kprobes required for primary parsing.
2507 def doesTraceLogHaveTraceEvents():
2508         kpcheck = ['_cal: (', '_cpu_down()']
2509         techeck = ['suspend_resume', 'device_pm_callback']
2510         tmcheck = ['tracing_mark_write']
2511         sysvals.usekprobes = False
2512         fp = sysvals.openlog(sysvals.ftracefile, 'r')
2513         for line in fp:
2514                 # check for kprobes
2515                 if not sysvals.usekprobes:
2516                         for i in kpcheck:
2517                                 if i in line:
2518                                         sysvals.usekprobes = True
2519                 # check for all necessary trace events
2520                 check = techeck[:]
2521                 for i in techeck:
2522                         if i in line:
2523                                 check.remove(i)
2524                 techeck = check
2525                 # check for all necessary trace markers
2526                 check = tmcheck[:]
2527                 for i in tmcheck:
2528                         if i in line:
2529                                 check.remove(i)
2530                 tmcheck = check
2531         fp.close()
2532         sysvals.usetraceevents = True if len(techeck) < 2 else False
2533         sysvals.usetracemarkers = True if len(tmcheck) == 0 else False
2534
2535 # Function: appendIncompleteTraceLog
2536 # Description:
2537 #        [deprecated for kernel 3.15 or newer]
2538 #        Adds callgraph data which lacks trace event data. This is only
2539 #        for timelines generated from 3.15 or older
2540 # Arguments:
2541 #        testruns: the array of Data objects obtained from parseKernelLog
2542 def appendIncompleteTraceLog(testruns):
2543         # create TestRun vessels for ftrace parsing
2544         testcnt = len(testruns)
2545         testidx = 0
2546         testrun = []
2547         for data in testruns:
2548                 testrun.append(TestRun(data))
2549
2550         # extract the callgraph and traceevent data
2551         sysvals.vprint('Analyzing the ftrace data (%s)...' % \
2552                 os.path.basename(sysvals.ftracefile))
2553         tp = TestProps()
2554         tf = sysvals.openlog(sysvals.ftracefile, 'r')
2555         data = 0
2556         for line in tf:
2557                 # remove any latent carriage returns
2558                 line = line.replace('\r\n', '')
2559                 # grab the stamp and sysinfo
2560                 if re.match(tp.stampfmt, line):
2561                         tp.stamp = line
2562                         continue
2563                 elif re.match(tp.sysinfofmt, line):
2564                         tp.sysinfo = line
2565                         continue
2566                 elif re.match(tp.cmdlinefmt, line):
2567                         tp.cmdline = line
2568                         continue
2569                 elif re.match(tp.batteryfmt, line):
2570                         tp.battery.append(line)
2571                         continue
2572                 elif re.match(tp.testerrfmt, line):
2573                         tp.testerror.append(line)
2574                         continue
2575                 # determine the trace data type (required for further parsing)
2576                 m = re.match(tp.tracertypefmt, line)
2577                 if(m):
2578                         tp.setTracerType(m.group('t'))
2579                         continue
2580                 # device properties line
2581                 if(re.match(tp.devpropfmt, line)):
2582                         devProps(line)
2583                         continue
2584                 # parse only valid lines, if this is not one move on
2585                 m = re.match(tp.ftrace_line_fmt, line)
2586                 if(not m):
2587                         continue
2588                 # gather the basic message data from the line
2589                 m_time = m.group('time')
2590                 m_pid = m.group('pid')
2591                 m_msg = m.group('msg')
2592                 if(tp.cgformat):
2593                         m_param3 = m.group('dur')
2594                 else:
2595                         m_param3 = 'traceevent'
2596                 if(m_time and m_pid and m_msg):
2597                         t = FTraceLine(m_time, m_msg, m_param3)
2598                         pid = int(m_pid)
2599                 else:
2600                         continue
2601                 # the line should be a call, return, or event
2602                 if(not t.fcall and not t.freturn and not t.fevent):
2603                         continue
2604                 # look for the suspend start marker
2605                 if(t.startMarker()):
2606                         data = testrun[testidx].data
2607                         tp.parseStamp(data, sysvals)
2608                         data.setStart(t.time)
2609                         continue
2610                 if(not data):
2611                         continue
2612                 # find the end of resume
2613                 if(t.endMarker()):
2614                         data.setEnd(t.time)
2615                         testidx += 1
2616                         if(testidx >= testcnt):
2617                                 break
2618                         continue
2619                 # trace event processing
2620                 if(t.fevent):
2621                         continue
2622                 # call/return processing
2623                 elif sysvals.usecallgraph:
2624                         # create a callgraph object for the data
2625                         if(pid not in testrun[testidx].ftemp):
2626                                 testrun[testidx].ftemp[pid] = []
2627                                 testrun[testidx].ftemp[pid].append(FTraceCallGraph(pid, sysvals))
2628                         # when the call is finished, see which device matches it
2629                         cg = testrun[testidx].ftemp[pid][-1]
2630                         res = cg.addLine(t)
2631                         if(res != 0):
2632                                 testrun[testidx].ftemp[pid].append(FTraceCallGraph(pid, sysvals))
2633                         if(res == -1):
2634                                 testrun[testidx].ftemp[pid][-1].addLine(t)
2635         tf.close()
2636
2637         for test in testrun:
2638                 # add the callgraph data to the device hierarchy
2639                 for pid in test.ftemp:
2640                         for cg in test.ftemp[pid]:
2641                                 if len(cg.list) < 1 or cg.invalid or (cg.end - cg.start == 0):
2642                                         continue
2643                                 if(not cg.postProcess()):
2644                                         id = 'task %s cpu %s' % (pid, m.group('cpu'))
2645                                         sysvals.vprint('Sanity check failed for '+\
2646                                                 id+', ignoring this callback')
2647                                         continue
2648                                 callstart = cg.start
2649                                 callend = cg.end
2650                                 for p in test.data.sortedPhases():
2651                                         if(test.data.dmesg[p]['start'] <= callstart and
2652                                                 callstart <= test.data.dmesg[p]['end']):
2653                                                 list = test.data.dmesg[p]['list']
2654                                                 for devname in list:
2655                                                         dev = list[devname]
2656                                                         if(pid == dev['pid'] and
2657                                                                 callstart <= dev['start'] and
2658                                                                 callend >= dev['end']):
2659                                                                 dev['ftrace'] = cg
2660                                                 break
2661
2662 # Function: parseTraceLog
2663 # Description:
2664 #        Analyze an ftrace log output file generated from this app during
2665 #        the execution phase. Used when the ftrace log is the primary data source
2666 #        and includes the suspend_resume and device_pm_callback trace events
2667 #        The ftrace filename is taken from sysvals
2668 # Output:
2669 #        An array of Data objects
2670 def parseTraceLog(live=False):
2671         sysvals.vprint('Analyzing the ftrace data (%s)...' % \
2672                 os.path.basename(sysvals.ftracefile))
2673         if(os.path.exists(sysvals.ftracefile) == False):
2674                 doError('%s does not exist' % sysvals.ftracefile)
2675         if not live:
2676                 sysvals.setupAllKprobes()
2677         ksuscalls = ['pm_prepare_console']
2678         krescalls = ['pm_restore_console']
2679         tracewatch = []
2680         if sysvals.usekprobes:
2681                 tracewatch += ['sync_filesystems', 'freeze_processes', 'syscore_suspend',
2682                         'syscore_resume', 'resume_console', 'thaw_processes', 'CPU_ON',
2683                         'CPU_OFF', 'timekeeping_freeze', 'acpi_suspend']
2684
2685         # extract the callgraph and traceevent data
2686         tp = TestProps()
2687         testruns = []
2688         testdata = []
2689         testrun = 0
2690         data = 0
2691         tf = sysvals.openlog(sysvals.ftracefile, 'r')
2692         phase = 'suspend_prepare'
2693         for line in tf:
2694                 # remove any latent carriage returns
2695                 line = line.replace('\r\n', '')
2696                 # stamp and sysinfo lines
2697                 if re.match(tp.stampfmt, line):
2698                         tp.stamp = line
2699                         continue
2700                 elif re.match(tp.sysinfofmt, line):
2701                         tp.sysinfo = line
2702                         continue
2703                 elif re.match(tp.cmdlinefmt, line):
2704                         tp.cmdline = line
2705                         continue
2706                 elif re.match(tp.batteryfmt, line):
2707                         tp.battery.append(line)
2708                         continue
2709                 elif re.match(tp.testerrfmt, line):
2710                         tp.testerror.append(line)
2711                         continue
2712                 # firmware line: pull out any firmware data
2713                 m = re.match(tp.firmwarefmt, line)
2714                 if(m):
2715                         tp.fwdata.append((int(m.group('s')), int(m.group('r'))))
2716                         continue
2717                 # tracer type line: determine the trace data type
2718                 m = re.match(tp.tracertypefmt, line)
2719                 if(m):
2720                         tp.setTracerType(m.group('t'))
2721                         continue
2722                 # device properties line
2723                 if(re.match(tp.devpropfmt, line)):
2724                         devProps(line)
2725                         continue
2726                 # ignore all other commented lines
2727                 if line[0] == '#':
2728                         continue
2729                 # ftrace line: parse only valid lines
2730                 m = re.match(tp.ftrace_line_fmt, line)
2731                 if(not m):
2732                         continue
2733                 # gather the basic message data from the line
2734                 m_time = m.group('time')
2735                 m_proc = m.group('proc')
2736                 m_pid = m.group('pid')
2737                 m_msg = m.group('msg')
2738                 if(tp.cgformat):
2739                         m_param3 = m.group('dur')
2740                 else:
2741                         m_param3 = 'traceevent'
2742                 if(m_time and m_pid and m_msg):
2743                         t = FTraceLine(m_time, m_msg, m_param3)
2744                         pid = int(m_pid)
2745                 else:
2746                         continue
2747                 # the line should be a call, return, or event
2748                 if(not t.fcall and not t.freturn and not t.fevent):
2749                         continue
2750                 # find the start of suspend
2751                 if(t.startMarker()):
2752                         data = Data(len(testdata))
2753                         testdata.append(data)
2754                         testrun = TestRun(data)
2755                         testruns.append(testrun)
2756                         tp.parseStamp(data, sysvals)
2757                         data.setStart(t.time)
2758                         data.first_suspend_prepare = True
2759                         phase = data.setPhase('suspend_prepare', t.time, True)
2760                         continue
2761                 if(not data):
2762                         continue
2763                 # process cpu exec line
2764                 if t.type == 'tracing_mark_write':
2765                         m = re.match(tp.procexecfmt, t.name)
2766                         if(m):
2767                                 proclist = dict()
2768                                 for ps in m.group('ps').split(','):
2769                                         val = ps.split()
2770                                         if not val:
2771                                                 continue
2772                                         name = val[0].replace('--', '-')
2773                                         proclist[name] = int(val[1])
2774                                 data.pstl[t.time] = proclist
2775                                 continue
2776                 # find the end of resume
2777                 if(t.endMarker()):
2778                         data.handleEndMarker(t.time)
2779                         if(not sysvals.usetracemarkers):
2780                                 # no trace markers? then quit and be sure to finish recording
2781                                 # the event we used to trigger resume end
2782                                 if('thaw_processes' in testrun.ttemp and len(testrun.ttemp['thaw_processes']) > 0):
2783                                         # if an entry exists, assume this is its end
2784                                         testrun.ttemp['thaw_processes'][-1]['end'] = t.time
2785                                 break
2786                         continue
2787                 # trace event processing
2788                 if(t.fevent):
2789                         if(t.type == 'suspend_resume'):
2790                                 # suspend_resume trace events have two types, begin and end
2791                                 if(re.match('(?P<name>.*) begin$', t.name)):
2792                                         isbegin = True
2793                                 elif(re.match('(?P<name>.*) end$', t.name)):
2794                                         isbegin = False
2795                                 else:
2796                                         continue
2797                                 m = re.match('(?P<name>.*)\[(?P<val>[0-9]*)\] .*', t.name)
2798                                 if(m):
2799                                         val = m.group('val')
2800                                         if val == '0':
2801                                                 name = m.group('name')
2802                                         else:
2803                                                 name = m.group('name')+'['+val+']'
2804                                 else:
2805                                         m = re.match('(?P<name>.*) .*', t.name)
2806                                         name = m.group('name')
2807                                 # ignore these events
2808                                 if(name.split('[')[0] in tracewatch):
2809                                         continue
2810                                 # -- phase changes --
2811                                 # start of kernel suspend
2812                                 if(re.match('suspend_enter\[.*', t.name)):
2813                                         if(isbegin):
2814                                                 data.tKernSus = t.time
2815                                         continue
2816                                 # suspend_prepare start
2817                                 elif(re.match('dpm_prepare\[.*', t.name)):
2818                                         if isbegin and data.first_suspend_prepare:
2819                                                 data.first_suspend_prepare = False
2820                                                 if data.tKernSus == 0:
2821                                                         data.tKernSus = t.time
2822                                                 continue
2823                                         phase = data.setPhase('suspend_prepare', t.time, isbegin)
2824                                         continue
2825                                 # suspend start
2826                                 elif(re.match('dpm_suspend\[.*', t.name)):
2827                                         phase = data.setPhase('suspend', t.time, isbegin)
2828                                         continue
2829                                 # suspend_late start
2830                                 elif(re.match('dpm_suspend_late\[.*', t.name)):
2831                                         phase = data.setPhase('suspend_late', t.time, isbegin)
2832                                         continue
2833                                 # suspend_noirq start
2834                                 elif(re.match('dpm_suspend_noirq\[.*', t.name)):
2835                                         phase = data.setPhase('suspend_noirq', t.time, isbegin)
2836                                         continue
2837                                 # suspend_machine/resume_machine
2838                                 elif(re.match('machine_suspend\[.*', t.name)):
2839                                         if(isbegin):
2840                                                 lp = data.lastPhase()
2841                                                 phase = data.setPhase('suspend_machine', data.dmesg[lp]['end'], True)
2842                                                 data.setPhase(phase, t.time, False)
2843                                                 if data.tSuspended == 0:
2844                                                         data.tSuspended = t.time
2845                                         else:
2846                                                 phase = data.setPhase('resume_machine', t.time, True)
2847                                                 if(sysvals.suspendmode in ['mem', 'disk']):
2848                                                         susp = phase.replace('resume', 'suspend')
2849                                                         if susp in data.dmesg:
2850                                                                 data.dmesg[susp]['end'] = t.time
2851                                                         data.tSuspended = t.time
2852                                                 data.tResumed = t.time
2853                                         continue
2854                                 # resume_noirq start
2855                                 elif(re.match('dpm_resume_noirq\[.*', t.name)):
2856                                         phase = data.setPhase('resume_noirq', t.time, isbegin)
2857                                         continue
2858                                 # resume_early start
2859                                 elif(re.match('dpm_resume_early\[.*', t.name)):
2860                                         phase = data.setPhase('resume_early', t.time, isbegin)
2861                                         continue
2862                                 # resume start
2863                                 elif(re.match('dpm_resume\[.*', t.name)):
2864                                         phase = data.setPhase('resume', t.time, isbegin)
2865                                         continue
2866                                 # resume complete start
2867                                 elif(re.match('dpm_complete\[.*', t.name)):
2868                                         phase = data.setPhase('resume_complete', t.time, isbegin)
2869                                         continue
2870                                 # skip trace events inside devices calls
2871                                 if(not data.isTraceEventOutsideDeviceCalls(pid, t.time)):
2872                                         continue
2873                                 # global events (outside device calls) are graphed
2874                                 if(name not in testrun.ttemp):
2875                                         testrun.ttemp[name] = []
2876                                 if(isbegin):
2877                                         # create a new list entry
2878                                         testrun.ttemp[name].append(\
2879                                                 {'begin': t.time, 'end': t.time, 'pid': pid})
2880                                 else:
2881                                         if(len(testrun.ttemp[name]) > 0):
2882                                                 # if an entry exists, assume this is its end
2883                                                 testrun.ttemp[name][-1]['end'] = t.time
2884                         # device callback start
2885                         elif(t.type == 'device_pm_callback_start'):
2886                                 if phase not in data.dmesg:
2887                                         continue
2888                                 m = re.match('(?P<drv>.*) (?P<d>.*), parent: *(?P<p>.*), .*',\
2889                                         t.name);
2890                                 if(not m):
2891                                         continue
2892                                 drv = m.group('drv')
2893                                 n = m.group('d')
2894                                 p = m.group('p')
2895                                 if(n and p):
2896                                         data.newAction(phase, n, pid, p, t.time, -1, drv)
2897                                         if pid not in data.devpids:
2898                                                 data.devpids.append(pid)
2899                         # device callback finish
2900                         elif(t.type == 'device_pm_callback_end'):
2901                                 if phase not in data.dmesg:
2902                                         continue
2903                                 m = re.match('(?P<drv>.*) (?P<d>.*), err.*', t.name);
2904                                 if(not m):
2905                                         continue
2906                                 n = m.group('d')
2907                                 list = data.dmesg[phase]['list']
2908                                 if(n in list):
2909                                         dev = list[n]
2910                                         dev['length'] = t.time - dev['start']
2911                                         dev['end'] = t.time
2912                 # kprobe event processing
2913                 elif(t.fkprobe):
2914                         kprobename = t.type
2915                         kprobedata = t.name
2916                         key = (kprobename, pid)
2917                         # displayname is generated from kprobe data
2918                         displayname = ''
2919                         if(t.fcall):
2920                                 displayname = sysvals.kprobeDisplayName(kprobename, kprobedata)
2921                                 if not displayname:
2922                                         continue
2923                                 if(key not in tp.ktemp):
2924                                         tp.ktemp[key] = []
2925                                 tp.ktemp[key].append({
2926                                         'pid': pid,
2927                                         'begin': t.time,
2928                                         'end': t.time,
2929                                         'name': displayname,
2930                                         'cdata': kprobedata,
2931                                         'proc': m_proc,
2932                                 })
2933                                 # start of kernel resume
2934                                 if(phase == 'suspend_prepare' and kprobename in ksuscalls):
2935                                         data.tKernSus = t.time
2936                         elif(t.freturn):
2937                                 if(key not in tp.ktemp) or len(tp.ktemp[key]) < 1:
2938                                         continue
2939                                 e = tp.ktemp[key][-1]
2940                                 if e['begin'] < 0.0 or t.time - e['begin'] < 0.000001:
2941                                         tp.ktemp[key].pop()
2942                                 else:
2943                                         e['end'] = t.time
2944                                         e['rdata'] = kprobedata
2945                                 # end of kernel resume
2946                                 if(phase != 'suspend_prepare' and kprobename in krescalls):
2947                                         if phase in data.dmesg:
2948                                                 data.dmesg[phase]['end'] = t.time
2949                                         data.tKernRes = t.time
2950
2951                 # callgraph processing
2952                 elif sysvals.usecallgraph:
2953                         # create a callgraph object for the data
2954                         key = (m_proc, pid)
2955                         if(key not in testrun.ftemp):
2956                                 testrun.ftemp[key] = []
2957                                 testrun.ftemp[key].append(FTraceCallGraph(pid, sysvals))
2958                         # when the call is finished, see which device matches it
2959                         cg = testrun.ftemp[key][-1]
2960                         res = cg.addLine(t)
2961                         if(res != 0):
2962                                 testrun.ftemp[key].append(FTraceCallGraph(pid, sysvals))
2963                         if(res == -1):
2964                                 testrun.ftemp[key][-1].addLine(t)
2965         tf.close()
2966         if data and not data.devicegroups:
2967                 sysvals.vprint('WARNING: end marker is missing')
2968                 data.handleEndMarker(t.time)
2969
2970         if sysvals.suspendmode == 'command':
2971                 for test in testruns:
2972                         for p in test.data.sortedPhases():
2973                                 if p == 'suspend_prepare':
2974                                         test.data.dmesg[p]['start'] = test.data.start
2975                                         test.data.dmesg[p]['end'] = test.data.end
2976                                 else:
2977                                         test.data.dmesg[p]['start'] = test.data.end
2978                                         test.data.dmesg[p]['end'] = test.data.end
2979                         test.data.tSuspended = test.data.end
2980                         test.data.tResumed = test.data.end
2981                         test.data.fwValid = False
2982
2983         # dev source and procmon events can be unreadable with mixed phase height
2984         if sysvals.usedevsrc or sysvals.useprocmon:
2985                 sysvals.mixedphaseheight = False
2986
2987         # expand phase boundaries so there are no gaps
2988         for data in testdata:
2989                 lp = data.sortedPhases()[0]
2990                 for p in data.sortedPhases():
2991                         if(p != lp and not ('machine' in p and 'machine' in lp)):
2992                                 data.dmesg[lp]['end'] = data.dmesg[p]['start']
2993                         lp = p
2994
2995         for i in range(len(testruns)):
2996                 test = testruns[i]
2997                 data = test.data
2998                 # find the total time range for this test (begin, end)
2999                 tlb, tle = data.start, data.end
3000                 if i < len(testruns) - 1:
3001                         tle = testruns[i+1].data.start
3002                 # add the process usage data to the timeline
3003                 if sysvals.useprocmon:
3004                         data.createProcessUsageEvents()
3005                 # add the traceevent data to the device hierarchy
3006                 if(sysvals.usetraceevents):
3007                         # add actual trace funcs
3008                         for name in test.ttemp:
3009                                 for event in test.ttemp[name]:
3010                                         data.newActionGlobal(name, event['begin'], event['end'], event['pid'])
3011                         # add the kprobe based virtual tracefuncs as actual devices
3012                         for key in tp.ktemp:
3013                                 name, pid = key
3014                                 if name not in sysvals.tracefuncs:
3015                                         continue
3016                                 for e in tp.ktemp[key]:
3017                                         kb, ke = e['begin'], e['end']
3018                                         if kb == ke or tlb > kb or tle <= kb:
3019                                                 continue
3020                                         color = sysvals.kprobeColor(name)
3021                                         data.newActionGlobal(e['name'], kb, ke, pid, color)
3022                         # add config base kprobes and dev kprobes
3023                         if sysvals.usedevsrc:
3024                                 for key in tp.ktemp:
3025                                         name, pid = key
3026                                         if name in sysvals.tracefuncs or name not in sysvals.dev_tracefuncs:
3027                                                 continue
3028                                         for e in tp.ktemp[key]:
3029                                                 kb, ke = e['begin'], e['end']
3030                                                 if kb == ke or tlb > kb or tle <= kb:
3031                                                         continue
3032                                                 data.addDeviceFunctionCall(e['name'], name, e['proc'], pid, kb,
3033                                                         ke, e['cdata'], e['rdata'])
3034                 if sysvals.usecallgraph:
3035                         # add the callgraph data to the device hierarchy
3036                         sortlist = dict()
3037                         for key in test.ftemp:
3038                                 proc, pid = key
3039                                 for cg in test.ftemp[key]:
3040                                         if len(cg.list) < 1 or cg.invalid or (cg.end - cg.start == 0):
3041                                                 continue
3042                                         if(not cg.postProcess()):
3043                                                 id = 'task %s' % (pid)
3044                                                 sysvals.vprint('Sanity check failed for '+\
3045                                                         id+', ignoring this callback')
3046                                                 continue
3047                                         # match cg data to devices
3048                                         devname = ''
3049                                         if sysvals.suspendmode != 'command':
3050                                                 devname = cg.deviceMatch(pid, data)
3051                                         if not devname:
3052                                                 sortkey = '%f%f%d' % (cg.start, cg.end, pid)
3053                                                 sortlist[sortkey] = cg
3054                                         elif len(cg.list) > 1000000:
3055                                                 sysvals.vprint('WARNING: the callgraph for %s is massive (%d lines)' %\
3056                                                         (devname, len(cg.list)))
3057                         # create blocks for orphan cg data
3058                         for sortkey in sorted(sortlist):
3059                                 cg = sortlist[sortkey]
3060                                 name = cg.name
3061                                 if sysvals.isCallgraphFunc(name):
3062                                         sysvals.vprint('Callgraph found for task %d: %.3fms, %s' % (cg.pid, (cg.end - cg.start)*1000, name))
3063                                         cg.newActionFromFunction(data)
3064         if sysvals.suspendmode == 'command':
3065                 return (testdata, '')
3066
3067         # fill in any missing phases
3068         error = []
3069         for data in testdata:
3070                 tn = '' if len(testdata) == 1 else ('%d' % (data.testnumber + 1))
3071                 terr = ''
3072                 phasedef = data.phasedef
3073                 lp = 'suspend_prepare'
3074                 for p in sorted(phasedef, key=lambda k:phasedef[k]['order']):
3075                         if p not in data.dmesg:
3076                                 if not terr:
3077                                         pprint('TEST%s FAILED: %s failed in %s phase' % (tn, sysvals.suspendmode, lp))
3078                                         terr = '%s%s failed in %s phase' % (sysvals.suspendmode, tn, lp)
3079                                         error.append(terr)
3080                                         if data.tSuspended == 0:
3081                                                 data.tSuspended = data.dmesg[lp]['end']
3082                                         if data.tResumed == 0:
3083                                                 data.tResumed = data.dmesg[lp]['end']
3084                                         data.fwValid = False
3085                                 sysvals.vprint('WARNING: phase "%s" is missing!' % p)
3086                         lp = p
3087                 if not terr and data.enterfail:
3088                         pprint('test%s FAILED: enter %s failed with %s' % (tn, sysvals.suspendmode, data.enterfail))
3089                         terr = 'test%s failed to enter %s mode' % (tn, sysvals.suspendmode)
3090                         error.append(terr)
3091                 if data.tSuspended == 0:
3092                         data.tSuspended = data.tKernRes
3093                 if data.tResumed == 0:
3094                         data.tResumed = data.tSuspended
3095
3096                 if(len(sysvals.devicefilter) > 0):
3097                         data.deviceFilter(sysvals.devicefilter)
3098                 data.fixupInitcallsThatDidntReturn()
3099                 if sysvals.usedevsrc:
3100                         data.optimizeDevSrc()
3101
3102         # x2: merge any overlapping devices between test runs
3103         if sysvals.usedevsrc and len(testdata) > 1:
3104                 tc = len(testdata)
3105                 for i in range(tc - 1):
3106                         devlist = testdata[i].overflowDevices()
3107                         for j in range(i + 1, tc):
3108                                 testdata[j].mergeOverlapDevices(devlist)
3109                 testdata[0].stitchTouchingThreads(testdata[1:])
3110         return (testdata, ', '.join(error))
3111
3112 # Function: loadKernelLog
3113 # Description:
3114 #        [deprecated for kernel 3.15.0 or newer]
3115 #        load the dmesg file into memory and fix up any ordering issues
3116 #        The dmesg filename is taken from sysvals
3117 # Output:
3118 #        An array of empty Data objects with only their dmesgtext attributes set
3119 def loadKernelLog():
3120         sysvals.vprint('Analyzing the dmesg data (%s)...' % \
3121                 os.path.basename(sysvals.dmesgfile))
3122         if(os.path.exists(sysvals.dmesgfile) == False):
3123                 doError('%s does not exist' % sysvals.dmesgfile)
3124
3125         # there can be multiple test runs in a single file
3126         tp = TestProps()
3127         tp.stamp = datetime.now().strftime('# suspend-%m%d%y-%H%M%S localhost mem unknown')
3128         testruns = []
3129         data = 0
3130         lf = sysvals.openlog(sysvals.dmesgfile, 'r')
3131         for line in lf:
3132                 line = line.replace('\r\n', '')
3133                 idx = line.find('[')
3134                 if idx > 1:
3135                         line = line[idx:]
3136                 # grab the stamp and sysinfo
3137                 if re.match(tp.stampfmt, line):
3138                         tp.stamp = line
3139                         continue
3140                 elif re.match(tp.sysinfofmt, line):
3141                         tp.sysinfo = line
3142                         continue
3143                 elif re.match(tp.cmdlinefmt, line):
3144                         tp.cmdline = line
3145                         continue
3146                 elif re.match(tp.batteryfmt, line):
3147                         tp.battery.append(line)
3148                         continue
3149                 elif re.match(tp.testerrfmt, line):
3150                         tp.testerror.append(line)
3151                         continue
3152                 m = re.match(tp.firmwarefmt, line)
3153                 if(m):
3154                         tp.fwdata.append((int(m.group('s')), int(m.group('r'))))
3155                         continue
3156                 m = re.match('[ \t]*(\[ *)(?P<ktime>[0-9\.]*)(\]) (?P<msg>.*)', line)
3157                 if(not m):
3158                         continue
3159                 msg = m.group("msg")
3160                 if(re.match('PM: Syncing filesystems.*', msg)):
3161                         if(data):
3162                                 testruns.append(data)
3163                         data = Data(len(testruns))
3164                         tp.parseStamp(data, sysvals)
3165                 if(not data):
3166                         continue
3167                 m = re.match('.* *(?P<k>[0-9]\.[0-9]{2}\.[0-9]-.*) .*', msg)
3168                 if(m):
3169                         sysvals.stamp['kernel'] = m.group('k')
3170                 m = re.match('PM: Preparing system for (?P<m>.*) sleep', msg)
3171                 if(m):
3172                         sysvals.stamp['mode'] = sysvals.suspendmode = m.group('m')
3173                 data.dmesgtext.append(line)
3174         lf.close()
3175
3176         if data:
3177                 testruns.append(data)
3178         if len(testruns) < 1:
3179                 pprint('ERROR: dmesg log has no suspend/resume data: %s' \
3180                         % sysvals.dmesgfile)
3181
3182         # fix lines with same timestamp/function with the call and return swapped
3183         for data in testruns:
3184                 last = ''
3185                 for line in data.dmesgtext:
3186                         mc = re.match('.*(\[ *)(?P<t>[0-9\.]*)(\]) calling  '+\
3187                                 '(?P<f>.*)\+ @ .*, parent: .*', line)
3188                         mr = re.match('.*(\[ *)(?P<t>[0-9\.]*)(\]) call '+\
3189                                 '(?P<f>.*)\+ returned .* after (?P<dt>.*) usecs', last)
3190                         if(mc and mr and (mc.group('t') == mr.group('t')) and
3191                                 (mc.group('f') == mr.group('f'))):
3192                                 i = data.dmesgtext.index(last)
3193                                 j = data.dmesgtext.index(line)
3194                                 data.dmesgtext[i] = line
3195                                 data.dmesgtext[j] = last
3196                         last = line
3197         return testruns
3198
3199 # Function: parseKernelLog
3200 # Description:
3201 #        [deprecated for kernel 3.15.0 or newer]
3202 #        Analyse a dmesg log output file generated from this app during
3203 #        the execution phase. Create a set of device structures in memory
3204 #        for subsequent formatting in the html output file
3205 #        This call is only for legacy support on kernels where the ftrace
3206 #        data lacks the suspend_resume or device_pm_callbacks trace events.
3207 # Arguments:
3208 #        data: an empty Data object (with dmesgtext) obtained from loadKernelLog
3209 # Output:
3210 #        The filled Data object
3211 def parseKernelLog(data):
3212         phase = 'suspend_runtime'
3213
3214         if(data.fwValid):
3215                 sysvals.vprint('Firmware Suspend = %u ns, Firmware Resume = %u ns' % \
3216                         (data.fwSuspend, data.fwResume))
3217
3218         # dmesg phase match table
3219         dm = {
3220                 'suspend_prepare': ['PM: Syncing filesystems.*'],
3221                         'suspend': ['PM: Entering [a-z]* sleep.*', 'Suspending console.*'],
3222                    'suspend_late': ['PM: suspend of devices complete after.*'],
3223                   'suspend_noirq': ['PM: late suspend of devices complete after.*'],
3224                 'suspend_machine': ['PM: noirq suspend of devices complete after.*'],
3225                  'resume_machine': ['ACPI: Low-level resume complete.*'],
3226                    'resume_noirq': ['ACPI: Waking up from system sleep state.*'],
3227                    'resume_early': ['PM: noirq resume of devices complete after.*'],
3228                          'resume': ['PM: early resume of devices complete after.*'],
3229                 'resume_complete': ['PM: resume of devices complete after.*'],
3230                     'post_resume': ['.*Restarting tasks \.\.\..*'],
3231         }
3232         if(sysvals.suspendmode == 'standby'):
3233                 dm['resume_machine'] = ['PM: Restoring platform NVS memory']
3234         elif(sysvals.suspendmode == 'disk'):
3235                 dm['suspend_late'] = ['PM: freeze of devices complete after.*']
3236                 dm['suspend_noirq'] = ['PM: late freeze of devices complete after.*']
3237                 dm['suspend_machine'] = ['PM: noirq freeze of devices complete after.*']
3238                 dm['resume_machine'] = ['PM: Restoring platform NVS memory']
3239                 dm['resume_early'] = ['PM: noirq restore of devices complete after.*']
3240                 dm['resume'] = ['PM: early restore of devices complete after.*']
3241                 dm['resume_complete'] = ['PM: restore of devices complete after.*']
3242         elif(sysvals.suspendmode == 'freeze'):
3243                 dm['resume_machine'] = ['ACPI: resume from mwait']
3244
3245         # action table (expected events that occur and show up in dmesg)
3246         at = {
3247                 'sync_filesystems': {
3248                         'smsg': 'PM: Syncing filesystems.*',
3249                         'emsg': 'PM: Preparing system for mem sleep.*' },
3250                 'freeze_user_processes': {
3251                         'smsg': 'Freezing user space processes .*',
3252                         'emsg': 'Freezing remaining freezable tasks.*' },
3253                 'freeze_tasks': {
3254                         'smsg': 'Freezing remaining freezable tasks.*',
3255                         'emsg': 'PM: Entering (?P<mode>[a-z,A-Z]*) sleep.*' },
3256                 'ACPI prepare': {
3257                         'smsg': 'ACPI: Preparing to enter system sleep state.*',
3258                         'emsg': 'PM: Saving platform NVS memory.*' },
3259                 'PM vns': {
3260                         'smsg': 'PM: Saving platform NVS memory.*',
3261                         'emsg': 'Disabling non-boot CPUs .*' },
3262         }
3263
3264         t0 = -1.0
3265         cpu_start = -1.0
3266         prevktime = -1.0
3267         actions = dict()
3268         for line in data.dmesgtext:
3269                 # parse each dmesg line into the time and message
3270                 m = re.match('[ \t]*(\[ *)(?P<ktime>[0-9\.]*)(\]) (?P<msg>.*)', line)
3271                 if(m):
3272                         val = m.group('ktime')
3273                         try:
3274                                 ktime = float(val)
3275                         except:
3276                                 continue
3277                         msg = m.group('msg')
3278                         # initialize data start to first line time
3279                         if t0 < 0:
3280                                 data.setStart(ktime)
3281                                 t0 = ktime
3282                 else:
3283                         continue
3284
3285                 # check for a phase change line
3286                 phasechange = False
3287                 for p in dm:
3288                         for s in dm[p]:
3289                                 if(re.match(s, msg)):
3290                                         phasechange, phase = True, p
3291                                         break
3292
3293                 # hack for determining resume_machine end for freeze
3294                 if(not sysvals.usetraceevents and sysvals.suspendmode == 'freeze' \
3295                         and phase == 'resume_machine' and \
3296                         re.match('calling  (?P<f>.*)\+ @ .*, parent: .*', msg)):
3297                         data.setPhase(phase, ktime, False)
3298                         phase = 'resume_noirq'
3299                         data.setPhase(phase, ktime, True)
3300
3301                 if phasechange:
3302                         if phase == 'suspend_prepare':
3303                                 data.setPhase(phase, ktime, True)
3304                                 data.setStart(ktime)
3305                                 data.tKernSus = ktime
3306                         elif phase == 'suspend':
3307                                 lp = data.lastPhase()
3308                                 if lp:
3309                                         data.setPhase(lp, ktime, False)
3310                                 data.setPhase(phase, ktime, True)
3311                         elif phase == 'suspend_late':
3312                                 lp = data.lastPhase()
3313                                 if lp:
3314                                         data.setPhase(lp, ktime, False)
3315                                 data.setPhase(phase, ktime, True)
3316                         elif phase == 'suspend_noirq':
3317                                 lp = data.lastPhase()
3318                                 if lp:
3319                                         data.setPhase(lp, ktime, False)
3320                                 data.setPhase(phase, ktime, True)
3321                         elif phase == 'suspend_machine':
3322                                 lp = data.lastPhase()
3323                                 if lp:
3324                                         data.setPhase(lp, ktime, False)
3325                                 data.setPhase(phase, ktime, True)
3326                         elif phase == 'resume_machine':
3327                                 lp = data.lastPhase()
3328                                 if(sysvals.suspendmode in ['freeze', 'standby']):
3329                                         data.tSuspended = prevktime
3330                                         if lp:
3331                                                 data.setPhase(lp, prevktime, False)
3332                                 else:
3333                                         data.tSuspended = ktime
3334                                         if lp:
3335                                                 data.setPhase(lp, prevktime, False)
3336                                 data.tResumed = ktime
3337                                 data.setPhase(phase, ktime, True)
3338                         elif phase == 'resume_noirq':
3339                                 lp = data.lastPhase()
3340                                 if lp:
3341                                         data.setPhase(lp, ktime, False)
3342                                 data.setPhase(phase, ktime, True)
3343                         elif phase == 'resume_early':
3344                                 lp = data.lastPhase()
3345                                 if lp:
3346                                         data.setPhase(lp, ktime, False)
3347                                 data.setPhase(phase, ktime, True)
3348                         elif phase == 'resume':
3349                                 lp = data.lastPhase()
3350                                 if lp:
3351                                         data.setPhase(lp, ktime, False)
3352                                 data.setPhase(phase, ktime, True)
3353                         elif phase == 'resume_complete':
3354                                 lp = data.lastPhase()
3355                                 if lp:
3356                                         data.setPhase(lp, ktime, False)
3357                                 data.setPhase(phase, ktime, True)
3358                         elif phase == 'post_resume':
3359                                 lp = data.lastPhase()
3360                                 if lp:
3361                                         data.setPhase(lp, ktime, False)
3362                                 data.setEnd(ktime)
3363                                 data.tKernRes = ktime
3364                                 break
3365
3366                 # -- device callbacks --
3367                 if(phase in data.sortedPhases()):
3368                         # device init call
3369                         if(re.match('calling  (?P<f>.*)\+ @ .*, parent: .*', msg)):
3370                                 sm = re.match('calling  (?P<f>.*)\+ @ '+\
3371                                         '(?P<n>.*), parent: (?P<p>.*)', msg);
3372                                 f = sm.group('f')
3373                                 n = sm.group('n')
3374                                 p = sm.group('p')
3375                                 if(f and n and p):
3376                                         data.newAction(phase, f, int(n), p, ktime, -1, '')
3377                         # device init return
3378                         elif(re.match('call (?P<f>.*)\+ returned .* after '+\
3379                                 '(?P<t>.*) usecs', msg)):
3380                                 sm = re.match('call (?P<f>.*)\+ returned .* after '+\
3381                                         '(?P<t>.*) usecs(?P<a>.*)', msg);
3382                                 f = sm.group('f')
3383                                 t = sm.group('t')
3384                                 list = data.dmesg[phase]['list']
3385                                 if(f in list):
3386                                         dev = list[f]
3387                                         dev['length'] = int(t)
3388                                         dev['end'] = ktime
3389
3390                 # if trace events are not available, these are better than nothing
3391                 if(not sysvals.usetraceevents):
3392                         # look for known actions
3393                         for a in at:
3394                                 if(re.match(at[a]['smsg'], msg)):
3395                                         if(a not in actions):
3396                                                 actions[a] = []
3397                                         actions[a].append({'begin': ktime, 'end': ktime})
3398                                 if(re.match(at[a]['emsg'], msg)):
3399                                         if(a in actions):
3400                                                 actions[a][-1]['end'] = ktime
3401                         # now look for CPU on/off events
3402                         if(re.match('Disabling non-boot CPUs .*', msg)):
3403                                 # start of first cpu suspend
3404                                 cpu_start = ktime
3405                         elif(re.match('Enabling non-boot CPUs .*', msg)):
3406                                 # start of first cpu resume
3407                                 cpu_start = ktime
3408                         elif(re.match('smpboot: CPU (?P<cpu>[0-9]*) is now offline', msg)):
3409                                 # end of a cpu suspend, start of the next
3410                                 m = re.match('smpboot: CPU (?P<cpu>[0-9]*) is now offline', msg)
3411                                 cpu = 'CPU'+m.group('cpu')
3412                                 if(cpu not in actions):
3413                                         actions[cpu] = []
3414                                 actions[cpu].append({'begin': cpu_start, 'end': ktime})
3415                                 cpu_start = ktime
3416                         elif(re.match('CPU(?P<cpu>[0-9]*) is up', msg)):
3417                                 # end of a cpu resume, start of the next
3418                                 m = re.match('CPU(?P<cpu>[0-9]*) is up', msg)
3419                                 cpu = 'CPU'+m.group('cpu')
3420                                 if(cpu not in actions):
3421                                         actions[cpu] = []
3422                                 actions[cpu].append({'begin': cpu_start, 'end': ktime})
3423                                 cpu_start = ktime
3424                 prevktime = ktime
3425         data.initDevicegroups()
3426
3427         # fill in any missing phases
3428         phasedef = data.phasedef
3429         terr, lp = '', 'suspend_prepare'
3430         for p in sorted(phasedef, key=lambda k:phasedef[k]['order']):
3431                 if p not in data.dmesg:
3432                         if not terr:
3433                                 pprint('TEST FAILED: %s failed in %s phase' % (sysvals.suspendmode, lp))
3434                                 terr = '%s failed in %s phase' % (sysvals.suspendmode, lp)
3435                                 if data.tSuspended == 0:
3436                                         data.tSuspended = data.dmesg[lp]['end']
3437                                 if data.tResumed == 0:
3438                                         data.tResumed = data.dmesg[lp]['end']
3439                         sysvals.vprint('WARNING: phase "%s" is missing!' % p)
3440                 lp = p
3441         lp = data.sortedPhases()[0]
3442         for p in data.sortedPhases():
3443                 if(p != lp and not ('machine' in p and 'machine' in lp)):
3444                         data.dmesg[lp]['end'] = data.dmesg[p]['start']
3445                 lp = p
3446         if data.tSuspended == 0:
3447                 data.tSuspended = data.tKernRes
3448         if data.tResumed == 0:
3449                 data.tResumed = data.tSuspended
3450
3451         # fill in any actions we've found
3452         for name in actions:
3453                 for event in actions[name]:
3454                         data.newActionGlobal(name, event['begin'], event['end'])
3455
3456         if(len(sysvals.devicefilter) > 0):
3457                 data.deviceFilter(sysvals.devicefilter)
3458         data.fixupInitcallsThatDidntReturn()
3459         return True
3460
3461 def callgraphHTML(sv, hf, num, cg, title, color, devid):
3462         html_func_top = '<article id="{0}" class="atop" style="background:{1}">\n<input type="checkbox" class="pf" id="f{2}" checked/><label for="f{2}">{3} {4}</label>\n'
3463         html_func_start = '<article>\n<input type="checkbox" class="pf" id="f{0}" checked/><label for="f{0}">{1} {2}</label>\n'
3464         html_func_end = '</article>\n'
3465         html_func_leaf = '<article>{0} {1}</article>\n'
3466
3467         cgid = devid
3468         if cg.id:
3469                 cgid += cg.id
3470         cglen = (cg.end - cg.start) * 1000
3471         if cglen < sv.mincglen:
3472                 return num
3473
3474         fmt = '<r>(%.3f ms @ '+sv.timeformat+' to '+sv.timeformat+')</r>'
3475         flen = fmt % (cglen, cg.start, cg.end)
3476         hf.write(html_func_top.format(cgid, color, num, title, flen))
3477         num += 1
3478         for line in cg.list:
3479                 if(line.length < 0.000000001):
3480                         flen = ''
3481                 else:
3482                         fmt = '<n>(%.3f ms @ '+sv.timeformat+')</n>'
3483                         flen = fmt % (line.length*1000, line.time)
3484                 if line.isLeaf():
3485                         hf.write(html_func_leaf.format(line.name, flen))
3486                 elif line.freturn:
3487                         hf.write(html_func_end)
3488                 else:
3489                         hf.write(html_func_start.format(num, line.name, flen))
3490                         num += 1
3491         hf.write(html_func_end)
3492         return num
3493
3494 def addCallgraphs(sv, hf, data):
3495         hf.write('<section id="callgraphs" class="callgraph">\n')
3496         # write out the ftrace data converted to html
3497         num = 0
3498         for p in data.sortedPhases():
3499                 if sv.cgphase and p != sv.cgphase:
3500                         continue
3501                 list = data.dmesg[p]['list']
3502                 for devname in data.sortedDevices(p):
3503                         if len(sv.cgfilter) > 0 and devname not in sv.cgfilter:
3504                                 continue
3505                         dev = list[devname]
3506                         color = 'white'
3507                         if 'color' in data.dmesg[p]:
3508                                 color = data.dmesg[p]['color']
3509                         if 'color' in dev:
3510                                 color = dev['color']
3511                         name = devname
3512                         if(devname in sv.devprops):
3513                                 name = sv.devprops[devname].altName(devname)
3514                         if sv.suspendmode in suspendmodename:
3515                                 name += ' '+p
3516                         if('ftrace' in dev):
3517                                 cg = dev['ftrace']
3518                                 num = callgraphHTML(sv, hf, num, cg,
3519                                         name, color, dev['id'])
3520                         if('ftraces' in dev):
3521                                 for cg in dev['ftraces']:
3522                                         num = callgraphHTML(sv, hf, num, cg,
3523                                                 name+' &rarr; '+cg.name, color, dev['id'])
3524         hf.write('\n\n    </section>\n')
3525
3526 # Function: createHTMLSummarySimple
3527 # Description:
3528 #        Create summary html file for a series of tests
3529 # Arguments:
3530 #        testruns: array of Data objects from parseTraceLog
3531 def createHTMLSummarySimple(testruns, htmlfile, title):
3532         # write the html header first (html head, css code, up to body start)
3533         html = '<!DOCTYPE html>\n<html>\n<head>\n\
3534         <meta http-equiv="content-type" content="text/html; charset=UTF-8">\n\
3535         <title>SleepGraph Summary</title>\n\
3536         <style type=\'text/css\'>\n\
3537                 .stamp {width: 100%;text-align:center;background:#888;line-height:30px;color:white;font: 25px Arial;}\n\
3538                 table {width:100%;border-collapse: collapse;}\n\
3539                 .summary {border:1px solid;}\n\
3540                 th {border: 1px solid black;background:#222;color:white;}\n\
3541                 td {font: 14px "Times New Roman";text-align: center;}\n\
3542                 tr.head td {border: 1px solid black;background:#aaa;}\n\
3543                 tr.alt {background-color:#ddd;}\n\
3544                 tr.notice {color:red;}\n\
3545                 .minval {background-color:#BBFFBB;}\n\
3546                 .medval {background-color:#BBBBFF;}\n\
3547                 .maxval {background-color:#FFBBBB;}\n\
3548                 .head a {color:#000;text-decoration: none;}\n\
3549         </style>\n</head>\n<body>\n'
3550
3551         # extract the test data into list
3552         list = dict()
3553         tAvg, tMin, tMax, tMed = [0.0, 0.0], [0.0, 0.0], [0.0, 0.0], [[], []]
3554         iMin, iMed, iMax = [0, 0], [0, 0], [0, 0]
3555         num = 0
3556         lastmode = ''
3557         cnt = dict()
3558         for data in sorted(testruns, key=lambda v:(v['mode'], v['host'], v['kernel'], v['time'])):
3559                 mode = data['mode']
3560                 if mode not in list:
3561                         list[mode] = {'data': [], 'avg': [0,0], 'min': [0,0], 'max': [0,0], 'med': [0,0]}
3562                 if lastmode and lastmode != mode and num > 0:
3563                         for i in range(2):
3564                                 s = sorted(tMed[i])
3565                                 list[lastmode]['med'][i] = s[int(len(s)/2)]
3566                                 iMed[i] = tMed[i].index(list[lastmode]['med'][i])
3567                         list[lastmode]['avg'] = [tAvg[0] / num, tAvg[1] / num]
3568                         list[lastmode]['min'] = tMin
3569                         list[lastmode]['max'] = tMax
3570                         list[lastmode]['idx'] = (iMin, iMed, iMax)
3571                         tAvg, tMin, tMax, tMed = [0.0, 0.0], [0.0, 0.0], [0.0, 0.0], [[], []]
3572                         iMin, iMed, iMax = [0, 0], [0, 0], [0, 0]
3573                         num = 0
3574                 tVal = [float(data['suspend']), float(data['resume'])]
3575                 list[mode]['data'].append([data['host'], data['kernel'],
3576                         data['time'], tVal[0], tVal[1], data['url'], data['result'],
3577                         data['issues'], data['sus_worst'], data['sus_worsttime'],
3578                         data['res_worst'], data['res_worsttime']])
3579                 idx = len(list[mode]['data']) - 1
3580                 if data['result'] not in cnt:
3581                         cnt[data['result']] = 1
3582                 else:
3583                         cnt[data['result']] += 1
3584                 if data['result'] == 'pass':
3585                         for i in range(2):
3586                                 tMed[i].append(tVal[i])
3587                                 tAvg[i] += tVal[i]
3588                                 if tMin[i] == 0 or tVal[i] < tMin[i]:
3589                                         iMin[i] = idx
3590                                         tMin[i] = tVal[i]
3591                                 if tMax[i] == 0 or tVal[i] > tMax[i]:
3592                                         iMax[i] = idx
3593                                         tMax[i] = tVal[i]
3594                         num += 1
3595                 lastmode = mode
3596         if lastmode and num > 0:
3597                 for i in range(2):
3598                         s = sorted(tMed[i])
3599                         list[lastmode]['med'][i] = s[int(len(s)/2)]
3600                         iMed[i] = tMed[i].index(list[lastmode]['med'][i])
3601                 list[lastmode]['avg'] = [tAvg[0] / num, tAvg[1] / num]
3602                 list[lastmode]['min'] = tMin
3603                 list[lastmode]['max'] = tMax
3604                 list[lastmode]['idx'] = (iMin, iMed, iMax)
3605
3606         # group test header
3607         desc = []
3608         for ilk in sorted(cnt, reverse=True):
3609                 if cnt[ilk] > 0:
3610                         desc.append('%d %s' % (cnt[ilk], ilk))
3611         html += '<div class="stamp">%s (%d tests: %s)</div>\n' % (title, len(testruns), ', '.join(desc))
3612         th = '\t<th>{0}</th>\n'
3613         td = '\t<td>{0}</td>\n'
3614         tdh = '\t<td{1}>{0}</td>\n'
3615         tdlink = '\t<td><a href="{0}">html</a></td>\n'
3616
3617         # table header
3618         html += '<table class="summary">\n<tr>\n' + th.format('#') +\
3619                 th.format('Mode') + th.format('Host') + th.format('Kernel') +\
3620                 th.format('Test Time') + th.format('Result') + th.format('Issues') +\
3621                 th.format('Suspend') + th.format('Resume') +\
3622                 th.format('Worst Suspend Device') + th.format('SD Time') +\
3623                 th.format('Worst Resume Device') + th.format('RD Time') +\
3624                 th.format('Detail') + '</tr>\n'
3625
3626         # export list into html
3627         head = '<tr class="head"><td>{0}</td><td>{1}</td>'+\
3628                 '<td colspan=12 class="sus">Suspend Avg={2} '+\
3629                 '<span class=minval><a href="#s{10}min">Min={3}</a></span> '+\
3630                 '<span class=medval><a href="#s{10}med">Med={4}</a></span> '+\
3631                 '<span class=maxval><a href="#s{10}max">Max={5}</a></span> '+\
3632                 'Resume Avg={6} '+\
3633                 '<span class=minval><a href="#r{10}min">Min={7}</a></span> '+\
3634                 '<span class=medval><a href="#r{10}med">Med={8}</a></span> '+\
3635                 '<span class=maxval><a href="#r{10}max">Max={9}</a></span></td>'+\
3636                 '</tr>\n'
3637         headnone = '<tr class="head"><td>{0}</td><td>{1}</td><td colspan=12></td></tr>\n'
3638         for mode in list:
3639                 # header line for each suspend mode
3640                 num = 0
3641                 tAvg, tMin, tMax, tMed = list[mode]['avg'], list[mode]['min'],\
3642                         list[mode]['max'], list[mode]['med']
3643                 count = len(list[mode]['data'])
3644                 if 'idx' in list[mode]:
3645                         iMin, iMed, iMax = list[mode]['idx']
3646                         html += head.format('%d' % count, mode.upper(),
3647                                 '%.3f' % tAvg[0], '%.3f' % tMin[0], '%.3f' % tMed[0], '%.3f' % tMax[0],
3648                                 '%.3f' % tAvg[1], '%.3f' % tMin[1], '%.3f' % tMed[1], '%.3f' % tMax[1],
3649                                 mode.lower()
3650                         )
3651                 else:
3652                         iMin = iMed = iMax = [-1, -1, -1]
3653                         html += headnone.format('%d' % count, mode.upper())
3654                 for d in list[mode]['data']:
3655                         # row classes - alternate row color
3656                         rcls = ['alt'] if num % 2 == 1 else []
3657                         if d[6] != 'pass':
3658                                 rcls.append('notice')
3659                         html += '<tr class="'+(' '.join(rcls))+'">\n' if len(rcls) > 0 else '<tr>\n'
3660                         # figure out if the line has sus or res highlighted
3661                         idx = list[mode]['data'].index(d)
3662                         tHigh = ['', '']
3663                         for i in range(2):
3664                                 tag = 's%s' % mode if i == 0 else 'r%s' % mode
3665                                 if idx == iMin[i]:
3666                                         tHigh[i] = ' id="%smin" class=minval title="Minimum"' % tag
3667                                 elif idx == iMax[i]:
3668                                         tHigh[i] = ' id="%smax" class=maxval title="Maximum"' % tag
3669                                 elif idx == iMed[i]:
3670                                         tHigh[i] = ' id="%smed" class=medval title="Median"' % tag
3671                         html += td.format("%d" % (list[mode]['data'].index(d) + 1)) # row
3672                         html += td.format(mode)                                                                         # mode
3673                         html += td.format(d[0])                                                                         # host
3674                         html += td.format(d[1])                                                                         # kernel
3675                         html += td.format(d[2])                                                                         # time
3676                         html += td.format(d[6])                                                                         # result
3677                         html += td.format(d[7])                                                                         # issues
3678                         html += tdh.format('%.3f ms' % d[3], tHigh[0]) if d[3] else td.format('')       # suspend
3679                         html += tdh.format('%.3f ms' % d[4], tHigh[1]) if d[4] else td.format('')       # resume
3680                         html += td.format(d[8])                                                                         # sus_worst
3681                         html += td.format('%.3f ms' % d[9])     if d[9] else td.format('')              # sus_worst time
3682                         html += td.format(d[10])                                                                        # res_worst
3683                         html += td.format('%.3f ms' % d[11]) if d[11] else td.format('')        # res_worst time
3684                         html += tdlink.format(d[5]) if d[5] else td.format('')          # url
3685                         html += '</tr>\n'
3686                         num += 1
3687
3688         # flush the data to file
3689         hf = open(htmlfile, 'w')
3690         hf.write(html+'</table>\n</body>\n</html>\n')
3691         hf.close()
3692
3693 def ordinal(value):
3694         suffix = 'th'
3695         if value < 10 or value > 19:
3696                 if value % 10 == 1:
3697                         suffix = 'st'
3698                 elif value % 10 == 2:
3699                         suffix = 'nd'
3700                 elif value % 10 == 3:
3701                         suffix = 'rd'
3702         return '%d%s' % (value, suffix)
3703
3704 # Function: createHTML
3705 # Description:
3706 #        Create the output html file from the resident test data
3707 # Arguments:
3708 #        testruns: array of Data objects from parseKernelLog or parseTraceLog
3709 # Output:
3710 #        True if the html file was created, false if it failed
3711 def createHTML(testruns, testfail):
3712         if len(testruns) < 1:
3713                 pprint('ERROR: Not enough test data to build a timeline')
3714                 return
3715
3716         kerror = False
3717         for data in testruns:
3718                 if data.kerror:
3719                         kerror = True
3720                 if(sysvals.suspendmode in ['freeze', 'standby']):
3721                         data.trimFreezeTime(testruns[-1].tSuspended)
3722
3723         # html function templates
3724         html_error = '<div id="{1}" title="kernel error/warning" class="err" style="right:{0}%">{2}&rarr;</div>\n'
3725         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'
3726         html_cpuexec = '<div class="jiffie" style="left:{0}%;top:{1}px;height:{2}px;width:{3}%;background:{4};"></div>\n'
3727         html_timetotal = '<table class="time1">\n<tr>'\
3728                 '<td class="green" title="{3}">{2} Suspend Time: <b>{0} ms</b></td>'\
3729                 '<td class="yellow" title="{4}">{2} Resume Time: <b>{1} ms</b></td>'\
3730                 '</tr>\n</table>\n'
3731         html_timetotal2 = '<table class="time1">\n<tr>'\
3732                 '<td class="green" title="{4}">{3} Suspend Time: <b>{0} ms</b></td>'\
3733                 '<td class="gray" title="time spent in low-power mode with clock running">'+sysvals.suspendmode+' time: <b>{1} ms</b></td>'\
3734                 '<td class="yellow" title="{5}">{3} Resume Time: <b>{2} ms</b></td>'\
3735                 '</tr>\n</table>\n'
3736         html_timetotal3 = '<table class="time1">\n<tr>'\
3737                 '<td class="green">Execution Time: <b>{0} ms</b></td>'\
3738                 '<td class="yellow">Command: <b>{1}</b></td>'\
3739                 '</tr>\n</table>\n'
3740         html_timegroups = '<table class="time2">\n<tr>'\
3741                 '<td class="green" title="time from kernel enter_state({5}) to firmware mode [kernel time only]">{4}Kernel Suspend: {0} ms</td>'\
3742                 '<td class="purple">{4}Firmware Suspend: {1} ms</td>'\
3743                 '<td class="purple">{4}Firmware Resume: {2} ms</td>'\
3744                 '<td class="yellow" title="time from firmware mode to return from kernel enter_state({5}) [kernel time only]">{4}Kernel Resume: {3} ms</td>'\
3745                 '</tr>\n</table>\n'
3746         html_fail = '<table class="testfail"><tr><td>{0}</td></tr></table>\n'
3747
3748         # html format variables
3749         scaleH = 20
3750         if kerror:
3751                 scaleH = 40
3752
3753         # device timeline
3754         devtl = Timeline(30, scaleH)
3755
3756         # write the test title and general info header
3757         devtl.createHeader(sysvals, testruns[0].stamp)
3758
3759         # Generate the header for this timeline
3760         for data in testruns:
3761                 tTotal = data.end - data.start
3762                 sktime, rktime = data.getTimeValues()
3763                 if(tTotal == 0):
3764                         doError('No timeline data')
3765                 if(len(data.tLow) > 0):
3766                         low_time = '|'.join(data.tLow)
3767                 if sysvals.suspendmode == 'command':
3768                         run_time = '%.0f'%((data.end-data.start)*1000)
3769                         if sysvals.testcommand:
3770                                 testdesc = sysvals.testcommand
3771                         else:
3772                                 testdesc = 'unknown'
3773                         if(len(testruns) > 1):
3774                                 testdesc = ordinal(data.testnumber+1)+' '+testdesc
3775                         thtml = html_timetotal3.format(run_time, testdesc)
3776                         devtl.html += thtml
3777                 elif data.fwValid:
3778                         suspend_time = '%.0f'%(sktime + (data.fwSuspend/1000000.0))
3779                         resume_time = '%.0f'%(rktime + (data.fwResume/1000000.0))
3780                         testdesc1 = 'Total'
3781                         testdesc2 = ''
3782                         stitle = 'time from kernel enter_state(%s) to low-power mode [kernel & firmware time]' % sysvals.suspendmode
3783                         rtitle = 'time from low-power mode to return from kernel enter_state(%s) [firmware & kernel time]' % sysvals.suspendmode
3784                         if(len(testruns) > 1):
3785                                 testdesc1 = testdesc2 = ordinal(data.testnumber+1)
3786                                 testdesc2 += ' '
3787                         if(len(data.tLow) == 0):
3788                                 thtml = html_timetotal.format(suspend_time, \
3789                                         resume_time, testdesc1, stitle, rtitle)
3790                         else:
3791                                 thtml = html_timetotal2.format(suspend_time, low_time, \
3792                                         resume_time, testdesc1, stitle, rtitle)
3793                         devtl.html += thtml
3794                         sftime = '%.3f'%(data.fwSuspend / 1000000.0)
3795                         rftime = '%.3f'%(data.fwResume / 1000000.0)
3796                         devtl.html += html_timegroups.format('%.3f'%sktime, \
3797                                 sftime, rftime, '%.3f'%rktime, testdesc2, sysvals.suspendmode)
3798                 else:
3799                         suspend_time = '%.3f' % sktime
3800                         resume_time = '%.3f' % rktime
3801                         testdesc = 'Kernel'
3802                         stitle = 'time from kernel enter_state(%s) to firmware mode [kernel time only]' % sysvals.suspendmode
3803                         rtitle = 'time from firmware mode to return from kernel enter_state(%s) [kernel time only]' % sysvals.suspendmode
3804                         if(len(testruns) > 1):
3805                                 testdesc = ordinal(data.testnumber+1)+' '+testdesc
3806                         if(len(data.tLow) == 0):
3807                                 thtml = html_timetotal.format(suspend_time, \
3808                                         resume_time, testdesc, stitle, rtitle)
3809                         else:
3810                                 thtml = html_timetotal2.format(suspend_time, low_time, \
3811                                         resume_time, testdesc, stitle, rtitle)
3812                         devtl.html += thtml
3813
3814         if testfail:
3815                 devtl.html += html_fail.format(testfail)
3816
3817         # time scale for potentially multiple datasets
3818         t0 = testruns[0].start
3819         tMax = testruns[-1].end
3820         tTotal = tMax - t0
3821
3822         # determine the maximum number of rows we need to draw
3823         fulllist = []
3824         threadlist = []
3825         pscnt = 0
3826         devcnt = 0
3827         for data in testruns:
3828                 data.selectTimelineDevices('%f', tTotal, sysvals.mindevlen)
3829                 for group in data.devicegroups:
3830                         devlist = []
3831                         for phase in group:
3832                                 for devname in data.tdevlist[phase]:
3833                                         d = DevItem(data.testnumber, phase, data.dmesg[phase]['list'][devname])
3834                                         devlist.append(d)
3835                                         if d.isa('kth'):
3836                                                 threadlist.append(d)
3837                                         else:
3838                                                 if d.isa('ps'):
3839                                                         pscnt += 1
3840                                                 else:
3841                                                         devcnt += 1
3842                                                 fulllist.append(d)
3843                         if sysvals.mixedphaseheight:
3844                                 devtl.getPhaseRows(devlist)
3845         if not sysvals.mixedphaseheight:
3846                 if len(threadlist) > 0 and len(fulllist) > 0:
3847                         if pscnt > 0 and devcnt > 0:
3848                                 msg = 'user processes & device pm callbacks'
3849                         elif pscnt > 0:
3850                                 msg = 'user processes'
3851                         else:
3852                                 msg = 'device pm callbacks'
3853                         d = testruns[0].addHorizontalDivider(msg, testruns[-1].end)
3854                         fulllist.insert(0, d)
3855                 devtl.getPhaseRows(fulllist)
3856                 if len(threadlist) > 0:
3857                         d = testruns[0].addHorizontalDivider('asynchronous kernel threads', testruns[-1].end)
3858                         threadlist.insert(0, d)
3859                         devtl.getPhaseRows(threadlist, devtl.rows)
3860         devtl.calcTotalRows()
3861
3862         # draw the full timeline
3863         devtl.createZoomBox(sysvals.suspendmode, len(testruns))
3864         for data in testruns:
3865                 # draw each test run and block chronologically
3866                 phases = {'suspend':[],'resume':[]}
3867                 for phase in data.sortedPhases():
3868                         if data.dmesg[phase]['start'] >= data.tSuspended:
3869                                 phases['resume'].append(phase)
3870                         else:
3871                                 phases['suspend'].append(phase)
3872                 # now draw the actual timeline blocks
3873                 for dir in phases:
3874                         # draw suspend and resume blocks separately
3875                         bname = '%s%d' % (dir[0], data.testnumber)
3876                         if dir == 'suspend':
3877                                 m0 = data.start
3878                                 mMax = data.tSuspended
3879                                 left = '%f' % (((m0-t0)*100.0)/tTotal)
3880                         else:
3881                                 m0 = data.tSuspended
3882                                 mMax = data.end
3883                                 # in an x2 run, remove any gap between blocks
3884                                 if len(testruns) > 1 and data.testnumber == 0:
3885                                         mMax = testruns[1].start
3886                                 left = '%f' % ((((m0-t0)*100.0)+sysvals.srgap/2)/tTotal)
3887                         mTotal = mMax - m0
3888                         # if a timeline block is 0 length, skip altogether
3889                         if mTotal == 0:
3890                                 continue
3891                         width = '%f' % (((mTotal*100.0)-sysvals.srgap/2)/tTotal)
3892                         devtl.html += devtl.html_tblock.format(bname, left, width, devtl.scaleH)
3893                         for b in phases[dir]:
3894                                 # draw the phase color background
3895                                 phase = data.dmesg[b]
3896                                 length = phase['end']-phase['start']
3897                                 left = '%f' % (((phase['start']-m0)*100.0)/mTotal)
3898                                 width = '%f' % ((length*100.0)/mTotal)
3899                                 devtl.html += devtl.html_phase.format(left, width, \
3900                                         '%.3f'%devtl.scaleH, '%.3f'%devtl.bodyH, \
3901                                         data.dmesg[b]['color'], '')
3902                         for e in data.errorinfo[dir]:
3903                                 # draw red lines for any kernel errors found
3904                                 type, t, idx1, idx2 = e
3905                                 id = '%d_%d' % (idx1, idx2)
3906                                 right = '%f' % (((mMax-t)*100.0)/mTotal)
3907                                 devtl.html += html_error.format(right, id, type)
3908                         for b in phases[dir]:
3909                                 # draw the devices for this phase
3910                                 phaselist = data.dmesg[b]['list']
3911                                 for d in data.tdevlist[b]:
3912                                         name = d
3913                                         drv = ''
3914                                         dev = phaselist[d]
3915                                         xtraclass = ''
3916                                         xtrainfo = ''
3917                                         xtrastyle = ''
3918                                         if 'htmlclass' in dev:
3919                                                 xtraclass = dev['htmlclass']
3920                                         if 'color' in dev:
3921                                                 xtrastyle = 'background:%s;' % dev['color']
3922                                         if(d in sysvals.devprops):
3923                                                 name = sysvals.devprops[d].altName(d)
3924                                                 xtraclass = sysvals.devprops[d].xtraClass()
3925                                                 xtrainfo = sysvals.devprops[d].xtraInfo()
3926                                         elif xtraclass == ' kth':
3927                                                 xtrainfo = ' kernel_thread'
3928                                         if('drv' in dev and dev['drv']):
3929                                                 drv = ' {%s}' % dev['drv']
3930                                         rowheight = devtl.phaseRowHeight(data.testnumber, b, dev['row'])
3931                                         rowtop = devtl.phaseRowTop(data.testnumber, b, dev['row'])
3932                                         top = '%.3f' % (rowtop + devtl.scaleH)
3933                                         left = '%f' % (((dev['start']-m0)*100)/mTotal)
3934                                         width = '%f' % (((dev['end']-dev['start'])*100)/mTotal)
3935                                         length = ' (%0.3f ms) ' % ((dev['end']-dev['start'])*1000)
3936                                         title = name+drv+xtrainfo+length
3937                                         if sysvals.suspendmode == 'command':
3938                                                 title += sysvals.testcommand
3939                                         elif xtraclass == ' ps':
3940                                                 if 'suspend' in b:
3941                                                         title += 'pre_suspend_process'
3942                                                 else:
3943                                                         title += 'post_resume_process'
3944                                         else:
3945                                                 title += b
3946                                         devtl.html += devtl.html_device.format(dev['id'], \
3947                                                 title, left, top, '%.3f'%rowheight, width, \
3948                                                 d+drv, xtraclass, xtrastyle)
3949                                         if('cpuexec' in dev):
3950                                                 for t in sorted(dev['cpuexec']):
3951                                                         start, end = t
3952                                                         j = float(dev['cpuexec'][t]) / 5
3953                                                         if j > 1.0:
3954                                                                 j = 1.0
3955                                                         height = '%.3f' % (rowheight/3)
3956                                                         top = '%.3f' % (rowtop + devtl.scaleH + 2*rowheight/3)
3957                                                         left = '%f' % (((start-m0)*100)/mTotal)
3958                                                         width = '%f' % ((end-start)*100/mTotal)
3959                                                         color = 'rgba(255, 0, 0, %f)' % j
3960                                                         devtl.html += \
3961                                                                 html_cpuexec.format(left, top, height, width, color)
3962                                         if('src' not in dev):
3963                                                 continue
3964                                         # draw any trace events for this device
3965                                         for e in dev['src']:
3966                                                 height = '%.3f' % devtl.rowH
3967                                                 top = '%.3f' % (rowtop + devtl.scaleH + (e.row*devtl.rowH))
3968                                                 left = '%f' % (((e.time-m0)*100)/mTotal)
3969                                                 width = '%f' % (e.length*100/mTotal)
3970                                                 xtrastyle = ''
3971                                                 if e.color:
3972                                                         xtrastyle = 'background:%s;' % e.color
3973                                                 devtl.html += \
3974                                                         html_traceevent.format(e.title(), \
3975                                                                 left, top, height, width, e.text(), '', xtrastyle)
3976                         # draw the time scale, try to make the number of labels readable
3977                         devtl.createTimeScale(m0, mMax, tTotal, dir)
3978                         devtl.html += '</div>\n'
3979
3980         # timeline is finished
3981         devtl.html += '</div>\n</div>\n'
3982
3983         # draw a legend which describes the phases by color
3984         if sysvals.suspendmode != 'command':
3985                 phasedef = testruns[-1].phasedef
3986                 devtl.html += '<div class="legend">\n'
3987                 pdelta = 100.0/len(phasedef.keys())
3988                 pmargin = pdelta / 4.0
3989                 for phase in sorted(phasedef, key=lambda k:phasedef[k]['order']):
3990                         id, p = '', phasedef[phase]
3991                         for word in phase.split('_'):
3992                                 id += word[0]
3993                         order = '%.2f' % ((p['order'] * pdelta) + pmargin)
3994                         name = string.replace(phase, '_', ' &nbsp;')
3995                         devtl.html += devtl.html_legend.format(order, p['color'], name, id)
3996                 devtl.html += '</div>\n'
3997
3998         hf = open(sysvals.htmlfile, 'w')
3999         addCSS(hf, sysvals, len(testruns), kerror)
4000
4001         # write the device timeline
4002         hf.write(devtl.html)
4003         hf.write('<div id="devicedetailtitle"></div>\n')
4004         hf.write('<div id="devicedetail" style="display:none;">\n')
4005         # draw the colored boxes for the device detail section
4006         for data in testruns:
4007                 hf.write('<div id="devicedetail%d">\n' % data.testnumber)
4008                 pscolor = 'linear-gradient(to top left, #ccc, #eee)'
4009                 hf.write(devtl.html_phaselet.format('pre_suspend_process', \
4010                         '0', '0', pscolor))
4011                 for b in data.sortedPhases():
4012                         phase = data.dmesg[b]
4013                         length = phase['end']-phase['start']
4014                         left = '%.3f' % (((phase['start']-t0)*100.0)/tTotal)
4015                         width = '%.3f' % ((length*100.0)/tTotal)
4016                         hf.write(devtl.html_phaselet.format(b, left, width, \
4017                                 data.dmesg[b]['color']))
4018                 hf.write(devtl.html_phaselet.format('post_resume_process', \
4019                         '0', '0', pscolor))
4020                 if sysvals.suspendmode == 'command':
4021                         hf.write(devtl.html_phaselet.format('cmdexec', '0', '0', pscolor))
4022                 hf.write('</div>\n')
4023         hf.write('</div>\n')
4024
4025         # write the ftrace data (callgraph)
4026         if sysvals.cgtest >= 0 and len(testruns) > sysvals.cgtest:
4027                 data = testruns[sysvals.cgtest]
4028         else:
4029                 data = testruns[-1]
4030         if sysvals.usecallgraph:
4031                 addCallgraphs(sysvals, hf, data)
4032
4033         # add the test log as a hidden div
4034         if sysvals.testlog and sysvals.logmsg:
4035                 hf.write('<div id="testlog" style="display:none;">\n'+sysvals.logmsg+'</div>\n')
4036         # add the dmesg log as a hidden div
4037         if sysvals.dmesglog and sysvals.dmesgfile:
4038                 hf.write('<div id="dmesglog" style="display:none;">\n')
4039                 lf = sysvals.openlog(sysvals.dmesgfile, 'r')
4040                 for line in lf:
4041                         line = line.replace('<', '&lt').replace('>', '&gt')
4042                         hf.write(line)
4043                 lf.close()
4044                 hf.write('</div>\n')
4045         # add the ftrace log as a hidden div
4046         if sysvals.ftracelog and sysvals.ftracefile:
4047                 hf.write('<div id="ftracelog" style="display:none;">\n')
4048                 lf = sysvals.openlog(sysvals.ftracefile, 'r')
4049                 for line in lf:
4050                         hf.write(line)
4051                 lf.close()
4052                 hf.write('</div>\n')
4053
4054         # write the footer and close
4055         addScriptCode(hf, testruns)
4056         hf.write('</body>\n</html>\n')
4057         hf.close()
4058         return True
4059
4060 def addCSS(hf, sv, testcount=1, kerror=False, extra=''):
4061         kernel = sv.stamp['kernel']
4062         host = sv.hostname[0].upper()+sv.hostname[1:]
4063         mode = sv.suspendmode
4064         if sv.suspendmode in suspendmodename:
4065                 mode = suspendmodename[sv.suspendmode]
4066         title = host+' '+mode+' '+kernel
4067
4068         # various format changes by flags
4069         cgchk = 'checked'
4070         cgnchk = 'not(:checked)'
4071         if sv.cgexp:
4072                 cgchk = 'not(:checked)'
4073                 cgnchk = 'checked'
4074
4075         hoverZ = 'z-index:8;'
4076         if sv.usedevsrc:
4077                 hoverZ = ''
4078
4079         devlistpos = 'absolute'
4080         if testcount > 1:
4081                 devlistpos = 'relative'
4082
4083         scaleTH = 20
4084         if kerror:
4085                 scaleTH = 60
4086
4087         # write the html header first (html head, css code, up to body start)
4088         html_header = '<!DOCTYPE html>\n<html>\n<head>\n\
4089         <meta http-equiv="content-type" content="text/html; charset=UTF-8">\n\
4090         <title>'+title+'</title>\n\
4091         <style type=\'text/css\'>\n\
4092                 body {overflow-y:scroll;}\n\
4093                 .stamp {width:100%;text-align:center;background:gray;line-height:30px;color:white;font:25px Arial;}\n\
4094                 .stamp.sysinfo {font:10px Arial;}\n\
4095                 .callgraph {margin-top:30px;box-shadow:5px 5px 20px black;}\n\
4096                 .callgraph article * {padding-left:28px;}\n\
4097                 h1 {color:black;font:bold 30px Times;}\n\
4098                 t0 {color:black;font:bold 30px Times;}\n\
4099                 t1 {color:black;font:30px Times;}\n\
4100                 t2 {color:black;font:25px Times;}\n\
4101                 t3 {color:black;font:20px Times;white-space:nowrap;}\n\
4102                 t4 {color:black;font:bold 30px Times;line-height:60px;white-space:nowrap;}\n\
4103                 cS {font:bold 13px Times;}\n\
4104                 table {width:100%;}\n\
4105                 .gray {background:rgba(80,80,80,0.1);}\n\
4106                 .green {background:rgba(204,255,204,0.4);}\n\
4107                 .purple {background:rgba(128,0,128,0.2);}\n\
4108                 .yellow {background:rgba(255,255,204,0.4);}\n\
4109                 .blue {background:rgba(169,208,245,0.4);}\n\
4110                 .time1 {font:22px Arial;border:1px solid;}\n\
4111                 .time2 {font:15px Arial;border-bottom:1px solid;border-left:1px solid;border-right:1px solid;}\n\
4112                 .testfail {font:bold 22px Arial;color:red;border:1px dashed;}\n\
4113                 td {text-align:center;}\n\
4114                 r {color:#500000;font:15px Tahoma;}\n\
4115                 n {color:#505050;font:15px Tahoma;}\n\
4116                 .tdhl {color:red;}\n\
4117                 .hide {display:none;}\n\
4118                 .pf {display:none;}\n\
4119                 .pf:'+cgchk+' + label {background:url(\'data:image/svg+xml;utf,<?xml version="1.0" standalone="no"?><svg xmlns="http://www.w3.org/2000/svg" height="18" width="18" version="1.1"><circle cx="9" cy="9" r="8" stroke="black" stroke-width="1" fill="white"/><rect x="4" y="8" width="10" height="2" style="fill:black;stroke-width:0"/><rect x="8" y="4" width="2" height="10" style="fill:black;stroke-width:0"/></svg>\') no-repeat left center;}\n\
4120                 .pf:'+cgnchk+' ~ label {background:url(\'data:image/svg+xml;utf,<?xml version="1.0" standalone="no"?><svg xmlns="http://www.w3.org/2000/svg" height="18" width="18" version="1.1"><circle cx="9" cy="9" r="8" stroke="black" stroke-width="1" fill="white"/><rect x="4" y="8" width="10" height="2" style="fill:black;stroke-width:0"/></svg>\') no-repeat left center;}\n\
4121                 .pf:'+cgchk+' ~ *:not(:nth-child(2)) {display:none;}\n\
4122                 .zoombox {position:relative;width:100%;overflow-x:scroll;-webkit-user-select:none;-moz-user-select:none;user-select:none;}\n\
4123                 .timeline {position:relative;font-size:14px;cursor:pointer;width:100%; overflow:hidden;background:linear-gradient(#cccccc, white);}\n\
4124                 .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\
4125                 .thread.ps {border-radius:3px;background:linear-gradient(to top, #ccc, #eee);}\n\
4126                 .thread:hover {background:white;border:1px solid red;'+hoverZ+'}\n\
4127                 .thread.sec,.thread.sec:hover {background:black;border:0;color:white;line-height:15px;font-size:10px;}\n\
4128                 .hover {background:white;border:1px solid red;'+hoverZ+'}\n\
4129                 .hover.sync {background:white;}\n\
4130                 .hover.bg,.hover.kth,.hover.sync,.hover.ps {background:white;}\n\
4131                 .jiffie {position:absolute;pointer-events: none;z-index:8;}\n\
4132                 .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\
4133                 .traceevent:hover {color:white;font-weight:bold;border:1px solid white;}\n\
4134                 .phase {position:absolute;overflow:hidden;border:0px;text-align:center;}\n\
4135                 .phaselet {float:left;overflow:hidden;border:0px;text-align:center;min-height:100px;font-size:24px;}\n\
4136                 .t {position:absolute;line-height:'+('%d'%scaleTH)+'px;pointer-events:none;top:0;height:100%;border-right:1px solid black;z-index:6;}\n\
4137                 .err {position:absolute;top:0%;height:100%;border-right:3px solid red;color:red;font:bold 14px Times;line-height:18px;}\n\
4138                 .legend {position:relative; width:100%; height:40px; text-align:center;margin-bottom:20px}\n\
4139                 .legend .square {position:absolute;cursor:pointer;top:10px; width:0px;height:20px;border:1px solid;padding-left:20px;}\n\
4140                 button {height:40px;width:200px;margin-bottom:20px;margin-top:20px;font-size:24px;}\n\
4141                 .btnfmt {position:relative;float:right;height:25px;width:auto;margin-top:3px;margin-bottom:0;font-size:10px;text-align:center;}\n\
4142                 .devlist {position:'+devlistpos+';width:190px;}\n\
4143                 a:link {color:white;text-decoration:none;}\n\
4144                 a:visited {color:white;}\n\
4145                 a:hover {color:white;}\n\
4146                 a:active {color:white;}\n\
4147                 .version {position:relative;float:left;color:white;font-size:10px;line-height:30px;margin-left:10px;}\n\
4148                 #devicedetail {min-height:100px;box-shadow:5px 5px 20px black;}\n\
4149                 .tblock {position:absolute;height:100%;background:#ddd;}\n\
4150                 .tback {position:absolute;width:100%;background:linear-gradient(#ccc, #ddd);}\n\
4151                 .bg {z-index:1;}\n\
4152 '+extra+'\
4153         </style>\n</head>\n<body>\n'
4154         hf.write(html_header)
4155
4156 # Function: addScriptCode
4157 # Description:
4158 #        Adds the javascript code to the output html
4159 # Arguments:
4160 #        hf: the open html file pointer
4161 #        testruns: array of Data objects from parseKernelLog or parseTraceLog
4162 def addScriptCode(hf, testruns):
4163         t0 = testruns[0].start * 1000
4164         tMax = testruns[-1].end * 1000
4165         # create an array in javascript memory with the device details
4166         detail = '      var devtable = [];\n'
4167         for data in testruns:
4168                 topo = data.deviceTopology()
4169                 detail += '     devtable[%d] = "%s";\n' % (data.testnumber, topo)
4170         detail += '     var bounds = [%f,%f];\n' % (t0, tMax)
4171         # add the code which will manipulate the data in the browser
4172         script_code = \
4173         '<script type="text/javascript">\n'+detail+\
4174         '       var resolution = -1;\n'\
4175         '       var dragval = [0, 0];\n'\
4176         '       function redrawTimescale(t0, tMax, tS) {\n'\
4177         '               var rline = \'<div class="t" style="left:0;border-left:1px solid black;border-right:0;">\';\n'\
4178         '               var tTotal = tMax - t0;\n'\
4179         '               var list = document.getElementsByClassName("tblock");\n'\
4180         '               for (var i = 0; i < list.length; i++) {\n'\
4181         '                       var timescale = list[i].getElementsByClassName("timescale")[0];\n'\
4182         '                       var m0 = t0 + (tTotal*parseFloat(list[i].style.left)/100);\n'\
4183         '                       var mTotal = tTotal*parseFloat(list[i].style.width)/100;\n'\
4184         '                       var mMax = m0 + mTotal;\n'\
4185         '                       var html = "";\n'\
4186         '                       var divTotal = Math.floor(mTotal/tS) + 1;\n'\
4187         '                       if(divTotal > 1000) continue;\n'\
4188         '                       var divEdge = (mTotal - tS*(divTotal-1))*100/mTotal;\n'\
4189         '                       var pos = 0.0, val = 0.0;\n'\
4190         '                       for (var j = 0; j < divTotal; j++) {\n'\
4191         '                               var htmlline = "";\n'\
4192         '                               var mode = list[i].id[5];\n'\
4193         '                               if(mode == "s") {\n'\
4194         '                                       pos = 100 - (((j)*tS*100)/mTotal) - divEdge;\n'\
4195         '                                       val = (j-divTotal+1)*tS;\n'\
4196         '                                       if(j == divTotal - 1)\n'\
4197         '                                               htmlline = \'<div class="t" style="right:\'+pos+\'%"><cS>S&rarr;</cS></div>\';\n'\
4198         '                                       else\n'\
4199         '                                               htmlline = \'<div class="t" style="right:\'+pos+\'%">\'+val+\'ms</div>\';\n'\
4200         '                               } else {\n'\
4201         '                                       pos = 100 - (((j)*tS*100)/mTotal);\n'\
4202         '                                       val = (j)*tS;\n'\
4203         '                                       htmlline = \'<div class="t" style="right:\'+pos+\'%">\'+val+\'ms</div>\';\n'\
4204         '                                       if(j == 0)\n'\
4205         '                                               if(mode == "r")\n'\
4206         '                                                       htmlline = rline+"<cS>&larr;R</cS></div>";\n'\
4207         '                                               else\n'\
4208         '                                                       htmlline = rline+"<cS>0ms</div>";\n'\
4209         '                               }\n'\
4210         '                               html += htmlline;\n'\
4211         '                       }\n'\
4212         '                       timescale.innerHTML = html;\n'\
4213         '               }\n'\
4214         '       }\n'\
4215         '       function zoomTimeline() {\n'\
4216         '               var dmesg = document.getElementById("dmesg");\n'\
4217         '               var zoombox = document.getElementById("dmesgzoombox");\n'\
4218         '               var left = zoombox.scrollLeft;\n'\
4219         '               var val = parseFloat(dmesg.style.width);\n'\
4220         '               var newval = 100;\n'\
4221         '               var sh = window.outerWidth / 2;\n'\
4222         '               if(this.id == "zoomin") {\n'\
4223         '                       newval = val * 1.2;\n'\
4224         '                       if(newval > 910034) newval = 910034;\n'\
4225         '                       dmesg.style.width = newval+"%";\n'\
4226         '                       zoombox.scrollLeft = ((left + sh) * newval / val) - sh;\n'\
4227         '               } else if (this.id == "zoomout") {\n'\
4228         '                       newval = val / 1.2;\n'\
4229         '                       if(newval < 100) newval = 100;\n'\
4230         '                       dmesg.style.width = newval+"%";\n'\
4231         '                       zoombox.scrollLeft = ((left + sh) * newval / val) - sh;\n'\
4232         '               } else {\n'\
4233         '                       zoombox.scrollLeft = 0;\n'\
4234         '                       dmesg.style.width = "100%";\n'\
4235         '               }\n'\
4236         '               var tS = [10000, 5000, 2000, 1000, 500, 200, 100, 50, 20, 10, 5, 2, 1];\n'\
4237         '               var t0 = bounds[0];\n'\
4238         '               var tMax = bounds[1];\n'\
4239         '               var tTotal = tMax - t0;\n'\
4240         '               var wTotal = tTotal * 100.0 / newval;\n'\
4241         '               var idx = 7*window.innerWidth/1100;\n'\
4242         '               for(var i = 0; (i < tS.length)&&((wTotal / tS[i]) < idx); i++);\n'\
4243         '               if(i >= tS.length) i = tS.length - 1;\n'\
4244         '               if(tS[i] == resolution) return;\n'\
4245         '               resolution = tS[i];\n'\
4246         '               redrawTimescale(t0, tMax, tS[i]);\n'\
4247         '       }\n'\
4248         '       function deviceName(title) {\n'\
4249         '               var name = title.slice(0, title.indexOf(" ("));\n'\
4250         '               return name;\n'\
4251         '       }\n'\
4252         '       function deviceHover() {\n'\
4253         '               var name = deviceName(this.title);\n'\
4254         '               var dmesg = document.getElementById("dmesg");\n'\
4255         '               var dev = dmesg.getElementsByClassName("thread");\n'\
4256         '               var cpu = -1;\n'\
4257         '               if(name.match("CPU_ON\[[0-9]*\]"))\n'\
4258         '                       cpu = parseInt(name.slice(7));\n'\
4259         '               else if(name.match("CPU_OFF\[[0-9]*\]"))\n'\
4260         '                       cpu = parseInt(name.slice(8));\n'\
4261         '               for (var i = 0; i < dev.length; i++) {\n'\
4262         '                       dname = deviceName(dev[i].title);\n'\
4263         '                       var cname = dev[i].className.slice(dev[i].className.indexOf("thread"));\n'\
4264         '                       if((cpu >= 0 && dname.match("CPU_O[NF]*\\\[*"+cpu+"\\\]")) ||\n'\
4265         '                               (name == dname))\n'\
4266         '                       {\n'\
4267         '                               dev[i].className = "hover "+cname;\n'\
4268         '                       } else {\n'\
4269         '                               dev[i].className = cname;\n'\
4270         '                       }\n'\
4271         '               }\n'\
4272         '       }\n'\
4273         '       function deviceUnhover() {\n'\
4274         '               var dmesg = document.getElementById("dmesg");\n'\
4275         '               var dev = dmesg.getElementsByClassName("thread");\n'\
4276         '               for (var i = 0; i < dev.length; i++) {\n'\
4277         '                       dev[i].className = dev[i].className.slice(dev[i].className.indexOf("thread"));\n'\
4278         '               }\n'\
4279         '       }\n'\
4280         '       function deviceTitle(title, total, cpu) {\n'\
4281         '               var prefix = "Total";\n'\
4282         '               if(total.length > 3) {\n'\
4283         '                       prefix = "Average";\n'\
4284         '                       total[1] = (total[1]+total[3])/2;\n'\
4285         '                       total[2] = (total[2]+total[4])/2;\n'\
4286         '               }\n'\
4287         '               var devtitle = document.getElementById("devicedetailtitle");\n'\
4288         '               var name = deviceName(title);\n'\
4289         '               if(cpu >= 0) name = "CPU"+cpu;\n'\
4290         '               var driver = "";\n'\
4291         '               var tS = "<t2>(</t2>";\n'\
4292         '               var tR = "<t2>)</t2>";\n'\
4293         '               if(total[1] > 0)\n'\
4294         '                       tS = "<t2>("+prefix+" Suspend:</t2><t0> "+total[1].toFixed(3)+" ms</t0> ";\n'\
4295         '               if(total[2] > 0)\n'\
4296         '                       tR = " <t2>"+prefix+" Resume:</t2><t0> "+total[2].toFixed(3)+" ms<t2>)</t2></t0>";\n'\
4297         '               var s = title.indexOf("{");\n'\
4298         '               var e = title.indexOf("}");\n'\
4299         '               if((s >= 0) && (e >= 0))\n'\
4300         '                       driver = title.slice(s+1, e) + " <t1>@</t1> ";\n'\
4301         '               if(total[1] > 0 && total[2] > 0)\n'\
4302         '                       devtitle.innerHTML = "<t0>"+driver+name+"</t0> "+tS+tR;\n'\
4303         '               else\n'\
4304         '                       devtitle.innerHTML = "<t0>"+title+"</t0>";\n'\
4305         '               return name;\n'\
4306         '       }\n'\
4307         '       function deviceDetail() {\n'\
4308         '               var devinfo = document.getElementById("devicedetail");\n'\
4309         '               devinfo.style.display = "block";\n'\
4310         '               var name = deviceName(this.title);\n'\
4311         '               var cpu = -1;\n'\
4312         '               if(name.match("CPU_ON\[[0-9]*\]"))\n'\
4313         '                       cpu = parseInt(name.slice(7));\n'\
4314         '               else if(name.match("CPU_OFF\[[0-9]*\]"))\n'\
4315         '                       cpu = parseInt(name.slice(8));\n'\
4316         '               var dmesg = document.getElementById("dmesg");\n'\
4317         '               var dev = dmesg.getElementsByClassName("thread");\n'\
4318         '               var idlist = [];\n'\
4319         '               var pdata = [[]];\n'\
4320         '               if(document.getElementById("devicedetail1"))\n'\
4321         '                       pdata = [[], []];\n'\
4322         '               var pd = pdata[0];\n'\
4323         '               var total = [0.0, 0.0, 0.0];\n'\
4324         '               for (var i = 0; i < dev.length; i++) {\n'\
4325         '                       dname = deviceName(dev[i].title);\n'\
4326         '                       if((cpu >= 0 && dname.match("CPU_O[NF]*\\\[*"+cpu+"\\\]")) ||\n'\
4327         '                               (name == dname))\n'\
4328         '                       {\n'\
4329         '                               idlist[idlist.length] = dev[i].id;\n'\
4330         '                               var tidx = 1;\n'\
4331         '                               if(dev[i].id[0] == "a") {\n'\
4332         '                                       pd = pdata[0];\n'\
4333         '                               } else {\n'\
4334         '                                       if(pdata.length == 1) pdata[1] = [];\n'\
4335         '                                       if(total.length == 3) total[3]=total[4]=0.0;\n'\
4336         '                                       pd = pdata[1];\n'\
4337         '                                       tidx = 3;\n'\
4338         '                               }\n'\
4339         '                               var info = dev[i].title.split(" ");\n'\
4340         '                               var pname = info[info.length-1];\n'\
4341         '                               pd[pname] = parseFloat(info[info.length-3].slice(1));\n'\
4342         '                               total[0] += pd[pname];\n'\
4343         '                               if(pname.indexOf("suspend") >= 0)\n'\
4344         '                                       total[tidx] += pd[pname];\n'\
4345         '                               else\n'\
4346         '                                       total[tidx+1] += pd[pname];\n'\
4347         '                       }\n'\
4348         '               }\n'\
4349         '               var devname = deviceTitle(this.title, total, cpu);\n'\
4350         '               var left = 0.0;\n'\
4351         '               for (var t = 0; t < pdata.length; t++) {\n'\
4352         '                       pd = pdata[t];\n'\
4353         '                       devinfo = document.getElementById("devicedetail"+t);\n'\
4354         '                       var phases = devinfo.getElementsByClassName("phaselet");\n'\
4355         '                       for (var i = 0; i < phases.length; i++) {\n'\
4356         '                               if(phases[i].id in pd) {\n'\
4357         '                                       var w = 100.0*pd[phases[i].id]/total[0];\n'\
4358         '                                       var fs = 32;\n'\
4359         '                                       if(w < 8) fs = 4*w | 0;\n'\
4360         '                                       var fs2 = fs*3/4;\n'\
4361         '                                       phases[i].style.width = w+"%";\n'\
4362         '                                       phases[i].style.left = left+"%";\n'\
4363         '                                       phases[i].title = phases[i].id+" "+pd[phases[i].id]+" ms";\n'\
4364         '                                       left += w;\n'\
4365         '                                       var time = "<t4 style=\\"font-size:"+fs+"px\\">"+pd[phases[i].id]+" ms<br></t4>";\n'\
4366         '                                       var pname = "<t3 style=\\"font-size:"+fs2+"px\\">"+phases[i].id.replace(new RegExp("_", "g"), " ")+"</t3>";\n'\
4367         '                                       phases[i].innerHTML = time+pname;\n'\
4368         '                               } else {\n'\
4369         '                                       phases[i].style.width = "0%";\n'\
4370         '                                       phases[i].style.left = left+"%";\n'\
4371         '                               }\n'\
4372         '                       }\n'\
4373         '               }\n'\
4374         '               if(typeof devstats !== \'undefined\')\n'\
4375         '                       callDetail(this.id, this.title);\n'\
4376         '               var cglist = document.getElementById("callgraphs");\n'\
4377         '               if(!cglist) return;\n'\
4378         '               var cg = cglist.getElementsByClassName("atop");\n'\
4379         '               if(cg.length < 10) return;\n'\
4380         '               for (var i = 0; i < cg.length; i++) {\n'\
4381         '                       cgid = cg[i].id.split("x")[0]\n'\
4382         '                       if(idlist.indexOf(cgid) >= 0) {\n'\
4383         '                               cg[i].style.display = "block";\n'\
4384         '                       } else {\n'\
4385         '                               cg[i].style.display = "none";\n'\
4386         '                       }\n'\
4387         '               }\n'\
4388         '       }\n'\
4389         '       function callDetail(devid, devtitle) {\n'\
4390         '               if(!(devid in devstats) || devstats[devid].length < 1)\n'\
4391         '                       return;\n'\
4392         '               var list = devstats[devid];\n'\
4393         '               var tmp = devtitle.split(" ");\n'\
4394         '               var name = tmp[0], phase = tmp[tmp.length-1];\n'\
4395         '               var dd = document.getElementById(phase);\n'\
4396         '               var total = parseFloat(tmp[1].slice(1));\n'\
4397         '               var mlist = [];\n'\
4398         '               var maxlen = 0;\n'\
4399         '               var info = []\n'\
4400         '               for(var i in list) {\n'\
4401         '                       if(list[i][0] == "@") {\n'\
4402         '                               info = list[i].split("|");\n'\
4403         '                               continue;\n'\
4404         '                       }\n'\
4405         '                       var tmp = list[i].split("|");\n'\
4406         '                       var t = parseFloat(tmp[0]), f = tmp[1], c = parseInt(tmp[2]);\n'\
4407         '                       var p = (t*100.0/total).toFixed(2);\n'\
4408         '                       mlist[mlist.length] = [f, c, t.toFixed(2), p+"%"];\n'\
4409         '                       if(f.length > maxlen)\n'\
4410         '                               maxlen = f.length;\n'\
4411         '               }\n'\
4412         '               var pad = 5;\n'\
4413         '               if(mlist.length == 0) pad = 30;\n'\
4414         '               var html = \'<div style="padding-top:\'+pad+\'px"><t3> <b>\'+name+\':</b>\';\n'\
4415         '               if(info.length > 2)\n'\
4416         '                       html += " start=<b>"+info[1]+"</b>, end=<b>"+info[2]+"</b>";\n'\
4417         '               if(info.length > 3)\n'\
4418         '                       html += ", length<i>(w/o overhead)</i>=<b>"+info[3]+" ms</b>";\n'\
4419         '               if(info.length > 4)\n'\
4420         '                       html += ", return=<b>"+info[4]+"</b>";\n'\
4421         '               html += "</t3></div>";\n'\
4422         '               if(mlist.length > 0) {\n'\
4423         '                       html += \'<table class=fstat style="padding-top:\'+(maxlen*5)+\'px;"><tr><th>Function</th>\';\n'\
4424         '                       for(var i in mlist)\n'\
4425         '                               html += "<td class=vt>"+mlist[i][0]+"</td>";\n'\
4426         '                       html += "</tr><tr><th>Calls</th>";\n'\
4427         '                       for(var i in mlist)\n'\
4428         '                               html += "<td>"+mlist[i][1]+"</td>";\n'\
4429         '                       html += "</tr><tr><th>Time(ms)</th>";\n'\
4430         '                       for(var i in mlist)\n'\
4431         '                               html += "<td>"+mlist[i][2]+"</td>";\n'\
4432         '                       html += "</tr><tr><th>Percent</th>";\n'\
4433         '                       for(var i in mlist)\n'\
4434         '                               html += "<td>"+mlist[i][3]+"</td>";\n'\
4435         '                       html += "</tr></table>";\n'\
4436         '               }\n'\
4437         '               dd.innerHTML = html;\n'\
4438         '               var height = (maxlen*5)+100;\n'\
4439         '               dd.style.height = height+"px";\n'\
4440         '               document.getElementById("devicedetail").style.height = height+"px";\n'\
4441         '       }\n'\
4442         '       function callSelect() {\n'\
4443         '               var cglist = document.getElementById("callgraphs");\n'\
4444         '               if(!cglist) return;\n'\
4445         '               var cg = cglist.getElementsByClassName("atop");\n'\
4446         '               for (var i = 0; i < cg.length; i++) {\n'\
4447         '                       if(this.id == cg[i].id) {\n'\
4448         '                               cg[i].style.display = "block";\n'\
4449         '                       } else {\n'\
4450         '                               cg[i].style.display = "none";\n'\
4451         '                       }\n'\
4452         '               }\n'\
4453         '       }\n'\
4454         '       function devListWindow(e) {\n'\
4455         '               var win = window.open();\n'\
4456         '               var html = "<title>"+e.target.innerHTML+"</title>"+\n'\
4457         '                       "<style type=\\"text/css\\">"+\n'\
4458         '                       "   ul {list-style-type:circle;padding-left:10px;margin-left:10px;}"+\n'\
4459         '                       "</style>"\n'\
4460         '               var dt = devtable[0];\n'\
4461         '               if(e.target.id != "devlist1")\n'\
4462         '                       dt = devtable[1];\n'\
4463         '               win.document.write(html+dt);\n'\
4464         '       }\n'\
4465         '       function errWindow() {\n'\
4466         '               var range = this.id.split("_");\n'\
4467         '               var idx1 = parseInt(range[0]);\n'\
4468         '               var idx2 = parseInt(range[1]);\n'\
4469         '               var win = window.open();\n'\
4470         '               var log = document.getElementById("dmesglog");\n'\
4471         '               var title = "<title>dmesg log</title>";\n'\
4472         '               var text = log.innerHTML.split("\\n");\n'\
4473         '               var html = "";\n'\
4474         '               for(var i = 0; i < text.length; i++) {\n'\
4475         '                       if(i == idx1) {\n'\
4476         '                               html += "<e id=target>"+text[i]+"</e>\\n";\n'\
4477         '                       } else if(i > idx1 && i <= idx2) {\n'\
4478         '                               html += "<e>"+text[i]+"</e>\\n";\n'\
4479         '                       } else {\n'\
4480         '                               html += text[i]+"\\n";\n'\
4481         '                       }\n'\
4482         '               }\n'\
4483         '               win.document.write("<style>e{color:red}</style>"+title+"<pre>"+html+"</pre>");\n'\
4484         '               win.location.hash = "#target";\n'\
4485         '               win.document.close();\n'\
4486         '       }\n'\
4487         '       function logWindow(e) {\n'\
4488         '               var name = e.target.id.slice(4);\n'\
4489         '               var win = window.open();\n'\
4490         '               var log = document.getElementById(name+"log");\n'\
4491         '               var title = "<title>"+document.title.split(" ")[0]+" "+name+" log</title>";\n'\
4492         '               win.document.write(title+"<pre>"+log.innerHTML+"</pre>");\n'\
4493         '               win.document.close();\n'\
4494         '       }\n'\
4495         '       function onMouseDown(e) {\n'\
4496         '               dragval[0] = e.clientX;\n'\
4497         '               dragval[1] = document.getElementById("dmesgzoombox").scrollLeft;\n'\
4498         '               document.onmousemove = onMouseMove;\n'\
4499         '       }\n'\
4500         '       function onMouseMove(e) {\n'\
4501         '               var zoombox = document.getElementById("dmesgzoombox");\n'\
4502         '               zoombox.scrollLeft = dragval[1] + dragval[0] - e.clientX;\n'\
4503         '       }\n'\
4504         '       function onMouseUp(e) {\n'\
4505         '               document.onmousemove = null;\n'\
4506         '       }\n'\
4507         '       function onKeyPress(e) {\n'\
4508         '               var c = e.charCode;\n'\
4509         '               if(c != 42 && c != 43 && c != 45) return;\n'\
4510         '               var click = document.createEvent("Events");\n'\
4511         '               click.initEvent("click", true, false);\n'\
4512         '               if(c == 43)  \n'\
4513         '                       document.getElementById("zoomin").dispatchEvent(click);\n'\
4514         '               else if(c == 45)\n'\
4515         '                       document.getElementById("zoomout").dispatchEvent(click);\n'\
4516         '               else if(c == 42)\n'\
4517         '                       document.getElementById("zoomdef").dispatchEvent(click);\n'\
4518         '       }\n'\
4519         '       window.addEventListener("resize", function () {zoomTimeline();});\n'\
4520         '       window.addEventListener("load", function () {\n'\
4521         '               var dmesg = document.getElementById("dmesg");\n'\
4522         '               dmesg.style.width = "100%"\n'\
4523         '               dmesg.onmousedown = onMouseDown;\n'\
4524         '               document.onmouseup = onMouseUp;\n'\
4525         '               document.onkeypress = onKeyPress;\n'\
4526         '               document.getElementById("zoomin").onclick = zoomTimeline;\n'\
4527         '               document.getElementById("zoomout").onclick = zoomTimeline;\n'\
4528         '               document.getElementById("zoomdef").onclick = zoomTimeline;\n'\
4529         '               var list = document.getElementsByClassName("err");\n'\
4530         '               for (var i = 0; i < list.length; i++)\n'\
4531         '                       list[i].onclick = errWindow;\n'\
4532         '               var list = document.getElementsByClassName("logbtn");\n'\
4533         '               for (var i = 0; i < list.length; i++)\n'\
4534         '                       list[i].onclick = logWindow;\n'\
4535         '               list = document.getElementsByClassName("devlist");\n'\
4536         '               for (var i = 0; i < list.length; i++)\n'\
4537         '                       list[i].onclick = devListWindow;\n'\
4538         '               var dev = dmesg.getElementsByClassName("thread");\n'\
4539         '               for (var i = 0; i < dev.length; i++) {\n'\
4540         '                       dev[i].onclick = deviceDetail;\n'\
4541         '                       dev[i].onmouseover = deviceHover;\n'\
4542         '                       dev[i].onmouseout = deviceUnhover;\n'\
4543         '               }\n'\
4544         '               var dev = dmesg.getElementsByClassName("srccall");\n'\
4545         '               for (var i = 0; i < dev.length; i++)\n'\
4546         '                       dev[i].onclick = callSelect;\n'\
4547         '               zoomTimeline();\n'\
4548         '       });\n'\
4549         '</script>\n'
4550         hf.write(script_code);
4551
4552 def setRuntimeSuspend(before=True):
4553         global sysvals
4554         sv = sysvals
4555         if sv.rs == 0:
4556                 return
4557         if before:
4558                 # runtime suspend disable or enable
4559                 if sv.rs > 0:
4560                         sv.rstgt, sv.rsval, sv.rsdir = 'on', 'auto', 'enabled'
4561                 else:
4562                         sv.rstgt, sv.rsval, sv.rsdir = 'auto', 'on', 'disabled'
4563                 pprint('CONFIGURING RUNTIME SUSPEND...')
4564                 sv.rslist = deviceInfo(sv.rstgt)
4565                 for i in sv.rslist:
4566                         sv.setVal(sv.rsval, i)
4567                 pprint('runtime suspend %s on all devices (%d changed)' % (sv.rsdir, len(sv.rslist)))
4568                 pprint('waiting 5 seconds...')
4569                 time.sleep(5)
4570         else:
4571                 # runtime suspend re-enable or re-disable
4572                 for i in sv.rslist:
4573                         sv.setVal(sv.rstgt, i)
4574                 pprint('runtime suspend settings restored on %d devices' % len(sv.rslist))
4575
4576 # Function: executeSuspend
4577 # Description:
4578 #        Execute system suspend through the sysfs interface, then copy the output
4579 #        dmesg and ftrace files to the test output directory.
4580 def executeSuspend():
4581         pm = ProcessMonitor()
4582         tp = sysvals.tpath
4583         testdata = []
4584         battery = True if getBattery() else False
4585         # run these commands to prepare the system for suspend
4586         if sysvals.display:
4587                 pprint('SET DISPLAY TO %s' % sysvals.display.upper())
4588                 displayControl(sysvals.display)
4589                 time.sleep(1)
4590         if sysvals.sync:
4591                 pprint('SYNCING FILESYSTEMS')
4592                 call('sync', shell=True)
4593         # mark the start point in the kernel ring buffer just as we start
4594         sysvals.initdmesg()
4595         # start ftrace
4596         if(sysvals.usecallgraph or sysvals.usetraceevents):
4597                 pprint('START TRACING')
4598                 sysvals.fsetVal('1', 'tracing_on')
4599                 if sysvals.useprocmon:
4600                         pm.start()
4601         # execute however many s/r runs requested
4602         for count in range(1,sysvals.execcount+1):
4603                 # x2delay in between test runs
4604                 if(count > 1 and sysvals.x2delay > 0):
4605                         sysvals.fsetVal('WAIT %d' % sysvals.x2delay, 'trace_marker')
4606                         time.sleep(sysvals.x2delay/1000.0)
4607                         sysvals.fsetVal('WAIT END', 'trace_marker')
4608                 # start message
4609                 if sysvals.testcommand != '':
4610                         pprint('COMMAND START')
4611                 else:
4612                         if(sysvals.rtcwake):
4613                                 pprint('SUSPEND START')
4614                         else:
4615                                 pprint('SUSPEND START (press a key to resume)')
4616                 bat1 = getBattery() if battery else False
4617                 # set rtcwake
4618                 if(sysvals.rtcwake):
4619                         pprint('will issue an rtcwake in %d seconds' % sysvals.rtcwaketime)
4620                         sysvals.rtcWakeAlarmOn()
4621                 # start of suspend trace marker
4622                 if(sysvals.usecallgraph or sysvals.usetraceevents):
4623                         sysvals.fsetVal('SUSPEND START', 'trace_marker')
4624                 # predelay delay
4625                 if(count == 1 and sysvals.predelay > 0):
4626                         sysvals.fsetVal('WAIT %d' % sysvals.predelay, 'trace_marker')
4627                         time.sleep(sysvals.predelay/1000.0)
4628                         sysvals.fsetVal('WAIT END', 'trace_marker')
4629                 # initiate suspend or command
4630                 tdata = {'error': ''}
4631                 if sysvals.testcommand != '':
4632                         res = call(sysvals.testcommand+' 2>&1', shell=True);
4633                         if res != 0:
4634                                 tdata['error'] = 'cmd returned %d' % res
4635                 else:
4636                         mode = sysvals.suspendmode
4637                         if sysvals.memmode and os.path.exists(sysvals.mempowerfile):
4638                                 mode = 'mem'
4639                                 pf = open(sysvals.mempowerfile, 'w')
4640                                 pf.write(sysvals.memmode)
4641                                 pf.close()
4642                         if sysvals.diskmode and os.path.exists(sysvals.diskpowerfile):
4643                                 mode = 'disk'
4644                                 pf = open(sysvals.diskpowerfile, 'w')
4645                                 pf.write(sysvals.diskmode)
4646                                 pf.close()
4647                         pf = open(sysvals.powerfile, 'w')
4648                         pf.write(mode)
4649                         # execution will pause here
4650                         try:
4651                                 pf.close()
4652                         except Exception as e:
4653                                 tdata['error'] = str(e)
4654                 if(sysvals.rtcwake):
4655                         sysvals.rtcWakeAlarmOff()
4656                 # postdelay delay
4657                 if(count == sysvals.execcount and sysvals.postdelay > 0):
4658                         sysvals.fsetVal('WAIT %d' % sysvals.postdelay, 'trace_marker')
4659                         time.sleep(sysvals.postdelay/1000.0)
4660                         sysvals.fsetVal('WAIT END', 'trace_marker')
4661                 # return from suspend
4662                 pprint('RESUME COMPLETE')
4663                 if(sysvals.usecallgraph or sysvals.usetraceevents):
4664                         sysvals.fsetVal('RESUME COMPLETE', 'trace_marker')
4665                 if(sysvals.suspendmode == 'mem' or sysvals.suspendmode == 'command'):
4666                         tdata['fw'] = getFPDT(False)
4667                 bat2 = getBattery() if battery else False
4668                 if battery and bat1 and bat2:
4669                         tdata['bat'] = (bat1, bat2)
4670                 testdata.append(tdata)
4671         # stop ftrace
4672         if(sysvals.usecallgraph or sysvals.usetraceevents):
4673                 if sysvals.useprocmon:
4674                         pm.stop()
4675                 sysvals.fsetVal('0', 'tracing_on')
4676         # grab a copy of the dmesg output
4677         pprint('CAPTURING DMESG')
4678         sysvals.getdmesg(testdata)
4679         # grab a copy of the ftrace output
4680         if(sysvals.usecallgraph or sysvals.usetraceevents):
4681                 pprint('CAPTURING TRACE')
4682                 op = sysvals.writeDatafileHeader(sysvals.ftracefile, testdata)
4683                 fp = open(tp+'trace', 'r')
4684                 for line in fp:
4685                         op.write(line)
4686                 op.close()
4687                 sysvals.fsetVal('', 'trace')
4688                 devProps()
4689
4690 def readFile(file):
4691         if os.path.islink(file):
4692                 return os.readlink(file).split('/')[-1]
4693         else:
4694                 return sysvals.getVal(file).strip()
4695
4696 # Function: ms2nice
4697 # Description:
4698 #        Print out a very concise time string in minutes and seconds
4699 # Output:
4700 #        The time string, e.g. "1901m16s"
4701 def ms2nice(val):
4702         val = int(val)
4703         h = val / 3600000
4704         m = (val / 60000) % 60
4705         s = (val / 1000) % 60
4706         if h > 0:
4707                 return '%d:%02d:%02d' % (h, m, s)
4708         if m > 0:
4709                 return '%02d:%02d' % (m, s)
4710         return '%ds' % s
4711
4712 def yesno(val):
4713         list = {'enabled':'A', 'disabled':'S', 'auto':'E', 'on':'D',
4714                 'active':'A', 'suspended':'S', 'suspending':'S'}
4715         if val not in list:
4716                 return ' '
4717         return list[val]
4718
4719 # Function: deviceInfo
4720 # Description:
4721 #        Detect all the USB hosts and devices currently connected and add
4722 #        a list of USB device names to sysvals for better timeline readability
4723 def deviceInfo(output=''):
4724         if not output:
4725                 pprint('LEGEND\n'\
4726                 '---------------------------------------------------------------------------------------------\n'\
4727                 '  A = async/sync PM queue (A/S)               C = runtime active children\n'\
4728                 '  R = runtime suspend enabled/disabled (E/D)  rACTIVE = runtime active (min/sec)\n'\
4729                 '  S = runtime status active/suspended (A/S)   rSUSPEND = runtime suspend (min/sec)\n'\
4730                 '  U = runtime usage count\n'\
4731                 '---------------------------------------------------------------------------------------------\n'\
4732                 'DEVICE                     NAME                       A R S U C    rACTIVE   rSUSPEND\n'\
4733                 '---------------------------------------------------------------------------------------------')
4734
4735         res = []
4736         tgtval = 'runtime_status'
4737         lines = dict()
4738         for dirname, dirnames, filenames in os.walk('/sys/devices'):
4739                 if(not re.match('.*/power', dirname) or
4740                         'control' not in filenames or
4741                         tgtval not in filenames):
4742                         continue
4743                 name = ''
4744                 dirname = dirname[:-6]
4745                 device = dirname.split('/')[-1]
4746                 power = dict()
4747                 power[tgtval] = readFile('%s/power/%s' % (dirname, tgtval))
4748                 # only list devices which support runtime suspend
4749                 if power[tgtval] not in ['active', 'suspended', 'suspending']:
4750                         continue
4751                 for i in ['product', 'driver', 'subsystem']:
4752                         file = '%s/%s' % (dirname, i)
4753                         if os.path.exists(file):
4754                                 name = readFile(file)
4755                                 break
4756                 for i in ['async', 'control', 'runtime_status', 'runtime_usage',
4757                         'runtime_active_kids', 'runtime_active_time',
4758                         'runtime_suspended_time']:
4759                         if i in filenames:
4760                                 power[i] = readFile('%s/power/%s' % (dirname, i))
4761                 if output:
4762                         if power['control'] == output:
4763                                 res.append('%s/power/control' % dirname)
4764                         continue
4765                 lines[dirname] = '%-26s %-26s %1s %1s %1s %1s %1s %10s %10s' % \
4766                         (device[:26], name[:26],
4767                         yesno(power['async']), \
4768                         yesno(power['control']), \
4769                         yesno(power['runtime_status']), \
4770                         power['runtime_usage'], \
4771                         power['runtime_active_kids'], \
4772                         ms2nice(power['runtime_active_time']), \
4773                         ms2nice(power['runtime_suspended_time']))
4774         for i in sorted(lines):
4775                 print lines[i]
4776         return res
4777
4778 # Function: devProps
4779 # Description:
4780 #        Retrieve a list of properties for all devices in the trace log
4781 def devProps(data=0):
4782         props = dict()
4783
4784         if data:
4785                 idx = data.index(': ') + 2
4786                 if idx >= len(data):
4787                         return
4788                 devlist = data[idx:].split(';')
4789                 for dev in devlist:
4790                         f = dev.split(',')
4791                         if len(f) < 3:
4792                                 continue
4793                         dev = f[0]
4794                         props[dev] = DevProps()
4795                         props[dev].altname = f[1]
4796                         if int(f[2]):
4797                                 props[dev].async = True
4798                         else:
4799                                 props[dev].async = False
4800                         sysvals.devprops = props
4801                 if sysvals.suspendmode == 'command' and 'testcommandstring' in props:
4802                         sysvals.testcommand = props['testcommandstring'].altname
4803                 return
4804
4805         if(os.path.exists(sysvals.ftracefile) == False):
4806                 doError('%s does not exist' % sysvals.ftracefile)
4807
4808         # first get the list of devices we need properties for
4809         msghead = 'Additional data added by AnalyzeSuspend'
4810         alreadystamped = False
4811         tp = TestProps()
4812         tf = sysvals.openlog(sysvals.ftracefile, 'r')
4813         for line in tf:
4814                 if msghead in line:
4815                         alreadystamped = True
4816                         continue
4817                 # determine the trace data type (required for further parsing)
4818                 m = re.match(tp.tracertypefmt, line)
4819                 if(m):
4820                         tp.setTracerType(m.group('t'))
4821                         continue
4822                 # parse only valid lines, if this is not one move on
4823                 m = re.match(tp.ftrace_line_fmt, line)
4824                 if(not m or 'device_pm_callback_start' not in line):
4825                         continue
4826                 m = re.match('.*: (?P<drv>.*) (?P<d>.*), parent: *(?P<p>.*), .*', m.group('msg'));
4827                 if(not m):
4828                         continue
4829                 dev = m.group('d')
4830                 if dev not in props:
4831                         props[dev] = DevProps()
4832         tf.close()
4833
4834         if not alreadystamped and sysvals.suspendmode == 'command':
4835                 out = '#\n# '+msghead+'\n# Device Properties: '
4836                 out += 'testcommandstring,%s,0;' % (sysvals.testcommand)
4837                 with sysvals.openlog(sysvals.ftracefile, 'a') as fp:
4838                         fp.write(out+'\n')
4839                 sysvals.devprops = props
4840                 return
4841
4842         # now get the syspath for each of our target devices
4843         for dirname, dirnames, filenames in os.walk('/sys/devices'):
4844                 if(re.match('.*/power', dirname) and 'async' in filenames):
4845                         dev = dirname.split('/')[-2]
4846                         if dev in props and (not props[dev].syspath or len(dirname) < len(props[dev].syspath)):
4847                                 props[dev].syspath = dirname[:-6]
4848
4849         # now fill in the properties for our target devices
4850         for dev in props:
4851                 dirname = props[dev].syspath
4852                 if not dirname or not os.path.exists(dirname):
4853                         continue
4854                 with open(dirname+'/power/async') as fp:
4855                         text = fp.read()
4856                         props[dev].async = False
4857                         if 'enabled' in text:
4858                                 props[dev].async = True
4859                 fields = os.listdir(dirname)
4860                 if 'product' in fields:
4861                         with open(dirname+'/product') as fp:
4862                                 props[dev].altname = fp.read()
4863                 elif 'name' in fields:
4864                         with open(dirname+'/name') as fp:
4865                                 props[dev].altname = fp.read()
4866                 elif 'model' in fields:
4867                         with open(dirname+'/model') as fp:
4868                                 props[dev].altname = fp.read()
4869                 elif 'description' in fields:
4870                         with open(dirname+'/description') as fp:
4871                                 props[dev].altname = fp.read()
4872                 elif 'id' in fields:
4873                         with open(dirname+'/id') as fp:
4874                                 props[dev].altname = fp.read()
4875                 elif 'idVendor' in fields and 'idProduct' in fields:
4876                         idv, idp = '', ''
4877                         with open(dirname+'/idVendor') as fp:
4878                                 idv = fp.read().strip()
4879                         with open(dirname+'/idProduct') as fp:
4880                                 idp = fp.read().strip()
4881                         props[dev].altname = '%s:%s' % (idv, idp)
4882
4883                 if props[dev].altname:
4884                         out = props[dev].altname.strip().replace('\n', ' ')
4885                         out = out.replace(',', ' ')
4886                         out = out.replace(';', ' ')
4887                         props[dev].altname = out
4888
4889         # and now write the data to the ftrace file
4890         if not alreadystamped:
4891                 out = '#\n# '+msghead+'\n# Device Properties: '
4892                 for dev in sorted(props):
4893                         out += props[dev].out(dev)
4894                 with sysvals.openlog(sysvals.ftracefile, 'a') as fp:
4895                         fp.write(out+'\n')
4896
4897         sysvals.devprops = props
4898
4899 # Function: getModes
4900 # Description:
4901 #        Determine the supported power modes on this system
4902 # Output:
4903 #        A string list of the available modes
4904 def getModes():
4905         modes = []
4906         if(os.path.exists(sysvals.powerfile)):
4907                 fp = open(sysvals.powerfile, 'r')
4908                 modes = string.split(fp.read())
4909                 fp.close()
4910         if(os.path.exists(sysvals.mempowerfile)):
4911                 deep = False
4912                 fp = open(sysvals.mempowerfile, 'r')
4913                 for m in string.split(fp.read()):
4914                         memmode = m.strip('[]')
4915                         if memmode == 'deep':
4916                                 deep = True
4917                         else:
4918                                 modes.append('mem-%s' % memmode)
4919                 fp.close()
4920                 if 'mem' in modes and not deep:
4921                         modes.remove('mem')
4922         if('disk' in modes and os.path.exists(sysvals.diskpowerfile)):
4923                 fp = open(sysvals.diskpowerfile, 'r')
4924                 for m in string.split(fp.read()):
4925                         modes.append('disk-%s' % m.strip('[]'))
4926                 fp.close()
4927         return modes
4928
4929 # Function: dmidecode
4930 # Description:
4931 #        Read the bios tables and pull out system info
4932 # Arguments:
4933 #        mempath: /dev/mem or custom mem path
4934 #        fatal: True to exit on error, False to return empty dict
4935 # Output:
4936 #        A dict object with all available key/values
4937 def dmidecode(mempath, fatal=False):
4938         out = dict()
4939
4940         # the list of values to retrieve, with hardcoded (type, idx)
4941         info = {
4942                 'bios-vendor': (0, 4),
4943                 'bios-version': (0, 5),
4944                 'bios-release-date': (0, 8),
4945                 'system-manufacturer': (1, 4),
4946                 'system-product-name': (1, 5),
4947                 'system-version': (1, 6),
4948                 'system-serial-number': (1, 7),
4949                 'baseboard-manufacturer': (2, 4),
4950                 'baseboard-product-name': (2, 5),
4951                 'baseboard-version': (2, 6),
4952                 'baseboard-serial-number': (2, 7),
4953                 'chassis-manufacturer': (3, 4),
4954                 'chassis-type': (3, 5),
4955                 'chassis-version': (3, 6),
4956                 'chassis-serial-number': (3, 7),
4957                 'processor-manufacturer': (4, 7),
4958                 'processor-version': (4, 16),
4959         }
4960         if(not os.path.exists(mempath)):
4961                 if(fatal):
4962                         doError('file does not exist: %s' % mempath)
4963                 return out
4964         if(not os.access(mempath, os.R_OK)):
4965                 if(fatal):
4966                         doError('file is not readable: %s' % mempath)
4967                 return out
4968
4969         # by default use legacy scan, but try to use EFI first
4970         memaddr = 0xf0000
4971         memsize = 0x10000
4972         for ep in ['/sys/firmware/efi/systab', '/proc/efi/systab']:
4973                 if not os.path.exists(ep) or not os.access(ep, os.R_OK):
4974                         continue
4975                 fp = open(ep, 'r')
4976                 buf = fp.read()
4977                 fp.close()
4978                 i = buf.find('SMBIOS=')
4979                 if i >= 0:
4980                         try:
4981                                 memaddr = int(buf[i+7:], 16)
4982                                 memsize = 0x20
4983                         except:
4984                                 continue
4985
4986         # read in the memory for scanning
4987         fp = open(mempath, 'rb')
4988         try:
4989                 fp.seek(memaddr)
4990                 buf = fp.read(memsize)
4991         except:
4992                 if(fatal):
4993                         doError('DMI table is unreachable, sorry')
4994                 else:
4995                         return out
4996         fp.close()
4997
4998         # search for either an SM table or DMI table
4999         i = base = length = num = 0
5000         while(i < memsize):
5001                 if buf[i:i+4] == '_SM_' and i < memsize - 16:
5002                         length = struct.unpack('H', buf[i+22:i+24])[0]
5003                         base, num = struct.unpack('IH', buf[i+24:i+30])
5004                         break
5005                 elif buf[i:i+5] == '_DMI_':
5006                         length = struct.unpack('H', buf[i+6:i+8])[0]
5007                         base, num = struct.unpack('IH', buf[i+8:i+14])
5008                         break
5009                 i += 16
5010         if base == 0 and length == 0 and num == 0:
5011                 if(fatal):
5012                         doError('Neither SMBIOS nor DMI were found')
5013                 else:
5014                         return out
5015
5016         # read in the SM or DMI table
5017         fp = open(mempath, 'rb')
5018         try:
5019                 fp.seek(base)
5020                 buf = fp.read(length)
5021         except:
5022                 if(fatal):
5023                         doError('DMI table is unreachable, sorry')
5024                 else:
5025                         return out
5026         fp.close()
5027
5028         # scan the table for the values we want
5029         count = i = 0
5030         while(count < num and i <= len(buf) - 4):
5031                 type, size, handle = struct.unpack('BBH', buf[i:i+4])
5032                 n = i + size
5033                 while n < len(buf) - 1:
5034                         if 0 == struct.unpack('H', buf[n:n+2])[0]:
5035                                 break
5036                         n += 1
5037                 data = buf[i+size:n+2].split('\0')
5038                 for name in info:
5039                         itype, idxadr = info[name]
5040                         if itype == type:
5041                                 idx = struct.unpack('B', buf[i+idxadr])[0]
5042                                 if idx > 0 and idx < len(data) - 1:
5043                                         s = data[idx-1].strip()
5044                                         if s and s.lower() != 'to be filled by o.e.m.':
5045                                                 out[name] = data[idx-1]
5046                 i = n + 2
5047                 count += 1
5048         return out
5049
5050 def getBattery():
5051         p, charge, bat = '/sys/class/power_supply', 0, {}
5052         if not os.path.exists(p):
5053                 return False
5054         for d in os.listdir(p):
5055                 type = sysvals.getVal(os.path.join(p, d, 'type')).strip().lower()
5056                 if type != 'battery':
5057                         continue
5058                 for v in ['status', 'energy_now', 'capacity_now']:
5059                         bat[v] = sysvals.getVal(os.path.join(p, d, v)).strip().lower()
5060                 break
5061         if 'status' not in bat:
5062                 return False
5063         ac = False if 'discharging' in bat['status'] else True
5064         for v in ['energy_now', 'capacity_now']:
5065                 if v in bat and bat[v]:
5066                         charge = int(bat[v])
5067         return (ac, charge)
5068
5069 def displayControl(cmd):
5070         xset, ret = 'xset -d :0.0 {0}', 0
5071         if sysvals.sudouser:
5072                 xset = 'sudo -u %s %s' % (sysvals.sudouser, xset)
5073         if cmd == 'init':
5074                 ret = call(xset.format('dpms 0 0 0'), shell=True)
5075                 if not ret:
5076                         ret = call(xset.format('s off'), shell=True)
5077         elif cmd == 'reset':
5078                 ret = call(xset.format('s reset'), shell=True)
5079         elif cmd in ['on', 'off', 'standby', 'suspend']:
5080                 b4 = displayControl('stat')
5081                 ret = call(xset.format('dpms force %s' % cmd), shell=True)
5082                 if not ret:
5083                         curr = displayControl('stat')
5084                         sysvals.vprint('Display Switched: %s -> %s' % (b4, curr))
5085                         if curr != cmd:
5086                                 sysvals.vprint('WARNING: Display failed to change to %s' % cmd)
5087                 if ret:
5088                         sysvals.vprint('WARNING: Display failed to change to %s with xset' % cmd)
5089                         return ret
5090         elif cmd == 'stat':
5091                 fp = Popen(xset.format('q').split(' '), stdout=PIPE).stdout
5092                 ret = 'unknown'
5093                 for line in fp:
5094                         m = re.match('[\s]*Monitor is (?P<m>.*)', line)
5095                         if(m and len(m.group('m')) >= 2):
5096                                 out = m.group('m').lower()
5097                                 ret = out[3:] if out[0:2] == 'in' else out
5098                                 break
5099                 fp.close()
5100         return ret
5101
5102 # Function: getFPDT
5103 # Description:
5104 #        Read the acpi bios tables and pull out FPDT, the firmware data
5105 # Arguments:
5106 #        output: True to output the info to stdout, False otherwise
5107 def getFPDT(output):
5108         rectype = {}
5109         rectype[0] = 'Firmware Basic Boot Performance Record'
5110         rectype[1] = 'S3 Performance Table Record'
5111         prectype = {}
5112         prectype[0] = 'Basic S3 Resume Performance Record'
5113         prectype[1] = 'Basic S3 Suspend Performance Record'
5114
5115         sysvals.rootCheck(True)
5116         if(not os.path.exists(sysvals.fpdtpath)):
5117                 if(output):
5118                         doError('file does not exist: %s' % sysvals.fpdtpath)
5119                 return False
5120         if(not os.access(sysvals.fpdtpath, os.R_OK)):
5121                 if(output):
5122                         doError('file is not readable: %s' % sysvals.fpdtpath)
5123                 return False
5124         if(not os.path.exists(sysvals.mempath)):
5125                 if(output):
5126                         doError('file does not exist: %s' % sysvals.mempath)
5127                 return False
5128         if(not os.access(sysvals.mempath, os.R_OK)):
5129                 if(output):
5130                         doError('file is not readable: %s' % sysvals.mempath)
5131                 return False
5132
5133         fp = open(sysvals.fpdtpath, 'rb')
5134         buf = fp.read()
5135         fp.close()
5136
5137         if(len(buf) < 36):
5138                 if(output):
5139                         doError('Invalid FPDT table data, should '+\
5140                                 'be at least 36 bytes')
5141                 return False
5142
5143         table = struct.unpack('4sIBB6s8sI4sI', buf[0:36])
5144         if(output):
5145                 pprint('\n'\
5146                 'Firmware Performance Data Table (%s)\n'\
5147                 '                  Signature : %s\n'\
5148                 '               Table Length : %u\n'\
5149                 '                   Revision : %u\n'\
5150                 '                   Checksum : 0x%x\n'\
5151                 '                     OEM ID : %s\n'\
5152                 '               OEM Table ID : %s\n'\
5153                 '               OEM Revision : %u\n'\
5154                 '                 Creator ID : %s\n'\
5155                 '           Creator Revision : 0x%x\n'\
5156                 '' % (table[0], table[0], table[1], table[2], table[3],
5157                         table[4], table[5], table[6], table[7], table[8]))
5158
5159         if(table[0] != 'FPDT'):
5160                 if(output):
5161                         doError('Invalid FPDT table')
5162                 return False
5163         if(len(buf) <= 36):
5164                 return False
5165         i = 0
5166         fwData = [0, 0]
5167         records = buf[36:]
5168         fp = open(sysvals.mempath, 'rb')
5169         while(i < len(records)):
5170                 header = struct.unpack('HBB', records[i:i+4])
5171                 if(header[0] not in rectype):
5172                         i += header[1]
5173                         continue
5174                 if(header[1] != 16):
5175                         i += header[1]
5176                         continue
5177                 addr = struct.unpack('Q', records[i+8:i+16])[0]
5178                 try:
5179                         fp.seek(addr)
5180                         first = fp.read(8)
5181                 except:
5182                         if(output):
5183                                 pprint('Bad address 0x%x in %s' % (addr, sysvals.mempath))
5184                         return [0, 0]
5185                 rechead = struct.unpack('4sI', first)
5186                 recdata = fp.read(rechead[1]-8)
5187                 if(rechead[0] == 'FBPT'):
5188                         record = struct.unpack('HBBIQQQQQ', recdata)
5189                         if(output):
5190                                 pprint('%s (%s)\n'\
5191                                 '                  Reset END : %u ns\n'\
5192                                 '  OS Loader LoadImage Start : %u ns\n'\
5193                                 ' OS Loader StartImage Start : %u ns\n'\
5194                                 '     ExitBootServices Entry : %u ns\n'\
5195                                 '      ExitBootServices Exit : %u ns'\
5196                                 '' % (rectype[header[0]], rechead[0], record[4], record[5],
5197                                         record[6], record[7], record[8]))
5198                 elif(rechead[0] == 'S3PT'):
5199                         if(output):
5200                                 pprint('%s (%s)' % (rectype[header[0]], rechead[0]))
5201                         j = 0
5202                         while(j < len(recdata)):
5203                                 prechead = struct.unpack('HBB', recdata[j:j+4])
5204                                 if(prechead[0] not in prectype):
5205                                         continue
5206                                 if(prechead[0] == 0):
5207                                         record = struct.unpack('IIQQ', recdata[j:j+prechead[1]])
5208                                         fwData[1] = record[2]
5209                                         if(output):
5210                                                 pprint('    %s\n'\
5211                                                 '               Resume Count : %u\n'\
5212                                                 '                 FullResume : %u ns\n'\
5213                                                 '              AverageResume : %u ns'\
5214                                                 '' % (prectype[prechead[0]], record[1],
5215                                                                 record[2], record[3]))
5216                                 elif(prechead[0] == 1):
5217                                         record = struct.unpack('QQ', recdata[j+4:j+prechead[1]])
5218                                         fwData[0] = record[1] - record[0]
5219                                         if(output):
5220                                                 pprint('    %s\n'\
5221                                                 '               SuspendStart : %u ns\n'\
5222                                                 '                 SuspendEnd : %u ns\n'\
5223                                                 '                SuspendTime : %u ns'\
5224                                                 '' % (prectype[prechead[0]], record[0],
5225                                                                 record[1], fwData[0]))
5226
5227                                 j += prechead[1]
5228                 if(output):
5229                         pprint('')
5230                 i += header[1]
5231         fp.close()
5232         return fwData
5233
5234 # Function: statusCheck
5235 # Description:
5236 #        Verify that the requested command and options will work, and
5237 #        print the results to the terminal
5238 # Output:
5239 #        True if the test will work, False if not
5240 def statusCheck(probecheck=False):
5241         status = ''
5242
5243         pprint('Checking this system (%s)...' % platform.node())
5244
5245         # check we have root access
5246         res = sysvals.colorText('NO (No features of this tool will work!)')
5247         if(sysvals.rootCheck(False)):
5248                 res = 'YES'
5249         pprint('    have root access: %s' % res)
5250         if(res != 'YES'):
5251                 pprint('    Try running this script with sudo')
5252                 return 'missing root access'
5253
5254         # check sysfs is mounted
5255         res = sysvals.colorText('NO (No features of this tool will work!)')
5256         if(os.path.exists(sysvals.powerfile)):
5257                 res = 'YES'
5258         pprint('    is sysfs mounted: %s' % res)
5259         if(res != 'YES'):
5260                 return 'sysfs is missing'
5261
5262         # check target mode is a valid mode
5263         if sysvals.suspendmode != 'command':
5264                 res = sysvals.colorText('NO')
5265                 modes = getModes()
5266                 if(sysvals.suspendmode in modes):
5267                         res = 'YES'
5268                 else:
5269                         status = '%s mode is not supported' % sysvals.suspendmode
5270                 pprint('    is "%s" a valid power mode: %s' % (sysvals.suspendmode, res))
5271                 if(res == 'NO'):
5272                         pprint('      valid power modes are: %s' % modes)
5273                         pprint('      please choose one with -m')
5274
5275         # check if ftrace is available
5276         res = sysvals.colorText('NO')
5277         ftgood = sysvals.verifyFtrace()
5278         if(ftgood):
5279                 res = 'YES'
5280         elif(sysvals.usecallgraph):
5281                 status = 'ftrace is not properly supported'
5282         pprint('    is ftrace supported: %s' % res)
5283
5284         # check if kprobes are available
5285         res = sysvals.colorText('NO')
5286         sysvals.usekprobes = sysvals.verifyKprobes()
5287         if(sysvals.usekprobes):
5288                 res = 'YES'
5289         else:
5290                 sysvals.usedevsrc = False
5291         pprint('    are kprobes supported: %s' % res)
5292
5293         # what data source are we using
5294         res = 'DMESG'
5295         if(ftgood):
5296                 sysvals.usetraceevents = True
5297                 for e in sysvals.traceevents:
5298                         if not os.path.exists(sysvals.epath+e):
5299                                 sysvals.usetraceevents = False
5300                 if(sysvals.usetraceevents):
5301                         res = 'FTRACE (all trace events found)'
5302         pprint('    timeline data source: %s' % res)
5303
5304         # check if rtcwake
5305         res = sysvals.colorText('NO')
5306         if(sysvals.rtcpath != ''):
5307                 res = 'YES'
5308         elif(sysvals.rtcwake):
5309                 status = 'rtcwake is not properly supported'
5310         pprint('    is rtcwake supported: %s' % res)
5311
5312         if not probecheck:
5313                 return status
5314
5315         # verify kprobes
5316         if sysvals.usekprobes:
5317                 for name in sysvals.tracefuncs:
5318                         sysvals.defaultKprobe(name, sysvals.tracefuncs[name])
5319                 if sysvals.usedevsrc:
5320                         for name in sysvals.dev_tracefuncs:
5321                                 sysvals.defaultKprobe(name, sysvals.dev_tracefuncs[name])
5322                 sysvals.addKprobes(True)
5323
5324         return status
5325
5326 # Function: doError
5327 # Description:
5328 #        generic error function for catastrphic failures
5329 # Arguments:
5330 #        msg: the error message to print
5331 #        help: True if printHelp should be called after, False otherwise
5332 def doError(msg, help=False):
5333         if(help == True):
5334                 printHelp()
5335         pprint('ERROR: %s\n' % msg)
5336         sysvals.outputResult({'error':msg})
5337         sys.exit(1)
5338
5339 # Function: getArgInt
5340 # Description:
5341 #        pull out an integer argument from the command line with checks
5342 def getArgInt(name, args, min, max, main=True):
5343         if main:
5344                 try:
5345                         arg = args.next()
5346                 except:
5347                         doError(name+': no argument supplied', True)
5348         else:
5349                 arg = args
5350         try:
5351                 val = int(arg)
5352         except:
5353                 doError(name+': non-integer value given', True)
5354         if(val < min or val > max):
5355                 doError(name+': value should be between %d and %d' % (min, max), True)
5356         return val
5357
5358 # Function: getArgFloat
5359 # Description:
5360 #        pull out a float argument from the command line with checks
5361 def getArgFloat(name, args, min, max, main=True):
5362         if main:
5363                 try:
5364                         arg = args.next()
5365                 except:
5366                         doError(name+': no argument supplied', True)
5367         else:
5368                 arg = args
5369         try:
5370                 val = float(arg)
5371         except:
5372                 doError(name+': non-numerical value given', True)
5373         if(val < min or val > max):
5374                 doError(name+': value should be between %f and %f' % (min, max), True)
5375         return val
5376
5377 def processData(live=False):
5378         pprint('PROCESSING DATA')
5379         error = ''
5380         if(sysvals.usetraceevents):
5381                 testruns, error = parseTraceLog(live)
5382                 if sysvals.dmesgfile:
5383                         for data in testruns:
5384                                 data.extractErrorInfo()
5385         else:
5386                 testruns = loadKernelLog()
5387                 for data in testruns:
5388                         parseKernelLog(data)
5389                 if(sysvals.ftracefile and (sysvals.usecallgraph or sysvals.usetraceevents)):
5390                         appendIncompleteTraceLog(testruns)
5391         sysvals.vprint('Command:\n    %s' % sysvals.cmdline)
5392         for data in testruns:
5393                 if data.battery:
5394                         a1, c1, a2, c2 = data.battery
5395                         s = 'Battery:\n    Before - AC: %s, Charge: %d\n     After - AC: %s, Charge: %d' % \
5396                                 (a1, int(c1), a2, int(c2))
5397                         sysvals.vprint(s)
5398                 data.printDetails()
5399         if sysvals.cgdump:
5400                 for data in testruns:
5401                         data.debugPrint()
5402                 sys.exit(0)
5403         if len(testruns) < 1:
5404                 pprint('ERROR: Not enough test data to build a timeline')
5405                 return (testruns, {'error': 'timeline generation failed'})
5406         sysvals.vprint('Creating the html timeline (%s)...' % sysvals.htmlfile)
5407         createHTML(testruns, error)
5408         pprint('DONE')
5409         data = testruns[0]
5410         stamp = data.stamp
5411         stamp['suspend'], stamp['resume'] = data.getTimeValues()
5412         if data.fwValid:
5413                 stamp['fwsuspend'], stamp['fwresume'] = data.fwSuspend, data.fwResume
5414         if error:
5415                 stamp['error'] = error
5416         return (testruns, stamp)
5417
5418 # Function: rerunTest
5419 # Description:
5420 #        generate an output from an existing set of ftrace/dmesg logs
5421 def rerunTest():
5422         if sysvals.ftracefile:
5423                 doesTraceLogHaveTraceEvents()
5424         if not sysvals.dmesgfile and not sysvals.usetraceevents:
5425                 doError('recreating this html output requires a dmesg file')
5426         sysvals.setOutputFile()
5427         if os.path.exists(sysvals.htmlfile):
5428                 if not os.path.isfile(sysvals.htmlfile):
5429                         doError('a directory already exists with this name: %s' % sysvals.htmlfile)
5430                 elif not os.access(sysvals.htmlfile, os.W_OK):
5431                         doError('missing permission to write to %s' % sysvals.htmlfile)
5432         testruns, stamp = processData(False)
5433         sysvals.logmsg = ''
5434         return stamp
5435
5436 # Function: runTest
5437 # Description:
5438 #        execute a suspend/resume, gather the logs, and generate the output
5439 def runTest(n=0):
5440         # prepare for the test
5441         sysvals.initFtrace()
5442         sysvals.initTestOutput('suspend')
5443
5444         # execute the test
5445         executeSuspend()
5446         sysvals.cleanupFtrace()
5447         if sysvals.skiphtml:
5448                 sysvals.sudoUserchown(sysvals.testdir)
5449                 return
5450         testruns, stamp = processData(True)
5451         for data in testruns:
5452                 del data
5453         sysvals.sudoUserchown(sysvals.testdir)
5454         sysvals.outputResult(stamp, n)
5455         if 'error' in stamp:
5456                 return 2
5457         return 0
5458
5459 def find_in_html(html, start, end, firstonly=True):
5460         n, out = 0, []
5461         while n < len(html):
5462                 m = re.search(start, html[n:])
5463                 if not m:
5464                         break
5465                 i = m.end()
5466                 m = re.search(end, html[n+i:])
5467                 if not m:
5468                         break
5469                 j = m.start()
5470                 str = html[n+i:n+i+j]
5471                 if end == 'ms':
5472                         num = re.search(r'[-+]?\d*\.\d+|\d+', str)
5473                         str = num.group() if num else 'NaN'
5474                 if firstonly:
5475                         return str
5476                 out.append(str)
5477                 n += i+j
5478         if firstonly:
5479                 return ''
5480         return out
5481
5482 def data_from_html(file, outpath, devlist=False):
5483         html = open(file, 'r').read()
5484         suspend = find_in_html(html, 'Kernel Suspend', 'ms')
5485         resume = find_in_html(html, 'Kernel Resume', 'ms')
5486         line = find_in_html(html, '<div class="stamp">', '</div>')
5487         stmp = line.split()
5488         if not suspend or not resume or len(stmp) != 8:
5489                 return False
5490         try:
5491                 dt = datetime.strptime(' '.join(stmp[3:]), '%B %d %Y, %I:%M:%S %p')
5492         except:
5493                 return False
5494         tstr = dt.strftime('%Y/%m/%d %H:%M:%S')
5495         error = find_in_html(html, '<table class="testfail"><tr><td>', '</td>')
5496         if error:
5497                 m = re.match('[a-z]* failed in (?P<p>[a-z0-9_]*) phase', error)
5498                 if m:
5499                         result = 'fail in %s' % m.group('p')
5500                 else:
5501                         result = 'fail'
5502         else:
5503                 result = 'pass'
5504         ilist = []
5505         e = find_in_html(html, 'class="err"[\w=":;\.%\- ]*>', '&rarr;</div>', False)
5506         for i in list(set(e)):
5507                 ilist.append('%sx%d' % (i, e.count(i)) if e.count(i) > 1 else i)
5508         low = find_in_html(html, 'freeze time: <b>', ' ms</b>')
5509         if low and '|' in low:
5510                 ilist.append('FREEZEx%d' % len(low.split('|')))
5511         devices = dict()
5512         for line in html.split('\n'):
5513                 m = re.match(' *<div id=\"[a,0-9]*\" *title=\"(?P<title>.*)\" class=\"thread.*', line)
5514                 if not m or 'thread kth' in line or 'thread sec' in line:
5515                         continue
5516                 m = re.match('(?P<n>.*) \((?P<t>[0-9,\.]*) ms\) (?P<p>.*)', m.group('title'))
5517                 if not m:
5518                         continue
5519                 name, time, phase = m.group('n'), m.group('t'), m.group('p')
5520                 if ' async' in name or ' sync' in name:
5521                         name = ' '.join(name.split(' ')[:-1])
5522                 d = phase.split('_')[0]
5523                 if d not in devices:
5524                         devices[d] = dict()
5525                 if name not in devices[d]:
5526                         devices[d][name] = 0.0
5527                 devices[d][name] += float(time)
5528         worst  = {'suspend': {'name':'', 'time': 0.0},
5529                 'resume': {'name':'', 'time': 0.0}}
5530         for d in devices:
5531                 if d not in worst:
5532                         worst[d] = dict()
5533                 dev = devices[d]
5534                 if len(dev.keys()) > 0:
5535                         n = sorted(dev, key=dev.get, reverse=True)[0]
5536                         worst[d]['name'], worst[d]['time'] = n, dev[n]
5537         data = {
5538                 'mode': stmp[2],
5539                 'host': stmp[0],
5540                 'kernel': stmp[1],
5541                 'time': tstr,
5542                 'result': result,
5543                 'issues': ' '.join(ilist),
5544                 'suspend': suspend,
5545                 'resume': resume,
5546                 'sus_worst': worst['suspend']['name'],
5547                 'sus_worsttime': worst['suspend']['time'],
5548                 'res_worst': worst['resume']['name'],
5549                 'res_worsttime': worst['resume']['time'],
5550                 'url': os.path.relpath(file, outpath),
5551         }
5552         if devlist:
5553                 data['devlist'] = devices
5554         return data
5555
5556 # Function: runSummary
5557 # Description:
5558 #        create a summary of tests in a sub-directory
5559 def runSummary(subdir, local=True, genhtml=False):
5560         inpath = os.path.abspath(subdir)
5561         outpath = os.path.abspath('.') if local else inpath
5562         pprint('Generating a summary of folder "%s"' % inpath)
5563         if genhtml:
5564                 for dirname, dirnames, filenames in os.walk(subdir):
5565                         sysvals.dmesgfile = sysvals.ftracefile = sysvals.htmlfile = ''
5566                         for filename in filenames:
5567                                 if(re.match('.*_dmesg.txt', filename)):
5568                                         sysvals.dmesgfile = os.path.join(dirname, filename)
5569                                 elif(re.match('.*_ftrace.txt', filename)):
5570                                         sysvals.ftracefile = os.path.join(dirname, filename)
5571                         sysvals.setOutputFile()
5572                         if sysvals.ftracefile and sysvals.htmlfile and \
5573                                 not os.path.exists(sysvals.htmlfile):
5574                                 pprint('FTRACE: %s' % sysvals.ftracefile)
5575                                 if sysvals.dmesgfile:
5576                                         pprint('DMESG : %s' % sysvals.dmesgfile)
5577                                 rerunTest()
5578         testruns = []
5579         desc = {'host':[],'mode':[],'kernel':[]}
5580         for dirname, dirnames, filenames in os.walk(subdir):
5581                 for filename in filenames:
5582                         if(not re.match('.*.html', filename)):
5583                                 continue
5584                         data = data_from_html(os.path.join(dirname, filename), outpath)
5585                         if(not data):
5586                                 continue
5587                         testruns.append(data)
5588                         for key in desc:
5589                                 if data[key] not in desc[key]:
5590                                         desc[key].append(data[key])
5591         outfile = os.path.join(outpath, 'summary.html')
5592         pprint('Summary file: %s' % outfile)
5593         if len(desc['host']) == len(desc['mode']) == len(desc['kernel']) == 1:
5594                 title = '%s %s %s' % (desc['host'][0], desc['kernel'][0], desc['mode'][0])
5595         else:
5596                 title = inpath
5597         createHTMLSummarySimple(testruns, outfile, title)
5598
5599 # Function: checkArgBool
5600 # Description:
5601 #        check if a boolean string value is true or false
5602 def checkArgBool(name, value):
5603         if value in switchvalues:
5604                 if value in switchoff:
5605                         return False
5606                 return True
5607         doError('invalid boolean --> (%s: %s), use "true/false" or "1/0"' % (name, value), True)
5608         return False
5609
5610 # Function: configFromFile
5611 # Description:
5612 #        Configure the script via the info in a config file
5613 def configFromFile(file):
5614         Config = ConfigParser.ConfigParser()
5615
5616         Config.read(file)
5617         sections = Config.sections()
5618         overridekprobes = False
5619         overridedevkprobes = False
5620         if 'Settings' in sections:
5621                 for opt in Config.options('Settings'):
5622                         value = Config.get('Settings', opt).lower()
5623                         option = opt.lower()
5624                         if(option == 'verbose'):
5625                                 sysvals.verbose = checkArgBool(option, value)
5626                         elif(option == 'addlogs'):
5627                                 sysvals.dmesglog = sysvals.ftracelog = checkArgBool(option, value)
5628                         elif(option == 'dev'):
5629                                 sysvals.usedevsrc = checkArgBool(option, value)
5630                         elif(option == 'proc'):
5631                                 sysvals.useprocmon = checkArgBool(option, value)
5632                         elif(option == 'x2'):
5633                                 if checkArgBool(option, value):
5634                                         sysvals.execcount = 2
5635                         elif(option == 'callgraph'):
5636                                 sysvals.usecallgraph = checkArgBool(option, value)
5637                         elif(option == 'override-timeline-functions'):
5638                                 overridekprobes = checkArgBool(option, value)
5639                         elif(option == 'override-dev-timeline-functions'):
5640                                 overridedevkprobes = checkArgBool(option, value)
5641                         elif(option == 'skiphtml'):
5642                                 sysvals.skiphtml = checkArgBool(option, value)
5643                         elif(option == 'sync'):
5644                                 sysvals.sync = checkArgBool(option, value)
5645                         elif(option == 'rs' or option == 'runtimesuspend'):
5646                                 if value in switchvalues:
5647                                         if value in switchoff:
5648                                                 sysvals.rs = -1
5649                                         else:
5650                                                 sysvals.rs = 1
5651                                 else:
5652                                         doError('invalid value --> (%s: %s), use "enable/disable"' % (option, value), True)
5653                         elif(option == 'display'):
5654                                 disopt = ['on', 'off', 'standby', 'suspend']
5655                                 if value not in disopt:
5656                                         doError('invalid value --> (%s: %s), use %s' % (option, value, disopt), True)
5657                                 sysvals.display = value
5658                         elif(option == 'gzip'):
5659                                 sysvals.gzip = checkArgBool(option, value)
5660                         elif(option == 'cgfilter'):
5661                                 sysvals.setCallgraphFilter(value)
5662                         elif(option == 'cgskip'):
5663                                 if value in switchoff:
5664                                         sysvals.cgskip = ''
5665                                 else:
5666                                         sysvals.cgskip = sysvals.configFile(val)
5667                                         if(not sysvals.cgskip):
5668                                                 doError('%s does not exist' % sysvals.cgskip)
5669                         elif(option == 'cgtest'):
5670                                 sysvals.cgtest = getArgInt('cgtest', value, 0, 1, False)
5671                         elif(option == 'cgphase'):
5672                                 d = Data(0)
5673                                 if value not in d.sortedPhases():
5674                                         doError('invalid phase --> (%s: %s), valid phases are %s'\
5675                                                 % (option, value, d.sortedPhases()), True)
5676                                 sysvals.cgphase = value
5677                         elif(option == 'fadd'):
5678                                 file = sysvals.configFile(value)
5679                                 if(not file):
5680                                         doError('%s does not exist' % value)
5681                                 sysvals.addFtraceFilterFunctions(file)
5682                         elif(option == 'result'):
5683                                 sysvals.result = value
5684                         elif(option == 'multi'):
5685                                 nums = value.split()
5686                                 if len(nums) != 2:
5687                                         doError('multi requires 2 integers (exec_count and delay)', True)
5688                                 sysvals.multitest['run'] = True
5689                                 sysvals.multitest['count'] = getArgInt('multi: n d (exec count)', nums[0], 2, 1000000, False)
5690                                 sysvals.multitest['delay'] = getArgInt('multi: n d (delay between tests)', nums[1], 0, 3600, False)
5691                         elif(option == 'devicefilter'):
5692                                 sysvals.setDeviceFilter(value)
5693                         elif(option == 'expandcg'):
5694                                 sysvals.cgexp = checkArgBool(option, value)
5695                         elif(option == 'srgap'):
5696                                 if checkArgBool(option, value):
5697                                         sysvals.srgap = 5
5698                         elif(option == 'mode'):
5699                                 sysvals.suspendmode = value
5700                         elif(option == 'command' or option == 'cmd'):
5701                                 sysvals.testcommand = value
5702                         elif(option == 'x2delay'):
5703                                 sysvals.x2delay = getArgInt('x2delay', value, 0, 60000, False)
5704                         elif(option == 'predelay'):
5705                                 sysvals.predelay = getArgInt('predelay', value, 0, 60000, False)
5706                         elif(option == 'postdelay'):
5707                                 sysvals.postdelay = getArgInt('postdelay', value, 0, 60000, False)
5708                         elif(option == 'maxdepth'):
5709                                 sysvals.max_graph_depth = getArgInt('maxdepth', value, 0, 1000, False)
5710                         elif(option == 'rtcwake'):
5711                                 if value in switchoff:
5712                                         sysvals.rtcwake = False
5713                                 else:
5714                                         sysvals.rtcwake = True
5715                                         sysvals.rtcwaketime = getArgInt('rtcwake', value, 0, 3600, False)
5716                         elif(option == 'timeprec'):
5717                                 sysvals.setPrecision(getArgInt('timeprec', value, 0, 6, False))
5718                         elif(option == 'mindev'):
5719                                 sysvals.mindevlen = getArgFloat('mindev', value, 0.0, 10000.0, False)
5720                         elif(option == 'callloop-maxgap'):
5721                                 sysvals.callloopmaxgap = getArgFloat('callloop-maxgap', value, 0.0, 1.0, False)
5722                         elif(option == 'callloop-maxlen'):
5723                                 sysvals.callloopmaxgap = getArgFloat('callloop-maxlen', value, 0.0, 1.0, False)
5724                         elif(option == 'mincg'):
5725                                 sysvals.mincglen = getArgFloat('mincg', value, 0.0, 10000.0, False)
5726                         elif(option == 'bufsize'):
5727                                 sysvals.bufsize = getArgInt('bufsize', value, 1, 1024*1024*8, False)
5728                         elif(option == 'output-dir'):
5729                                 sysvals.outdir = sysvals.setOutputFolder(value)
5730
5731         if sysvals.suspendmode == 'command' and not sysvals.testcommand:
5732                 doError('No command supplied for mode "command"')
5733
5734         # compatibility errors
5735         if sysvals.usedevsrc and sysvals.usecallgraph:
5736                 doError('-dev is not compatible with -f')
5737         if sysvals.usecallgraph and sysvals.useprocmon:
5738                 doError('-proc is not compatible with -f')
5739
5740         if overridekprobes:
5741                 sysvals.tracefuncs = dict()
5742         if overridedevkprobes:
5743                 sysvals.dev_tracefuncs = dict()
5744
5745         kprobes = dict()
5746         kprobesec = 'dev_timeline_functions_'+platform.machine()
5747         if kprobesec in sections:
5748                 for name in Config.options(kprobesec):
5749                         text = Config.get(kprobesec, name)
5750                         kprobes[name] = (text, True)
5751         kprobesec = 'timeline_functions_'+platform.machine()
5752         if kprobesec in sections:
5753                 for name in Config.options(kprobesec):
5754                         if name in kprobes:
5755                                 doError('Duplicate timeline function found "%s"' % (name))
5756                         text = Config.get(kprobesec, name)
5757                         kprobes[name] = (text, False)
5758
5759         for name in kprobes:
5760                 function = name
5761                 format = name
5762                 color = ''
5763                 args = dict()
5764                 text, dev = kprobes[name]
5765                 data = text.split()
5766                 i = 0
5767                 for val in data:
5768                         # bracketted strings are special formatting, read them separately
5769                         if val[0] == '[' and val[-1] == ']':
5770                                 for prop in val[1:-1].split(','):
5771                                         p = prop.split('=')
5772                                         if p[0] == 'color':
5773                                                 try:
5774                                                         color = int(p[1], 16)
5775                                                         color = '#'+p[1]
5776                                                 except:
5777                                                         color = p[1]
5778                                 continue
5779                         # first real arg should be the format string
5780                         if i == 0:
5781                                 format = val
5782                         # all other args are actual function args
5783                         else:
5784                                 d = val.split('=')
5785                                 args[d[0]] = d[1]
5786                         i += 1
5787                 if not function or not format:
5788                         doError('Invalid kprobe: %s' % name)
5789                 for arg in re.findall('{(?P<n>[a-z,A-Z,0-9]*)}', format):
5790                         if arg not in args:
5791                                 doError('Kprobe "%s" is missing argument "%s"' % (name, arg))
5792                 if (dev and name in sysvals.dev_tracefuncs) or (not dev and name in sysvals.tracefuncs):
5793                         doError('Duplicate timeline function found "%s"' % (name))
5794
5795                 kp = {
5796                         'name': name,
5797                         'func': function,
5798                         'format': format,
5799                         sysvals.archargs: args
5800                 }
5801                 if color:
5802                         kp['color'] = color
5803                 if dev:
5804                         sysvals.dev_tracefuncs[name] = kp
5805                 else:
5806                         sysvals.tracefuncs[name] = kp
5807
5808 # Function: printHelp
5809 # Description:
5810 #        print out the help text
5811 def printHelp():
5812         pprint('\n%s v%s\n'\
5813         'Usage: sudo sleepgraph <options> <commands>\n'\
5814         '\n'\
5815         'Description:\n'\
5816         '  This tool is designed to assist kernel and OS developers in optimizing\n'\
5817         '  their linux stack\'s suspend/resume time. Using a kernel image built\n'\
5818         '  with a few extra options enabled, the tool will execute a suspend and\n'\
5819         '  capture dmesg and ftrace data until resume is complete. This data is\n'\
5820         '  transformed into a device timeline and an optional callgraph to give\n'\
5821         '  a detailed view of which devices/subsystems are taking the most\n'\
5822         '  time in suspend/resume.\n'\
5823         '\n'\
5824         '  If no specific command is given, the default behavior is to initiate\n'\
5825         '  a suspend/resume and capture the dmesg/ftrace output as an html timeline.\n'\
5826         '\n'\
5827         '  Generates output files in subdirectory: suspend-yymmdd-HHMMSS\n'\
5828         '   HTML output:                    <hostname>_<mode>.html\n'\
5829         '   raw dmesg output:               <hostname>_<mode>_dmesg.txt\n'\
5830         '   raw ftrace output:              <hostname>_<mode>_ftrace.txt\n'\
5831         '\n'\
5832         'Options:\n'\
5833         '   -h           Print this help text\n'\
5834         '   -v           Print the current tool version\n'\
5835         '   -config fn   Pull arguments and config options from file fn\n'\
5836         '   -verbose     Print extra information during execution and analysis\n'\
5837         '   -m mode      Mode to initiate for suspend (default: %s)\n'\
5838         '   -o name      Overrides the output subdirectory name when running a new test\n'\
5839         '                default: suspend-{date}-{time}\n'\
5840         '   -rtcwake t   Wakeup t seconds after suspend, set t to "off" to disable (default: 15)\n'\
5841         '   -addlogs     Add the dmesg and ftrace logs to the html output\n'\
5842         '   -srgap       Add a visible gap in the timeline between sus/res (default: disabled)\n'\
5843         '   -skiphtml    Run the test and capture the trace logs, but skip the timeline (default: disabled)\n'\
5844         '   -result fn   Export a results table to a text file for parsing.\n'\
5845         '  [testprep]\n'\
5846         '   -sync        Sync the filesystems before starting the test\n'\
5847         '   -rs on/off   Enable/disable runtime suspend for all devices, restore all after test\n'\
5848         '   -display m   Change the display mode to m for the test (on/off/standby/suspend)\n'\
5849         '  [advanced]\n'\
5850         '   -gzip        Gzip the trace and dmesg logs to save space\n'\
5851         '   -cmd {s}     Run the timeline over a custom command, e.g. "sync -d"\n'\
5852         '   -proc        Add usermode process info into the timeline (default: disabled)\n'\
5853         '   -dev         Add kernel function calls and threads to the timeline (default: disabled)\n'\
5854         '   -x2          Run two suspend/resumes back to back (default: disabled)\n'\
5855         '   -x2delay t   Include t ms delay between multiple test runs (default: 0 ms)\n'\
5856         '   -predelay t  Include t ms delay before 1st suspend (default: 0 ms)\n'\
5857         '   -postdelay t Include t ms delay after last resume (default: 0 ms)\n'\
5858         '   -mindev ms   Discard all device blocks shorter than ms milliseconds (e.g. 0.001 for us)\n'\
5859         '   -multi n d   Execute <n> consecutive tests at <d> seconds intervals. The outputs will\n'\
5860         '                be created in a new subdirectory with a summary page.\n'\
5861         '  [debug]\n'\
5862         '   -f           Use ftrace to create device callgraphs (default: disabled)\n'\
5863         '   -maxdepth N  limit the callgraph data to N call levels (default: 0=all)\n'\
5864         '   -expandcg    pre-expand the callgraph data in the html output (default: disabled)\n'\
5865         '   -fadd file   Add functions to be graphed in the timeline from a list in a text file\n'\
5866         '   -filter "d1,d2,..." Filter out all but this comma-delimited list of device names\n'\
5867         '   -mincg  ms   Discard all callgraphs shorter than ms milliseconds (e.g. 0.001 for us)\n'\
5868         '   -cgphase P   Only show callgraph data for phase P (e.g. suspend_late)\n'\
5869         '   -cgtest N    Only show callgraph data for test N (e.g. 0 or 1 in an x2 run)\n'\
5870         '   -timeprec N  Number of significant digits in timestamps (0:S, [3:ms], 6:us)\n'\
5871         '   -cgfilter S  Filter the callgraph output in the timeline\n'\
5872         '   -cgskip file Callgraph functions to skip, off to disable (default: cgskip.txt)\n'\
5873         '   -bufsize N   Set trace buffer size to N kilo-bytes (default: all of free memory)\n'\
5874         '   -devdump     Print out all the raw device data for each phase\n'\
5875         '   -cgdump      Print out all the raw callgraph data\n'\
5876         '\n'\
5877         'Other commands:\n'\
5878         '   -modes       List available suspend modes\n'\
5879         '   -status      Test to see if the system is enabled to run this tool\n'\
5880         '   -fpdt        Print out the contents of the ACPI Firmware Performance Data Table\n'\
5881         '   -battery     Print out battery info (if available)\n'\
5882         '   -x<mode>     Test xset by toggling the given mode (on/off/standby/suspend)\n'\
5883         '   -sysinfo     Print out system info extracted from BIOS\n'\
5884         '   -devinfo     Print out the pm settings of all devices which support runtime suspend\n'\
5885         '   -flist       Print the list of functions currently being captured in ftrace\n'\
5886         '   -flistall    Print all functions capable of being captured in ftrace\n'\
5887         '   -summary dir Create a summary of tests in this dir [-genhtml builds missing html]\n'\
5888         '  [redo]\n'\
5889         '   -ftrace ftracefile  Create HTML output using ftrace input (used with -dmesg)\n'\
5890         '   -dmesg dmesgfile    Create HTML output using dmesg (used with -ftrace)\n'\
5891         '' % (sysvals.title, sysvals.version, sysvals.suspendmode))
5892         return True
5893
5894 # ----------------- MAIN --------------------
5895 # exec start (skipped if script is loaded as library)
5896 if __name__ == '__main__':
5897         genhtml = False
5898         cmd = ''
5899         simplecmds = ['-sysinfo', '-modes', '-fpdt', '-flist', '-flistall',
5900                 '-devinfo', '-status', '-battery', '-xon', '-xoff', '-xstandby',
5901                 '-xsuspend', '-xinit', '-xreset', '-xstat']
5902         if '-f' in sys.argv:
5903                 sysvals.cgskip = sysvals.configFile('cgskip.txt')
5904         # loop through the command line arguments
5905         args = iter(sys.argv[1:])
5906         for arg in args:
5907                 if(arg == '-m'):
5908                         try:
5909                                 val = args.next()
5910                         except:
5911                                 doError('No mode supplied', True)
5912                         if val == 'command' and not sysvals.testcommand:
5913                                 doError('No command supplied for mode "command"', True)
5914                         sysvals.suspendmode = val
5915                 elif(arg in simplecmds):
5916                         cmd = arg[1:]
5917                 elif(arg == '-h'):
5918                         printHelp()
5919                         sys.exit(0)
5920                 elif(arg == '-v'):
5921                         pprint("Version %s" % sysvals.version)
5922                         sys.exit(0)
5923                 elif(arg == '-x2'):
5924                         sysvals.execcount = 2
5925                 elif(arg == '-x2delay'):
5926                         sysvals.x2delay = getArgInt('-x2delay', args, 0, 60000)
5927                 elif(arg == '-predelay'):
5928                         sysvals.predelay = getArgInt('-predelay', args, 0, 60000)
5929                 elif(arg == '-postdelay'):
5930                         sysvals.postdelay = getArgInt('-postdelay', args, 0, 60000)
5931                 elif(arg == '-f'):
5932                         sysvals.usecallgraph = True
5933                 elif(arg == '-skiphtml'):
5934                         sysvals.skiphtml = True
5935                 elif(arg == '-cgdump'):
5936                         sysvals.cgdump = True
5937                 elif(arg == '-devdump'):
5938                         sysvals.devdump = True
5939                 elif(arg == '-genhtml'):
5940                         genhtml = True
5941                 elif(arg == '-addlogs'):
5942                         sysvals.dmesglog = sysvals.ftracelog = True
5943                 elif(arg == '-addlogdmesg'):
5944                         sysvals.dmesglog = True
5945                 elif(arg == '-addlogftrace'):
5946                         sysvals.ftracelog = True
5947                 elif(arg == '-verbose'):
5948                         sysvals.verbose = True
5949                 elif(arg == '-proc'):
5950                         sysvals.useprocmon = True
5951                 elif(arg == '-dev'):
5952                         sysvals.usedevsrc = True
5953                 elif(arg == '-sync'):
5954                         sysvals.sync = True
5955                 elif(arg == '-gzip'):
5956                         sysvals.gzip = True
5957                 elif(arg == '-rs'):
5958                         try:
5959                                 val = args.next()
5960                         except:
5961                                 doError('-rs requires "enable" or "disable"', True)
5962                         if val.lower() in switchvalues:
5963                                 if val.lower() in switchoff:
5964                                         sysvals.rs = -1
5965                                 else:
5966                                         sysvals.rs = 1
5967                         else:
5968                                 doError('invalid option: %s, use "enable/disable" or "on/off"' % val, True)
5969                 elif(arg == '-display'):
5970                         try:
5971                                 val = args.next()
5972                         except:
5973                                 doError('-display requires an mode value', True)
5974                         disopt = ['on', 'off', 'standby', 'suspend']
5975                         if val.lower() not in disopt:
5976                                 doError('valid display mode values are %s' % disopt, True)
5977                         sysvals.display = val.lower()
5978                 elif(arg == '-maxdepth'):
5979                         sysvals.max_graph_depth = getArgInt('-maxdepth', args, 0, 1000)
5980                 elif(arg == '-rtcwake'):
5981                         try:
5982                                 val = args.next()
5983                         except:
5984                                 doError('No rtcwake time supplied', True)
5985                         if val.lower() in switchoff:
5986                                 sysvals.rtcwake = False
5987                         else:
5988                                 sysvals.rtcwake = True
5989                                 sysvals.rtcwaketime = getArgInt('-rtcwake', val, 0, 3600, False)
5990                 elif(arg == '-timeprec'):
5991                         sysvals.setPrecision(getArgInt('-timeprec', args, 0, 6))
5992                 elif(arg == '-mindev'):
5993                         sysvals.mindevlen = getArgFloat('-mindev', args, 0.0, 10000.0)
5994                 elif(arg == '-mincg'):
5995                         sysvals.mincglen = getArgFloat('-mincg', args, 0.0, 10000.0)
5996                 elif(arg == '-bufsize'):
5997                         sysvals.bufsize = getArgInt('-bufsize', args, 1, 1024*1024*8)
5998                 elif(arg == '-cgtest'):
5999                         sysvals.cgtest = getArgInt('-cgtest', args, 0, 1)
6000                 elif(arg == '-cgphase'):
6001                         try:
6002                                 val = args.next()
6003                         except:
6004                                 doError('No phase name supplied', True)
6005                         d = Data(0)
6006                         if val not in d.phasedef:
6007                                 doError('invalid phase --> (%s: %s), valid phases are %s'\
6008                                         % (arg, val, d.phasedef.keys()), True)
6009                         sysvals.cgphase = val
6010                 elif(arg == '-cgfilter'):
6011                         try:
6012                                 val = args.next()
6013                         except:
6014                                 doError('No callgraph functions supplied', True)
6015                         sysvals.setCallgraphFilter(val)
6016                 elif(arg == '-cgskip'):
6017                         try:
6018                                 val = args.next()
6019                         except:
6020                                 doError('No file supplied', True)
6021                         if val.lower() in switchoff:
6022                                 sysvals.cgskip = ''
6023                         else:
6024                                 sysvals.cgskip = sysvals.configFile(val)
6025                                 if(not sysvals.cgskip):
6026                                         doError('%s does not exist' % sysvals.cgskip)
6027                 elif(arg == '-callloop-maxgap'):
6028                         sysvals.callloopmaxgap = getArgFloat('-callloop-maxgap', args, 0.0, 1.0)
6029                 elif(arg == '-callloop-maxlen'):
6030                         sysvals.callloopmaxlen = getArgFloat('-callloop-maxlen', args, 0.0, 1.0)
6031                 elif(arg == '-cmd'):
6032                         try:
6033                                 val = args.next()
6034                         except:
6035                                 doError('No command string supplied', True)
6036                         sysvals.testcommand = val
6037                         sysvals.suspendmode = 'command'
6038                 elif(arg == '-expandcg'):
6039                         sysvals.cgexp = True
6040                 elif(arg == '-srgap'):
6041                         sysvals.srgap = 5
6042                 elif(arg == '-multi'):
6043                         sysvals.multitest['run'] = True
6044                         sysvals.multitest['count'] = getArgInt('-multi n d (exec count)', args, 2, 1000000)
6045                         sysvals.multitest['delay'] = getArgInt('-multi n d (delay between tests)', args, 0, 3600)
6046                 elif(arg == '-o'):
6047                         try:
6048                                 val = args.next()
6049                         except:
6050                                 doError('No subdirectory name supplied', True)
6051                         sysvals.outdir = sysvals.setOutputFolder(val)
6052                 elif(arg == '-config'):
6053                         try:
6054                                 val = args.next()
6055                         except:
6056                                 doError('No text file supplied', True)
6057                         file = sysvals.configFile(val)
6058                         if(not file):
6059                                 doError('%s does not exist' % val)
6060                         configFromFile(file)
6061                 elif(arg == '-fadd'):
6062                         try:
6063                                 val = args.next()
6064                         except:
6065                                 doError('No text file supplied', True)
6066                         file = sysvals.configFile(val)
6067                         if(not file):
6068                                 doError('%s does not exist' % val)
6069                         sysvals.addFtraceFilterFunctions(file)
6070                 elif(arg == '-dmesg'):
6071                         try:
6072                                 val = args.next()
6073                         except:
6074                                 doError('No dmesg file supplied', True)
6075                         sysvals.notestrun = True
6076                         sysvals.dmesgfile = val
6077                         if(os.path.exists(sysvals.dmesgfile) == False):
6078                                 doError('%s does not exist' % sysvals.dmesgfile)
6079                 elif(arg == '-ftrace'):
6080                         try:
6081                                 val = args.next()
6082                         except:
6083                                 doError('No ftrace file supplied', True)
6084                         sysvals.notestrun = True
6085                         sysvals.ftracefile = val
6086                         if(os.path.exists(sysvals.ftracefile) == False):
6087                                 doError('%s does not exist' % sysvals.ftracefile)
6088                 elif(arg == '-summary'):
6089                         try:
6090                                 val = args.next()
6091                         except:
6092                                 doError('No directory supplied', True)
6093                         cmd = 'summary'
6094                         sysvals.outdir = val
6095                         sysvals.notestrun = True
6096                         if(os.path.isdir(val) == False):
6097                                 doError('%s is not accesible' % val)
6098                 elif(arg == '-filter'):
6099                         try:
6100                                 val = args.next()
6101                         except:
6102                                 doError('No devnames supplied', True)
6103                         sysvals.setDeviceFilter(val)
6104                 elif(arg == '-result'):
6105                         try:
6106                                 val = args.next()
6107                         except:
6108                                 doError('No result file supplied', True)
6109                         sysvals.result = val
6110                         sysvals.signalHandlerInit()
6111                 else:
6112                         doError('Invalid argument: '+arg, True)
6113
6114         # compatibility errors
6115         if(sysvals.usecallgraph and sysvals.usedevsrc):
6116                 doError('-dev is not compatible with -f')
6117         if(sysvals.usecallgraph and sysvals.useprocmon):
6118                 doError('-proc is not compatible with -f')
6119
6120         if sysvals.usecallgraph and sysvals.cgskip:
6121                 sysvals.vprint('Using cgskip file: %s' % sysvals.cgskip)
6122                 sysvals.setCallgraphBlacklist(sysvals.cgskip)
6123
6124         # callgraph size cannot exceed device size
6125         if sysvals.mincglen < sysvals.mindevlen:
6126                 sysvals.mincglen = sysvals.mindevlen
6127
6128         # remove existing buffers before calculating memory
6129         if(sysvals.usecallgraph or sysvals.usedevsrc):
6130                 sysvals.fsetVal('16', 'buffer_size_kb')
6131         sysvals.cpuInfo()
6132
6133         # just run a utility command and exit
6134         if(cmd != ''):
6135                 ret = 0
6136                 if(cmd == 'status'):
6137                         if not statusCheck(True):
6138                                 ret = 1
6139                 elif(cmd == 'fpdt'):
6140                         if not getFPDT(True):
6141                                 ret = 1
6142                 elif(cmd == 'battery'):
6143                         out = getBattery()
6144                         if out:
6145                                 pprint('AC Connect    : %s\nBattery Charge: %d' % out)
6146                         else:
6147                                 pprint('no battery found')
6148                                 ret = 1
6149                 elif(cmd == 'sysinfo'):
6150                         sysvals.printSystemInfo(True)
6151                 elif(cmd == 'devinfo'):
6152                         deviceInfo()
6153                 elif(cmd == 'modes'):
6154                         print getModes()
6155                 elif(cmd == 'flist'):
6156                         sysvals.getFtraceFilterFunctions(True)
6157                 elif(cmd == 'flistall'):
6158                         sysvals.getFtraceFilterFunctions(False)
6159                 elif(cmd == 'summary'):
6160                         runSummary(sysvals.outdir, True, genhtml)
6161                 elif(cmd in ['xon', 'xoff', 'xstandby', 'xsuspend', 'xinit', 'xreset']):
6162                         sysvals.verbose = True
6163                         ret = displayControl(cmd[1:])
6164                 elif(cmd == 'xstat'):
6165                         pprint('Display Status: %s' % displayControl('stat').upper())
6166                 sys.exit(ret)
6167
6168         # if instructed, re-analyze existing data files
6169         if(sysvals.notestrun):
6170                 stamp = rerunTest()
6171                 sysvals.outputResult(stamp)
6172                 sys.exit(0)
6173
6174         # verify that we can run a test
6175         error = statusCheck()
6176         if(error):
6177                 doError(error)
6178
6179         # extract mem/disk extra modes and convert
6180         mode = sysvals.suspendmode
6181         if mode.startswith('mem'):
6182                 memmode = mode.split('-', 1)[-1] if '-' in mode else 'deep'
6183                 if memmode == 'shallow':
6184                         mode = 'standby'
6185                 elif memmode ==  's2idle':
6186                         mode = 'freeze'
6187                 else:
6188                         mode = 'mem'
6189                 sysvals.memmode = memmode
6190                 sysvals.suspendmode = mode
6191         if mode.startswith('disk-'):
6192                 sysvals.diskmode = mode.split('-', 1)[-1]
6193                 sysvals.suspendmode = 'disk'
6194
6195         sysvals.systemInfo(dmidecode(sysvals.mempath))
6196
6197         setRuntimeSuspend(True)
6198         if sysvals.display:
6199                 displayControl('init')
6200         ret = 0
6201         if sysvals.multitest['run']:
6202                 # run multiple tests in a separate subdirectory
6203                 if not sysvals.outdir:
6204                         s = 'suspend-x%d' % sysvals.multitest['count']
6205                         sysvals.outdir = datetime.now().strftime(s+'-%y%m%d-%H%M%S')
6206                 if not os.path.isdir(sysvals.outdir):
6207                         os.mkdir(sysvals.outdir)
6208                 for i in range(sysvals.multitest['count']):
6209                         if(i != 0):
6210                                 pprint('Waiting %d seconds...' % (sysvals.multitest['delay']))
6211                                 time.sleep(sysvals.multitest['delay'])
6212                         pprint('TEST (%d/%d) START' % (i+1, sysvals.multitest['count']))
6213                         fmt = 'suspend-%y%m%d-%H%M%S'
6214                         sysvals.testdir = os.path.join(sysvals.outdir, datetime.now().strftime(fmt))
6215                         ret = runTest(i+1)
6216                         pprint('TEST (%d/%d) COMPLETE' % (i+1, sysvals.multitest['count']))
6217                         sysvals.logmsg = ''
6218                 if not sysvals.skiphtml:
6219                         runSummary(sysvals.outdir, False, False)
6220                 sysvals.sudoUserchown(sysvals.outdir)
6221         else:
6222                 if sysvals.outdir:
6223                         sysvals.testdir = sysvals.outdir
6224                 # run the test in the current directory
6225                 ret = runTest()
6226         if sysvals.display:
6227                 displayControl('reset')
6228         setRuntimeSuspend(False)
6229         sys.exit(ret)