CODEWITHSUNDEEP
linuxlinux-kernelftrace
wenhung
wenhung

Reputation: 1

The trace-cmd report do not show the function name

I used the following command to trace the kernel.

$ trace-cmd record -p function_graph ls
$ trace-cmd report

but I saw the following result just show the address instead of the function name.

       MtpServer-4877  [000]  1706.014074: funcgraph_exit:       + 23.875 us  |      }
       trace-cmd-4892  [001]  1706.014075: funcgraph_entry:        2.000 us   |      ffff0000082cdc24();
       trace-cmd-4895  [002]  1706.014076: funcgraph_entry:        1.250 us   |        ffff00000829e704();
       MtpServer-4877  [000]  1706.014076: funcgraph_entry:        1.375 us   |      ffff0000083266bc();
         kswapd0-1024  [003]  1706.014078: funcgraph_entry:                   |                ffff00000827956c() {
         kswapd0-1024  [003]  1706.014081: funcgraph_entry:                   |                  ffff00000827801c() {
       trace-cmd-4895  [002]  1706.014081: funcgraph_entry:        1.375 us   |        ffff0000082bd8b4();
       MtpServer-4877  [000]  1706.014082: funcgraph_entry:        1.375 us   |      ffff0000082ccefc();
       trace-cmd-4892  [001]  1706.014082: funcgraph_entry:                   |      ffff0000082c5adc() {
         kswapd0-1024  [003]  1706.014084: funcgraph_entry:        1.500 us   |                    ffff00000828c8f0();
       trace-cmd-4892  [001]  1706.014085: funcgraph_entry:        1.250 us   |        ffff0000082c5a58();
       MtpServer-4877  [000]  1706.014088: funcgraph_entry:        1.125 us   |      ffff0000082e3a30();
       trace-cmd-4895  [002]  1706.014089: funcgraph_exit:       + 19.125 us  |      }
         kswapd0-1024  [003]  1706.014090: funcgraph_entry:        1.500 us   |                    ffff0000090b6c04();
       trace-cmd-4895  [002]  1706.014090: funcgraph_entry:                   |      ffff0000082d4ffc() {
       trace-cmd-4892  [001]  1706.014092: funcgraph_exit:         6.875 us   |      }
       trace-cmd-4895  [002]  1706.014093: funcgraph_entry:        1.000 us   |        ffff0000090b3a40();

May I know how to show the exact function name on the trace-cmd result?

Upvotes: 0

Views: 514

Answers (1)

user19698349
user19698349

Reputation: 11

I ran into this issue, and for me it was caused by /proc/kallsyms (a file which mappings from kernel addresses to symbol names) displaying all zeros for kernel addresses.

Since this is a procfs "file" it's behavior can, and does vary depending on what context you are accessing it from.

In this case, it is due to security checks.

If you pass the checks, the addresses will be nonzero and look similar to this:

000000000000c000 A exception_stacks
0000000000014000 A entry_stack_storage
0000000000015000 A espfix_waddr
0000000000015008 A espfix_stack

If you fail the checks they will be zero, like this: (In my case I did not have the CAP_SYSLOG capability because I was running in a container and systemd-nspawn's default behaviour was dropping the capability. [1])

0000000000000000 A exception_stacks
0000000000000000 A entry_stack_storage
0000000000000000 A espfix_waddr
0000000000000000 A espfix_stack

This is influenced by kernel settings and more information (along with the rather simple checking source code) can be found on the answers in Allow single user to access /proc/kallsyms

To fix this issue you need to start your trace-cmd with proper permissions / capabilities.

[1] This is what the capability settings look like for an nspawned process with no modifications:

# cat /proc/2894/status | grep -i cap
CapInh: 0000000000000000
CapPrm: 00000000fdecafff
CapEff: 00000000fdecafff
CapBnd: 00000000fdecafff
CapAmb: 0000000000000000

This is what it looks like for a process started by root in a "normal" context:

# cat /proc/616428/status | grep -i cap
CapInh: 0000000000000000
CapPrm: 000001ffffffffff
CapEff: 000001ffffffffff
CapBnd: 000001ffffffffff
CapAmb: 0000000000000000

Alternative solution

This is speculation on my part, but I expect this manner of censoring in the kallsyms file is to prevent defeating kASLR by just reading addresses of memory locations out of the file.

It seems that if you directly use the tracefs ftrace interfaces, as opposed to reading raw trace events and then resolving symbols (I don't know if there is a way to make trace-cmd do this), then the kernel will resolve the symbol names for you (and this way does not expose kernel addresses) and so this is not an issue.

For example (note how it says !cap_syslog):

# capsh --print
Current: =ep cap_syslog-ep
Bounding set = [...elided for brevity ...]
Ambient set =
Current IAB: !cap_syslog
Securebits: 00/0x0/1'b0 (no-new-privs=0)
 secure-noroot: no (unlocked)
 secure-no-suid-fixup: no (unlocked)
 secure-keep-caps: no (unlocked)
 secure-no-ambient-raise: no (unlocked)
uid=0(root) euid=0(root)
gid=0(root)
groups=0(root)
Guessed mode: HYBRID (4)

# echo 1 > events/enable 
# echo function_graph > current_tracer 
# echo 1 > tracing_on 
# head trace
 # tracer: function_graph
 #
 # CPU  DURATION                  FUNCTION CALLS
 # |     |   |                     |   |   |   |
  2)   0.276 us    |    } /* fpregs_assert_state_consistent */
  1)   2.052 us    |  } /* exit_to_user_mode_prepare */
  1)               |  syscall_trace_enter.constprop.0() {
  1)               |    __traceiter_sys_enter() {
  1)               |      /* sys_futex(uaddr: 7fc3565b9378, op: 80, val: 0, utime: 0, uaddr2: 0, val3: 0) */
  1)               |      /* sys_enter: NR 202 (7fc3565b9378, 80, 0, 0, 0, 0) */

Upvotes: 1

Related Questions