Working on systemtap equivalent to bcc ucalls.py

[William Cohen]

Hi,

I have been working a Systemtap script that implements similar functionality to bcc's ucalls (https://github.com/iovisor/bcc/blob/master/tools/lib/ucalls.py). The systemtap script will count the number of function/method calls for java/python/perl/php/ruby/tcl code pointed at by the -x <pid> or -c <command> options. It also takes an optional argument for the number of seconds between reports. One can also control the number of printed by setting the TOP variable on the command line. So something like this monitoring "dnf debuginfo-install kernel-4.18.17-200.fc28.x86_64"


$ ./profiling/ucalls.stp -x 22952 -G TOP=10 10
Missing separate debuginfos, use: debuginfo-install kernel-core-4.18.17-200.fc28.x86_64
METHOD # CALLS
/usr/lib/python3.6/site-packages/dnf/cli/progress.py.progress 20
/usr/lib/python3.6/site-packages/dnf/cli/format.py.format_number 20
/usr/lib64/python3.6/posixpath.py.basename 20
/usr/lib/python3.6/site-packages/dnf/repo.py._progress_cb 20
/usr/lib/python3.6/site-packages/dnf/repo.py.download_size 20
/usr/lib/python3.6/site-packages/dnf/repo.py.__str__ 20
/usr/lib64/python3.6/posixpath.py._get_sep 20
/usr/lib/python3.6/site-packages/dnf/cli/progress.py._update 10
/usr/lib/python3.6/site-packages/dnf/cli/progress.py.message 10
/usr/lib/python3.6/site-packages/dnf/cli/format.py.format_time 10

METHOD # CALLS
/usr/lib/python3.6/site-packages/dnf/cli/progress.py.progress 20
/usr/lib/python3.6/site-packages/dnf/cli/format.py.format_number 20
/usr/lib64/python3.6/posixpath.py.basename 20
/usr/lib/python3.6/site-packages/dnf/repo.py._progress_cb 20
/usr/lib/python3.6/site-packages/dnf/repo.py.download_size 20
/usr/lib/python3.6/site-packages/dnf/repo.py.__str__ 20
/usr/lib64/python3.6/posixpath.py._get_sep 20
/usr/lib/python3.6/site-packages/dnf/cli/progress.py._update 10
/usr/lib/python3.6/site-packages/dnf/cli/progress.py.message 10
/usr/lib/python3.6/site-packages/dnf/cli/format.py.format_time 10

There are a number of other options that the bcc ucalls has that are not implemented in this systemtap script:

language "-l" <language> : this isn't needed in the systemtap script. systemtap optional probes allow automatic selection of the language

Latency "-L": this is possible and considering adding this. However, the ucalls doesn't handle recursive functions.

Report syscalls "-S" this should also be easy to add. Need to see how ucalls outputs this.

Report in milliseconds "-m" : this didn't seem that important


One of the things I noticed when running the script with the periodic updates is that it will exist due to exceeding the overhead limits. I think it is because the handler printing out the data takes a substantial amount of time and locks the associative array will working on it, causing the overhead to go up quite a bit for all the probes that are collecting data.

It would be nice if systemtap had some mechanism kind of like double buffering used for video displays. Two entries for associative arrays: one for the data collection and the other for the display. They are swapped when then time probe handler runs. This would allow the reporting to lock the associative arrays for a much shorter period of time.

-Will