nded reservations for Forbidden Zones paper @ RTAS'20
aboutsummaryrefslogblamecommitdiffstats
path: root/scripts/analyze_suspend.py
blob: 93e1fd40f43053e599c3d986dd15fb574ea2fb76 (plain) (tree)
1119
1120
1121
1122
1123
1124
1125
1126
1127
1128
1129
1130
1131
1132
1133
1134
1135
1136
1137
1138
1139
1140
1141
1142
1143
1144
1145
1146
1147
1148
1149
1150
1151
1152
1153
1154
1155
1156
1157
1158
1159
1160
1161
1162
1163
1164
1165
1166
1167
1168
1169
1170
1171
1172
1173
1174
1175
1176
1177
1178
1179
1180
1181
1182
1183
1184
1185
1186
1187
1188
1189
1190
1191
1192
1193
1194
1195
1196
1197
1198
1199
1200
1201
1202
1203
1204
1205
1206
1207
1208
1209
1210
1211
1212
1213
1214
1215
1216
1217
1218
1219
1220
1221
1222
1223
1224
1225
1226
1227
1228
1229
1230
1231
1232
1233
1234
1235
1236
1237
1238
1239
1240
1241
1242
1243
1244
1245
1246
1247
1248
1249
1250
1251
1252
1253
1254
1255
1256
1257
1258
1259
1260
1261
1262
1263
1264
1265
1266
1267
1268
1269
1270
1271
1272
1273
1274
1275
1276
1277
1278
1279
1280
1281
1282
1283
1284
1285
1286
1287
1288
1289
1290
1291
1292
1293
1294
1295
1296
1297
1298
1299
1300
1301
1302
1303
1304
1305
1306
1307
1308
1309
1310
1311
1312
1313
1314
1315
1316
1317
1318
1319
1320
1321
1322
1323
1324
1325
1326
1327
1328
1329
1330
1331
1332
1333
1334
1335
1336
1337
1338
1339
1340
1341
1342
1343
1344
1345
1346
1347
1348
1349
1350
1351
1352
1353
1354
1355
1356
1357
1358
1359
1360
1361
1362
1363
1364
1365
1366
1367
1368
1369
1370
1371
1372
1373
1374
1375
1376
1377
1378
1379
1380
1381
1382
1383
1384
1385
1386
1387
1388
1389
1390
1391
1392
1393
1394
1395
1396
1397
1398
1399
1400
1401
1402
1403
1404
1405
1406
1407
1408
1409
1410
1411
1412
1413
1414
1415
1416
1417
1418
1419
1420
1421
1422
1423
1424
1425
1426
1427
1428
1429
1430
1431
1432
1433
1434
1435
1436
1437
1438
1439
1440
1441
1442
1443
1444
1445
1446
1447
1448
1449
1450
1451
1452
1453
1454
1455
1456
1457
1458
1459
1460
1461
1462
1463
1464
1465
1466
1467
1468
1469
1470
1471
1472
1473
1474
1475
1476
1477
1478
1479
1480
1481
1482
1483
1484
1485
1486
1487
1488
1489
1490
1491
1492
1493
1494
1495
1496
1497
1498
1499
1500
1501





































                                                                               
                                             




                                                                                    

                                                  




             
               
                             

             
                                                
 



                                                    
                   

























                                                         
                       






























                                                                                         
                                

                                                                                
                              


                                                                                  
                              
























                                                                                        
                                      



















                                                                                             
 





































                                                                                                
           




























                                                                                                          
                                                                                       




                                                                                                          
                                                                                       
                                                                                                          
                                                                                       




                                                                                                          

                                                 
















































































                                                                                        
                                         
                                             

                                                                               


                                              

                                                                                       

                                                        

                                                                                           
                                                            





































































                                                                                                     




















                                                                             
























                                                                                           


                                                                             



















                                                                                 




                                                                                    
                                                                                               

                                            



                                                                  

                                                 






                                                   
                           
                                                 
                            












                                                                      
                                                     























































































                                                                                               






                       

                 

                                    















                                                                                     





                                                      
                                                           








                                                                     
                                                                                 






                                                                    
                                                                       




                                                                    
                                                                       






                                                                    









                                                                                      
 





                                                                               























                                                      

                                                      





                                                                















                                                                                        



                                              


















                                                                                 







                                                        
                                                         








                                                                

                                                                   

                                                          

                                                                                       
                                                

                                                                                     
                                     


                                                                                        




                                                          

                                                                                            
                                                

                                                                                          
                                     

                                                                                             

                                  




                                                                          

                 
                                                                            





                                                                         


                                       









                                                                 




































                                                                              
 
                                                  
 








                                                         


                      
                                                                


                      






















































                                                                                   



                                                   

                      

                      










                                                                            
                       






                                                                                    

                   
                      
              












































































                                                                                    
                                          
                       


















                                                                                  
                                

                                                                    

                                







                                                             
                                               
                                                               






                                                                   

                                                   

                                                           


                                                                         

                                        
                                                
                                     






























































































































































































































































































































































































                                                                                                        

                                                                


                                                                            
                                                                                












































                                                                                                          
                                                





                                                                                        

                                                                           



                                                                                             
                                                     
 






























                                                                                    
              














                                                                                
                                         
                       





























                                                                                                
                  






















                                                                                       
              
                                                


                                                                         







                                                                                
 
                                 
 


                                                                              
 
                                 
              










                                                                                   
         




































                                                                                      

                                                                 
                                                                                     
                      











                                                                        
                     

                                







                                                                                   
                                     








                                                                    
                                                          



                                                            


                                                          

                                                                 
                                                          



                                                                  
                                                          










                                                                                


                                                          

                                                                   
                                                          

                                                        

                                                                 
                                                          



                                                                 


                                                           







                                                                    




                                          





                                                                                   
                                                  
                                                                                          
                                            





                                                                                     




                                                                



































                                                                                                

                                    
                           
                             




                                                                                          

                                                                      
                                                  
                                                                       

                                                                     



                                                                     
















                                                                                




                                            
                                                        

                                                           



                                                                              
                                      



















                                                              

                                                                            










                                                                       
                                                          


                                       


                                                               
                                          
                                                                   










                                                 
                                                                          
                                  
                                                                   
                             
                                        






                                                            
                                                                               
                                                  
                                        
                                              
                                           
                             
                                                                              



                                                            


































































































































                                                                                                                                 

                      






                                                                             
 

                                                           
 


                                             

                                                                     



                                                                                                                                                            
                                                                                                                               
                                                                                                                                                                       
                                                                                                                            
                                                                                                                   

                                                                                                    






                                                                                    

                                                        



                                                                      

                                   


                                             
 




                                                           
                                
                                                        
                                  

                                                          
                                























                                                                                        
                     

















                                                                                        
 


                                                              






                                                          






                                                                             
 

                                                       

                                             










                                                                                  



                                                         
                                        
                                                  



                                                                    
                                                                                    












































                                                                                                     



                                        


                                                                              
                                        
                                    




                                                                                                                              




                                                                                              







                                                                                                                  

                                                      


                                         

                                                                                                                                                                                                                                                                                                                                                                                                                                                                    


                                                                                                                                           
                                                                                                                                                                                                                      
                                                                                          

                                                                                                                                                                                 
                                                                                             

                                                                                                                          


                                                                                                                            


                                                                               


                                                      





















                                                                            

                                           

                                 












                                                                                                                                                                                        

                                                                          

                                                            



                                                                                              


                                                                      
                                                         
                                             

                                                                                                       







                                                                                                      
                                                
                                    

                                      


                   








                                                                             
                                                                      




                                                                                 


                                                                    






























                                                                                                         
                                                                                                           


                                                       





















































                                                                                                                      
                                             































































                                                                                                                                              



                                                                               
                                                                       





                                                                          















                                                                                                            





                                                                                      


                                                                                     


                                                                             

                                                                      







                                           

                                                                                 
                     







































                                                                                    
                                             
















































































































































                                                                                            


                     

































                                                                                                                      
                                                     


                                                                            
                             






























                                                                                                         

                      









                                                           

                    































































































































                                                                                                

                       






                                                                     
 














                                                                                     

                                   














                                                                                         

                                











                                                         

                                           
                  
                          


















                                                                                       

                                      































                                                                                   

                          





                                                   
 
                     
 





                                                                        
                       

                           
                                  

                  

















                                                                                 
 




















                                                                                      
 




                                                                       
                               



























































































































































                                                                                                             
 




































































































































































                                                                                                       
#!/usr/bin/python
#
# Tool for analyzing suspend/resume timing
# Copyright (c) 2013, Intel Corporation.
#
# This program is free software; you can redistribute it and/or modify it
# under the terms and conditions of the GNU General Public License,
# version 2, as published by the Free Software Foundation.
#
# This program is distributed in the hope it will be useful, but WITHOUT
# ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
# FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License for
# more details.
#
# You should have received a copy of the GNU General Public License along with
# this program; if not, write to the Free Software Foundation, Inc.,
# 51 Franklin St - Fifth Floor, Boston, MA 02110-1301 USA.
#
# Authors:
#	 Todd Brandt <todd.e.brandt@linux.intel.com>
#
# Description:
#	 This tool is designed to assist kernel and OS developers in optimizing
#	 their linux stack's suspend/resume time. Using a kernel image built
#	 with a few extra options enabled, the tool will execute a suspend and
#	 will capture dmesg and ftrace data until resume is complete. This data
#	 is transformed into a device timeline and a callgraph to give a quick
#	 and detailed view of which devices and callbacks are taking the most
#	 time in suspend/resume. The output is a single html file which can be
#	 viewed in firefox or chrome.
#
#	 The following kernel build options are required:
#		 CONFIG_PM_DEBUG=y
#		 CONFIG_PM_SLEEP_DEBUG=y
#		 CONFIG_FTRACE=y
#		 CONFIG_FUNCTION_TRACER=y
#		 CONFIG_FUNCTION_GRAPH_TRACER=y
#
#	 For kernel versions older than 3.15:
#	 The following additional kernel parameters are required:
#		 (e.g. in file /etc/default/grub)
#		 GRUB_CMDLINE_LINUX_DEFAULT="... initcall_debug log_buf_len=16M ..."
#

# ----------------- LIBRARIES --------------------

import sys
import time
import os
import string
import re
import platform
from datetime import datetime
import struct

# ----------------- CLASSES --------------------

