def parseTraceLog(data):
sysvals.vprint('Analyzing the ftrace data (%s)...' % \
os.path.basename(sysvals.ftracefile))
# if available, calculate cgfilter allowable ranges
cgfilter = []
if len(sysvals.cgfilter) > 0:
for p in data.phases:
list = data.dmesg[p]['list']
for i in sysvals.cgfilter:
if i in list:
cgfilter.append(
[list[i]['start'] - 0.0001, list[i]['end'] + 0.0001])
# parse the trace log
ftemp = dict()
tp = aslib.TestProps()
tp.setTracerType('function_graph')
tf = open(sysvals.ftracefile, 'r')
for line in tf:
if line[0] == '#':
continue
m = re.match(tp.ftrace_line_fmt, line.strip())
if (not m):
continue
m_time, m_proc, m_pid, m_msg, m_dur = \
m.group('time', 'proc', 'pid', 'msg', 'dur')
t = float(m_time)
if len(cgfilter) > 0:
allow = False
for r in cgfilter:
if t >= r[0] and t < r[1]:
allow = True
break
if not allow:
continue
if t > data.end:
break
if (m_time and m_pid and m_msg):
t = aslib.FTraceLine(m_time, m_msg, m_dur)
pid = int(m_pid)
else:
continue
if t.fevent or t.fkprobe:
continue
key = (m_proc, pid)
if (key not in ftemp):
ftemp[key] = []
ftemp[key].append(aslib.FTraceCallGraph(pid, sysvals))
cg = ftemp[key][-1]
res = cg.addLine(t)
if (res != 0):
ftemp[key].append(aslib.FTraceCallGraph(pid, sysvals))
if (res == -1):
ftemp[key][-1].addLine(t)
tf.close()
# add the callgraph data to the device hierarchy
for key in ftemp:
proc, pid = key
for cg in ftemp[key]:
if len(cg.list) < 1 or cg.invalid or (cg.end - cg.start == 0):
continue
if (not cg.postProcess()):
pprint('Sanity check failed for %s-%d' % (proc, pid))
continue
# match cg data to devices
devname = data.deviceMatch(pid, cg)
if not devname:
kind = 'Orphan'
if cg.partial:
kind = 'Partial'
sysvals.vprint('%s callgraph found for %s %s-%d [%f - %f]' %\
(kind, cg.name, proc, pid, cg.start, cg.end))
elif len(cg.list) > 1000000:
pprint('WARNING: the callgraph found for %s is massive! (%d lines)' %\
(devname, len(cg.list)))
def parseKernelLog():
sysvals.vprint('Analyzing the dmesg data (%s)...' % \
os.path.basename(sysvals.dmesgfile))
phase = 'kernel'
data = Data(0)
data.dmesg['kernel']['start'] = data.start = ktime = 0.0
sysvals.stamp = {
'time': datetime.now().strftime('%B %d %Y, %I:%M:%S %p'),
'host': sysvals.hostname,
'mode': 'boot',
'kernel': ''
}
tp = aslib.TestProps()
devtemp = dict()
if (sysvals.dmesgfile):
lf = open(sysvals.dmesgfile, 'r')
else:
lf = Popen('dmesg', stdout=PIPE).stdout
for line in lf:
line = line.replace('\r\n', '')
# grab the stamp and sysinfo
if re.match(tp.stampfmt, line):
tp.stamp = line
continue
elif re.match(tp.sysinfofmt, line):
tp.sysinfo = line
continue
elif re.match(tp.cmdlinefmt, line):
tp.cmdline = line
continue
elif re.match(tp.kparamsfmt, line):
tp.kparams = line
continue
idx = line.find('[')
if idx > 1:
line = line[idx:]
m = re.match('[ \t]*(\[ *)(?P<ktime>[0-9\.]*)(\]) (?P<msg>.*)', line)
if (not m):
continue
ktime = float(m.group('ktime'))
if (ktime > 120):
break
msg = m.group('msg')
data.dmesgtext.append(line)
if (ktime == 0.0 and re.match('^Linux version .*', msg)):
if (not sysvals.stamp['kernel']):
sysvals.stamp['kernel'] = sysvals.kernelVersion(msg)
continue
m = re.match('.* setting system clock to (?P<t>.*) UTC.*', msg)
if (m):
bt = datetime.strptime(m.group('t'), '%Y-%m-%d %H:%M:%S')
bt = bt - timedelta(seconds=int(ktime))
data.boottime = bt.strftime('%Y-%m-%d_%H:%M:%S')
sysvals.stamp['time'] = bt.strftime('%B %d %Y, %I:%M:%S %p')
continue
m = re.match('^calling *(?P<f>.*)\+.* @ (?P<p>[0-9]*)', msg)
if (m):
func = m.group('f')
pid = int(m.group('p'))
devtemp[func] = (ktime, pid)
continue
m = re.match(
'^initcall *(?P<f>.*)\+.* returned (?P<r>.*) after (?P<t>.*) usecs',
msg)
if (m):
data.valid = True
data.end = ktime
f, r, t = m.group('f', 'r', 't')
if (f in devtemp):
start, pid = devtemp[f]
data.newAction(phase, f, pid, start, ktime, int(r), int(t))
del devtemp[f]
continue
if (re.match('^Freeing unused kernel memory.*', msg)):
data.tUserMode = ktime
data.dmesg['kernel']['end'] = ktime
data.dmesg['user']['start'] = ktime
phase = 'user'
if tp.stamp:
sysvals.stamp = 0
tp.parseStamp(data, sysvals)
data.dmesg['user']['end'] = data.end
lf.close()
return data
