diff --git a/tools/old/profile.py b/tools/old/profile.py index 6f28eed5a56d..7dbc2469dd17 100755 --- a/tools/old/profile.py +++ b/tools/old/profile.py @@ -347,11 +347,11 @@ def aksym(addr): else: # print default multi-line stack output. for addr in kernel_stack: - print(" %016x %s" % (addr, aksym(addr))) + print(" %s" % aksym(addr)) if do_delimiter: print(" --") for addr in user_stack: - print(" %016x %s" % (addr, b.sym(addr, k.pid))) + print(" %s" % b.sym(addr, k.pid)) print(" %-16s %s (%d)" % ("-", k.name, k.pid)) print(" %d\n" % v.value) diff --git a/tools/profile.py b/tools/profile.py index 1b99f4371f12..0658306dd899 100755 --- a/tools/profile.py +++ b/tools/profile.py @@ -287,11 +287,11 @@ def aksym(addr): else: # print default multi-line stack output. for addr in kernel_stack: - print(" %016x %s" % (addr, aksym(addr))) + print(" %s" % aksym(addr)) if do_delimiter: print(" --") for addr in user_stack: - print(" %016x %s" % (addr, b.sym(addr, k.pid))) + print(" %s" % b.sym(addr, k.pid)) print(" %-16s %s (%d)" % ("-", k.name, k.pid)) print(" %d\n" % v.value) diff --git a/tools/profile_example.txt b/tools/profile_example.txt index ab1c4eba7f93..25f985412c41 100644 --- a/tools/profile_example.txt +++ b/tools/profile_example.txt @@ -9,67 +9,66 @@ Example output: # ./profile Sampling at 49 Hertz of all threads by user + kernel stack... Hit Ctrl-C to end. ^C - ffffffff81189249 filemap_map_pages - ffffffff811bd3f5 handle_mm_fault - ffffffff81065990 __do_page_fault - ffffffff81065caf do_page_fault - ffffffff817ce228 page_fault - 00007fed989afcc0 [unknown] + filemap_map_pages + handle_mm_fault + __do_page_fault + do_page_fault + page_fault + [unknown] - cp (9036) 1 - 00007f31d76c3251 [unknown] - 47a2c1e752bf47f7 [unknown] + [unknown] + [unknown] - sign-file (8877) 1 - ffffffff813d0af8 __clear_user - ffffffff813d5277 iov_iter_zero - ffffffff814ec5f2 read_iter_zero - ffffffff8120be9d __vfs_read - ffffffff8120c385 vfs_read - ffffffff8120d786 sys_read - ffffffff817cc076 entry_SYSCALL_64_fastpath - 00007fc5652ad9b0 read + __clear_user + iov_iter_zero + read_iter_zero + __vfs_read + vfs_read + sys_read + entry_SYSCALL_64_fastpath + read - dd (25036) 4 - 0000000000400542 func_a - 0000000000400598 main - 00007f12a133e830 __libc_start_main - 083e258d4c544155 [unknown] + func_a + main + __libc_start_main + [unknown] - func_ab (13549) 5 [...] - ffffffff8105eb66 native_safe_halt - ffffffff8103659e default_idle - ffffffff81036d1f arch_cpu_idle - ffffffff810bba5a default_idle_call - ffffffff810bbd07 cpu_startup_entry - ffffffff817bf4a7 rest_init - ffffffff81d65f58 start_kernel - ffffffff81d652db x86_64_start_reservations - ffffffff81d65418 x86_64_start_kernel + native_safe_halt + default_idle + arch_cpu_idle + default_idle_call + cpu_startup_entry + rest_init + start_kernel + x86_64_start_reservations + x86_64_start_kernel - swapper/0 (0) 72 - ffffffff8105eb66 native_safe_halt - ffffffff8103659e default_idle - ffffffff81036d1f arch_cpu_idle - ffffffff810bba5a default_idle_call - ffffffff810bbd07 cpu_startup_entry - ffffffff8104df55 start_secondary + native_safe_halt + default_idle + arch_cpu_idle + default_idle_call + cpu_startup_entry + start_secondary - swapper/1 (0) 75 The output was long; I truncated some lines ("[...]"). -This default output prints stack traces as two columns (raw addresses, and -then translated symbol names), followed by a line to describe the process (a -dash, the process name, and a PID in parenthesis), and then an integer count -of how many times this stack trace was sampled. +This default output prints stack traces, followed by a line to describe the +process (a dash, the process name, and a PID in parenthesis), and then an +integer count of how many times this stack trace was sampled. The output above shows the most frequent stack was from the "swapper/1" process (PID 0), running the native_safe_halt() function, which was called @@ -95,57 +94,57 @@ Profiling just that process: # ./profile -p 25036 Sampling at 49 Hertz of PID 25036 by user + kernel stack... Hit Ctrl-C to end. ^C - 0000000000402748 [unknown] - 00007fc56561422c [unknown] + [unknown] + [unknown] - dd (25036) 1 - 00007fc5652ada0e __write + __write - dd (25036) 1 - 00007fc5652ad9b0 read + read - dd (25036) 1 [...] - 00000000004047b2 [unknown] - 00007fc56561422c [unknown] + [unknown] + [unknown] - dd (25036) 2 - ffffffff817cc060 entry_SYSCALL_64_fastpath - 00007fc5652ada10 __write - 00007fc56561422c [unknown] + entry_SYSCALL_64_fastpath + __write + [unknown] - dd (25036) 3 - ffffffff817cc060 entry_SYSCALL_64_fastpath - 00007fc5652ad9b0 read + entry_SYSCALL_64_fastpath + read - dd (25036) 3 - ffffffff813d0af8 __clear_user - ffffffff813d5277 iov_iter_zero - ffffffff814ec5f2 read_iter_zero - ffffffff8120be9d __vfs_read - ffffffff8120c385 vfs_read - ffffffff8120d786 sys_read - ffffffff817cc076 entry_SYSCALL_64_fastpath - 00007fc5652ad9b0 read - 00007fc56561422c [unknown] + __clear_user + iov_iter_zero + read_iter_zero + __vfs_read + vfs_read + sys_read + entry_SYSCALL_64_fastpath + read + [unknown] - dd (25036) 3 - ffffffff813d0af8 __clear_user - ffffffff813d5277 iov_iter_zero - ffffffff814ec5f2 read_iter_zero - ffffffff8120be9d __vfs_read - ffffffff8120c385 vfs_read - ffffffff8120d786 sys_read - ffffffff817cc076 entry_SYSCALL_64_fastpath - 00007fc5652ad9b0 read + __clear_user + iov_iter_zero + read_iter_zero + __vfs_read + vfs_read + sys_read + entry_SYSCALL_64_fastpath + read - dd (25036) 7 @@ -162,41 +161,41 @@ Lets add delimiters between the user and kernel stacks, using -d: # ./profile -p 25036 -d ^C - ffffffff8120b385 __vfs_write - ffffffff8120d826 sys_write - ffffffff817cc076 entry_SYSCALL_64_fastpath + __vfs_write + sys_write + entry_SYSCALL_64_fastpath -- - 00007fc5652ada10 __write + __write - dd (25036) 1 -- - 00007fc565255ef3 [unknown] - 00007fc56561422c [unknown] + [unknown] + [unknown] - dd (25036) 1 - ffffffff813d4569 iov_iter_init - ffffffff8120be8e __vfs_read - ffffffff8120c385 vfs_read - ffffffff8120d786 sys_read - ffffffff817cc076 entry_SYSCALL_64_fastpath + iov_iter_init + __vfs_read + vfs_read + sys_read + entry_SYSCALL_64_fastpath -- - 00007fc5652ad9b0 read + read - dd (25036) 1 [...] - ffffffff813d0af8 __clear_user - ffffffff813d5277 iov_iter_zero - ffffffff814ec5f2 read_iter_zero - ffffffff8120be9d __vfs_read - ffffffff8120c385 vfs_read - ffffffff8120d786 sys_read - ffffffff817cc076 entry_SYSCALL_64_fastpath + __clear_user + iov_iter_zero + read_iter_zero + __vfs_read + vfs_read + sys_read + entry_SYSCALL_64_fastpath -- - 00007fc5652ad9b0 read + read - dd (25036) 9 @@ -210,59 +209,59 @@ func_b(). Profiling it for 5 seconds: # ./profile -p `pgrep -n func_ab` 5 Sampling at 49 Hertz of PID 2930 by user + kernel stack for 5 secs. - 000000000040053e func_a - 0000000000400598 main - 00007f0458819830 __libc_start_main - 083e258d4c544155 [unknown] + func_a + main + __libc_start_main + [unknown] - func_ab (2930) 2 - 0000000000400566 func_b - 00000000004005ac main - 00007f0458819830 __libc_start_main - 083e258d4c544155 [unknown] + func_b + main + __libc_start_main + [unknown] - func_ab (2930) 3 - 000000000040053a func_a - 0000000000400598 main - 00007f0458819830 __libc_start_main - 083e258d4c544155 [unknown] + func_a + main + __libc_start_main + [unknown] - func_ab (2930) 5 - 0000000000400562 func_b - 00000000004005ac main - 00007f0458819830 __libc_start_main - 083e258d4c544155 [unknown] + func_b + main + __libc_start_main + [unknown] - func_ab (2930) 12 - 000000000040056a func_b - 00000000004005ac main - 00007f0458819830 __libc_start_main - 083e258d4c544155 [unknown] + func_b + main + __libc_start_main + [unknown] - func_ab (2930) 19 - 0000000000400542 func_a - 0000000000400598 main - 00007f0458819830 __libc_start_main - 083e258d4c544155 [unknown] + func_a + main + __libc_start_main + [unknown] - func_ab (2930) 22 - 0000000000400571 func_b - 00000000004005ac main - 00007f0458819830 __libc_start_main - 083e258d4c544155 [unknown] + func_b + main + __libc_start_main + [unknown] - func_ab (2930) 64 - 0000000000400549 func_a - 0000000000400598 main - 00007f0458819830 __libc_start_main - 083e258d4c544155 [unknown] + func_a + main + __libc_start_main + [unknown] - func_ab (2930) 72 @@ -540,33 +539,33 @@ You can increase or decrease the sample frequency. Eg, sampling at 9 Hertz: # ./profile -F 9 Sampling at 9 Hertz of all threads by user + kernel stack... Hit Ctrl-C to end. ^C - 000000000040056a func_b - 00000000004005ac main - 00007f0458819830 __libc_start_main - 083e258d4c544155 [unknown] + func_b + main + __libc_start_main + [unknown] - func_ab (2930) 1 [...] - ffffffff8105eb66 native_safe_halt - ffffffff8103659e default_idle - ffffffff81036d1f arch_cpu_idle - ffffffff810bba5a default_idle_call - ffffffff810bbd07 cpu_startup_entry - ffffffff8104df55 start_secondary + native_safe_halt + default_idle + arch_cpu_idle + default_idle_call + cpu_startup_entry + start_secondary - swapper/3 (0) 8 - ffffffff8105eb66 native_safe_halt - ffffffff8103659e default_idle - ffffffff81036d1f arch_cpu_idle - ffffffff810bba5a default_idle_call - ffffffff810bbd07 cpu_startup_entry - ffffffff817bf497 rest_init - ffffffff81d65f58 start_kernel - ffffffff81d652db x86_64_start_reservations - ffffffff81d65418 x86_64_start_kernel + native_safe_halt + default_idle + arch_cpu_idle + default_idle_call + cpu_startup_entry + rest_init + start_kernel + x86_64_start_reservations + x86_64_start_kernel - swapper/0 (0) 8 @@ -577,99 +576,99 @@ For example, just user stacks: # ./profile -U Sampling at 49 Hertz of all threads by user stack... Hit Ctrl-C to end. ^C - 0000000000402ccc [unknown] - 00007f45a624422c [unknown] + [unknown] + [unknown] - dd (2931) 1 - 0000000000404b80 [unknown] - 00007f45a624422c [unknown] + [unknown] + [unknown] - dd (2931) 1 - 0000000000404d77 [unknown] - 00007f45a624422c [unknown] + [unknown] + [unknown] - dd (2931) 1 - 00007f45a5e85e5e [unknown] - 00007f45a624422c [unknown] + [unknown] + [unknown] - dd (2931) 1 - 0000000000402d12 [unknown] - 00007f45a624422c [unknown] + [unknown] + [unknown] - dd (2931) 1 - 0000000000400562 func_b - 00000000004005ac main - 00007f0458819830 __libc_start_main - 083e258d4c544155 [unknown] + func_b + main + __libc_start_main + [unknown] - func_ab (2930) 1 - 0000000000404805 [unknown] + [unknown] - dd (2931) 1 - 00000000004047de [unknown] + [unknown] - dd (2931) 1 - 0000000000400542 func_a - 0000000000400598 main - 00007f0458819830 __libc_start_main - 083e258d4c544155 [unknown] + func_a + main + __libc_start_main + [unknown] - func_ab (2930) 3 - 00007f45a5edda10 __write - 00007f45a624422c [unknown] + __write + [unknown] - dd (2931) 3 - 000000000040053a func_a - 0000000000400598 main - 00007f0458819830 __libc_start_main - 083e258d4c544155 [unknown] + func_a + main + __libc_start_main + [unknown] - func_ab (2930) 4 - 000000000040056a func_b - 00000000004005ac main - 00007f0458819830 __libc_start_main - 083e258d4c544155 [unknown] + func_b + main + __libc_start_main + [unknown] - func_ab (2930) 7 - swapper/6 (0) 10 - 0000000000400571 func_b - 00000000004005ac main - 00007f0458819830 __libc_start_main - 083e258d4c544155 [unknown] + func_b + main + __libc_start_main + [unknown] - func_ab (2930) 10 - 00007f45a5edda10 __write + __write - dd (2931) 10 - 0000000000400549 func_a - 0000000000400598 main - 00007f0458819830 __libc_start_main - 083e258d4c544155 [unknown] + func_a + main + __libc_start_main + [unknown] - func_ab (2930) 11 - 00007f45a5edd9b0 read + read - dd (2931) 12 - 00007f45a5edd9b0 read - 00007f45a624422c [unknown] + read + [unknown] - dd (2931) 14