# Class: SystemValues
# Description:
#	 A global, single-instance container used to
#	 store system values and test parameters
class SystemValues:
	version = 3.0
	verbose = False
	testdir = '.'
	tpath = '/sys/kernel/debug/tracing/'
	fpdtpath = '/sys/firmware/acpi/tables/FPDT'
	epath = '/sys/kernel/debug/tracing/events/power/'
	traceevents = [
		'suspend_resume',
		'device_pm_callback_end',
		'device_pm_callback_start'
	]
	modename = {
		'freeze': 'Suspend-To-Idle (S0)',
		'standby': 'Power-On Suspend (S1)',
		'mem': 'Suspend-to-RAM (S3)',
		'disk': 'Suspend-to-disk (S4)'
	}
	mempath = '/dev/mem'
	powerfile = '/sys/power/state'
	suspendmode = 'mem'
	hostname = 'localhost'
	prefix = 'test'
	teststamp = ''
	dmesgfile = ''
	ftracefile = ''
	htmlfile = ''
	rtcwake = False
	rtcwaketime = 10
	rtcpath = ''
	android = False
	adb = 'adb'
	devicefilter = []
	stamp = 0
	execcount = 1
	x2delay = 0
	usecallgraph = False
	usetraceevents = False
	usetraceeventsonly = False
	notestrun = False
	altdevname = dict()
	postresumetime = 0
	tracertypefmt = '# tracer: (?P<t>.*)'
	firmwarefmt = '# fwsuspend (?P<s>[0-9]*) fwresume (?P<r>[0-9]*)$'
	postresumefmt = '# post resume time (?P<t>[0-9]*)$'
	stampfmt = '# suspend-(?P<m>[0-9]{2})(?P<d>[0-9]{2})(?P<y>[0-9]{2})-'+\
				'(?P<H>[0-9]{2})(?P<M>[0-9]{2})(?P<S>[0-9]{2})'+\
				' (?P<host>.*) (?P<mode>.*) (?P<kernel>.*)$'
	def __init__(self):
		self.hostname = platform.node()
		if(self.hostname == ''):
			self.hostname = 'localhost'
		rtc = "rtc0"
		if os.path.exists('/dev/rtc'):
			rtc = os.readlink('/dev/rtc')
		rtc = '/sys/class/rtc/'+rtc
		if os.path.exists(rtc) and os.path.exists(rtc+'/date') and \
			os.path.exists(rtc+'/time') and os.path.exists(rtc+'/wakealarm'):
			self.rtcpath = rtc
	def setOutputFile(self):
		if((self.htmlfile == '') and (self.dmesgfile != '')):
			m = re.match('(?P<name>.*)_dmesg\.txt$', self.dmesgfile)
			if(m):
				self.htmlfile = m.group('name')+'.html'
		if((self.htmlfile == '') and (self.ftracefile != '')):
			m = re.match('(?P<name>.*)_ftrace\.txt$', self.ftracefile)
			if(m):
				self.htmlfile = m.group('name')+'.html'
		if(self.htmlfile == ''):
			self.htmlfile = 'output.html'
	def initTestOutput(self, subdir):
		if(not self.android):
			self.prefix = self.hostname
			v = open('/proc/version', 'r').read().strip()
			kver = string.split(v)[2]
		else:
			self.prefix = 'android'
			v = os.popen(self.adb+' shell cat /proc/version').read().strip()
			kver = string.split(v)[2]
		testtime = datetime.now().strftime('suspend-%m%d%y-%H%M%S')
		if(subdir != "."):
			self.testdir = subdir+"/"+testtime
		else:
			self.testdir = testtime
		self.teststamp = \
			'# '+testtime+' '+self.prefix+' '+self.suspendmode+' '+kver
		self.dmesgfile = \
			self.testdir+'/'+self.prefix+'_'+self.suspendmode+'_dmesg.txt'
		self.ftracefile = \
			self.testdir+'/'+self.prefix+'_'+self.suspendmode+'_ftrace.txt'
		self.htmlfile = \
			self.testdir+'/'+self.prefix+'_'+self.suspendmode+'.html'
		os.mkdir(self.testdir)
	def setDeviceFilter(self, devnames):
		self.devicefilter = string.split(devnames)
	def rtcWakeAlarm(self):
		os.system('echo 0 > '+self.rtcpath+'/wakealarm')
		outD = open(self.rtcpath+'/date', 'r').read().strip()
		outT = open(self.rtcpath+'/time', 'r').read().strip()
		mD = re.match('^(?P<y>[0-9]*)-(?P<m>[0-9]*)-(?P<d>[0-9]*)', outD)
		mT = re.match('^(?P<h>[0-9]*):(?P<m>[0-9]*):(?P<s>[0-9]*)', outT)
		if(mD and mT):
			# get the current time from hardware
			utcoffset = int((datetime.now() - datetime.utcnow()).total_seconds())
			dt = datetime(\
				int(mD.group('y')), int(mD.group('m')), int(mD.group('d')),
				int(mT.group('h')), int(mT.group('m')), int(mT.group('s')))
			nowtime = int(dt.strftime('%s')) + utcoffset
		else:
			# if hardware time fails, use the software time
			nowtime = int(datetime.now().strftime('%s'))
		alarm = nowtime + self.rtcwaketime
		os.system('echo %d > %s/wakealarm' % (alarm, self.rtcpath))

sysvals = SystemValues()

# Class: DeviceNode
# Description:
#	 A container used to create a device hierachy, with a single root node
#	 and a tree of child nodes. Used by Data.deviceTopology()
class DeviceNode:
	name = ''
	children = 0
	depth = 0
	def __init__(self, nodename, nodedepth):
		self.name = nodename
		self.children = []
		self.depth = nodedepth

