Skip to contentSkip to conversation

system statistics sampling

PATCH New Patrick Ohly 1 participant 12 messages Nov 30, 2016

lore
Share & tools
lore
#0 lore raw

v2 cover system statistics sampling

buildstats.bbclass gets extended so that disk bandwidth and capacity, CPU and memory usage get sampled at regular time intervals by default. pybootchart had code for most of that data, which gets restored and re-enabled. The disk capacity graph is new.

The original pybootchart just stored raw dumps of the special files under /proc. bitbake builds run longer, so a more compact ("reduced") format is used.

Logging disk capacity was mostly motivated by some work on enhancing rm_work.bbclass behavior, but could also be useful for others ("how much free space did my build need").

Changes in V2:
- SystemStats instance survives between event handler calls by storing it in the corresponding datastore, instead of using a global variable, and open files get closed properly when the build ends. This should work better with memres bitbake (not tested, though, because of YOCTO #10741).
- Sampling now already starts when setscene tasks start to run.

The following changes since commit 9f1fe76727e98e58fc9e46ea2b49cf5c0cb48e6c:

libpcap: Fix build when PACKAGECONFIG ipv6 is not enable (2016-11-23 11:02:33 +0000)

are available in the git repository at:

git://github.com/pohly/openembedded-core buildstats
https://github.com/pohly/openembedded-core/tree/buildstats

Patrick Ohly (11):
buildstats: add system state sampling pybootchartgui/draw.py: allow moving process chart up and down pybootchartgui/draw.py: fix drawing of samples not starting at zero
pybootchartgui: show system utilization pybootchartgui/draw.py: skip empty CPU and disk usage charts
buildstats: record disk space usage pybootchartgui/parsing.py: fix error handling in meminfo parser
pybootchartgui: render disk space usage
pybootchartgui: simplify drawing of memory usage
buildstats: reduce amount of data stored for system utilization
pybootchartgui: support reading reduced /proc logs

 meta/classes/buildstats.bbclass                  |  24 +++
 meta/lib/buildstats.py                           | 153 ++++++++++++++++++
 scripts/pybootchartgui/pybootchartgui/draw.py    | 192 ++++++++++++++++-------
 scripts/pybootchartgui/pybootchartgui/parsing.py | 122 +++++++++++---
 scripts/pybootchartgui/pybootchartgui/samples.py |  27 ++++
 5 files changed, 440 insertions(+), 78 deletions(-)
 create mode 100644 meta/lib/buildstats.py
Signature · 1 line
2.1.4
#1 lore raw

PATCH v2 1/11 buildstats: add system state sampling

/proc/[diskstats|meminfo|stat] get sampled and written to the same proc_<filename>.log files as during normal bootchat logging. This will allow rendering the CPU, disk and memory usage charts.

Right now sampling happens once a second, triggered by the heartbeat event.That produces quite a bit of data for long builds, which will be addressed in a separate commit by storing the data in a more compact form.

---
 meta/classes/buildstats.bbclass | 24 +++++++++++++++++++++
 meta/lib/buildstats.py          | 47 +++++++++++++++++++++++++++++++++++++++++
 2 files changed, 71 insertions(+)
 create mode 100644 meta/lib/buildstats.py
meta/classes/buildstats.bbclass +24 -0
index 57ecc8f..9c0c37d 100644
@@ -188,3 +188,27 @@ python run_buildstats () {
 addhandler run_buildstats
 run_buildstats[eventmask] = "bb.event.BuildStarted bb.event.BuildCompleted bb.build.TaskStarted bb.build.TaskSucceeded bb.build.TaskFailed"
 
+python runqueue_stats () {
+    import buildstats
+    from bb import event, runqueue
+    # We should not record any samples before the first task has started,
+    # because that's the first activity shown in the process chart.
+    # Besides, at that point we are sure that the build variables
+    # are available that we need to find the output directory.
+    # The persistent SystemStats is stored in the datastore and
+    # closed when the build is done.
+    system_stats = d.getVar('_buildstats_system_stats', True)
+    if not system_stats and isinstance(e, (bb.runqueue.sceneQueueTaskStarted, bb.runqueue.runQueueTaskStarted)):
+        system_stats = buildstats.SystemStats(d)
+        d.setVar('_buildstats_system_stats', system_stats)
+    if system_stats:
+        # Ensure that we sample at important events.
+        done = isinstance(e, bb.event.BuildCompleted)
+        system_stats.sample(force=done)
+        if done:
+            system_stats.close()
+            d.delVar('_buildstats_system_stats')
+}
+
+addhandler runqueue_stats
+runqueue_stats[eventmask] = "bb.runqueue.sceneQueueTaskStarted bb.runqueue.runQueueTaskStarted bb.event.HeartbeatEvent bb.event.BuildCompleted"
meta/lib/buildstats.py new file +47 -0

47 lines not on this page · raw message

Signature · 1 line
2.1.4
#2 lore raw

PATCH v2 2/11 pybootchartgui/draw.py: allow moving process chart up and down

In reply to Patrick Ohly

Substracting curr_y when determining the hight of the process chart is wrong because the height is independent of the position where the chart is about to be drawn. It happens to work at the moment because curr_y is always 10 when render_processes_chart() gets called. But it leads to a negative height when other charts are drawn above it, and then the grid gets drawn on top of those other charts.

Substracting some constant is relevant because otherwise the box is slightly larger than the process bars. Not sure exactly where that comes from (text height?); leg_s seems a suitable constant and happens to be 10, so everything still gets rendered exactly as before.

---
 scripts/pybootchartgui/pybootchartgui/draw.py | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)
scripts/pybootchartgui/pybootchartgui/draw.py +1 -1
index 8c574be..2b5907b 100644
@@ -415,7 +415,7 @@ def render_charts(ctx, options, clip, trace, curr_y, w, h, sec_w):
 	return curr_y
 
 def render_processes_chart(ctx, options, trace, curr_y, w, h, sec_w):
-        chart_rect = [off_x, curr_y+header_h, w, h - 2 * off_y - (curr_y+header_h) + proc_h]
+        chart_rect = [off_x, curr_y+header_h, w, h - 2 * off_y - header_h - leg_s + proc_h]
 
 	draw_legend_box (ctx, "Configure", \
 			 TASK_COLOR_CONFIGURE, off_x  , curr_y + 45, leg_s)
Signature · 1 line
2.1.4
#3 lore raw

PATCH v2 3/11 pybootchartgui/draw.py: fix drawing of samples not starting at zero

In reply to Patrick Ohly

The code did not handle x scaling correctly when drawing starts at some time larger than zero, i.e. it worked for normal bootchart data, but not for the system statistics recorded by buildstats.bbclass.

---
 scripts/pybootchartgui/pybootchartgui/draw.py | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)
