7. Benchmarking ExecuTorch
In this section we will look at how we can verify that ExecuTorch is producing the expected results, and then how to benchmark its performance.
7.1. Overview of how to benchmark ExecuTorch
There are two aspects to ExecuTorch performance. The first is a fixed cost of just bringing up ExecuTorch. Some of this is independent of the choice of model—including zeroing BSS memory, initializing operators and setting up the memory allocation system. Some is a one-off cost dependent on the model—including reading and parsing the model.
The remainder is the dynamic cost, dependent on the model and the size of data it is processing. This is typically the cost we care about, because we may load an initialize a model once, but execute it many times.
The dynamic cost for a model is typically found by running the same model with different sizes of data. This allows us to measure the per-element cost of the model, and hence determine how performance will scale.
The total fixed cost can be determined by projecting the dynamic cost backwards to determine the time taken if the data had zero size. Some of the fixed costs can also be measured by differential approach. For example measuring the time to execute the identical model with different size buffers gives a good measure of the time spent zeroing BSS, since this is completely dominated by the two buffers.
More detailed timing analysis requires full performance profiling using tools such as gprof, and extracting performance data from a Verilator model trace. This is not covered in this application note.
7.2. Files to be changed
Before we get into the detail of benchmarking, we will need to look at how we
set the inputs and read the outputs when executing the model. The changes to
the executorch repository described here can be found in the commit tagged
ean16-1.0-benchmarking. It can be selected using
git switch --detach ean16-1.0-benchmarking
The only file we are going to modify is the runtime driver.
examples/corev/executor_runner/corev_executor_runner.cpp
We will extend it to set up input data and to print out result data.
7.3. Modifying the ExecuTorch runtime for benchmarking
7.3.1. Updating the runtime driver
The driver code is in
examples/corev/executor_runner/corev_executor_runner.cpp. We are going to
need to understand the format of tensors, we will need the
appropriate header.
using executorch::runtime::MemoryManager;
using executorch::runtime::Method;
using executorch::runtime::MethodMeta;
using executorch::runtime::Program;
The next step is to set up explicit input data. We are going to use the
add8 model for benchmarking, so we will set up data with values from 0
through 127. This means that when the tensors are added, we will
have values from 0 through 254 in the output vector.
We set the data using the executorch::extension::prepare_input_tensors
function. Originally we just passed in the method to be executed, and it
populated the tensor with constant 1 in each element.
auto inputs = executorch::extension::prepare_input_tensors(*method);
However this function has two optional arguments. The first of these is some
options to control initialization, primarily to ensure the memory is not
exhausted. However the second is a vector of buffers to be used to initialize
each input argument. Each element of the vector is a std::pair of: i) a
pointer to a byte array of raw input data; and ii) the size of the byte array.
We can use this argument to create a set of values. The original line of code is replaced by the following.
auto isz = method_meta->input_tensor_meta(0)->sizes()[0];
char *arr1 = new char[isz];
char *arr2 = new char[isz];
for (size_t i = 0; i < isz; i++) {
arr1[i] = i % 128;
arr2[i] = i % 128;
}
auto inputs = executorch::extension::prepare_input_tensors(
*method, {}, {{arr1, isz}, {arr2, isz}});
Note
We have kept this simple here as a demonstration. We do not check that the tensor is of 8-bit integers, and we do not check that it is one dimensional. However all this information is in the meta data, and we could do the check.
In order to verify that the model is working correctly, we need to print out
the data. As discussed previously, we cannot use the logging infrastructure
on such a small target, so we use printf instead (see
Running the ExecuTorch runtime on the Verilator model).
// Print the outputs. Change the #if 0 to enable this.
#if 0
std::vector<EValue> outputs(method->outputs_size());
ET_LOG(Info, "%zu outputs: ", outputs.size());
Error status = method->get_outputs(outputs.data(), outputs.size());
Tensor& ot = outputs.data()[0].toTensor();
const uint8_t * res = static_cast<const uint8_t *>(ot.const_data_ptr());
for(int i = 0; i < ot.numel(); i++)
printf("res[%d] = %d\n", i, res[i]);
ET_CHECK(status == Error::Ok);
#endif
In general we don’t want to print results when benchmarking, because the
execution time will be dominated by printf. So we surround the code by
#if 0 and #endif. For runs where we want to print results, we edit
the code to #if 1 before compiling.
7.3.2. Building and running to verify results
If the add8 model has not been built, we rebuild it from the
executorch repository.
python3 -m examples.corev.aot_corev_compiler --delegate \
--model_name="add8" -o="model.pte"
We edit the conditional code for output to #if 1 and rebuild from the
tooling repository.
./build-executorch-runtime.sh
We can then invoke the model as before.
../core-v-verif/cv32e40p/sim/core/cobj_dir/Vtb_top_verilator \
+firmware=../install/executor_runner.hex
Now we can see the output.
scopesDump:
SCOPE 0x73d683dffac0: TOP.tb_top_verilator
SCOPE 0x73d683dffaf8: TOP.tb_top_verilator.cv32e40p_core_tb_wrapper_i.ram_i
SCOPE 0x73d683dffb30: TOP.tb_top_verilator.cv32e40p_core_tb_wrapper_i.ram_i.dp_ram_i
DPI-EXPORT 0x6393ee1377e0: read_byte
DPI-EXPORT 0x6393ee1377f0: write_byte
[tb_top_verilator] finished dumping memory
Model executed successfully 1 time(s).
res[0] = 0
res[1] = 2
res[2] = 4
res[3] = 6
And looking at the end
res[1020] = 248
res[1021] = 250
res[1022] = 252
res[1023] = 254
TOP.tb_top_verilator @ 138615220: EXIT SUCCESS
- /home/jeremy/gittrees/executorch-corev/core-v-verif/cv32e40p/tb/core/tb_top_verilator.sv:83: Verilog $finish
Given that we set each input value to the index modulo 128, these are the
correct results. So our delegated code looks good. We can revert the #if
1 back to #if 0 and rebuild, to get a model suitable for benchmarking.
7.4. Benchmarking ExecuTorch
We can now use our model to explore the performance of the model and determine how much we gain from our custom delegation.
We will explore two questions
What are the fixed and dynamic costs of our two models (
addandadd8).What is the speedup due to delegation.
7.4.1. Fixed and dynamic costs of the add model
As noted earlier (see Running the ExecuTorch runtime on the Verilator model), we can extract a cycle count, and hence execution time from the Verilator model termination message.
7.4.1.1. Measuring dynamic cost by running the model multiple times
In order to separate out fixed and dynamic costs (i.e. execution time) for the
model, we need two runs. In one, we increase the value of
FLAGS_num_executions in
examples/corev/executor_runner/corev_executor_runner.cpp, so that the
evaluation of the model is repeated. We know that these repeat runs will
only be setting up the input data and then executing the model, so we can use
the difference to work out the dynamic cost. For the baseline we get
Model executed successfully 1 time(s).
TOP.tb_top_verilator @ 113333120: EXIT SUCCESS
- /home/jeremy/gittrees/ean16/core-v-verif/cv32e40p/tb/core/tb_top_verilator.sv:83: Verilog $finish
While if we increase FLAGS_num_executions to 11, we get
Model executed successfully 11 time(s).
TOP.tb_top_verilator @ 114753540: EXIT SUCCESS
- /home/jeremy/gittrees/ean16/core-v-verif/cv32e40p/tb/core/tb_top_verilator.sv:83: Verilog $finish
Summarizing the performance.
# runs |
1 |
11 |
Verilator time |
113,333,120 |
114,753,540 |
Cycles |
11,333,312 |
11,475,354 |
Time @ 400MHz |
28.33 ms |
28.69 ms |
We can then subtract to work out the dynamic cost.
Increment for 10 runs |
355.1 μs |
Increment for 1 run |
35.5 μs |
Time per element @ 400MHz |
7.1 μs |
At 400 MHz, 7.1 μs is over 2,800 instructions, which seems quite high to add two 32-bit floating point instructions. In the next section we shall show how to get more insight into the cost of the operation for each element.
We can also see that the overall runtime is dominated by the fixed cost. In the original run, which took 28.33 ms, 28.30ms is fixed overhead. We can see how much of this is due to BSS initialization of the buffers, by changing the size of the buffers (see Breaking down the fixed cost of a model).
7.4.1.2. Measuring dynamic cost by varying the model size
An alternative approach is to compare runs with models of different sizes. The following table shows the time taken to run models with vectors of size 1 through 10 elements.
Vector size |
Cycles |
Time @ 400 MHz |
Incremental time |
|---|---|---|---|
1 |
11,327,856 |
28.32ms |
|
2 |
11,329,178 |
28.32 ms |
3.3 μs |
3 |
11,330,415 |
28.33 ms |
3.1 μs |
4 |
11,331,668 |
28.33 ms |
3.1 μs |
5 |
11,333,312 |
28.33 ms |
4.1 μs |
6 |
11,334,522 |
28.34 ms |
3.0 μs |
7 |
11,335,734 |
28.34 ms |
3.0 μs |
8 |
11,336,944 |
28.134ms |
3.0 μs |
9 |
11,338,588 |
28.35 ms |
4.1 μs |
10 |
11,339,798 |
28.35 ms |
3.0 μs |
Now this is interesting. We can see performance variation, likely due to alignment as sizes change. But on average the cost is around 3.3 μs per element.
So how do we reconcile this with the 7.0 μs per element we found in the previous approach1
The question is, what is the time for the first element. The previous approach had a time estimate of 7.1 μs per element, or 35.5 μs for a 5 element vector. From the table above, we can see that elements 2 through 5 took around 13.6 μs. This suggests that there is a first element cost of starting the operation of around 21.9 μs.
It was clear that 28.33 ms for 5 floating point additions seemed far too high. We can see that after the first element, we are using an average 3.3 μs per element. However at 400 MHz, that is still over 1,300 cycles. Again this seems very high to load and add two float32 values, even with floating point emulation. We’ll dig into this more later (see Fixed and dynamic costs of the add8 model).
In the next section we will look at how to break down some of the fixed cost of a model
7.4.1.3. Breaking down the fixed cost of a model
Detailed performance breakdown requires profiling, but we can use differential
measurements to estimate the time spent spent zeroing BSS. It would
be tempting to see the total amount of BSS using the size command on
the ExecuTorch runtime executable. However this command determines
BSS as any section in the binary that has just the ALLOC flag set,
so also includes the stack, heap and debugger stack, none of which will be
zeroed as BSS.
Instead, we can look in the binary for the symbols defining the start and end of the BSS using the nm command.
From the
toolingrepository.
$ riscv32-corev-elf-nm ../install/executor_runner | grep bss
002fa18c B __bss_end
001b3e24 B __bss_start
Subtracting the start from the end, we see we have 0x146368 bytes of
BSS. We know that we have a method buffer of 1MiB (0x100000
bytes) and a temporary buffer of 256kiB (0x40000 bytes), so there is just
0x6368 (decimal 25,448) bytes of other BSS. Thus the size of the
method and temporary buffers completely dominates BSS.
We already know the time taken to run the standard model. We can rebuild, but
editing examples/corev/executor_runner/corev_executor_runner.cpp to halve
the size of the buffers. After rebuilding, the size of BSS is
reduced.
$ riscv32-corev-elf-nm ../install/executor_runner | grep bss
0025a18c B __bss_end
001b3e24 B __bss_start
The difference is now 0xA6368 bytes. As expected we now have 640kiB
(0xA0000) bytes of buffers in total and the same 0x6368 (decimal
25,444) bytes of other BSS.
When we run the model, it has a shorter runtime
Model executed successfully 1 time(s).
TOP.tb_top_verilator @ 67457920: EXIT SUCCESS
- /home/jeremy/gittrees/ean16/core-v-verif/cv32e40p/tb/core/tb_top_verilator.sv:83: Verilog $finish
The difference corresponds to the time taken to zero the 640kiB that is not in the smaller buffer model. Tabulating the results, we can see how much time is used by BSS.
Normal buffers |
Small buffers |
Difference |
|
|---|---|---|---|
Size of BSS (bytes) |
1,336,168 |
680,808 |
655,360 |
Cycles |
11,333,312 |
6,745,792 |
4,587,520 |
Time @ 400 MHz |
28.33 ms |
16.86 ms |
11.47 ms |
Time/byte |
17.5 ns |
||
23.38 ms |
The key result is that on the original run, 23.38ms (83%) of the execution time is zeroing the BSS. This is a one off cost that will be the same for all models. For larger models it will cease to be significant. BSS is zeroed in a tight assembly language loop, so 5 cycles per byte seems reasonable. Potentially this could be done faster, depending on the architecture of the specific device.
Of the remaining time, we then have 4.91 ms in fixed costs, and 0.0355 ms actually running the model. To break this down further really requires profiling, which is not covered by this application note.
However, we know from other work, that a large part of this is running the constructors for all the various operators which make up the Edge subset of ATen operators. One optimization is to build the ExecuTorch runtime using only those operators we are actually going to use, a technique known as selective building. This further reduces the time spent in initialization, and as a useful side effect makes the ExecuTorch runtime significantly smaller.
7.4.2. Fixed and dynamic costs of the add8 model
We can repeat all the techniques in Fixed and dynamic costs of the add model for the add8
model (all without delegation enabled at this stage). AS before, we
take the 1,024 element model and increase the value of
FLAGS_num_executions. The results are as follows…
Summarizing the performance.
# runs |
1 |
11 |
Verilator time |
123,889,310 |
12,388,931 |
Cycles |
227,605,310 |
22,760,531 |
Time @ 400MHz |
30.97 ms |
56.90 ms |
We can then subtract to work out the dynamic cost.
Increment for 10 runs |
25.93 ms |
Increment for 1 run |
2.59 ms |
Time per element @ 400MHz |
2.53 μs |
The per element time is quicker than before, because we doing 8-bit integer arithmetic.
We can also use single runs, changing the size of the vectors we use.
Vector size |
Cycles |
Time @ 400 MHz |
Incremental time |
Time per element |
|---|---|---|---|---|
4 |
11,331,598 |
28.33 ms |
||
8 |
11,335,635 |
28.34 ms |
10.1 μs |
2.5 μs |
12 |
11,339,678 |
28.35 ms |
10.1 μs |
2.5 μs |
16 |
11,343,715 |
28.36 ms |
10.1 μs |
2.5 μs |
20 |
11,348,190 |
28.37 ms |
11.2 μs |
2.8 μs |
24 |
11,352,227 |
28.38 ms |
10.1 μs |
2.5 μs |
28 |
11,356,270 |
28.39 ms |
10.1 μs |
2.5 μs |
32 |
11,360,307 |
28.40 ms |
10.1 μs |
2.5 μs |
36 |
11,364,782 |
28.41 ms |
11.2 μs |
2.8 μs |
40 |
11,368,819 |
28.42 ms |
10.1 μs |
2.5 μs |
Note
Our sizes are in multiples of 4 bytes, since we defined our algorithm to work with sizes that are multiples of 4 bytes.
Now this is interesting, since the time per element measured this way is the same as the time per element measured by repeat runs. There is no overhead on the first element. The main difference is that we are doing native arithmetic, rather than relying on floating point emulation. A point for further investigation would be whether there is an initialization cost to floating point emulation.
More generally, 2.5 μs, corresponds to 1,000 clock cycles. The initialization of values and the addition of elements can only be a few cycles, so the rest is the overhead of ExecuTorch combined with any inefficiency in generic operator implementations.
7.4.3. The impact of delegation
We now repeat the measurement with delegation enabled. These are the results measuring the time per element by carrying out multiple runs with the same model (1,024 elements in the vector).
Increment for 10 runs |
1,526 μs |
Increment for 1 run |
152.6 μs |
Time per element @ 400MHz |
0.15 μs |
The speed up is obvious. We are measuring the incremental time in microseconds rather than milliseconds.
We can also use single runs, changing the size of the vectors we use.
Vector size |
Cycles |
Time @ 400 MHz |
Incremental time |
Time per element |
|---|---|---|---|---|
4 |
11,307,431 |
28.27 ms |
||
8 |
11,307,644 |
28.27 ms |
0.53 μs |
0.13 μs |
12 |
11,307,863 |
28.27 ms |
0.55 μs |
0.14 μs |
16 |
11,308,076 |
28.27 ms |
0.53 μs |
0.13 μs |
20 |
11,308,727 |
28.27 ms |
1.63 μs |
0.41 μs |
24 |
11,308,940 |
28.27 ms |
0.53 μs |
0.13 μs |
28 |
11,309,159 |
28.27 ms |
0.55 μs |
0.14 μs |
32 |
11,309,372 |
28.27 ms |
0.53 μs |
0.13 μs |
36 |
11,310,023 |
28.28 ms |
1.63 μs |
0.41 μs |
40 |
11,310,326 |
28.28 ms |
0.53 μs |
0.13 μs |
Once again, we can see how much smaller the times are. As with the non-delegated version, the time taken is the same measured either way.
Without delegation, loading and adding a vector of 8-bit integers takes 2.5 μs, with delegation it is just 0.15 μs, a more than 16-fold speedup. With delegation we have removed a lot of overhead, but it is still 60 instructions per element, the overhead of the AI framework.
This completes the chapter on testing and benchmarking. In the next chapter we’ll explore other ways in which we can optimize ExecuTorch.