Re: [PATCH v10 2/8] tracing: Add documentation for funcgraph-retval and funcgraph-retval-hex
From: Donglin Peng
Date: Tue Apr 04 2023 - 08:09:16 EST
On 2023/4/3 16:30, Mark Rutland wrote:
On Fri, Mar 31, 2023 at 05:47:38AM -0700, Donglin Peng wrote:
Add documentation for the two newly introduced options for the
function_graph tracer. The funcgraph-retval option is used to
control whether or not to display the return value, while the
funcgraph-retval-hex option is used to control the display
format of the return value.
Signed-off-by: Donglin Peng <pengdonglin@xxxxxxxxxxxxxx>
---
v9:
- Update limitation description
v7:
- Rename trace option 'graph_retval_hex' to 'funcgraph-retval-hex'
- Update documentation description
v6:
- Modify the limitations for funcgraph-retval
- Optimize the English expression
v5:
- Describe the limitations of funcgraph-retval
---
Documentation/trace/ftrace.rst | 74 ++++++++++++++++++++++++++++++++++
1 file changed, 74 insertions(+)
diff --git a/Documentation/trace/ftrace.rst b/Documentation/trace/ftrace.rst
index b927fb2b94dc..f572ae419219 100644
--- a/Documentation/trace/ftrace.rst
+++ b/Documentation/trace/ftrace.rst
@@ -1328,6 +1328,19 @@ Options for function_graph tracer:
only a closing curly bracket "}" is displayed for
the return of a function.
+ funcgraph-retval
+ When set, the return value of each traced function
+ will be printed after an equal sign "=". By default
+ this is off.
+
+ funcgraph-retval-hex
+ When set, the return value will always be printed
+ in hexadecimal format. If the option is not set and
+ the return value is an error code, it will be printed
+ in signed decimal format; otherwise it will also be
+ printed in hexadecimal format. By default, this option
+ is off.
+
sleep-time
When running function graph tracer, to include
the time a task schedules out in its function.
@@ -2673,6 +2686,67 @@ It is default disabled.
0) 1.757 us | } /* kmem_cache_free() */
0) 2.861 us | } /* putname() */
+The return value of each traced function can be displayed after
+an equal sign "=". When encountering system call failures, it
+can be verfy helpful to quickly locate the function that first
+returns an error code.
+
+ - hide: echo nofuncgraph-retval > trace_options
+ - show: echo funcgraph-retval > trace_options
+
+ Example with funcgraph-retval::
+
+ 1) | cgroup_migrate() {
+ 1) 0.651 us | cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
+ 1) | cgroup_migrate_execute() {
+ 1) | cpu_cgroup_can_attach() {
+ 1) | cgroup_taskset_first() {
+ 1) 0.732 us | cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
+ 1) 1.232 us | } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
+ 1) 0.380 us | sched_rt_can_attach(); /* = 0x0 */
+ 1) 2.335 us | } /* cpu_cgroup_can_attach = -22 */
+ 1) 4.369 us | } /* cgroup_migrate_execute = -22 */
+ 1) 7.143 us | } /* cgroup_migrate = -22 */
+
+The above example shows that the function cpu_cgroup_can_attach
+returned the error code -22 firstly, then we can read the code
+of this function to get the root cause.
+
+When the option funcgraph-retval-hex is not set, the return value can
+be displayed in a smart way. Specifically, if it is an error code,
+it will be printed in signed decimal format, otherwise it will
+printed in hexadecimal format.
+
+ - smart: echo nofuncgraph-retval-hex > trace_options
+ - hexadecimal always: echo funcgraph-retval-hex > trace_options
+
+ Example with funcgraph-retval-hex::
+
+ 1) | cgroup_migrate() {
+ 1) 0.651 us | cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
+ 1) | cgroup_migrate_execute() {
+ 1) | cpu_cgroup_can_attach() {
+ 1) | cgroup_taskset_first() {
+ 1) 0.732 us | cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
+ 1) 1.232 us | } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
+ 1) 0.380 us | sched_rt_can_attach(); /* = 0x0 */
+ 1) 2.335 us | } /* cpu_cgroup_can_attach = 0xffffffea */
+ 1) 4.369 us | } /* cgroup_migrate_execute = 0xffffffea */
+ 1) 7.143 us | } /* cgroup_migrate = 0xffffffea */
+
+At present, there are some limitations when using the funcgraph-retval
+option, and these limitations will be eliminated in the future:
+
+- Even if the function return type is void, a return value will still
+ be printed, and you can just ignore it.
+
+- Even if return values are stored in multiple registers, only the
+ value contained in the first register will be recorded and printed.
+ To illustrate, in the x86 architecture, eax and edx are used to store
+ a 64-bit return value, with the lower 32 bits saved in eax and the
+ upper 32 bits saved in edx. However, only the value stored in eax
+ will be recorded and printed.
With some procedure call standards (e.g. arm64's AAPCS64), when a type is
smaller than a GPR it's up to the consumer to perform the narrowing, and the
upport bits may contain UNKNOWN values. For example, with a u8 in a 64-bit GPR,
bits [3:8] may contain arbitrary values.
Thank you. Just to clarify, Should it be that bits [63:8] may contain
arbitrary values in such cases?
It's probably worth noting that this means *some* manual processing will always
be necessary for such cases.
That's mostly visible around where largelr types get truncated (whether
explciitly or implicitly), e.g.
u8 narrow_to_u8(u64 val)
{
// implicitly truncated
return val;
}
... could be compiled to:
narrow_to_u8:
< ... ftrace instrumentation ... >
RET
... and so:
narrow_to_u8(0x123456789abcdef);
... might be recorded as returning 0x123456789abcdef rather than 0xef.
That can happen in surprising ways, e.g.
int error_if_not_4g_aligned(u64 val)
{
if (val & GENMASK(63, 32))
Should it be GENMASK(31, 0)?
return -EINVAL;
return 0;
}
... could be compiled to:
error_if_not_4g_aligned:
CBNZ w0, .Lnot_aligned
RET // bits [31:0] are zero, bits
// [63:32] are UNKNOWN
.Lnot_aligned:
MOV x0, #-EINVAL
RET
.... and so:
error_if_not_4g_aligned(SZ_8G)
... could return with bits [63:32] non-zero
Thanks,
Mark.
Thank you for sharing this note. I will append the following limitation.
In certain procedure call standards, such as arm64's AAPCS64, when a
type is smaller than a GPR, it is the responsibility of the consumer to
perform the narrowing, and the upper bits may contain UNKNOWN values.
Therefore, it is advisable to check the code for such cases. For
instance,when using a u8 in a 64-bit GPR, bits [63:8] may contain
arbitrary values, especially when larger types are truncated, whether
explicitly or implicitly. Here are some specific cases to illustrate
this point:
- Case One:
The function narrow_to_u8 is defined as follows:
u8 narrow_to_u8(u64 val)
{
// implicitly truncated
return val;
}
It may be compiled to:
narrow_to_u8:
< ... ftrace instrumentation ... >
RET
If you pass 0x123456789abcdef to this function and want to narrow it,
it may be recorded as 0x123456789abcdef instead of 0xef.
- Case Two:
The function error_if_not_4g_aligned is defined as follows:
int error_if_not_4g_aligned(u64 val)
{
if (val & GENMASK(31, 0))
return -EINVAL;
return 0;
}
It could be compile to:
error_if_not_4g_aligned:
CBNZ w0, .Lnot_aligned
RET // bits [31:0] are zero, bits
// [63:32] are UNKNOWN
.Lnot_aligned:
MOV x0, #-EINVAL
RET
When passing 0x2_0000_0000 to it, the return value may be recorded as
0x2_0000_0000 instead of 0.