linux-kernel - Re: [PATCH 0/5] [GIT PULL] updates for tip/tracing/ftrace

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Date:	Sun, 22 Mar 2009 18:02:15 +0100
From:	Ingo Molnar <mingo@...e.hu>
To:	"Paul E. McKenney" <paulmck@...ux.vnet.ibm.com>
Cc:	Steven Rostedt <rostedt@...dmis.org>,
	Frederic Weisbecker <fweisbec@...il.com>,
	LKML <linux-kernel@...r.kernel.org>,
	Thomas Gleixner <tglx@...utronix.de>,
	Peter Zijlstra <peterz@...radead.org>
Subject: Re: [PATCH 0/5] [GIT PULL] updates for tip/tracing/ftrace


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.

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

	Ingo
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/