Browse Source

started with profiling section

pull/8/head
Zoltán Vörös 5 years ago
parent
commit
14f89aeb36
  1. 28
      consumeiterable/consumeiterable.c
  2. 8
      consumeiterable/micropython.mk
  3. 247
      docs/developing_micropython.ipynb
  4. 9
      profiling/profiling.c
  5. 8
      returniterable/micropython.mk
  6. 28
      returniterable/returniterable.c

28
consumeiterable/consumeiterable.c

@ -0,0 +1,28 @@
#include "py/obj.h"
#include "py/runtime.h"
STATIC mp_obj_t consumeiterable_sumsq(mp_obj_t o_in) {
mp_float_t _sum = 0.0, itemf;
mp_obj_iter_buf_t iter_buf;
mp_obj_t item, iterable = mp_getiter(o_in, &iter_buf);
while ((item = mp_iternext(iterable)) != MP_OBJ_STOP_ITERATION) {
itemf = mp_obj_get_float(item);
_sum += itemf*itemf;
}
return mp_obj_new_float(_sum);
}
STATIC MP_DEFINE_CONST_FUN_OBJ_1(consumeiterable_sumsq_obj, consumeiterable_sumsq);
STATIC const mp_rom_map_elem_t consumeiterable_module_globals_table[] = {
{ MP_ROM_QSTR(MP_QSTR___name__), MP_ROM_QSTR(MP_QSTR_consumeiterable) },
{ MP_ROM_QSTR(MP_QSTR_sumsq), MP_ROM_PTR(&consumeiterable_sumsq_obj) },
};
STATIC MP_DEFINE_CONST_DICT(consumeiterable_module_globals, consumeiterable_module_globals_table);
const mp_obj_module_t consumeiterable_user_cmodule = {
.base = { &mp_type_module },
.globals = (mp_obj_dict_t*)&consumeiterable_module_globals,
};
MP_REGISTER_MODULE(MP_QSTR_consumeiterable, consumeiterable_user_cmodule, MODULE_CONSUMEITERABLE_ENABLED);

8
consumeiterable/micropython.mk

@ -0,0 +1,8 @@
USERMODULES_DIR := $(USERMOD_DIR)
# Add all C files to SRC_USERMOD.
SRC_USERMOD += $(USERMODULES_DIR)/consumeiterable.c
# We can add our module folder to include paths if needed
# This is not actually needed in this example.
CFLAGS_USERMOD += -I$(USERMODULES_DIR)

247
docs/developing_micropython.ipynb