# Class: Data
# Description:
#	 The primary container for suspend/resume test data. There is one for
#	 each test run. The data is organized into a cronological hierarchy:
#	 Data.dmesg {
#		root structure, started as dmesg & ftrace, but now only ftrace
#		contents: times for suspend start/end, resume start/end, fwdata
#		phases {
#			10 sequential, non-overlapping phases of S/R
#			contents: times for phase start/end, order/color data for html
#			devlist {
#				device callback or action list for this phase
#				device {
#					a single device callback or generic action
#					contents: start/stop times, pid/cpu/driver info
#						parents/children, html id for timeline/callgraph
#						optionally includes an ftrace callgraph
#						optionally includes intradev trace events
#				}
#			}
#		}
#	}
#
class Data:
	dmesg = {}  # root data structure
	phases = [] # ordered list of phases
	start = 0.0 # test start
	end = 0.0   # test end
	tSuspended = 0.0 # low-level suspend start
	tResumed = 0.0   # low-level resume start
	tLow = 0.0       # time spent in low-level suspend (standby/freeze)
	fwValid = False  # is firmware data available
	fwSuspend = 0    # time spent in firmware suspend
	fwResume = 0     # time spent in firmware resume
	dmesgtext = []   # dmesg text file in memory
	testnumber = 0
	idstr = ''
	html_device_id = 0
	stamp = 0
	outfile = ''
	def __init__(self, num):
		idchar = 'abcdefghijklmnopqrstuvwxyz'
		self.testnumber = num
		self.idstr = idchar[num]
		self.dmesgtext = []
		self.phases = []
		self.dmesg = { # fixed list of 10 phases
			'suspend_prepare': {'list': dict(), 'start': -1.0, 'end': -1.0,
								'row': 0, 'color': '#CCFFCC', 'order': 0},
			        'suspend': {'list': dict(), 'start': -1.0, 'end': -1.0,
								'row': 0, 'color': '#88FF88', 'order': 1},
			   'suspend_late': {'list': dict(), 'start': -1.0, 'end': -1.0,
								'row': 0, 'color': '#00AA00', 'order': 2},
			  'suspend_noirq': {'list': dict(), 'start': -1.0, 'end': -1.0,
								'row': 0, 'color': '#008888', 'order': 3},
		    'suspend_machine': {'list': dict(), 'start': -1.0, 'end': -1.0,
								'row': 0, 'color': '#0000FF', 'order': 4},
			 'resume_machine': {'list': dict(), 'start': -1.0, 'end': -1.0,
								'row': 0, 'color': '#FF0000', 'order': 5},
			   'resume_noirq': {'list': dict(), 'start': -1.0, 'end': -1.0,
								'row': 0, 'color': '#FF9900', 'order': 6},
			   'resume_early': {'list': dict(), 'start': -1.0, 'end': -1.0,
								'row': 0, 'color': '#FFCC00', 'order': 7},
			         'resume': {'list': dict(), 'start': -1.0, 'end': -1.0,
								'row': 0, 'color': '#FFFF88', 'order': 8},
			'resume_complete': {'list': dict(), 'start': -1.0, 'end': -1.0,
								'row': 0, 'color': '#FFFFCC', 'order': 9}
		}
		self.phases = self.sortedPhases()
	def getStart(self):
		return self.dmesg[self.phases[0]]['start']
	def setStart(self, time):
		self.start = time
		self.dmesg[self.phases[0]]['start'] = time
	def getEnd(self):
		return self.dmesg[self.phases[-1]]['end']
	def setEnd(self, time):
		self.end = time
		self.dmesg[self.phases[-1]]['end'] = time
	def isTraceEventOutsideDeviceCalls(self, pid, time):
		for phase in self.phases:
			list = self.dmesg[phase]['list']
			for dev in list:
				d = list[dev]
				if(d['pid'] == pid and time >= d['start'] and
					time <= d['end']):
					return False
		return True
	def addIntraDevTraceEvent(self, action, name, pid, time):
		if(action == 'mutex_lock_try'):
			color = 'red'
		elif(action == 'mutex_lock_pass'):
			color = 'green'
		elif(action == 'mutex_unlock'):
			color = 'blue'
		else:
			# create separate colors based on the name
			v1 = len(name)*10 % 256
			v2 = string.count(name, 'e')*100 % 256
			v3 = ord(name[0])*20 % 256
			color = '#%06X' % ((v1*0x10000) + (v2*0x100) + v3)
		for phase in self.phases:
			list = self.dmesg[phase]['list']
			for dev in list:
				d = list[dev]
				if(d['pid'] == pid and time >= d['start'] and
					time <= d['end']):
					e = TraceEvent(action, name, color, time)
					if('traceevents' not in d):
						d['traceevents'] = []
					d['traceevents'].append(e)
					return d
					break
		return 0
	def capIntraDevTraceEvent(self, action, name, pid, time):
		for phase in self.phases:
			list = self.dmesg[phase]['list']
			for dev in list:
				d = list[dev]
				if(d['pid'] == pid and time >= d['start'] and
					time <= d['end']):
					if('traceevents' not in d):
						return
					for e in d['traceevents']:
						if(e.action == action and
							e.name == name and not e.ready):
							e.length = time - e.time
							e.ready = True
							break
					return
	def trimTimeVal(self, t, t0, dT, left):
		if left:
			if(t > t0):
				if(t - dT < t0):
					return t0
				return t - dT
			else:
				return t
		else:
			if(t < t0 + dT):
				if(t > t0):
					return t0 + dT
				return t + dT
			else:
				return t
	def trimTime(self, t0, dT, left):
		self.tSuspended = self.trimTimeVal(self.tSuspended, t0, dT, left)
		self.tResumed = self.trimTimeVal(self.tResumed, t0, dT, left)
		self.start = self.trimTimeVal(self.start, t0, dT, left)
		self.end = self.trimTimeVal(self.end, t0, dT, left)
		for phase in self.phases:
			p = self.dmesg[phase]
			p['start'] = self.trimTimeVal(p['start'], t0, dT, left)
			p['end'] = self.trimTimeVal(p['end'], t0, dT, left)
			list = p['list']
			for name in list:
				d = list[name]
				d['start'] = self.trimTimeVal(d['start'], t0, dT, left)
				d['end'] = self.trimTimeVal(d['end'], t0, dT, left)
				if('ftrace' in d):
					cg = d['ftrace']
					cg.start = self.trimTimeVal(cg.start, t0, dT, left)
					cg.end = self.trimTimeVal(cg.end, t0, dT, left)
					for line in cg.list:
						line.time = self.trimTimeVal(line.time, t0, dT, left)
				if('traceevents' in d):
					for e in d['traceevents']:
						e.time = self.trimTimeVal(e.time, t0, dT, left)
	def normalizeTime(self, tZero):
		# first trim out any standby or freeze clock time
		if(self.tSuspended != self.tResumed):
			if(self.tResumed > tZero):
				self.trimTime(self.tSuspended, \
					self.tResumed-self.tSuspended, True)
			else:
				self.trimTime(self.tSuspended, \
					self.tResumed-self.tSuspended, False)
		# shift the timeline so that tZero is the new 0
		self.tSuspended -= tZero
		self.tResumed -= tZero
		self.start -= tZero
		self.end -= tZero
		for phase in self.phases:
			p = self.dmesg[phase]
			p['start'] -= tZero
			p['end'] -= tZero
			list = p['list']
			for name in list:
				d = list[name]
				d['start'] -= tZero
				d['end'] -= tZero
				if('ftrace' in d):
					cg = d['ftrace']
					cg.start -= tZero
					cg.end -= tZero
					for line in cg.list:
						line.time -= tZero
				if('traceevents' in d):
					for e in d['traceevents']:
						e.time -= tZero
	def newPhaseWithSingleAction(self, phasename, devname, start, end, color):
		for phase in self.phases:
			self.dmesg[phase]['order'] += 1
		self.html_device_id += 1
		devid = '%s%d' % (self.idstr, self.html_device_id)
		list = dict()
		list[devname] = \
			{'start': start, 'end': end, 'pid': 0, 'par': '',
			'length': (end-start), 'row': 0, 'id': devid, 'drv': '' };
		self.dmesg[phasename] = \
			{'list': list, 'start': start, 'end': end,
			'row': 0, 'color': color, 'order': 0}
		self.phases = self.sortedPhases()
	def newPhase(self, phasename, start, end, color, order):
		if(order < 0):
			order = len(self.phases)
		for phase in self.phases[order:]:
			self.dmesg[phase]['order'] += 1
		if(order > 0):
			p = self.phases[order-1]
			self.dmesg[p]['end'] = start
		if(order < len(self.phases)):
			p = self.phases[order]
			self.dmesg[p]['start'] = end
		list = dict()
		self.dmesg[phasename] = \
			{'list': list, 'start': start, 'end': end,
			'row': 0, 'color': color, 'order': order}
		self.phases = self.sortedPhases()
	def setPhase(self, phase, ktime, isbegin):
		if(isbegin):
			self.dmesg[phase]['start'] = ktime
		else:
			self.dmesg[phase]['end'] = ktime
	def dmesgSortVal(self, phase):
		return self.dmesg[phase]['order']
	def sortedPhases(self):
		return sorted(self.dmesg, key=self.dmesgSortVal)
	def sortedDevices(self, phase):
		list = self.dmesg[phase]['list']
		slist = []
		tmp = dict()
		for devname in list:
			dev = list[devname]
			tmp[dev['start']] = devname
		for t in sorted(tmp):
			slist.append(tmp[t])
		return slist
	def fixupInitcalls(self, phase, end):
		# if any calls never returned, clip them at system resume end
		phaselist = self.dmesg[phase]['list']
		for devname in phaselist:
			dev = phaselist[devname]
			if(dev['end'] < 0):
				dev['end'] = end
				vprint('%s (%s): callback didnt return' % (devname, phase))
	def deviceFilter(self, devicefilter):
		# remove all by the relatives of the filter devnames
		filter = []
		for phase in self.phases:
			list = self.dmesg[phase]['list']
			for name in devicefilter:
				dev = name
				while(dev in list):
					if(dev not in filter):
						filter.append(dev)
					dev = list[dev]['par']
				children = self.deviceDescendants(name, phase)
				for dev in children:
					if(dev not in filter):
						filter.append(dev)
		for phase in self.phases:
			list = self.dmesg[phase]['list']
			rmlist = []
			for name in list:
				pid = list[name]['pid']
				if(name not in filter and pid >= 0):
					rmlist.append(name)
			for name in rmlist:
				del list[name]
	def fixupInitcallsThatDidntReturn(self):
		# if any calls never returned, clip them at system resume end
		for phase in self.phases:
			self.fixupInitcalls(phase, self.getEnd())
	def newActionGlobal(self, name, start, end):
		# which phase is this device callback or action "in"
		targetphase = "none"
		overlap = 0.0
		for phase in self.phases:
			pstart = self.dmesg[phase]['start']
			pend = self.dmesg[phase]['end']
			o = max(0, min(end, pend) - max(start, pstart))
			if(o > overlap):
				targetphase = phase
				overlap = o
		if targetphase in self.phases:
			self.newAction(targetphase, name, -1, '', start, end, '')
			return True
		return False
	def newAction(self, phase, name, pid, parent, start, end, drv):
		# new device callback for a specific phase
		self.html_device_id += 1
		devid = '%s%d' % (self.idstr, self.html_device_id)
		list = self.dmesg[phase]['list']
		length = -1.0
		if(start >= 0 and end >= 0):
			length = end - start
		list[name] = {'start': start, 'end': end, 'pid': pid, 'par': parent,
					  'length': length, 'row': 0, 'id': devid, 'drv': drv }
	def deviceIDs(self, devlist, phase):
		idlist = []
		list = self.dmesg[phase]['list']
		for devname in list:
			if devname in devlist:
				idlist.append(list[devname]['id'])
		return idlist
	def deviceParentID(self, devname, phase):
		pdev = ''
		pdevid = ''
		list = self.dmesg[phase]['list']
		if devname in list:
			pdev = list[devname]['par']
		if pdev in list:
			return list[pdev]['id']
		return pdev
	def deviceChildren(self, devname, phase):
		devlist = []
		list = self.dmesg[phase]['list']
		for child in list:
			if(list[child]['par'] == devname):
				devlist.append(child)
		return devlist
	def deviceDescendants(self, devname, phase):
		children = self.deviceChildren(devname, phase)
		family = children
		for child in children:
			family += self.deviceDescendants(child, phase)
		return family
	def deviceChildrenIDs(self, devname, phase):
		devlist = self.deviceChildren(devname, phase)
		return self.deviceIDs(devlist, phase)
	def printDetails(self):
		vprint('          test start: %f' % self.start)
		for phase in self.phases:
			dc = len(self.dmesg[phase]['list'])
			vprint('    %16s: %f - %f (%d devices)' % (phase, \
				self.dmesg[phase]['start'], self.dmesg[phase]['end'], dc))
		vprint('            test end: %f' % self.end)
	def masterTopology(self, name, list, depth):
		node = DeviceNode(name, depth)
		for cname in list:
			clist = self.deviceChildren(cname, 'resume')
			cnode = self.masterTopology(cname, clist, depth+1)
			node.children.append(cnode)
		return node
	def printTopology(self, node):
		html = ''
		if node.name:
			info = ''
			drv = ''
			for phase in self.phases:
				list = self.dmesg[phase]['list']
				if node.name in list:
					s = list[node.name]['start']
					e = list[node.name]['end']
					if list[node.name]['drv']:
						drv = ' {'+list[node.name]['drv']+'}'
					info += ('<li>%s: %.3fms</li>' % (phase, (e-s)*1000))
			html += '<li><b>'+node.name+drv+'</b>'
			if info:
				html += '<ul>'+info+'</ul>'
			html += '</li>'
		if len(node.children) > 0:
			html += '<ul>'
			for cnode in node.children:
				html += self.printTopology(cnode)
			html += '</ul>'
		return html
	def rootDeviceList(self):
		# list of devices graphed
		real = []
		for phase in self.dmesg:
			list = self.dmesg[phase]['list']
			for dev in list:
				if list[dev]['pid'] >= 0 and dev not in real:
					real.append(dev)
		# list of top-most root devices
		rootlist = []
		for phase in self.dmesg:
			list = self.dmesg[phase]['list']
			for dev in list:
				pdev = list[dev]['par']
				if(re.match('[0-9]*-[0-9]*\.[0-9]*[\.0-9]*\:[\.0-9]*$', pdev)):
					continue
				if pdev and pdev not in real and pdev not in rootlist:
					rootlist.append(pdev)
		return rootlist
	def deviceTopology(self):
		rootlist = self.rootDeviceList()
		master = self.masterTopology('', rootlist, 0)
		return self.printTopology(master)

# Class: TraceEvent
# Description:
#	 A container for trace event data found in the ftrace file
class TraceEvent:
	ready = False
	name = ''
	time = 0.0
	color = '#FFFFFF'
	length = 0.0
	action = ''
	def __init__(self, a, n, c, t):
		self.action = a
		self.name = n
		self.color = c
		self.time = t

