lkml.org 
[lkml]   [2009]   [Mar]   [22]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
    /
    Date
    From
    SubjectRe: [PATCH 0/5] [GIT PULL] updates for tip/tracing/ftrace

    On Sun, 22 Mar 2009, Ingo Molnar wrote:

    >
    > ok, with Frederic we figured out the problem.
    >
    > What helped things most was this trace-dump output:
    >
    > 0) + 15.281 us | }
    > 0) | handle_irq() {
    > 1) + 35.871 us | }
    > 1) | timespec_to_ktime() {
    > 0) 4.608 us | }
    > 0) | generic_handle_irq_desc() {
    > 1) 4.097 us | }
    > 1) + 14.171 us | }
    > 0) 4.450 us | _spin_lock();
    > 1) + 60.127 us | }
    > 1) | ktime_get() {
    > 0) | ack_apic_edge() {
    > 1) | getnstimeofday() {
    > 0) 6.486 us | }
    > 0) 5.619 us | irq_complete_move();
    > 1) 5.158 us | jiffies_read();
    > 0) | move_native_irq() {
    > 1) + 15.495 us | }
    > 1) + 26.161 us | }
    > 0) 5.631 us | }
    > 1) 5.549 us | set_normalized_timespec();
    > 0) + 16.304 us | }
    > 0) | ack_APIC_irq() {
    > 1) + 48.377 us | }
    > 1) | timespec_to_ktime() {
    > 0) 5.762 us | native_apic_mem_write();
    > 1) 5.751 us | }
    > 0) + 16.162 us | }
    > 1) + 16.413 us | }
    > 0) + 27.185 us | }
    > 1) + 81.519 us | }
    > 0) + 80.245 us | }
    > 1) ! 154.606 us | }
    > 0) | _spin_unlock() {
    > 1) 5.743 us | tick_nohz_update_jiffies();
    > 0) 5.781 us | }
    > 1) ! 183.912 us | }
    > 0) 5.327 us | preempt_schedule();
    > 1) ! 202.575 us | }
    > 0) + 25.827 us | }
    >
    > [...]
    > 1) ! 2623.297 us | }
    >
    > i.e. all CPUs spend 2-3 milliseconds to handle a single tick. This
    > is on a Core2 Extreme Edition 2.93 GHz CPU, so this kind of cost was
    > unexpected.
    >
    > Until i saw this:
    >
    > CONFIG_TRACE_BRANCH_PROFILING=y
    > CONFIG_PROFILE_ALL_BRANCHES=y
    >
    > that explains it all. The above sequence is two CPUs 'lock stepped'
    > in a very high overhead series of cacheline ping-pongs. The
    > ping-pongs happen due to every branch in the kernel doing:
    >
    > ______f.miss_hit[______r]++;
    >
    > where the branch info metadata is defined as global variables:
    >
    > static struct ftrace_branch_data \
    > __attribute__((__aligned__(4))) \
    > __attribute__((section("_ftrace_branch"))) \
    >
    > not only is it global, it's also false cacheline-shared due to a 4
    > byte alignment.
    >
    > The proper solution would be to use percpu data and percpu_add()
    > primitives for this.

    Ug, that would increase the size tremendously. Remember, we have a data
    structure for ever if statement in the kernel. I can't recall how much
    memory it takes up now, but it was quite a bit. I can't imagine what it
    would be like to multiply that by NR_CPUS.

    Perhaps we could just check a single CPU?

    if (!smp_processor_id()) {
    [...]
    }

    Have CPU 0 be profiled only? Or at least make it an option?

    -- Steve

    >
    > Anyway ... i turned off the branch tracer for my tests.



    \
     
     \ /
      Last update: 2009-03-22 19:35    [W:0.026 / U:1.100 seconds]
    ©2003-2016 Jasper Spaans. hosted at Digital OceanAdvertise on this site