scripts/pybootchartgui/pybootchartgui/draw.py +1 -1
index 2b5907b..925002d 100644
@@ -256,7 +256,7 @@ def draw_chart(ctx, color, fill, chart_bounds, data, proc_tree, data_range):
 	# avoid divide by zero
 	if max_y == 0:
 		max_y = 1.0
-	xscale = float (chart_bounds[2]) / max_x
+	xscale = float (chart_bounds[2]) / (max_x - x_shift)
 	# If data_range is given, scale the chart so that the value range in
 	# data_range matches the chart bounds exactly.
 	# Otherwise, scale so that the actual data matches the chart bounds.
Signature · 1 line
2.1.4
#4 lore raw

PATCH v2 4/11 pybootchartgui: show system utilization

In reply to Patrick Ohly

This enables rendering of the original bootchart charts for CPU, disk and memory usage. It depends on the /proc samples recorded by the updated buildstats.bbclass. Currently, empty charts CPU and disk usage charts are drawn if that data is not present; the memory chart already gets skipped when there's no data, which will also have to be added for the other two.

---
 scripts/pybootchartgui/pybootchartgui/draw.py    | 16 +++++--
 scripts/pybootchartgui/pybootchartgui/parsing.py | 61 +++++++++++++++++-------
 2 files changed, 57 insertions(+), 20 deletions(-)
scripts/pybootchartgui/pybootchartgui/draw.py +13 -3
index 925002d..bddd804 100644
@@ -321,6 +321,16 @@ def extents(options, xscale, trace):
 	w = int ((end - start) * sec_w_base * xscale) + 2 * off_x
 	h = proc_h * processes + header_h + 2 * off_y
 
+	if options.charts:
+		if trace.cpu_stats:
+			h += 30 + bar_h
+		if trace.disk_stats:
+			h += 30 + bar_h
+		if trace.monitor_disk:
+			h += 30 + bar_h
+		if trace.mem_stats:
+			h += meminfo_bar_h
+
 	return (w, h)
 
 def clip_visible(clip, rect):
@@ -496,6 +506,9 @@ def render(ctx, options, xscale, trace):
 	w -= 2*off_x
 	curr_y = off_y;
 
+	if options.charts:
+		curr_y = render_charts (ctx, options, clip, trace, curr_y, w, h, sec_w)
+
 	curr_y = render_processes_chart (ctx, options, trace, curr_y, w, h, sec_w)
 
 	return
@@ -513,9 +526,6 @@ def render(ctx, options, xscale, trace):
 	else:
 		curr_y = off_y;
 
-	if options.charts:
-		curr_y = render_charts (ctx, options, clip, trace, curr_y, w, h, sec_w)
-
 	# draw process boxes
 	proc_height = h
 	if proc_tree.taskstats and options.cumulative:
scripts/pybootchartgui/pybootchartgui/parsing.py +44 -17

104 lines not on this page · raw message

Signature · 1 line
2.1.4
#5 lore raw

PATCH v2 5/11 pybootchartgui/draw.py: skip empty CPU and disk usage charts

In reply to Patrick Ohly

