diff options
author | Robert Yang <liezhi.yang@windriver.com> | 2012-06-06 14:00:48 +0800 |
---|---|---|
committer | Richard Purdie <richard.purdie@linuxfoundation.org> | 2012-06-15 15:12:42 +0100 |
commit | bc5b86f025c9c1d9f0e1a58e92fe8c1381c096a5 (patch) | |
tree | 8c7af16040e4a25fb750673194c937f626ea5166 /scripts/pybootchartgui/pybootchartgui/draw.py | |
parent | 3d78bc19c5b63541fd45dad7580ade55ba512764 (diff) | |
download | poky-bc5b86f025c9c1d9f0e1a58e92fe8c1381c096a5.tar.gz |
pybootchartgui: make the build profiling in pictures
The original patch is from Richard, I rebased it to the up-to-date
upstream code, here are the original messages from him:
We have just merged Beth's initial buildstats logging work. I was
sitting wondering how to actually evaluate the numbers as I wanted to
know "where are we spending the time?".
It occurred to me that I wanted a graph very similar to that generated
by bootchart. I looked around and found pyboootchartgui and then hacked
it around a bit and coerced it to start producing charts like:
http://tim.rpsys.net/bootchart.png
which is the initial "pseudo-native" part of the build. This was simple
enough to test with.
I then tried graphing a poky-image-sato. To get a graph I could actually
read, I stripped out any task taking less than 8 seconds and scaled the
x axis from 25 units per second to one unit per second. The result was:
http://tim.rpsys.net/bootchart2.png
(warning this is a 2.7MB png)
I also added in a little bit of colour coding for the second chart.
Interestingly it looks like there is more yellow than green meaning
configure is a bigger drain on the build time not that its
unexpected :/.
I quite enjoyed playing with this and on a serious note, the gradient of
the task graph makes me a little suspicious of whether the overhead of
launching tasks in bitbake itself is having some effect on build time.
Certainly on the first graph there are some interesting latencies
showing up.
Anyhow, I think this is the first time bitbake's task execution has been
visualised and there are some interesting things we can learn from it.
I'm hoping this is a start of a much more detailed understanding of the
build process with respect to performance.
[YOCTO #2403]
(From OE-Core rev: 6ea0c02d0db08f6b4570769c6811ecdb051646ad)
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
Signed-off-by: Robert Yang <liezhi.yang@windriver.com>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
Diffstat (limited to 'scripts/pybootchartgui/pybootchartgui/draw.py')
-rw-r--r-- | scripts/pybootchartgui/pybootchartgui/draw.py | 131 |
1 files changed, 92 insertions, 39 deletions
diff --git a/scripts/pybootchartgui/pybootchartgui/draw.py b/scripts/pybootchartgui/pybootchartgui/draw.py index 249cd2ef81..16830fa456 100644 --- a/scripts/pybootchartgui/pybootchartgui/draw.py +++ b/scripts/pybootchartgui/pybootchartgui/draw.py | |||
@@ -37,7 +37,7 @@ FILE_OPEN_COLOR = (0.20, 0.71, 0.71, 1.0) | |||
37 | 37 | ||
38 | # Process border color. | 38 | # Process border color. |
39 | PROC_BORDER_COLOR = (0.71, 0.71, 0.71, 1.0) | 39 | PROC_BORDER_COLOR = (0.71, 0.71, 0.71, 1.0) |
40 | # Waiting process color. | 40 | |
41 | PROC_COLOR_D = (0.76, 0.48, 0.48, 0.125) | 41 | PROC_COLOR_D = (0.76, 0.48, 0.48, 0.125) |
42 | # Running process color. | 42 | # Running process color. |
43 | PROC_COLOR_R = CPU_COLOR | 43 | PROC_COLOR_R = CPU_COLOR |
@@ -72,6 +72,17 @@ DEP_STROKE = 1.0 | |||
72 | # Process description date format. | 72 | # Process description date format. |
73 | DESC_TIME_FORMAT = "mm:ss.SSS" | 73 | DESC_TIME_FORMAT = "mm:ss.SSS" |
74 | 74 | ||
75 | # Configure task color | ||
76 | TASK_COLOR_CONFIGURE = (1.0, 1.0, 0.00, 1.0) | ||
77 | # Compile task color. | ||
78 | TASK_COLOR_COMPILE = (0.0, 1.00, 0.00, 1.0) | ||
79 | # Install task color | ||
80 | TASK_COLOR_INSTALL = (1.0, 0.00, 1.00, 1.0) | ||
81 | # Package task color | ||
82 | TASK_COLOR_PACKAGE = (0.0, 1.00, 1.00, 1.0) | ||
83 | # Sysroot task color | ||
84 | TASK_COLOR_SYSROOT = (0.0, 0.00, 1.00, 1.0) | ||
85 | |||
75 | # Process states | 86 | # Process states |
76 | STATE_UNDEFINED = 0 | 87 | STATE_UNDEFINED = 0 |
77 | STATE_RUNNING = 1 | 88 | STATE_RUNNING = 1 |
@@ -131,7 +142,7 @@ def draw_label_in_box(ctx, color, label, x, y, w, maxx): | |||
131 | def draw_5sec_labels(ctx, rect, sec_w): | 142 | def draw_5sec_labels(ctx, rect, sec_w): |
132 | ctx.set_font_size(AXIS_FONT_SIZE) | 143 | ctx.set_font_size(AXIS_FONT_SIZE) |
133 | for i in range(0, rect[2] + 1, sec_w): | 144 | for i in range(0, rect[2] + 1, sec_w): |
134 | if ((i / sec_w) % 5 == 0) : | 145 | if ((i / sec_w) % 30 == 0) : |
135 | label = "%ds" % (i / sec_w) | 146 | label = "%ds" % (i / sec_w) |
136 | label_w = ctx.text_extents(label)[2] | 147 | label_w = ctx.text_extents(label)[2] |
137 | draw_text(ctx, label, TEXT_COLOR, rect[0] + i - label_w/2, rect[1] - 2) | 148 | draw_text(ctx, label, TEXT_COLOR, rect[0] + i - label_w/2, rect[1] - 2) |
@@ -143,7 +154,7 @@ def draw_box_ticks(ctx, rect, sec_w): | |||
143 | ctx.set_line_cap(cairo.LINE_CAP_SQUARE) | 154 | ctx.set_line_cap(cairo.LINE_CAP_SQUARE) |
144 | 155 | ||
145 | for i in range(sec_w, rect[2] + 1, sec_w): | 156 | for i in range(sec_w, rect[2] + 1, sec_w): |
146 | if ((i / sec_w) % 5 == 0) : | 157 | if ((i / sec_w) % 30 == 0) : |
147 | ctx.set_source_rgba(*TICK_COLOR_BOLD) | 158 | ctx.set_source_rgba(*TICK_COLOR_BOLD) |
148 | else : | 159 | else : |
149 | ctx.set_source_rgba(*TICK_COLOR) | 160 | ctx.set_source_rgba(*TICK_COLOR) |
@@ -188,87 +199,129 @@ header_h = 280 | |||
188 | bar_h = 55 | 199 | bar_h = 55 |
189 | # offsets | 200 | # offsets |
190 | off_x, off_y = 10, 10 | 201 | off_x, off_y = 10, 10 |
191 | sec_w = 25 # the width of a second | 202 | sec_w = 1 # the width of a second |
192 | proc_h = 16 # the height of a process | 203 | proc_h = 16 # the height of a process |
193 | leg_s = 10 | 204 | leg_s = 10 |
194 | MIN_IMG_W = 800 | 205 | MIN_IMG_W = 800 |
195 | 206 | ||
196 | 207 | ||
197 | def extents(headers, cpu_stats, disk_stats, proc_tree): | 208 | def extents(res): |
198 | w = (proc_tree.duration * sec_w / 100) + 2*off_x | 209 | start = min(res.start.keys()) |
199 | h = proc_h * proc_tree.num_proc + header_h + 2*off_y | 210 | end = max(res.end.keys()) |
211 | |||
212 | w = ((end - start) * sec_w) + 2*off_x | ||
213 | h = proc_h * len(res.processes) + header_h + 2*off_y | ||
214 | |||
200 | return (w,h) | 215 | return (w,h) |
201 | 216 | ||
202 | # | 217 | # |
203 | # Render the chart. | 218 | # Render the chart. |
204 | # | 219 | # |
205 | def render(ctx, headers, cpu_stats, disk_stats, proc_tree): | 220 | def render(ctx, res): |
206 | (w, h) = extents(headers, cpu_stats, disk_stats, proc_tree) | 221 | (w, h) = extents(res) |
207 | 222 | ||
208 | ctx.set_line_width(1.0) | 223 | ctx.set_line_width(1.0) |
209 | ctx.select_font_face(FONT_NAME) | 224 | ctx.select_font_face(FONT_NAME) |
210 | draw_fill_rect(ctx, WHITE, (0, 0, max(w, MIN_IMG_W), h)) | 225 | draw_fill_rect(ctx, WHITE, (0, 0, max(w, MIN_IMG_W), h)) |
211 | w -= 2*off_x | 226 | w -= 2*off_x |
212 | # draw the title and headers | 227 | # draw the title and headers |
213 | curr_y = draw_header(ctx, headers, off_x, proc_tree.duration) | 228 | #curr_y = draw_header(ctx, headers, off_x, proc_tree.duration) |
229 | curr_y = 0 | ||
214 | 230 | ||
215 | # render bar legend | 231 | # render bar legend |
216 | ctx.set_font_size(LEGEND_FONT_SIZE) | 232 | ctx.set_font_size(LEGEND_FONT_SIZE) |
217 | 233 | ||
218 | draw_legend_box(ctx, "CPU (user+sys)", CPU_COLOR, off_x, curr_y+20, leg_s) | 234 | #print "w, h %s %s" % (w, h) |
219 | draw_legend_box(ctx, "I/O (wait)", IO_COLOR, off_x + 120, curr_y+20, leg_s) | 235 | |
236 | #draw_legend_box(ctx, "CPU (user+sys)", CPU_COLOR, off_x, curr_y+20, leg_s) | ||
237 | #draw_legend_box(ctx, "I/O (wait)", IO_COLOR, off_x + 120, curr_y+20, leg_s) | ||
220 | 238 | ||
221 | # render I/O wait | 239 | # render I/O wait |
222 | chart_rect = (off_x, curr_y+30, w, bar_h) | 240 | #chart_rect = (off_x, curr_y+30, w, bar_h) |
223 | draw_box_ticks(ctx, chart_rect, sec_w) | 241 | #draw_box_ticks(ctx, chart_rect, sec_w) |
224 | draw_chart(ctx, IO_COLOR, True, chart_rect, [(sample.time, sample.user + sample.sys + sample.io) for sample in cpu_stats], proc_tree) | 242 | #draw_chart(ctx, IO_COLOR, True, chart_rect, [(sample.time, sample.user + sample.sys + sample.io) for sample in cpu_stats], proc_tree) |
225 | # render CPU load | 243 | # render CPU load |
226 | draw_chart(ctx, CPU_COLOR, True, chart_rect, [(sample.time, sample.user + sample.sys) for sample in cpu_stats], proc_tree) | 244 | #draw_chart(ctx, CPU_COLOR, True, chart_rect, [(sample.time, sample.user + sample.sys) for sample in cpu_stats], proc_tree) |
227 | 245 | ||
228 | curr_y = curr_y + 30 + bar_h | 246 | #curr_y = curr_y + 30 + bar_h |
229 | 247 | ||
230 | # render second chart | 248 | # render second chart |
231 | draw_legend_line(ctx, "Disk throughput", DISK_TPUT_COLOR, off_x, curr_y+20, leg_s) | 249 | #draw_legend_line(ctx, "Disk throughput", DISK_TPUT_COLOR, off_x, curr_y+20, leg_s) |
232 | draw_legend_box(ctx, "Disk utilization", IO_COLOR, off_x + 120, curr_y+20, leg_s) | 250 | #draw_legend_box(ctx, "Disk utilization", IO_COLOR, off_x + 120, curr_y+20, leg_s) |
233 | 251 | ||
234 | # render I/O utilization | 252 | # render I/O utilization |
235 | chart_rect = (off_x, curr_y+30, w, bar_h) | 253 | #chart_rect = (off_x, curr_y+30, w, bar_h) |
236 | draw_box_ticks(ctx, chart_rect, sec_w) | 254 | #draw_box_ticks(ctx, chart_rect, sec_w) |
237 | draw_chart(ctx, IO_COLOR, True, chart_rect, [(sample.time, sample.util) for sample in disk_stats], proc_tree) | 255 | #draw_chart(ctx, IO_COLOR, True, chart_rect, [(sample.time, sample.util) for sample in disk_stats], proc_tree) |
238 | 256 | ||
239 | # render disk throughput | 257 | # render disk throughput |
240 | max_sample = max(disk_stats, key=lambda s: s.tput) | 258 | #max_sample = max(disk_stats, key=lambda s: s.tput) |
241 | draw_chart(ctx, DISK_TPUT_COLOR, False, chart_rect, [(sample.time, sample.tput) for sample in disk_stats], proc_tree) | 259 | #draw_chart(ctx, DISK_TPUT_COLOR, False, chart_rect, [(sample.time, sample.tput) for sample in disk_stats], proc_tree) |
242 | 260 | ||
243 | pos_x = off_x + ((max_sample.time - proc_tree.start_time) * w / proc_tree.duration) | 261 | #pos_x = off_x + ((max_sample.time - proc_tree.start_time) * w / proc_tree.duration) |
262 | pos_x = off_x | ||
244 | 263 | ||
245 | shift_x, shift_y = -20, 20 | 264 | shift_x, shift_y = -20, 20 |
246 | if (pos_x < off_x + 245): | 265 | if (pos_x < off_x + 245): |
247 | shift_x, shift_y = 5, 40 | 266 | shift_x, shift_y = 5, 40 |
248 | 267 | ||
249 | label = "%dMB/s" % round((max_sample.tput) / 1024.0) | 268 | #label = "%dMB/s" % round((max_sample.tput) / 1024.0) |
250 | draw_text(ctx, label, DISK_TPUT_COLOR, pos_x + shift_x, curr_y + shift_y) | 269 | #draw_text(ctx, label, DISK_TPUT_COLOR, pos_x + shift_x, curr_y + shift_y) |
251 | 270 | ||
252 | 271 | ||
253 | # draw process boxes | ||
254 | draw_process_bar_chart(ctx, proc_tree, curr_y + bar_h, w, h) | ||
255 | 272 | ||
256 | ctx.set_font_size(SIG_FONT_SIZE) | 273 | chart_rect = [off_x, curr_y+60, w, h - 2 * off_y - (curr_y+60) + proc_h] |
257 | draw_text(ctx, SIGNATURE, SIG_COLOR, off_x + 5, h - off_y - 5) | 274 | |
258 | 275 | draw_legend_box(ctx, "Configure", TASK_COLOR_CONFIGURE, off_x , curr_y + 45, leg_s) | |
259 | def draw_process_bar_chart(ctx, proc_tree, curr_y, w, h): | 276 | draw_legend_box(ctx, "Compile", TASK_COLOR_COMPILE, off_x+120, curr_y + 45, leg_s) |
260 | draw_legend_box(ctx, "Running (%cpu)", PROC_COLOR_R, off_x , curr_y + 45, leg_s) | 277 | draw_legend_box(ctx, "Install", TASK_COLOR_INSTALL, off_x+240, curr_y + 45, leg_s) |
261 | draw_legend_box(ctx, "Unint.sleep (I/O)", PROC_COLOR_D, off_x+120, curr_y + 45, leg_s) | 278 | draw_legend_box(ctx, "Package", TASK_COLOR_PACKAGE, off_x+360, curr_y + 45, leg_s) |
262 | draw_legend_box(ctx, "Sleeping", PROC_COLOR_S, off_x+240, curr_y + 45, leg_s) | 279 | draw_legend_box(ctx, "Populate Sysroot", TASK_COLOR_SYSROOT, off_x+480, curr_y + 45, leg_s) |
263 | draw_legend_box(ctx, "Zombie", PROC_COLOR_Z, off_x+360, curr_y + 45, leg_s) | ||
264 | 280 | ||
265 | chart_rect = [off_x, curr_y+60, w, h - 2 * off_y - (curr_y+60) + proc_h] | ||
266 | ctx.set_font_size(PROC_TEXT_FONT_SIZE) | 281 | ctx.set_font_size(PROC_TEXT_FONT_SIZE) |
267 | 282 | ||
268 | draw_box_ticks(ctx, chart_rect, sec_w) | 283 | draw_box_ticks(ctx, chart_rect, sec_w) |
269 | draw_5sec_labels(ctx, chart_rect, sec_w) | 284 | draw_5sec_labels(ctx, chart_rect, sec_w) |
270 | 285 | ||
271 | y = curr_y+60 | 286 | y = curr_y+60 |
287 | |||
288 | offset = min(res.start.keys()) | ||
289 | for s in sorted(res.start.keys()): | ||
290 | task = res.start[s].split(":")[1] | ||
291 | #print res.start[s] | ||
292 | #print res.processes[res.start[s]][1] | ||
293 | #print s | ||
294 | x = (s - offset) * sec_w | ||
295 | w = ((res.processes[res.start[s]][1] - s) * sec_w) | ||
296 | |||
297 | #print "proc at %s %s %s %s" % (x, y, w, proc_h) | ||
298 | col = None | ||
299 | if task == "do_compile": | ||
300 | col = TASK_COLOR_COMPILE | ||
301 | elif task == "do_configure": | ||
302 | col = TASK_COLOR_CONFIGURE | ||
303 | elif task == "do_install": | ||
304 | col = TASK_COLOR_INSTALL | ||
305 | elif task == "do_package": | ||
306 | col = TASK_COLOR_PACKAGE | ||
307 | elif task == "do_populate_sysroot": | ||
308 | col = TASK_COLOR_SYSROOT | ||
309 | |||
310 | draw_rect(ctx, PROC_BORDER_COLOR, (x, y, w, proc_h)) | ||
311 | if col: | ||
312 | draw_fill_rect(ctx, col, (x, y, w, proc_h)) | ||
313 | |||
314 | draw_label_in_box(ctx, PROC_TEXT_COLOR, res.start[s], x, y + proc_h - 4, w, proc_h) | ||
315 | y = y + proc_h | ||
316 | |||
317 | # draw process boxes | ||
318 | #draw_process_bar_chart(ctx, proc_tree, curr_y + bar_h, w, h) | ||
319 | |||
320 | ctx.set_font_size(SIG_FONT_SIZE) | ||
321 | draw_text(ctx, SIGNATURE, SIG_COLOR, off_x + 5, h - off_y - 5) | ||
322 | |||
323 | def draw_process_bar_chart(ctx, proc_tree, curr_y, w, h): | ||
324 | |||
272 | for root in proc_tree.process_tree: | 325 | for root in proc_tree.process_tree: |
273 | draw_processes_recursively(ctx, root, proc_tree, y, proc_h, chart_rect) | 326 | draw_processes_recursively(ctx, root, proc_tree, y, proc_h, chart_rect) |
274 | y = y + proc_h * proc_tree.num_nodes([root]) | 327 | y = y + proc_h * proc_tree.num_nodes([root]) |