# Class: FTraceLine
# Description:
#	 A container for a single line of ftrace data. There are six basic types:
#		 callgraph line:
#			  call: "  dpm_run_callback() {"
#			return: "  }"
#			  leaf: " dpm_run_callback();"
#		 trace event:
#			 tracing_mark_write: SUSPEND START or RESUME COMPLETE
#			 suspend_resume: phase or custom exec block data
#			 device_pm_callback: device callback info
class FTraceLine:
	time = 0.0
	length = 0.0
	fcall = False
	freturn = False
	fevent = False
	depth = 0
	name = ''
	type = ''
	def __init__(self, t, m, d):
		self.time = float(t)
		# is this a trace event
		if(d == 'traceevent' or re.match('^ *\/\* *(?P<msg>.*) \*\/ *$', m)):
			if(d == 'traceevent'):
				# nop format trace event
				msg = m
			else:
				# function_graph format trace event
				em = re.match('^ *\/\* *(?P<msg>.*) \*\/ *$', m)
				msg = em.group('msg')

			emm = re.match('^(?P<call>.*?): (?P<msg>.*)', msg)
			if(emm):
				self.name = emm.group('msg')
				self.type = emm.group('call')
			else:
				self.name = msg
			self.fevent = True
			return
		# convert the duration to seconds
		if(d):
			self.length = float(d)/1000000
		# the indentation determines the depth
		match = re.match('^(?P<d> *)(?P<o>.*)$', m)
		if(not match):
			return
		self.depth = self.getDepth(match.group('d'))
		m = match.group('o')
		# function return
		if(m[0] == '}'):
			self.freturn = True
			if(len(m) > 1):
				# includes comment with function name
				match = re.match('^} *\/\* *(?P<n>.*) *\*\/$', m)
				if(match):
					self.name = match.group('n')
		# function call
		else:
			self.fcall = True
			# function call with children
			if(m[-1] == '{'):
				match = re.match('^(?P<n>.*) *\(.*', m)
				if(match):
					self.name = match.group('n')
			# function call with no children (leaf)
			elif(m[-1] == ';'):
				self.freturn = True
				match = re.match('^(?P<n>.*) *\(.*', m)
				if(match):
					self.name = match.group('n')
			# something else (possibly a trace marker)
			else:
				self.name = m
	def getDepth(self, str):
		return len(str)/2
	def debugPrint(self, dev):
		if(self.freturn and self.fcall):
			print('%s -- %f (%02d): %s(); (%.3f us)' % (dev, self.time, \
				self.depth, self.name, self.length*1000000))
		elif(self.freturn):
			print('%s -- %f (%02d): %s} (%.3f us)' % (dev, self.time, \
				self.depth, self.name, self.length*1000000))
		else:
			print('%s -- %f (%02d): %s() { (%.3f us)' % (dev, self.time, \
				self.depth, self.name, self.length*1000000))

# Class: FTraceCallGraph
# Description:
#	 A container for the ftrace callgraph of a single recursive function.
#	 This can be a dpm_run_callback, dpm_prepare, or dpm_complete callgraph
#	 Each instance is tied to a single device in a single phase, and is
#	 comprised of an ordered list of FTraceLine objects
class FTraceCallGraph:
	start = -1.0
	end = -1.0
	list = []
	invalid = False
	depth = 0
	def __init__(self):
		self.start = -1.0
		self.end = -1.0
		self.list = []
		self.depth = 0
	def setDepth(self, line):
		if(line.fcall and not line.freturn):
			line.depth = self.depth
			self.depth += 1
		elif(line.freturn and not line.fcall):
			self.depth -= 1
			line.depth = self.depth
		else:
			line.depth = self.depth
	def addLine(self, line, match):
		if(not self.invalid):
			self.setDepth(line)
		if(line.depth == 0 and line.freturn):
			if(self.start < 0):
				self.start = line.time
			self.end = line.time
			self.list.append(line)
			return True
		if(self.invalid):
			return False
		if(len(self.list) >= 1000000 or self.depth < 0):
			if(len(self.list) > 0):
				first = self.list[0]
				self.list = []
				self.list.append(first)
			self.invalid = True
			if(not match):
				return False
			id = 'task %s cpu %s' % (match.group('pid'), match.group('cpu'))
			window = '(%f - %f)' % (self.start, line.time)
			if(self.depth < 0):
				print('Too much data for '+id+\
					' (buffer overflow), ignoring this callback')
			else:
				print('Too much data for '+id+\
					' '+window+', ignoring this callback')
			return False
		self.list.append(line)
		if(self.start < 0):
			self.start = line.time
		return False
	def slice(self, t0, tN):
		minicg = FTraceCallGraph()
		count = -1
		firstdepth = 0
		for l in self.list:
			if(l.time < t0 or l.time > tN):
				continue
			if(count < 0):
				if(not l.fcall or l.name == 'dev_driver_string'):
					continue
				firstdepth = l.depth
				count = 0
			l.depth -= firstdepth
			minicg.addLine(l, 0)
			if((count == 0 and l.freturn and l.fcall) or
				(count > 0 and l.depth <= 0)):
				break
			count += 1
		return minicg
	def sanityCheck(self):
		stack = dict()
		cnt = 0
		for l in self.list:
			if(l.fcall and not l.freturn):
				stack[l.depth] = l
				cnt += 1
			elif(l.freturn and not l.fcall):
				if(l.depth not in stack):
					return False
				stack[l.depth].length = l.length
				stack[l.depth] = 0
				l.length = 0
				cnt -= 1
		if(cnt == 0):
			return True
		return False
	def debugPrint(self, filename):
		if(filename == 'stdout'):
			print('[%f - %f]') % (self.start, self.end)
			for l in self.list:
				if(l.freturn and l.fcall):
					print('%f (%02d): %s(); (%.3f us)' % (l.time, \
						l.depth, l.name, l.length*1000000))
				elif(l.freturn):
					print('%f (%02d): %s} (%.3f us)' % (l.time, \
						l.depth, l.name, l.length*1000000))
				else:
					print('%f (%02d): %s() { (%.3f us)' % (l.time, \
						l.depth, l.name, l.length*1000000))
			print(' ')
		else:
			fp = open(filename, 'w')
			print(filename)
			for l in self.list:
				if(l.freturn and l.fcall):
					fp.write('%f (%02d): %s(); (%.3f us)\n' % (l.time, \
						l.depth, l.name, l.length*1000000))
				elif(l.freturn):
					fp.write('%f (%02d): %s} (%.3f us)\n' % (l.time, \
						l.depth, l.name, l.length*1000000))
				else:
					fp.write('%f (%02d): %s() { (%.3f us)\n' % (l.time, \
						l.depth, l.name, l.length*1000000))
			fp.close()

# Class: Timeline
# Description:
#	 A container for a suspend/resume html timeline. In older versions
#	 of the script there were multiple timelines, but in the latest
#	 there is only one.
class Timeline:
	html = {}
	scaleH = 0.0 # height of the row as a percent of the timeline height
	rowH = 0.0 # height of each row in percent of the timeline height
	row_height_pixels = 30
	maxrows = 0
	height = 0
	def __init__(self):
		self.html = {
			'timeline': '',
			'legend': '',
			'scale': ''
		}
	def setRows(self, rows):
		self.maxrows = int(rows)
		self.scaleH = 100.0/float(self.maxrows)
		self.height = self.maxrows*self.row_height_pixels
		r = float(self.maxrows - 1)
		if(r < 1.0):
			r = 1.0
		self.rowH = (100.0 - self.scaleH)/r

# Class: TestRun
# Description:
#	 A container for a suspend/resume test run. This is necessary as
#	 there could be more than one, and they need to be separate.
class TestRun:
	ftrace_line_fmt_fg = \
		'^ *(?P<time>[0-9\.]*) *\| *(?P<cpu>[0-9]*)\)'+\
		' *(?P<proc>.*)-(?P<pid>[0-9]*) *\|'+\
		'[ +!]*(?P<dur>[0-9\.]*) .*\|  (?P<msg>.*)'
	ftrace_line_fmt_nop = \
		' *(?P<proc>.*)-(?P<pid>[0-9]*) *\[(?P<cpu>[0-9]*)\] *'+\
		'(?P<flags>.{4}) *(?P<time>[0-9\.]*): *'+\
		'(?P<msg>.*)'
	ftrace_line_fmt = ftrace_line_fmt_nop
	cgformat = False
	ftemp = dict()
	ttemp = dict()
	inthepipe = False
	tracertype = ''
	data = 0
	def __init__(self, dataobj):
		self.data = dataobj
		self.ftemp = dict()
		self.ttemp = dict()
	def isReady(self):
		if(tracertype == '' or not data):
			return False
		return True
	def setTracerType(self, tracer):
		self.tracertype = tracer
		if(tracer == 'function_graph'):
			self.cgformat = True
			self.ftrace_line_fmt = self.ftrace_line_fmt_fg
		elif(tracer == 'nop'):
			self.ftrace_line_fmt = self.ftrace_line_fmt_nop
		else:
			doError('Invalid tracer format: [%s]' % tracer, False)

# ----------------- FUNCTIONS --------------------

# Function: vprint
# Description:
#	 verbose print (prints only with -verbose option)
# Arguments:
#	 msg: the debug/log message to print
def vprint(msg):
	global sysvals
	if(sysvals.verbose):
		print(msg)

# Function: initFtrace
# Description:
#	 Configure ftrace to use trace events and/or a callgraph
def initFtrace():
	global sysvals

	tp = sysvals.tpath
	cf = 'dpm_run_callback'
	if(sysvals.usetraceeventsonly):
		cf = '-e dpm_prepare -e dpm_complete -e dpm_run_callback'
	if(sysvals.usecallgraph or sysvals.usetraceevents):
		print('INITIALIZING FTRACE...')
		# turn trace off
		os.system('echo 0 > '+tp+'tracing_on')
		# set the trace clock to global
		os.system('echo global > '+tp+'trace_clock')
		# set trace buffer to a huge value
		os.system('echo nop > '+tp+'current_tracer')
		os.system('echo 100000 > '+tp+'buffer_size_kb')
		# initialize the callgraph trace, unless this is an x2 run
		if(sysvals.usecallgraph and sysvals.execcount == 1):
			# set trace type
			os.system('echo function_graph > '+tp+'current_tracer')
			os.system('echo "" > '+tp+'set_ftrace_filter')
			# set trace format options
			os.system('echo funcgraph-abstime > '+tp+'trace_options')
			os.system('echo funcgraph-proc > '+tp+'trace_options')
			# focus only on device suspend and resume
			os.system('cat '+tp+'available_filter_functions | grep '+\
				cf+' > '+tp+'set_graph_function')
		if(sysvals.usetraceevents):
			# turn trace events on
			events = iter(sysvals.traceevents)
			for e in events:
				os.system('echo 1 > '+sysvals.epath+e+'/enable')
		# clear the trace buffer
		os.system('echo "" > '+tp+'trace')