The only real change is the addition of two if checks that skips the corresponding drawing code when there is no data.

---
 scripts/pybootchartgui/pybootchartgui/draw.py | 98 ++++++++++++++-------------
 1 file changed, 50 insertions(+), 48 deletions(-)
scripts/pybootchartgui/pybootchartgui/draw.py +50 -48
index bddd804..ec5dd33 100644
@@ -344,56 +344,58 @@ def render_charts(ctx, options, clip, trace, curr_y, w, h, sec_w):
 	proc_tree = options.proc_tree(trace)
 
 	# render bar legend
-	ctx.set_font_size(LEGEND_FONT_SIZE)
-
-	draw_legend_box(ctx, "CPU (user+sys)", CPU_COLOR, off_x, curr_y+20, leg_s)
-	draw_legend_box(ctx, "I/O (wait)", IO_COLOR, off_x + 120, curr_y+20, leg_s)
-
-	# render I/O wait
-	chart_rect = (off_x, curr_y+30, w, bar_h)
-	if clip_visible (clip, chart_rect):
-		draw_box_ticks (ctx, chart_rect, sec_w)
-		draw_annotations (ctx, proc_tree, trace.times, chart_rect)
-		draw_chart (ctx, IO_COLOR, True, chart_rect, \
-			    [(sample.time, sample.user + sample.sys + sample.io) for sample in trace.cpu_stats], \
-			    proc_tree, None)
-		# render CPU load
-		draw_chart (ctx, CPU_COLOR, True, chart_rect, \
-			    [(sample.time, sample.user + sample.sys) for sample in trace.cpu_stats], \
-			    proc_tree, None)
-
-	curr_y = curr_y + 30 + bar_h
+	if trace.cpu_stats:
+		ctx.set_font_size(LEGEND_FONT_SIZE)
+
+		draw_legend_box(ctx, "CPU (user+sys)", CPU_COLOR, off_x, curr_y+20, leg_s)
+		draw_legend_box(ctx, "I/O (wait)", IO_COLOR, off_x + 120, curr_y+20, leg_s)
+
+		# render I/O wait
+		chart_rect = (off_x, curr_y+30, w, bar_h)
+		if clip_visible (clip, chart_rect):
+			draw_box_ticks (ctx, chart_rect, sec_w)
+			draw_annotations (ctx, proc_tree, trace.times, chart_rect)
+			draw_chart (ctx, IO_COLOR, True, chart_rect, \
+				    [(sample.time, sample.user + sample.sys + sample.io) for sample in trace.cpu_stats], \
+				    proc_tree, None)
+			# render CPU load
+			draw_chart (ctx, CPU_COLOR, True, chart_rect, \
+				    [(sample.time, sample.user + sample.sys) for sample in trace.cpu_stats], \
+				    proc_tree, None)
+
+		curr_y = curr_y + 30 + bar_h
 
 	# render second chart
-	draw_legend_line(ctx, "Disk throughput", DISK_TPUT_COLOR, off_x, curr_y+20, leg_s)
-	draw_legend_box(ctx, "Disk utilization", IO_COLOR, off_x + 120, curr_y+20, leg_s)
-
-        # render I/O utilization
-	chart_rect = (off_x, curr_y+30, w, bar_h)
-	if clip_visible (clip, chart_rect):
-		draw_box_ticks (ctx, chart_rect, sec_w)
-		draw_annotations (ctx, proc_tree, trace.times, chart_rect)
-		draw_chart (ctx, IO_COLOR, True, chart_rect, \
-			    [(sample.time, sample.util) for sample in trace.disk_stats], \
-			    proc_tree, None)
-
-	# render disk throughput
-	max_sample = max (trace.disk_stats, key = lambda s: s.tput)
-	if clip_visible (clip, chart_rect):
-		draw_chart (ctx, DISK_TPUT_COLOR, False, chart_rect, \
-			    [(sample.time, sample.tput) for sample in trace.disk_stats], \
-			    proc_tree, None)
-
-	pos_x = off_x + ((max_sample.time - proc_tree.start_time) * w / proc_tree.duration)
-
-	shift_x, shift_y = -20, 20
-	if (pos_x < off_x + 245):
-		shift_x, shift_y = 5, 40
-
-	label = "%dMB/s" % round ((max_sample.tput) / 1024.0)
-	draw_text (ctx, label, DISK_TPUT_COLOR, pos_x + shift_x, curr_y + shift_y)
-
-	curr_y = curr_y + 30 + bar_h
+	if trace.disk_stats:
+		draw_legend_line(ctx, "Disk throughput", DISK_TPUT_COLOR, off_x, curr_y+20, leg_s)
+		draw_legend_box(ctx, "Disk utilization", IO_COLOR, off_x + 120, curr_y+20, leg_s)
+
+		# render I/O utilization
+		chart_rect = (off_x, curr_y+30, w, bar_h)
+		if clip_visible (clip, chart_rect):
+			draw_box_ticks (ctx, chart_rect, sec_w)
+			draw_annotations (ctx, proc_tree, trace.times, chart_rect)
+			draw_chart (ctx, IO_COLOR, True, chart_rect, \
+				    [(sample.time, sample.util) for sample in trace.disk_stats], \
+				    proc_tree, None)
+
+		# render disk throughput
+		max_sample = max (trace.disk_stats, key = lambda s: s.tput)
+		if clip_visible (clip, chart_rect):
+			draw_chart (ctx, DISK_TPUT_COLOR, False, chart_rect, \
+				    [(sample.time, sample.tput) for sample in trace.disk_stats], \
+				    proc_tree, None)
+
+		pos_x = off_x + ((max_sample.time - proc_tree.start_time) * w / proc_tree.duration)
+
+		shift_x, shift_y = -20, 20
+		if (pos_x < off_x + 245):
+			shift_x, shift_y = 5, 40
+
+		label = "%dMB/s" % round ((max_sample.tput) / 1024.0)
+		draw_text (ctx, label, DISK_TPUT_COLOR, pos_x + shift_x, curr_y + shift_y)
+
+		curr_y = curr_y + 30 + bar_h
 
 	# render mem usage
 	chart_rect = (off_x, curr_y+30, w, meminfo_bar_h)