@ -1058,12 +1058,41 @@
"\n",
"## Iterating over built-in types\n",
"\n",
"In order to demonstrate the use of an iterator, we are going to write a function that sums the square of the values in an iterable. The python version of the function could be something like this: \n",
"\n",
"```python\n",
"In order to demonstrate the use of an iterator, we are going to write a function that sums the square of the values in an iterable. The python version of the function could be something like this: "
]
},
{
"cell_type": "code",
"execution_count": 11,
"metadata": {
"ExecuteTime": {
"end_time": "2019-07-18T05:30:14.184248Z",
"start_time": "2019-07-18T05:30:14.172333Z"
}
},
"outputs": [
{
"data": {
"text/plain": [
"30"
]
},
"execution_count": 11,
"metadata": {},
"output_type": "execute_result"
}
],
"source": [
"def sumsq(some_iterable):\n",
" return sum([item**2 for item in some_iterable])\n",
"```\n",
"\n",
"sumsq([1, 2, 3, 4])"
]
},
{
"cell_type": "markdown",
"metadata": {},
"source": [
"In C, the key is in the snippet\n",
"\n",
"```c\n",
@ -1073,7 +1102,7 @@
" // do something with the item just retrieved\n",
"}\n",
"```\n",
"This is more or less the equivalent of the `for item in iterable` instruction. In C, the `mp_obj_t` object `o_in` is the argument of our python function, which is turned into an iterable by passing it into the `mp_getiter` function. This function also needs a buffer object that is of type `mp_obj_iter_buf_t`. The buffer type is defined in `obj.h` as \n",
"This is more or less the equivalent of the `for item in some_iterable` instruction. In C, the `mp_obj_t` object `o_in` is the argument of our python function, which is turned into an iterable by passing it into the `mp_getiter` function. This function also needs a buffer object that is of type `mp_obj_iter_buf_t`. The buffer type is defined in `obj.h` as \n",
"\n",
"```c\n",
"typedef struct _mp_obj_iter_buf_t {\n",
@ -1097,7 +1126,7 @@
"\n",
"construct, or you can inspect the type of the variable at the C level. Unfortunately, there does not seem to be a type identifier for iterables in general, so you have to check, whether the argument is a list, tuple, range, etc. This can be done by calling the `MP_OBJ_IS_TYPE` macro, and see which Boolean it returns, if you pass `&mp_type_tuple`, `&mp_type_list`, `&mp_type_range` etc. to it, as we discussed in the section Object representation. \n",
"\n",
"The complete code listing of `iterables.c` follows below. Quite frankly, this is a lot of code to replace a single-line python function."
"The complete code listing of `consumeiterable.c` follows below. If you ask me, this is a lot of code just to replace a single-line python function."
]
},
{
@ -1137,6 +1166,84 @@
"```"
]
},
{
"cell_type": "markdown",
"metadata": {},
"source": [
"## Returning iterables\n",
"\n",
"Let us suppose that the result of some operation is an iterable, e.g., a tuple, or a list. How would we return such an object? How about a function that returns the powers of its argument? In python"
]
},
{
"cell_type": "code",
"execution_count": 9,
"metadata": {
"ExecuteTime": {
"end_time": "2019-07-18T05:28:14.059085Z",
"start_time": "2019-07-18T05:28:14.050803Z"
}
},
"outputs": [
{
"data": {
"text/plain": [
"[1, 2, 4, 8, 16, 32, 64, 128, 256, 512, 1024]"
]
},
"execution_count": 9,
"metadata": {},
"output_type": "execute_result"
}
],
"source": [
"def powerit(base, exponent):\n",
" return [base**e for e in range(0, exponent+1)]\n",
"\n",
"powerit(2, 10)"
]
},
{
"cell_type": "markdown",
"metadata": {},
"source": [
"and in C, `returniterable.c`, \n",
"```c\n",
"#include \"py/obj.h\"\n",
"#include \"py/runtime.h\"\n",
"\n",
"STATIC mp_obj_t powers_iterable(mp_obj_t base, mp_obj_t exponent) {\n",
"\tint e = mp_obj_get_int(exponent);\n",
"\tmp_obj_t tuple[e+1];\n",
"\tint b = mp_obj_get_int(base), ba = 1;\n",
"\tfor(int i=0; i <= e; i++) {\n",
"\t\ttuple[i] = mp_obj_new_int(ba);\n",
"\t\tba *= b;\n",
"\t}\n",
"\treturn mp_obj_new_tuple(e+1, tuple);\n",
"}\n",
"\n",
"STATIC MP_DEFINE_CONST_FUN_OBJ_2(powers_iterable_obj, powers_iterable);\n",
"\n",
"STATIC const mp_rom_map_elem_t returniterable_module_globals_table[] = {\n",
" { MP_ROM_QSTR(MP_QSTR___name__), MP_ROM_QSTR(MP_QSTR_returniterable) },\n",
" { MP_ROM_QSTR(MP_QSTR_powers), MP_ROM_PTR(&powers_iterable_obj) },\n",
"};\n",
"STATIC MP_DEFINE_CONST_DICT(returniterable_module_globals, returniterable_module_globals_table);\n",
"\n",
"const mp_obj_module_t returniterable_user_cmodule = {\n",
" .base = { &mp_type_module },\n",
" .globals = (mp_obj_dict_t*)&returniterable_module_globals,\n",
"};\n",
"\n",
"MP_REGISTER_MODULE(MP_QSTR_returniterable, returniterable_user_cmodule, MODULE_RETURNITERABLE_ENABLED);\n",
"```\n",
"\n",
"As everything else, the elements of tuples and lists are objects of type `mp_obj_t`, so, after finding out how far we have got to go with the exponents, we declare an array of the required length. Values are generated and assigned in the while loop. Since on the left hand side of the assignment we have an `mp_obj_t`, we convert the results with `mp_obj_new_int`. Once we are done with the computations, we return the array with `mp_obj_new_tuple`. This functions takes the array as the second argument, while the first argument specifies the length. \n",
"\n",
"If you happen to want to return a list instead of a tuple, all you have to do is use `mp_obj_new_list` instead at the very end. "
]
},
{
"cell_type": "markdown",
"metadata": {},
@ -1166,13 +1273,22 @@
"source": [
"# Profiling\n",
"\n",
"There are times, when you might want to find out how long a particular operation takes. If you are interested in the execution time of a complete function, you can measure it simply by making use of the python interpreter\n",
"There are times, when you might want to find out what resources (time and RAM) a particular operation requires. Not because you are nosy, but because the resources of a microcontroller are limited, therefore, if you are out of luck, the desired operation might not even fit within the constraints of the chip. In order to locate the bottleneck, you will need to do a bit of profiling. Or perhaps, a lot. This is what we are going to discuss now. \n",
"\n",
"Since you are not going to face serious difficulties when running micropython on a computer, profiling makes really sense only in the context of the microcontroller, so this might be a golden opportunity to brush up on how the firmware has to be compiled and uploaded. It is not by accident that we spent some time on this at the very beginning of this document. \n",
"\n",
"\n",
"## Profiling in python\n",
"\n",
"### Measuring time\n",
"\n",
"If you are interested in the execution time of a complete function, you can measure it simply by making use of the python interpreter\n",
"\n",
"```python\n",
"\n",
"from utime import ticks_us, diff_ticks\n",
"\n",
"now = ticks_us\n",
"now = ticks_us()\n",
"run_my_function()\n",
"then = diff_ticks(ticks_us(), now)\n",
"\n",
@ -1180,9 +1296,13 @@
"\n",
"```\n",
"\n",
"In fact, since our function is flanked by two other statements, this construct easily lends itself to a decorator implementation. \n",
"In fact, since our function is flanked by two other statements, this construct easily lends itself to a decorator implementation, as in (taken from ...)\n",
"\n",
"```python\n",
"```\n",
"\n",
"\n",
"(If you need an even better estimate, you can yank run_my_function(): in this way, you would get the costs of measuring time itself:\n",
"(If you need an even better estimate, you can get the ticks twice, and yank run_my_function() in the second pass: in this way, you would get the cost of measuring time itself:\n",
"\n",
"```python\n",
"\n",
@ -1194,15 +1314,105 @@
"print(\"the time measurement took %d us\"%then)\n",
"\n",
"```\n",
"Then you subtract the results of the second measurement from those of the first.)"
"Then you subtract the results of the second measurement from those of the first.)\n",
"\n",
"\n",
"### The memory cost of a function\n",
"\n",
"While time is money, RAM is gold. We shouldn't pass up on that! The `micropython` has a very handy function for \n",
"printing a pretty summary of the state of the RAM. You would call it like \n",
"\n",
"```python\n",
"import micropython\n",
"\n",
"micropyton.mem_info()\n",
"```\n",
"which will give you something like this\n",
"\n",
"```python\n",
"mem: total=5748, current=1858, peak=3451\n",
"stack: 928 out of 80000\n",
"GC: total: 2072832, used: 2528, free: 2070304\n",
" No. of 1-blocks: 61, 2-blocks: 4, max blk sz: 6, max free sz: 64686\n",
"```\n",
"If you call `mem_info()` after you executed your function, but before calling the garbage collector (if that is enabled, that is), then from the two reports, you can figure out how many bytes the function has eaten. "
]
},
{
"cell_type": "code",
"execution_count": null,
"cell_type": "markdown",
"metadata": {},
"outputs": [],
"source": []
"source": [
"## Profiling in C\n",
"\n",
"With the profiling method above we can measure the cost of a complete function only, but we cannot say anything about individual instructions in the body. Execution time is definitely a significant issue, but even worse is the problem of RAM: it might happen that the function allocates a huge amount of memory, but cleans up properly before returning. Such a function would certainly wreak havoc, even if it is rather inocuous-looking from the outside. So, what do we do? We should probably just measure. It is not going to hurt. \n",
"\n",
"In the example below (`profiling.c`), I discuss both time and RAM measurements in a single module, because splitting them wouldn't be worth the trouble. The function whose behaviour we inspect does nothing, but calculate the length of a three-dimensional vector. With that, we can figure out, how much the assignment, and how much the actual calculation cost. "
]
},
{
"cell_type": "markdown",
"metadata": {},
"source": [
"```c\n",
"#include <math.h>\n",
"#include <stdio.h>\n",
"#include \"py/obj.h\"\n",
"#include \"py/runtime.h\"\n",
"#include \"mphalport.h\" // needed for mp_hal_ticks_cpu()\n",
"#include \"py/builtin.h\" // needed for mp_micropython_mem_info()\n",
"\n",
"STATIC mp_obj_t measure_cpu(mp_obj_t _x, mp_obj_t _y, mp_obj_t _z) {\n",
"\t// first, measure the time taken up by the assignments\n",
"\tmp_uint_t start = mp_hal_ticks_cpu();\n",
"\tfloat x = mp_obj_get_float(_x);\n",
"\tfloat y = mp_obj_get_float(_y);\n",
"\tfloat z = mp_obj_get_float(_z);\n",
"\tmp_uint_t stop = mp_hal_ticks_cpu();\n",
"\tprintf(\"time elapsed: %ld CPU cycles\\n\", stop - start);\n",
"\tmp_micropython_mem_info(0, NULL);\n",
"\t\n",
"\t// measure the time used by the square root\n",
"\tstart = mp_hal_ticks_cpu();\n",
"\tfloat hypo = sqrtf(x*x + y*y + z*z);\n",
"\tstop = mp_hal_ticks_cpu();\n",
"\tprintf(\"time elapsed: %ld CPU cycles\\n\", stop - start);\t\n",
"\tmp_micropython_mem_info(0, NULL);\n",
"\treturn mp_obj_new_float(hypo);\n",
"}\n",
"\n",
"STATIC MP_DEFINE_CONST_FUN_OBJ_3(measure_cpu_obj, measure_cpu);\n",
"\n",
"STATIC const mp_rom_map_elem_t profiling_module_globals_table[] = {\n",
" { MP_ROM_QSTR(MP_QSTR___name__), MP_ROM_QSTR(MP_QSTR_profiling) },\n",
" { MP_ROM_QSTR(MP_QSTR_measure), MP_ROM_PTR(&measure_cpu_obj) },\n",
"};\n",
"STATIC MP_DEFINE_CONST_DICT(profiling_module_globals, profiling_module_globals_table);\n",
"\n",
"const mp_obj_module_t profiling_user_cmodule = {\n",
" .base = { &mp_type_module },\n",
" .globals = (mp_obj_dict_t*)&profiling_module_globals,\n",
"};\n",
"\n",
"MP_REGISTER_MODULE(MP_QSTR_profiling, profiling_user_cmodule, MODULE_PROFILING_ENABLED);\n",
"```"
]
},
{
"cell_type": "markdown",
"metadata": {},
"source": [
"The above-mentioned `mem_info()` function of the micropython module can directly be called from C: after including the `builtin.h` header, we can issue `mp_micropython_mem_info(0, NULL);`, which will print"
]
},
{
"cell_type": "markdown",
"metadata": {},
"source": [
"```bash\n",
"make BOARD=PYBV11 USER_C_MODULES=../../../usermod/ all\n",
"python ../../tools/pydfu.py -u build-PYBV11/firmware.dfu \n",
"```"
]
}
],
"metadata": {
@ -1232,7 +1442,12 @@
"title_cell": "Table of Contents",
"title_sidebar": "Contents",
"toc_cell": false,
"toc_position": {},
"toc_position": {
"height": "calc(100% - 180px)",
"left": "10px",
"top": "150px",
"width": "383px"
},
"toc_section_display": true,
"toc_window_display": true
}