# Function: initFtraceAndroid
# Description:
#	 Configure ftrace to capture trace events
def initFtraceAndroid():
	global sysvals

	tp = sysvals.tpath
	if(sysvals.usetraceevents):
		print('INITIALIZING FTRACE...')
		# turn trace off
		os.system(sysvals.adb+" shell 'echo 0 > "+tp+"tracing_on'")
		# set the trace clock to global
		os.system(sysvals.adb+" shell 'echo global > "+tp+"trace_clock'")
		# set trace buffer to a huge value
		os.system(sysvals.adb+" shell 'echo nop > "+tp+"current_tracer'")
		os.system(sysvals.adb+" shell 'echo 10000 > "+tp+"buffer_size_kb'")
		# turn trace events on
		events = iter(sysvals.traceevents)
		for e in events:
			os.system(sysvals.adb+" shell 'echo 1 > "+\
				sysvals.epath+e+"/enable'")
		# clear the trace buffer
		os.system(sysvals.adb+" shell 'echo \"\" > "+tp+"trace'")

# Function: verifyFtrace
# Description:
#	 Check that ftrace is working on the system
# Output:
#	 True or False
def verifyFtrace():
	global sysvals
	# files needed for any trace data
	files = ['buffer_size_kb', 'current_tracer', 'trace', 'trace_clock',
			 'trace_marker', 'trace_options', 'tracing_on']
	# files needed for callgraph trace data
	tp = sysvals.tpath
	if(sysvals.usecallgraph):
		files += [
			'available_filter_functions',
			'set_ftrace_filter',
			'set_graph_function'
		]
	for f in files:
		if(sysvals.android):
			out = os.popen(sysvals.adb+' shell ls '+tp+f).read().strip()
			if(out != tp+f):
				return False
		else:
			if(os.path.exists(tp+f) == False):
				return False
	return True

# Function: parseStamp
# Description:
#	 Pull in the stamp comment line from the data file(s),
#	 create the stamp, and add it to the global sysvals object
# Arguments:
#	 m: the valid re.match output for the stamp line
def parseStamp(m, data):
	global sysvals
	data.stamp = {'time': '', 'host': '', 'mode': ''}
	dt = datetime(int(m.group('y'))+2000, int(m.group('m')),
		int(m.group('d')), int(m.group('H')), int(m.group('M')),
		int(m.group('S')))
	data.stamp['time'] = dt.strftime('%B %d %Y, %I:%M:%S %p')
	data.stamp['host'] = m.group('host')
	data.stamp['mode'] = m.group('mode')
	data.stamp['kernel'] = m.group('kernel')
	sysvals.suspendmode = data.stamp['mode']
	if not sysvals.stamp:
		sysvals.stamp = data.stamp

# Function: diffStamp
# Description:
#	compare the host, kernel, and mode fields in 3 stamps
# Arguments:
#	 stamp1: string array with mode, kernel, and host
#	 stamp2: string array with mode, kernel, and host
# Return:
#	True if stamps differ, False if they're the same
def diffStamp(stamp1, stamp2):
	if 'host' in stamp1 and 'host' in stamp2:
		if stamp1['host'] != stamp2['host']:
			return True
	if 'kernel' in stamp1 and 'kernel' in stamp2:
		if stamp1['kernel'] != stamp2['kernel']:
			return True
	if 'mode' in stamp1 and 'mode' in stamp2:
		if stamp1['mode'] != stamp2['mode']:
			return True
	return False

# Function: doesTraceLogHaveTraceEvents
# Description:
#	 Quickly determine if the ftrace log has some or all of the trace events
#	 required for primary parsing. Set the usetraceevents and/or
#	 usetraceeventsonly flags in the global sysvals object
def doesTraceLogHaveTraceEvents():
	global sysvals

	sysvals.usetraceeventsonly = True
	sysvals.usetraceevents = False
	for e in sysvals.traceevents:
		out = os.popen('cat '+sysvals.ftracefile+' | grep "'+e+': "').read()
		if(not out):
			sysvals.usetraceeventsonly = False
		if(e == 'suspend_resume' and out):
			sysvals.usetraceevents = True

# Function: appendIncompleteTraceLog
# Description:
#	 [deprecated for kernel 3.15 or newer]
#	 Legacy support of ftrace outputs that lack the device_pm_callback
#	 and/or suspend_resume trace events. The primary data should be
#	 taken from dmesg, and this ftrace is used only for callgraph data
#	 or custom actions in the timeline. The data is appended to the Data
#	 objects provided.
# Arguments:
#	 testruns: the array of Data objects obtained from parseKernelLog
def appendIncompleteTraceLog(testruns):
	global sysvals

	# create TestRun vessels for ftrace parsing
	testcnt = len(testruns)
	testidx = -1
	testrun = []
	for data in testruns:
		testrun.append(TestRun(data))

	# extract the callgraph and traceevent data
	vprint('Analyzing the ftrace data...')
	tf = open(sysvals.ftracefile, 'r')
	for line in tf:
		# remove any latent carriage returns
		line = line.replace('\r\n', '')
		# grab the time stamp first (signifies the start of the test run)
		m = re.match(sysvals.stampfmt, line)
		if(m):
			testidx += 1
			parseStamp(m, testrun[testidx].data)
			continue
		# pull out any firmware data
		if(re.match(sysvals.firmwarefmt, line)):
			continue
		# if we havent found a test time stamp yet keep spinning til we do
		if(testidx < 0):
			continue
		# determine the trace data type (required for further parsing)
		m = re.match(sysvals.tracertypefmt, line)
		if(m):
			tracer = m.group('t')
			testrun[testidx].setTracerType(tracer)
			continue
		# parse only valid lines, if this isnt one move on
		m = re.match(testrun[testidx].ftrace_line_fmt, line)
		if(not m):
			continue
		# gather the basic message data from the line
		m_time = m.group('time')
		m_pid = m.group('pid')
		m_msg = m.group('msg')
		if(testrun[testidx].cgformat):
			m_param3 = m.group('dur')
		else:
			m_param3 = 'traceevent'
		if(m_time and m_pid and m_msg):
			t = FTraceLine(m_time, m_msg, m_param3)
			pid = int(m_pid)
		else:
			continue
		# the line should be a call, return, or event
		if(not t.fcall and not t.freturn and not t.fevent):
			continue
		# only parse the ftrace data during suspend/resume
		data = testrun[testidx].data
		if(not testrun[testidx].inthepipe):
			# look for the suspend start marker
			if(t.fevent):
				if(t.name == 'SUSPEND START'):
					testrun[testidx].inthepipe = True
					data.setStart(t.time)
				continue
		else:
			# trace event processing
			if(t.fevent):
				if(t.name == 'RESUME COMPLETE'):
					testrun[testidx].inthepipe = False
					data.setEnd(t.time)
					if(testidx == testcnt - 1):
						break
					continue
				# general trace events have two types, begin and end
				if(re.match('(?P<name>.*) begin$', t.name)):
					isbegin = True
				elif(re.match('(?P<name>.*) end$', t.name)):
					isbegin = False
				else:
					continue
				m = re.match('(?P<name>.*)\[(?P<val>[0-9]*)\] .*', t.name)
				if(m):
					val = m.group('val')
					if val == '0':
						name = m.group('name')
					else:
						name = m.group('name')+'['+val+']'
				else:
					m = re.match('(?P<name>.*) .*', t.name)
					name = m.group('name')
				# special processing for trace events
				if re.match('dpm_prepare\[.*', name):
					continue
				elif re.match('machine_suspend.*', name):
					continue
				elif re.match('suspend_enter\[.*', name):
					if(not isbegin):
						data.dmesg['suspend_prepare']['end'] = t.time
					continue
				elif re.match('dpm_suspend\[.*', name):
					if(not isbegin):
						data.dmesg['suspend']['end'] = t.time
					continue
				elif re.match('dpm_suspend_late\[.*', name):
					if(isbegin):
						data.dmesg['suspend_late']['start'] = t.time
					else:
						data.dmesg['suspend_late']['end'] = t.time
					continue
				elif re.match('dpm_suspend_noirq\[.*', name):
					if(isbegin):
						data.dmesg['suspend_noirq']['start'] = t.time
					else:
						data.dmesg['suspend_noirq']['end'] = t.time
					continue
				elif re.match('dpm_resume_noirq\[.*', name):
					if(isbegin):
						data.dmesg['resume_machine']['end'] = t.time
						data.dmesg['resume_noirq']['start'] = t.time
					else:
						data.dmesg['resume_noirq']['end'] = t.time
					continue
				elif re.match('dpm_resume_early\[.*', name):
					if(isbegin):
						data.dmesg['resume_early']['start'] = t.time
					else:
						data.dmesg['resume_early']['end'] = t.time
					continue
				elif re.match('dpm_resume\[.*', name):
					if(isbegin):
						data.dmesg['resume']['start'] = t.time
					else:
						data.dmesg['resume']['end'] = t.time
					continue
				elif re.match('dpm_complete\[.*', name):
					if(isbegin):
						data.dmesg['resume_complete']['start'] = t.time
					else:
						data.dmesg['resume_complete']['end'] = t.time
					continue
				# is this trace event outside of the devices calls
				if(data.isTraceEventOutsideDeviceCalls(pid, t.time)):
					# global events (outside device calls) are simply graphed
					if(isbegin):
						# store each trace event in ttemp
						if(name not in testrun[testidx].ttemp):
							testrun[testidx].ttemp[name] = []
						testrun[testidx].ttemp[name].append(\
							{'begin': t.time, 'end': t.time})
					else:
						# finish off matching trace event in ttemp
						if(name in testrun[testidx].ttemp):
							testrun[testidx].ttemp[name][-1]['end'] = t.time
				else:
					if(isbegin):
						data.addIntraDevTraceEvent('', name, pid, t.time)
					else:
						data.capIntraDevTraceEvent('', name, pid, t.time)
			# call/return processing
			elif sysvals.usecallgraph:
				# create a callgraph object for the data
				if(pid not in testrun[testidx].ftemp):
					testrun[testidx].ftemp[pid] = []
					testrun[testidx].ftemp[pid].append(FTraceCallGraph())
				# when the call is finished, see which device matches it
				cg = testrun[testidx].ftemp[pid][-1]
				if(cg.addLine(t, m)):
					testrun[testidx].ftemp[pid].append(FTraceCallGraph())
	tf.close()

	for test in testrun:
		# add the traceevent data to the device hierarchy
		if(sysvals.usetraceevents):
			for name in test.ttemp:
				for event in test.ttemp[name]:
					begin = event['begin']
					end = event['end']
					# if event starts before timeline start, expand timeline
					if(begin < test.data.start):
						test.data.setStart(begin)
					# if event ends after timeline end, expand the timeline
					if(end > test.data.end):
						test.data.setEnd(end)
					test.data.newActionGlobal(name, begin, end)

		# add the callgraph data to the device hierarchy
		for pid in test.ftemp:
			for cg in test.ftemp[pid]:
				if(not cg.sanityCheck()):
					id = 'task %s cpu %s' % (pid, m.group('cpu'))
					vprint('Sanity check failed for '+\
						id+', ignoring this callback')
					continue
				callstart = cg.start
				callend = cg.end
				for p in test.data.phases:
					if(test.data.dmesg[p]['start'] <= callstart and
						callstart <= test.data.dmesg[p]['end']):
						list = test.data.dmesg[p]['list']
						for devname in list:
							dev = list[devname]
							if(pid == dev['pid'] and
								callstart <= dev['start'] and
								callend >= dev['end']):
								dev['ftrace'] = cg
						break

		if(sysvals.verbose):
			test.data.printDetails()


	# add the time in between the tests as a new phase so we can see it
	if(len(testruns) > 1):
		t1e = testruns[0].getEnd()
		t2s = testruns[-1].getStart()
		testruns[-1].newPhaseWithSingleAction('user mode', \
			'user mode', t1e, t2s, '#FF9966')

