summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
authorScott Shawcroft <scott.shawcroft@gmail.com>2016-11-23 17:31:53 -0800
committerScott Shawcroft <scott.shawcroft@gmail.com>2016-11-23 17:31:53 -0800
commita8fbad5d8bfd6c0abca8a6759785c61d1f553b3f (patch)
tree15bbb65ac1626096e3f91e2ff0f0b116ddc76871
parentea1320bee7fbd0f895e8afe528e4b528489b2c5e (diff)
Add heap analysis scripts based on GDB breakpoint logs.
Diffstat
-rw-r--r--py/gc.c28
-rw-r--r--tools/gc_activity.html137
-rw-r--r--tools/gc_activity.md198
-rw-r--r--tools/gc_activity.py94
-rw-r--r--tools/output_gc_until_repl.txt28
5 files changed, 485 insertions, 0 deletions
diff --git a/py/gc.c b/py/gc.c
index f883a724e..a93f7347a 100644
--- a/py/gc.c
+++ b/py/gc.c
@@ -102,6 +102,15 @@
#define GC_EXIT()
#endif
+#ifdef LOG_HEAP_ACTIVITY
+volatile uint32_t change_me;
+
+void __attribute__ ((noinline)) gc_log_change(uint32_t start_block, uint32_t length) {
+ change_me += start_block;
+ change_me += length; // Break on this line.
+}
+#endif
+
// TODO waste less memory; currently requires that all entries in alloc_table have a corresponding block in pool
void gc_init(void *start, void *end) {
// align end pointer on block boundary
@@ -278,6 +287,10 @@ STATIC void gc_sweep(void) {
#endif
free_tail = 1;
DEBUG_printf("gc_sweep(%x)\n", PTR_FROM_BLOCK(block));
+
+ #ifdef LOG_HEAP_ACTIVITY
+ gc_log_change(block, 0);
+ #endif
#if MICROPY_PY_GC_COLLECT_RETVAL
MP_STATE_MEM(gc_collected)++;
#endif
@@ -470,6 +483,10 @@ found:
MP_STATE_MEM(gc_last_free_atb_index) = (i + 1) / BLOCKS_PER_ATB;
}
+ #ifdef LOG_HEAP_ACTIVITY
+ gc_log_change(start_block, end_block - start_block + 1);
+ #endif
+
// mark first block as used head
ATB_FREE_TO_HEAD(start_block);
@@ -556,6 +573,9 @@ void gc_free(void *ptr) {
}
// free head and all of its tail blocks
+ #ifdef LOG_HEAP_ACTIVITY
+ gc_log_change(block, 0);
+ #endif
do {
ATB_ANY_TO_FREE(block);
block += 1;
@@ -715,6 +735,10 @@ void *gc_realloc(void *ptr_in, size_t n_bytes, bool allow_move) {
gc_dump_alloc_table();
#endif
+ #ifdef LOG_HEAP_ACTIVITY
+ gc_log_change(block, new_blocks);
+ #endif
+
return ptr_in;
}
@@ -740,6 +764,10 @@ void *gc_realloc(void *ptr_in, size_t n_bytes, bool allow_move) {
gc_dump_alloc_table();
#endif
+ #ifdef LOG_HEAP_ACTIVITY
+ gc_log_change(block, new_blocks);
+ #endif
+
return ptr_in;
}
diff --git a/tools/gc_activity.html b/tools/gc_activity.html
new file mode 100644
index 000000000..ec0ccbf88
--- /dev/null
+++ b/tools/gc_activity.html
@@ -0,0 +1,137 @@
+<!DOCTYPE html>
+<html>
+ <head>
+ <meta charset="utf-8">
+ <style>
+
+ html, body, svg {
+ margin: 0px;
+ min-height: 100%;
+ height: 100%;
+ width: 100%;
+ }
+
+ .chart rect {
+ fill: steelblue;
+ }
+
+ .axis text {
+ font: 10px sans-serif;
+ }
+
+ .axis path,
+ .axis line {
+ fill: none;
+ stroke: #000;
+ shape-rendering: crispEdges;
+ }
+
+ div.tooltip {
+ position: absolute;
+ # text-align: center;
+ # width: 60px;
+ # height: 28px;
+ padding: 2px;
+ font: 12px sans-serif;
+ background: lightsteelblue;
+ border: 0px;
+ }
+
+ </style>
+ </head>
+ <body>
+ <svg class="chart"></svg>
+ <script src="https://d3js.org/d3.v4.js"></script>
+ <script>
+ var barHeight = 2;
+
+ var chart = d3.select(".chart");
+
+ var margin = {top: 20, right: 30, bottom: 30, left: 40},
+ width = chart.style("width").replace("px", "") - margin.left - margin.right,
+ height = chart.style("height").replace("px", "") - margin.top - margin.bottom;
+
+ var x = d3.scaleLinear().range([0, width]);
+ var y = d3.scaleLinear().range([0, height]);
+
+ var chart = chart.append("g")
+ .attr("transform", "translate(" + margin.left + "," + margin.top + ")");
+
+ var xAxis = d3.axisBottom().scale(x);
+ var yAxis = d3.axisLeft().scale(y);
+
+ var div = d3.select("body").append("div")
+ .attr("class", "tooltip")
+ .style("opacity", 0);
+
+ d3.json("/allocation_history.json", function(error, data) {
+ console.log(data[0]);
+ x.domain([0, d3.max(data, function(d) { return d.end_time; })]);
+ y.domain([0, d3.max(data, function(d) { return d.start_block + d.size; })]);
+
+ chart.append("g")
+ .attr("class", "x axis")
+ .attr("transform", "translate(0," + height + ")")
+ .call(xAxis);
+
+ chart.append("g")
+ .attr("class", "y axis")
+ .call(yAxis);
+
+ var bar = chart.selectAll("g")
+ .data(data)
+ .enter().append("g")
+ .attr("transform", function(d, i) { return "translate(" + x(d.start_time) + "," + y(d.start_block) + ")"; });
+
+ bar.append("rect")
+ .attr("width", function(d) { return x(d.end_time - d.start_time); })
+ .attr("height", function(d) { return y(d.size) - 1; })
+ .on("mouseover", function(d) {
+ var trace = "";
+ for (var i = 0, len = d.start_trace.length; i < len; i++) {
+ var frame = d.start_trace[i];
+ trace += frame[2] + " " + frame[1] + "<br/>";
+ }
+ trace += "<br/>End Trace:<br/>";
+ for (var i = 0, len = d.end_trace.length; i < len; i++) {
+ var frame = d.end_trace[i];
+ trace += frame[2] + " " + frame[1] + "<br/>";
+ }
+ var side = "left";
+ var other_side = "right";
+ var pos_x = x(d.start_time) + margin.left;
+ if (width - pos_x < 300) {
+ side = "right";
+ other_side = "left";
+ pos_x = width - x(d.start_time) + margin.right;
+ }
+ var pos_y = (height - y(d.start_block) + margin.bottom)
+ var edge = "bottom";
+ var other_edge = "top";
+ if ((height - pos_y) < 300) {
+ edge = "top";
+ other_edge = "bottom";
+ pos_y = y(d.start_block) + margin.top + y(d.size);
+ }
+ div.style("opacity", 1)
+ .html("Start block: " + d.start_block + " Size: " + d.size + " blocks<br/><br/>" + trace)
+ .style(side, pos_x + "px")
+ .style(other_side, null)
+ .style(edge, pos_y + "px")
+ .style(other_edge, null);
+ });
+
+ // bar.append("text")
+ // .attr("x", function(d) { return x(d.value) - 3; })
+ // .attr("y", barHeight / 2)
+ // .attr("dy", ".35em")
+ // .text(function(d) { return d.value; });
+ });
+
+ function type(d) {
+ d.value = +d.value; // coerce to number
+ return d;
+ }
+ </script>
+ </body>
+</html>
diff --git a/tools/gc_activity.md b/tools/gc_activity.md
new file mode 100644
index 000000000..40252bdf7
--- /dev/null
+++ b/tools/gc_activity.md
@@ -0,0 +1,198 @@
+# GC Analysis
+
+Here are some terse instructions on doing heap analysis via gdb.
+
+First, build your port with `LOG_HEAP_ACTIVITY` defined and load it onto your
+board. This will enable calls to a gc log function that isn't inlined so it uses
+only one breakpoint.
+
+Next, double check that the `break gc.c:110` line in `output_gc_until_repl.txt`
+has the correct line number. Also make sure the tar ext line connects to the
+correct port. GDB is usually :3333 and JLink is :2331.
+
+Now, run gdb from your port directory:
+
+```
+arm-none-eabi-gdb -x ../tools/output_gc_until_repl.txt build-metro_m0_flash/firmware.elf
+```
+
+This will take a little time while it breaks, backtraces and continues for every
+gc change until the repl. At the end it will have a `mylog.txt` file.
+
+To analyze that file run:
+```
+python3 ../tools/gc_activity.py mylog.txt
+```
+
+It will create a file `allocation_history.json` which documents the lifespan of
+the allocations. It also outputs a tree of the current number of blocks
+allocated by a piece of code such as:
+```
+main.c:298 main 5 blocks
+ main.c:159 reset_mp 2 blocks
+ ../py/runtime.c:81 mp_init 2 blocks
+ ../py/objmodule.c:227 mp_module_init 2 blocks
+ ../py/objdict.c:595 mp_obj_dict_init 2 blocks
+ ../py/map.c:79 mp_map_init 2 blocks
+ main.c:160 reset_mp 1 blocks
+ ../py/objlist.c:458 mp_obj_list_init 1 blocks
+ main.c:164 reset_mp 1 blocks
+ ../py/objlist.c:458 mp_obj_list_init 1 blocks
+ main.c:166 reset_mp 1 blocks
+ ../py/objexcept.c:297 mp_obj_new_exception 1 blocks
+ ../py/objexcept.c:307 mp_obj_new_exception_args 1 blocks
+ ../py/objexcept.c:130 mp_obj_exception_make_new 1 blocks
+main.c:311 main 289 blocks
+ main.c:211 start_mp 14 blocks
+ main.c:196 maybe_run 14 blocks
+ ../lib/utils/pyexec.c:501 pyexec_file 14 blocks
+ main.c:352 mp_lexer_new_from_file 14 blocks
+ ../py/../extmod/vfs_fat_lexer.c:80 fat_vfs_lexer_new_from_file 14 blocks
+ ../py/qstr.c:184 qstr_from_str 14 blocks
+ ../py/qstr.c:216 qstr_from_strn 8 blocks
+ ../py/qstr.c:240 qstr_from_strn 6 blocks
+ ../py/qstr.c:146 qstr_add 6 blocks
+ main.c:220 start_mp 275 blocks
+ main.c:196 maybe_run 275 blocks
+ ../lib/utils/pyexec.c:508 pyexec_file 275 blocks
+ ../lib/utils/pyexec.c:82 parse_compile_execute 4 blocks
+ ../py/compile.c:3511 mp_compile 3 blocks
+ ../py/compile.c:3451 mp_compile_to_raw_code 3 blocks
+ ../py/compile.c:3092 compile_scope 3 blocks
+ ../py/emitbc.c:419 mp_emit_bc_end_pass 3 blocks
+ ../py/compile.c:3513 mp_compile 1 blocks
+ ../py/emitglue.c:131 mp_make_function_from_raw_code 1 blocks
+ ../py/objfun.c:364 mp_obj_new_fun_bc 1 blocks
+ ../lib/utils/pyexec.c:88 parse_compile_execute 271 blocks
+ ../py/runtime.c:551 mp_call_function_0 271 blocks
+ ../py/runtime.c:577 mp_call_function_n_kw 271 blocks
+ ../py/objfun.c:275 fun_bc_call 271 blocks
+ ../py/vm.c:1161 mp_execute_bytecode 269 blocks
+ ../py/runtime.c:1315 mp_import_name 269 blocks
+ ../py/builtinimport.c:442 mp_builtin___import__ 2 blocks
+ ../py/objmodule.c:113 mp_obj_new_module 1 blocks
+ ../py/objmodule.c:115 mp_obj_new_module 1 blocks
+ ../py/objdict.c:599 mp_obj_new_dict 1 blocks
+ ../py/builtinimport.c:473 mp_builtin___import__ 267 blocks
+ ../py/builtinimport.c:230 do_load 140 blocks
+ ../py/emitglue.c:469 mp_raw_code_load_file 140 blocks
+ ../py/emitglue.c:356 mp_raw_code_load 140 blocks
+ ../py/emitglue.c:320 load_raw_code 8 blocks
+ ../py/emitglue.c:295 load_bytecode_qstrs 8 blocks
+ ../py/emitglue.c:265 load_qstr 8 blocks
+ ../py/qstr.c:216 qstr_from_strn 8 blocks
+ ../py/emitglue.c:331 load_raw_code 2 blocks
+ ../py/emitglue.c:277 load_obj 1 blocks
+ ../py/vstr.c:53 vstr_init_len 1 blocks
+ ../py/vstr.c:46 vstr_init 1 blocks
+ ../py/emitglue.c:280 load_obj 1 blocks
+ ../py/objstr.c:2001 mp_obj_new_str_from_vstr 1 blocks
+ ../py/emitglue.c:334 load_raw_code 130 blocks
+ ../py/emitglue.c:306 load_raw_code 6 blocks
+ ../py/emitglue.c:325 load_raw_code 4 blocks
+ ../py/emitglue.c:328 load_raw_code 19 blocks
+ ../py/emitglue.c:265 load_qstr 19 blocks
+ ../py/qstr.c:216 qstr_from_strn 8 blocks
+ ../py/qstr.c:240 qstr_from_strn 11 blocks
+ ../py/qstr.c:146 qstr_add 11 blocks
+ ../py/emitglue.c:334 load_raw_code 101 blocks
+ ../py/emitglue.c:306 load_raw_code 80 blocks
+ ../py/emitglue.c:320 load_raw_code 8 blocks
+ ../py/emitglue.c:295 load_bytecode_qstrs 8 blocks
+ ../py/emitglue.c:265 load_qstr 8 blocks
+ ../py/qstr.c:216 qstr_from_strn 8 blocks
+ ../py/emitglue.c:325 load_raw_code 13 blocks
+ ../py/builtinimport.c:231 do_load 127 blocks
+ ../py/builtinimport.c:181 do_execute_raw_code 127 blocks
+ ../py/runtime.c:551 mp_call_function_0 127 blocks
+ ../py/runtime.c:577 mp_call_function_n_kw 127 blocks
+ ../py/objfun.c:275 fun_bc_call 127 blocks
+ ../py/vm.c:400 mp_execute_bytecode 6 blocks
+ ../py/runtime.c:168 mp_store_name 6 blocks
+ ../py/objdict.c:612 mp_obj_dict_store 6 blocks
+ ../py/map.c:283 mp_map_lookup 6 blocks
+ ../py/map.c:130 mp_map_rehash 6 blocks
+ ../py/vm.c:847 mp_execute_bytecode 2 blocks
+ ../py/emitglue.c:131 mp_make_function_from_raw_code 2 blocks
+ ../py/objfun.c:364 mp_obj_new_fun_bc 2 blocks
+ ../py/vm.c:855 mp_execute_bytecode 3 blocks
+ ../py/emitglue.c:131 mp_make_function_from_raw_code 3 blocks
+ ../py/objfun.c:364 mp_obj_new_fun_bc 3 blocks
+ ../py/vm.c:903 mp_execute_bytecode 110 blocks
+ ../py/runtime.c:577 mp_call_function_n_kw 110 blocks
+ ../py/objfun.c:129 fun_builtin_var_call 110 blocks
+ ../py/modbuiltins.c:56 mp_builtin___build_class__ 5 blocks
+ ../py/objdict.c:599 mp_obj_new_dict 5 blocks
+ ../py/modbuiltins.c:60 mp_builtin___build_class__ 84 blocks
+ ../py/runtime.c:551 mp_call_function_0 84 blocks
+ ../py/runtime.c:577 mp_call_function_n_kw 84 blocks
+ ../py/objfun.c:275 fun_bc_call 84 blocks
+ ../py/vm.c:400 mp_execute_bytecode 17 blocks
+ ../py/runtime.c:168 mp_store_name 17 blocks
+ ../py/objdict.c:612 mp_obj_dict_store 17 blocks
+ ../py/map.c:283 mp_map_lookup 17 blocks
+ ../py/map.c:130 mp_map_rehash 17 blocks
+ ../py/vm.c:847 mp_execute_bytecode 9 blocks
+ ../py/emitglue.c:131 mp_make_function_from_raw_code 9 blocks
+ ../py/objfun.c:364 mp_obj_new_fun_bc 9 blocks
+ ../py/vm.c:855 mp_execute_bytecode 8 blocks
+ ../py/emitglue.c:131 mp_make_function_from_raw_code 8 blocks
+ ../py/objfun.c:364 mp_obj_new_fun_bc 8 blocks
+ ../py/vm.c:903 mp_execute_bytecode 50 blocks
+ ../py/runtime.c:577 mp_call_function_n_kw 50 blocks
+ ../py/objboundmeth.c:69 bound_meth_call 1 blocks
+ ../py/runtime.c:577 mp_call_function_n_kw 1 blocks
+ ../py/objfun.c:86 fun_builtin_2_call 1 blocks
+ ../py/objproperty.c:66 property_setter 1 blocks
+ ../py/objtype.c:816 type_call 49 blocks
+ ../py/objtype.c:248 mp_obj_instance_make_new 7 blocks
+ ../py/objtype.c:52 mp_obj_new_instance 7 blocks
+ ../py/objtype.c:312 mp_obj_instance_make_new 42 blocks
+ ../py/runtime.c:594 mp_call_method_n_kw 42 blocks
+ ../py/runtime.c:577 mp_call_function_n_kw 42 blocks
+ ../py/objfun.c:275 fun_bc_call 42 blocks
+ ../py/vm.c:381 mp_execute_bytecode 14 blocks
+ ../py/obj.c:442 mp_obj_subscr 14 blocks
+ ../py/objarray.c:461 array_subscr 14 blocks
+ ../py/vm.c:415 mp_execute_bytecode 14 blocks
+ ../py/runtime.c:1083 mp_store_attr 14 blocks
+ ../py/objtype.c:645 mp_obj_instance_attr 14 blocks
+ ../py/objtype.c:636 mp_obj_instance_store_attr 14 blocks
+ ../py/map.c:283 mp_map_lookup 14 blocks
+ ../py/map.c:130 mp_map_rehash 14 blocks
+ ../py/vm.c:903 mp_execute_bytecode 14 blocks
+ ../py/runtime.c:577 mp_call_function_n_kw 14 blocks
+ ../py/objtype.c:816 type_call 14 blocks
+ ../py/objarray.c:192 bytearray_make_new 14 blocks
+ ../py/objarray.c:100 array_new 7 blocks
+ ../py/objarray.c:111 array_new 7 blocks
+ ../py/modbuiltins.c:80 mp_builtin___build_class__ 1 blocks
+ ../py/objtuple.c:242 mp_obj_new_tuple 1 blocks
+ ../py/modbuiltins.c:82 mp_builtin___build_class__ 20 blocks
+ ../py/runtime.c:577 mp_call_function_n_kw 20 blocks
+ ../py/objtype.c:816 type_call 20 blocks
+ ../py/objtype.c:794 type_make_new 20 blocks
+ ../py/objtype.c:904 mp_obj_new_type 20 blocks
+ ../py/vm.c:974 mp_execute_bytecode 6 blocks
+ ../py/runtime.c:594 mp_call_method_n_kw 6 blocks
+ ../py/runtime.c:577 mp_call_function_n_kw 6 blocks
+ ../py/objfun.c:86 fun_builtin_2_call 6 blocks
+ ../py/objnamedtuple.c:169 new_namedtuple_type 6 blocks
+ ../py/objnamedtuple.c:140 mp_obj_new_namedtuple_type 6 blocks
+ ../py/vm.c:400 mp_execute_bytecode 2 blocks
+ ../py/runtime.c:168 mp_store_name 2 blocks
+ ../py/objdict.c:612 mp_obj_dict_store 2 blocks
+ ../py/map.c:283 mp_map_lookup 2 blocks
+ ../py/map.c:130 mp_map_rehash 2 blocks
+main.c:321 main 2 blocks
+ ../lib/utils/pyexec.c:374 pyexec_friendly_repl 2 blocks
+ ../py/vstr.c:46 vstr_init 2 blocks
+296 total blocks
+```
+
+To load the json file in the browser install http-server with npm
+(`npm install -g http-server`) and run it from the `micropython` directory with
+`http-server`.
+
+Navigate to `https://127.0.0.1/tools/gc_activity.html` to see the data. (You
+will likely need to edit the html to point to the right place for your file.)
diff --git a/tools/gc_activity.py b/tools/gc_activity.py
new file mode 100644
index 000000000..8d172ea3a
--- /dev/null
+++ b/tools/gc_activity.py
@@ -0,0 +1,94 @@
+import sys
+import json
+
+# Map start block to current allocation info.
+current_heap = {}
+allocation_history = []
+root = {}
+
+def change_root(trace, size):
+ level = root
+ for frame in reversed(trace):
+ file_location = frame[1]
+ if file_location not in level:
+ level[file_location] = {"blocks": 0,
+ "file": file_location,
+ "function": frame[2],
+ "subcalls": {}}
+ level[file_location]["blocks"] += size
+ level = level[file_location]["subcalls"]
+
+total_actions = 0
+with open(sys.argv[1], "r") as f:
+ for line in f:
+ if not line.strip():
+ break
+ for line in f:
+ action = None
+ if line.startswith("Breakpoint 2"):
+ break
+ next(f) # throw away breakpoint code line
+ next(f) # first frame
+ block = 0
+ size = 0
+ trace = []
+ for line in f:
+ #print(line.strip())
+ if line[0] == "#":
+ frame = line.strip().split()
+ if frame[1].startswith("0x"):
+ trace.append((frame[1], frame[-1], frame[3]))
+ else:
+ trace.append(("0x0", frame[-1], frame[1]))
+ elif line[0] == "$":
+ block = int(line.strip().split()[-1][2:], 16)
+ size = int(next(f).strip().split()[-1][2:], 16)
+ if not line.strip():
+ break
+
+ action = "unknown"
+ if block not in current_heap:
+ current_heap[block] = {"start_block": block, "size": size, "start_trace": trace, "start_time": total_actions}
+ action = "alloc"
+ change_root(trace, size)
+ else:
+ alloc = current_heap[block]
+ alloc["end_trace"] = trace
+ alloc["end_time"] = total_actions
+ change_root(alloc["start_trace"], -1 * alloc["size"])
+ if size > 0:
+ action = "realloc"
+ current_heap[block] = {"start_block": block, "size": size, "start_trace": trace, "start_time": total_actions}
+ change_root(trace, size)
+ else:
+ action = "free"
+ if trace[0][2] == "gc_sweep":
+ action = "sweep"
+ del current_heap[block]
+ alloc["end_cause"] = action
+ allocation_history.append(alloc)
+ print(total_actions, action, block, size)
+ total_actions += 1
+
+print()
+
+for alloc in current_heap.values():
+ alloc["end_trace"] = ""
+ alloc["end_time"] = total_actions
+ allocation_history.append(alloc)
+
+def print_frame(frame, indent=0):
+ for key in sorted(frame):
+ if not frame[key]["blocks"] or key.startswith("../py/malloc.c") or key.startswith("../py/gc.c"):
+ continue
+ print(" " * (indent - 1), key, frame[key]["function"], frame[key]["blocks"], "blocks")
+ print_frame(frame[key]["subcalls"], indent + 2)
+
+print_frame(root)
+total_blocks = 0
+for key in sorted(root):
+ total_blocks += root[key]["blocks"]
+print(total_blocks, "total blocks")
+
+with open("allocation_history.json", "w") as f:
+ json.dump(allocation_history, f)
diff --git a/tools/output_gc_until_repl.txt b/tools/output_gc_until_repl.txt
new file mode 100644
index 000000000..28fb29219
--- /dev/null
+++ b/tools/output_gc_until_repl.txt
@@ -0,0 +1,28 @@
+tar ext :2331
+monitor reset
+set width 0
+set height 0
+set verbose off
+set logging file mylog.txt
+set logging overwrite on
+set logging redirect on
+set logging on
+set remote hardware-breakpoint-limit 4
+
+# gc log
+break gc.c:110
+commands
+backtrace
+p/x start_block
+p/x length
+continue
+end
+
+break mp_hal_stdin_rx_chr
+
+continue
+
+delete
+
+disconnect
+quit
generated by cgit v1.2.3 (git 2.39.1) at 2026-08-08 13:49:56 +0000