ProbeVue: Practical Introduction

Since the introduction of ProbeVue on AIX 6.1, IBM has supported dynamic tracing on AIX. ProbeVue is particularly suitable for online debugging and troubleshooting, as well as performance analysis and monitoring. So-called sample points in the kernel or user programs can be activated dynamically in order to collect interesting data which can then be evaluated. ProbeVue is designed to be safe to run and therefore can be used on production systems. In this introduction, ProbeVue is to be briefly introduced and it is shown how to write and start simple (Vue) programs.

**How ProbeVue Works**

To use ProbeVue you don’t need a special debug version of the kernel and you don’t have to adapt applications. ProbeVue can be used on any AIX kernel starting with AIX 6.1 and any binary program. As long as no probe is activated at a probe point, ProbeVue does not cost a single machine instruction overhead! Only when a probe is activated, the machine code is changed at the probe point and additional code is added to collect data. This is shown briefly using a small example with the help of the kernel debugger (kdb). The example lists the first 8 assembler instructions that are executed in the kernel when a system call is started. ProbeVue is initially not active.

# echo "dc sc_entry_etrc_point 8" | kdb -script
read vscsi_scsi_ptrs OK, ptr = 0x0
(0)> dc sc_entry_etrc_point 8
Executing dc command
sc_entry_etrc_point+000000              ori    r0,r0,0
syscall+000244           bcctrl   
.sys_call_ret+000000              ori    r0,r0,0
sc_exit_etrc_point+000000              ori    r0,r0,0
.sys_call_ret+000008           mfsprg    r9,SPRG1
.sys_call_ret+00000C               mr    r31,r3
.sys_call_ret+000010               ld    r3,5020(0)          5020=legacy_amr+000010
.sys_call_ret+000014               li    r5,0

End of execution for dc command
(0)> Executing q command
#

As soon as ProveVue is started and at least one system call is traced, the code in the kernel is changed dynamically:

# echo "dc sc_entry_etrc_point 8" | kdb -script
read vscsi_scsi_ptrs OK, ptr = 0x0
(0)> dc sc_entry_etrc_point 8
Executing dc command
sc_entry_etrc_point+000000                b    <.sc_entry_etrc_fixup>
syscall+000244           bcctrl   
.sys_call_ret+000000              ori    r0,r0,0
sc_exit_etrc_point+000000                b    <.sc_exit_etrc_fixup>
.sys_call_ret+000008           mfsprg    r9,SPRG1
.sys_call_ret+00000C               mr    r31,r3
.sys_call_ret+000010               ld    r3,5020(0)          5020=legacy_amr+000010
.sys_call_ret+000014               li    r5,0

End of execution for dc command
(0)> Executing q command
#

You can see that the first instruction has changed from “ori r0, r0,0” (OR Immediate) to “b <.sc_entry_etrc_fixup>” (Branch). Additional code is executed by ProbeVue through the branch. Once this has been processed, the system jumps back and continues with the next instruction bcctrl (Branch Conditional to Count Register).

As soon as ProbeVue is no longer tracing system calls, the code in the kernel is changed back to the original version, which means that ProbeVue no longer incurs any overhead. Overhead through ProbeVue arises only at probe points that are activated! If only a few probes are activated, the overhead by ProbeVue should be extremely small. If you activate a large number of probes on a system, this can manifest itself in the form of performance problems. You should only activate those probes that are really interesting and necessary for an investigation!

When using ProbeVue, small scripts are typically written, which can then be executed with the probevue command. To do this, you need special permissions that only the root user has by default. The scripts are written in ProbeVue‘s own script language Vue and typically saved in files with the extension “.e“.

**The first ProbeVue Script**

In order to use ProbeVue, the fileset bos.sysmgt.trace must be installed. The probevue command is part of this fileset. The available probe points belong to so-called probe managers, these include syscall, syscallx and interval. For the first examples, we stick to samples from the manager syscall.

Which probe points a probe manager supports, can be displayed with the help of the option “-l” and the name of the probe manager, here for the manager syscall:

# probevue -l syscall
The syscall probe manager supports probes at the entry and exit of well-defined and documented base AIX system calls. List of Probes Supported by Syscall Probe Manager are:
absinterval
accept
bind
close
creat
execve
exit
fork
…
socket
socketpair
stat
waitpid
write
#