# Function: parseTraceLog
# Description:
#	 Analyze an ftrace log output file generated from this app during
#	 the execution phase. Used when the ftrace log is the primary data source
#	 and includes the suspend_resume and device_pm_callback trace events
#	 The ftrace filename is taken from sysvals
# Output:
#	 An array of Data objects
def parseTraceLog():
	global sysvals

	vprint('Analyzing the ftrace data...')
	if(os.path.exists(sysvals.ftracefile) == False):
		doError('%s doesnt exist' % sysvals.ftracefile, False)

	# extract the callgraph and traceevent data
	testruns = []
	testdata = []
	testrun = 0
	data = 0
	tf = open(sysvals.ftracefile, 'r')
	phase = 'suspend_prepare'
	for line in tf:
		# remove any latent carriage returns
		line = line.replace('\r\n', '')
		# stamp line: each stamp means a new test run
		m = re.match(sysvals.stampfmt, line)
		if(m):
			data = Data(len(testdata))
			testdata.append(data)
			testrun = TestRun(data)
			testruns.append(testrun)
			parseStamp(m, data)
			continue
		if(not data):
			continue
		# firmware line: pull out any firmware data
		m = re.match(sysvals.firmwarefmt, line)
		if(m):
			data.fwSuspend = int(m.group('s'))
			data.fwResume = int(m.group('r'))
			if(data.fwSuspend > 0 or data.fwResume > 0):
				data.fwValid = True
			continue
		# tracer type line: determine the trace data type
		m = re.match(sysvals.tracertypefmt, line)
		if(m):
			tracer = m.group('t')
			testrun.setTracerType(tracer)
			continue
		# post resume time line: did this test run include post-resume data
		m = re.match(sysvals.postresumefmt, line)
		if(m):
			t = int(m.group('t'))
			if(t > 0):
				sysvals.postresumetime = t
			continue
		# ftrace line: parse only valid lines
		m = re.match(testrun.ftrace_line_fmt, line)
		if(not m):
			continue
		# gather the basic message data from the line
		m_time = m.group('time')
		m_pid = m.group('pid')
		m_msg = m.group('msg')
		if(testrun.cgformat):
			m_param3 = m.group('dur')
		else:
			m_param3 = 'traceevent'
		if(m_time and m_pid and m_msg):
			t = FTraceLine(m_time, m_msg, m_param3)
			pid = int(m_pid)
		else:
			continue
		# the line should be a call, return, or event
		if(not t.fcall and not t.freturn and not t.fevent):
			continue
		# only parse the ftrace data during suspend/resume
		if(not testrun.inthepipe):
			# look for the suspend start marker
			if(t.fevent):
				if(t.name == 'SUSPEND START'):
					testrun.inthepipe = True
					data.setStart(t.time)
			continue
		# trace event processing
		if(t.fevent):
			if(t.name == 'RESUME COMPLETE'):
				if(sysvals.postresumetime > 0):
					phase = 'post_resume'
					data.newPhase(phase, t.time, t.time, '#FF9966', -1)
				else:
					testrun.inthepipe = False
				data.setEnd(t.time)
				continue
			if(phase == 'post_resume'):
				data.setEnd(t.time)
			if(t.type == 'suspend_resume'):
				# suspend_resume trace events have two types, begin and end
				if(re.match('(?P<name>.*) begin$', t.name)):
					isbegin = True
				elif(re.match('(?P<name>.*) end$', t.name)):
					isbegin = False
				else:
					continue
				m = re.match('(?P<name>.*)\[(?P<val>[0-9]*)\] .*', t.name)
				if(m):
					val = m.group('val')
					if val == '0':
						name = m.group('name')
					else:
						name = m.group('name')+'['+val+']'
				else:
					m = re.match('(?P<name>.*) .*', t.name)
					name = m.group('name')
				# ignore these events
				if(re.match('acpi_suspend\[.*', t.name) or
					re.match('suspend_enter\[.*', name)):
					continue
				# -- phase changes --
				# suspend_prepare start
				if(re.match('dpm_prepare\[.*', t.name)):
					phase = 'suspend_prepare'
					if(not isbegin):
						data.dmesg[phase]['end'] = t.time
					continue
				# suspend start
				elif(re.match('dpm_suspend\[.*', t.name)):
					phase = 'suspend'
					data.setPhase(phase, t.time, isbegin)
					continue
				# suspend_late start
				elif(re.match('dpm_suspend_late\[.*', t.name)):
					phase = 'suspend_late'
					data.setPhase(phase, t.time, isbegin)
					continue
				# suspend_noirq start
				elif(re.match('dpm_suspend_noirq\[.*', t.name)):
					phase = 'suspend_noirq'
					data.setPhase(phase, t.time, isbegin)
					if(not isbegin):
						phase = 'suspend_machine'
						data.dmesg[phase]['start'] = t.time
					continue
				# suspend_machine/resume_machine
				elif(re.match('machine_suspend\[.*', t.name)):
					if(isbegin):
						phase = 'suspend_machine'
						data.dmesg[phase]['end'] = t.time
						data.tSuspended = t.time
					else:
						if(sysvals.suspendmode in ['mem', 'disk']):
							data.dmesg['suspend_machine']['end'] = t.time
							data.tSuspended = t.time
						phase = 'resume_machine'
						data.dmesg[phase]['start'] = t.time
						data.tResumed = t.time
						data.tLow = data.tResumed - data.tSuspended
					continue
				# resume_noirq start
				elif(re.match('dpm_resume_noirq\[.*', t.name)):
					phase = 'resume_noirq'
					data.setPhase(phase, t.time, isbegin)
					if(isbegin):
						data.dmesg['resume_machine']['end'] = t.time
					continue
				# resume_early start
				elif(re.match('dpm_resume_early\[.*', t.name)):
					phase = 'resume_early'
					data.setPhase(phase, t.time, isbegin)
					continue
				# resume start
				elif(re.match('dpm_resume\[.*', t.name)):
					phase = 'resume'
					data.setPhase(phase, t.time, isbegin)
					continue
				# resume complete start
				elif(re.match('dpm_complete\[.*', t.name)):
					phase = 'resume_complete'
					if(isbegin):
						data.dmesg[phase]['start'] = t.time
					continue

				# is this trace event outside of the devices calls
				if(data.isTraceEventOutsideDeviceCalls(pid, t.time)):
					# global events (outside device calls) are simply graphed
					if(name not in testrun.ttemp):
						testrun.ttemp[name] = []
					if(isbegin):
						# create a new list entry
						testrun.ttemp[name].append(\
							{'begin': t.time, 'end': t.time})
					else:
						if(len(testrun.ttemp[name]) > 0):
							# if an antry exists, assume this is its end
							testrun.ttemp[name][-1]['end'] = t.time
						elif(phase == 'post_resume'):
							# post resume events can just have ends
							testrun.ttemp[name].append({
								'begin': data.dmesg[phase]['start'],
								'end': t.time})
				else:
					if(isbegin):
						data.addIntraDevTraceEvent('', name, pid, t.time)
					else:
						data.capIntraDevTraceEvent('', name, pid, t.time)
			# device callback start
			elif(t.type == 'device_pm_callback_start'):
				m = re.match('(?P<drv>.*) (?P<d>.*), parent: *(?P<p>.*), .*',\
					t.name);
				if(not m):
					continue
				drv = m.group('drv')
				n = m.group('d')
				p = m.group('p')
				if(n and p):
					data.newAction(phase, n, pid, p, t.time, -1, drv)
			# device callback finish
			elif(t.type == 'device_pm_callback_end'):
				m = re.match('(?P<drv>.*) (?P<d>.*), err.*', t.name);
				if(not m):
					continue
				n = m.group('d')
				list = data.dmesg[phase]['list']
				if(n in list):
					dev = list[n]
					dev['length'] = t.time - dev['start']
					dev['end'] = t.time
		# callgraph processing
		elif sysvals.usecallgraph:
			# this shouldn't happen, but JIC, ignore callgraph data post-res
			if(phase == 'post_resume'):
				continue
			# create a callgraph object for the data
			if(pid not in testrun.ftemp):
				testrun.ftemp[pid] = []
				testrun.ftemp[pid].append(FTraceCallGraph())
			# when the call is finished, see which device matches it
			cg = testrun.ftemp[pid][-1]
			if(cg.addLine(t, m)):
				testrun.ftemp[pid].append(FTraceCallGraph())
	tf.close()

	for test in testruns:
		# add the traceevent data to the device hierarchy
		if(sysvals.usetraceevents):
			for name in test.ttemp:
				for event in test.ttemp[name]:
					begin = event['begin']
					end = event['end']
					# if event starts before timeline start, expand timeline
					if(begin < test.data.start):
						test.data.setStart(begin)
					# if event ends after timeline end, expand the timeline
					if(end > test.data.end):
						test.data.setEnd(end)
					test.data.newActionGlobal(name, begin, end)

		# add the callgraph data to the device hierarchy
		borderphase = {
			'dpm_prepare': 'suspend_prepare',
			'dpm_complete': 'resume_complete'
		}
		for pid in test.ftemp:
			for cg in test.ftemp[pid]:
				if len(cg.list) < 2:
					continue
				if(not cg.sanityCheck()):
					id = 'task %s cpu %s' % (pid, m.group('cpu'))
					vprint('Sanity check failed for '+\
						id+', ignoring this callback')
					continue
				callstart = cg.start
				callend = cg.end
				if(cg.list[0].name in borderphase):
					p = borderphase[cg.list[0].name]
					list = test.data.dmesg[p]['list']
					for devname in list:
						dev = list[devname]
						if(pid == dev['pid'] and
							callstart <= dev['start'] and
							callend >= dev['end']):
							dev['ftrace'] = cg.slice(dev['start'], dev['end'])
					continue
				if(cg.list[0].name != 'dpm_run_callback'):
					continue
				for p in test.data.phases:
					if(test.data.dmesg[p]['start'] <= callstart and
						callstart <= test.data.dmesg[p]['end']):
						list = test.data.dmesg[p]['list']
						for devname in list:
							dev = list[devname]
							if(pid == dev['pid'] and
								callstart <= dev['start'] and
								callend >= dev['end']):
								dev['ftrace'] = cg
						break

	# fill in any missing phases
	for data in testdata:
		lp = data.phases[0]
		for p in data.phases:
			if(data.dmesg[p]['start'] < 0 and data.dmesg[p]['end'] < 0):
				print('WARNING: phase "%s" is missing!' % p)
			if(data.dmesg[p]['start'] < 0):
				data.dmesg[p]['start'] = data.dmesg[lp]['end']
				if(p == 'resume_machine'):
					data.tSuspended = data.dmesg[lp]['end']
					data.tResumed = data.dmesg[lp]['end']
					data.tLow = 0
			if(data.dmesg[p]['end'] < 0):
				data.dmesg[p]['end'] = data.dmesg[p]['start']
			lp = p

		if(len(sysvals.devicefilter) > 0):
			data.deviceFilter(sysvals.devicefilter)
		data.fixupInitcallsThatDidntReturn()
		if(sysvals.verbose):
			data.printDetails()

	# add the time in between the tests as a new phase so we can see it
	if(len(testdata) > 1):
		t1e = testdata[0].getEnd()
		t2s = testdata[-1].getStart()
		testdata[-1].newPhaseWithSingleAction('user mode', \
			'user mode', t1e, t2s, '#FF9966')
	return testdata