Signature · 1 line
2.1.4
#6 lore raw

PATCH v2 6/11 buildstats: record disk space usage

In reply to Patrick Ohly

Hooks into the new monitordisk.py event and records the used space for each volume. That is probably the only relevant value when it comes to visualizing the build and recording more would only increase disk usage.

---
 meta/classes/buildstats.bbclass |  4 ++--
 meta/lib/buildstats.py          | 22 +++++++++++++++++-----
 2 files changed, 19 insertions(+), 7 deletions(-)
meta/classes/buildstats.bbclass +2 -2
index 9c0c37d..c6b77e6 100644
@@ -204,11 +204,11 @@ python runqueue_stats () {
     if system_stats:
         # Ensure that we sample at important events.
         done = isinstance(e, bb.event.BuildCompleted)
-        system_stats.sample(force=done)
+        system_stats.sample(e, force=done)
         if done:
             system_stats.close()
             d.delVar('_buildstats_system_stats')
 }
 
 addhandler runqueue_stats
-runqueue_stats[eventmask] = "bb.runqueue.sceneQueueTaskStarted bb.runqueue.runQueueTaskStarted bb.event.HeartbeatEvent bb.event.BuildCompleted"
+runqueue_stats[eventmask] = "bb.runqueue.sceneQueueTaskStarted bb.runqueue.runQueueTaskStarted bb.event.HeartbeatEvent bb.event.BuildCompleted bb.event.MonitorDiskEvent"
meta/lib/buildstats.py +17 -5
index 8ce4112..7c8b352 100644
@@ -3,6 +3,7 @@
 # like open log files and the time of the last sampling.
 
 import time
+import bb.event
 
 class SystemStats:
     def __init__(self, d):
@@ -19,8 +20,10 @@ class SystemStats:
             # concurrently.
             self.proc_files.append((filename,
                                     open(os.path.join(bsdir, 'proc_%s.log' % filename), 'ab')))
-        # Last time that we sampled data.
-        self.last = 0
+        self.monitor_disk = open(os.path.join(bsdir, 'monitor_disk.log'), 'ab')
+        # Last time that we sampled /proc data resp. recorded disk monitoring data.
+        self.last_proc = 0
+        self.last_disk_monitor = 0
         # Minimum number of seconds between recording a sample. This
         # becames relevant when we get called very often while many
         # short tasks get started. Sampling during quiet periods
@@ -32,9 +35,9 @@ class SystemStats:
         for _, output, _ in self.proc_files:
             output.close()
 
-    def sample(self, force):
+    def sample(self, event, force):
         now = time.time()
-        if (now - self.last > self.min_seconds) or force:
+        if (now - self.last_proc > self.min_seconds) or force:
             for filename, output in self.proc_files:
                 with open(os.path.join('/proc', filename), 'rb') as input:
                     data = input.read()
@@ -44,4 +47,13 @@ class SystemStats:
                              ('%.0f\n' % now).encode('ascii') +
                              data +
                              b'\n')
-            self.last = now
+            self.last_proc = now
+
+        if isinstance(event, bb.event.MonitorDiskEvent) and \
+           ((now - self.last_disk_monitor > self.min_seconds) or force):
+            os.write(self.monitor_disk.fileno(),
+                     ('%.0f\n' % now).encode('ascii') +
+                     ''.join(['%s: %d\n' % (dev, sample.total_bytes - sample.free_bytes)
+                              for dev, sample in event.disk_usage.items()]).encode('ascii') +
+                     b'\n')
+            self.last_disk_monitor = now
Signature · 1 line
2.1.4
#7 lore raw

PATCH v2 7/11 pybootchartgui/parsing.py: fix error handling in meminfo parser