In the simplest case, so-called clauses are used in a Vue script. Each clause consists of one (or more probe points) and a so-called action block. A probe point is a tuple of fields separated by a colon, the first field starts with “@@” and the name of the manager of the probe. The other fields then depend on the specific manager. In the case of the syscall probe manager there are exactly 4 fields, here are a few examples first:

@@syscall:45678:open:entry
   Probe at entry of open system call in process with ID 45678.

@@syscall:*:write:exit
   Probe at exit of system call write. The asterisk indicates that the system call has to be traced for all processes.

The second field (PID or “*“) can be used to decide whether all processes or only a specific process should be traced. The third field is used to specify the system call that is of interest and, finally, the fourth field is used to select whether an action is to be carried out when entering or exiting the system call. You can of course do both.

The action block with statements to be carried out is started by a curly bracket “{” and ended by a curly bracket “}“. One of the simplest and most useful statements is the printf() function known from ksh, awk, and C. We summarize this in our first Vue script:

# cat example1.e
@@syscall:*:open:entry
{
        printf("system call open was called\n");
}
#

For all processes, when the system call open is entered, the printf() function is started, which outputs the text “system call open was called” followed by a new line.

The Vue script can easily be started with the probevue command by specifying it as an argument:

# probevue example1.e
system call open was called
system call open was called
system call open was called
system call open was called
system call open was called
system call open was called
system call open was called
system call open was called
system call open was called
system call open was called
system call open was called
system call open was called
system call open was called
system call open was called
system call open was called
system call open was called
system call open was called
system call open was called
system call open was called
system call open was called
^C
#

The program runs until it is aborted e.g. by using Control-C. Every time any process uses the system call open, the message “system call open was called” is produced.

The possibility to specify the interpreter to use with the special comment “#!” in the first line of the script, also works for Vue scripts, of course:

# cat example1.e
#! /usr/bin/probevue

@@syscall:*:open:entry
{
        printf("system call open was called\n");
}
# chmod +x example1.e
#

The script can now be started simply using its file name:

# ./example1.e
system call open was called
system call open was called
system call open was called
system call open was called
^C
#

Scripts Should be Documented

A good programming style is to add comments to programs. On the one hand, e.g. the author, date, version and description of the script could be documented at the beginning of the script; on the other hand, parts of the program that are not easy to understand should be explained with the help of comments. In Vue scripts, as in the C programming language, the character string “/*” serves as the start of a comment. The comment extends until the next occurrence of the character string “*/“.

We’ll improve our script by adding a few lines of comment:

# cat example1.e
#! /usr/bin/probevue

/* Description: First Vue script to show usage of open system call.
   Version: 0.2  */

@@syscall:*:open:entry
{
        printf("system call open was called\n");
}

#

Alternatively, a comment in C++ style is possible, a comment is started by the character string “//” and extends until the end of the line.

Lines beginning with the “#” character are ignored. IBM recommends not to use this for comments!

Using Builtin Variables

Our program is rather uninteresting so far. It outputs that an open system call was carried out, but no further information is given.

ProbeVue has a number of built-in variables that are automatically filled by ProbeVue with values from the current context of a probe. In particular, there are the builtin variables __pid and __pname. The variable __pid contains the PID of the process that triggered a probe, in our case the PID of the process that started the open system call. The associated name of the process is stored in the variable __pname.

With the help of these two built-in variables, our script can be expanded and the PID and the name of the process that started the open system call can also be shown each time an open system call is executed. We extend our program by letting printf() output this additional information:

# cat example1.e
#! /usr/bin/probevue

/* Description: First Vue script to show usage of open system call.
   Version: 0.3  */

@@syscall:*:open:entry
{
        printf("%s (%lld) has called open\n",__pname,__pid);
}

#

After starting the extended script you get slightly more information:

# ./example1.e
ovbbccb (12058768) has called open
ovbbccb (12058768) has called open
oacore (25165874) has called open
oacore (25165874) has called open
auditpr (12124312) has called open
db2fmcd (5570782) has called open
sh (31064148) has called open
db2sysc (18743362) has called open
db2sysc (18743362) has called open
…
^C
#

Access to Arguments of a System Call

The system call open is called with 2 or 3 arguments, see “man open“:

int open (Path, OFlag [, Mode])

       const char *Path;

       int OFlag;

       mode_t Mode;

The first argument is the address (pointer) to a character string with the path name of the file to be opened. When entering a system call, the probe manager syscall assigns the arguments with which a system call was called to the special builtin variables __arg1, __arg2, etc. This means that we theoretically have access to the argument with the file path for the system call open by our Vue script. The idea would be to display the file path as additional information.

