Oracle associates the wait event name with the wait time, which in Figure 2-6 is 0.6 ms. If we had been looking at server process 14558 through Oracle's wait event interface during the time of the Figure 2-6 trace, we would have seen the server process was posting a db file scattered read. I like to say that the Oracle process is yelling out the wait event as it impatiently waits for the operating system to return the requested blocks. After the server process was done waiting, we would see that the time waited was 0.6 ms. So, in a very real way, Oracle has made this tracing information available to us without tracing, but through its wait interface. Beautiful simplicity!

Every Oracle process is either posting a wait event or consuming CPU3-there are no exceptions. This means that if you have hundreds of Oracle sessions, there is a good chance you'll have hundreds of sessions posting wait events. Knowing that sessions either consume CPU or post a wait event will become more important as you go deeper into performance analysis.

Let's take a look at another multiblock read call but using a different operating system tracing option. Look closely at Figure 2-7. Process 6852 was traced using the rp options. The r option shows the timing information at the beginning of the next line. For this example, the initial gettimeofday call took 0.000147 (s, or 0.147 ms. The 16 8KB block multiblock read request took 22.5 ms. This is much too slow for a respectable IO subsystem. Clearly, this IO request contains at least one block that resides on a physically spinning disk.