Commit 8996719b authored by Akilesh Kailash's avatar Akilesh Kailash Committed by yonghong-song

Add -d (duration) option to argdist, funclatency and syscount (#1768)

* Add -d (duration) option to argdist, funclatency and syscount

* Add -d option to man pages and _example.txt
parent 9733011a
...@@ -2,7 +2,7 @@ ...@@ -2,7 +2,7 @@
.SH NAME .SH NAME
argdist \- Trace a function and display a histogram or frequency count of its parameter values. Uses Linux eBPF/bcc. argdist \- Trace a function and display a histogram or frequency count of its parameter values. Uses Linux eBPF/bcc.
.SH SYNOPSIS .SH SYNOPSIS
.B argdist [-h] [-p PID] [-z STRING_SIZE] [-i INTERVAL] [-n COUNT] [-v] [-T TOP] [-H specifier] [-C specifier] [-I header] .B argdist [-h] [-p PID] [-z STRING_SIZE] [-i INTERVAL] [-d DURATION] [-n COUNT] [-v] [-T TOP] [-H specifier] [-C specifier] [-I header]
.SH DESCRIPTION .SH DESCRIPTION
argdist attaches to function entry and exit points, collects specified parameter argdist attaches to function entry and exit points, collects specified parameter
values, and stores them in a histogram or a frequency collection that counts values, and stores them in a histogram or a frequency collection that counts
...@@ -27,6 +27,9 @@ characters. Longer strings will be truncated. ...@@ -27,6 +27,9 @@ characters. Longer strings will be truncated.
\-i INTERVAL \-i INTERVAL
Print the collected data every INTERVAL seconds. The default is 1 second. Print the collected data every INTERVAL seconds. The default is 1 second.
.TP .TP
\-d DURATION
Total duration of trace in seconds.
.TP
\-n NUMBER \-n NUMBER
Print the collected data COUNT times and then exit. Print the collected data COUNT times and then exit.
.TP .TP
......
...@@ -2,7 +2,7 @@ ...@@ -2,7 +2,7 @@
.SH NAME .SH NAME
funclatency \- Time functions and print latency as a histogram. funclatency \- Time functions and print latency as a histogram.
.SH SYNOPSIS .SH SYNOPSIS
.B funclatency [\-h] [\-p PID] [\-i INTERVAL] [\-T] [\-u] [\-m] [\-F] [\-r] [\-v] pattern .B funclatency [\-h] [\-p PID] [\-i INTERVAL] [\-d DURATION] [\-T] [\-u] [\-m] [\-F] [\-r] [\-v] pattern
.SH DESCRIPTION .SH DESCRIPTION
This tool traces function calls and times their duration (latency), and This tool traces function calls and times their duration (latency), and
shows the latency distribution as a histogram. The time is measured from when shows the latency distribution as a histogram. The time is measured from when
...@@ -37,6 +37,9 @@ Trace this process ID only. ...@@ -37,6 +37,9 @@ Trace this process ID only.
\-i INTERVAL \-i INTERVAL
Print output every interval seconds. Print output every interval seconds.
.TP .TP
\-d DURATION
Total duration of trace, in seconds.
.TP
\-T \-T
Include timestamps on output. Include timestamps on output.
.TP .TP
...@@ -72,6 +75,10 @@ Time do_nanosleep(), and print the histogram in units of milliseconds: ...@@ -72,6 +75,10 @@ Time do_nanosleep(), and print the histogram in units of milliseconds:
# #
.B funclatency \-m do_nanosleep .B funclatency \-m do_nanosleep
.TP .TP
Time libc open(), and print output every 2 seconds, for duration 10 seconds:
#
.B funclatency \-i 2 -d 10 c:read
.TP
Time vfs_read(), and print output every 5 seconds, with timestamps: Time vfs_read(), and print output every 5 seconds, with timestamps:
# #
.B funclatency \-mTi 5 vfs_read .B funclatency \-mTi 5 vfs_read
......
...@@ -2,7 +2,7 @@ ...@@ -2,7 +2,7 @@
.SH NAME .SH NAME
syscount \- Summarize syscall counts and latencies. syscount \- Summarize syscall counts and latencies.
.SH SYNOPSIS .SH SYNOPSIS
.B syscount [-h] [-p PID] [-i INTERVAL] [-T TOP] [-x] [-e ERRNO] [-L] [-m] [-P] [-l] .B syscount [-h] [-p PID] [-i INTERVAL] [-d DURATION] [-T TOP] [-x] [-e ERRNO] [-L] [-m] [-P] [-l]
.SH DESCRIPTION .SH DESCRIPTION
This tool traces syscall entry and exit tracepoints and summarizes either the This tool traces syscall entry and exit tracepoints and summarizes either the
number of syscalls of each type, or the number of syscalls per process. It can number of syscalls of each type, or the number of syscalls per process. It can
...@@ -23,6 +23,9 @@ Trace only this process. ...@@ -23,6 +23,9 @@ Trace only this process.
\-i INTERVAL \-i INTERVAL
Print the summary at the specified interval (in seconds). Print the summary at the specified interval (in seconds).
.TP .TP
\-d DURATION
Total duration of trace (in seconds).
.TP
\-T TOP \-T TOP
Print only this many entries. Default: 10. Print only this many entries. Default: 10.
.TP .TP
......
...@@ -610,7 +610,9 @@ argdist -I 'kernel/sched/sched.h' \\ ...@@ -610,7 +610,9 @@ argdist -I 'kernel/sched/sched.h' \\
type=int, type=int,
help="maximum string size to read from char* arguments") help="maximum string size to read from char* arguments")
parser.add_argument("-i", "--interval", default=1, type=int, parser.add_argument("-i", "--interval", default=1, type=int,
help="output interval, in seconds") help="output interval, in seconds (default 1 second)")
parser.add_argument("-d", "--duration", type=int,
help="total duration of trace, in seconds")
parser.add_argument("-n", "--number", type=int, dest="count", parser.add_argument("-n", "--number", type=int, dest="count",
help="number of outputs") help="number of outputs")
parser.add_argument("-v", "--verbose", action="store_true", parser.add_argument("-v", "--verbose", action="store_true",
...@@ -684,9 +686,11 @@ struct __string_t { char s[%d]; }; ...@@ -684,9 +686,11 @@ struct __string_t { char s[%d]; };
def _main_loop(self): def _main_loop(self):
count_so_far = 0 count_so_far = 0
seconds = 0
while True: while True:
try: try:
sleep(self.args.interval) sleep(self.args.interval)
seconds += self.args.interval
except KeyboardInterrupt: except KeyboardInterrupt:
exit() exit()
print("[%s]" % strftime("%H:%M:%S")) print("[%s]" % strftime("%H:%M:%S"))
...@@ -696,6 +700,9 @@ struct __string_t { char s[%d]; }; ...@@ -696,6 +700,9 @@ struct __string_t { char s[%d]; };
if self.args.count is not None and \ if self.args.count is not None and \
count_so_far >= self.args.count: count_so_far >= self.args.count:
exit() exit()
if self.args.duration and \
seconds >= self.args.duration:
exit()
def run(self): def run(self):
try: try:
......
...@@ -348,7 +348,9 @@ optional arguments: ...@@ -348,7 +348,9 @@ optional arguments:
-z STRING_SIZE, --string-size STRING_SIZE -z STRING_SIZE, --string-size STRING_SIZE
maximum string size to read from char* arguments maximum string size to read from char* arguments
-i INTERVAL, --interval INTERVAL -i INTERVAL, --interval INTERVAL
output interval, in seconds output interval, in seconds (default 1 second)
-d DURATION, --duration DURATION
total duration of trace, in seconds
-n COUNT, --number COUNT -n COUNT, --number COUNT
number of outputs number of outputs
-v, --verbose print resulting BPF program code before executing -v, --verbose print resulting BPF program code before executing
......
...@@ -35,6 +35,7 @@ examples = """examples: ...@@ -35,6 +35,7 @@ examples = """examples:
./funclatency c:read # time the read() C library function ./funclatency c:read # time the read() C library function
./funclatency -u vfs_read # time vfs_read(), in microseconds ./funclatency -u vfs_read # time vfs_read(), in microseconds
./funclatency -m do_nanosleep # time do_nanosleep(), in milliseconds ./funclatency -m do_nanosleep # time do_nanosleep(), in milliseconds
./funclatency -i 2 -d 10 c:open # output every 2 seconds, for duration 10s
./funclatency -mTi 5 vfs_read # output every 5 seconds, with timestamps ./funclatency -mTi 5 vfs_read # output every 5 seconds, with timestamps
./funclatency -p 181 vfs_read # time process 181 only ./funclatency -p 181 vfs_read # time process 181 only
./funclatency 'vfs_fstat*' # time both vfs_fstat() and vfs_fstatat() ./funclatency 'vfs_fstat*' # time both vfs_fstat() and vfs_fstatat()
...@@ -47,8 +48,10 @@ parser = argparse.ArgumentParser( ...@@ -47,8 +48,10 @@ parser = argparse.ArgumentParser(
epilog=examples) epilog=examples)
parser.add_argument("-p", "--pid", type=int, parser.add_argument("-p", "--pid", type=int,
help="trace this PID only") help="trace this PID only")
parser.add_argument("-i", "--interval", default=99999999, parser.add_argument("-i", "--interval", type=int,
help="summary interval, seconds") help="summary interval, in seconds")
parser.add_argument("-d", "--duration", type=int,
help="total duration of trace, in seconds")
parser.add_argument("-T", "--timestamp", action="store_true", parser.add_argument("-T", "--timestamp", action="store_true",
help="include timestamp on output") help="include timestamp on output")
parser.add_argument("-u", "--microseconds", action="store_true", parser.add_argument("-u", "--microseconds", action="store_true",
...@@ -66,6 +69,10 @@ parser.add_argument("pattern", ...@@ -66,6 +69,10 @@ parser.add_argument("pattern",
parser.add_argument("--ebpf", action="store_true", parser.add_argument("--ebpf", action="store_true",
help=argparse.SUPPRESS) help=argparse.SUPPRESS)
args = parser.parse_args() args = parser.parse_args()
if args.duration and not args.interval:
args.interval = args.duration
if not args.interval:
args.interval = 99999999
def bail(error): def bail(error):
print("Error: " + error) print("Error: " + error)
...@@ -226,14 +233,18 @@ def print_section(key): ...@@ -226,14 +233,18 @@ def print_section(key):
return "%s [%d]" % (BPF.sym(key[0], key[1]), key[1]) return "%s [%d]" % (BPF.sym(key[0], key[1]), key[1])
exiting = 0 if args.interval else 1 exiting = 0 if args.interval else 1
seconds = 0
dist = b.get_table("dist") dist = b.get_table("dist")
while (1): while (1):
try: try:
sleep(int(args.interval)) sleep(args.interval)
seconds += args.interval
except KeyboardInterrupt: except KeyboardInterrupt:
exiting = 1 exiting = 1
# as cleanup can take many seconds, trap Ctrl-C: # as cleanup can take many seconds, trap Ctrl-C:
signal.signal(signal.SIGINT, signal_ignore) signal.signal(signal.SIGINT, signal_ignore)
if args.duration and seconds >= args.duration:
exiting = 1
print() print()
if args.timestamp: if args.timestamp:
......
...@@ -343,7 +343,9 @@ optional arguments: ...@@ -343,7 +343,9 @@ optional arguments:
-h, --help show this help message and exit -h, --help show this help message and exit
-p PID, --pid PID trace this PID only -p PID, --pid PID trace this PID only
-i INTERVAL, --interval INTERVAL -i INTERVAL, --interval INTERVAL
summary interval, seconds summary interval, in seconds
-d DURATION, --duration DURATION
total duration of trace, in seconds
-T, --timestamp include timestamp on output -T, --timestamp include timestamp on output
-u, --microseconds microsecond histogram -u, --microseconds microsecond histogram
-m, --milliseconds millisecond histogram -m, --milliseconds millisecond histogram
...@@ -357,6 +359,7 @@ examples: ...@@ -357,6 +359,7 @@ examples:
./funclatency c:read # time the read() C library function ./funclatency c:read # time the read() C library function
./funclatency -u vfs_read # time vfs_read(), in microseconds ./funclatency -u vfs_read # time vfs_read(), in microseconds
./funclatency -m do_nanosleep # time do_nanosleep(), in milliseconds ./funclatency -m do_nanosleep # time do_nanosleep(), in milliseconds
./funclatency -i 2 -d 10 c:open # output every 2 seconds, for duration 10s
./funclatency -mTi 5 vfs_read # output every 5 seconds, with timestamps ./funclatency -mTi 5 vfs_read # output every 5 seconds, with timestamps
./funclatency -p 181 vfs_read # time process 181 only ./funclatency -p 181 vfs_read # time process 181 only
./funclatency 'vfs_fstat*' # time both vfs_fstat() and vfs_fstatat() ./funclatency 'vfs_fstat*' # time both vfs_fstat() and vfs_fstatat()
......
...@@ -17,6 +17,7 @@ import errno ...@@ -17,6 +17,7 @@ import errno
import itertools import itertools
import subprocess import subprocess
import sys import sys
import signal
import platform import platform
if sys.version_info.major < 3: if sys.version_info.major < 3:
...@@ -370,6 +371,9 @@ except Exception as e: ...@@ -370,6 +371,9 @@ except Exception as e:
else: else:
raise Exception("ausyscall: command not found") raise Exception("ausyscall: command not found")
# signal handler
def signal_ignore(signal, frame):
print()
def handle_errno(errstr): def handle_errno(errstr):
try: try:
...@@ -388,6 +392,8 @@ parser = argparse.ArgumentParser( ...@@ -388,6 +392,8 @@ parser = argparse.ArgumentParser(
parser.add_argument("-p", "--pid", type=int, help="trace only this pid") parser.add_argument("-p", "--pid", type=int, help="trace only this pid")
parser.add_argument("-i", "--interval", type=int, parser.add_argument("-i", "--interval", type=int,
help="print summary at this interval (seconds)") help="print summary at this interval (seconds)")
parser.add_argument("-d", "--duration", type=int,
help="total duration of trace, in seconds")
parser.add_argument("-T", "--top", type=int, default=10, parser.add_argument("-T", "--top", type=int, default=10,
help="print only the top syscalls by count or latency") help="print only the top syscalls by count or latency")
parser.add_argument("-x", "--failures", action="store_true", parser.add_argument("-x", "--failures", action="store_true",
...@@ -405,6 +411,10 @@ parser.add_argument("-l", "--list", action="store_true", ...@@ -405,6 +411,10 @@ parser.add_argument("-l", "--list", action="store_true",
parser.add_argument("--ebpf", action="store_true", parser.add_argument("--ebpf", action="store_true",
help=argparse.SUPPRESS) help=argparse.SUPPRESS)
args = parser.parse_args() args = parser.parse_args()
if args.duration and not args.interval:
args.interval = args.duration
if not args.interval:
args.interval = 99999999
if args.list: if args.list:
for grp in izip_longest(*(iter(sorted(syscalls.values())),) * 4): for grp in izip_longest(*(iter(sorted(syscalls.values())),) * 4):
...@@ -545,11 +555,20 @@ def print_latency_stats(): ...@@ -545,11 +555,20 @@ def print_latency_stats():
print("Tracing %ssyscalls, printing top %d... Ctrl+C to quit." % print("Tracing %ssyscalls, printing top %d... Ctrl+C to quit." %
("failed " if args.failures else "", args.top)) ("failed " if args.failures else "", args.top))
exiting = 0 if args.interval else 1
seconds = 0
while True: while True:
try: try:
sleep(args.interval or 999999999) sleep(args.interval)
print_stats() seconds += args.interval
except KeyboardInterrupt: except KeyboardInterrupt:
if not args.interval: exiting = 1
print_stats() signal.signal(signal.SIGINT, signal_ignore)
break if args.duration and seconds >= args.duration:
exiting = 1
print_stats()
if exiting:
print("Detaching...")
exit()
...@@ -151,6 +151,8 @@ optional arguments: ...@@ -151,6 +151,8 @@ optional arguments:
-p PID, --pid PID trace only this pid -p PID, --pid PID trace only this pid
-i INTERVAL, --interval INTERVAL -i INTERVAL, --interval INTERVAL
print summary at this interval (seconds) print summary at this interval (seconds)
-d DURATION, --duration DURATION
total duration of trace, in seconds
-T TOP, --top TOP print only the top syscalls by count or latency -T TOP, --top TOP print only the top syscalls by count or latency
-x, --failures trace only failed syscalls (return < 0) -x, --failures trace only failed syscalls (return < 0)
-e ERRNO, --errno ERRNO -e ERRNO, --errno ERRNO
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment