Figure 2-6 shows an Oracle Database 10g Release 1 server process operating system trace. The Oracle server process oracleprod3 has the process ID 14558. This is an active process, so many of lines in Figure 2-6 have been removed. Where the lines were removed, an ellipsis (...) was inserted.

Figure 2-6. Oracle's instrumentation through an operating system lens. Oracle has submitted a multiblock IO read request to the operating system by issuing the operating system readv call. The call took 0.6 ms, which is wonderfully fast.

In Figure 2-6, the instrumented call is readv. But just before the Oracle kernel code makes the readv call, Oracle asks the operating system for the time by issuing the gettimeofday call. Then, immediately after the readv call, Oracle once again asks the operating system for the time by issuing another gettimeofday call. According to the Linux gettimeofday manual page, the second numeric output shown is a time in microseconds. Subtracting the initial time (801187) from the final time (801788), we find that this particular readv call took 601 (s (801788 - 801187), or 0.6 ms.