mirror of
git://git.yoctoproject.org/poky.git
synced 2025-07-19 21:09:03 +02:00
f68e3e49d4
This patch adds support for parsing and visualizing network interface statistics from /proc/net/dev in pybootchartgui. It introduces a new NetSample class to hold per-interface metrics, including received/transmitted bytes and their deltas over time. The data is drawn using line and box charts in draw.py and helps to monitor network usage during the boot process for each interface individually. (From OE-Core rev: 9e640022c83a627bd05c23b66b658bd644b2f0d7) Signed-off-by: denisova-ok <denisova.olga.k@yandex.ru> Signed-off-by: Mathieu Dubois-Briand <mathieu.dubois-briand@bootlin.com> Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
873 lines
32 KiB
Python
873 lines
32 KiB
Python
# This file is part of pybootchartgui.
|
|
|
|
# pybootchartgui is free software: you can redistribute it and/or modify
|
|
# it under the terms of the GNU General Public License as published by
|
|
# the Free Software Foundation, either version 3 of the License, or
|
|
# (at your option) any later version.
|
|
|
|
# pybootchartgui is distributed in the hope that 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 pybootchartgui. If not, see <http://www.gnu.org/licenses/>.
|
|
|
|
import os
|
|
import string
|
|
import re
|
|
import sys
|
|
import tarfile
|
|
import time
|
|
from collections import defaultdict
|
|
from functools import reduce
|
|
|
|
from .samples import *
|
|
from .process_tree import ProcessTree
|
|
|
|
if sys.version_info >= (3, 0):
|
|
long = int
|
|
|
|
# Parsing produces as its end result a 'Trace'
|
|
|
|
class Trace:
|
|
def __init__(self, writer, paths, options):
|
|
self.processes = {}
|
|
self.start = {}
|
|
self.end = {}
|
|
self.min = None
|
|
self.max = None
|
|
self.headers = None
|
|
self.disk_stats = []
|
|
self.ps_stats = None
|
|
self.taskstats = None
|
|
self.cpu_stats = []
|
|
self.cmdline = None
|
|
self.kernel = None
|
|
self.kernel_tree = None
|
|
self.filename = None
|
|
self.parent_map = None
|
|
self.mem_stats = []
|
|
self.net_stats = []
|
|
self.monitor_disk = None
|
|
self.cpu_pressure = []
|
|
self.io_pressure = []
|
|
self.mem_pressure = []
|
|
self.times = [] # Always empty, but expected by draw.py when drawing system charts.
|
|
|
|
if len(paths):
|
|
parse_paths (writer, self, paths)
|
|
if not self.valid():
|
|
raise ParseError("empty state: '%s' does not contain a valid bootchart" % ", ".join(paths))
|
|
|
|
if options.full_time:
|
|
self.min = min(self.start.keys())
|
|
self.max = max(self.end.keys())
|
|
|
|
|
|
# Rendering system charts depends on start and end
|
|
# time. Provide them where the original drawing code expects
|
|
# them, i.e. in proc_tree.
|
|
class BitbakeProcessTree:
|
|
def __init__(self, start_time, end_time):
|
|
self.start_time = start_time
|
|
self.end_time = end_time
|
|
self.duration = self.end_time - self.start_time
|
|
self.proc_tree = BitbakeProcessTree(min(self.start.keys()),
|
|
max(self.end.keys()))
|
|
|
|
|
|
return
|
|
|
|
# Turn that parsed information into something more useful
|
|
# link processes into a tree of pointers, calculate statistics
|
|
self.compile(writer)
|
|
|
|
# Crop the chart to the end of the first idle period after the given
|
|
# process
|
|
if options.crop_after:
|
|
idle = self.crop (writer, options.crop_after)
|
|
else:
|
|
idle = None
|
|
|
|
# Annotate other times as the first start point of given process lists
|
|
self.times = [ idle ]
|
|
if options.annotate:
|
|
for procnames in options.annotate:
|
|
names = [x[:15] for x in procnames.split(",")]
|
|
for proc in self.ps_stats.process_map.values():
|
|
if proc.cmd in names:
|
|
self.times.append(proc.start_time)
|
|
break
|
|
else:
|
|
self.times.append(None)
|
|
|
|
self.proc_tree = ProcessTree(writer, self.kernel, self.ps_stats,
|
|
self.ps_stats.sample_period,
|
|
self.headers.get("profile.process"),
|
|
options.prune, idle, self.taskstats,
|
|
self.parent_map is not None)
|
|
|
|
if self.kernel is not None:
|
|
self.kernel_tree = ProcessTree(writer, self.kernel, None, 0,
|
|
self.headers.get("profile.process"),
|
|
False, None, None, True)
|
|
|
|
def valid(self):
|
|
return len(self.processes) != 0
|
|
return self.headers != None and self.disk_stats != None and \
|
|
self.ps_stats != None and self.cpu_stats != None
|
|
|
|
def add_process(self, process, start, end):
|
|
self.processes[process] = [start, end]
|
|
if start not in self.start:
|
|
self.start[start] = []
|
|
if process not in self.start[start]:
|
|
self.start[start].append(process)
|
|
if end not in self.end:
|
|
self.end[end] = []
|
|
if process not in self.end[end]:
|
|
self.end[end].append(process)
|
|
|
|
def compile(self, writer):
|
|
|
|
def find_parent_id_for(pid):
|
|
if pid == 0:
|
|
return 0
|
|
ppid = self.parent_map.get(pid)
|
|
if ppid:
|
|
# many of these double forks are so short lived
|
|
# that we have no samples, or process info for them
|
|
# so climb the parent hierarcy to find one
|
|
if int (ppid * 1000) not in self.ps_stats.process_map:
|
|
# print "Pid '%d' short lived with no process" % ppid
|
|
ppid = find_parent_id_for (ppid)
|
|
# else:
|
|
# print "Pid '%d' has an entry" % ppid
|
|
else:
|
|
# print "Pid '%d' missing from pid map" % pid
|
|
return 0
|
|
return ppid
|
|
|
|
# merge in the cmdline data
|
|
if self.cmdline is not None:
|
|
for proc in self.ps_stats.process_map.values():
|
|
rpid = int (proc.pid // 1000)
|
|
if rpid in self.cmdline:
|
|
cmd = self.cmdline[rpid]
|
|
proc.exe = cmd['exe']
|
|
proc.args = cmd['args']
|
|
# else:
|
|
# print "proc %d '%s' not in cmdline" % (rpid, proc.exe)
|
|
|
|
# re-parent any stray orphans if we can
|
|
if self.parent_map is not None:
|
|
for process in self.ps_stats.process_map.values():
|
|
ppid = find_parent_id_for (int(process.pid // 1000))
|
|
if ppid:
|
|
process.ppid = ppid * 1000
|
|
|
|
# stitch the tree together with pointers
|
|
for process in self.ps_stats.process_map.values():
|
|
process.set_parent (self.ps_stats.process_map)
|
|
|
|
# count on fingers variously
|
|
for process in self.ps_stats.process_map.values():
|
|
process.calc_stats (self.ps_stats.sample_period)
|
|
|
|
def crop(self, writer, crop_after):
|
|
|
|
def is_idle_at(util, start, j):
|
|
k = j + 1
|
|
while k < len(util) and util[k][0] < start + 300:
|
|
k += 1
|
|
k = min(k, len(util)-1)
|
|
|
|
if util[j][1] >= 0.25:
|
|
return False
|
|
|
|
avgload = sum(u[1] for u in util[j:k+1]) / (k-j+1)
|
|
if avgload < 0.25:
|
|
return True
|
|
else:
|
|
return False
|
|
def is_idle(util, start):
|
|
for j in range(0, len(util)):
|
|
if util[j][0] < start:
|
|
continue
|
|
return is_idle_at(util, start, j)
|
|
else:
|
|
return False
|
|
|
|
names = [x[:15] for x in crop_after.split(",")]
|
|
for proc in self.ps_stats.process_map.values():
|
|
if proc.cmd in names or proc.exe in names:
|
|
writer.info("selected proc '%s' from list (start %d)"
|
|
% (proc.cmd, proc.start_time))
|
|
break
|
|
if proc is None:
|
|
writer.warn("no selected crop proc '%s' in list" % crop_after)
|
|
|
|
|
|
cpu_util = [(sample.time, sample.user + sample.sys + sample.io) for sample in self.cpu_stats]
|
|
disk_util = [(sample.time, sample.util) for sample in self.disk_stats]
|
|
|
|
idle = None
|
|
for i in range(0, len(cpu_util)):
|
|
if cpu_util[i][0] < proc.start_time:
|
|
continue
|
|
if is_idle_at(cpu_util, cpu_util[i][0], i) \
|
|
and is_idle(disk_util, cpu_util[i][0]):
|
|
idle = cpu_util[i][0]
|
|
break
|
|
|
|
if idle is None:
|
|
writer.warn ("not idle after proc '%s'" % crop_after)
|
|
return None
|
|
|
|
crop_at = idle + 300
|
|
writer.info ("cropping at time %d" % crop_at)
|
|
while len (self.cpu_stats) \
|
|
and self.cpu_stats[-1].time > crop_at:
|
|
self.cpu_stats.pop()
|
|
while len (self.disk_stats) \
|
|
and self.disk_stats[-1].time > crop_at:
|
|
self.disk_stats.pop()
|
|
|
|
self.ps_stats.end_time = crop_at
|
|
|
|
cropped_map = {}
|
|
for key, value in self.ps_stats.process_map.items():
|
|
if (value.start_time <= crop_at):
|
|
cropped_map[key] = value
|
|
|
|
for proc in cropped_map.values():
|
|
proc.duration = min (proc.duration, crop_at - proc.start_time)
|
|
while len (proc.samples) \
|
|
and proc.samples[-1].time > crop_at:
|
|
proc.samples.pop()
|
|
|
|
self.ps_stats.process_map = cropped_map
|
|
|
|
return idle
|
|
|
|
|
|
|
|
class ParseError(Exception):
|
|
"""Represents errors during parse of the bootchart."""
|
|
def __init__(self, value):
|
|
self.value = value
|
|
|
|
def __str__(self):
|
|
return self.value
|
|
|
|
def _parse_headers(file):
|
|
"""Parses the headers of the bootchart."""
|
|
def parse(acc, line):
|
|
(headers, last) = acc
|
|
if '=' in line:
|
|
last, value = map (lambda x: x.strip(), line.split('=', 1))
|
|
else:
|
|
value = line.strip()
|
|
headers[last] += value
|
|
return headers, last
|
|
return reduce(parse, file.read().split('\n'), (defaultdict(str),''))[0]
|
|
|
|
def _parse_timed_blocks(file):
|
|
"""Parses (ie., splits) a file into so-called timed-blocks. A
|
|
timed-block consists of a timestamp on a line by itself followed
|
|
by zero or more lines of data for that point in time."""
|
|
def parse(block):
|
|
lines = block.split('\n')
|
|
if not lines:
|
|
raise ParseError('expected a timed-block consisting a timestamp followed by data lines')
|
|
try:
|
|
return (int(lines[0]), lines[1:])
|
|
except ValueError:
|
|
raise ParseError("expected a timed-block, but timestamp '%s' is not an integer" % lines[0])
|
|
blocks = file.read().split('\n\n')
|
|
return [parse(block) for block in blocks if block.strip() and not block.endswith(' not running\n')]
|
|
|
|
def _parse_proc_ps_log(writer, file):
|
|
"""
|
|
* See proc(5) for details.
|
|
*
|
|
* {pid, comm, state, ppid, pgrp, session, tty_nr, tpgid, flags, minflt, cminflt, majflt, cmajflt, utime, stime,
|
|
* cutime, cstime, priority, nice, 0, itrealvalue, starttime, vsize, rss, rlim, startcode, endcode, startstack,
|
|
* kstkesp, kstkeip}
|
|
"""
|
|
processMap = {}
|
|
ltime = 0
|
|
timed_blocks = _parse_timed_blocks(file)
|
|
for time, lines in timed_blocks:
|
|
for line in lines:
|
|
if not line: continue
|
|
tokens = line.split(' ')
|
|
if len(tokens) < 21:
|
|
continue
|
|
|
|
offset = [index for index, token in enumerate(tokens[1:]) if token[-1] == ')'][0]
|
|
pid, cmd, state, ppid = int(tokens[0]), ' '.join(tokens[1:2+offset]), tokens[2+offset], int(tokens[3+offset])
|
|
userCpu, sysCpu, stime = int(tokens[13+offset]), int(tokens[14+offset]), int(tokens[21+offset])
|
|
|
|
# magic fixed point-ness ...
|
|
pid *= 1000
|
|
ppid *= 1000
|
|
if pid in processMap:
|
|
process = processMap[pid]
|
|
process.cmd = cmd.strip('()') # why rename after latest name??
|
|
else:
|
|
process = Process(writer, pid, cmd.strip('()'), ppid, min(time, stime))
|
|
processMap[pid] = process
|
|
|
|
if process.last_user_cpu_time is not None and process.last_sys_cpu_time is not None and ltime is not None:
|
|
userCpuLoad, sysCpuLoad = process.calc_load(userCpu, sysCpu, max(1, time - ltime))
|
|
cpuSample = CPUSample('null', userCpuLoad, sysCpuLoad, 0.0)
|
|
process.samples.append(ProcessSample(time, state, cpuSample))
|
|
|
|
process.last_user_cpu_time = userCpu
|
|
process.last_sys_cpu_time = sysCpu
|
|
ltime = time
|
|
|
|
if len (timed_blocks) < 2:
|
|
return None
|
|
|
|
startTime = timed_blocks[0][0]
|
|
avgSampleLength = (ltime - startTime)/(len (timed_blocks) - 1)
|
|
|
|
return ProcessStats (writer, processMap, len (timed_blocks), avgSampleLength, startTime, ltime)
|
|
|
|
def _parse_taskstats_log(writer, file):
|
|
"""
|
|
* See bootchart-collector.c for details.
|
|
*
|
|
* { pid, ppid, comm, cpu_run_real_total, blkio_delay_total, swapin_delay_total }
|
|
*
|
|
"""
|
|
processMap = {}
|
|
pidRewrites = {}
|
|
ltime = None
|
|
timed_blocks = _parse_timed_blocks(file)
|
|
for time, lines in timed_blocks:
|
|
# we have no 'stime' from taskstats, so prep 'init'
|
|
if ltime is None:
|
|
process = Process(writer, 1, '[init]', 0, 0)
|
|
processMap[1000] = process
|
|
ltime = time
|
|
# continue
|
|
for line in lines:
|
|
if not line: continue
|
|
tokens = line.split(' ')
|
|
if len(tokens) != 6:
|
|
continue
|
|
|
|
opid, ppid, cmd = int(tokens[0]), int(tokens[1]), tokens[2]
|
|
cpu_ns, blkio_delay_ns, swapin_delay_ns = long(tokens[-3]), long(tokens[-2]), long(tokens[-1]),
|
|
|
|
# make space for trees of pids
|
|
opid *= 1000
|
|
ppid *= 1000
|
|
|
|
# when the process name changes, we re-write the pid.
|
|
if opid in pidRewrites:
|
|
pid = pidRewrites[opid]
|
|
else:
|
|
pid = opid
|
|
|
|
cmd = cmd.strip('(').strip(')')
|
|
if pid in processMap:
|
|
process = processMap[pid]
|
|
if process.cmd != cmd:
|
|
pid += 1
|
|
pidRewrites[opid] = pid
|
|
# print "process mutation ! '%s' vs '%s' pid %s -> pid %s\n" % (process.cmd, cmd, opid, pid)
|
|
process = process.split (writer, pid, cmd, ppid, time)
|
|
processMap[pid] = process
|
|
else:
|
|
process.cmd = cmd;
|
|
else:
|
|
process = Process(writer, pid, cmd, ppid, time)
|
|
processMap[pid] = process
|
|
|
|
delta_cpu_ns = (float) (cpu_ns - process.last_cpu_ns)
|
|
delta_blkio_delay_ns = (float) (blkio_delay_ns - process.last_blkio_delay_ns)
|
|
delta_swapin_delay_ns = (float) (swapin_delay_ns - process.last_swapin_delay_ns)
|
|
|
|
# make up some state data ...
|
|
if delta_cpu_ns > 0:
|
|
state = "R"
|
|
elif delta_blkio_delay_ns + delta_swapin_delay_ns > 0:
|
|
state = "D"
|
|
else:
|
|
state = "S"
|
|
|
|
# retain the ns timing information into a CPUSample - that tries
|
|
# with the old-style to be a %age of CPU used in this time-slice.
|
|
if delta_cpu_ns + delta_blkio_delay_ns + delta_swapin_delay_ns > 0:
|
|
# print "proc %s cpu_ns %g delta_cpu %g" % (cmd, cpu_ns, delta_cpu_ns)
|
|
cpuSample = CPUSample('null', delta_cpu_ns, 0.0,
|
|
delta_blkio_delay_ns,
|
|
delta_swapin_delay_ns)
|
|
process.samples.append(ProcessSample(time, state, cpuSample))
|
|
|
|
process.last_cpu_ns = cpu_ns
|
|
process.last_blkio_delay_ns = blkio_delay_ns
|
|
process.last_swapin_delay_ns = swapin_delay_ns
|
|
ltime = time
|
|
|
|
if len (timed_blocks) < 2:
|
|
return None
|
|
|
|
startTime = timed_blocks[0][0]
|
|
avgSampleLength = (ltime - startTime)/(len(timed_blocks)-1)
|
|
|
|
return ProcessStats (writer, processMap, len (timed_blocks), avgSampleLength, startTime, ltime)
|
|
|
|
def _parse_proc_stat_log(file):
|
|
samples = []
|
|
ltimes = None
|
|
for time, lines in _parse_timed_blocks(file):
|
|
# skip emtpy lines
|
|
if not lines:
|
|
continue
|
|
# CPU times {user, nice, system, idle, io_wait, irq, softirq}
|
|
tokens = lines[0].split()
|
|
times = [ int(token) for token in tokens[1:] ]
|
|
if ltimes:
|
|
user = float((times[0] + times[1]) - (ltimes[0] + ltimes[1]))
|
|
system = float((times[2] + times[5] + times[6]) - (ltimes[2] + ltimes[5] + ltimes[6]))
|
|
idle = float(times[3] - ltimes[3])
|
|
iowait = float(times[4] - ltimes[4])
|
|
|
|
aSum = max(user + system + idle + iowait, 1)
|
|
samples.append( CPUSample(time, user/aSum, system/aSum, iowait/aSum) )
|
|
|
|
ltimes = times
|
|
# skip the rest of statistics lines
|
|
return samples
|
|
|
|
def _parse_reduced_log(file, sample_class):
|
|
samples = []
|
|
for time, lines in _parse_timed_blocks(file):
|
|
samples.append(sample_class(time, *[float(x) for x in lines[0].split()]))
|
|
return samples
|
|
|
|
def _parse_proc_disk_stat_log(file):
|
|
"""
|
|
Parse file for disk stats, but only look at the whole device, eg. sda,
|
|
not sda1, sda2 etc. The format of relevant lines should be:
|
|
{major minor name rio rmerge rsect ruse wio wmerge wsect wuse running use aveq}
|
|
"""
|
|
disk_regex_re = re.compile (r'^([hsv]d.|mtdblock\d|mmcblk\d|cciss/c\d+d\d+.*)$')
|
|
|
|
# this gets called an awful lot.
|
|
def is_relevant_line(linetokens):
|
|
if len(linetokens) != 14:
|
|
return False
|
|
disk = linetokens[2]
|
|
return disk_regex_re.match(disk)
|
|
|
|
disk_stat_samples = []
|
|
|
|
for time, lines in _parse_timed_blocks(file):
|
|
sample = DiskStatSample(time)
|
|
relevant_tokens = [linetokens for linetokens in map (lambda x: x.split(),lines) if is_relevant_line(linetokens)]
|
|
|
|
for tokens in relevant_tokens:
|
|
disk, rsect, wsect, use = tokens[2], int(tokens[5]), int(tokens[9]), int(tokens[12])
|
|
sample.add_diskdata([rsect, wsect, use])
|
|
|
|
disk_stat_samples.append(sample)
|
|
|
|
disk_stats = []
|
|
for sample1, sample2 in zip(disk_stat_samples[:-1], disk_stat_samples[1:]):
|
|
interval = sample1.time - sample2.time
|
|
if interval == 0:
|
|
interval = 1
|
|
sums = [ a - b for a, b in zip(sample1.diskdata, sample2.diskdata) ]
|
|
readTput = sums[0] / 2.0 * 100.0 / interval
|
|
writeTput = sums[1] / 2.0 * 100.0 / interval
|
|
util = float( sums[2] ) / 10 / interval
|
|
util = max(0.0, min(1.0, util))
|
|
disk_stats.append(DiskSample(sample2.time, readTput, writeTput, util))
|
|
|
|
return disk_stats
|
|
|
|
def _parse_reduced_proc_meminfo_log(file):
|
|
"""
|
|
Parse file for global memory statistics with
|
|
'MemTotal', 'MemFree', 'Buffers', 'Cached', 'SwapTotal', 'SwapFree' values
|
|
(in that order) directly stored on one line.
|
|
"""
|
|
used_values = ('MemTotal', 'MemFree', 'Buffers', 'Cached', 'SwapTotal', 'SwapFree',)
|
|
|
|
mem_stats = []
|
|
for time, lines in _parse_timed_blocks(file):
|
|
sample = MemSample(time)
|
|
for name, value in zip(used_values, lines[0].split()):
|
|
sample.add_value(name, int(value))
|
|
|
|
if sample.valid():
|
|
mem_stats.append(DrawMemSample(sample))
|
|
|
|
return mem_stats
|
|
|
|
def _parse_proc_meminfo_log(file):
|
|
"""
|
|
Parse file for global memory statistics.
|
|
The format of relevant lines should be: ^key: value( unit)?
|
|
"""
|
|
used_values = ('MemTotal', 'MemFree', 'Buffers', 'Cached', 'SwapTotal', 'SwapFree',)
|
|
|
|
mem_stats = []
|
|
meminfo_re = re.compile(r'([^ \t:]+):\s*(\d+).*')
|
|
|
|
for time, lines in _parse_timed_blocks(file):
|
|
sample = MemSample(time)
|
|
|
|
for line in lines:
|
|
match = meminfo_re.match(line)
|
|
if not match:
|
|
raise ParseError("Invalid meminfo line \"%s\"" % line)
|
|
sample.add_value(match.group(1), int(match.group(2)))
|
|
|
|
if sample.valid():
|
|
mem_stats.append(DrawMemSample(sample))
|
|
|
|
return mem_stats
|
|
|
|
def _parse_monitor_disk_log(file):
|
|
"""
|
|
Parse file with information about amount of diskspace used.
|
|
The format of relevant lines should be: ^volume path: number-of-bytes?
|
|
"""
|
|
disk_stats = []
|
|
diskinfo_re = re.compile(r'^(.+):\s*(\d+)$')
|
|
|
|
for time, lines in _parse_timed_blocks(file):
|
|
sample = DiskSpaceSample(time)
|
|
|
|
for line in lines:
|
|
match = diskinfo_re.match(line)
|
|
if not match:
|
|
raise ParseError("Invalid monitor_disk line \"%s\"" % line)
|
|
sample.add_value(match.group(1), int(match.group(2)))
|
|
|
|
if sample.valid():
|
|
disk_stats.append(sample)
|
|
|
|
return disk_stats
|
|
|
|
|
|
def _parse_reduced_net_log(file):
|
|
net_stats = {}
|
|
for time, lines in _parse_timed_blocks(file):
|
|
|
|
for line in lines:
|
|
parts = line.split()
|
|
iface = parts[0][:-1]
|
|
if iface not in net_stats:
|
|
net_stats[iface] = [NetSample(time, iface, int(parts[1]), int(parts[2]), int(parts[3]), int(parts[4]))]
|
|
else:
|
|
net_stats[iface].append(NetSample(time, iface, int(parts[1]), int(parts[2]), int(parts[3]), int(parts[4])))
|
|
return net_stats
|
|
|
|
|
|
def _parse_pressure_logs(file, filename):
|
|
"""
|
|
Parse file for "some" pressure with 'avg10', 'avg60' 'avg300' and delta total values
|
|
(in that order) directly stored on one line for both CPU and IO, based on filename.
|
|
"""
|
|
pressure_stats = []
|
|
if filename == "cpu.log":
|
|
SamplingClass = CPUPressureSample
|
|
elif filename == "memory.log":
|
|
SamplingClass = MemPressureSample
|
|
else:
|
|
SamplingClass = IOPressureSample
|
|
for time, lines in _parse_timed_blocks(file):
|
|
for line in lines:
|
|
if not line: continue
|
|
tokens = line.split()
|
|
avg10 = float(tokens[0])
|
|
avg60 = float(tokens[1])
|
|
avg300 = float(tokens[2])
|
|
delta = float(tokens[3])
|
|
pressure_stats.append(SamplingClass(time, avg10, avg60, avg300, delta))
|
|
|
|
return pressure_stats
|
|
|
|
# if we boot the kernel with: initcall_debug printk.time=1 we can
|
|
# get all manner of interesting data from the dmesg output
|
|
# We turn this into a pseudo-process tree: each event is
|
|
# characterised by a
|
|
# we don't try to detect a "kernel finished" state - since the kernel
|
|
# continues to do interesting things after init is called.
|
|
#
|
|
# sample input:
|
|
# [ 0.000000] ACPI: FACP 3f4fc000 000F4 (v04 INTEL Napa 00000001 MSFT 01000013)
|
|
# ...
|
|
# [ 0.039993] calling migration_init+0x0/0x6b @ 1
|
|
# [ 0.039993] initcall migration_init+0x0/0x6b returned 1 after 0 usecs
|
|
def _parse_dmesg(writer, file):
|
|
timestamp_re = re.compile (r"^\[\s*(\d+\.\d+)\s*]\s+(.*)$")
|
|
split_re = re.compile (r"^(\S+)\s+([\S\+_-]+) (.*)$")
|
|
processMap = {}
|
|
idx = 0
|
|
inc = 1.0 / 1000000
|
|
kernel = Process(writer, idx, "k-boot", 0, 0.1)
|
|
processMap['k-boot'] = kernel
|
|
base_ts = False
|
|
max_ts = 0
|
|
for line in file.read().split('\n'):
|
|
t = timestamp_re.match (line)
|
|
if t is None:
|
|
# print "duff timestamp " + line
|
|
continue
|
|
|
|
time_ms = float (t.group(1)) * 1000
|
|
# looks like we may have a huge diff after the clock
|
|
# has been set up. This could lead to huge graph:
|
|
# so huge we will be killed by the OOM.
|
|
# So instead of using the plain timestamp we will
|
|
# use a delta to first one and skip the first one
|
|
# for convenience
|
|
if max_ts == 0 and not base_ts and time_ms > 1000:
|
|
base_ts = time_ms
|
|
continue
|
|
max_ts = max(time_ms, max_ts)
|
|
if base_ts:
|
|
# print "fscked clock: used %f instead of %f" % (time_ms - base_ts, time_ms)
|
|
time_ms -= base_ts
|
|
m = split_re.match (t.group(2))
|
|
|
|
if m is None:
|
|
continue
|
|
# print "match: '%s'" % (m.group(1))
|
|
type = m.group(1)
|
|
func = m.group(2)
|
|
rest = m.group(3)
|
|
|
|
if t.group(2).startswith ('Write protecting the') or \
|
|
t.group(2).startswith ('Freeing unused kernel memory'):
|
|
kernel.duration = time_ms / 10
|
|
continue
|
|
|
|
# print "foo: '%s' '%s' '%s'" % (type, func, rest)
|
|
if type == "calling":
|
|
ppid = kernel.pid
|
|
p = re.match (r"\@ (\d+)", rest)
|
|
if p is not None:
|
|
ppid = float (p.group(1)) // 1000
|
|
# print "match: '%s' ('%g') at '%s'" % (func, ppid, time_ms)
|
|
name = func.split ('+', 1) [0]
|
|
idx += inc
|
|
processMap[func] = Process(writer, ppid + idx, name, ppid, time_ms / 10)
|
|
elif type == "initcall":
|
|
# print "finished: '%s' at '%s'" % (func, time_ms)
|
|
if func in processMap:
|
|
process = processMap[func]
|
|
process.duration = (time_ms / 10) - process.start_time
|
|
else:
|
|
print("corrupted init call for %s" % (func))
|
|
|
|
elif type == "async_waiting" or type == "async_continuing":
|
|
continue # ignore
|
|
|
|
return processMap.values()
|
|
|
|
#
|
|
# Parse binary pacct accounting file output if we have one
|
|
# cf. /usr/include/linux/acct.h
|
|
#
|
|
def _parse_pacct(writer, file):
|
|
# read LE int32
|
|
def _read_le_int32(file):
|
|
byts = file.read(4)
|
|
return (ord(byts[0])) | (ord(byts[1]) << 8) | \
|
|
(ord(byts[2]) << 16) | (ord(byts[3]) << 24)
|
|
|
|
parent_map = {}
|
|
parent_map[0] = 0
|
|
while file.read(1) != "": # ignore flags
|
|
ver = file.read(1)
|
|
if ord(ver) < 3:
|
|
print("Invalid version 0x%x" % (ord(ver)))
|
|
return None
|
|
|
|
file.seek (14, 1) # user, group etc.
|
|
pid = _read_le_int32 (file)
|
|
ppid = _read_le_int32 (file)
|
|
# print "Parent of %d is %d" % (pid, ppid)
|
|
parent_map[pid] = ppid
|
|
file.seek (4 + 4 + 16, 1) # timings
|
|
file.seek (16, 1) # acct_comm
|
|
return parent_map
|
|
|
|
def _parse_paternity_log(writer, file):
|
|
parent_map = {}
|
|
parent_map[0] = 0
|
|
for line in file.read().split('\n'):
|
|
if not line:
|
|
continue
|
|
elems = line.split(' ') # <Child> <Parent>
|
|
if len (elems) >= 2:
|
|
# print "paternity of %d is %d" % (int(elems[0]), int(elems[1]))
|
|
parent_map[int(elems[0])] = int(elems[1])
|
|
else:
|
|
print("Odd paternity line '%s'" % (line))
|
|
return parent_map
|
|
|
|
def _parse_cmdline_log(writer, file):
|
|
cmdLines = {}
|
|
for block in file.read().split('\n\n'):
|
|
lines = block.split('\n')
|
|
if len (lines) >= 3:
|
|
# print "Lines '%s'" % (lines[0])
|
|
pid = int (lines[0])
|
|
values = {}
|
|
values['exe'] = lines[1].lstrip(':')
|
|
args = lines[2].lstrip(':').split('\0')
|
|
args.pop()
|
|
values['args'] = args
|
|
cmdLines[pid] = values
|
|
return cmdLines
|
|
|
|
def _parse_bitbake_buildstats(writer, state, filename, file):
|
|
paths = filename.split("/")
|
|
task = paths[-1]
|
|
pn = paths[-2]
|
|
start = None
|
|
end = None
|
|
for line in file:
|
|
if line.startswith("Started:"):
|
|
start = int(float(line.split()[-1]))
|
|
elif line.startswith("Ended:"):
|
|
end = int(float(line.split()[-1]))
|
|
if start and end:
|
|
state.add_process(pn + ":" + task, start, end)
|
|
|
|
def get_num_cpus(headers):
|
|
"""Get the number of CPUs from the system.cpu header property. As the
|
|
CPU utilization graphs are relative, the number of CPUs currently makes
|
|
no difference."""
|
|
if headers is None:
|
|
return 1
|
|
if headers.get("system.cpu.num"):
|
|
return max (int (headers.get("system.cpu.num")), 1)
|
|
cpu_model = headers.get("system.cpu")
|
|
if cpu_model is None:
|
|
return 1
|
|
mat = re.match(r".*\\((\\d+)\\)", cpu_model)
|
|
if mat is None:
|
|
return 1
|
|
return max (int(mat.group(1)), 1)
|
|
|
|
def _do_parse(writer, state, filename, file):
|
|
writer.info("parsing '%s'" % filename)
|
|
t1 = time.process_time()
|
|
name = os.path.basename(filename)
|
|
if name == "proc_diskstats.log":
|
|
state.disk_stats = _parse_proc_disk_stat_log(file)
|
|
elif name == "reduced_proc_diskstats.log":
|
|
state.disk_stats = _parse_reduced_log(file, DiskSample)
|
|
elif name == "proc_stat.log":
|
|
state.cpu_stats = _parse_proc_stat_log(file)
|
|
elif name == "reduced_proc_stat.log":
|
|
state.cpu_stats = _parse_reduced_log(file, CPUSample)
|
|
elif name == "proc_meminfo.log":
|
|
state.mem_stats = _parse_proc_meminfo_log(file)
|
|
elif name == "reduced_proc_meminfo.log":
|
|
state.mem_stats = _parse_reduced_proc_meminfo_log(file)
|
|
elif name == "cmdline2.log":
|
|
state.cmdline = _parse_cmdline_log(writer, file)
|
|
elif name == "monitor_disk.log":
|
|
state.monitor_disk = _parse_monitor_disk_log(file)
|
|
elif name == "reduced_proc_net.log":
|
|
state.net_stats = _parse_reduced_net_log(file)
|
|
#pressure logs are in a subdirectory
|
|
elif name == "cpu.log":
|
|
state.cpu_pressure = _parse_pressure_logs(file, name)
|
|
elif name == "io.log":
|
|
state.io_pressure = _parse_pressure_logs(file, name)
|
|
elif name == "memory.log":
|
|
state.mem_pressure = _parse_pressure_logs(file, name)
|
|
elif not filename.endswith('.log'):
|
|
_parse_bitbake_buildstats(writer, state, filename, file)
|
|
t2 = time.process_time()
|
|
writer.info(" %s seconds" % str(t2-t1))
|
|
return state
|
|
|
|
def parse_file(writer, state, filename):
|
|
if state.filename is None:
|
|
state.filename = filename
|
|
basename = os.path.basename(filename)
|
|
with open(filename, "r") as file:
|
|
return _do_parse(writer, state, filename, file)
|
|
|
|
def parse_paths(writer, state, paths):
|
|
for path in paths:
|
|
if state.filename is None:
|
|
state.filename = path
|
|
root, extension = os.path.splitext(path)
|
|
if not(os.path.exists(path)):
|
|
writer.warn("warning: path '%s' does not exist, ignoring." % path)
|
|
continue
|
|
#state.filename = path
|
|
if os.path.isdir(path):
|
|
files = sorted([os.path.join(path, f) for f in os.listdir(path)])
|
|
state = parse_paths(writer, state, files)
|
|
elif extension in [".tar", ".tgz", ".gz"]:
|
|
if extension == ".gz":
|
|
root, extension = os.path.splitext(root)
|
|
if extension != ".tar":
|
|
writer.warn("warning: can only handle zipped tar files, not zipped '%s'-files; ignoring" % extension)
|
|
continue
|
|
tf = None
|
|
try:
|
|
writer.status("parsing '%s'" % path)
|
|
tf = tarfile.open(path, 'r:*')
|
|
for name in tf.getnames():
|
|
state = _do_parse(writer, state, name, tf.extractfile(name))
|
|
except tarfile.ReadError as error:
|
|
raise ParseError("error: could not read tarfile '%s': %s." % (path, error))
|
|
finally:
|
|
if tf != None:
|
|
tf.close()
|
|
else:
|
|
state = parse_file(writer, state, path)
|
|
return state
|
|
|
|
def split_res(res, options):
|
|
""" Split the res into n pieces """
|
|
res_list = []
|
|
if options.num > 1:
|
|
s_list = sorted(res.start.keys())
|
|
frag_size = len(s_list) / float(options.num)
|
|
# Need the top value
|
|
if frag_size > int(frag_size):
|
|
frag_size = int(frag_size + 1)
|
|
else:
|
|
frag_size = int(frag_size)
|
|
|
|
start = 0
|
|
end = frag_size
|
|
while start < end:
|
|
state = Trace(None, [], None)
|
|
if options.full_time:
|
|
state.min = min(res.start.keys())
|
|
state.max = max(res.end.keys())
|
|
for i in range(start, end):
|
|
# Add this line for reference
|
|
#state.add_process(pn + ":" + task, start, end)
|
|
for p in res.start[s_list[i]]:
|
|
state.add_process(p, s_list[i], res.processes[p][1])
|
|
start = end
|
|
end = end + frag_size
|
|
if end > len(s_list):
|
|
end = len(s_list)
|
|
res_list.append(state)
|
|
else:
|
|
res_list.append(res)
|
|
return res_list
|