From b280b1148077a0365b3eedea53a2161932548459 Mon Sep 17 00:00:00 2001 From: Bill Thiede Date: Thu, 24 Oct 2019 13:57:41 -0700 Subject: [PATCH] Call more fuctions to see out profiling behaves. --- src/flamegraph.svg | 4 ++-- src/main.rs | 33 ++++++++++++++++++++++++++++++++- 2 files changed, 34 insertions(+), 3 deletions(-) diff --git a/src/flamegraph.svg b/src/flamegraph.svg index 162639d..22be3af 100644 --- a/src/flamegraph.svg +++ b/src/flamegraph.svg @@ -1,4 +1,4 @@ -Flame Graph Reset ZoomSearch perf_4.19 (4 samples, 0.70%)[unknown] (4 samples, 0.70%)entry_SYSCALL_64_after_hwframe (4 samples, 0.70%)do_syscall_64 (4 samples, 0.70%)__x64_sys_execve (4 samples, 0.70%)__do_execve_file.isra.34 (4 samples, 0.70%)search_binary_handler (4 samples, 0.70%)load_elf_binary (4 samples, 0.70%)setup_new_exec (4 samples, 0.70%)perf_event_exec (4 samples, 0.70%)__intel_pmu_enable_all.constprop.23 (4 samples, 0.70%)native_write_msr (4 samples, 0.70%)entry_SYSCALL_64_after_hwframe (1 samples, 0.18%)do_syscall_64 (1 samples, 0.18%)__x64_sys_execve (1 samples, 0.18%)__do_execve_file.isra.34 (1 samples, 0.18%)search_binary_handler (1 samples, 0.18%)load_elf_binary (1 samples, 0.18%)__clear_user (1 samples, 0.18%)page_fault (1 samples, 0.18%)__do_page_fault (1 samples, 0.18%)handle_mm_fault (1 samples, 0.18%)__handle_mm_fault (1 samples, 0.18%)finish_fault (1 samples, 0.18%)alloc_set_pte (1 samples, 0.18%)[unknown] (4 samples, 0.70%)swapgs_restore_regs_and_return_to_usermode (3 samples, 0.53%)prepare_exit_to_usermode (3 samples, 0.53%)exit_to_usermode_loop (3 samples, 0.53%)schedule (3 samples, 0.53%)__sched_text_start (3 samples, 0.53%)finish_task_switch (3 samples, 0.53%)__perf_event_task_sched_in (3 samples, 0.53%)__intel_pmu_enable_all.constprop.23 (3 samples, 0.53%)native_write_msr (3 samples, 0.53%)<std::time::Instant as core::ops::arith::Sub>::sub (21 samples, 3.69%)<std..std::sys::unix::time::Timespec::sub_timespec (17 samples, 2.99%)std..rustperf::one (164 samples, 28.82%)rustperf::onestd::time::Instant::now (137 samples, 24.08%)std::time::Instant::now__clock_gettime (127 samples, 22.32%)__clock_gettime__vdso_clock_gettime (108 samples, 18.98%)__vdso_clock_gettime[[vdso]] (73 samples, 12.83%)[[vdso]]<std::time::Instant as core::ops::arith::Sub>::sub (38 samples, 6.68%)<std::tim..std::sys::unix::time::Timespec::sub_timespec (28 samples, 4.92%)std::s..rustperf::main (371 samples, 65.20%)rustperf::mainrustperf::two (198 samples, 34.80%)rustperf::twostd::time::Instant::now (160 samples, 28.12%)std::time::Instant::now__clock_gettime (153 samples, 26.89%)__clock_gettime__vdso_clock_gettime (137 samples, 24.08%)__vdso_clock_gettime[[vdso]] (92 samples, 16.17%)[[vdso]]<std::time::Instant as core::ops::arith::Sub>::sub (45 samples, 7.91%)<std::time:..std::sys::unix::time::Timespec::sub_timespec (33 samples, 5.80%)std::sy.._start (560 samples, 98.42%)_start__libc_start_main (560 samples, 98.42%)__libc_start_mainmain (560 samples, 98.42%)mainstd::rt::lang_start_internal (560 samples, 98.42%)std::rt::lang_start_internal__rust_maybe_catch_panic (560 samples, 98.42%)__rust_maybe_catch_panicstd::panicking::try::do_call (560 samples, 98.42%)std::panicking::try::do_callstd::rt::lang_start::_$u7b$$u7b$closure$u7d$$u7d$::h80d40c3a4e341551 (560 samples, 98.42%)std::rt::lang_start::_$u7b$$u7b$closure$u7d$$u7d$::h80d40c3a4e341551rustperf::one (189 samples, 33.22%)rustperf::onestd::time::Instant::now (144 samples, 25.31%)std::time::Instant::now__clock_gettime (134 samples, 23.55%)__clock_gettime__vdso_clock_gettime (121 samples, 21.27%)__vdso_clock_gettime[[vdso]] (69 samples, 12.13%)[[vdso]]all (569 samples, 100%)rustperf (565 samples, 99.30%)rustperfstd::time::Instant::now (1 samples, 0.18%)swapgs_restore_regs_and_return_to_usermode (1 samples, 0.18%)prepare_exit_to_usermode (1 samples, 0.18%)exit_to_usermode_loop (1 samples, 0.18%)schedule (1 samples, 0.18%)__sched_text_start (1 samples, 0.18%)finish_task_switch (1 samples, 0.18%)__perf_event_task_sched_in (1 samples, 0.18%)__intel_pmu_enable_all.constprop.23 (1 samples, 0.18%)native_write_msr (1 samples, 0.18%) \ No newline at end of file +]]>Flame Graph Reset ZoomSearch perf_4.19 (4 samples, 0.20%)[unknown] (4 samples, 0.20%)entry_SYSCALL_64_after_hwframe (4 samples, 0.20%)do_syscall_64 (4 samples, 0.20%)__x64_sys_execve (4 samples, 0.20%)__do_execve_file.isra.34 (4 samples, 0.20%)search_binary_handler (4 samples, 0.20%)load_elf_binary (4 samples, 0.20%)setup_new_exec (4 samples, 0.20%)perf_event_exec (4 samples, 0.20%)__intel_pmu_enable_all.constprop.23 (4 samples, 0.20%)native_write_msr (4 samples, 0.20%)[unknown] (1 samples, 0.05%)entry_SYSCALL_64_after_hwframe (1 samples, 0.05%)do_syscall_64 (1 samples, 0.05%)__x64_sys_execve (1 samples, 0.05%)__do_execve_file.isra.34 (1 samples, 0.05%)search_binary_handler (1 samples, 0.05%)load_elf_binary (1 samples, 0.05%)elf_map (1 samples, 0.05%)vm_mmap_pgoff (1 samples, 0.05%)do_mmap (1 samples, 0.05%)mmap_region (1 samples, 0.05%)vm_area_alloc (1 samples, 0.05%)kmem_cache_alloc (1 samples, 0.05%)memcg_kmem_get_cache (1 samples, 0.05%)get_mem_cgroup_from_mm (1 samples, 0.05%)<std::time::Instant as core::ops::arith::Sub>::sub (43 samples, 2.18%)<..std::sys::unix::time::Timespec::sub_timespec (36 samples, 1.82%)rustperf::four (187 samples, 9.48%)rustperf::fourstd::time::Instant::now (144 samples, 7.30%)std::time:..__clock_gettime (139 samples, 7.05%)__clock_g..__vdso_clock_gettime (132 samples, 6.69%)__vdso_cl..[[vdso]] (81 samples, 4.11%)[[vd..<std::time::Instant as core::ops::arith::Sub>::sub (119 samples, 6.03%)<std::ti..std::sys::unix::time::Timespec::sub_timespec (86 samples, 4.36%)std::..apic_timer_interrupt (1 samples, 0.05%)smp_apic_timer_interrupt (1 samples, 0.05%)hrtimer_interrupt (1 samples, 0.05%)__hrtimer_run_queues (1 samples, 0.05%)tick_sched_timer (1 samples, 0.05%)tick_sched_do_timer (1 samples, 0.05%)timekeeping_advance (1 samples, 0.05%)timekeeping_update (1 samples, 0.05%)notifier_call_chain (1 samples, 0.05%)pvclock_gtod_notify (1 samples, 0.05%)rustperf::four (581 samples, 29.45%)rustperf::fourstd::time::Instant::now (442 samples, 22.40%)std::time::Instant::now__clock_gettime (423 samples, 21.44%)__clock_gettime__vdso_clock_gettime (374 samples, 18.96%)__vdso_clock_gettime[[vdso]] (229 samples, 11.61%)[[vdso]]<std::time::Instant as core::ops::arith::Sub>::sub (46 samples, 2.33%)<..std::sys::unix::time::Timespec::sub_timespec (36 samples, 1.82%)rustperf::one (197 samples, 9.98%)rustperf::onestd::time::Instant::now (142 samples, 7.20%)std::time:..__clock_gettime (137 samples, 6.94%)__clock_g..__vdso_clock_gettime (127 samples, 6.44%)__vdso_c..[[vdso]] (84 samples, 4.26%)[[vds..<std::time::Instant as core::ops::arith::Sub>::sub (130 samples, 6.59%)<std::tim..std::sys::unix::time::Timespec::sub_timespec (96 samples, 4.87%)std::s..rustperf::three (594 samples, 30.11%)rustperf::threestd::time::Instant::now (434 samples, 22.00%)std::time::Instant::now__clock_gettime (412 samples, 20.88%)__clock_gettime__vdso_clock_gettime (375 samples, 19.01%)__vdso_clock_gettime[[vdso]] (247 samples, 12.52%)[[vdso]]<std::time::Instant as core::ops::arith::Sub>::sub (86 samples, 4.36%)<std:..std::sys::unix::time::Timespec::sub_timespec (72 samples, 3.65%)std:.._start (1,967 samples, 99.70%)_start__libc_start_main (1,967 samples, 99.70%)__libc_start_mainmain (1,967 samples, 99.70%)mainstd::rt::lang_start_internal (1,967 samples, 99.70%)std::rt::lang_start_internal__rust_maybe_catch_panic (1,967 samples, 99.70%)__rust_maybe_catch_panicstd::panicking::try::do_call (1,967 samples, 99.70%)std::panicking::try::do_callstd::rt::lang_start::_$u7b$$u7b$closure$u7d$$u7d$::h80d40c3a4e341551 (1,967 samples, 99.70%)std::rt::lang_start::_$u7b$$u7b$closure$u7d$$u7d$::h80d40c3a4e341551rustperf::main (1,780 samples, 90.22%)rustperf::mainrustperf::two (397 samples, 20.12%)rustperf::twostd::time::Instant::now (295 samples, 14.95%)std::time::Instant::now__clock_gettime (288 samples, 14.60%)__clock_gettime__vdso_clock_gettime (267 samples, 13.53%)__vdso_clock_gettime[[vdso]] (164 samples, 8.31%)[[vdso]]all (1,973 samples, 100%)rustperf (1,969 samples, 99.80%)rustperfentry_SYSCALL_64_after_hwframe (1 samples, 0.05%)do_syscall_64 (1 samples, 0.05%)__x64_sys_exit_group (1 samples, 0.05%)do_group_exit (1 samples, 0.05%)do_exit (1 samples, 0.05%)mmput (1 samples, 0.05%)exit_mmap (1 samples, 0.05%)unmap_vmas (1 samples, 0.05%)unmap_page_range (1 samples, 0.05%) \ No newline at end of file diff --git a/src/main.rs b/src/main.rs index 4054fa3..10a3054 100644 --- a/src/main.rs +++ b/src/main.rs @@ -24,10 +24,41 @@ fn two(runtime: Duration) { } } +#[inline(never)] +fn three(runtime: Duration) { + println!("Starting three"); + let start = Instant::now(); + loop { + let diff = Instant::now() - start; + if diff > runtime { + return; + } + } +} + +#[inline(never)] +fn four(runtime: Duration) { + println!("Starting four"); + let start = Instant::now(); + loop { + let diff = Instant::now() - start; + if diff > runtime { + return; + } + } +} + fn main() { let runtime = Duration::new(2, 0); - one(runtime); + four(runtime); + three(runtime); two(runtime); + four(runtime); + three(runtime); + two(runtime); + four(runtime); + three(runtime); one(runtime); + four(runtime); }