From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (qmail 2586 invoked by alias); 22 Dec 2013 21:10:38 -0000 Mailing-List: contact systemtap-help@sourceware.org; run by ezmlm Precedence: bulk List-Id: List-Subscribe: List-Post: List-Help: , Sender: systemtap-owner@sourceware.org Received: (qmail 2576 invoked by uid 89); 22 Dec 2013 21:10:37 -0000 Authentication-Results: sourceware.org; auth=none X-Virus-Found: No X-Spam-SWARE-Status: No, score=-1.8 required=5.0 tests=AWL,BAYES_00,RCVD_IN_DNSWL_LOW,SPF_PASS autolearn=ham version=3.3.2 X-HELO: mail4.hitachi.co.jp Received: from mail4.hitachi.co.jp (HELO mail4.hitachi.co.jp) (133.145.228.5) by sourceware.org (qpsmtpd/0.93/v0.84-503-g423c35a) with ESMTP; Sun, 22 Dec 2013 21:10:35 +0000 Received: from mlsv2.hitachi.co.jp (unknown [133.144.234.166]) by mail4.hitachi.co.jp (Postfix) with ESMTP id EC21333CC2; Mon, 23 Dec 2013 06:10:32 +0900 (JST) Received: from mfilter05.hitachi.co.jp by mlsv2.hitachi.co.jp (8.13.1/8.13.1) id rBMLAWbK008574; Mon, 23 Dec 2013 06:10:32 +0900 Received: from vshuts02.hitachi.co.jp (vshuts02.hitachi.co.jp [10.201.6.84]) by mfilter05.hitachi.co.jp (Switch-3.3.4/Switch-3.3.4) with ESMTP id rBMLAVV9010733; Mon, 23 Dec 2013 06:10:32 +0900 Received: from gxml20a.ad.clb.hitachi.co.jp (unknown [158.213.157.160]) by vshuts02.hitachi.co.jp (Postfix) with ESMTP id 35253490042; Mon, 23 Dec 2013 06:10:31 +0900 (JST) Received: from [10.198.194.57] by gxml20a.ad.clb.hitachi.co.jp (Switch-3.1.10/Switch-3.1.9) id 5BML0AU8I000100D8; Mon, 23 Dec 2013 06:10:30 +0900 Message-ID: <52B75542.7040600@hitachi.com> Date: Sun, 22 Dec 2013 21:10:00 -0000 From: Masami Hiramatsu User-Agent: Mozilla/5.0 (Windows NT 5.2; rv:13.0) Gecko/20120614 Thunderbird/13.0.1 MIME-Version: 1.0 To: Ingo Molnar Cc: "Frank Ch. Eigler" , linux-arch@vger.kernel.org, Ananth N Mavinakayanahalli , Sandeepa Prabhu , x86@kernel.org, lkml , "Steven Rostedt (Red Hat)" , systemtap@sourceware.org, "David S. Miller" Subject: Re: [PATCH -tip v6 00/22] kprobes: introduce NOKPROBE_SYMBOL(), cleanup and fixes crash bugs References: <20131219090353.14309.15496.stgit@kbuild-fedora.novalocal> <52B3C5E6.2040802@hitachi.com> <20131220082056.GA15934@gmail.com> <52B40E79.8040701@hitachi.com> <20131220104615.GA22609@gmail.com> In-Reply-To: <20131220104615.GA22609@gmail.com> Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 7bit X-IsSubscribed: yes X-SW-Source: 2013-q4/txt/msg00478.txt.bz2 (2013/12/20 19:46), Ingo Molnar wrote: > > * Masami Hiramatsu wrote: > >> (2013/12/20 17:20), Ingo Molnar wrote: >>> >>> * Masami Hiramatsu wrote: >>> >>>>> But a closer look indicates that the insertion of kprobes is >>>>> taking about three (!!) orders of magnitude longer than before, as >>>>> judged by the rate of increase of 'wc -l >>>>> /sys/kernel/debug/kprobes/list'. >>>> >>>> Right, because kprobes are not designed for thousands of probes. >>> >>> Then this needs to be fixed, because right now this bug is making it >>> near impossible to properly test kprobes robustness. >>> >>> For example a hash table (hashed by probe address) could be used in >>> addition to the list, to speed up basic operations. >> >> kprobe itself is already using hlist (6bits hash table). >> Maybe we'd better expand the table bits. However, the iteration >> of the list on debugfs is just doing seq_printf()s. I'm not exactly >> sure what Frank complaints about... > > Well, Frank reported that the test he performed takes hours to finish, > and he mentioned a specific script line he used to produce that: > > # stap -te "probe kprobe.function("*") {}" > > I suspect an equivalent perf probe sequence would be something like: > > # for FUNC in $(grep -iw t /proc/kallsyms | cut -d' ' -f3); do date; perf probe -a $FUNC; done > > (totally untested.) > > Can you reproduce that slowdown, using his method? Yes I could, but there are some differences between them. - perf probe itself opens debuginfo file repeatedly for each event, this is just slow. Thus I recommend you to use tracing/kprobe-events directly. (this can be relaxed by introducing the wildcard support on perf probe, however, it still requires to walk through the debuginfo, this means it'll take a long time and consume huge memory) - perf probe/kprobe tracer will slowdown registration process when the number of events blown up, because the "kprobe-tracer" itself using the linear search on a list for checking event-name conflicts. (this can be fixed by using the rbtree instead of the list) - kprobe-tracer registers events as disabled, but systemtap does it as enabled. This means that we'll have no system slowdown which comes from probing overhead. I guess the last one (runtime overhead) is what Frank complaints about, isn't it? That is actually bigger when we add thousands of probes. (since the hash table has only 64 slots) > I can reproduce one weirdness, with just 13 probes added, 'perf probe > -l' [which should really be 'perf probe list'!] executes very slowly: > > # perf stat --null --repeat 3 perf probe -l > > Performance counter stats for 'perf probe -l' (3 runs): > > 0.763640098 seconds time elapsed ( +- 1.61% ) > > 0.7 seconds is ridiculously long. This comes from the perf-probe's internal issue. It tries to get actual lines and files by using debuginfo. I guess most of the time consumed when processing huge kernel debuginfo. > > Also, here's another bugreport as well: while playing around with > 'perf probe' I found that its usability is still very poor. For > example I mis-remembered the syntax and typed the obvious way to : > > # perf probe add __schedule > Failed to find path of kernel module. > Failed to open debuginfo file. > Error: Failed to add events. (-2) > > why the heck does a simple and obvious 'perf probe add' not work, why > is the strange syntax of 'perf probe -a' forced? Every other perf > subcommand uses clean command spaces - see for example 'perf bench'. But what happens if we have the function names "add"? And also, as you commented 4years ago, for adding new event, you don't need -a/--add. you just can do # perf probe __schedule for that purpose. :) > Also, the error message is totally misleading and uninformative to the > level of being passive-aggressive. An error message should directly > relate to the mistake performed and should give a good way out of the > situation. Who the heck cares that there was no debuginfo file to > open? Who cares that the 'path of kernel module' was not found? It has > no relation to the bug. Sorry for confusion, but that is because syntax misunderstanding. As I said above, the perf probe understand the options as below # perf probe (--add ")add (arg1=)__schedule(") This means that perf needs a debuginfo to get the location of "__schedule" local variable at "add" function. So, it tried to open debuginfo and failed. > > An informative error message would be: > > # perf probe add __schedule > Error: Could not find symbol 'add'. > > and that's it. No 'failed to add events' message - obviously the event > is not enabled if we cannot find the symbol name. Yeah, if you run it without __schedule, it shows such kind of error. $ ./perf probe add Kernel symbol 'add' not found. Error: Failed to add events. (-2) Thank you, -- Masami HIRAMATSU IT Management Research Dept. Linux Technology Center Hitachi, Ltd., Yokohama Research Laboratory E-mail: masami.hiramatsu.pt@hitachi.com