Home
last modified time | relevance | path

Searched hist:"5 c2c0fb31efbeff60960336d7438e810b825d582" (Results 1 – 5 of 5) sorted by relevance

/optee_os/scripts/
H A Dftrace_format.py5c2c0fb31efbeff60960336d7438e810b825d582 Wed Jun 14 21:55:23 UTC 2023 Jerome Forissier <jerome.forissier@linaro.org> ftrace: change implementation to use binary circular buffer

The current implementation of function tracing (CFG_FTRACE_SUPPORT)
produces human-readable text into the output buffer that is passed to
tee-supplicant and ultimately saved to the Linux filesystem. Two main
issues with that:

1. The string formatting code is somewhat complex. It introduces
significant overhead in the execution time of the instrumented
functions.
2. The various policies about how to handle a buffer full condition
(CFG_FTRACE_BUF_WHEN_FULL) are not very convenient. In particular,
"shift" is typically the most desirable option because it always
keeps the most recent entries, but it is very inefficient to the
point of not being usable in practice.

This commit addresses the above concerns by making the ftrace buffer
circular one, each entry being 64-bit value. The formatting code is
offloaded to a new Python script: scripts/ftrace_format.py. The
output is unchanged except for an added field showing the current
depth in the call stack.

Typical usage (captured on QEMUv8):

