I implemented the ring_buffer_set_clock solution and I have some questions.
void __init ftrace_early_fill_ringbuffer(void *data)
{
...
ring_buffer_set_clock(tr->trace_buffer.buffer, early_trace_clock);
preempt_disable_notrace();
for (i = 0; i < vearly_entries_count; i++) {
entry = &ftrace_vearly_entries[i];
early_timestamp = entry->clock;
trace_function(tr, entry->ip, entry->parent_ip, 0, 0);
}
preempt_enable_notrace();
/* TODO: should set the previous clock */
ring_buffer_set_clock(tr->trace_buffer.buffer, trace_clock_local);
I need also to save the current clock before calling
"ring_buffer_set_clock()", is there
a way to get the current clock or to set the clock from tr->clock_id ?
There is one thing happening when using the trace_clock_local instead
of rdtsc.
I added different kernel params to trigger the issue :
When using entry->clock = trace_clock_local():
kernel param "ftrace_vearly ftrace_filter=*_init"
[ 0.312179] <idle>-0 0dp.. 0us : boot_cpu_init <-start_kernel
...
[ 0.320280] <idle>-0 0dp.. 0us : numa_init <-x86_numa_init
[ 0.320673] <idle>-0 0dp.. 0us : dummy_numa_init <-numa_init
[ 0.321082] <idle>-0 0dp.. 6us : paging_init <-setup_arch
[ 0.321471] <idle>-0 0dp.. 9us : sparse_init <-paging_init
[ 0.321867] <idle>-0 0dp.. 1174us : zone_sizes_init <-paging_init
[ 0.322283] <idle>-0 0dp.. 1201us : lruvec_init
<-free_area_init_node
[ 0.322714] <idle>-0 0dp.. 1524us : acpi_boot_init <-setup_arch
[ 0.323120] <idle>-0 0dp.. 1595us : sfi_init <-setup_arch
[ 0.323500] <idle>-0 0dp.. 1601us : kvm_guest_init <-setup_arch
[ 0.323904] <idle>-0 0dp.. 1623us : mcheck_init <-setup_arch
[ 0.324293] <idle>-0 0dp.. 1623us : mcheck_intel_therm_init
<-mcheck_init
[ 0.324772] <idle>-0 0dp.. 1724us : boot_cpu_state_init
<-start_kernel
[ 0.325259] <idle>-0 0dp.. 1724us : kvm_guest_cpu_init
<-kvm_smp_prepare_boot_cpu
[ 0.325789] <idle>-0 0dp.. 1733us : kvm_spinlock_init
<-kvm_smp_prepare_boot_cpu
[ 0.326300] <idle>-0 0dp.. 1733us :
build_all_zonelists_init <-build_all_zonelists
[ 0.326820] <idle>-0 0dp.. 1738us : page_alloc_init <-start_kernel
[ 0.327252] <idle>-0 0dp.. 1906us : jump_label_init <-start_kernel
[ 0.327673] <idle>-0 0dp.. 4913us : pidhash_init <-start_kernel
[ 0.328076] <idle>-0 0dp.. 4917us : trap_init <-start_kernel
[ 0.328466] <idle>-0 0dp.. 4927us : kvm_apf_trap_init <-trap_init
[ 0.328877] <idle>-0 0dp.. 4928us : mem_init <-start_kernel
[ 0.329263] <idle>-0 0dp.. 4930us : gart_iommu_hole_init
<-pci_iommu_alloc
[ 0.329745] <idle>-0 0dp.. 5129us : kmem_cache_init <-start_kernel
[ 0.330162] <idle>-0 0dp.. 5300us : vmalloc_init <-start_kernel
kernel param "ftrace=function ftrace_vearly ftrace_filter=*_init"
[ 0.315455] <idle>-0 0dp.. 18446744073666366us :
boot_cpu_init <-start_kernel
...
[ 0.338102] <idle>-0 0dp.. 18446744073671436us : trap_init
<-start_kernel
[ 0.338584] <idle>-0 0dp.. 18446744073671446us :
kvm_apf_trap_init <-trap_init
[ 0.339089] <idle>-0 0dp.. 18446744073671447us : mem_init
<-start_kernel
[ 0.339564] <idle>-0 0dp.. 18446744073671449us :
gart_iommu_hole_init <-pci_iommu_alloc
[ 0.340111] <idle>-0 0dp.. 18446744073671635us :
kmem_cache_init <-start_kernel
[ 0.340622] <idle>-0 0dp.. 18446744073671775us :
vmalloc_init <-start_kernel
function tracing starts here <<<<<<<<<<<<<<<<<<<<<<<<<<
[ 0.341119] <idle>-0 0dp.1 48004us : sched_init <-start_kernel
[ 0.341520] <idle>-0 0dp.1 48005us : wait_bit_init <-sched_init
[ 0.341926] <idle>-0 0dp.1 48007us : hrtimer_init
<-init_rt_bandwidth
[ 0.342359] <idle>-0 0dp.1 48007us : __hrtimer_init <-hrtimer_init
[ 0.342779] <idle>-0 0dp.1 48007us : cpudl_init <-init_rootdomain
[ 0.343196] <idle>-0 0dp.1 48008us : cpupri_init <-init_rootdomain
[ 0.343618] <idle>-0 0dp.1 48014us : autogroup_init <-sched_init
When using entry->clock = rdtsc() [working well]:
kernel param "ftrace=function ftrace_vearly ftrace_filter=*_init"
[ 0.314067] <idle>-0 0dp.. 154207us : boot_cpu_init <-start_kernel
...
[ 0.333397] <idle>-0 0dp.. 180362us : mem_init <-start_kernel
[ 0.333806] <idle>-0 0dp.. 180365us : gart_iommu_hole_init
<-pci_iommu_alloc
[ 0.334330] <idle>-0 0dp.. 180652us : kmem_cache_init
<-start_kernel
[ 0.334760] <idle>-0 0dp.. 180810us : vmalloc_init <-start_kernel
function tracing starts here <<<<<<<<<<<<<<<<<<<<<<<<<<
[ 0.335225] <idle>-0 0dp.1 180810us : sched_init <-start_kernel
[ 0.335626] <idle>-0 0dp.1 180810us : wait_bit_init <-sched_init
[ 0.336015] <idle>-0 0dp.1 180810us : hrtimer_init
<-init_rt_bandwidth
[ 0.336500] <idle>-0 0dp.1 180810us : __hrtimer_init <-hrtimer_init
[ 0.336981] <idle>-0 0dp.1 180810us : cpudl_init <-init_rootdomain
[ 0.337381] <idle>-0 0dp.1 180810us : cpupri_init <-init_rootdomain
