aboutsummaryrefslogtreecommitdiffstats
path: root/tools/perf/Documentation (follow)
AgeCommit message (Collapse)AuthorFilesLines
2019-08-16perf report: Add --switch-on/--switch-off eventsArnaldo Carvalho de Melo1-0/+17
Since 'perf top' shares the histogram browser with 'perf report', then the same explanation in the previous cset applies. An additional example uses a pair of SDT events available for systemtap: # perf probe --exec=/usr/bin/stap '%*:*' Added new events: sdt_stap:benchmark__thread__start (on %* in /usr/bin/stap) sdt_stap:benchmark (on %* in /usr/bin/stap) sdt_stap:benchmark__thread__end (on %* in /usr/bin/stap) sdt_stap:pass6__start (on %* in /usr/bin/stap) sdt_stap:pass6__end (on %* in /usr/bin/stap) sdt_stap:pass5__start (on %* in /usr/bin/stap) sdt_stap:pass5__end (on %* in /usr/bin/stap) sdt_stap:pass0__start (on %* in /usr/bin/stap) sdt_stap:pass0__end (on %* in /usr/bin/stap) sdt_stap:pass1a__start (on %* in /usr/bin/stap) sdt_stap:pass1b__start (on %* in /usr/bin/stap) sdt_stap:pass1__end (on %* in /usr/bin/stap) sdt_stap:pass2__start (on %* in /usr/bin/stap) sdt_stap:pass2__end (on %* in /usr/bin/stap) sdt_stap:pass3__start (on %* in /usr/bin/stap) sdt_stap:pass3__end (on %* in /usr/bin/stap) sdt_stap:pass4__start (on %* in /usr/bin/stap) sdt_stap:pass4__end (on %* in /usr/bin/stap) sdt_stap:benchmark__start (on %* in /usr/bin/stap) sdt_stap:benchmark__end (on %* in /usr/bin/stap) sdt_stap:cache__get (on %* in /usr/bin/stap) sdt_stap:cache__clean (on %* in /usr/bin/stap) sdt_stap:cache__add__module (on %* in /usr/bin/stap) sdt_stap:cache__add__source (on %* in /usr/bin/stap) sdt_stap:stap_system__complete (on %* in /usr/bin/stap) sdt_stap:stap_system__start (on %* in /usr/bin/stap) sdt_stap:stap_system__spawn (on %* in /usr/bin/stap) sdt_stap:stap_system__fork (on %* in /usr/bin/stap) sdt_stap:intern_string (on %* in /usr/bin/stap) sdt_stap:client__start (on %* in /usr/bin/stap) sdt_stap:client__end (on %* in /usr/bin/stap) You can now use it in all perf tools, such as: perf record -e sdt_stap:client__end -aR sleep 1 # From these we're use the two below to run systemtap's test suite: # perf record -e sdt_stap:pass2__*,cycles:P make installcheck > /dev/null ^C[ perf record: Woken up 8 times to write data ] [ perf record: Captured and wrote 2.691 MB perf.data (39638 samples) ] Terminated # perf script | grep sdt_stap stap 28979 [000] 19424.302660: sdt_stap:pass2__start: (561b9a537de3) arg1=140730364262544 stap 28979 [000] 19424.333083: sdt_stap:pass2__end: (561b9a53a9e1) arg1=140730364262544 stap 29045 [006] 19424.933460: sdt_stap:pass2__start: (563edddcede3) arg1=140722674883152 stap 29045 [006] 19424.963794: sdt_stap:pass2__end: (563edddd19e1) arg1=140722674883152 # perf script | grep cycles | wc -l 39634 # Looking at the whole perf.data file: [root@quaco testsuite]# perf report | grep cycles:P -A25 # Samples: 39K of event 'cycles:P' # Event count (approx.): 34044267368 # # Overhead Command Shared Object Symbol # ........ ....... .................... ................................ # 3.50% cc1 cc1 [.] ht_lookup_with_hash 3.04% cc1 cc1 [.] _cpp_lex_token 2.11% cc1 cc1 [.] ggc_internal_alloc 1.83% cc1 cc1 [.] cpp_get_token_with_location 1.68% cc1 libc-2.29.so [.] _int_malloc 1.41% cc1 cc1 [.] linemap_position_for_column 1.25% cc1 cc1 [.] ggc_internal_cleared_alloc 1.20% cc1 cc1 [.] c_lex_with_flags 1.18% cc1 cc1 [.] get_combined_adhoc_loc 1.05% cc1 libc-2.29.so [.] malloc 1.01% cc1 libc-2.29.so [.] _int_free 0.96% stap stap [.] std::_Hashtable<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::__detail::_Identity, std::equal_to<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, stringtable_hash, std::__detail::_Mod_range_hashing, std::__detail::_Default_ranged_hash, std::__detail::_Prime_rehash_policy, std::__detail::_Hashtable_traits<true, true, true> >::_M_insert<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::__detail::_AllocNode<std::allocator<std::__detail::_Hash_node<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, true> > > > 0.78% stap stap [.] lexer::scan 0.74% cc1 cc1 [.] _cpp_lex_direct 0.70% cc1 cc1 [.] pop_scope 0.70% cc1 cc1 [.] c_parser_declspecs 0.69% stap libc-2.29.so [.] _int_malloc 0.68% cc1 cc1 [.] htab_find_slot 0.68% cc1 [kernel.vmlinux] [k] prepare_exit_to_usermode 0.64% cc1 [kernel.vmlinux] [k] clear_page_erms [root@quaco testsuite]# And now only what happens in slices demarcated by those start/end SDT events: [root@quaco testsuite]# perf report --switch-on=sdt_stap:pass2__start --switch-off=sdt_stap:pass2__end | grep cycles:P -A100 # Samples: 240 of event 'cycles:P' # Event count (approx.): 206491934 # # Overhead Command Shared Object Symbol # ........ ....... ................... ................................................ # 38.99% stap stap [.] systemtap_session::register_library_aliases 19.47% stap stap [.] match_key::operator< 15.01% stap libc-2.29.so [.] __memcmp_avx2_movbe 5.19% stap libc-2.29.so [.] _int_malloc 2.50% stap libstdc++.so.6.0.26 [.] std::_Rb_tree_insert_and_rebalance 2.30% stap stap [.] match_node::build_no_more 2.07% stap libc-2.29.so [.] malloc 1.66% stap stap [.] std::_Rb_tree<match_key, std::pair<match_key const, match_node*>, std::_Select1st<std::pair<match_key const, match_node*> >, std::less<match_key>, std::allocator<std::pair<match_key const, match_node*> > >::find 1.66% stap stap [.] match_node::bind 1.58% stap [kernel.vmlinux] [k] prepare_exit_to_usermode 1.17% stap [kernel.vmlinux] [k] native_irq_return_iret 0.87% stap stap [.] 0x0000000000032ec4 0.77% stap libstdc++.so.6.0.26 [.] std::_Rb_tree_increment 0.47% stap stap [.] std::vector<derived_probe_builder*, std::allocator<derived_probe_builder*> >::_M_realloc_insert<derived_probe_builder* const&> 0.47% stap [kernel.vmlinux] [k] get_page_from_freelist 0.47% stap [kernel.vmlinux] [k] swapgs_restore_regs_and_return_to_usermode 0.47% stap [kernel.vmlinux] [k] do_user_addr_fault 0.46% stap [kernel.vmlinux] [k] __pagevec_lru_add_fn 0.46% stap stap [.] std::_Rb_tree<match_key, std::pair<match_key const, match_node*>, std::_Select1st<std::pair<match_key const, match_node*> >, std::less<match_key>, std::allocator<std::pair<match_key const, match_node*> > >::_M_emplace_unique<std::pair<match_key, match_node*> > 0.42% stap libstdc++.so.6.0.26 [.] 0x00000000000c18fa 0.40% stap [kernel.vmlinux] [k] interrupt_entry 0.40% stap [kernel.vmlinux] [k] update_load_avg 0.40% stap [kernel.vmlinux] [k] __intel_pmu_disable_all 0.40% stap [kernel.vmlinux] [k] clear_page_erms 0.39% stap [kernel.vmlinux] [k] __mod_node_page_state 0.39% stap [kernel.vmlinux] [k] error_entry 0.39% stap [kernel.vmlinux] [k] sync_regs 0.38% stap [kernel.vmlinux] [k] __handle_mm_fault 0.38% stap stap [.] derive_probes # # (Tip: System-wide collection from all CPUs: perf record -a) # [root@quaco testsuite]# Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Florian Weimer <fweimer@redhat.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: William Cohen <wcohen@redhat.com> Link: https://lkml.kernel.org/n/tip-408hvumcnyn93a0auihnawew@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-08-15perf top: Add --switch-on/--switch-off eventsArnaldo Carvalho de Melo1-0/+38
Just like 'perf trace' and 'perf script', should be useful for instance to only consider samples after the initialization phase of some workload. The man page has some examples and considerations about its current interface, that still doesn't handle the on/off events in a special way, behaving just like when multiple events are specified, i.e.: - In non-group mode (when the event list is not enclosed in {}) show a a menu to allow choosing which event the user wants to see in the histograms browser - In group mode, be it using {} or asking for --group, show one column per event. Try for instance: # perf top -e '{cycles,instructions,probe:icmp_rcv}' --switch-on=probe:icmp_rcv Replace probe:icmp_rcv, that I put in place using: # perf probe icmp_rcv:59 To hit when broadcast packets arrive, with a probe installed after an initialization phase is over or after some other point of interest, some garbage collection, etc, and also use --switch-off, for instance, on a probe installed after said garbage collection is over. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Florian Weimer <fweimer@redhat.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: William Cohen <wcohen@redhat.com> Link: https://lkml.kernel.org/n/tip-c7q7qjeqtyvc9mkeipxza6ne@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-08-15perf trace: Add --switch-on/--switch-off eventsArnaldo Carvalho de Melo1-0/+9
Just like with 'perf script': # perf trace -e sched:*,syscalls:*sleep* sleep 1 0.000 :28345/28345 sched:sched_waking:comm=perf pid=28346 prio=120 target_cpu=005 0.005 :28345/28345 sched:sched_wakeup:perf:28346 [120] success=1 CPU:005 0.383 sleep/28346 sched:sched_process_exec:filename=/usr/bin/sleep pid=28346 old_pid=28346 0.613 sleep/28346 sched:sched_stat_runtime:comm=sleep pid=28346 runtime=607375 [ns] vruntime=23289041218 [ns] 0.689 sleep/28346 syscalls:sys_enter_nanosleep:rqtp: 0x7ffc491789b0 0.693 sleep/28346 sched:sched_stat_runtime:comm=sleep pid=28346 runtime=72021 [ns] vruntime=23289113239 [ns] 0.694 sleep/28346 sched:sched_switch:sleep:28346 [120] S ==> swapper/5:0 [120] 1000.787 :0/0 sched:sched_waking:comm=sleep pid=28346 prio=120 target_cpu=005 1000.824 :0/0 sched:sched_wakeup:sleep:28346 [120] success=1 CPU:005 1000.908 sleep/28346 syscalls:sys_exit_nanosleep:0x0 1001.218 sleep/28346 sched:sched_process_exit:comm=sleep pid=28346 prio=120 # perf trace -e sched:*,syscalls:*sleep* --switch-on=syscalls:sys_enter_nanosleep sleep 1 0.000 sleep/28349 sched:sched_stat_runtime:comm=sleep pid=28349 runtime=603036 [ns] vruntime=23873537697 [ns] 0.001 sleep/28349 sched:sched_switch:sleep:28349 [120] S ==> swapper/4:0 [120] 1000.392 :0/0 sched:sched_waking:comm=sleep pid=28349 prio=120 target_cpu=004 1000.443 :0/0 sched:sched_wakeup:sleep:28349 [120] success=1 CPU:004 1000.540 sleep/28349 syscalls:sys_exit_nanosleep:0x0 1000.852 sleep/28349 sched:sched_process_exit:comm=sleep pid=28349 prio=120 # perf trace -e sched:*,syscalls:*sleep* --switch-on=syscalls:sys_enter_nanosleep --switch-off=syscalls:sys_exit_nanosleep sleep 1 0.000 sleep/28352 sched:sched_stat_runtime:comm=sleep pid=28352 runtime=610543 [ns] vruntime=24811686681 [ns] 0.001 sleep/28352 sched:sched_switch:sleep:28352 [120] S ==> swapper/0:0 [120] 1000.397 :0/0 sched:sched_waking:comm=sleep pid=28352 prio=120 target_cpu=000 1000.440 :0/0 sched:sched_wakeup:sleep:28352 [120] success=1 CPU:000 # # perf trace -e sched:*,syscalls:*sleep* --switch-on=syscalls:sys_enter_nanosleep --switch-off=syscalls:sys_exit_nanosleep --show-on-off sleep 1 0.000 sleep/28367 syscalls:sys_enter_nanosleep:rqtp: 0x7fffd1a25fc0 0.004 sleep/28367 sched:sched_stat_runtime:comm=sleep pid=28367 runtime=628760 [ns] vruntime=22170052672 [ns] 0.005 sleep/28367 sched:sched_switch:sleep:28367 [120] S ==> swapper/2:0 [120] 1000.367 :0/0 sched:sched_waking:comm=sleep pid=28367 prio=120 target_cpu=002 1000.412 :0/0 sched:sched_wakeup:sleep:28367 [120] success=1 CPU:002 1000.512 sleep/28367 syscalls:sys_exit_nanosleep:0x0 # Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Florian Weimer <fweimer@redhat.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: William Cohen <wcohen@redhat.com> Link: https://lkml.kernel.org/n/tip-t3ngpt1brcc1fm9gep9gxm4q@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-08-15perf script: Allow specifying event to switch off processing of other eventsArnaldo Carvalho de Melo1-1/+4
Counterpart of --switch-on: # perf record -e sched:*,syscalls:sys_*_nanosleep sleep 1 [ perf record: Woken up 36 times to write data ] [ perf record: Captured and wrote 0.032 MB perf.data (10 samples) ] # # perf script :20918 20918 [002] 109866.143696: sched:sched_waking: comm=perf pid=20919 prio=120 target_cpu=001 :20918 20918 [002] 109866.143702: sched:sched_wakeup: perf:20919 [120] success=1 CPU:001 sleep 20919 [001] 109866.144081: sched:sched_process_exec: filename=/usr/bin/sleep pid=20919 old_pid=20919 sleep 20919 [001] 109866.144408: syscalls:sys_enter_nanosleep: rqtp: 0x7ffc2384fef0, rmtp: 0x00000000 sleep 20919 [001] 109866.144411: sched:sched_stat_runtime: comm=sleep pid=20919 runtime=521249 [ns] vruntime=202919398131 [n> sleep 20919 [001] 109866.144412: sched:sched_switch: sleep:20919 [120] S ==> swapper/1:0 [120] swapper 0 [001] 109867.144568: sched:sched_waking: comm=sleep pid=20919 prio=120 target_cpu=001 swapper 0 [001] 109867.144586: sched:sched_wakeup: sleep:20919 [120] success=1 CPU:001 sleep 20919 [001] 109867.144614: syscalls:sys_exit_nanosleep: 0x0 sleep 20919 [001] 109867.144753: sched:sched_process_exit: comm=sleep pid=20919 prio=120 # # perf script --switch-off syscalls:sys_exit_nanosleep :20918 20918 [002] 109866.143696: sched:sched_waking: comm=perf pid=20919 prio=120 target_cpu=001 :20918 20918 [002] 109866.143702: sched:sched_wakeup: perf:20919 [120] success=1 CPU:001 sleep 20919 [001] 109866.144081: sched:sched_process_exec: filename=/usr/bin/sleep pid=20919 old_pid=20919 sleep 20919 [001] 109866.144408: syscalls:sys_enter_nanosleep: rqtp: 0x7ffc2384fef0, rmtp: 0x00000000 sleep 20919 [001] 109866.144411: sched:sched_stat_runtime: comm=sleep pid=20919 runtime=521249 [ns] vruntime=202919398131 [n> sleep 20919 [001] 109866.144412: sched:sched_switch: sleep:20919 [120] S ==> swapper/1:0 [120] swapper 0 [001] 109867.144568: sched:sched_waking: comm=sleep pid=20919 prio=120 target_cpu=001 swapper 0 [001] 109867.144586: sched:sched_wakeup: sleep:20919 [120] success=1 CPU:001 sleep 20919 [001] 109867.144753: sched:sched_process_exit: comm=sleep pid=20919 prio=120 # # perf script --switch-on syscalls:sys_enter_nanosleep --switch-off syscalls:sys_exit_nanosleep sleep 20919 [001] 109866.144411: sched:sched_stat_runtime: comm=sleep pid=20919 runtime=521249 [ns] vruntime=202919398131 [n> sleep 20919 [001] 109866.144412: sched:sched_switch: sleep:20919 [120] S ==> swapper/1:0 [120] swapper 0 [001] 109867.144568: sched:sched_waking: comm=sleep pid=20919 prio=120 target_cpu=001 swapper 0 [001] 109867.144586: sched:sched_wakeup: sleep:20919 [120] success=1 CPU:001 # # perf script --switch-on syscalls:sys_enter_nanosleep --switch-off syscalls:sys_exit_nanosleep --show-on-off sleep 20919 [001] 109866.144408: syscalls:sys_enter_nanosleep: rqtp: 0x7ffc2384fef0, rmtp: 0x00000000 sleep 20919 [001] 109866.144411: sched:sched_stat_runtime: comm=sleep pid=20919 runtime=521249 [ns] vruntime=202919398131 [n> sleep 20919 [001] 109866.144412: sched:sched_switch: sleep:20919 [120] S ==> swapper/1:0 [120] swapper 0 [001] 109867.144568: sched:sched_waking: comm=sleep pid=20919 prio=120 target_cpu=001 swapper 0 [001] 109867.144586: sched:sched_wakeup: sleep:20919 [120] success=1 CPU:001 sleep 20919 [001] 109867.144614: syscalls:sys_exit_nanosleep: 0x0 # Now think about using this together with 'perf probe' to create custom on/off events in your app :-) Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Florian Weimer <fweimer@redhat.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: William Cohen <wcohen@redhat.com> Link: https://lkml.kernel.org/n/tip-li3j01c4tmj9kw6ydsl8swej@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-08-15perf script: Allow showing the --switch-on eventArnaldo Carvalho de Melo1-0/+3
One may want to see the --switch-on event as well, allow for that, using the previous cset example: # perf script --switch-on syscalls:sys_enter_nanosleep --show-on-off sleep 13638 [001] 108237.582286: syscalls:sys_enter_nanosleep: rqtp: 0x7fff1948ac40, rmtp: 0x00000000 sleep 13638 [001] 108237.582289: sched:sched_stat_runtime: comm=sleep pid=13638 runtime=578104 [ns] vruntime=202889459556 [ns] sleep 13638 [001] 108237.582291: sched:sched_switch: sleep:13638 [120] S ==> swapper/1:0 [120] swapper 0 [001] 108238.582428: sched:sched_waking: comm=sleep pid=13638 prio=120 target_cpu=001 swapper 0 [001] 108238.582458: sched:sched_wakeup: sleep:13638 [120] success=1 CPU:001 sleep 13638 [001] 108238.582698: sched:sched_stat_runtime: comm=sleep pid=13638 runtime=173915 [ns] vruntime=202889633471 [ns] sleep 13638 [001] 108238.582782: sched:sched_process_exit: comm=sleep pid=13638 prio=120 # # perf script --switch-on syscalls:sys_enter_nanosleep sleep 13638 [001] 108237.582289: sched:sched_stat_runtime: comm=sleep pid=13638 runtime=578104 [ns] vruntime=202889459556 [ns] sleep 13638 [001] 108237.582291: sched:sched_switch: sleep:13638 [120] S ==> swapper/1:0 [120] swapper 0 [001] 108238.582428: sched:sched_waking: comm=sleep pid=13638 prio=120 target_cpu=001 swapper 0 [001] 108238.582458: sched:sched_wakeup: sleep:13638 [120] success=1 CPU:001 sleep 13638 [001] 108238.582698: sched:sched_stat_runtime: comm=sleep pid=13638 runtime=173915 [ns] vruntime=202889633471 [ns] sleep 13638 [001] 108238.582782: sched:sched_process_exit: comm=sleep pid=13638 prio=120 # Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com> Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: William Cohen <wcohen@redhat.com> Cc: Florian Weimer <fweimer@redhat.com> Link: https://lkml.kernel.org/n/tip-0omwwoywj1v63gu8cz0tr0cy@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-08-15perf script: Allow specifying event to switch on processing of other eventsArnaldo Carvalho de Melo1-0/+3
Sometime we want to only consider events after something happens, so allow discarding events till such events is found, e.g.: Record all scheduler tracepoints and the sys_enter_nanosleep syscall event for the 'sleep 1' workload: # perf record -e sched:*,syscalls:sys_enter_nanosleep sleep 1 [ perf record: Woken up 31 times to write data ] [ perf record: Captured and wrote 0.032 MB perf.data (10 samples) ] # So we have these events in the generated perf data file: # perf evlist sched:sched_kthread_stop sched:sched_kthread_stop_ret sched:sched_waking sched:sched_wakeup sched:sched_wakeup_new sched:sched_switch sched:sched_migrate_task sched:sched_process_free sched:sched_process_exit sched:sched_wait_task sched:sched_process_wait sched:sched_process_fork sched:sched_process_exec sched:sched_stat_wait sched:sched_stat_sleep sched:sched_stat_iowait sched:sched_stat_blocked sched:sched_stat_runtime sched:sched_pi_setprio sched:sched_move_numa sched:sched_stick_numa sched:sched_swap_numa sched:sched_wake_idle_without_ipi syscalls:sys_enter_nanosleep # Tip: use 'perf evlist --trace-fields' to show fields for tracepoint events # Then show all of the events that actually took place in this 'perf record' session: # perf script :13637 13637 [002] 108237.581529: sched:sched_waking: comm=perf pid=13638 prio=120 target_cpu=001 :13637 13637 [002] 108237.581537: sched:sched_wakeup: perf:13638 [120] success=1 CPU:001 sleep 13638 [001] 108237.581992: sched:sched_process_exec: filename=/usr/bin/sleep pid=13638 old_pid=13638 sleep 13638 [001] 108237.582286: syscalls:sys_enter_nanosleep: rqtp: 0x7fff1948ac40, rmtp: 0x00000000 sleep 13638 [001] 108237.582289: sched:sched_stat_runtime: comm=sleep pid=13638 runtime=578104 [ns] vruntime=202889459556 [ns] sleep 13638 [001] 108237.582291: sched:sched_switch: sleep:13638 [120] S ==> swapper/1:0 [120] swapper 0 [001] 108238.582428: sched:sched_waking: comm=sleep pid=13638 prio=120 target_cpu=001 swapper 0 [001] 108238.582458: sched:sched_wakeup: sleep:13638 [120] success=1 CPU:001 sleep 13638 [001] 108238.582698: sched:sched_stat_runtime: comm=sleep pid=13638 runtime=173915 [ns] vruntime=202889633471 [ns] sleep 13638 [001] 108238.582782: sched:sched_process_exit: comm=sleep pid=13638 prio=120 # Now lets see only the ones that took place after a certain "marker": # perf script --switch-on syscalls:sys_enter_nanosleep sleep 13638 [001] 108237.582289: sched:sched_stat_runtime: comm=sleep pid=13638 runtime=578104 [ns] vruntime=202889459556 [ns] sleep 13638 [001] 108237.582291: sched:sched_switch: sleep:13638 [120] S ==> swapper/1:0 [120] swapper 0 [001] 108238.582428: sched:sched_waking: comm=sleep pid=13638 prio=120 target_cpu=001 swapper 0 [001] 108238.582458: sched:sched_wakeup: sleep:13638 [120] success=1 CPU:001 sleep 13638 [001] 108238.582698: sched:sched_stat_runtime: comm=sleep pid=13638 runtime=173915 [ns] vruntime=202889633471 [ns] sleep 13638 [001] 108238.582782: sched:sched_process_exit: comm=sleep pid=13638 prio=120 # Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Florian Weimer <fweimer@redhat.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: William Cohen <wcohen@redhat.com> Link: https://lkml.kernel.org/n/tip-f1oo0ufdhrkx6nhy2lj1ierm@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-08-14perf.data documentation: Clarify HEADER_SAMPLE_TOPOLOGY formatVince Weaver1-10/+15
The perf.data file format documentation for HEADER_SAMPLE_TOPOLOGY specifies the layout in a confusing manner that doesn't match the rest of the document. This patch attempts to describe things consistent with the rest of the file. Signed-off-by: Vince Weaver <vincent.weaver@maine.edu> Acked-by: Jiri Olsa <jolsa@kernel.org> Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com> Cc: Andi Kleen <ak@linux.intel.com> Cc: Chong Jiang <chongjiang@chromium.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Simon Que <sque@chromium.org> Link: http://lkml.kernel.org/r/alpine.DEB.2.21.1908011425240.14303@macbook-air Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-08-14perf intel-pt: Add brief documentation for PEBS via Intel PTAdrian Hunter1-0/+15
Document how to select PEBS via Intel PT and how to display synthesized PEBS samples. Signed-off-by: Adrian Hunter <adrian.hunter@intel.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Kan Liang <kan.liang@linux.intel.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Peter Zijlstra <peterz@infradead.org> Link: http://lkml.kernel.org/r/20190806084606.4021-8-alexander.shishkin@linux.intel.com Signed-off-by: Alexander Shishkin <alexander.shishkin@linux.intel.com> [ Update the example to use a group with intel_pt// as the group leader, as per Alex comment ] Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-08-14perf tools: Add aux-output config termAdrian Hunter1-0/+2
Expose the aux_output attribute flag to the user to configure, by adding a config term 'aux-output'. For events that support it, selection of 'aux-output' causes the generation of AUX records instead of event records. This requires that an AUX area event is also provided. Signed-off-by: Adrian Hunter <adrian.hunter@intel.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Kan Liang <kan.liang@linux.intel.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Peter Zijlstra <peterz@infradead.org> Link: http://lkml.kernel.org/r/20190806084606.4021-7-alexander.shishkin@linux.intel.com Signed-off-by: Alexander Shishkin <alexander.shishkin@linux.intel.com> Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-08-14perf tools: Add itrace option 'o' to synthesize aux-output eventsAdrian Hunter1-0/+2
Add itrace option 'o' to synthesize events recorded in the AUX area due to the use of perf record's aux-output config term. Signed-off-by: Adrian Hunter <adrian.hunter@intel.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Kan Liang <kan.liang@linux.intel.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Peter Zijlstra <peterz@infradead.org> Link: http://lkml.kernel.org/r/20190806084606.4021-5-alexander.shishkin@linux.intel.com Signed-off-by: Alexander Shishkin <alexander.shishkin@linux.intel.com> Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-08-14perf record: Add an option to take an AUX snapshot on exitAlexander Shishkin1-3/+8
It is sometimes useful to generate a snapshot when perf record exits; I've been using a wrapper script around the workload that would do a killall -USR2 perf when the workload exits. This patch makes it easier and also works when perf record is attached to a pre-existing task. A new snapshot option 'e' can be specified in -S to enable this behavior: root@elsewhere:~# perf record -e intel_pt// -Se sleep 1 [ perf record: Woken up 2 times to write data ] [ perf record: Captured and wrote 0.085 MB perf.data ] Co-developed-by: Adrian Hunter <adrian.hunter@intel.com> Signed-off-by: Alexander Shishkin <alexander.shishkin@linux.intel.com> Cc: Peter Zijlstra <peterz@infradead.org> Link: http://lkml.kernel.org/r/20190806144101.62892-1-alexander.shishkin@linux.intel.com [ Fixed up !HAVE_AUXTRACE_SUPPORT build in builtin-record.c, adding 2 missing __maybe_unused ] Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-08-12perf config: Document the PERF_CONFIG environment variableArnaldo Carvalho de Melo1-0/+4
There was a provision for setting this variable, but not the getenv("PERF_CONFIG") call to set it, as this was fixed in the previous cset, document that it can be used to ask for using an alternative .perfconfig file or to disable reading whatever file exists in the system or home directory, i.e. using: export PERF_CONFIG=/dev/null Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Luis Cláudio Gonçalves <lclaudio@redhat.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Taeung Song <treeze.taeung@gmail.com> Link: https://lkml.kernel.org/n/tip-0u4o967hsk7j0o50zp9ctn89@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-08-08perf tools: Fix a typo in a variable name in the Documentation MakefileMasanari Iida1-1/+1
This patch fix a spelling typo in a variable name in the Documentation Makefile. Signed-off-by: Masanari Iida <standby24x7@gmail.com> Reviewed-by: Mukesh Ojha <mojha@codeaurora.org> Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Peter Zijlstra <peterz@infradead.org> Link: http://lkml.kernel.org/r/20190801032812.25018-1-standby24x7@gmail.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-07-29perf tools: Fix perf.data documentation units for memory sizeVince Weaver1-1/+1
The perf.data-file-format documentation incorrectly says the HEADER_TOTAL_MEM results are in bytes. The results are in kilobytes (perf reads the value from /proc/meminfo) Signed-off-by: Vince Weaver <vincent.weaver@maine.edu> Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Peter Zijlstra <peterz@infradead.org> Link: http://lkml.kernel.org/r/alpine.DEB.2.21.1907251155500.22624@macbook-air Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-07-23Merge tag 'perf-urgent-for-mingo-5.3-20190723' of git://git.kernel.org/pub/scm/linux/kernel/git/acme/linux into perf/urgentIngo Molnar1-4/+4
Pull perf/urgent fixes from Arnaldo Carvalho de Melo: perf.data: Alexey Budankov: - Fix loading of compressed data split across adjacent records Jiri Olsa: - Fix buffer size setting for processing CPU topology perf.data header. perf stat: Jiri Olsa: - Fix segfault for event group in repeat mode Cong Wang: - Always separate "stalled cycles per insn" line, it was being appended to the "instructions" line. perf script: Andi Kleen: - Fix --max-blocks man page description. - Improve man page description of metrics. - Fix off by one in brstackinsn IPC computation. perf probe: Arnaldo Carvalho de Melo: - Avoid calling freeing routine multiple times for same pointer. perf build: - Do not use -Wshadow on gcc < 4.8, avoiding too strict warnings treated as errors, breaking the build. Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com> Signed-off-by: Ingo Molnar <mingo@kernel.org>
2019-07-23perf script: Improve man page description of metricsAndi Kleen1-3/+3
Clarify that a metric is based on events, not referring to itself. Also some improvements with the sentences. Signed-off-by: Andi Kleen <ak@linux.intel.com> Cc: Jiri Olsa <jolsa@kernel.org> Link: http://lkml.kernel.org/r/20190711181922.18765-3-andi@firstfloor.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-07-23perf script: Fix --max-blocks man page descriptionAndi Kleen1-1/+1
The --max-blocks description was using the old name brstackasm. Use brstackinsn instead. Signed-off-by: Andi Kleen <ak@linux.intel.com> Cc: Jiri Olsa <jolsa@kernel.org> Link: http://lkml.kernel.org/r/20190711181922.18765-1-andi@firstfloor.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-07-18Merge tag 'trace-v5.3' of git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-traceLinus Torvalds1-1/+2
Pull tracing updates from Steven Rostedt: "The main changes in this release include: - Add user space specific memory reading for kprobes - Allow kprobes to be executed earlier in boot The rest are mostly just various clean ups and small fixes" * tag 'trace-v5.3' of git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace: (33 commits) tracing: Make trace_get_fields() global tracing: Let filter_assign_type() detect FILTER_PTR_STRING tracing: Pass type into tracing_generic_entry_update() ftrace/selftest: Test if set_event/ftrace_pid exists before writing ftrace/selftests: Return the skip code when tracing directory not configured in kernel tracing/kprobe: Check registered state using kprobe tracing/probe: Add trace_event_call accesses APIs tracing/probe: Add probe event name and group name accesses APIs tracing/probe: Add trace flag access APIs for trace_probe tracing/probe: Add trace_event_file access APIs for trace_probe tracing/probe: Add trace_event_call register API for trace_probe tracing/probe: Add trace_probe init and free functions tracing/uprobe: Set print format when parsing command tracing/kprobe: Set print format right after parsed command kprobes: Fix to init kprobes in subsys_initcall tracepoint: Use struct_size() in kmalloc() ring-buffer: Remove HAVE_64BIT_ALIGNED_ACCESS ftrace: Enable trampoline when rec count returns back to one tracing/kprobe: Do not run kprobe boot tests if kprobe_event is on cmdline tracing: Make a separate config for trace event self tests ...
2019-07-02perf tools: Fix typos / broken sentencesAndi Kleen2-2/+2
- Fix a typo in the man page - Fix a tip that doesn't make any sense. Signed-off-by: Andi Kleen <ak@linux.intel.com> Cc: Jiri Olsa <jolsa@kernel.org> Link: http://lkml.kernel.org/r/20190628220900.13741-1-andi@firstfloor.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-07-02perf diff: Documentation -c cycles optionJin Yao1-3/+14
Documentation the new computation selection 'cycles'. v4: --- Change the column 'Block cycles diff [start:end]' to '[Program Block Range] Cycles Diff' Signed-off-by: Jin Yao <yao.jin@linux.intel.com> Reviewed-by: Jiri Olsa <jolsa@kernel.org> Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com> Cc: Andi Kleen <ak@linux.intel.com> Cc: Jin Yao <yao.jin@intel.com> Cc: Kan Liang <kan.liang@linux.intel.com> Cc: Peter Zijlstra <peterz@infradead.org> Link: http://lkml.kernel.org/r/1561713784-30533-8-git-send-email-yao.jin@linux.intel.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-06-10perf time-utils: Add support for multiple explicit time intervalsAdrian Hunter3-5/+9
Currently only a single explicit time range is accepted. Add support for multiple ranges separated by spaces, which requires the string to be quoted. Update the time utils test accordingly. Signed-off-by: Adrian Hunter <adrian.hunter@intel.com> Cc: Jin Yao <yao.jin@linux.intel.com> Cc: Jiri Olsa <jolsa@redhat.com> Link: http://lkml.kernel.org/r/20190604130017.31207-20-adrian.hunter@intel.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-06-10perf time-utils: Fix --time documentationAdrian Hunter3-9/+9
Correct some punctuation and spelling and correct the format to show that the time resolution is nanoseconds not microseconds. Signed-off-by: Adrian Hunter <adrian.hunter@intel.com> Cc: Jin Yao <yao.jin@linux.intel.com> Cc: Jiri Olsa <jolsa@redhat.com> Link: http://lkml.kernel.org/r/20190604130017.31207-16-adrian.hunter@intel.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-06-10perf config: Update default value for llvm.clang-bpf-cmd-templateLeo Yan1-3/+6
The clang bpf cmdline template has defined default value in the file tools/perf/util/llvm-utils.c, which has been changed for several times. This patch updates the documentation to reflect the latest default value for the configuration llvm.clang-bpf-cmd-template. Signed-off-by: Leo Yan <leo.yan@linaro.org> Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com> Cc: Alexei Starovoitov <ast@kernel.org> Cc: Andi Kleen <ak@linux.intel.com> Cc: Daniel Borkmann <daniel@iogearbox.net> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mark Drayton <mbd@fb.com> Cc: Martin KaFai Lau <kafai@fb.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Song Liu <songliubraving@fb.com> Cc: Yonghong Song <yhs@fb.com> Cc: bpf@vger.kernel.org Cc: netdev@vger.kernel.org Fixes: d35b168c3dcd ("perf bpf: Give precedence to bpf header dir") Fixes: cb76371441d0 ("perf llvm: Allow passing options to llc in addition to clang") Fixes: 1b16fffa389d ("perf llvm-utils: Add bpf include path to clang command line") Link: http://lkml.kernel.org/r/20190607143508.18141-1-leo.yan@linaro.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-06-10perf data: Fix perf.data documentation for HEADER_CPU_TOPOLOGYArnaldo Carvalho de Melo1-7/+22
The 'die' info isn't in the same array as core and socket ids, and we missed the 'dies' string list, that comes right after the 'core' + 'socket' id variable length array, followed by the VLA for the dies. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Andi Kleen <ak@linux.intel.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Kan Liang <kan.liang@linux.intel.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Peter Zijlstra <peterz@infradead.org> Fixes: c9cb12c5ba08 ("perf header: Add die information in CPU topology") Link: https://lkml.kernel.org/n/tip-nubi6mxp2n8ofvlx7ph6k3h6@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-06-10perf header: Rename "sibling cores" to "sibling sockets"Kan Liang1-1/+1
The "sibling cores" actually shows the sibling CPUs of a socket. The name "sibling cores" is very misleading. Rename "sibling cores" to "sibling sockets" Signed-off-by: Kan Liang <kan.liang@linux.intel.com> Reviewed-by: Jiri Olsa <jolsa@kernel.org> Cc: Andi Kleen <ak@linux.intel.com> Cc: Peter Zijlstra <peterz@infradead.org> Link: http://lkml.kernel.org/r/1559688644-106558-4-git-send-email-kan.liang@linux.intel.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-06-10perf stat: Support per-die aggregationKan Liang1-0/+10
It is useful to aggregate counts per die. E.g. Uncore becomes die-scope on Xeon Cascade Lake-AP. Introduce a new option "--per-die" to support per-die aggregation. The global id for each core has been changed to socket + die id + core id. The global id for each die is socket + die id. Add die information for per-core aggregation. The output of per-core aggregation will be changed from "S0-C0" to "S0-D0-C0". Any scripts which rely on the output format of per-core aggregation probably be broken. For 'perf stat record/report', there is no die information when processing the old perf.data. The per-die result will be the same as per-socket. Committer notes: Renamed 'die' variable to 'die_id' to fix the build in some systems: CC /tmp/build/perf/builtin-script.o cc1: warnings being treated as errors builtin-stat.c: In function 'perf_env__get_die': builtin-stat.c:963: error: declaration of 'die' shadows a global declaration util/util.h:19: error: shadowed declaration is here mv: cannot stat `/tmp/build/perf/.builtin-stat.o.tmp': No such file or directory Signed-off-by: Kan Liang <kan.liang@linux.intel.com> Reviewed-by: Jiri Olsa <jolsa@kernel.org> Cc: Andi Kleen <ak@linux.intel.com> Cc: Peter Zijlstra <peterz@infradead.org> Link: https://lkml.kernel.org/n/tip-bsnhx7vgsuu6ei307mw60mbj@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-06-10perf header: Add die information in CPU topologyKan Liang1-2/+7
With the new CPUID.1F, a new level type of CPU topology, 'die', is introduced. The 'die' information in CPU topology should be added in perf header. To be compatible with old perf.data, the patch checks the section size before reading the die information. The new info is added at the end of the cpu_topology section, the old perf tool ignores the extra data. It never reads data crossing the section boundary. The new perf tool with the patch can be used on legacy kernel. Add a new function has_die_topology() to check if die topology information is supported by kernel. The function only check X86 and CPU 0. Assuming other CPUs have same topology. Use similar method for core and socket to support die id and sibling dies string. Signed-off-by: Kan Liang <kan.liang@linux.intel.com> Reviewed-by: Jiri Olsa <jolsa@kernel.org> Cc: Andi Kleen <ak@linux.intel.com> Cc: Peter Zijlstra <peterz@infradead.org> Link: http://lkml.kernel.org/r/1559688644-106558-2-git-send-email-kan.liang@linux.intel.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-06-10perf record: Add support to collect callchains from kernel or user space onlyyuzhoujian1-0/+11
One can just record callchains in the kernel or user space with this new options. We can use it together with "--all-kernel" options. This two options is used just like print_stack(sys) or print_ustack(usr) for systemtap. Shown below is the usage of this new option combined with "--all-kernel" options: 1. Configure all used events to run in kernel space and just collect kernel callchains. $ perf record -a -g --all-kernel --kernel-callchains 2. Configure all used events to run in kernel space and just collect user callchains. $ perf record -a -g --all-kernel --user-callchains Committer notes: Improved documentation to state that asking for kernel callchains really is asking for excluding user callchains, and vice versa. Further mentioned that using both won't get both, but nothing, as both will be excluded. Signed-off-by: yuzhoujian <yuzhoujian@didichuxing.com> Acked-by: Jiri Olsa <jolsa@kernel.org> Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Milian Wolff <milian.wolff@kdab.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/r/1559222962-22891-1-git-send-email-ufo19890607@gmail.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-06-05perf db-export: Add brief documentationAdrian Hunter1-0/+41
Add brief documentation to explain how the database export maintains backward and forward compatibility. Signed-off-by: Adrian Hunter <adrian.hunter@intel.com> Cc: Jiri Olsa <jolsa@redhat.com> Link: http://lkml.kernel.org/r/20190520113728.14389-15-adrian.hunter@intel.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-06-05perf intel-pt: Document IPC usageAdrian Hunter1-0/+30
Add brief documentation about instructions-per-cycle (IPC) information derived from Intel PT. Signed-off-by: Adrian Hunter <adrian.hunter@intel.com> Cc: Jiri Olsa <jolsa@redhat.com> Link: http://lkml.kernel.org/r/20190520113728.14389-13-adrian.hunter@intel.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-06-05perf script: Add output of IPC ratioAdrian Hunter1-1/+4
Add field 'ipc' to display instructions-per-cycle. Example: perf record -e intel_pt/cyc/u ls perf script --insn-trace --xed -F+ipc,-dso,-cpu,-tid ls 2670177.697113434: 7f0dfdbcd090 _start+0x0 mov %rsp, %rdi IPC: 0.00 (1/877) ls 2670177.697113434: 7f0dfdbcd093 _start+0x3 callq 0x7f0dfdbce030 ls 2670177.697113434: 7f0dfdbce030 _dl_start+0x0 pushq %rbp ls 2670177.697113434: 7f0dfdbce031 _dl_start+0x1 mov %rsp, %rbp ls 2670177.697113434: 7f0dfdbce034 _dl_start+0x4 pushq %r15 ls 2670177.697113434: 7f0dfdbce036 _dl_start+0x6 pushq %r14 ls 2670177.697113434: 7f0dfdbce038 _dl_start+0x8 pushq %r13 ls 2670177.697113434: 7f0dfdbce03a _dl_start+0xa pushq %r12 ls 2670177.697113434: 7f0dfdbce03c _dl_start+0xc mov %rdi, %r12 ls 2670177.697113434: 7f0dfdbce03f _dl_start+0xf pushq %rbx ls 2670177.697113434: 7f0dfdbce040 _dl_start+0x10 sub $0x38, %rsp ls 2670177.697113434: 7f0dfdbce044 _dl_start+0x14 rdtsc ls 2670177.697113434: 7f0dfdbce046 _dl_start+0x16 mov %eax, %eax ls 2670177.697113434: 7f0dfdbce048 _dl_start+0x18 shl $0x20, %rdx ls 2670177.697113434: 7f0dfdbce04c _dl_start+0x1c or %rax, %rdx ls 2670177.697114471: 7f0dfdbce04f _dl_start+0x1f movq 0x27e22(%rip), %rax IPC: 0.00 (15/1685) ls 2670177.697116177: 7f0dfdbce056 _dl_start+0x26 movq %rdx, 0x27683(%rip) IPC: 0.00 (1/881) Note, the IPC values are low due to page faults at the beginning of execution. The additional cycles are due to the time to enter the kernel, not the actual kernel page fault handler. Signed-off-by: Adrian Hunter <adrian.hunter@intel.com> Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com> Cc: Jiri Olsa <jolsa@redhat.com> Link: http://lkml.kernel.org/r/20190520113728.14389-9-adrian.hunter@intel.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-06-05perf data: Document directory format header: HEADER_DIR_FORMATArnaldo Carvalho de Melo1-0/+17
We forgot to update the perf.data file format document for the HEADER_DIR_FORMAT header, do it now from comments in the patch introducing it. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com> Cc: Alexey Budankov <alexey.budankov@linux.intel.com> Cc: Andi Kleen <ak@linux.intel.com> Cc: Chong Jiang <chongjiang@chromium.org> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Simon Que <sque@chromium.org> Fixes: 258031c017c3 ("perf header: Add DIR_FORMAT feature to describe directory data") Link: https://lkml.kernel.org/n/tip-jbrzb7ijb5al33gi8br6f9rr@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-06-05perf data: Document clockid header: HEADER_CLOCKIDArnaldo Carvalho de Melo1-0/+6
We forgot to update the perf.data file format document for the HEADER_CLOCKID header, do it now from comments in the patch introducing it. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com> Cc: Alexey Budankov <alexey.budankov@linux.intel.com> Cc: Andi Kleen <ak@linux.intel.com> Cc: Chong Jiang <chongjiang@chromium.org> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Simon Que <sque@chromium.org> Fixes: cf7905165fee ("perf record: Encode -k clockid frequency into Perf trace") Link: https://lkml.kernel.org/n/tip-slhnjp06027j3ae17qqetzxj@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-06-05perf data: Document memory topology header: HEADER_MEM_TOPOLOGYArnaldo Carvalho de Melo1-0/+24
We forgot to update the perf.data file format document for the HEADER_MEM_TOPOLOGY header, do it now from comments in the patch introducing it. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Andi Kleen <ak@linux.intel.com> Cc: Chong Jiang <chongjiang@chromium.org> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Simon Que <sque@chromium.org> Fixes: e2091cedd51b ("perf tools: Add MEM_TOPOLOGY feature to perf data file") Link: https://lkml.kernel.org/n/tip-h5lcm1nbe9ztxwm61gmadd56@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-06-05perf data: Add description of header HEADER_BPF_PROG_INFO and HEADER_BPF_BTFSong Liu1-0/+16
This patch addes description of HEADER_BPF_PROG_INFO and HEADER_BPF_BTF to perf.data-file-format.txt. Requested-by: Arnaldo Carvalho de Melo <acme@redhat.com> Signed-off-by: Song Liu <songliubraving@fb.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Peter Zijlstra <peterz@infradead.org> Fixes: 606f972b1361 ("perf bpf: Save bpf_prog_info information as headers to perf.data") Link: http://lkml.kernel.org/r/20190521064406.2498925-1-songliubraving@fb.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-06-03Merge tag 'v5.2-rc3' into perf/core, to pick up fixesIngo Molnar1-0/+1
Signed-off-by: Ingo Molnar <mingo@kernel.org>
2019-05-28perf script: Add --show-bpf-events to show eBPF related eventsJiri Olsa1-0/+3
Add the --show-bpf-events command line option to show the eBPF related events: PERF_RECORD_KSYMBOL PERF_RECORD_BPF_EVENT Usage: # perf record -a ... # perf script --show-bpf-events ... swapper 0 [000] 0.000000: PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc0ef971d len 229 type 1 flags 0x0 name bpf_prog_2a142ef67aaad174 swapper 0 [000] 0.000000: PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 36 ... Committer testing: # perf script --show-bpf-events | egrep -i 'PERF_RECORD_(BPF|KSY)' 0 PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc029a6c3 len 229 type 1 flags 0x0 name bpf_prog_7be49e3934a125ba 0 PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 47 0 PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc029c1ae len 229 type 1 flags 0x0 name bpf_prog_2a142ef67aaad174 0 PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 48 0 PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc02ddd1c len 229 type 1 flags 0x0 name bpf_prog_7be49e3934a125ba 0 PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 49 0 PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc02dfc11 len 229 type 1 flags 0x0 name bpf_prog_2a142ef67aaad174 0 PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 50 0 PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc045da0a len 229 type 1 flags 0x0 name bpf_prog_7be49e3934a125ba 0 PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 51 0 PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc04ef4b4 len 229 type 1 flags 0x0 name bpf_prog_2a142ef67aaad174 0 PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 52 0 PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc09e15da len 229 type 1 flags 0x0 name bpf_prog_7be49e3934a125ba 0 PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 53 0 PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc0d2b1a3 len 229 type 1 flags 0x0 name bpf_prog_2a142ef67aaad174 0 PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 54 0 PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc0fd9850 len 381 type 1 flags 0x0 name bpf_prog_819967866022f1e1_sys_enter 0 PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 179 0 PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc0feb1ec len 191 type 1 flags 0x0 name bpf_prog_c1bd85c092d6e4aa_sys_exit 0 PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 180 ^C[root@quaco pt]# perf evlist intel_pt//ku dummy:u # Signed-off-by: Jiri Olsa <jolsa@kernel.org> Acked-by: Song Liu <songliubraving@fb.com> Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com> Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com> Cc: Andi Kleen <ak@linux.intel.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stanislav Fomichev <sdf@google.com> Link: http://lkml.kernel.org/r/20190508132010.14512-11-jolsa@kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-05-28perf top: Add --namespaces optionNamhyung Kim1-0/+5
Since 'perf record' already have this option, let's have it for 'perf top' as well. Signed-off-by: Namhyung Kim <namhyung@kernel.org> Cc: Hari Bathini <hbathini@linux.vnet.ibm.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Krister Johansen <kjlx@templeofstupid.com> Link: http://lkml.kernel.org/r/20190522053250.207156-4-namhyung@kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-05-28perf intel-pt: Fix itrace defaults for perf script intel-pt documentationAdrian Hunter1-5/+5
Fix intel-pt documentation to reflect the change of itrace defaults for perf script. Signed-off-by: Adrian Hunter <adrian.hunter@intel.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: stable@vger.kernel.org Fixes: 4eb068157121 ("perf script: Make itrace script default to all calls") Link: http://lkml.kernel.org/r/20190520113728.14389-4-adrian.hunter@intel.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-05-25perf-probe: Add user memory access attribute supportMasami Hiramatsu1-1/+2
Add user memory access attribute for kprobe event arguments. If a given 'local variable' is in user-space, User can specify memory access method by '@user' suffix. This is not only for string but also for data structure. If we access a field of data structure in user memory from kernel on some arch, it will fail. e.g. perf probe -a "sched_setscheduler param->sched_priority" This will fail to access the "param->sched_priority" because the param is __user pointer. Instead, we can now specify @user suffix for such argument. perf probe -a "sched_setscheduler param->sched_priority@user" Note that kernel memory access with "@user" must always fail on any arch. Link: http://lkml.kernel.org/r/155789874562.26965.10836126971405890891.stgit@devnote2 Acked-by: Ingo Molnar <mingo@kernel.org> Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org> Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
2019-05-21treewide: Add SPDX license identifier - Makefile/KconfigThomas Gleixner1-0/+1
Add SPDX license identifiers to all Make/Kconfig files which: - Have no license information of any form These files fall under the project license, GPL v2 only. The resulting SPDX license identifier is: GPL-2.0-only Signed-off-by: Thomas Gleixner <tglx@linutronix.de> Signed-off-by: Greg Kroah-Hartman <gregkh@linuxfoundation.org>
2019-05-16perf stat: Support 'percore' event qualifierJin Yao1-0/+4
With this patch, we can use the 'percore' event qualifier in perf-stat. root@skl:/tmp# perf stat -e cpu/event=0,umask=0x3,percore=1/,cpu/event=0,umask=0x3/ -a -A -I1000 1.000773050 S0-C0 98,352,832 cpu/event=0,umask=0x3,percore=1/ (50.01%) 1.000773050 S0-C1 103,763,057 cpu/event=0,umask=0x3,percore=1/ (50.02%) 1.000773050 S0-C2 196,776,995 cpu/event=0,umask=0x3,percore=1/ (50.02%) 1.000773050 S0-C3 176,493,779 cpu/event=0,umask=0x3,percore=1/ (50.02%) 1.000773050 CPU0 47,699,641 cpu/event=0,umask=0x3/ (50.02%) 1.000773050 CPU1 49,052,451 cpu/event=0,umask=0x3/ (49.98%) 1.000773050 CPU2 102,771,422 cpu/event=0,umask=0x3/ (49.98%) 1.000773050 CPU3 100,784,662 cpu/event=0,umask=0x3/ (49.98%) 1.000773050 CPU4 43,171,342 cpu/event=0,umask=0x3/ (49.98%) 1.000773050 CPU5 54,152,158 cpu/event=0,umask=0x3/ (49.98%) 1.000773050 CPU6 93,618,410 cpu/event=0,umask=0x3/ (49.98%) 1.000773050 CPU7 74,477,589 cpu/event=0,umask=0x3/ (49.99%) In this example, we count the event 'ref-cycles' per-core and per-CPU in one perf stat command-line. From the output, we can see: S0-C0 = CPU0 + CPU4 S0-C1 = CPU1 + CPU5 S0-C2 = CPU2 + CPU6 S0-C3 = CPU3 + CPU7 So the result is expected (tiny difference is ignored). Note that, the 'percore' event qualifier needs to use with option '-A'. Signed-off-by: Jin Yao <yao.jin@linux.intel.com> Tested-by: Ravi Bangoria <ravi.bangoria@linux.ibm.com> Acked-by: Jiri Olsa <jolsa@kernel.org> Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com> Cc: Andi Kleen <ak@linux.intel.com> Cc: Jin Yao <yao.jin@intel.com> Cc: Kan Liang <kan.liang@linux.intel.com> Cc: Peter Zijlstra <peterz@infradead.org> Link: http://lkml.kernel.org/r/1555077590-27664-4-git-send-email-yao.jin@linux.intel.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-05-16perf tools: Add a 'percore' event qualifierJin Yao1-0/+12
Add a 'percore' event qualifier, like cpu/event=0,umask=0x3,percore=1/, that sums up the event counts for both hardware threads in a core. We can already do this with --per-core, but it's often useful to do this together with other metrics that are collected per hardware thread. So we need to support this per-core counting on a event level. This can be implemented in only the user tool, no kernel support needed. v4: --- 1. Add Arnaldo's patch which updates the documentation for this new qualifier. 2. Rebase to latest perf/core branch v3: --- Simplify the code according to Jiri's comments. Before: "return term->val.percore ? true : false;" Now: "return term->val.percore;" v2: --- Change the qualifier name from 'coresum' to 'percore' according to comments from Jiri and Andi. Signed-off-by: Jin Yao <yao.jin@linux.intel.com> Tested-by: Ravi Bangoria <ravi.bangoria@linux.ibm.com> Acked-by: Jiri Olsa <jolsa@kernel.org> Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com> Cc: Andi Kleen <ak@linux.intel.com> Cc: Jin Yao <yao.jin@intel.com> Cc: Kan Liang <kan.liang@linux.intel.com> Cc: Peter Zijlstra <peterz@infradead.org> Link: http://lkml.kernel.org/r/1555077590-27664-2-git-send-email-yao.jin@linux.intel.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-05-16perf docs: Add description for stderrThomas Richter1-0/+2
'perf report' displays recorded data on the screen and emits warnings and debug messages in the status line (last one on screen). perf also supports the possibility to write all debug messages to stderr (instead of writing them to the status line). This is achieved with the following command: # ./perf --debug stderr=1 report -vvvvv -i ~/fast.data 2>/tmp/2 # ll /tmp/2 -rw-rw-r-- 1 tmricht tmricht 5420835 May 7 13:46 /tmp/2 # The usage of variable stderr=1 is not documented, so add it to the perf man page. Signed-off-by: Thomas Richter <tmricht@linux.ibm.com> Cc: Heiko Carstens <heiko.carstens@de.ibm.com> Cc: Hendrik Brueckner <brueckner@linux.vnet.ibm.com> Cc: Martin Schwidefsky <schwidefsky@de.ibm.com> Link: http://lkml.kernel.org/r/20190513080220.91966-1-tmricht@linux.ibm.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-05-15perf parse-regs: Split parse_regsKan Liang1-1/+2
The available registers for --int-regs and --user-regs may be different, e.g. XMM registers. Split parse_regs into two dedicated functions for --int-regs and --user-regs respectively. Modify the warning message. "--user-regs=?" should be applied to show the available registers for --user-regs. Signed-off-by: Kan Liang <kan.liang@linux.intel.com> Tested-by: Ravi Bangoria <ravi.bangoria@linux.ibm.com> Cc: Andi Kleen <ak@linux.intel.com> Cc: Jiri Olsa <jolsa@kernel.org> Link: http://lkml.kernel.org/r/1557865174-56264-1-git-send-email-kan.liang@linux.intel.com [ Changed docs as suggested by Ravi and agreed by Kan ] Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-05-15perf record: Implement -z,--compression_level[=<n>] optionAlexey Budankov1-0/+5
Implemented -z,--compression_level[=<n>] option that enables compression of mmaped kernel data buffers content in runtime during perf record mode collection. Default option value is 1 (fastest compression). Compression overhead has been measured for serial and AIO streaming when profiling matrix multiplication workload: ------------------------------------------------------------- | SERIAL | AIO-1 | ----------------------------------------------------------------| |-z | OVH(x) | ratio(x) size(MiB) | OVH(x) | ratio(x) size(MiB) | |---------------------------------------------------------------| | 0 | 1,00 | 1,000 179,424 | 1,00 | 1,000 187,527 | | 1 | 1,04 | 8,427 181,148 | 1,01 | 8,474 188,562 | | 2 | 1,07 | 8,055 186,953 | 1,03 | 7,912 191,773 | | 3 | 1,04 | 8,283 181,908 | 1,03 | 8,220 191,078 | | 5 | 1,09 | 8,101 187,705 | 1,05 | 7,780 190,065 | | 8 | 1,05 | 9,217 179,191 | 1,12 | 6,111 193,024 | ----------------------------------------------------------------- OVH = (Execution time with -z N) / (Execution time with -z 0) ratio - compression ratio size - number of bytes that was compressed size ~= trace size x ratio Committer notes: Testing it I noticed that it failed to disable build id processing when compression is enabled, and as we'd have to uncompress everything to look for the PERF_RECORD_{MMAP,SAMPLE,etc} to figure out which build ids to read from DSOs, we better disable build id processing when compression is enabled, logging with pr_debug() when doing so: Original patch: # perf record -z2 ^C[ perf record: Woken up 1 times to write data ] 0x1746e0 [0x76]: failed to process type: 81 [Invalid argument] [ perf record: Captured and wrote 1.568 MB perf.data, compressed (original 0.452 MB, ratio is 3.995) ] # After auto-disabling build id processing when compression is enabled: $ perf record -z2 sleep 1 [ perf record: Woken up 1 times to write data ] [ perf record: Captured and wrote 0.001 MB perf.data, compressed (original 0.001 MB, ratio is 2.292) ] $ perf record -v -z2 sleep 1 Compression enabled, disabling build id collection at the end of the session. <SNIP extra -v pr_debug() messages> [ perf record: Woken up 1 times to write data ] [ perf record: Captured and wrote 0.001 MB perf.data, compressed (original 0.001 MB, ratio is 2.305) ] $ Also, with parts of the patch originally after this one moved to just before this one we get: $ perf record -z2 sleep 1 [ perf record: Woken up 1 times to write data ] [ perf record: Captured and wrote 0.001 MB perf.data, compressed (original 0.001 MB, ratio is 2.371) ] $ perf report -D | grep COMPRESS 0 0x1b8 [0x155]: PERF_RECORD_COMPRESSED: unhandled! 0 0x30d [0x80]: PERF_RECORD_COMPRESSED: unhandled! COMPRESSED events: 2 COMPRESSED events: 0 $ I.e. when faced with PERF_RECORD_COMPRESSED that we still have no code to process, we just show it as not being handled, skip them and continue, while before we had: $ perf report -D | grep COMPRESS 0x1b8 [0x169]: failed to process type: 81 [Invalid argument] Error: failed to process sample 0 0x1b8 [0x169]: PERF_RECORD_COMPRESSED $ Signed-off-by: Alexey Budankov <alexey.budankov@linux.intel.com> Reviewed-by: Jiri Olsa <jolsa@kernel.org> Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com> Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com> Cc: Andi Kleen <ak@linux.intel.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Peter Zijlstra <peterz@infradead.org> Link: http://lkml.kernel.org/r/9ff06518-ae63-a908-e44d-5d9e56dd66d9@linux.intel.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-05-15perf record: Implement COMPRESSED event record and its attributesAlexey Budankov1-0/+24
Implemented PERF_RECORD_COMPRESSED event, related data types, header feature and functions to write, read and print feature attributes from the trace header section. comp_mmap_len preserves the size of mmaped kernel buffer that was used during collection. comp_mmap_len size is used on loading stage as the size of decomp buffer for decompression of COMPRESSED events content. Committer notes: Fixed up conflict with BPF_PROG_INFO and BTF_BTF header features. Signed-off-by: Alexey Budankov <alexey.budankov@linux.intel.com> Reviewed-by: Jiri Olsa <jolsa@kernel.org> Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com> Cc: Andi Kleen <ak@linux.intel.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Peter Zijlstra <peterz@infradead.org> Link: http://lkml.kernel.org/r/ebbaf031-8dda-3864-ebc6-7922d43ee515@linux.intel.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-04-01perf record: Implement --mmap-flush=<number> optionAlexey Budankov1-0/+19
Implement a --mmap-flush option that specifies minimal number of bytes that is extracted from mmaped kernel buffer to store into a trace. The default option value is 1 byte what means every time trace writing thread finds some new data in the mmaped buffer the data is extracted, possibly compressed and written to a trace. $ tools/perf/perf record --mmap-flush 1024 -e cycles -- matrix.gcc $ tools/perf/perf record --aio --mmap-flush 1K -e cycles -- matrix.gcc The option is independent from -z setting, doesn't vary with compression level and can serve two purposes. The first purpose is to increase the compression ratio of a trace data. Larger data chunks are compressed more effectively so the implemented option allows specifying data chunk size to compress. Also at some cases executing more write syscalls with smaller data size can take longer than executing less write syscalls with bigger data size due to syscall overhead so extracting bigger data chunks specified by the option value could additionally decrease runtime overhead. The second purpose is to avoid self monitoring live-lock issue in system wide (-a) profiling mode. Profiling in system wide mode with compression (-a -z) can additionally induce data into the kernel buffers along with the data from monitored processes. If performance data rate and volume from the monitored processes is high then trace streaming and compression activity in the tool is also high. High tool process activity can lead to subtle live-lock effect when compression of single new byte from some of mmaped kernel buffer leads to generation of the next single byte at some mmaped buffer. So perf tool process ends up in endless self monitoring. Implemented synch parameter is the mean to force data move independently from the specified flush threshold value. Despite the provided flush value the tool needs capability to unconditionally drain memory buffers, at least in the end of the collection. Committer testing: Running with the default value, i.e. as soon as there is something to read go on consuming, we first write the synthesized events, small chunks of about 128 bytes: # perf trace -m 2048 --call-graph dwarf -e write -- perf record <SNIP> 101.142 ( 0.004 ms): perf/25821 write(fd: 3</root/perf.data>, buf: 0x210db60, count: 120) = 120 __libc_write (/usr/lib64/libpthread-2.28.so) ion (/home/acme/bin/perf) record__write (inlined) process_synthesized_event (/home/acme/bin/perf) perf_tool__process_synth_event (inlined) perf_event__synthesize_mmap_events (/home/acme/bin/perf) Then we move to reading the mmap buffers consuming the events put there by the kernel perf infrastructure: 107.561 ( 0.005 ms): perf/25821 write(fd: 3</root/perf.data>, buf: 0x7f1befc02000, count: 336) = 336 __libc_write (/usr/lib64/libpthread-2.28.so) ion (/home/acme/bin/perf) record__write (inlined) record__pushfn (/home/acme/bin/perf) perf_mmap__push (/home/acme/bin/perf) record__mmap_read_evlist (inlined) record__mmap_read_all (inlined) __cmd_record (inlined) cmd_record (/home/acme/bin/perf) 12919.953 ( 0.136 ms): perf/25821 write(fd: 3</root/perf.data>, buf: 0x7f1befc83150, count: 184984) = 184984 <SNIP same backtrace as in the 107.561 timestamp> 12920.094 ( 0.155 ms): perf/25821 write(fd: 3</root/perf.data>, buf: 0x7f1befc02150, count: 261816) = 261816 <SNIP same backtrace as in the 107.561 timestamp> 12920.253 ( 0.093 ms): perf/25821 write(fd: 3</root/perf.data>, buf: 0x7f1befb81120, count: 170832) = 170832 <SNIP same backtrace as in the 107.561 timestamp> If we limit it to write only when more than 16MB are available for reading, it throttles that to a quarter of the --mmap-pages set for 'perf record', which by default get to 528384 bytes, found out using 'record -v': mmap flush: 132096 mmap size 528384B With that in place all the writes coming from record__mmap_read_evlist(), i.e. from the mmap buffers setup by the kernel perf infrastructure were at least 132096 bytes long. Trying with a bigger mmap size: perf trace -e write perf record -v -m 2048 --mmap-flush 16M 74982.928 ( 2.471 ms): perf/26500 write(fd: 3</root/perf.data>, buf: 0x7ff94a6cc000, count: 3580888) = 3580888 74985.406 ( 2.353 ms): perf/26500 write(fd: 3</root/perf.data>, buf: 0x7ff949ecb000, count: 3453256) = 3453256 74987.764 ( 2.629 ms): perf/26500 write(fd: 3</root/perf.data>, buf: 0x7ff9496ca000, count: 3859232) = 3859232 74990.399 ( 2.341 ms): perf/26500 write(fd: 3</root/perf.data>, buf: 0x7ff948ec9000, count: 3769032) = 3769032 74992.744 ( 2.064 ms): perf/26500 write(fd: 3</root/perf.data>, buf: 0x7ff9486c8000, count: 3310520) = 3310520 74994.814 ( 2.619 ms): perf/26500 write(fd: 3</root/perf.data>, buf: 0x7ff947ec7000, count: 4194688) = 4194688 74997.439 ( 2.787 ms): perf/26500 write(fd: 3</root/perf.data>, buf: 0x7ff9476c6000, count: 4029760) = 4029760 Was again limited to a quarter of the mmap size: mmap flush: 2098176 mmap size 8392704B A warning about that would be good to have but can be added later, something like: "max flush is a quarter of the mmap size, if wanting to bump the mmap flush further, bump the mmap size as well using -m/--mmap-pages" Also rename the 'sync' parameters to 'synch' to keep tools/perf building with older glibcs: cc1: warnings being treated as errors builtin-record.c: In function 'record__mmap_read_evlist': builtin-record.c:775: warning: declaration of 'sync' shadows a global declaration /usr/include/unistd.h:933: warning: shadowed declaration is here builtin-record.c: In function 'record__mmap_read_all': builtin-record.c:856: warning: declaration of 'sync' shadows a global declaration /usr/include/unistd.h:933: warning: shadowed declaration is here Signed-off-by: Alexey Budankov <alexey.budankov@linux.intel.com> Reviewed-by: Jiri Olsa <jolsa@kernel.org> Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com> Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com> Cc: Andi Kleen <ak@linux.intel.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Peter Zijlstra <peterz@infradead.org> Link: http://lkml.kernel.org/r/f6600d72-ecfa-2eb7-7e51-f6954547d500@linux.intel.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-03-19perf config: Fix an error in the config template documentationChangbin Du1-1/+1
The option 'sort-order' should be 'sort_order'. Signed-off-by: Changbin Du <changbin.du@gmail.com> Reviewed-by: Jiri Olsa <jolsa@kernel.org> Cc: Alexei Starovoitov <ast@kernel.org> Cc: Daniel Borkmann <daniel@iogearbox.net> Cc: Milian Wolff <milian.wolff@kdab.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Steven Rostedt (VMware) <rostedt@goodmis.org> Fixes: 893c5c798be9 ("perf config: Show default report configuration in example and docs") Link: http://lkml.kernel.org/r/20190316080556.3075-5-changbin.du@gmail.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-03-19perf tools: Add doc about how to build perf with Asan and UBSanChangbin Du1-0/+24
AddressSanitizer (or ASan) and UndefinedBehaviorSanitizer (or UBSan) are very useful tools to detect program bugs: - AddressSanitizer (or ASan) is a GCC feature that detects memory corruption bugs such as buffer overflows and memory leaks. - UndefinedBehaviorSanitizer (or UBSan) is a fast undefined behavior detector supported by GCC. UBSan detects undefined behaviors of programs at runtime. This patch adds a document about how to use them on perf. Later patches will fix some of the issues disclosed by them. Signed-off-by: Changbin Du <changbin.du@gmail.com> Reviewed-by: Jiri Olsa <jolsa@kernel.org> Cc: Alexei Starovoitov <ast@kernel.org> Cc: Daniel Borkmann <daniel@iogearbox.net> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Steven Rostedt (VMware) <rostedt@goodmis.org> Link: http://lkml.kernel.org/r/20190316080556.3075-2-changbin.du@gmail.com [ Make some changes based on comments made by Jiri Olsa ] Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>