Significant time spent in g_get_monotonic_time #1141
Description
g_get_monotonic_time is relatively slow, and we call it relatively often.
Using the "workload" benchmark here, with #define WORK_ITR 1 in workload.c, at shadow commit 0e13d3f,
sudo chrt -f 1 perf record -o ptrace.pin.256.perf --call-graph=dwarf /home/jnewsome/.shadow/bin/shadow --interpose-method=ptrace -w 4 -t host --pin-cpus config.xml > ptrace
sudo perf report --call-graph=graph,0.5,callee -n -i ptrace.pin.256.perf
We spend 16% of each worker thread in do_syscall_64, mostly by way of __vdso_clock_gettime, which is called from g_get_monotonic_time:
- 16.33% 2.18% 9218 worker-2 [kernel.vmlinux] ▒
- 16.32% do_syscall_64 ▒
- 16.30% entry_SYSCALL_64 ▒
- 13.18% __vdso_clock_gettime ▒
__GI___clock_gettime (inlined) ▒
- g_get_monotonic_time ▒
- 4.59% g_timer_stop ▒
+ 1.60% _schedulerpolicyhostsingle_pop ▒
+ 1.54% _schedulerpolicyhostsingle_push ▒
+ 1.45% event_execute ▒
- 4.22% g_timer_continue ▒
+ 1.49% event_execute ▒
+ 1.47% _schedulerpolicyhostsingle_pop ▒
+ 1.25% _schedulerpolicyhostsingle_push ▒
- 2.18% g_timer_start ▒
+ 1.42% _syscallhandler_pre_syscall (inlined) ▒
+ 0.76% process_continue ▒
- 2.17% g_timer_elapsed ▒
+ 1.44% _syscallhandler_post_syscall (inlined) ▒
+ 0.73% process_continue ▒
+ 1.55% ptrace ▒
+ 0.77% __GI___sched_yield (inlined) ▒
+ 0.58% __waitpid
The timers in _syscallhandler_pre_syscall and _syscallhandler_post_syscall could probably be disabled in release builds.
If we need the timers in the scheduler, perhaps we could ensure clock_gettime gets called with CLOCK_MONOTONIC_COARSE; that should let __vdso_clock_gettime avoid making a syscall, making it much cheaper.