Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]


Groups > linux.kernel > #1163643

Re: latency histogram with BPF

Path csiph.com!aioe.org!bofh.it!news.nic.it!robomod
From Alexei Starovoitov <ast@plumgrid.com>
Newsgroups linux.kernel
Subject Re: latency histogram with BPF
Date Fri, 12 Jun 2015 00:10:01 +0200
Message-ID <pAiPD-2eE-9@gated-at.bofh.it> (permalink)
References <pA562-77H-3@gated-at.bofh.it>
X-Original-To Daniel Wagner <daniel.wagner@bmw-carit.de>, Steven Rostedt <rostedt@goodmis.org>, Tom Zanussi <tom.zanussi@linux.intel.com>
X-Google-Dkim-Signature v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20130820; h=x-gm-message-state:message-id:date:from:user-agent:mime-version:to :cc:subject:references:in-reply-to:content-type :content-transfer-encoding; bh=7fjW1eAc8DF5iw0E4lLAFz3eAmMQJpKV79PZ6FbVU0c=; b=b4t4Ptz6I8LJtzfFaA1/dYQlA/TfWqGVU47Gv9JtHqGURXW92d946cRj2/8esRUEdq afycqZ48HWyMc9o0SN8ql4H3saAdOELrX2vAAV2LdhgFWLba1P5Q/Su5v7SjFYUQuukn 9CoKL0ZVQPL+UxhFubjX1apVLd51QAUjxZgCRyGvQIw7wg9DWUNUXu5QDrYptwcpXZ7b B0b/piHMBdYU9OZXPY+zcoeDXUjjFHsDh/J3levdvRRw4nG/ZYwZmpdpzZ4mxcjuTq9H aR9apVQ5sjB5CMGERAokk4xTZgjbfzD1LADoMlOK7esgL/gf5jq5ajNaMYDl2jpBhLfr Wiew==
X-Gm-Message-State ALoCoQmjsKN83ehjsOMi78wPHIR+xUtiWKTzZvGiUAexIzEf0/G+zgLWgjd8poqhZg5QCbQTBIH3
X-Received by 10.55.22.130 with SMTP id 2mr24305568qkw.45.1434060502511; Thu, 11 Jun 2015 15:08:22 -0700 (PDT)
User-Agent Mozilla/5.0 (Macintosh; Intel Mac OS X 10.10; rv:31.0) Gecko/20100101 Thunderbird/31.7.0
MIME-Version 1.0
Content-Type text/plain; charset=utf-8; format=flowed
Content-Transfer-Encoding 7bit
Sender robomod@news.nic.it
List-ID <linux-kernel.vger.kernel.org>
X-Mailing-List linux-kernel@vger.kernel.org
Approved robomod@news.nic.it
Lines 97
Organization linux.* mail to news gateway
X-Original-Cc "linux-kernel@vger.kernel.org" <linux-kernel@vger.kernel.org>, Wang Nan <wangnan0@huawei.com>
X-Original-Date Thu, 11 Jun 2015 15:08:23 -0700
X-Original-Message-ID <557A06D7.7030304@plumgrid.com>
X-Original-References <557937D8.90606@bmw-carit.de>
X-Original-Sender linux-kernel-owner@vger.kernel.org
Xref aioe.org linux.kernel:1163643

Show key headers only | View raw


On 6/11/15 12:25 AM, Daniel Wagner wrote:
>
> In both cases BPF or based on Tom's 'hist' triggers' patches, there is
> some trickery necessary to get it working. While the first approach
> has more flexibility what you want to measure or how you want to
> present it, I suspect it will be harder to get it working/accepted.

why? Out of your patch only 2 lines are for kernel, which I wanted
to add anyway. The sample code also looks good.

> Obviously, adding kprobes to trace_preempt_[on|off] is
> asking for problems:

thanks for reporting.
I reproduced it with hackbench, but my stack trace looks completely
different. Looks like some memory corruption is happening.
Not clear where. I'm still debugging.

