In this document we would like to describe how to debug OP-TEE. Depending on the platform you are using you will have a couple of different options.
To debug OP-TEE when using QEMU you could use gdb as the main debugger. Using
this setup will also make it possible to use some frontends for gdb if you don't
feel comfortable using a command line debugging tool.
Since there are inter-dependencies between the gits used when building OP-TEE, we recommend that you have been following the guide as described in README.md.
# Root folder for the project
$HOME/devel/opteeIf you've followed the instructions until here, then you should have the toolchains already in
$HOME/devel/optee/toolchainsA few helper scripts that makes life easier.
Start by creating $HOME/.gdbinit and add:
set print array on
set print pretty on
define optee
handle SIGTRAP noprint nostop pass
symbol-file $HOME/devel/optee/optee_os/out/arm/core/tee.elf
target remote localhost:1234
end
document optee
Loads and setup the binary (tee.elf) for OP-TEE and also connects to the QEMU
remote.
end
Now you are good to go for doing debugging using command line.
Start QEMU according to the instructions in QEMU ARMv7-A, however, do
not start the emulation, i.e. do not type the c command in QEMU. The main
reason for not doing so is because you cannot set the breakpoints on secure side
when when kernel has booted up (if anyone knows why, please let us now about it,
we haven't investigated it) and then in another shell start gdb like this:
$ $HOME/devel/optee/toolchains/aarch32/bin/arm-linux-gnueabihf-gdb -q
To connect to the remote and to load the tee.elf, simply type:
(gdb) optee
SIGTRAP is used by the debugger.
Are you sure you want to change it? (y or n) [answered Y; input not from
terminal]
0x00000000 in ?? ()
Now it is time to set the breakpoints. For example
(gdb) b tee_entry_std
Breakpoint 1 at 0x7df0c7be: file core/arch/arm/tee/entry_std.c, line 268.
and then start the execution by writing the continue command in gdb.
(gdb) c
Continuing.
When the driver has been loaded and you start using OP-TEE the breakpoint will trigger, which will look something like this:
Breakpoint 1, tee_entry_std (smc_args=0x7df6ff98 <stack_thread+8216>)
at core/arch/arm/tee/entry_std.c:268
268 struct optee_msg_arg *arg = NULL;
(gdb)
With the PATH exported to the arm-none-eabi-gdb binary and the optee
helper function defined as above in the .gdbinit file, you invoke ddd by
typing:
ddd --debugger arm-none-eabi-gdb
Then in the lower pane (which is the gdb command window), just simply type
optee and ddd will connect to the remote and load tee.elf, just as described
above for the command line version.
1.5.2 GNU Visual Debugger (gvd)
This is a rather old frontend for gdb and share a lot of similarities with ddd,
however it seems like it's more stable compared to ddd. To run it, you simply
need to tell the path to the arm-none-eabi-gdb binary:
gvd --debugger $HOME/devel/toolchains/gcc-linaro-arm-none-eabi-4.9-2014.09_linux/bin/arm-none-eabi-gdb
Similarly to ddd, just simply run optee in the lower gdb command pane in gvd.
Affinic Debugger seems to be the most stable graphical front end. It's not free (at this moment it costs roughly $50 USD). If you can afford it and prefer graphical frontends we highly recommend this tool.
Ftrace is useful set of tools for debugging both kernel and to some extent user space. Ftrace is really useful if you want to learn how some piece of code interact with other parts of the system. It's nothing special you have to do to make use of ftrace for OP-TEE. But for a reference we list a couple of commands and scenarios that could be handy to have ready to be copy/pasted.
First you will need to enable ftrace in the kernel. Depending on which version
you are using it might look a bit different compared to what is shown below
(here we were using 4.1.0-rc4)
make ARCH=arm menuconfig
# Go into "Kernel hacking"
General setup --->
...
Kernel hacking --->
# Enable and go into Tracers
...
[*] Tracers --->
# Below is a good set of features (*) to enable
--- Tracers
-*- Kernel Function Tracer
[*] Kernel Function Graph Tracer
[ ] Interrupts-off Latency Tracer
[ ] Scheduling Latency Tracer
[*] Trace syscalls
[ ] Create a snapshot trace buffer
Branch Profiling (No branch profiling) --->
[*] Trace max stack
[ ] Support for tracing block IO actions
[ ] Enable uprobes-based dynamic events
[*] enable/disable function tracing dynamically
[*] Kernel function profiler
[ ] Perform a startup test on ftrace
[ ] Add tracepoint that benchmarks tracepoints
< > Ring buffer benchmark stress tester
[ ] Ring buffer startup self test
[ ] Show enum mappings for trace events
Then simply recompile the kernel.
$ modprobe optee_armtz
$ cd /sys/kernel/debug/tracing
$ echo ':mod:optee' > set_ftrace_filter
$ echo ':mod:optee_armtz' >> set_ftrace_filterUsing the commands below will enable function profiling for the functions
currently mentioned in the set_ftrace_filter
$ echo "function" > current_tracer
$ echo "1" > function_profile_enabledIf you now run xtest for example, then when done you can get profiling data
by reading the content of the files in /sys/kernel/debug/tracing/trace_stat
$ cat trace_stat/function0
$ cat trace_stat/function1
...The result will look something like this:
Function Hit Time Avg s^2
-------- --- ---- --- ---
call_tee.isra.13 13499 55772240 us 4131.583 us 1537657 us
tee_session_ioctl 11330 54380860 us 4799.722 us 35403.79 us
tee_session_invoke_be 11330 54330744 us 4795.299 us 162939.5 us
tz_invoke 11330 54014297 us 4767.369 us 573472.7 us
tee_ioctl 1139 2893849 us 2540.692 us 2841179 us
tee_session_create_fd 1135 2889859 us 2546.131 us 2615175 us
...
# Print also the core number in the log
$ for core in `seq 0 7`; do echo core: $core; cat trace_stat/function$core; done# The functions that are called mostly:
$ cat trace_stat/function0 | sort -nk2 -r | less# The functions taking most time:
$ cat trace_stat/function0 | sort -nk5 -r | lessThe function_graph will give you the call flow and also tell you the amount of time spent in the functions. There are ways to turn of sleep time and not count time spent when calling other functions. Let us say that your are interested in knowing how much various open, invoke and close and the call_tee command takes, then you can do like this:
$ echo "tz_open" > set_ftrace_filter
$ echo "tz_close" >> set_ftrace_filter
$ echo "tz_invoke" >> set_ftrace_filter
$ echo "call_tee*" >> set_ftrace_filter
# Don't count the time if you are being schduled out
$ echo 0 > options/sleep-time
# Enable the function_graph tracer
$ echo "function_graph" > current_tracerNow if you run xtest and then done, read the contents of trace, you will see
something like this:
# CPU DURATION FUNCTION CALLS
# | | | | | | |
2) | tz_open [optee_armtz]() {
2) ! 3145.834 us | call_tee.isra.13 [optee_armtz]();
2) ! 3222.500 us | }
2) | tz_invoke [optee_armtz]() {
2) ! 125.833 us | call_tee.isra.13 [optee_armtz]();
2) ! 166.667 us | }
2) | tz_invoke [optee_armtz]() {
2) ! 135.833 us | call_tee.isra.13 [optee_armtz]();
2) ! 170.833 us | }
2) | tz_invoke [optee_armtz]() {
2) ! 153.334 us | call_tee.isra.13 [optee_armtz]();
2) ! 186.667 us | }
...
If you don't want to count the time when being scheduled out, then run:
$ echo 0 > options/sleep-timeIf you only want to measure the time spent in the function, then disable the graph-time.
$ echo 0 > options/graph-time- Printing the call stack using
btmakes gdb go into an endless loop. Temporary workaround, in gdb, instead of simply writingbt, also mention how many frames you would like to see, for examplebt 10. - Cannot set breakpoints when the system is up and running. Workaround, set the breakpoints before booting up the system.