Process Monitoring with prstat

The following chapter takes a deeper look at the Solaris tool prstat(1), the all round utility that helps understand system utilisation.

prstat– The Allround Utility

One of the most important and widely used utility found in Solaris is prstat (see prstat(1)). prstat gives fast answers to question:

• How much is my system utilized in terms of CPU and memory?

• Which processes (or users, zones, projects, tasks) are utilizing my system?

• How are processes/threads using my system (user bound, I/O bound)?

In its simplest form, the command prstat <interval> (i.e. prstat 2) will examine all processes and report statistics sorted by CPU usage.

prstat – prstat 2 command reporting on all processes and sorting by CPU usage

As can be seen from the screen capture, processes are ordered from top (highest) to bottom (lowest) according to their current CPU usage (in % - 100% means all system CPUs are fully utilized). For each process in the list, following information is printed:

• PID: the process ID of the process.

• USERNAME: the real user (login) name or real user ID.

• SIZE: the total virtual memory size of the process, including all mapped files and devices, in kilobytes (K), megabytes (M), or gigabytes (G).

• RSS: the resident set size of the process (RSS), in kilobytes (K), megabytes (M), or gigabytes (G).

• STATE: the state of the process (cpuN/sleep/wait/run/zombie/stop).

• PRI: the priority of the process. Larger numbers mean higher priority.

• NICE: nice value used in priority computation. Only processes in certain scheduling classes have a nice value.

• TIME: the cumulative execution time for the process.

• CPU: The percentage of recent CPU time used by the process. If executing in a non-global zone and the pools facility is active, the percentage will be that of the processors in the processor set in use by the pool to which the zone is bound.

• PROCESS: the name of the process (name of executed file).

• NLWP: the number of lwps in the process.

The <interval> argument given to prstat is the sampling/refresh interval in seconds.

Special Report – Sorting

The prstat output can be sorted by another criteria than CPU usage. Use the option -s (descending) or -S (ascending) with the criteria of choice (i.e. prstat -s time 2):

Criteria	Comments
cpu	Sort by process CPU usage. This is the default.
pri	Sort by process priority.
rss	Sort by resident set size.
size	Sort by size of process image.
time	Sort by process execution time.

Special report – Continuous Mode

With the option -c to prstat, new reports are printed below previous ones, instead of overprinting them. This is especially useful when gathering information to a file (i.e. prstat -c 2 > prstat.txt). The option -n <number of output lines> can be used to set the maximum length of a report.

prstat – continuous report sorted by ascending other of CPU usage

Special Report – by users

With the option -a or -t to prstat, additional reports about users are printed.

prstat – prstat -a 2 reports by user

Special Report – by Zones

With the option -Z to prstat, additional reports about zones are printed.

Special Report – by Projects (see projects(1))

With the option -J to prstat, additional reports about projects are printed.

prstat – prstat -J 2 reports about projects

Special Report – by Tasks (see newtask(1))

With the option -T to prstat, additional reports about tasks are printed.

prstat – prstat -T 2 reports by tasks

Special Report – Microstate Accounting

Unlike other operating systems that gather CPU statistics every clock tick or every fixed time interval (typically every hundredth of a second), Solaris 10 incorporates a technology called microstate accounting that uses high-resolution timestamps to measure CPU statistics for every event, thus producing extremely accurate statistics.

The microstate accounting system maintains accurate time counters for threads as well as CPUs. Thread-based microstate accounting tracks several meaningful states per thread in addition to user and system time, which include trap time, lock time, sleep time and latency time. prstat reports the per-process (option -m) or per-thread (option -mL) microstates.

prstat – prstat -m 2 reports on process microstates

The screen output shown above displays microstates for the running system. Looking at the top line with PID 693, one can see that the process Xorg spends 1.8% of its time in userland while sleeping (98%) the rest of its time. prstat – prstat -mL 2:

The screen output shown above displays per-thread microstates for the running system. Looking at the line with PID 1311 (display middle), one can see the microstates for LWP #9 and LWP #8 of the process firefox-bin.

prstat usage Scenario – cpu Latency

One important measure for CPU saturation is the latency (LAT column) output of prstat. Let's once again, start two (2) copies of our CPU intensive application.

prstat – observing latency with CPU intensive application

Now let's run prstat with microstate accounting reporting, i.e. prstat -m 2 and record the output:

prstat – prstat -m 2 output

Please observe the top two (2) lines of the output with PID 2223 and PID 2224. One can clearly see that both processes exhibit a high percentage of their time (50% and 52% respectively) in LAT microstate (CPU latency). The remaining time is spent in computation as expected (USR microstate). Clearly in this example, both CPU bound applications are fighting for the one CPU of the test system, resulting in high waiting times (latency) to gain access to a CPU.

prstat usage Scenario – High System Time

Let's run a system call intensive applicationand watch the output of prstat. First, start one instance of cc_sys:

prstat – system call intensive application

Then watch the prstat -m 2 output:

prstat – prstat -m 2 output for system call intensive application

Note the top line of the above output with PID 2310. One clearly identifies a high-system time usage (61%) for the process cc_sys. Also notice the high ratio of ICX/VCX (277/22) which shows that the process is frequently involuntarily context switched off the CPU.

prstat usage Scenario – Excessive Locking

Frequently, poor scaling is observed for applications on multi-processor systems. One possible root cause is badly designed locking inside the application resulting in large time spent waiting for synchronisation. The prstat column LCK reports on percentage of time spent waiting on user locks.

Let's look at an example with a sample program that implements a locking mechanism for a critical section using reader/writer locks. The programs has four (4) threads looking for access to the shared critical region as readers while one thread accesses the critical section in writer mode. To exhibit the problem, the writer has been slowed down on purpose, so that it spends some time holding the critical section (effectively barring access for the readers).

First start the program such as the writer spends zero (0) microseconds in the critical region (ideal case).

cc_lck 0 – running in ideal conditions

Now let's observe the per-thread microstates. Use prstat -mL -p 2626 2 for this.

cc_lck 0 – prstat output

One can observe, that all threads (5) are fighting almost equally for computing resources. Since nor the reader nor the writer hold the critical section for long there is no wait time registered.

Now let's restart, the whole test with a writer wait time of ten (10) microseconds.

Again, let's observe the microstates. Use prstat -mL -p 2656 2 for this.

cc_lck 10 – prstat output

Now the picture looks different. The four (4) reader threads are spending 84% of their time waiting on the lock for the critical region. The writer (LWP #1) on the other hand, is spending most of its time sleeping (82%).

While in the case of this sample application, the locking problems are obvious when looking at the source code, prstat microstate accounting capabilities can help pin-point locking weaknesses in larger applications.

Thomas Bastian was a coauthor of an earlier version of this document. The earlier version of this page has been published in the "The Developers Edge" in 2009.