build$ mkdir -p ../tmp
build$ chmod a+w ../tmp
build$ make CFG_FTRACE_SUPPORT=y CFG_FTRACE_BUF_SIZE=15000 \
CFG_TA_MCOUNT=y CFG_ULIBS_MCOUNT=y CFG_SYSCALL_FTRACE=y \
QEMU_VIRTFS_AUTOMOUNT=y run
$ xtest regression_1004
...
$ cp /tmp/ftrace-cb3e5ba0-adf1-11e0-998b-0002a5d5c51b.out /mnt/host/tmp
build$ cd ..
optee$ optee_os/scripts/ftrace_format.py \
tmp/ftrace-cb3e5ba0-adf1-11e0-998b-0002a5d5c51b.out |
optee_os/scripts/symbolize.py \
-d optee_os/out/arm/core \
-d out-br/build/optee_test_ext-1.0/ta/*/out | less
TEE load address @ 0x5ab04000
Function graph for TA: cb3e5ba0-adf1-11e0-998b-0002a5d5c51b @ 80085000
| 1 | __ta_entry() {
| 2 | __utee_entry() {
43.840 us | 3 | ta_header_get_session()
7.216 us | 3 | tahead_get_trace_level()
14.480 us | 3 | trace_set_level()
| 3 | malloc_add_pool() {
| 4 | raw_malloc_add_pool() {
46.032 us | 5 | bpool()
| 5 | raw_realloc() {
166.256 us | 6 | bget()
23.056 us | 6 | raw_malloc_return_hook()
267.952 us | 5 | }
398.720 us | 4 | }
426.992 us | 3 | }
| 3 | TEE_GetPropertyAsU32() {
23.600 us | 4 | is_propset_pseudo_handle()
| 4 | __utee_check_instring_annotation() {
26.416 us | 5 | strlen()
| 5 | check_access() {
| 6 | TEE_CheckMemoryAccessRights() {
| 7 | _utee_check_access_rights() {
| 8 | syscall_check_access_rights() {
| 9 | ts_get_current_session() {
4.304 us | 10 | ts_get_current_session_may_fail()
10.976 us | 9 | }
| 9 | to_user_ta_ctx() {
2.496 us | 10 | is_user_ta_ctx()
8.096 us | 9 | }
| 9 | vm_check_access_rights() {
| 10 | vm_buf_is_inside_um_private() {
| 11 | core_is_buffer_inside() {
...

Signed-off-by: Jerome Forissier <jerome.forissier@linaro.org>
Acked-by: Jens Wiklander <jens.wiklander@linaro.org>
Reviewed-by: Sumit Garg <sumit.garg@linaro.org>
Acked-by: Etienne Carriere <etienne.carriere@foss.st.com>
/optee_os/ldelf/
H A Dftrace.c5c2c0fb31efbeff60960336d7438e810b825d582 Wed Jun 14 21:55:23 UTC 2023 Jerome Forissier <jerome.forissier@linaro.org> ftrace: change implementation to use binary circular buffer

The current implementation of function tracing (CFG_FTRACE_SUPPORT)
produces human-readable text into the output buffer that is passed to
tee-supplicant and ultimately saved to the Linux filesystem. Two main
issues with that:

1. The string formatting code is somewhat complex. It introduces
significant overhead in the execution time of the instrumented
functions.
2. The various policies about how to handle a buffer full condition
(CFG_FTRACE_BUF_WHEN_FULL) are not very convenient. In particular,
"shift" is typically the most desirable option because it always
keeps the most recent entries, but it is very inefficient to the
point of not being usable in practice.

This commit addresses the above concerns by making the ftrace buffer
circular one, each entry being 64-bit value. The formatting code is
offloaded to a new Python script: scripts/ftrace_format.py. The
output is unchanged except for an added field showing the current
depth in the call stack.

Typical usage (captured on QEMUv8):

build$ mkdir -p ../tmp
build$ chmod a+w ../tmp
build$ make CFG_FTRACE_SUPPORT=y CFG_FTRACE_BUF_SIZE=15000 \
CFG_TA_MCOUNT=y CFG_ULIBS_MCOUNT=y CFG_SYSCALL_FTRACE=y \
QEMU_VIRTFS_AUTOMOUNT=y run
$ xtest regression_1004
...
$ cp /tmp/ftrace-cb3e5ba0-adf1-11e0-998b-0002a5d5c51b.out /mnt/host/tmp
build$ cd ..
optee$ optee_os/scripts/ftrace_format.py \
tmp/ftrace-cb3e5ba0-adf1-11e0-998b-0002a5d5c51b.out |
optee_os/scripts/symbolize.py \
-d optee_os/out/arm/core \
-d out-br/build/optee_test_ext-1.0/ta/*/out | less
TEE load address @ 0x5ab04000
Function graph for TA: cb3e5ba0-adf1-11e0-998b-0002a5d5c51b @ 80085000
| 1 | __ta_entry() {
| 2 | __utee_entry() {
43.840 us | 3 | ta_header_get_session()
7.216 us | 3 | tahead_get_trace_level()
14.480 us | 3 | trace_set_level()
| 3 | malloc_add_pool() {
| 4 | raw_malloc_add_pool() {
46.032 us | 5 | bpool()
| 5 | raw_realloc() {
166.256 us | 6 | bget()
23.056 us | 6 | raw_malloc_return_hook()
267.952 us | 5 | }
398.720 us | 4 | }
426.992 us | 3 | }
| 3 | TEE_GetPropertyAsU32() {
23.600 us | 4 | is_propset_pseudo_handle()
| 4 | __utee_check_instring_annotation() {
26.416 us | 5 | strlen()
| 5 | check_access() {
| 6 | TEE_CheckMemoryAccessRights() {
| 7 | _utee_check_access_rights() {
| 8 | syscall_check_access_rights() {
| 9 | ts_get_current_session() {
4.304 us | 10 | ts_get_current_session_may_fail()
10.976 us | 9 | }
| 9 | to_user_ta_ctx() {
2.496 us | 10 | is_user_ta_ctx()
8.096 us | 9 | }
| 9 | vm_check_access_rights() {
| 10 | vm_buf_is_inside_um_private() {
| 11 | core_is_buffer_inside() {
...

Signed-off-by: Jerome Forissier <jerome.forissier@linaro.org>
Acked-by: Jens Wiklander <jens.wiklander@linaro.org>
Reviewed-by: Sumit Garg <sumit.garg@linaro.org>
Acked-by: Etienne Carriere <etienne.carriere@foss.st.com>
/optee_os/lib/libutils/ext/ftrace/
H A Dftrace.c5c2c0fb31efbeff60960336d7438e810b825d582 Wed Jun 14 21:55:23 UTC 2023 Jerome Forissier <jerome.forissier@linaro.org> ftrace: change implementation to use binary circular buffer

The current implementation of function tracing (CFG_FTRACE_SUPPORT)
produces human-readable text into the output buffer that is passed to
tee-supplicant and ultimately saved to the Linux filesystem. Two main
issues with that:

1. The string formatting code is somewhat complex. It introduces
significant overhead in the execution time of the instrumented
functions.
2. The various policies about how to handle a buffer full condition
(CFG_FTRACE_BUF_WHEN_FULL) are not very convenient. In particular,
"shift" is typically the most desirable option because it always
keeps the most recent entries, but it is very inefficient to the
point of not being usable in practice.

This commit addresses the above concerns by making the ftrace buffer
circular one, each entry being 64-bit value. The formatting code is
offloaded to a new Python script: scripts/ftrace_format.py. The
output is unchanged except for an added field showing the current
depth in the call stack.

Typical usage (captured on QEMUv8):

build$ mkdir -p ../tmp
build$ chmod a+w ../tmp
build$ make CFG_FTRACE_SUPPORT=y CFG_FTRACE_BUF_SIZE=15000 \
CFG_TA_MCOUNT=y CFG_ULIBS_MCOUNT=y CFG_SYSCALL_FTRACE=y \
QEMU_VIRTFS_AUTOMOUNT=y run
$ xtest regression_1004
...
$ cp /tmp/ftrace-cb3e5ba0-adf1-11e0-998b-0002a5d5c51b.out /mnt/host/tmp
build$ cd ..
optee$ optee_os/scripts/ftrace_format.py \
tmp/ftrace-cb3e5ba0-adf1-11e0-998b-0002a5d5c51b.out |
optee_os/scripts/symbolize.py \
-d optee_os/out/arm/core \
-d out-br/build/optee_test_ext-1.0/ta/*/out | less
TEE load address @ 0x5ab04000
Function graph for TA: cb3e5ba0-adf1-11e0-998b-0002a5d5c51b @ 80085000
| 1 | __ta_entry() {
| 2 | __utee_entry() {
43.840 us | 3 | ta_header_get_session()
7.216 us | 3 | tahead_get_trace_level()
14.480 us | 3 | trace_set_level()
| 3 | malloc_add_pool() {
| 4 | raw_malloc_add_pool() {
46.032 us | 5 | bpool()
| 5 | raw_realloc() {
166.256 us | 6 | bget()
23.056 us | 6 | raw_malloc_return_hook()
267.952 us | 5 | }
398.720 us | 4 | }
426.992 us | 3 | }
| 3 | TEE_GetPropertyAsU32() {
23.600 us | 4 | is_propset_pseudo_handle()
| 4 | __utee_check_instring_annotation() {
26.416 us | 5 | strlen()
| 5 | check_access() {
| 6 | TEE_CheckMemoryAccessRights() {
| 7 | _utee_check_access_rights() {
| 8 | syscall_check_access_rights() {
| 9 | ts_get_current_session() {
4.304 us | 10 | ts_get_current_session_may_fail()
10.976 us | 9 | }
| 9 | to_user_ta_ctx() {
2.496 us | 10 | is_user_ta_ctx()
8.096 us | 9 | }
| 9 | vm_check_access_rights() {
| 10 | vm_buf_is_inside_um_private() {
| 11 | core_is_buffer_inside() {
...

Signed-off-by: Jerome Forissier <jerome.forissier@linaro.org>
Acked-by: Jens Wiklander <jens.wiklander@linaro.org>
Reviewed-by: Sumit Garg <sumit.garg@linaro.org>
Acked-by: Etienne Carriere <etienne.carriere@foss.st.com>
/optee_os/lib/libutee/include/
H A Duser_ta_header.h5c2c0fb31efbeff60960336d7438e810b825d582 Wed Jun 14 21:55:23 UTC 2023 Jerome Forissier <jerome.forissier@linaro.org> ftrace: change implementation to use binary circular buffer

The current implementation of function tracing (CFG_FTRACE_SUPPORT)
produces human-readable text into the output buffer that is passed to
tee-supplicant and ultimately saved to the Linux filesystem. Two main
issues with that:

1. The string formatting code is somewhat complex. It introduces
significant overhead in the execution time of the instrumented
functions.
2. The various policies about how to handle a buffer full condition
(CFG_FTRACE_BUF_WHEN_FULL) are not very convenient. In particular,
"shift" is typically the most desirable option because it always
keeps the most recent entries, but it is very inefficient to the
point of not being usable in practice.

This commit addresses the above concerns by making the ftrace buffer
circular one, each entry being 64-bit value. The formatting code is
offloaded to a new Python script: scripts/ftrace_format.py. The
output is unchanged except for an added field showing the current
depth in the call stack.

Typical usage (captured on QEMUv8):

build$ mkdir -p ../tmp
build$ chmod a+w ../tmp
build$ make CFG_FTRACE_SUPPORT=y CFG_FTRACE_BUF_SIZE=15000 \
CFG_TA_MCOUNT=y CFG_ULIBS_MCOUNT=y CFG_SYSCALL_FTRACE=y \
QEMU_VIRTFS_AUTOMOUNT=y run
$ xtest regression_1004
...
$ cp /tmp/ftrace-cb3e5ba0-adf1-11e0-998b-0002a5d5c51b.out /mnt/host/tmp
build$ cd ..
optee$ optee_os/scripts/ftrace_format.py \
tmp/ftrace-cb3e5ba0-adf1-11e0-998b-0002a5d5c51b.out |
optee_os/scripts/symbolize.py \
-d optee_os/out/arm/core \
-d out-br/build/optee_test_ext-1.0/ta/*/out | less
TEE load address @ 0x5ab04000
Function graph for TA: cb3e5ba0-adf1-11e0-998b-0002a5d5c51b @ 80085000
| 1 | __ta_entry() {
| 2 | __utee_entry() {
43.840 us | 3 | ta_header_get_session()
7.216 us | 3 | tahead_get_trace_level()
14.480 us | 3 | trace_set_level()
| 3 | malloc_add_pool() {
| 4 | raw_malloc_add_pool() {
46.032 us | 5 | bpool()
| 5 | raw_realloc() {
166.256 us | 6 | bget()
23.056 us | 6 | raw_malloc_return_hook()
267.952 us | 5 | }
398.720 us | 4 | }
426.992 us | 3 | }
| 3 | TEE_GetPropertyAsU32() {
23.600 us | 4 | is_propset_pseudo_handle()
| 4 | __utee_check_instring_annotation() {
26.416 us | 5 | strlen()
| 5 | check_access() {
| 6 | TEE_CheckMemoryAccessRights() {
| 7 | _utee_check_access_rights() {
| 8 | syscall_check_access_rights() {
| 9 | ts_get_current_session() {
4.304 us | 10 | ts_get_current_session_may_fail()
10.976 us | 9 | }
| 9 | to_user_ta_ctx() {
2.496 us | 10 | is_user_ta_ctx()
8.096 us | 9 | }
| 9 | vm_check_access_rights() {
| 10 | vm_buf_is_inside_um_private() {
| 11 | core_is_buffer_inside() {
...

Signed-off-by: Jerome Forissier <jerome.forissier@linaro.org>
Acked-by: Jens Wiklander <jens.wiklander@linaro.org>
Reviewed-by: Sumit Garg <sumit.garg@linaro.org>
Acked-by: Etienne Carriere <etienne.carriere@foss.st.com>
/optee_os/mk/
H A Dconfig.mk5c2c0fb31efbeff60960336d7438e810b825d582 Wed Jun 14 21:55:23 UTC 2023 Jerome Forissier <jerome.forissier@linaro.org> ftrace: change implementation to use binary circular buffer

The current implementation of function tracing (CFG_FTRACE_SUPPORT)
produces human-readable text into the output buffer that is passed to
tee-supplicant and ultimately saved to the Linux filesystem. Two main
issues with that:

1. The string formatting code is somewhat complex. It introduces
significant overhead in the execution time of the instrumented
functions.
2. The various policies about how to handle a buffer full condition
(CFG_FTRACE_BUF_WHEN_FULL) are not very convenient. In particular,
"shift" is typically the most desirable option because it always
keeps the most recent entries, but it is very inefficient to the
point of not being usable in practice.

This commit addresses the above concerns by making the ftrace buffer
circular one, each entry being 64-bit value. The formatting code is
offloaded to a new Python script: scripts/ftrace_format.py. The
output is unchanged except for an added field showing the current
depth in the call stack.

Typical usage (captured on QEMUv8):

build$ mkdir -p ../tmp
build$ chmod a+w ../tmp
build$ make CFG_FTRACE_SUPPORT=y CFG_FTRACE_BUF_SIZE=15000 \
CFG_TA_MCOUNT=y CFG_ULIBS_MCOUNT=y CFG_SYSCALL_FTRACE=y \
QEMU_VIRTFS_AUTOMOUNT=y run
$ xtest regression_1004
...
$ cp /tmp/ftrace-cb3e5ba0-adf1-11e0-998b-0002a5d5c51b.out /mnt/host/tmp
build$ cd ..
optee$ optee_os/scripts/ftrace_format.py \
tmp/ftrace-cb3e5ba0-adf1-11e0-998b-0002a5d5c51b.out |
optee_os/scripts/symbolize.py \
-d optee_os/out/arm/core \
-d out-br/build/optee_test_ext-1.0/ta/*/out | less
TEE load address @ 0x5ab04000
Function graph for TA: cb3e5ba0-adf1-11e0-998b-0002a5d5c51b @ 80085000
| 1 | __ta_entry() {
| 2 | __utee_entry() {
43.840 us | 3 | ta_header_get_session()
7.216 us | 3 | tahead_get_trace_level()
14.480 us | 3 | trace_set_level()
| 3 | malloc_add_pool() {
| 4 | raw_malloc_add_pool() {
46.032 us | 5 | bpool()
| 5 | raw_realloc() {
166.256 us | 6 | bget()
23.056 us | 6 | raw_malloc_return_hook()
267.952 us | 5 | }
398.720 us | 4 | }
426.992 us | 3 | }
| 3 | TEE_GetPropertyAsU32() {
23.600 us | 4 | is_propset_pseudo_handle()
| 4 | __utee_check_instring_annotation() {
26.416 us | 5 | strlen()
| 5 | check_access() {
| 6 | TEE_CheckMemoryAccessRights() {
| 7 | _utee_check_access_rights() {
| 8 | syscall_check_access_rights() {
| 9 | ts_get_current_session() {
4.304 us | 10 | ts_get_current_session_may_fail()
10.976 us | 9 | }
| 9 | to_user_ta_ctx() {
2.496 us | 10 | is_user_ta_ctx()
8.096 us | 9 | }
| 9 | vm_check_access_rights() {
| 10 | vm_buf_is_inside_um_private() {
| 11 | core_is_buffer_inside() {
...

Signed-off-by: Jerome Forissier <jerome.forissier@linaro.org>
Acked-by: Jens Wiklander <jens.wiklander@linaro.org>
Reviewed-by: Sumit Garg <sumit.garg@linaro.org>
Acked-by: Etienne Carriere <etienne.carriere@foss.st.com>