First of all you have to declare the the system call in the form of a function prototype if you want to use arguments of the system call. This is necessary so that ProbeVue knows the associated data types for the arguments (integer value, floating point value, address). This is very easy by listing the system call with return type, name and argument list in C form, before the first clause, e.g. like this:

int open( const char* Path , int OFlag );

This means that ProbeVue can tell that the first argument is an address and the second argument is an integer value. We have left out the third, optional, argument. In principle, it would even be sufficient to only give the first argument here, since we will only access this one.

Unfortunately, there is another small complication, the address for the file path is not in the address space of the Vue script. Therefore the address cannot be used directly, but the underlying data (character string) must be copied into the address space of the Vue script. The Vue function get_userstring() is available for this:

String get_userstring( char* addr , int len )

The first argument is the address at which the data to be copied (character string) is located. The second argument specifies the maximum number of characters to be copied. The value -1 can be specified (not recommended), then copying continues until the end of the character string is reached or the ProbeVue script crashes.

We put the declaration of open and the printing of the file path, using get_userstring(), into our Vue script:

# cat example1.e
#! /usr/bin/probevue

/* Description: First Vue script to show usage of open system call.
   Version: 0.4  */

int open( const char *Path , int OFlag );

@@syscall:*:open:entry
{
        printf("%s (%lld) has called open for %s\n",__pname,__pid,get_userstring(__arg1,256));
}
#

If we start our script now, with every open system call we not only get the PID and the name of the process, but also the path of the file that is being opened:

# ./example1.e
WRN-592: Line:12 Column:82 Incompatible argument, type mismatch in pointer assignment.
nimesis (15925642) has called open for /.nimesis_dbg_level
nimesis (15925642) has called open for /etc/objrepos/nim_attr
nimesis (15925642) has called open for /etc/objrepos/nim_attr.vc
sshd (20054452) has called open for /etc/passwd
sshd (20054452) has called open for /etc/security/passwd
sshd (20054452) has called open for /etc/security/login.cfg.idx
…
^C
#

The warning in the first line of the output comes from calling get_userstring(). The builtin variable __arg1 has the type 64-bit integer value, but the get_userstring() function expects an address (pointer). With the warning, ProbeVue signals that the integer value will be interpreted as an address. In our case, __arg1 actually contains an address and you can signal this to ProbeVue by using a so-called cast:

(void*)__arg1

This tells ProbeVue that the integer value should be used as an address (pointer). ProbeVue then no longer issues a warning when the script is started.

Monitoring of only one Process

The developed example program monitors the open calls of all processes. But sometimes you are only interested in one particular process. If you know the PID of the process in question, this can be done very easily, instead of the wildcard “*” in the probe point, you simply enter the PID of the process:

# cat example1.e
#! /usr/bin/probevue

/* Description: First Vue script to show usage of open system call.
   Version: 0.5  */

int open( const char *Path , int OFlag );

@@syscall: 15925642:open:entry
{
        printf("%s (%lld) has called open for %s\n",__pname,__pid,get_userstring((void*)__arg1,256));
}

#

Then only the process with the PID 15925642 is monitored. However, this is a bit impractical if you want to monitor another process later, you would always have to change the PID in the Vue script. The use of arguments is an alternative. Similar to a shell, in Vue scripts you can access the arguments with which the script was called via $1, $2 etc. We therefore use the argument $1 instead of the fixed PID 15925642 in the probe point:

# cat example1.e
#! /usr/bin/probevue

/* Description: First Vue script to show usage of open system call.
   Version: 0.6  */

int open( const char *Path , int OFlag );

@@syscall: $1:open:entry
{
        printf("%s (%lld) has called open for %s\n",__pname,__pid,get_userstring((void*)__arg1,256));
}

#

When the script is started, the PID of the process to be monitored must now be given as an argument:

# ./example1.e 31130058
sshd (31130058) has called open for /dev/ptc
sshd (31130058) has called open for /dev/pts/1
sshd (31130058) has called open for /etc/group
sshd (31130058) has called open for /etc/group
sshd (31130058) has called open for /etc/group
sshd (31130058) has called open for /etc/group
sshd (31130058) has called open for /etc/passwd
sshd (31130058) has called open for /etc/security/passwd
sshd (31130058) has called open for /etc/passwd
^C
#

In a number of further articles we will show you more of ProbeVue‘s capabilities.

How ProbeVue Works

The first ProbeVue Script