From b03d9eb25e727b1af906b292e2b1e71aa6919870 Mon Sep 17 00:00:00 2001 From: Brendan Gregg <brendan.d.gregg@gmail.com> Date: Wed, 23 Aug 2017 15:00:30 -0700 Subject: [PATCH] funccount: add -d for duration --- man/man8/funccount.8 | 7 ++++++ tools/funccount.py | 17 +++++++++++--- tools/funccount_example.txt | 45 ++++++++++++++++++++++++++++++++++--- 3 files changed, 63 insertions(+), 6 deletions(-) diff --git a/man/man8/funccount.8 b/man/man8/funccount.8 index e55258c1..6c1623a4 100644 --- a/man/man8/funccount.8 +++ b/man/man8/funccount.8 @@ -27,6 +27,9 @@ Trace this process ID only. \-i INTERVAL Print output every interval seconds. .TP +\-d DURATION +Total duration of trace in seconds. +.TP \-T Include timestamps on output. .TP @@ -49,6 +52,10 @@ Print kernel functions beginning with "vfs_", every second: # .B funccount \-i 1 'vfs_*' .TP +Print kernel functions beginning with "vfs_", for ten seconds only: +# +.B funccount \-d 10 'vfs_*' +.TP Match kernel functions beginning with "vfs_", using regular expressions: # .B funccount \-r '^vfs_.*' diff --git a/tools/funccount.py b/tools/funccount.py index ff64df91..99654f26 100755 --- a/tools/funccount.py +++ b/tools/funccount.py @@ -4,7 +4,7 @@ # funccount Count functions, tracepoints, and USDT probes. # For Linux, uses BCC, eBPF. # -# USAGE: funccount [-h] [-p PID] [-i INTERVAL] [-T] [-r] pattern +# USAGE: funccount [-h] [-p PID] [-i INTERVAL] [-d DURATION] [-T] [-r] pattern # # The pattern is a string with optional '*' wildcards, similar to file # globbing. If you'd prefer to use regular expressions, use the -r option. @@ -218,6 +218,7 @@ class Tool(object): ./funccount 'vfs_*' # count kernel fns starting with "vfs" ./funccount -r '^vfs.*' # same as above, using regular expressions ./funccount -Ti 5 'vfs_*' # output every 5 seconds, with timestamps + ./funccount -d 10 'vfs_*' # trace for 10 seconds only ./funccount -p 185 'vfs_*' # count vfs calls for PID 181 only ./funccount t:sched:sched_fork # count calls to the sched_fork tracepoint ./funccount -p 185 u:node:gc* # count all GC USDT probes in node, PID 185 @@ -232,13 +233,15 @@ class Tool(object): epilog=examples) parser.add_argument("-p", "--pid", type=int, help="trace this PID only") - parser.add_argument("-i", "--interval", default=99999999, + parser.add_argument("-i", "--interval", help="summary interval, seconds") + parser.add_argument("-d", "--duration", + help="total duration of trace, seconds") parser.add_argument("-T", "--timestamp", action="store_true", help="include timestamp on output") parser.add_argument("-r", "--regexp", action="store_true", help="use regular expressions. Default is \"*\" wildcards only.") - parser.add_argument("-d", "--debug", action="store_true", + parser.add_argument("-D", "--debug", action="store_true", help="print BPF program before starting (for debugging purposes)") parser.add_argument("pattern", help="search expression for events") @@ -246,6 +249,10 @@ class Tool(object): global debug debug = self.args.debug self.probe = Probe(self.args.pattern, self.args.regexp, self.args.pid) + if self.args.duration and not self.args.interval: + self.args.interval = self.args.duration + if not self.args.interval: + self.args.interval = 99999999 @staticmethod def _signal_ignore(signal, frame): @@ -257,13 +264,17 @@ class Tool(object): print("Tracing %d functions for \"%s\"... Hit Ctrl-C to end." % (self.probe.matched, self.args.pattern)) exiting = 0 if self.args.interval else 1 + seconds = 0 while True: try: sleep(int(self.args.interval)) + seconds += int(self.args.interval) except KeyboardInterrupt: exiting = 1 # as cleanup can take many seconds, trap Ctrl-C: signal.signal(signal.SIGINT, Tool._signal_ignore) + if self.args.duration and seconds >= int(self.args.duration): + exiting = 1 print() if self.args.timestamp: diff --git a/tools/funccount_example.txt b/tools/funccount_example.txt index 16efe1ba..d06cfd98 100644 --- a/tools/funccount_example.txt +++ b/tools/funccount_example.txt @@ -266,6 +266,41 @@ kernel activity that aren't visible in other metrics. Include -T to print timestamps on output. +A maximum duration can be set. For example, to print 5 x 1 second summaries +of vfs_read() calls: + +# ./funccount -i 1 -d 5 vfs_read +Tracing 1 functions for "vfs_read"... Hit Ctrl-C to end. + +FUNC COUNT +vfs_read 30 + +FUNC COUNT +vfs_read 26 + +FUNC COUNT +vfs_read 54 + +FUNC COUNT +vfs_read 25 + +FUNC COUNT +vfs_read 31 +Detaching... + +By leaving off the "-i 1", this will print a single 5 second summary: + +# funccount.py -d 5 vfs_read +Tracing 1 functions for "vfs_read"... Hit Ctrl-C to end. + +FUNC COUNT +vfs_read 167 +Detaching... + +This can be useful for finding out rates: trace all functions for ten seconds +and then divide by ten for the per-second rate. + + The "*" wildcard can be used multiple times. Eg, matching functions that contain the word "readdir": @@ -293,8 +328,9 @@ Detaching... Full USAGE: -# ./funccount -h -usage: funccount.py [-h] [-p PID] [-i INTERVAL] [-T] [-r] [-d] pattern +# ./funccount -h +usage: funccount [-h] [-p PID] [-i INTERVAL] [-d DURATION] [-T] [-r] [-D] + pattern Count functions, tracepoints, and USDT probes @@ -306,16 +342,19 @@ optional arguments: -p PID, --pid PID trace this PID only -i INTERVAL, --interval INTERVAL summary interval, seconds + -d DURATION, --duration DURATION + total duration of trace, seconds -T, --timestamp include timestamp on output -r, --regexp use regular expressions. Default is "*" wildcards only. - -d, --debug print BPF program before starting (for debugging + -D, --debug print BPF program before starting (for debugging purposes) examples: ./funccount 'vfs_*' # count kernel fns starting with "vfs" ./funccount -r '^vfs.*' # same as above, using regular expressions ./funccount -Ti 5 'vfs_*' # output every 5 seconds, with timestamps + ./funccount -d 10 'vfs_*' # trace for 10 seconds only ./funccount -p 185 'vfs_*' # count vfs calls for PID 181 only ./funccount t:sched:sched_fork # count calls to the sched_fork tracepoint ./funccount -p 185 u:node:gc* # count all GC USDT probes in node, PID 185 -- 2.30.9