On Wed, 08 Nov 2017 18:44:39 +0000
Abderrahmane Benbachir <abderrahmane.benbac...@polymtl.ca> wrote:
> 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 ?
No, but we could add one, although it is not really necessary. This is
why I just defaulted to what it is set to at the start anyway. It's
hard coded to trace_clock_local now, and it's only changed via the
command line parameter after this code is run.
>
>
> 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
>
I'd have to see the code to figure this out.
-- Steve
>
> 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
>
