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 analyzeTraceLog(file): global sysvals tracer = "" cg = sglib.FTraceCallGraph(0, sglib.sysvals) cg.stamp = '' tZero = -1.0 # read through the ftrace and parse the data print("Analyzing the ftrace data...") ttypefmt = r"# tracer: (?P<t>.*)" stampfmt = r"# (?P<name>.*)-(?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})$" linefmt = r"^ *(?P<time>[0-9\.]*) *\| *(?P<cpu>[0-9]*)\)"+\ " *(?P<proc>.*)-(?P<pid>[0-9]*) *\|"+\ "[ +!]*(?P<dur>[0-9\.]*) .*\| (?P<msg>.*)" # extract the callgraph and traceevent data tf = open(file, '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(stampfmt, line) if(m): dt = datetime.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"))) cg.stamp = dt.strftime("%B %d %Y, %I:%M:%S %p") if(m.group("name")): cg.stamp = m.group("name")+" "+cg.stamp print(cg.stamp) continue # determine the trace data type (required for further parsing) m = re.match(ttypefmt, line) if(m): tracer = m.group("t") if(tracer != "function_graph"): print("Invalid tracer type: %s" % tracer) sys.exit() continue # parse only valid lines, if this isn't one move on m = re.match(linefmt, 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") m_param3 = m.group("dur") if(m_time and m_pid and m_msg): t = sglib.FTraceLine(m_time, m_msg, m_param3) pid = int(m_pid) if(tZero < 0): tZero = t.time else: continue # the line should be a call, return, or event if(not t.fcall and not t.freturn and not t.fevent): continue cg.addLine(t) tf.close() # normalize time to start of first line cg.start -= tZero cg.end -= tZero for line in cg.list: line.time -= tZero return cg