In reply to Patrick Ohly

When matching fails, m.group(0) is invalid and can't be used in the error message.

---
 scripts/pybootchartgui/pybootchartgui/parsing.py | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)
scripts/pybootchartgui/pybootchartgui/parsing.py +1 -1
index af68435..48eb048 100644
@@ -498,7 +498,7 @@ def _parse_proc_meminfo_log(file):
         for line in lines:
             match = meminfo_re.match(line)
             if not match:
-                raise ParseError("Invalid meminfo line \"%s\"" % match.groups(0))
+                raise ParseError("Invalid meminfo line \"%s\"" % line)
             sample.add_value(match.group(1), int(match.group(2)))
 
         if sample.valid():
Signature · 1 line
2.1.4
#8 lore raw

PATCH v2 8/11 pybootchartgui: render disk space usage

In reply to Patrick Ohly

This adds a new, separate chart showing the amount of disk space used over time for each volume monitored during the build. The hight of the graph entries represents the delta between current usage and minimal usage during the build.

That's more useful than showing just the current usage, because then a graph showing changes in the order of MBs in a volume that is several GB large would be just flat.

The legend shows the maximum of those deltas, i.e. maximum amount of space needed for the build. Minor caveat: sampling of disk space usage starts a bit later than the initial task, so the displayed value may be slightly lower than the actual amount of space needed because sampling does not record the actual initial state.

---
 scripts/pybootchartgui/pybootchartgui/draw.py    | 62 ++++++++++++++++++++++++
 scripts/pybootchartgui/pybootchartgui/parsing.py | 26 ++++++++++
 scripts/pybootchartgui/pybootchartgui/samples.py | 11 +++++
 3 files changed, 99 insertions(+)
scripts/pybootchartgui/pybootchartgui/draw.py +62 -0
index ec5dd33..f0143ad 100644
@@ -133,6 +133,16 @@ TASK_COLOR_PACKAGE = (0.0, 1.00, 1.00, 1.0)
 # Package Write RPM/DEB/IPK task color
 TASK_COLOR_PACKAGE_WRITE = (0.0, 0.50, 0.50, 1.0)
 
+# Distinct colors used for different disk volumnes.
+# If we have more volumns, colors get re-used.
+VOLUME_COLORS = [
+	(1.0, 1.0, 0.00, 1.0),
+	(0.0, 1.00, 0.00, 1.0),
+	(1.0, 0.00, 1.00, 1.0),
+	(0.0, 0.00, 1.00, 1.0),
+	(0.0, 1.00, 1.00, 1.0),
+]
+
 # Process states
 STATE_UNDEFINED = 0
 STATE_RUNNING   = 1
@@ -397,6 +407,58 @@ def render_charts(ctx, options, clip, trace, curr_y, w, h, sec_w):
 
 		curr_y = curr_y + 30 + bar_h
 
+	# render disk space usage
+	#
+	# Draws the amount of disk space used on each volume relative to the
+	# lowest recorded amount. The graphs for each volume are stacked above
+	# each other so that total disk usage is visible.
+	if trace.monitor_disk:
+		ctx.set_font_size(LEGEND_FONT_SIZE)
+		# Determine set of volumes for which we have
+		# information and the minimal amount of used disk
+		# space for each. Currently samples are allowed to
+		# not have a values for all volumes; drawing could be
+		# made more efficient if that wasn't the case.
+		volumes = set()
+		min_used = {}
+		for sample in trace.monitor_disk:
+			for volume, used in sample.records.items():
+				volumes.add(volume)
+				if volume not in min_used or min_used[volume] > used:
+					min_used[volume] = used
+		volumes = sorted(list(volumes))
+		disk_scale = 0
+		for i, volume in enumerate(volumes):
+			volume_scale = max([sample.records[volume] - min_used[volume]
+			                    for sample in trace.monitor_disk
+			                    if volume in sample.records])
+			# Does not take length of volume name into account, but fixed offset
+			# works okay in practice.
+			draw_legend_box(ctx, '%s (max: %u MiB)' % (volume, volume_scale / 1024 / 1024),
+			                VOLUME_COLORS[i % len(VOLUME_COLORS)],
+			                off_x + i * 250, curr_y+20, leg_s)
+			disk_scale += volume_scale
+
+		# render used amount of disk space
+		chart_rect = (off_x, curr_y+30, w, bar_h)
+		if clip_visible (clip, chart_rect):
+			draw_box_ticks (ctx, chart_rect, sec_w)
+			draw_annotations (ctx, proc_tree, trace.times, chart_rect)
+			for i in range(len(volumes), 0, -1):
+				draw_chart (ctx, VOLUME_COLORS[(i - 1) % len(VOLUME_COLORS)], True, chart_rect, \
+				            [(sample.time,
+				              # Sum up used space of all volumes including the current one
+				              # so that the graphs appear as stacked on top of each other.
+				              reduce(lambda x,y: x+y,
+				                     [sample.records[volume] - min_used[volume]
+				                      for volume in volumes[0:i]
+				                      if volume in sample.records],
+				                     0))
+				             for sample in trace.monitor_disk], \
+				            proc_tree, [0, disk_scale])
+
+		curr_y = curr_y + 30 + bar_h
+
 	# render mem usage
 	chart_rect = (off_x, curr_y+30, w, meminfo_bar_h)
 	mem_stats = trace.mem_stats