# Function: loadKernelLog
# Description:
#	 [deprecated for kernel 3.15.0 or newer]
#	 load the dmesg file into memory and fix up any ordering issues
#	 The dmesg filename is taken from sysvals
# Output:
#	 An array of empty Data objects with only their dmesgtext attributes set
def loadKernelLog():
	global sysvals

	vprint('Analyzing the dmesg data...')
	if(os.path.exists(sysvals.dmesgfile) == False):
		doError('%s doesnt exist' % sysvals.dmesgfile, False)

	# there can be multiple test runs in a single file delineated by stamps
	testruns = []
	data = 0
	lf = open(sysvals.dmesgfile, 'r')
	for line in lf:
		line = line.replace('\r\n', '')
		idx = line.find('[')
		if idx > 1:
			line = line[idx:]
		m = re.match(sysvals.stampfmt, line)
		if(m):
			if(data):
				testruns.append(data)
			data = Data(len(testruns))
			parseStamp(m, data)
			continue
		if(not data):
			continue
		m = re.match(sysvals.firmwarefmt, line)
		if(m):
			data.fwSuspend = int(m.group('s'))
			data.fwResume = int(m.group('r'))
			if(data.fwSuspend > 0 or data.fwResume > 0):
				data.fwValid = True
			continue
		m = re.match('[ \t]*(\[ *)(?P<ktime>[0-9\.]*)(\]) (?P<msg>.*)', line)
		if(m):
			data.dmesgtext.append(line)
			if(re.match('ACPI: resume from mwait', m.group('msg'))):
				print('NOTE: This suspend appears to be freeze rather than'+\
					' %s, it will be treated as such' % sysvals.suspendmode)
				sysvals.suspendmode = 'freeze'
		else:
			vprint('ignoring dmesg line: %s' % line.replace('\n', ''))
	testruns.append(data)
	lf.close()

	if(not data):
		print('ERROR: analyze_suspend header missing from dmesg log')
		sys.exit()

	# fix lines with same timestamp/function with the call and return swapped
	for data in testruns:
		last = ''
		for line in data.dmesgtext:
			mc = re.match('.*(\[ *)(?P<t>[0-9\.]*)(\]) calling  '+\
				'(?P<f>.*)\+ @ .*, parent: .*', line)
			mr = re.match('.*(\[ *)(?P<t>[0-9\.]*)(\]) call '+\
				'(?P<f>.*)\+ returned .* after (?P<dt>.*) usecs', last)
			if(mc and mr and (mc.group('t') == mr.group('t')) and
				(mc.group('f') == mr.group('f'))):
				i = data.dmesgtext.index(last)
				j = data.dmesgtext.index(line)
				data.dmesgtext[i] = line
				data.dmesgtext[j] = last
			last = line
	return testruns

# Function: parseKernelLog
# Description:
#	 [deprecated for kernel 3.15.0 or newer]
#	 Analyse a dmesg log output file generated from this app during
#	 the execution phase. Create a set of device structures in memory
#	 for subsequent formatting in the html output file
#	 This call is only for legacy support on kernels where the ftrace
#	 data lacks the suspend_resume or device_pm_callbacks trace events.
# Arguments:
#	 data: an empty Data object (with dmesgtext) obtained from loadKernelLog
# Output:
#	 The filled Data object
def parseKernelLog(data):
	global sysvals

	phase = 'suspend_runtime'

	if(data.fwValid):
		vprint('Firmware Suspend = %u ns, Firmware Resume = %u ns' % \
			(data.fwSuspend, data.fwResume))

	# dmesg phase match table
	dm = {
		'suspend_prepare': 'PM: Syncing filesystems.*',
		        'suspend': 'PM: Entering [a-z]* sleep.*',
		   'suspend_late': 'PM: suspend of devices complete after.*',
		  'suspend_noirq': 'PM: late suspend of devices complete after.*',
		'suspend_machine': 'PM: noirq suspend of devices complete after.*',
		 'resume_machine': 'ACPI: Low-level resume complete.*',
		   'resume_noirq': 'ACPI: Waking up from system sleep state.*',
		   'resume_early': 'PM: noirq resume of devices complete after.*',
		         'resume': 'PM: early resume of devices complete after.*',
		'resume_complete': 'PM: resume of devices complete after.*',
		    'post_resume': '.*Restarting tasks \.\.\..*',
	}
	if(sysvals.suspendmode == 'standby'):
		dm['resume_machine'] = 'PM: Restoring platform NVS memory'
	elif(sysvals.suspendmode == 'disk'):
		dm['suspend_late'] = 'PM: freeze of devices complete after.*'
		dm['suspend_noirq'] = 'PM: late freeze of devices complete after.*'
		dm['suspend_machine'] = 'PM: noirq freeze of devices complete after.*'
		dm['resume_machine'] = 'PM: Restoring platform NVS memory'
		dm['resume_early'] = 'PM: noirq restore of devices complete after.*'
		dm['resume'] = 'PM: early restore of devices complete after.*'
		dm['resume_complete'] = 'PM: restore of devices complete after.*'
	elif(sysvals.suspendmode == 'freeze'):
		dm['resume_machine'] = 'ACPI: resume from mwait'

	# action table (expected events that occur and show up in dmesg)
	at = {
		'sync_filesystems': {
			'smsg': 'PM: Syncing filesystems.*',
			'emsg': 'PM: Preparing system for mem sleep.*' },
		'freeze_user_processes': {
			'smsg': 'Freezing user space processes .*',
			'emsg': 'Freezing remaining freezable tasks.*' },
		'freeze_tasks': {
			'smsg': 'Freezing remaining freezable tasks.*',
			'emsg': 'PM: Entering (?P<mode>[a-z,A-Z]*) sleep.*' },
		'ACPI prepare': {
			'smsg': 'ACPI: Preparing to enter system sleep state.*',
			'emsg': 'PM: Saving platform NVS memory.*' },
		'PM vns': {
			'smsg': 'PM: Saving platform NVS memory.*',
			'emsg': 'Disabling non-boot CPUs .*' },
	}

	t0 = -1.0
	cpu_start = -1.0
	prevktime = -1.0
	actions = dict()
	for line in data.dmesgtext:
		# -- preprocessing --
		# parse each dmesg line into the time and message
		m = re.match('[ \t]*(\[ *)(?P<ktime>[0-9\.]*)(\]) (?P<msg>.*)', line)
		if(m):
			val = m.group('ktime')
			try:
				ktime = float(val)
			except:
				doWarning('INVALID DMESG LINE: '+\
					line.replace('\n', ''), 'dmesg')
				continue
			msg = m.group('msg')
			# initialize data start to first line time
			if t0 < 0:
				data.setStart(ktime)
				t0 = ktime
		else:
			continue

		# hack for determining resume_machine end for freeze
		if(not sysvals.usetraceevents and sysvals.suspendmode == 'freeze' \
			and phase == 'resume_machine' and \
			re.match('calling  (?P<f>.*)\+ @ .*, parent: .*', msg)):
			data.dmesg['resume_machine']['end'] = ktime
			phase = 'resume_noirq'
			data.dmesg[phase]['start'] = ktime

		# -- phase changes --
		# suspend start
		if(re.match(dm['suspend_prepare'], msg)):
			phase = 'suspend_prepare'
			data.dmesg[phase]['start'] = ktime
			data.setStart(ktime)
		# suspend start
		elif(re.match(dm['suspend'], msg)):
			data.dmesg['suspend_prepare']['end'] = ktime
			phase = 'suspend'
			data.dmesg[phase]['start'] = ktime
		# suspend_late start
		elif(re.match(dm['suspend_late'], msg)):
			data.dmesg['suspend']['end'] = ktime
			phase = 'suspend_late'
			data.dmesg[phase]['start'] = ktime
		# suspend_noirq start
		elif(re.match(dm['suspend_noirq'], msg)):
			data.dmesg['suspend_late']['end'] = ktime
			phase = 'suspend_noirq'
			data.dmesg[phase]['start'] = ktime
		# suspend_machine start
		elif(re.match(dm['suspend_machine'], msg)):
			data.dmesg['suspend_noirq']['end'] = ktime
			phase = 'suspend_machine'
			data.dmesg[phase]['start'] = ktime
		# resume_machine start
		elif(re.match(dm['resume_machine'], msg)):
			if(sysvals.suspendmode in ['freeze', 'standby']):
				data.tSuspended = prevktime
				data.dmesg['suspend_machine']['end'] = prevktime
			else:
				data.tSuspended = ktime
				data.dmesg['suspend_machine']['end'] = ktime
			phase = 'resume_machine'
			data.tResumed = ktime
			data.tLow = data.tResumed - data.tSuspended
			data.dmesg[phase]['start'] = ktime
		# resume_noirq start
		elif(re.match(dm['resume_noirq'], msg)):
			data.dmesg['resume_machine']['end'] = ktime
			phase = 'resume_noirq'
			data.dmesg[phase]['start'] = ktime
		# resume_early start
		elif(re.match(dm['resume_early'], msg)):
			data.dmesg['resume_noirq']['end'] = ktime
			phase = 'resume_early'
			data.dmesg[phase]['start'] = ktime
		# resume start
		elif(re.match(dm['resume'], msg)):
			data.dmesg['resume_early']['end'] = ktime
			phase = 'resume'
			data.dmesg[phase]['start'] = ktime
		# resume complete start
		elif(re.match(dm['resume_complete'], msg)):
			data.dmesg['resume']['end'] = ktime
			phase = 'resume_complete'
			data.dmesg[phase]['start'] = ktime
		# post resume start
		elif(re.match(dm['post_resume'], msg)):
			data.dmesg['resume_complete']['end'] = ktime
			data.setEnd(ktime)
			phase = 'post_resume'
			break

		# -- device callbacks --
		if(phase in data.phases):
			# device init call
			if(re.match('calling  (?P<f>.*)\+ @ .*, parent: .*', msg)):
				sm = re.match('calling  (?P<f>.*)\+ @ '+\
					'(?P<n>.*), parent: (?P<p>.*)', msg);
				f = sm.group('f')
				n = sm.group('n')
				p = sm.group('p')
				if(f and n and p):
					data.newAction(phase, f, int(n), p, ktime, -1, '')
			# device init return
			elif(re.match('call (?P<f>.*)\+ returned .* after '+\
				'(?P<t>.*) usecs', msg)):
				sm = re.match('call (?P<f>.*)\+ returned .* after '+\
					'(?P<t>.*) usecs(?P<a>.*)', msg);
				f = sm.group('f')
				t = sm.group('t')
				list = data.dmesg[phase]['list']
				if(f in list):
					dev = list[f]
					dev['length'] = int(t)
					dev['end'] = ktime

		# -- non-devicecallback actions --
		# if trace events are not available, these are better than nothing
		if(not sysvals.usetraceevents):
			# look for known actions
			for a in at:
				if(re.match(at[a]['smsg'], msg)):
					if(a not in actions):
						actions[a] = []
					actions[a].append({'begin': ktime, 'end': ktime})
				if(re.match(at[a]['emsg'], msg)):
					actions[a][-1]['end'] = ktime
			# now look for CPU on/off events
			if(re.match('Disabling non-boot CPUs .*', msg)):
				# start of first cpu suspend
				cpu_start = ktime
			elif(re.match('Enabling non-boot CPUs .*', msg)):
				# start of first cpu resume
				cpu_start = ktime
			elif(re.match('smpboot: CPU (?P<cpu>[0-9]*) is now offline', msg)):
				# end of a cpu suspend, start of the next
				m = re.match('smpboot: CPU (?P<cpu>[0-9]*) is now offline', msg)
				cpu = 'CPU'+m.group('cpu')
				if(cpu not in actions):
					actions[cpu] = []
				actions[cpu].append({'begin': cpu_start, 'end': ktime})
				cpu_start = ktime
			elif(re.match('CPU(?P<cpu>[0-9]*) is up', msg)):
				# end of a cpu resume, start of the next
				m = re.match('CPU(?P<cpu>[0-9]*) is up', msg)
				cpu = 'CPU'+m.group('cpu')
				if(cpu not in actions):
					actions[cpu] = []
				actions[cpu].append({'begin': cpu_start, 'end': ktime})
				cpu_start = ktime
		prevktime = ktime

	# fill in any missing phases
	lp = data.phases[0]
	for p in data.phases:
		if(data.dmesg[p]['start'] < 0 and data.dmesg[p]['end'] < 0):
			print('WARNING: phase "%s" is missing, something went wrong!' % p)
			print('    In %s, this dmesg line denotes the start of %s:' % \
				(sysvals.suspendmode, p))
			print('        "%s"' % dm[p])
		if(data.dmesg[p]['start'] < 0):
			data.dmesg[p]['start'] = data.dmesg[lp]['end']
			if(p == 'resume_machine'):
				data.tSuspended = data.dmesg[lp]['end']
				data.tResumed = data.dmesg[lp]['end']
				data.tLow = 0
		if(data.dmesg[p]['end'] < 0):
			data.dmesg[p]['end'] = data.dmesg[p]['start']
		lp = p

	# fill in any actions we've found
	for name in actions:
		for event in actions[name]:
			begin = event['begin']
			end = event['end']
			# if event starts before timeline start, expand timeline
			if(begin < data.start):
				data.setStart(begin)
			# if event ends after timeline end, expand the timeline
			if(end > data.end):
				data.setEnd(end)
			data.newActionGlobal(name, begin, end)

	if(sysvals.verbose):
		data.printDetails()
	if(len(sysvals.devicefilter) > 0):
		data.deviceFilter(sysvals.devicefilter)
	data.fixupInitcallsThatDidntReturn()
	return True

