| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Message-Id: <1264580883-15324-1-git-send-email-tzanussi@gmail.com>
Date: Wed, 27 Jan 2010 02:27:51 -0600
From: Tom Zanussi <tzanussi@...il.com>
To: linux-kernel@...r.kernel.org
Cc: mingo@...e.hu, fweisbec@...il.com, rostedt@...dmis.org,
k-keiichi@...jp.nec.com
Subject: [PATCH 00/12] perf trace: Python scripting support
This patchset adds a Python scripting engine to perf trace. In the
process, it also creates a scripting-engines directory under perf/util
and moves the existing Perl support there, to avoid cluttering the
main perf/util directory with scripting support files.
It also includes some minor bugfixes and adds Documentation for the
Python support, which includes a step-by-step example detailing how to
write a new trace stream processing script using Python.
Finally, it adds several new scripts, all dealing with aggregation of
system call trace data. To make those scripts more user-friendly, it
adds a couple patches that export some of the syscall metadata, enough
to allow syscall names rather than raw numbers to be printed in the
output.
NOTE: in order to run the 'record' side of these scripts, you need to
first revert commit f5a2c3dce03621b55f84496f58adc2d1a87ca16f "perf
record: Intercept all events" - recording the syscall events seems to
always trigger the infinite loop in there.
Here's the new current listing of available scripts:
# perf trace -l
List of available trace scripts:
workqueue-stats workqueue stats (ins/exe/create/destroy)
wakeup-latency system-wide min/max/avg wakeup latency
rw-by-file <comm> r/w activity for a program, by file
failed-syscalls [comm] system-wide failed syscalls
rw-by-pid system-wide r/w activity
syscall-counts-by-pid [comm] system-wide syscall counts, by pid
failed-syscalls-by-pid [comm] system-wide failed syscalls, by pid
syscall-counts [comm] system-wide syscall counts
And some sample output from the four new ones:
The 'syscall-counts' script just gives a high-level overview of all
syscalls on the system, listed by syscall:
root@...picana:~# perf trace record syscall-counts
^C[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 32.165 MB perf.data (~1405309 samples) ]
root@...picana:~# perf trace report syscall-counts
syscall events:
event count
---------------------------------------- -----------
sys_write 269407
sys_getdents 2782
sys_close 2004
sys_swapoff 1095
sys_read 920
sys_sched_setparam 511
sys_open 331
sys_newfstat 326
sys_mmap 217
sys_munmap 216
sys_select 173
sys_getgid 128
sys_futex 89
sys_poll 76
174 64
sys_setuid 64
sys_setitimer 50
15 25
sys_rt_sigprocmask 24
sys_lseek 7
sys_inotify_add_watch 6
sys_writev 5
sys_ioctl 5
sys_wait4 2
sys_perf_event_open 1
sys_fcntl 1
The 'syscall-counts-by-pid' script dives down into more detail,
listing the system calls by comm/pid:
root@...picana:~# perf trace report syscall-counts
syscall events by comm/pid:
comm [pid]/syscalls count
---------------------------------------- ----------
gnome-screensav [6351]
sys_read 8
sys_poll 2
firefox [6505]
sys_futex 72
sys_write 19
firefox [6502]
sys_read 61
sys_select 41
sys_poll 41
sys_futex 17
sys_inotify_add_watch 2
sys_write 1
perf [13629]
sys_write 269386
sys_read 790
sys_newfstat 326
sys_open 326
sys_close 324
sys_getdents 222
sys_mmap 217
sys_munmap 216
sys_lseek 7
sys_ioctl 4
sys_perf_event_open 1
sys_fcntl 1
15 1
sys_poll 1
pulseaudio [6275]
sys_poll 1
gnome-panel [6329]
sys_inotify_add_watch 4
sys_poll 1
sys_read 1
apache2 [6004]
sys_wait4 2
sys_select 2
wterm [6659]
sys_read 7
sys_select 3
sys_write 1
mysqld [5120]
sys_select 2
mysqld [5119]
sys_select 2
npviewer.bin [13313]
sys_getdents 2560
sys_close 1679
sys_swapoff 1095
sys_sched_setparam 511
sys_getgid 128
174 64
sys_setuid 64
Xorg [5853]
sys_select 123
sys_setitimer 50
sys_read 50
15 24
sys_rt_sigprocmask 24
sys_poll 24
sys_writev 5
The 'failed-syscalls' script likewise gives a high-level overview of
all failed syscalls on the system, listed both by comm and by syscall:
root@...picana:~# perf trace record failed-syscalls
^C[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 32.653 MB perf.data (~1426644 samples) ]
root@...picana:~# perf trace report failed-syscalls
failed syscalls, by comm:
comm # errors
-------------------- ----------
npviewer.bin 2468
firefox 91
Xorg 31
gnome-screensav 6
wterm 5
gnome-panel 5
trashapplet 4
hald-addon-stor 4
gvfsd-trash 2
gnome-settings- 2
sh 1
update-notifier 1
failed syscalls, by syscall:
syscall # errors
------------------------------ ----------
sys_close 2468
sys_read 81
sys_futex 29
sys_select 15
undefined 15
sys_inotify_add_watch 6
sys_open 4
sys_access 1
sys_wait4 1
And again, diving into more detail, the 'failed-syscalls-by-pid'
script lists the failed system calls by comm/pid and error:
root@...picana:~# perf trace report failed-syscalls-by-pid
perf trace started with Python script /root/libexec/perf-core/scripts/python/failed-syscalls-by-pid.py
syscall errors:
comm [pid] count
------------------------------ ----------
gnome-screensav [6351]
syscall: sys_read
err = -11 6
firefox [6505]
syscall: sys_futex
err = -110 28
firefox [6502]
syscall: sys_read
err = -11 60
syscall: sys_access
err = -2 1
syscall: sys_inotify_add_watch
err = -2 2
gnome-panel [6329]
syscall: sys_read
err = -11 1
syscall: sys_inotify_add_watch
err = -2 4
wterm [6659]
syscall: sys_read
err = -11 5
trashapplet [6364]
syscall: sys_read
err = -11 4
sh [13717]
syscall: sys_wait4
err = -512 1
npviewer.bin [13313]
syscall: sys_close
err = -11 2468
Xorg [5853]
syscall: sys_read
err = -11 1
syscall: undefined
err = -4 15
syscall: sys_select
err = -514 15
gnome-settings- [6297]
syscall: sys_read
err = -11 2
hald-addon-stor [5721]
syscall: sys_open
err = -123 1
hald-addon-stor [5715]
syscall: sys_open
err = -123 1
hald-addon-stor [5724]
syscall: sys_open
err = -123 1
hald-addon-stor [5718]
syscall: sys_open
err = -123 1
gvfsd-trash [6370]
syscall: sys_read
err = -11 1
gvfsd-trash [13719]
syscall: sys_futex
err = -110 1
update-notifier [6395]
syscall: sys_read
err = -11 1
These scripts can be used to get a general idea of syscall activity on
the system, which can be used to direct further investigation in the
form of either more refined scripts and/or looking at the source of
apps that seem to be acting strangely.
For instance, the output of failed-syscalls-by-pid shows npviewer.bin,
a flash plugin wrapper, seems to be making a lot of failed close
system calls, while the output of syscalls-by-pid doesn't show a lot
of open calls. So it's apparently wasting a lot of time closing
nonexistent files (this script was run for only a very short time).
It might be useful at this point to record
syscalls::sys_enter/exit_close syscalls and write a script that would
hash the fds by error code to find out which files it's trying
unsuccessfully to close. That might be enough information to go
examine and fix the offending code in the wrapper, or put the blame on
the wrappee if that's where the problem is...
Tom Zanussi (12): perf trace/scripting: Fix supported language listing
option perf trace/scripting: fix bug in Util.pm perf
trace/scripting: move common code out of Perl-specific files perf
trace/scripting: move Perl scripting files to scripting-engines dir
perf trace/scripting: remove check-perf-trace from listed scripts
perf trace/scripting: add Python scripting engine perf
trace/scripting: add syscall tracing scripts perf: export some
syscall metadata perf tools: save syscall map perf trace/scripting:
make the syscall map available as a Python dict perf
trace/scripting: make the syscall map available as a Perl hash perf
trace/scripting: add perf-trace-python Documentation
kernel/trace/trace_syscalls.c | 87 +++
tools/perf/Documentation/perf-trace-perl.txt | 3 +-
tools/perf/Documentation/perf-trace-python.txt | 624 ++++++++++++++++++
tools/perf/Documentation/perf-trace.txt | 15 +-
tools/perf/Makefile | 33 +-
tools/perf/builtin-trace.c | 5 +-
tools/perf/scripts/perl/Perf-Trace-Util/Context.c | 49 ++-
tools/perf/scripts/perl/Perf-Trace-Util/Context.xs | 27 +-
.../perl/Perf-Trace-Util/lib/Perf/Trace/Context.pm | 2 +-
.../perl/Perf-Trace-Util/lib/Perf/Trace/Util.pm | 24 +-
.../perf/scripts/perl/bin/check-perf-trace-record | 7 +-
.../perf/scripts/perl/bin/check-perf-trace-report | 6 -
tools/perf/scripts/perl/bin/failed-syscalls-record | 2 +
tools/perf/scripts/perl/bin/failed-syscalls-report | 4 +
tools/perf/scripts/perl/failed-syscalls.pl | 51 ++
.../perf/scripts/python/Perf-Trace-Util/Context.c | 110 ++++
.../python/Perf-Trace-Util/lib/Perf/Trace/Core.py | 91 +++
.../python/Perf-Trace-Util/lib/Perf/Trace/Util.py | 37 ++
.../python/bin/failed-syscalls-by-pid-record | 2 +
.../python/bin/failed-syscalls-by-pid-report | 4 +
.../python/bin/syscall-counts-by-pid-record | 2 +
.../python/bin/syscall-counts-by-pid-report | 4 +
.../perf/scripts/python/bin/syscall-counts-record | 2 +
.../perf/scripts/python/bin/syscall-counts-report | 4 +
tools/perf/scripts/python/check-perf-trace.py | 83 +++
.../perf/scripts/python/failed-syscalls-by-pid.py | 69 ++
tools/perf/scripts/python/syscall-counts-by-pid.py | 65 ++
tools/perf/scripts/python/syscall-counts.py | 59 ++
.../perf/util/scripting-engines/trace-event-perl.c | 568 +++++++++++++++++
.../util/scripting-engines/trace-event-python.c | 576 +++++++++++++++++
tools/perf/util/trace-event-info.c | 25 +
tools/perf/util/trace-event-parse.c | 78 +++
tools/perf/util/trace-event-perl.c | 661 --------------------
tools/perf/util/trace-event-perl.h | 55 --
tools/perf/util/trace-event-read.c | 18 +
tools/perf/util/trace-event-scripting.c | 167 +++++
tools/perf/util/trace-event.h | 20 +-
37 files changed, 2895 insertions(+), 744 deletions(-)
create mode 100644 tools/perf/Documentation/perf-trace-python.txt
delete mode 100644 tools/perf/scripts/perl/bin/check-perf-trace-report
create mode 100644 tools/perf/scripts/perl/bin/failed-syscalls-record
create mode 100644 tools/perf/scripts/perl/bin/failed-syscalls-report
create mode 100644 tools/perf/scripts/perl/failed-syscalls.pl
create mode 100644 tools/perf/scripts/python/Perf-Trace-Util/Context.c
create mode 100644 tools/perf/scripts/python/Perf-Trace-Util/lib/Perf/Trace/Core.py
create mode 100644 tools/perf/scripts/python/Perf-Trace-Util/lib/Perf/Trace/Util.py
create mode 100644 tools/perf/scripts/python/bin/failed-syscalls-by-pid-record
create mode 100644 tools/perf/scripts/python/bin/failed-syscalls-by-pid-report
create mode 100644 tools/perf/scripts/python/bin/syscall-counts-by-pid-record
create mode 100644 tools/perf/scripts/python/bin/syscall-counts-by-pid-report
create mode 100644 tools/perf/scripts/python/bin/syscall-counts-record
create mode 100644 tools/perf/scripts/python/bin/syscall-counts-report
create mode 100644 tools/perf/scripts/python/check-perf-trace.py
create mode 100644 tools/perf/scripts/python/failed-syscalls-by-pid.py
create mode 100644 tools/perf/scripts/python/syscall-counts-by-pid.py
create mode 100644 tools/perf/scripts/python/syscall-counts.py
create mode 100644 tools/perf/util/scripting-engines/trace-event-perl.c
create mode 100644 tools/perf/util/scripting-engines/trace-event-python.c
delete mode 100644 tools/perf/util/trace-event-perl.c
delete mode 100644 tools/perf/util/trace-event-perl.h
create mode 100644 tools/perf/util/trace-event-scripting.c
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Powered by blists - more mailing lists