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