scripts/pybootchartgui/pybootchartgui/parsing.py +26 -0
index 48eb048..301145a 100644
@@ -48,6 +48,7 @@ class Trace:
         self.filename = None
         self.parent_map = None
         self.mem_stats = []
+        self.monitor_disk = None
         self.times = [] # Always empty, but expected by draw.py when drawing system charts.
 
         if len(paths):
@@ -506,6 +507,29 @@ def _parse_proc_meminfo_log(file):
 
     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
+
+
 # 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
@@ -684,6 +708,8 @@ def _do_parse(writer, state, filename, file):
         state.mem_stats = _parse_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 not filename.endswith('.log'):
         _parse_bitbake_buildstats(writer, state, filename, file)
     t2 = clock()
scripts/pybootchartgui/pybootchartgui/samples.py +11 -0
index 015d743..bedca41 100644
@@ -53,6 +53,17 @@ class MemSample:
         # discard incomplete samples
         return [v for v in MemSample.used_values if v not in keys] == []
 
+class DiskSpaceSample:
+    def __init__(self, time):
+        self.time = time
+        self.records = {}
+
+    def add_value(self, name, value):
+        self.records[name] = value
+
+    def valid(self):
+        return bool(self.records)
+
 class ProcessSample:
     def __init__(self, time, state, cpu_sample):
         self.time = time
Signature · 1 line
2.1.4
#9 lore raw

PATCH v2 9/11 pybootchartgui: simplify drawing of memory usage

In reply to Patrick Ohly

The internal representation after parsing now matches exactly what the drawing code needs, thus speeding up drawing a bit. However, the main motivation is to store exactly that required information in a more compact file.

---
 scripts/pybootchartgui/pybootchartgui/draw.py    | 12 ++++++------
 scripts/pybootchartgui/pybootchartgui/parsing.py |  2 +-
 scripts/pybootchartgui/pybootchartgui/samples.py | 16 ++++++++++++++++
 3 files changed, 23 insertions(+), 7 deletions(-)
scripts/pybootchartgui/pybootchartgui/draw.py +6 -6
index f0143ad..201ce45 100644
@@ -463,25 +463,25 @@ def render_charts(ctx, options, clip, trace, curr_y, w, h, sec_w):
 	chart_rect = (off_x, curr_y+30, w, meminfo_bar_h)
 	mem_stats = trace.mem_stats
 	if mem_stats and clip_visible (clip, chart_rect):
-		mem_scale = max(sample.records['MemTotal'] - sample.records['MemFree'] for sample in mem_stats)
+		mem_scale = max(sample.buffers for sample in mem_stats)
 		draw_legend_box(ctx, "Mem cached (scale: %u MiB)" % (float(mem_scale) / 1024), MEM_CACHED_COLOR, off_x, curr_y+20, leg_s)
 		draw_legend_box(ctx, "Used", MEM_USED_COLOR, off_x + 240, curr_y+20, leg_s)
 		draw_legend_box(ctx, "Buffers", MEM_BUFFERS_COLOR, off_x + 360, curr_y+20, leg_s)