9
profiling/profiling.c

@ -2,7 +2,8 @@
#include <stdio.h>
#include "py/obj.h"
#include "py/runtime.h"
#include "mphalport.h"
#include "mphalport.h" // needed for mp_hal_ticks_cpu()
#include "py/builtin.h" // needed for mp_micropython_mem_info()
STATIC mp_obj_t measure_cpu(mp_obj_t _x, mp_obj_t _y, mp_obj_t _z) {
// first, measure the time taken up by the assignments
@ -11,13 +12,15 @@ STATIC mp_obj_t measure_cpu(mp_obj_t _x, mp_obj_t _y, mp_obj_t _z) {
float y = mp_obj_get_float(_y);
float z = mp_obj_get_float(_z);
mp_uint_t stop = mp_hal_ticks_cpu();
printf("time elapsed: %d CPU cycles\n", stop - start);
printf("time elapsed: %ld CPU cycles\n", stop - start);
mp_micropython_mem_info(0, NULL);
// measure the time used by the square root
start = mp_hal_ticks_cpu();
float hypo = sqrtf(x*x + y*y + z*z);
stop = mp_hal_ticks_cpu();
printf("time elapsed: %d CPU cycles\n", stop - start);
printf("time elapsed: %ld CPU cycles\n", stop - start);
mp_micropython_mem_info(0, NULL);
return mp_obj_new_float(hypo);
}

8
returniterable/micropython.mk

@ -0,0 +1,8 @@
USERMODULES_DIR := $(USERMOD_DIR)
# Add all C files to SRC_USERMOD.
SRC_USERMOD += $(USERMODULES_DIR)/returniterable.c
# We can add our module folder to include paths if needed
# This is not actually needed in this example.
CFLAGS_USERMOD += -I$(USERMODULES_DIR)

28
returniterable/returniterable.c

@ -0,0 +1,28 @@
#include "py/obj.h"
#include "py/runtime.h"
STATIC mp_obj_t powers_iterable(mp_obj_t base, mp_obj_t exponent) {
int e = mp_obj_get_int(exponent);
mp_obj_t tuple[e+1];
int b = mp_obj_get_int(base), ba = 1;
for(int i=0; i <= e; i++) {
tuple[i] = mp_obj_new_int(ba);
ba *= b;
}
return mp_obj_new_tuple(e+1, tuple);
}
STATIC MP_DEFINE_CONST_FUN_OBJ_2(powers_iterable_obj, powers_iterable);
STATIC const mp_rom_map_elem_t returniterable_module_globals_table[] = {
{ MP_ROM_QSTR(MP_QSTR___name__), MP_ROM_QSTR(MP_QSTR_returniterable) },
{ MP_ROM_QSTR(MP_QSTR_powers), MP_ROM_PTR(&powers_iterable_obj) },
};
STATIC MP_DEFINE_CONST_DICT(returniterable_module_globals, returniterable_module_globals_table);
const mp_obj_module_t returniterable_user_cmodule = {
.base = { &mp_type_module },
.globals = (mp_obj_dict_t*)&returniterable_module_globals,
};
MP_REGISTER_MODULE(MP_QSTR_returniterable, returniterable_user_cmodule, MODULE_RETURNITERABLE_ENABLED);
Loading…
Cancel
Save