# Function: setTimelineRows
# Description:
#	 Organize the timeline entries into the smallest
#	 number of rows possible, with no entry overlapping
# Arguments:
#	 list: the list of devices/actions for a single phase
#	 sortedkeys: cronologically sorted key list to use
# Output:
#	 The total number of rows needed to display this phase of the timeline
def setTimelineRows(list, sortedkeys):

	# clear all rows and set them to undefined
	remaining = len(list)
	rowdata = dict()
	row = 0
	for item in list:
		list[item]['row'] = -1

	# try to pack each row with as many ranges as possible
	while(remaining > 0):
		if(row not in rowdata):
			rowdata[row] = []
		for item in sortedkeys:
			if(list[item]['row'] < 0):
				s = list[item]['start']
				e = list[item]['end']
				valid = True
				for ritem in rowdata[row]:
					rs = ritem['start']
					re = ritem['end']
					if(not (((s <= rs) and (e <= rs)) or
						((s >= re) and (e >= re)))):
						valid = False
						break
				if(valid):
					rowdata[row].append(list[item])
					list[item]['row'] = row
					remaining -= 1
		row += 1
	return row

# Function: createTimeScale
# Description:
#	 Create the timescale header for the html timeline
# Arguments:
#	 t0: start time (suspend begin)
#	 tMax: end time (resume end)
#	 tSuspend: time when suspend occurs, i.e. the zero time
# Output:
#	 The html code needed to display the time scale
def createTimeScale(t0, tMax, tSuspended):
	timescale = '<div class="t" style="right:{0}%">{1}</div>\n'
	output = '<div id="timescale">\n'

	# set scale for timeline
	tTotal = tMax - t0
	tS = 0.1
	if(tTotal <= 0):
		return output
	if(tTotal > 4):
		tS = 1
	if(tSuspended < 0):
		for i in range(int(tTotal/tS)+1):
			pos = '%0.3f' % (100 - ((float(i)*tS*100)/tTotal))
			if(i > 0):
				val = '%0.fms' % (float(i)*tS*1000)
			else:
				val = ''
			output += timescale.format(pos, val)
	else:
		tSuspend = tSuspended - t0
		divTotal = int(tTotal/tS) + 1
		divSuspend = int(tSuspend/tS)
		s0 = (tSuspend - tS*divSuspend)*100/tTotal
		for i in range(divTotal):
			pos = '%0.3f' % (100 - ((float(i)*tS*100)/tTotal) - s0)
			if((i == 0) and (s0 < 3)):
				val = ''
			elif(i == divSuspend):
				val = 'S/R'
			else:
				val = '%0.fms' % (float(i-divSuspend)*tS*1000)
			output += timescale.format(pos, val)
	output += '</div>\n'
	return output

# Function: createHTMLSummarySimple
# Description:
#	 Create summary html file for a series of tests
# Arguments:
#	 testruns: array of Data objects from parseTraceLog
def createHTMLSummarySimple(testruns, htmlfile):
	global sysvals

	# print out the basic summary of all the tests
	hf = open(htmlfile, 'w')

	# write the html header first (html head, css code, up to body start)
	html = '<!DOCTYPE html>\n<html>\n<head>\n\
	<meta http-equiv="content-type" content="text/html; charset=UTF-8">\n\
	<title>AnalyzeSuspend Summary</title>\n\
	<style type=\'text/css\'>\n\
		body {overflow-y: scroll;}\n\
		.stamp {width: 100%;text-align:center;background-color:#495E09;line-height:30px;color:white;font: 25px Arial;}\n\
		table {width:100%;border-collapse: collapse;}\n\
		.summary {font: 22px Arial;border:1px solid;}\n\
		th {border: 1px solid black;background-color:#A7C942;color:white;}\n\
		td {text-align: center;}\n\
		tr.alt td {background-color:#EAF2D3;}\n\
		tr.avg td {background-color:#BDE34C;}\n\
		a:link {color: #90B521;}\n\
		a:visited {color: #495E09;}\n\
		a:hover {color: #B1DF28;}\n\
		a:active {color: #FFFFFF;}\n\
	</style>\n</head>\n<body>\n'

	# group test header
	count = len(testruns)
	headline_stamp = '<div class="stamp">{0} {1} {2} {3} ({4} tests)</div>\n'
	html += headline_stamp.format(sysvals.stamp['host'],
		sysvals.stamp['kernel'], sysvals.stamp['mode'],
		sysvals.stamp['time'], count)

	# check to see if all the tests have the same value
	stampcolumns = False
	for data in testruns:
		if diffStamp(sysvals.stamp, data.stamp):
			stampcolumns = True
			break

	th = '\t<th>{0}</th>\n'
	td = '\t<td>{0}</td>\n'
	tdlink = '\t<td><a href="{0}">Click Here</a></td>\n'

	# table header
	html += '<table class="summary">\n<tr>\n'
	html += th.format("Test #")
	if stampcolumns:
		html += th.format("Hostname")
		html += th.format("Kernel Version")
		html += th.format("Suspend Mode")
	html += th.format("Test Time")
	html += th.format("Suspend Time")
	html += th.format("Resume Time")
	html += th.format("Detail")
	html += '</tr>\n'

	# test data, 1 row per test
	sTimeAvg = 0.0
	rTimeAvg = 0.0
	num = 1
	for data in testruns:
		# data.end is the end of post_resume
		resumeEnd = data.dmesg['resume_complete']['end']
		if num % 2 == 1:
			html += '<tr class="alt">\n'
		else:
			html += '<tr>\n'

		# test num
		html += td.format("test %d" % num)
		num += 1
		if stampcolumns:
			# host name
			val = "unknown"
			if('host' in data.stamp):
				val = data.stamp['host']
			html += td.format(val)
			# host kernel
			val = "unknown"
			if('kernel' in data.stamp):
				val = data.stamp['kernel']
			html += td.format(val)
			# suspend mode
			val = "unknown"
			if('mode' in data.stamp):
				val = data.stamp['mode']
			html += td.format(val)
		# test time
		val = "unknown"
		if('time' in data.stamp):
			val = data.stamp['time']
		html += td.format(val)
		# suspend time