-		draw_legend_line(ctx, "Swap (scale: %u MiB)" % max([(sample.records['SwapTotal'] - sample.records['SwapFree'])/1024 for sample in mem_stats]), \
+		draw_legend_line(ctx, "Swap (scale: %u MiB)" % max([(sample.swap)/1024 for sample in mem_stats]), \
 				 MEM_SWAP_COLOR, off_x + 480, curr_y+20, leg_s)
 		draw_box_ticks(ctx, chart_rect, sec_w)
 		draw_annotations(ctx, proc_tree, trace.times, chart_rect)
 		draw_chart(ctx, MEM_BUFFERS_COLOR, True, chart_rect, \
-			   [(sample.time, sample.records['MemTotal'] - sample.records['MemFree']) for sample in trace.mem_stats], \
+			   [(sample.time, sample.buffers) for sample in trace.mem_stats], \
 			   proc_tree, [0, mem_scale])
 		draw_chart(ctx, MEM_USED_COLOR, True, chart_rect, \
-			   [(sample.time, sample.records['MemTotal'] - sample.records['MemFree'] - sample.records['Buffers']) for sample in mem_stats], \
+			   [(sample.time, sample.used) for sample in mem_stats], \
 			   proc_tree, [0, mem_scale])
 		draw_chart(ctx, MEM_CACHED_COLOR, True, chart_rect, \
-			   [(sample.time, sample.records['Cached']) for sample in mem_stats], \
+			   [(sample.time, sample.cached) for sample in mem_stats], \
 			   proc_tree, [0, mem_scale])
 		draw_chart(ctx, MEM_SWAP_COLOR, False, chart_rect, \
-			   [(sample.time, float(sample.records['SwapTotal'] - sample.records['SwapFree'])) for sample in mem_stats], \
+			   [(sample.time, float(sample.swap)) for sample in mem_stats], \
 			   proc_tree, None)
 
 		curr_y = curr_y + meminfo_bar_h
scripts/pybootchartgui/pybootchartgui/parsing.py +1 -1
index 301145a..1c8d8ef 100644
@@ -503,7 +503,7 @@ def _parse_proc_meminfo_log(file):
             sample.add_value(match.group(1), int(match.group(2)))
 
         if sample.valid():
-            mem_stats.append(sample)
+            mem_stats.append(DrawMemSample(sample))
 
     return mem_stats
 
scripts/pybootchartgui/pybootchartgui/samples.py +16 -0
index bedca41..9fc309b 100644
@@ -53,6 +53,22 @@ class MemSample:
         # discard incomplete samples
         return [v for v in MemSample.used_values if v not in keys] == []
 
+class DrawMemSample:
+    """
+    Condensed version of a MemSample with exactly the values used by the drawing code.
+    Initialized either from a valid MemSample or
+    a tuple/list of buffer/used/cached/swap values.
+    """
+    def __init__(self, mem_sample):
+        self.time = mem_sample.time
+        if isinstance(mem_sample, MemSample):
+            self.buffers = mem_sample.records['MemTotal'] - mem_sample.records['MemFree']
+            self.used = mem_sample.records['MemTotal'] - mem_sample.records['MemFree'] - mem_sample.records['Buffers']
+            self.cached = mem_sample.records['Cached']
+            self.swap = mem_sample.records['SwapTotal'] - mem_sample.records['SwapFree']
+        else:
+            self.buffers, self.used, self.cached, self.swap = mem_sample
+
 class DiskSpaceSample:
     def __init__(self, time):
         self.time = time
Signature · 1 line
2.1.4
#10 lore raw

PATCH v2 10/11 buildstats: reduce amount of data stored for system utilization

In reply to Patrick Ohly

Pre-processing /proc data during the build considerably reduces the amount of data written to disk: 176KB instead of 4.7MB for a 20 minuted build. Parsing also becomes faster.

The disk monitor log added another 16KB in that example build. The overall buildstat was 20MB, so the overhead for monitoring system utilization is small enough that it can be enabled by default.

---
 meta/lib/buildstats.py | 114 ++++++++++++++++++++++++++++++++++++++++++++-----
 1 file changed, 104 insertions(+), 10 deletions(-)
meta/lib/buildstats.py +104 -10
index 7c8b352..9e5b6be 100644
@@ -3,6 +3,7 @@
 # like open log files and the time of the last sampling.
 
 import time
+import re
 import bb.event
 
 class SystemStats:
@@ -12,14 +13,18 @@ class SystemStats:
         bb.utils.mkdirhier(bsdir)
 
         self.proc_files = []
-        for filename in ('diskstats', 'meminfo', 'stat'):
+        for filename, handler in (
+                ('diskstats', self._reduce_diskstats),
+                ('meminfo', self._reduce_meminfo),
+                ('stat', self._reduce_stat),
+        ):
             # In practice, this class gets instantiated only once in
             # the bitbake cooker process.  Therefore 'append' mode is
             # not strictly necessary, but using it makes the class
             # more robust should two processes ever write
             # concurrently.
-            self.proc_files.append((filename,
-                                    open(os.path.join(bsdir, 'proc_%s.log' % filename), 'ab')))
+            destfile = os.path.join(bsdir, '%sproc_%s.log' % ('reduced_' if handler else '', filename))
+            self.proc_files.append((filename, open(destfile, 'ab'), handler))
         self.monitor_disk = open(os.path.join(bsdir, 'monitor_disk.log'), 'ab')
         # Last time that we sampled /proc data resp. recorded disk monitoring data.
         self.last_proc = 0
@@ -30,23 +35,112 @@ class SystemStats:
         # depends on the heartbeat event, which fires less often.
         self.min_seconds = 1
 
+        self.meminfo_regex = re.compile(b'^(MemTotal|MemFree|Buffers|Cached|SwapTotal|SwapFree):\s*(\d+)')
+        self.diskstats_regex = re.compile(b'^([hsv]d.|mtdblock\d|mmcblk\d|cciss/c\d+d\d+.*)$')
+        self.diskstats_ltime = None
+        self.diskstats_data = None
+        self.stat_ltimes = None
+
     def close(self):
         self.monitor_disk.close()
         for _, output, _ in self.proc_files:
             output.close()
 
+    def _reduce_meminfo(self, time, data):
+        """
+        Extracts 'MemTotal', 'MemFree', 'Buffers', 'Cached', 'SwapTotal', 'SwapFree'
+        and writes their values into a single line, in that order.
+        """
+        values = {}
+        for line in data.split(b'\n'):
+            m = self.meminfo_regex.match(line)
+            if m:
+                values[m.group(1)] = m.group(2)
+        if len(values) == 6:
+            return (time,
+                    b' '.join([values[x] for x in
+                               (b'MemTotal', b'MemFree', b'Buffers', b'Cached', b'SwapTotal', b'SwapFree')]) + b'\n')
+
+    def _diskstats_is_relevant_line(self, linetokens):
+        if len(linetokens) != 14:
+            return False
+        disk = linetokens[2]
+        return self.diskstats_regex.match(disk)
+
+    def _reduce_diskstats(self, time, data):
+        relevant_tokens = filter(self._diskstats_is_relevant_line, map(lambda x: x.split(), data.split(b'\n')))
+        diskdata = [0] * 3
+        reduced = None
+        for tokens in relevant_tokens:
+            # rsect
+            diskdata[0] += int(tokens[5])
+            # wsect
+            diskdata[1] += int(tokens[9])
+            # use
+            diskdata[2] += int(tokens[12])
+        if self.diskstats_ltime:
+            # We need to compute information about the time interval
+            # since the last sampling and record the result as sample
+            # for that point in the past.
+            interval = time - self.diskstats_ltime
+            if interval > 0:
+                sums = [ a - b for a, b in zip(diskdata, self.diskstats_data) ]
+                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))
+                reduced = (self.diskstats_ltime, (readTput, writeTput, util))
+
+        self.diskstats_ltime = time
+        self.diskstats_data = diskdata
+        return reduced
+
+
+    def _reduce_nop(self, time, data):
+        return (time, data)
+
+    def _reduce_stat(self, time, data):
+        if not data:
+            return None
+        # CPU times {user, nice, system, idle, io_wait, irq, softirq} from first line
+        tokens = data.split(b'\n', 1)[0].split()
+        times = [ int(token) for token in tokens[1:] ]
+        reduced = None
+        if self.stat_ltimes:
+            user = float((times[0] + times[1]) - (self.stat_ltimes[0] + self.stat_ltimes[1]))
+            system = float((times[2] + times[5] + times[6]) - (self.stat_ltimes[2] + self.stat_ltimes[5] + self.stat_ltimes[6]))
+            idle = float(times[3] - self.stat_ltimes[3])
+            iowait = float(times[4] - self.stat_ltimes[4])
+
+            aSum = max(user + system + idle + iowait, 1)
+            reduced = (time, (user/aSum, system/aSum, iowait/aSum))
+
+        self.stat_ltimes = times
+        return reduced
+
     def sample(self, event, force):
         now = time.time()
         if (now - self.last_proc > self.min_seconds) or force:
