C.1 System Call Tracing

Many versions of Unix provide a system call tracing facility. This can often provide a valuable debugging technique.

Working at this level, we need to differentiate between a system call and a function. The former is an entry point into the kernel, and that is what we are able to trace with the tools we will look at in this section. POSIX and most other standards use the term "function" to describe what appears to the user to be functions, even though on some implementations, they may be system calls. For example, on a Berkeley-derived kernel, socket is a system call even though it appears to be a normal C function to the application programmer. But under SVR4, we will see shortly that it is a library function in the sockets library that issues calls to putmsg and getmsg, these latter two being actual system calls.

In this section, we will examine the system calls involved in running our daytime client. We showed this client in Figure 1.5.

BSD Kernel Sockets

We start with FreeBSD, a Berkeley-derived kernel in which all the socket functions are system calls. The ktrace program is provided by FreeBSD to run a program and trace the system calls that are executed. This writes the trace information to a file (whose default name is ktrace.out), which we print with kdump. We execute our sockets client as

freebsd % ktrace daytimetcpcli 192.168.42.2
Tue Aug 19 23:35:10 2003

We then execute kdump to output the trace information to standard output.

 3211 daytimetcpcli CALL socket(0x2,0x1,0)
 3211 daytimetcpcli RET  socket 3

 3211 daytimetcpcli CALL connect(0x3,0x7fdffffe820,0x10)
 3211 daytimetcpcli RET  connect 0

 3211 daytimetcpcli CALL read(0x3,0x7fdffffe830,0x1000)
 3211 daytimetcpcli GIO  fd 3 read 26 bytes
      "Tue Aug 19 23:35:10 2003
      "
 3211 daytimetcpcli RET  read 26/0x1a

...

 3211 daytimetcpcli CALL write(0x1,0x204000,0x1a)
 3211 daytimetcpcli GIO  fd 1 wrote 26 bytes
      "Tue Aug 19 23:35:10 2003/r
      "
 3211 daytimetcpcli RET  write 26/0x1a

 3211 daytimetcpcli CALL read(0x3,0x7fdffffe830,0x1000)
 3211 daytimetcpcli GIO  fd 3 read 0 bytes
      ""
 3211 daytimetcpcli RET  read 0

 3211 daytimetcpcli CALL exit(0)

3211 is the PID. CALL identifies a system call, RET is the return, and GIO stands for generic process I/O. We see the calls to socket and connect, followed by the call to read that returns 26 bytes. Our client writes these bytes to standard output and the next call to read returns 0 (EOF).

Solaris 9 Kernel Sockets

Solaris 2.x is based on SVR4 and all the releases before 2.6 have implemented sockets as shown in Figure 31.3. One problem, however, with all SVR4 implementations that implement sockets in this fashion is that they rarely provide 100% compatibility with Berkeley-derived kernel sockets. To provide additional compatibility, versions starting with Solaris 2.6 changed the implementation technique and implemented sockets using a sockfs filesystem. This provides kernel sockets, as we can verify using truss on our sockets client.

solaris % truss -v connect daytimetcpcli 127.0.0.1
Mon Sep  8 12:16:42 2003

After the normal library linking, the first system call we see is to so_socket, a system call invoked by our call to socket.

so_socket(PF_INET, SOCK_STREAM, IPPROTO_IP, "", 1) = 3
connect(3, 0xFFBFDEF0, 16, 1)                   =0
        AF_INET  name = 127.0.0.1  port = 13
read(3, " M o n   S e p     8   1".., 4096)     = 26
Mon Sep  8 12:48:06 2003
write(1, " M o n   S e p     8   1".., 26)      = 26
read(3, 0xFFBFDF03, 4096)                       = 0
_exit(0)

The first three arguments to so_socket are our three arguments to socket.

We see that connect is a system call, and truss, when invoked with the -v connect flag, prints the contents of the socket address structure pointed to by the second argument (the IP address and port number). The only system calls that we have replaced with ellipses are a few dealing with standard input and standard output.