From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1760732Ab3B0R4J (ORCPT ); Wed, 27 Feb 2013 12:56:09 -0500 Received: from mga01.intel.com ([192.55.52.88]:52761 "EHLO mga01.intel.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1760716Ab3B0R4C (ORCPT ); Wed, 27 Feb 2013 12:56:02 -0500 X-ExtLoop1: 1 X-IronPort-AV: E=Sophos;i="4.84,749,1355126400"; d="scan'208";a="292634070" From: Eliezer Tamir Subject: [RFC PATCH 5/5] ixgbe: kprobes latency test module To: linux-kernel@vger.kernel.org, netdev@vger.kernel.org Cc: Dave Miller , Jesse Brandeburg , e1000-devel@lists.sourceforge.net, Willem de Bruijn , Andi Kleen , HPA , Eliezer Tamir Date: Wed, 27 Feb 2013 09:56:17 -0800 Message-ID: <20130227175617.10611.73061.stgit@gitlad.jf.intel.com> In-Reply-To: <20130227175549.10611.82188.stgit@gitlad.jf.intel.com> References: <20130227175549.10611.82188.stgit@gitlad.jf.intel.com> User-Agent: StGIT/0.14.2 MIME-Version: 1.0 Content-Type: text/plain; charset="utf-8" Content-Transfer-Encoding: 7bit Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org A module to measure time between two symbols. For each delta compile with EXTRA_CFLAGS="-DSTAGE=$stage" where stage is from 0 to 20 Signed-off-by: Alexander Duyck Signed-off-by: Jesse Brandeburg Signed-off-by: Eliezer Tamir --- drivers/net/ethernet/intel/ixgbe/ixgbe_main.c | 5 - samples/kprobes/Makefile | 2 samples/kprobes/kprobe_delta.c | 208 +++++++++++++++++++++++++ 3 files changed, 212 insertions(+), 3 deletions(-) create mode 100644 samples/kprobes/kprobe_delta.c diff --git a/drivers/net/ethernet/intel/ixgbe/ixgbe_main.c b/drivers/net/ethernet/intel/ixgbe/ixgbe_main.c index 5248c63..c7c8432 100644 --- a/drivers/net/ethernet/intel/ixgbe/ixgbe_main.c +++ b/drivers/net/ethernet/intel/ixgbe/ixgbe_main.c @@ -1755,8 +1755,9 @@ static bool ixgbe_add_rx_frag(struct ixgbe_ring *rx_ring, return true; } -static struct sk_buff *ixgbe_fetch_rx_buffer(struct ixgbe_ring *rx_ring, - union ixgbe_adv_rx_desc *rx_desc) +static noinline struct sk_buff *ixgbe_fetch_rx_buffer( + struct ixgbe_ring *rx_ring, + union ixgbe_adv_rx_desc *rx_desc) { struct ixgbe_rx_buffer *rx_buffer; struct sk_buff *skb; diff --git a/samples/kprobes/Makefile b/samples/kprobes/Makefile index 68739bc..5559ea9 100644 --- a/samples/kprobes/Makefile +++ b/samples/kprobes/Makefile @@ -1,5 +1,5 @@ # builds the kprobes example kernel modules; # then to use one (as root): insmod -obj-$(CONFIG_SAMPLE_KPROBES) += kprobe_example.o jprobe_example.o +obj-$(CONFIG_SAMPLE_KPROBES) += kprobe_example.o kprobe_delta.o jprobe_example.o obj-$(CONFIG_SAMPLE_KRETPROBES) += kretprobe_example.o diff --git a/samples/kprobes/kprobe_delta.c b/samples/kprobes/kprobe_delta.c new file mode 100644 index 0000000..88abe63 --- /dev/null +++ b/samples/kprobes/kprobe_delta.c @@ -0,0 +1,208 @@ +/* + * measure the time between two points in the kernel. + * for each stage compile with EXTRA_CFLAGS="-DSTAGE=$stage" + * where stage goes from 0 to 20 + */ + +#include +#include +#include +#include +#include +#include + +#ifndef STAGE +#define STAGE 3 +#endif + +#if (STAGE == 0) +#define START_SYMBOL "ixgbe_fetch_rx_buffer" +#define END_SYMBOL "__netif_receive_skb" +#elif (STAGE == 1) +#define START_SYMBOL "__netif_receive_skb" +#define END_SYMBOL "tcp_v4_rcv" +#elif (STAGE == 2) +#define START_SYMBOL "tcp_v4_rcv" +#define END_SYMBOL "sys_recvfrom" +#define END_POST +#elif (STAGE == 3) +#define START_SYMBOL "sys_recvfrom" +#define START_POST +#define END_SYMBOL "sys_sendto" +#elif (STAGE == 4) +#define START_SYMBOL "sys_sendto" +#define END_SYMBOL "tcp_transmit_skb" +#elif (STAGE == 5) +#define START_SYMBOL "tcp_transmit_skb" +#define END_SYMBOL "dev_queue_xmit" +#elif (STAGE == 6) +#define START_SYMBOL "dev_queue_xmit" +#define END_SYMBOL "ixgbe_xmit_frame" +#define END_POST +#elif (STAGE == 7) +#define START_SYMBOL "ixgbe_fetch_rx_buffer" +#define END_SYMBOL "ixgbe_xmit_frame" +#define END_POST +#elif (STAGE == 8) +#define START_SYMBOL "__netif_receive_skb" +#define END_SYMBOL "ixgbe_xmit_frame" +#define END_POST +#elif (STAGE == 9) +#define START_SYMBOL "tcp_v4_rcv" +#define END_SYMBOL "ixgbe_xmit_frame" +#define END_POST +#elif (STAGE == 10) +#define START_SYMBOL "sys_recvfrom" +#define START_POST +#define END_SYMBOL "ixgbe_xmit_frame" +#define END_POST +#elif (STAGE == 11) +#define START_SYMBOL "sys_sendto" +#define END_SYMBOL "ixgbe_xmit_frame" +#define END_POST +#elif (STAGE == 12) +#define START_SYMBOL "tcp_transmit_skb" +#define END_SYMBOL "ixgbe_xmit_frame" +#define END_POST +#elif (STAGE == 13) +#define START_SYMBOL "dev_queue_xmit" +#define END_SYMBOL "ixgbe_xmit_frame" +#define END_POST +#elif (STAGE == 14) +#define START_SYMBOL "ixgbe_fetch_rx_buffer" +#define END_SYMBOL "__netif_receive_skb" +#elif (STAGE == 15) +#define START_SYMBOL "ixgbe_fetch_rx_buffer" +#define END_SYMBOL "tcp_v4_rcv" +#elif (STAGE == 16) +#define START_SYMBOL "ixgbe_fetch_rx_buffer" +#define END_SYMBOL "sys_recvfrom" +#define END_POST +#elif (STAGE == 17) +#define START_SYMBOL "ixgbe_fetch_rx_buffer" +#define END_SYMBOL "sys_sendto" +#elif (STAGE == 18) +#define START_SYMBOL "ixgbe_fetch_rx_buffer" +#define END_SYMBOL "tcp_transmit_skb" +#elif (STAGE == 19) +#define START_SYMBOL "ixgbe_fetch_rx_buffer" +#define END_SYMBOL "dev_queue_xmit" +#elif (STAGE == 20) +#define START_SYMBOL "ixgbe_fetch_rx_buffer" +#define END_SYMBOL "ixgbe_xmit_frame" +#define END_POST +#endif + +/* per-instance private data */ +u64 start_cycles; +u64 total_cycles; +bool probe_valid; +unsigned int sample_count; + +static u64 rdtsc(void) +{ + unsigned int l, h; + + asm volatile("rdtsc" : "=a" (l), "=d" (h)); + + return l | (((u64)h) << 32); +} + +/* Here we use the entry_hanlder to timestamp function entry */ +static int start_handler(struct kretprobe_instance *ri, struct pt_regs *regs) +{ + start_cycles = rdtsc(); + probe_valid = true; + + return 0; +} + +/* + * Return-probe handler: Log the return value and duration. Duration may turn + * out to be zero consistently, depending upon the granularity of time + * accounting on the platform. + */ +static int end_handler(struct kretprobe_instance *ri, struct pt_regs *regs) +{ + if (probe_valid) { + total_cycles += rdtsc() - start_cycles; + sample_count++; + probe_valid = false; + } + + if (sample_count > 1000000) { + trace_printk("%4lldns %22s -> " END_SYMBOL " %s\n", + (long long)(total_cycles * 10) / + (sample_count * 27), +#ifdef START_POST + START_SYMBOL " (ret)", +#else + START_SYMBOL, +#endif +#ifdef END_POST + "(ret)" +#else + "" +#endif + ); + total_cycles = 0; + sample_count = 0; + } + + return 0; +} + +/* For each probe you need to allocate a kprobe structure */ +static struct kretprobe start_kretprobe = { +#ifdef START_POST + .handler = start_handler, +#else + .entry_handler = start_handler, +#endif + .kp.symbol_name = START_SYMBOL, +}; + +static struct kretprobe end_kretprobe = { +#ifdef END_POST + .handler = end_handler, +#else + .entry_handler = end_handler, +#endif + .kp.symbol_name = END_SYMBOL, +}; + +static int __init kretprobe_init(void) +{ + int ret; + + total_cycles = 0; + sample_count = 0; + probe_valid = false; + + ret = register_kretprobe(&start_kretprobe); + if (ret < 0) { + printk(KERN_INFO "register_kretprobe failed, returned %d\n", + ret); + return ret; + } + + ret = register_kretprobe(&end_kretprobe); + if (ret < 0) { + unregister_kretprobe(&end_kretprobe); + printk(KERN_INFO "register_kretprobe failed, returned %d\n", + ret); + return ret; + } + + return 0; +} + +static void __exit kretprobe_exit(void) +{ + unregister_kretprobe(&start_kretprobe); + unregister_kretprobe(&end_kretprobe); +} + +module_init(kretprobe_init) +module_exit(kretprobe_exit) +MODULE_LICENSE("GPL");