-            for filename, output in self.proc_files:
+            for filename, output, handler in self.proc_files:
                 with open(os.path.join('/proc', filename), 'rb') as input:
                     data = input.read()
-                    # Unbuffered raw write, less overhead and useful
-                    # in case that we end up with concurrent writes.
-                    os.write(output.fileno(),
-                             ('%.0f\n' % now).encode('ascii') +
-                             data +
-                             b'\n')
+                    if handler:
+                        reduced = handler(now, data)
+                    else:
+                        reduced = (now, data)
+                    if reduced:
+                        if isinstance(reduced[1], bytes):
+                            # Use as it is.
+                            data = reduced[1]
+                        else:
+                            # Convert to a single line.
+                            data = (' '.join([str(x) for x in reduced[1]]) + '\n').encode('ascii')
+                        # Unbuffered raw write, less overhead and useful
+                        # in case that we end up with concurrent writes.
+                        os.write(output.fileno(),
+                                 ('%.0f\n' % reduced[0]).encode('ascii') +
+                                 data +
+                                 b'\n')
             self.last_proc = now
 
         if isinstance(event, bb.event.MonitorDiskEvent) and \
Signature · 1 line
2.1.4
#11 lore raw

PATCH v2 11/11 pybootchartgui: support reading reduced /proc logs

In reply to Patrick Ohly

Pre-processing /proc data during the build considerably reduces the amount of data written to disk: 176KB instead of 4.7MB for a 20 minuted build. Parsing also becomes faster.

buildstats.bbclass only writes the reduced logs now, but support for the full /proc files is kept around as reference.

---
 scripts/pybootchartgui/pybootchartgui/parsing.py | 31 ++++++++++++++++++++++++
 1 file changed, 31 insertions(+)
scripts/pybootchartgui/pybootchartgui/parsing.py +31 -0
index 1c8d8ef..bcfb2da 100644
@@ -442,6 +442,12 @@ def _parse_proc_stat_log(file):
         # 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,
@@ -483,6 +489,25 @@ def _parse_proc_disk_stat_log(file):
 
     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.
@@ -702,10 +727,16 @@ def _do_parse(writer, state, filename, file):
     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":
Signature · 1 line
2.1.4