> CPU 3
>        latency        : count     distribution
>         1 -> 1        : 0        |                                                  |
>         2 -> 3        : 0        |                                                  |
>         4 -> 7        : 0        |                                                  |
>         8 -> 15       : 25182    |************************************************* |
>        16 -> 31       : 1675     |**                                                |
>        32 -> 63       : 0        |                                                  |
>        64 -> 127      : 0        |                                                  |
>       128 -> 255      : 0        |                                                  |
>       256 -> 511      : 0        |                                                  |
>       512 -> 1023     : 0        |                                                  |
>
> The numbers look a bit too nice and low. I suspect something is going
> wrong.

I see similar numbers. 25k over 5 sec = 5k preempt on/off per second
which sounds about right for idle.

> diff --git a/kernel/trace/bpf_trace.c b/kernel/trace/bpf_trace.c
> index 2d56ce5..e4d3e76 100644
> --- a/kernel/trace/bpf_trace.c
> +++ b/kernel/trace/bpf_trace.c
> @@ -172,6 +172,8 @@ static const struct bpf_func_proto *kprobe_prog_func_proto(enum bpf_func_id func
>   		return &bpf_probe_read_proto;
>   	case BPF_FUNC_ktime_get_ns:
>   		return &bpf_ktime_get_ns_proto;
> +	case BPF_FUNC_get_smp_processor_id:
> +		return &bpf_get_smp_processor_id_proto;

This part I'll take into my set of patches.

> --- a/samples/bpf/bpf_helpers.h
> +++ b/samples/bpf/bpf_helpers.h
> @@ -21,6 +21,8 @@ static unsigned long long (*bpf_ktime_get_ns)(void) =
>   	(void *) BPF_FUNC_ktime_get_ns;
>   static int (*bpf_trace_printk)(const char *fmt, int fmt_size, ...) =
>   	(void *) BPF_FUNC_trace_printk;
> +static unsigned int (*bpf_get_smp_processor_id)(void) =
> +	(void *) BPF_FUNC_get_smp_processor_id;

this part is already there in net-next.

> diff --git a/samples/bpf/hwlathist_kern.c b/samples/bpf/hwlathist_kern.c
> new file mode 100644
> index 0000000..7a97e7e
> --- /dev/null
> +++ b/samples/bpf/hwlathist_kern.c

looks good and useful, but I would like to find and fix the bug first
before exposing this bit as a 'sample', since right now it's
'crash me if hackbench is running' test :)
If you have any suggestions on where to look, I'm all ears.
My stack traces look like:
Running with 10*40 (== 400) tasks.
[   12.032571] kernel BUG at ../mm/slub.c:3413!
[   12.036004]  [<ffffffff810c1913>] rcu_process_callbacks+0x283/0x680
[   12.036004]  [<ffffffff810632d0>] __do_softirq+0xf0/0x2b0
[   12.036004]  [<ffffffff8107dff9>] ? kthread+0xc9/0xe0
[   12.036004]  [<ffffffff810634b1>] run_ksoftirqd+0x21/0x50
or
[   25.788074] kernel tried to execute NX-protected page - exploit 
attempt? (uid: 0)
[   25.788801] BUG: unable to handle kernel paging request at 
ffff88000b1ea2a0
[   25.800085]  [<ffffffff810c18ba>] ? rcu_process_callbacks+0x22a/0x680
[   25.800085]  [<ffffffff810632d0>] __do_softirq+0xf0/0x2b0
[   25.800085]  [<ffffffff816d6d7c>] do_softirq_own_stack+0x1c/0x30
[   25.800085]  <EOI>
[   25.800085]  [<ffffffff8106351d>] do_softirq+0x3d/0x40
[   25.800085]  [<ffffffff810635ba>] __local_bh_enable_ip+0x9a/0xb0
[   25.800085]  [<ffffffff816d4c1b>] _raw_spin_unlock_bh+0x1b/0x20
[   25.800085]  [<ffffffff811f3e42>] bdi_writeback_workfn+0x1b2/0x470

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

Back to linux.kernel | Previous | Next | Find similar | Unroll thread


Thread

Re: latency histogram with BPF Alexei Starovoitov <ast@plumgrid.com> - 2015-06-12 00:10 +0200

csiph-web