If you have not already done so, you must collect performance data for synprog. See Collecting Data for the synprog Example for instructions.
This part of the example illustrates different ways of creating descendant processes and how they are handled, and demonstrates the Timeline display to get an overview of the execution of a program that creates descendant processes. The program forks two descendant processes. The parent process does some work, then calls popen, then does some more work. The first descendant does some work and then calls exec. The second calls system, then calls fork. The descendant from this call to fork immediately calls exec. After doing some work, the descendant calls exec again and does some more work.
% cd /work-directory/synprog % analyzer test.2.er &
When you load the parent experiment, the descendant experiments are automatically loaded, but their data is filtered out.
The topmost bar for each experiment is the Samples bar. The bar below it contains the clock-based profiling event data.
Some of the samples are colored yellow and green. The green color indicates that the process is running in User CPU mode. The fraction of time spent in User CPU mode is given by the proportion of the sample that is colored green. Because there are three processes running most of the time, only about one-third of each sample is colored green. The rest is colored yellow, which indicates that the process is waiting for the CPU. This kind of display is normal when there are more processes running than there are CPUs to run on. When the parent process (experiment 1) has finished executing and is waiting for its children to finish, the samples for the running processes are half green and half yellow, showing that there are only two processes contending for the CPU. When the process that generates experiment 3 has completed, the remaining process (experiment 7) is able to use the CPU exclusively, and the samples in experiment 7 show all green after that time.
You can zoom in by dragging through the region you want to zoom in to, or clicking the zoom in button , or choosing Timeline
Zoom In, or typing Alt-T, I.
There are gaps between the event markers in both experiment 3 and experiment 7, but the gaps in one experiment occur where there are event markers in the other experiment. These gaps show where one process is waiting for the CPU while the other process is executing.
You can reset the display by clicking the Reset Display button , or choosing Timeline
Zoom In x2, or typing Alt-T, R.
Some experiments do not extend for the entire length of the run. This situation is indicated by a light gray color for the regions of time where these experiments do not have any data. Experiments 3, 5, 6, and 7 are created after their parent processes have done some work. Experiments 2, 5, and 6 are terminated by a successful call to exec. Experiment 3 ends before experiment 7 and its process terminates normally. The points at which exec is called show clearly: the data for experiment 3 starts where the data for experiment 2 ends, and the data for experiment 7 starts where the data for experiment 6 ends.
The experiments that are terminated by a successful call to exec show up as "bad experiments" in the Experiments tab. The experiment icon has a cross in a red circle superimposed on it.
At the bottom of the text pane is a warning that the experiment terminated abnormally. Whenever a process successfully calls exec, the process image is replaced and the collector library is unloaded. The normal completion of the experiment cannot take place, and is done instead when the experiment is loaded into the Analyzer.
The dark gray regions in the samples bars indicate time spent waiting, other than waiting for the CPU or for a user lock. The first dark gray region in experiment 1 occurs during the call to popen. Most of the time is spent waiting, but there are some events recorded during this time. In this region, the process created by popen is using CPU time and competing with the other processes, but it is not recorded in an experiment. Similarly, the first dark gray region in experiment 4 occurs during a call to system. In this case the calling process waits until the call is complete, and does no work until that time. The process created by the call to system is also competing with the other processes for the CPU, and does not record an experiment.
The last gray region in experiment 1 occurs when the process is waiting for its descendants to complete. The process that records experiment 4 calls fork after the call to system is complete, and then waits until all its descendant processes have completed. This wait time is indicated by the last gray region. In both these cases, the waiting processes do no work and do not have descendants that are not recording experiments.
Experiment 4 spends most of its time waiting. As a consequence, it records no profiling data until the very end of the experiment.
Experiment 5 appears to have no data at all. It is created by a call to fork that is immediately followed by a call to exec.
At sufficiently high zoom, you can see that there is a very small sample in experiment 5.
The experiment recorded an initial sample point and a sample point in the call to exec, but did not last long enough to record any profiling data. This is the reason why there is no profiling data bar for experiment 5.
If you have access to a computer with more than one processor, run the second data collection again. What differences do you see in the Timeline display?
See also | |
---|---|
The Timeline Tab The Event Tab Interpreting the Timeline Display Finding Problem Time Periods in Your Program |