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