tools/power/pm-graph/analyze_suspend.py

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