Performance Analysis Tools

Table of Contents

1. Scope and Motivation
2. Performance Considerations and Strategies
3. Timers
   1. time
   2. timex
   3. MPI Timing Routines
   4. gettimeofday()
   5. read_real_time()
   6. IBM Fortran Routines
      1. rtc()
      2. irtc()
      3. dtime_()
      4. etime_()
      5. mclock()
      6. timef()
   7. AIX Trace Facility
4. AIX System Commands
   1. Hardware Configuration Commands
      1. lscfg
      2. lsdev
      3. lsattr
      4. lsps
      5. qcpu
   2. vmstat
   3. netstat
   4. iostat
   5. ps
5. Profilers
   1. prof
   2. gprof
   3. tprof
   4. monitor
   5. xprofiler
   6. mpiP
6. Performance Analysis Tools
   1. HPM Toolkit
   2. PE Benchmarker Toolset
   3. VampirGuideView (VGV)
   4. Paraver and Dimemas
   5. Performance Toolbox
   6. Dynamic Probe Class Library (DPCL)
   7. Other Multi-Platform Parallel Performance Analysis Tools
7. Miscellaneous Tools
8. References and More Information
9. Exercise

Scope of This Tutorial:

• A variety of profiling and execution analysis tools exist for both serial and parallel programs. They range widely in usefulness and complexity:
  • Simple command line timing utilities
  • Fortran and C timing routines
  • Profilers
  • Execution trace generators
  • Graphical execution analyzers - with/without trace generation
  • Both real-time and post-execution tools

• Most of the more sophisticated and useful tools have a learning curve associated with them and would deserve a full day tutorial themselves.

• The purpose of this tutorial is to briefly review a range of performance analysis tools, and to provide pointers for more information to many of these tools.

• Although a number of the tools reviewed are cross-platform, the emphasis of this tutorial is their usage on the IBM SP platform.

• Writing large-scale parallel and distributed scientific applications that make optimum use of computational resources is a challenging problem. Very often, resources are under-utilized or used inefficiently.

• The factors which determine a program's performance are complex, interrelated, and oftentimes, hidden from the programmer. Some of them are listed by category below.

  Application Related Factors:

  • Algorithms
  • Dataset Sizes
  • Memory Usage Patterns
  • Use of I/O
  • Communication Patterns
  • Task Granularity
  • Load Balancing
  • Amdahl's Law

  Hardware Related Factors:

  • Processor Architecture
  • Memory Hierarchy
  • I/O Configuration
  • Network

  Software Related Factors:

  • Operating system
  • Compiler
  • Preprocessor
  • Communication protocols
  • Libraries

• Because of these challenges and complexities, performance analysis tools are essential to optimizing an application's performance. They can assist you in understanding what your program is "really doing" and suggest how program performance should be improved.

• The most important goal of performance tuning is to reduce a program's wall clock execution time. Reducing resource usage in other areas, such as memory or disk requirements, may also be a tuning goal.

• Performance tuning is an iterative process used to optimize the efficiency of a program. It usually involves finding your program's hot spots and eliminating the bottlenecks in them.

  • Hot Spot: An area of code within the program that uses a disproportionately high amount of processor time.

  • Bottleneck: An area of code within the program that uses processor resources inefficiently and therefore causes unnecessary delays.

• Performance tuning usually involves profiling - using software tools to measure a program's run-time characteristics and resource utilization.

• Use profiling tools and techniques to learn which areas of your code offer the greatest potential performance increase BEFORE you start the tuning process. Then, target the most time consuming and frequently executed portions of a program for optimization.

• Consider optimizing your underlying algorithm: an extremely fine-tuned O(N * N) sorting algorithm may perform significantly worse than a untuned O(N log N) algorithm.

• For data dependent computations, benchmark based on a variety of realistic (both size and values) input data sets. Maintain consistent input data during the fine-tuning process.

• Take advantage of compiler and preprocessor optimizations when possible.

• Finally, know when to stop - there are diminishing returns in successive optimizations. Consider a program with the following breakdown of execution time percentages for the associated parts of the program:

  Procedure	% CPU Time
  main() procedure1() procedure2() procedure3()	13% 17% 20% 50%

  A 20% increase in the performance of procedure3() results in a 10% performance increase overall.

  A 20% increase in the performance of main() results in only a 2.6% performance increase overall.

• A wide variety of timers are available on the IBM SP platform. The table below compares a number of these. A detailed description for each follows.

  Timer	Usage	Wallclock / CPU Time	Resolution	Languages	Portable?
  time	shell / script	both	1/100th second	any	yes
  timex	shell / script	both	1/100th second	any	yes
  gettimeofday	subroutine	wallclock	microsecond	C/C++	yes
  read_real_time	subroutine	wallclock	nanosecond	C/C++	no
  rtc	subroutine	wallclock	microsecond	Fortran	no
  irtc	subroutine	wallclock	nanosecond	Fortran	no
  dtime_	subroutine	CPU	1/100th second	Fortran	no
  etime_	subroutine	CPU	1/100th second	Fortran	no
  mclock	subroutine	CPU	1/100th second	Fortran	no
  timef	subroutine	wallclock	millisecond	Fortran	no
  MPI_Wtime	subroutine	wallclock	microsecond	C/C++, Fortran	yes
  AIX Trace Facility	shell / script / subroutine	wallclock	microsecond	any	no

time

• The time command returns the total execution time of your program.

• The format of the output is different for the Korn shell and the C shell. The basic information is :
  • Real time: the total wall clock (start to finish) time your program took to load, execute, and exit.
  • User time: the total amount of CPU time your program took to execute.
  • System time: the amount of CPU time spent on operating system calls in executing your program.

• The system and user times are defined differently across different computer architectures.

• Example csh time output:

  1 2 3 4 5 6 7 8 1.150u 0.020s 0:01.76 66.4% 15+3981k 24+10io 0pf+0w

  Explanation:

  1. 1.15 seconds of user CPU time
  2. 0.02 seconds of system (kernel) time used on behalf of user
  3. 1.76 seconds real time (wall clock time)
  4. 66.4% total CPU time (user+system) during execution as a percentage of elapsed time.
  5. 15 Kbytes of shared memory usage and 3981 Kbytes of unshared data space
  6. 24 block input operations and 10 block output operations
  7. no page faults
  8. no swaps

• Example ksh time output:

  
      real    0m2.58s
      user    0m1.14s
      sys     0m0.03s
  

  Explanation:
  • 0 minutes, 2.58 seconds of wall clock time
  • 0 minutes, 1.14 seconds of user CPU time
  • 0 minutes, 0.03 seconds of system CPU time

• See the time man page for details.

timex

• Without options, the timex command provides the same type of information as the ksh version of the time command.

• timex reports its information in a common format across a variety of shells.

• The -s option causes the timex command to display a wide variety of additional system related information, including:
  • I/O statistics
  • caching effectiveness
  • system calls
  • kernel process activity
  • message and semaphore activity
  • queue statistics
  • paging statistics
  • system unit activity
  • system switching activity
  • tty device activity

• See the timex man page for details.

Note that much of the timex command's output is NOT described in the timex man page. Some of it may be understood from reading the sar command man page.

MPI Timing Routines

• MPI includes a built in timing routine, called MPI_Wtime, which returns the elapsed wall clock time in seconds (double precision) on the calling processor.

• MPI also includes a routine, called MPI_Wtick, which returns the resolution in seconds (double precision) of MPI_Wtime. Resolution on IBM SP systems varies by model but is microsecond level or better.

  Example Codes (C and Fortran) #include "mpi.h" int main(argc,argv) int argc; char *argv[]; { int n=0,m; double start,end,resolution; MPI_Init(&argc,&argv); start = MPI_Wtime(); /* start time */ for (m=0;m<2000000;m++) n = n + m; end = MPI_Wtime(); /* end time */ resolution = MPI_Wtick(); printf("Wallclock times(secs): start= %f end= %f \n",start,end); printf("elapsed= %e resolution= %e\n", end-start,resolution); MPI_Finalize (); } program wtime_test include 'mpif.h' integer n,m,ierr double precision start,end,resolution call MPI_INIT(ierr) start = MPI_WTIME() do m=1,2000000 n = n + m end do end = MPI_WTIME() resolution = MPI_WTICK() print *,'Wallclock times(secs): start= ',start,'end=',end print *,'elapsed=',end-start,'resolution=',resolution call MPI_FINALIZE (ierr) end

gettimeofday()

• The gettimeofday() routine is part of the Standard C Library (libc.a) on most Unix systems. It returns the time in seconds and microseconds since midnight, January 1, 1970.

• Can be inserted anywhere within a C program and used to determine the start and end times of code fragments.

• Fortran programs must perform an interlanguage call in order to use the gettimeofday function.

• Timer resolution is hardware dependent. Microsecond resolution on the IBM SP systems.

• See the gettimeofday man page for details.

  Example Code Fragment #include <stdio.h> #include <sys/time.h> #include <time.h> struct timeval start_time, end_time; main() { int total_usecs; gettimeofday(&start_time, (struct timeval*)0); /* do some work */ gettimeofday(&end_time, (struct timeval*)0); total_usecs = (end_time.tv_sec-start_time.tv_sec) * 1000000 + (end_time.tv_usec-start_time.tv_usec); printf("Total time was %d uSec.\n", total_usecs); } C example Fortran example

read_real_time()
time_base_to_time()

• Both of these routines are part of the Standard C Library (libc.a) on IBM AIX systems.

• Designed to be used for making high-resolution measurement of elapsed time, using the processor real time clock or time base registers.

• Nanosecond resolution on the IBM SP.

• The time_base_to_time() routine is used to guarantee correct time units across different IBM RS/6000 architectures.

• See the read_real_time() man page for details.

  Example Code #include <stdio.h> #include <sys/time.h> int main(void) { timebasestruct_t start, finish; int secs, n_secs; read_real_time(&start, TIMEBASE_SZ); /* do some work */ read_real_time(&finish, TIMEBASE_SZ); /* Make sure both values are in seconds and nanoseconds */ time_base_to_time(&start, TIMEBASE_SZ); time_base_to_time(&finish, TIMEBASE_SZ); /* Subtract the starting time from the ending time */ secs = finish.tb_high - start.tb_high; n_secs = finish.tb_low - start.tb_low; /* Fix carry from low-order to high-order during the measurement */ if (n_secs < 0) { secs--; n_secs += 1000000000; } (void) printf("Sample time was %d seconds %d nanoseconds\n", secs, n_secs); exit(0); }

xlf Fortran Timing Routines

rtc()

• The rtc (real time clock) function returns a REAL(8) value of the number of seconds since the initial value of the machine's real-time clock.

• rtc is easy to use and has excellent (microsecond) resolution.

  Example Code PROGRAM RTC_TIME REAL(8) A, B, rtc A = rtc() DO M = 1,2000000 N = N + M END DO B = rtc() PRINT *, 'Seconds elapsed: ',B - A END

irtc()

• The irtc function returns a INTEGER(8) value of the number of nanoseconds since the initial value of the machine's real-time clock. Similar to the rtc function in other respects.

  Example Code PROGRAM IRTC_TIME INTEGER(8) A, B, irtc A = irtc() DO M = 1,2000000 N = N + M END DO B = irtc() PRINT *, 'Nanoseconds elapsed: ',B - A END

dtime_()

• The dtime_ function may used to obtain the user and system elapsed CPU times since the last call to dtime_.

• In the example below, dtime_ sets the user and system elapsed time in the variable DTIME_STRUCT of derived type TB_TYPE. The returned value, DELTA, is the sum of the user elapsed time and the system elapsed time since the last call to dtime_.

• The resolution for all timing is 1/100 of a second.

  Example Code PROGRAM DTIME_TIME REAL(4) DELTA, dtime_ TYPE TB_TYPE SEQUENCE REAL(4) USRTIME REAL(4) SYSTIME END TYPE TYPE (TB_TYPE) DTIME_STRUCT DELTA = dtime_(DTIME_STRUCT) DO M = 1,2000000 N = N + M END DO DELTA = dtime_(DTIME_STRUCT) PRINT *, 'User time: ',DTIME_STRUCT%USRTIME, 'seconds' PRINT *, 'System time: ',DTIME_STRUCT%SYSTIME, 'seconds' PRINT *, 'Elapsed time: ',DELTA, 'seconds' END

etime_()

• The etime_ function may be used to obtain the user and system elapsed CPU times since the start of the execution of a process.

• In the example below, etime_ sets the user and system elapsed time in the variable ETIME_STRUCT of derived type TB_TYPE. The returned value, ELAPSED, is the sum of the user elapsed time and the system elapsed time.

• The resolution for all timing is 1/100 of a second.

  Example Code PROGRAM ETIME_TIME REAL(4) ELAPSED, etime_ TYPE TB_TYPE SEQUENCE REAL(4) USRTIME REAL(4) SYSTIME END TYPE TYPE (TB_TYPE) ETIME_STRUCT DO M = 1,2000000 N = N + M END DO ELAPSED = etime_(ETIME_STRUCT) PRINT *, 'User time: ',ETIME_STRUCT%USRTIME, 'seconds' PRINT *, 'System time: ',ETIME_STRUCT%SYSTIME, 'seconds' PRINT *, 'Elapsed time: ',ELAPSED, 'seconds' END

mclock()

• The mclock function returns timing information about the current process and its child processes. The returned value is the sum of the current process's user time and the user and system time of all child processes.

• The unit of measure is one one-hundredth (1/100) of a second.

  Example Code PROGRAM MCLOCK_TIME INTEGER(4) T1, T2, mclock REAL(4) SECONDS T1 = mclock() DO M = 1,2000000 N = N + M END DO T2 = mclock() SECONDS = REAL(T2 - T1) / 100 PRINT *, 'Elapsed CPU time: ',SECONDS,'seconds' END

timef()

• The timef function returns the elapsed time in milliseconds since the first instance timef was called.

• The first instance when timef is called, the value 0.0d0 is returned.

  Example Code PROGRAM TIMEF_TIME REAL(8) ELAPSED, timef ELAPSED = timef() DO M = 1,2000000 N = N + M END DO ELAPSED = timef() PRINT *, 'Elapsed time: ',ELAPSED,'milliseconds' END

AIX Trace Facility

• AIX's built in Trace Facility provides the ability to timestamp many different system events.

• It can be used at both the command line level and subroutine level.

• Using the Trace Facility to collect timing statistics for an event is a three step process:
  1. Determine the code numbers for the events you wish to trace by consulting the /usr/include/sys/trchkid.h file.
  2. Generate a tracefile from either the command line or from within your program.
  3. Produce a "readable" trace report from your tracefile after it has been completed.

Example:

1. Get event tags from /usr/include/sys/trchkid.h for desired events.

   Thread create=465, thread terminate=467, wait lock=46d.

2. Remove any existing tracefile (can cause problems):

   rm trcfile

3. Execute program, creating a tracefile with specified events:

   trace -a -o trcfile -j 465,467,46d; dotprod; trcstop

4. Produce a readable trace report:

   trcrpt -o trace.report -O pid=on trcfile

5. View report using your favorite editor.

   Sample AIX Trace Facilty output

   Fri Jul 19 00:02:05 2002 System: AIX frost067 Node: 5 Machine: 006008594C00 Internet Address: 86092F43 134.9.47.67 The system contains 16 cpus, of which 16 were traced. Buffering: Kernel Heap This is from a 32-bit kernel. Tracing only these hooks, 465,467,46d trace -a -o trcfile -j 465,467,46d ID PID I ELAPSED_SEC DELTA_MSEC APPL SYSCALL KERNEL INTERRUPT 001 70640 0.000000000 0.000000 TRACE ON channel 0 Fri Jul 19 00:02: 05 2002 465 -1 0.000482511 0.482511 thread_create: pid=7825 0 tid=226787 priority=60 policy=0 46D 85616 0.000495484 0.012973 wait_on_lock: pid=85616 tid=238427 lockaddr=5819F0 465 -1 0.027897260 27.401776 thread_create: pid=7731 8 tid=146769 priority=61 policy=0 467 77318 0.028225717 0.328457 thread_terminate: pid=7 7318 tid=146769 465 -1 0.028235827 0.010110 thread_create: pid=7731 8 tid=206215 priority=61 policy=0 46D -1 0.028251016 0.015189 wait_on_lock: pid=77318 tid=238429 lockaddr=5819F0 465 -1 0.028633968 0.382952 thread_create: pid=7731 8 tid=151151 priority=61 policy=0 467 77318 0.028795141 0.161173 thread_terminate: pid=7 7318 tid=206215 467 77318 0.028861449 0.066308 thread_terminate: pid=7 7318 tid=151151 465 -1 0.028876390 0.014941 thread_create: pid=7731 8 tid=233391 priority=61 policy=0 46D -1 0.028886636 0.010246 wait_on_lock: pid=77318 tid=238429 lockaddr=5819F0 467 77318 0.029303598 0.416962 thread_terminate: pid=7 7318 tid=233391 002 -1 0.055766970 26.463372 TRACE OFF channel 0000 Fri Jul 19 00:02:05 2002

• Further information is available from the following IBM references:
  • Performance Tuning Guide (IBM SC23-2365-04)
  • General Programming Concepts (IBM SC23-2533-03)
  • AIX Performance Tuning, Frank Waters (ISBN 0133867072)

Hardware Configuration Commands

lscfg

• Lists overall hardware / device configuration, including memory cards, disks, peripherals and communications adapters.

  Sample output

  % lscfg INSTALLED RESOURCE LIST The following resources are installed on the machine. +/- = Added or deleted from Resource List. * = Diagnostic support not available. Model Architecture: chrp Model Implementation: Multiple Processor, PCI bus + sys0 00-00 System Object + sysplanar0 00-00 System Planar + mem0 00-00 Memory + proc0 00-00 Processor + L2cache0 00-00 L2 Cache * pmc0 00-00 Power Management Controller + proc1 00-01 Processor + proc2 00-02 Processor + proc3 00-03 Processor + proc4 00-04 Processor + proc5 00-05 Processor + proc6 00-06 Processor + proc7 00-07 Processor + proc8 00-08 Processor + proc9 00-09 Processor + proc10 00-10 Processor + proc11 00-11 Processor + proc12 00-12 Processor + proc13 00-13 Processor + proc14 00-14 Processor + proc15 00-15 Processor * pci0 00-c8000000 PCI Bus * isa0 10-58 ISA Bus + fda0 01-D1 Standard I/O Diskette Adapter + sa0 01-S1 Standard I/O Serial Port + tty0 01-S1-00-00 Asynchronous Terminal + sa1 01-S2 Standard I/O Serial Port + tty1 01-S2-00-00 Asynchronous Terminal + sa2 01-S3 Standard I/O Serial Port + tty2 01-S3-00-00 Asynchronous Terminal + scsi0 10-60 Wide/Fast-20 SCSI I/O Controller + hdisk0 10-60-00-0,0 Other SCSI Disk Drive + hdisk1 10-60-00-1,0 Other SCSI Disk Drive + ent0 10-68 IBM 10/100 Mbps Ethernet PCI Adapter (23100020) * pci1 00-c8100000 PCI Bus * pci2 00-d8000000 PCI Bus * pci3 00-d8100000 PCI Bus + ent1 J0-58 Gigabit Ethernet-SX PCI Adapter (14100401) * pci4 00-d8200000 PCI Bus * pci5 00-d8300000 PCI Bus + ent2 L0-58 Gigabit Ethernet-SX PCI Adapter (14100401) * pci6 00-d8400000 PCI Bus * pci7 00-d8500000 PCI Bus + ent3 N0-58 Gigabit Ethernet-SX PCI Adapter (14100401) * pci8 00-d8600000 PCI Bus * pci9 00-d8700000 PCI Bus + ent4 Q0-58 Gigabit Ethernet-SX PCI Adapter (14100401) * pci10 00-d8800000 PCI Bus * pci11 00-d8900000 PCI Bus + ent5 S0-58 Gigabit Ethernet-SX PCI Adapter (14100401) * pci12 00-d8a00000 PCI Bus * pci13 00-d8b00000 PCI Bus + ent6 U0-58 Gigabit Ethernet-SX PCI Adapter (14100401) + css0 00-e0000000 SP Switch2 Communications Adapter + css1 00-e8000000 SP Switch2 Communications Adapter

lsdev -C

• Lists overall hardware / device configuration. Output resembles that of the lscfg command.

lsattr

• Lists device attributes. This is probably the most useful hardware configuration command, as it shows the most detail.

  Sample output

  % lsattr -EH -l sys0 lsattr -EH -l sys0 attribute value description use r_settable keylock normal State of system keylock at boot time Fal se maxbuf 20 Maximum number of pages in block I/O BUFFER CACHE Tru e maxmbuf 0 Maximum Kbytes of real memory allowed for MBUFS Tru e maxuproc 256 Maximum number of PROCESSES allowed per user Tru e autorestart false Automatically REBOOT system after a crash Tru e iostat false Continuously maintain DISK I/O history Tru e realmem 16777216 Amount of usable physical memory in Kbytes Fal se conslogin enable System Console Login Fal se fwversion IBM,NI01261 Firmware version and revision levels Fal se maxpout 0 HIGH water mark for pending write I/Os per file Tru e minpout 0 LOW water mark for pending write I/Os per file Tru e fullcore true Enable full CORE dump Tru e pre430core false Use pre-430 style CORE dump Tru e ncargs 6 ARG/ENV list size in 4K byte blocks Tru e rtasversion 1 Open Firmware RTAS version Fal se modelname IBM,9076-N81 Machine name Fal se systemid IBM,011600859 Hardware system identifier Fal se boottype disk N/A Fal se SW_dist_intr false Enable SW distribution of interrupts Tru e cpuguard disable CPU Guard Tru e frequency 125000000 System Bus Frequency Fal se % lsattr -EH -l mem0 attribute value description user_settable size 16384 Total amount of physical memory in Mbytes False goodsize 16384 Amount of usable physical memory in Mbytes False % lsattr -EH -l L2cache0 attribute value description user_settable size 8192 Size of L2 cache in Kbytes False % lsattr -EH -l css0 attribute value description user_settable adapter_memory 0xe0000000 adapter memory address False rambus_memory 0x10c0000000 RAMBUS memory address False win_poolsize 134217728 Total window memory pool size True win_maxsize 16777216 Maximum window memory size True win_minsize 1048576 Minimum window memory size True int_priority 3 Interrupt priority False int_level 224 Bus interrupt level False spoolsize 33554432 Size of IP send buffer True rpoolsize 33554432 Size of IP receive buffer True khal_spoolsize 524288 Size of KHAL send buffer True khal_rpoolsize 524288 Size of KHAL receive buffer True adapter_status css_ready Configuration status False diags_prog /usr/sbin/diag Diagnostic program True ucode_version 3 Micro code version True ucode_name /etc/microcode/col_ucode Micro code name True window VSD AVAIL AVAIL AVAIL AVAIL AVAIL AVAIL AVAIL AVAIL AVAIL AVAIL A VAIL AVAIL AVAIL AVAIL AVAIL AVAIL window owners True driver_debug 0 Device Driver Debug True ip_chksum off if_cl checksum True ip_debug 0 if_cl debug level True proto_debug off proto debug True

lsps -a

• Lists all paging space partitions and usage.

  Sample output

  % lsps -a Page Space Physical Volume Volume Group Size %Used Active Auto Type paging00 hdisk1 rootvg 12032MB 1 yes yes lv hd6 hdisk0 rootvg 12032MB 1 yes yes lv

qcpu

• Not an AIX command, but rather a public domain C program which provides information about an IBM SP's cpus and caches. Clock speed is an approximation and the utility needs updated for the POWER4 architecture.

  Sample output

  % qcpu number of cpus: 16 processor class: POWER_630 L1 Inst Cache Size in KB: 32 L1 Data Cache Size in KB: 64 L1 Data Cache Line Sz (B): 128 L2 Cache Size in KB: 8192 data TLB: Size = 256, associativity = 2 instruction TLB: Size = 128, associativity = 2 apparent freq = 373.9 MHz

vmstat - Virtual Memory Statistics

• Displays virtual memory statistics. Syntax:

       vmstat [options] n [m] 

  n = interval in seconds
  m = count (optional) - number of interval lines to print

• First line of output represents statistics since system initialization. Subsequent lines are statistics collected during the specified interval period.

• See the vmstat man page for additional details.

  Sample output

  % vmstat 2 3 kthr memory page faults cpu ----- ----------- ------------------------ ------------ ----------- r b avm fre re pi po fr sr cy in sy cs us sy id wa 2 1 504038 3489832 0 0 0 0 0 0 2760 8705 1730 4 3 92 0 1 0 503080 3490975 0 0 0 0 0 0 5676 8619 4277 0 15 85 0 0 0 503073 3490982 0 0 0 0 0 0 1937 2707 232 0 0 99 0 * 1 page = 4096 bytes

• Legend:

  r = kernel threads placed on the run queue b = kernel threads blocked avm = active virtual memory pages fre = free memory pages re= pager input/output list pi = page-ins from paging space

  po = page-outs to paging space fr = pages freed sr = pages scanned cy = scan cycles in = device interrupts sy = system calls

  cs = context switches us = % user cpu utilization sy = % system cpu utilization id = % cpu idle time wa = % cpu time waiting on I/O

netstat - Network Statistics

• Displays network statistics. Numerous options and outputs. Syntax

       netstat [options] n 

  n = interval in seconds

• First line of output shows summary statistics since system initialization Subsequent lines are statistics collected during the specified interval period.

• See the netstat man page for details.

  Sample output

  % netstat -i - shows state of all configured interfaces Name Mtu Network Address Ipkts Ierrs Opkts Oerrs Coll en0 1500 link#2 0.4.ac.ec.11.e 319849 0 2787430 0 0 en0 1500 134.9.46 efrost067 319849 0 2787430 0 0 en1 1500 link#3 0.4.ac.7c.d6.3a 60416480 0 119342413 0 0 en1 1500 134.9.45 frost067-ge0.llnl 60416480 0 119342413 0 0 en2 1500 link#4 0.4.ac.7c.d3.1d 111043029 0 131259660 3 0 en2 1500 134.9.6 frost067-ge1.llnl 111043029 0 131259660 3 0 en3 9000 link#5 0.4.ac.7c.d6.43 12557524 0 14013408 0 0 en3 9000 134.9.60 frost067-ge2.llnl 12557524 0 14013408 0 0 en4 9000 link#6 0.4.ac.7c.d5.37 12555933 0 13775758 0 0 en4 9000 134.9.61 frost067-ge3.llnl 12555933 0 13775758 0 0 en5 9000 link#7 0.4.ac.7c.d5.36 12711192 0 13896158 0 0 en5 9000 134.9.62 frost067-ge4.llnl 12711192 0 13896158 0 0 en6 9000 link#8 0.4.ac.7c.d5.21 12408381 0 12936330 0 0 en6 9000 134.9.63 frost067-ge5.llnl 12408381 0 12936330 0 0 css0 65504 link#9 20162383 0 47045300 0 0 css0 65504 134.9.48 frost067-css0 20162383 0 47045300 0 0 css1 65504 link#10 20155508 0 47041708 0 0 css1 65504 134.9.49 frost067-css1 20155508 0 47041708 0 0 ml0 65504 link#11 0 0 75604311 4367 0 ml0 65504 134.9.47 frost067 0 0 75604311 4367 0 ml0 65504 134.9.47 frostgw 0 0 75604311 4367 0 lo0 16896 link#1 1902914 0 1903901 0 0 lo0 16896 127 localhost 1902914 0 1903901 0 0 lo0 16896 ::1 1902914 0 1903901 0 0 % netstat -Icss0 2 - monitor IP traffic over High-Performance Switch input (css0) output input (Total) output packets errs packets errs colls packets errs packets errs colls 20167216 0 47050260 0 0 264249001 0 479647008 4370 0 110 0 110 0 0 275 0 366 0 0 167 0 164 0 0 344 0 337 0 0 171 0 167 0 0 348 0 339 0 0 82 0 81 0 0 179 0 198 0 0 181 0 186 0 0 734 0 1212 0 0 168 0 168 0 0 595 0 510 0 0 111 0 112 0 0 315 0 523 0 0 211 0 216 0 0 535 0 648 0 0

iostat - I/O Statistics

• Displays I/O (disk activity) statistics. Syntax:

       iostat [options] n [m] 

  n = interval in seconds
  m = count (optional)

• First line of output displays statistics since system initialization. Subsequent lines are statistics collected during the specified interval period.

• See the iostat man page for details and interpretation of output columns.

  Sample output

  % iostat 10 3 tty: tin tout avg-cpu: % user % sys % idle % iowait 1.9 569.4 4.1 3.4 92.2 0.3 Disks: % tm_act Kbps tps Kb_read Kb_wrtn hdisk0 1.2 79.3 6.2 497100 9818957 hdisk1 0.4 56.7 1.8 48840 7328280 tty: tin tout avg-cpu: % user % sys % idle % iowait 0.3 1183.6 0.4 0.2 99.3 0.0 Disks: % tm_act Kbps tps Kb_read Kb_wrtn hdisk0 0.0 1.6 0.1 0 16 hdisk1 0.0 1.6 0.1 0 16 tty: tin tout avg-cpu: % user % sys % idle % iowait 0.1 418.2 0.1 0.7 99.2 0.0 Disks: % tm_act Kbps tps Kb_read Kb_wrtn hdisk0 3.9 67.7 13.0 0 677 hdisk1 0.2 10.4 1.5 0 104

ps - Process Status

• Shows current status of processes. Many options and outputs.

• Provides a quick and easy way to view overall memory and cpu usage by any/all processes on the system.

• See the ps man page for details.

  Sample output

  % ps ux USER PID %CPU %MEM SZ RSS TTY STAT STIME TIME COMMAND userjoe 41728 62.9 0.0 352 396 pts/15 A 18:39:14 5:02 a.out userjoe 41728 22.3 33.0 412 478 pts/15 A 18:39:14 5:02 b.out userjoe 41502 0.0 0.0 696 828 pts/15 A 17:25:27 0:03 -tcsh userjoe 13334 0.0 0.0 200 252 pts/15 A 18:40:14 0:00 ps ux

prof

• The prof utility is included in most Unix systems. It is used to profile program execution at the procedure level.

• IBM has enabled the mpcc and mpxlf compiler commands to use prof for parallel programs.

• prof displays the following information:
  • The name of each procedure - in descending order of processing activity
  • The percentage of the program's CPU time used by each procedure.
  • The execution time in seconds for all references by each procedure.
  • The number of times the procedure was called.
  • The average time in milliseconds for a call to each procedure.

  Sample prof output (abbreviated)

  Name %Time Seconds Cumsecs #Calls msec/call .fft 51.8 0.59 0.59 1024 0.576 .main 40.4 0.46 1.05 1 460. .bit_reverse 7.9 0.09 1.14 1024 0.088 .cos 0.0 0.00 1.14 256 0.00 .sin 0.0 0.00 1.14 256 0.00 .catopen 0.0 0.00 1.14 1 0. .setlocale 0.0 0.00 1.14 1 0. ._doprnt 0.0 0.00 1.14 7 0. ._flsbuf 0.0 0.00 1.14 11 0.0 ._xflsbuf 0.0 0.00 1.14 7 0. ._wrtchk 0.0 0.00 1.14 1 0. ._findbuf 0.0 0.00 1.14 1 0. ._xwrite 0.0 0.00 1.14 7 0. .free 0.0 0.00 1.14 2 0. .free_y 0.0 0.00 1.14 2 0. .write 0.0 0.00 1.14 7 0. .exit 0.0 0.00 1.14 1 0. .memchr 0.0 0.00 1.14 19 0.0 .atoi 0.0 0.00 1.14 1 0. .__nl_langinfo_std 0.0 0.00 1.14 4 0. .gettimeofday 0.0 0.00 1.14 8 0. .printf 0.0 0.00 1.14 7 0.

• How to use prof

  1. Compile your program with the -p option

  2. Run the program. When it completes you should have a file called mon.out which contains runtime statistics. If you are running a parallel program (compiled with mpcc or mpxlf) you will have multiple files differentiated by the taskid which created them, such as mon.out.0 mon.out.1 mon.out.2, etc.

  3. For serial users, view the profile statistics with prof by typing prof at the shell prompt in the same directory that you ran the program. By default, prof will look for a file called mon.out and display the statistics contained in it.

  4. For parallel users, run prof with the -m option followed by the names of the mon.out.X files you wish to view. You may view any single file or any combination. Examples:

     
         prof -m mon.out.0
         prof -m mon.out.0 mon.out.1 mon.out.2
         prof -m mon.out.*
         

  Note: If you view more than one mon.out file at a time, the results are averaged into a single report.

• See the prof man page for details. Also see the additional notes about prof and gprof in the gprof discussion (next section).

gprof

• The gprof utility is included in most Unix systems. Like prof, it is used to profile program execution at the procedure level. Unlike prof, it profiles procedures according to their call graphs.

• IBM has enabled the mpcc and mpxlf compiler commands to use gprof for parallel programs.

• gprof displays the following information:
  • The parent of each procedure.
  • An index number for each procedure.
  • The percentage of CPU time taken by that procedure and all procedures it calls (the calling tree).
  • A breakdown of time used by the procedure and its descendents.
  • The number of times the procedure was called.
  • The direct descendents of each procedure.

  Sample gprof output

• How to use gprof

  1. Compile your program with the -pg option. If your compilation includes the -c option (to produce a *.o file), then you will need to include the -pg during the link/load also.

  2. Run the program. When it completes you should have a file called gmon.out which contains runtime statistics. If you are running a parallel program (compiled with mpcc or mpxlf) you will have multiple files differentiated by the taskid which created them, such as gmon.out.0 gmon.out.1 gmon.out.2, etc.

  3. For serial users, view the profile statistics with gprof by typing gprof at the shell prompt in the same directory that you ran the program. By default, gprof will look for a file called gmon.out and display the statistics contained in it.

  4. For parallel users, view the profile statistics with gprof by typing gprof followed by the name of your executable and the gmon.out.X files you wish to view. You may view any single file or any combination. Examples:

     
         gprof myprog gmon.out.0
         gprof myprog gmon.out.0 gmon.out.1 gmon.out.2
         gprof myprog gmon.out.*
             

  Note: If you view more than one gmon.out file at a time, the results are summed into a single report.

• See the gprof man page for details.

Additional Notes About prof and gprof:

• Primary difference between prof and gprof timings:
  • For prof, CPU time assigned to each procedure does not include CPU time used by procedures further down the calling tree.
  • For gprof, CPU time assigned to each procedure includes CPU time used by procedures further down the calling tree. Thus gprof should be used for programs which make calls to library procedures.

• All procedures called by the object code, including many not listed in your source program, are profiled.

• Statistics are created by interrupting your program at periodic intervals and equating the interrupt address with a procedure. It is possible for phase problems to occur and cause disproportionately high, or low, execution times to be reported.

• prof and gprof show CPU time, not real time. Disk delays due to input and output are not included.

• The cumlative seconds output is based on procedure listing, not on invocation order.

tprof

• The tprof command reports CPU usage for individual programs and the system as a whole. It is useful to see what other processes are "competing" with your process while it runs - in particular, system processes.

• How to use tprof

  1. Compile your program with the -qlist and -g so that tprof can do source code instruction level profiling. For example:

     xlc_r myprog.f -o myprog

  2. Run tprof with desired options on your program. For example:

     tprof -vx myprog

• After your program has completed, tprof will have created a number of files in with names that begin with two underscore characters (i.e. "__") so that they are readily recognizable as tprof output files. For example:

  -rw-------   1 blaise   blaise        10078 Jul 20 12:06 __ldmap
  -rw-------   1 blaise   blaise         1808 Jul 20 12:06 __prof.all
  -rw-------   1 blaise   blaise            0 Jul 20 12:06 __tmp.j
  -rw-------   1 blaise   blaise         1451 Jul 20 12:06 __tmp.k
  -rw-------   1 blaise   blaise            0 Jul 20 12:06 __tmp.o
  -rw-------   1 blaise   blaise            0 Jul 20 12:06 __tmp.s
  -rw-------   1 blaise   blaise            0 Jul 20 12:06 __tmp.u
  -rw-------   1 blaise   blaise        89982 Jul 20 12:06 __trc_rpt2
  

• tprof will probably give a few error messages that can be ignored, upon completion also, such as:

  Trace is done now
  open: check_unix_file failure: Permission denied
   * Samples from __trc_rpt2
   * Reached second section of __trc_rpt2
  

• The report of interest is the __prof.all report. It is divided into two sections. The first section details the number of "ticks" (1/100th sec) for every process that was running on the system while your process was executing. The second part of the report provides a summary for each process. An example is shown below.

• See the tprof man page for details.

  Sample tprof output

  Process PID TID Total Kernel User Shared Other ======= === === ===== ====== ==== ====== ===== prime 99578 223099 1233 837 396 0 0 wait 516 517 1231 1231 0 0 0 wait 2322 2323 1216 1216 0 0 0 wait 3870 3871 1215 1215 0 0 0 wait 1548 1549 1213 1213 0 0 0 wait 3612 3613 1209 1209 0 0 0 wait 4386 4387 1208 1208 0 0 0 wait 2580 2581 1197 1197 0 0 0 [snip - big chunk of long report ommitted] /usr/sbin/entstat.phxent 76924 250719 1 1 0 0 0 /usr/sbin/entstat.phxent 76926 250721 1 1 0 0 0 /usr/sbin/entstat.gxent 76928 250723 1 1 0 0 0 /usr/sbin/entstat.gxent 76930 250725 1 1 0 0 0 /usr/sbin/entstat.gxent 66452 262251 1 1 0 0 0 /usr/sbin/entstat.gxent 66454 262253 1 1 0 0 0 /usr/sbin/entstat.gxent 66456 262255 1 1 0 0 0 /usr/sbin/entstat.gxent 66460 262259 1 1 0 0 0 uname 111540 144913 1 1 0 0 0 netstat 44478 145855 1 1 0 0 0 /bin/stty 41944 197711 1 1 0 0 0 execerror 13234 248433 1 1 0 0 0 ======= === === ===== ====== ==== ====== ===== Total 19771 19286 408 77 0 Process FREQ Total Kernel User Shared Other ======= === ===== ====== ==== ====== ===== wait 16 17738 17738 0 0 0 prime 1 1233 837 396 0 0 netperfbin/netperf.AIX 1 568 568 0 0 0 LoadL_negotiator 4 41 8 0 33 0 pspd 1 27 1 1 25 0 sh 14 23 20 1 2 0 mld 1 20 17 2 1 0 ps 2 19 10 0 9 0 expect 5 18 14 2 2 0 netmon.AIX 6 10 9 1 0 0 netstat 9 9 9 0 0 0 /usr/sbin/entstat.gxent 9 9 9 0 0 0 date 9 9 8 0 1 0 /usr/sbin/entstat 7 8 8 0 0 0 acctd 1 6 4 2 0 0 tprof 1 5 2 3 0 0 ping 2 4 2 0 2 0 sshd1 1 3 3 0 0 0 hats_nim 2 2 2 0 0 0 /usr/lpp/csd/bin/statvsd 2 2 2 0 0 0 PID.99578 1 2 1 0 1 0

monitor

• Provides a real-time display with updating on how a process (processes) are utilizing a range of machine resources.

  Sample output

  AIX Monitor v2.1.9llnl 21apr2002: frost067.pacific.llnlThu Jul 18 23:51:44 2002 Uptime: 1 days, 11:00 Users: 1 of 51 active 51 remote 501:00 sleep time CPU: User 0.3% Sys 0.1% Wait 0.0% Idle 99.6% Refresh: 10.00 s 0% 25% 50% 75% 100% Runnable (Swap-in) processes 0.10 (0.00) load average: 0.24, 0.18, 0.23 FOR NON-COMMERCIAL USE ONLY see http://www.mesa.nl/monitor Memory Real Virtual Paging (4kB) Process events File/TTY-IO free 13388 MB N/A 0.0 pgfaults 220 pswitch 0 iget procs 1958 MB N/A 0.0 pgin 1237 syscall 8 namei files 1035 MB 0.0 pgout 48 read 0 dirblk total 16383 MB N/A 0.0 pgsin 21 write 13519 readch IO (kB/s) read write busy% 0.0 pgsout 0 fork 6787 writech hdisk0 0.0 0.0 0 0 exec 0 ttyrawch hdisk1 0.0 0.0 0 Client Server NFS/s 0 rcvint 0 ttycanch 0.5 0.0 calls 0 xmtint 26 ttyoutch 0.0 0.0 retry 0 mdmint 0.0 0.0 getattr MESA Consulting 0.0 0.0 lookup Netw read write kB/s Unix and Internet 0.0 0.0 read en0 0.2 0.1 Technology Specialists 0.0 0.0 write en1 1.4 1.7 http://www.mesa.nl 0.0 0.0 other en2 0.1 0.7 en3 0.0 0.0 en4 0.0 0.0 en5 0.0 0.0 en6 0.0 0.0 css0 7.0 12.9 css1 5.6 7.7 ml0 0.0 7.7 lo0 0.0 0.0

• Useful options include -top, which shows the top cpu processes, and -smp, which shows SMP cpu information. Example output for the -smp version is shown below.

• See the monitor man page for details.

  Sample output for monitor command with -smp option

  Load averages: 0.22, 0.17, 0.21 frost067.pacific.llnThu Jul 18 23:56:06 2002 Cpu states: 4.0% user 3.3% system 0.0% wait 92.7% idle For non-commercial Logged on: 52 users 2 active 52 remote 495:01 sleep time use only! Real memory: 1966.6M procs 1024.3M files 13392.8M free 16383.6M total Virtual memory: N/A used N/A free N/A total CPU USER KERN WAIT IDLE% PSW SYSCALL WRITE READ WRITEkb READkb #0 2 2 0 94 47 367 65 48 92.97 106.72 #1 1 2 0 96 37 290 14 49 2.26 41.24 #2 3 3 0 92 56 3827 20 83 43.87 224.47 #3 4 2 0 93 22 709 6 158 2.00 198.02 #4 4 2 0 92 42 481 42 58 126.00 173.23 #5 5 4 0 89 38 7159 47 105 50.89 346.71 #6 1 2 0 96 47 767 1 157 0.89 211.42 #7 1 4 0 93 48 895 4 66 2.90 173.56 #8 12 3 0 83 27 836 12 215 2.69 590.16 #9 3 3 0 93 61 957 56 65 52.87 165.28 #10 6 3 0 90 52 602 5 129 2.53 357.57 #11 3 4 0 92 35 3737 20 63 44.11 192.94 #12 3 1 0 95 50 307 98 51 134.06 93.54 #13 3 5 0 91 34 3659 95 37 94.71 29.31 #14 3 1 0 94 15 370 90 108 94.77 71.00 #15 3 3 0 93 41 7194 7 59 0.90 162.28 SUM 4 3 0 92 659 32166 588 1459 748.40 3137.45 PID USER PRI NICE SIZE RES STAT TIME CPU% COMMAND 774 root 255 21 12k 73M run 32:57:01 102.4/93.7 Kernel (wait) 2064 root 255 21 12k 73M run 32:52:13 100.8/93.5 Kernel (wait) 4128 root 255 21 12k 73M run 32:39:51 100.8/92.9 Kernel (wait) 3612 root 255 21 12k 73M run 32:35:47 100.8/92.7 Kernel (wait) 516 root 255 21 12k 73M run 33:15:45 99.2/94.6 Kernel (wait) 4386 root 255 21 12k 73M run 32:51:00 99.2/93.4 Kernel (wait) 2322 root 255 21 12k 73M run 32:49:28 99.2/93.3 Kernel (wait) 1290 root 255 21 12k 73M run 32:55:52 97.6/93.6 Kernel (wait) 1032 root 255 21 12k 73M run 32:53:48 97.6/93.5 Kernel (wait) 2838 root 255 21 12k 73M run 32:48:12 97.6/93.3 Kernel (wait) 1548 root 255 21 12k 73M run 32:56:02 97.6/93.7 Kernel (wait) 3354 root 255 21 12k 73M run 32:51:38 97.6/93.4 Kernel (wait) 3870 root 255 21 12k 73M run 32:40:09 96.0/92.9 Kernel (wait) 3096 root 255 21 12k 73M run 32:44:59 94.4/93.1 Kernel (wait) 1806 root 255 21 12k 73M run 31:54:16 94.4/90.7 Kernel (wait) 2580 root 255 21 12k 73M run 32:55:12 88.0/93.6 Kernel (wait) 53960 root 60 0 32M 32M run 1:17:39 12.8/ 3.7 LoadL_negotiator 74622 yetter 60 0 9884k 11M Frun 1:31 3.2/ 0.2 xemacs-21.1.14 52242 root 56 -4 11M 11M run 41:00 1.6/ 2.0 pspd 16268 root 40 -20 400k 420k run 24:21 0.0/ 1.2 mld 23240 root 60 0 771k 812k run 1:20 0.0/ 0.1 sh 50850 root 29 21 8019k 8136k run 7:16 0.0/ 0.3 acctd 12918 root 60 0 2983k 3116k run 0:30 0.0/ 0.0 snmpd 78200 blaise 61 0 5464k 5496k Frun 0:00 0.0/ 0.7 monitor115240 jdh

xprofiler

Overview:

• xprofiler is an X Windows based profiling tool distributed with IBM's Parallel Environment software. It is based upon the gprof profiling utility, however it provides a graphical representation of profile data in addition to all of the usual gprof reports.

• Graphical information is organized into 3 main components:
  • Library Cluster Boxes
  • Function Boxes
  • Call Arcs

• xprofiler can profile at both the subroutine level, and at the source statement level. Profiling also includes any calls made to library functions.

• Time sampled profiling:
  • Like many profiling tools, xprofiler acquires its data by keeping track of the executing program's location whenever it is interrupted.
  • Interrupts occur at set intervals and are commonly called "ticks". Under AIX, a tick occurs every 1/100th second.
  • Those portions of the program which accumulate the most "ticks" reflect the areas where the program spends most of its time.

• Filters, zooming, and other options allow you to limit displays to only those portions of the call tree you are interested in analyzing.

Example Displays and Reports:

	Opening display of the entire call tree. Initial display is fully zoomed-out, demonstrating the main library clusters, calling arc summaries, and overall routine control flow.
	Unclustered functions view. Same as previous display, but functions are not grouped within their library cluster.
	Zoom-in view of main program. The smaller "Overview Window" allows easy positioning of desired view area. Zoomed-in area provides function details.
	Collapsed library clusters. Zoomed-out view. Demonstrates how undesired information can be removed/summarized.

	Flat Profile Report. Similar to the same report produced by the gprof utility. Lists functions according to cpu usage.
	Source Code Report showing accumulated ticks for code statement lines.
	Call Graph Profile. Similar to the same report produced by by the gprof utility.
	Library Statistics. Shows execution statistics for libraries called

Using xprofiler:

1. Compile and link your program with both of the options: -g -pg . The -g option enables source statement profiling and -pg turns profiling on.

   Note: when you compile and link separately, you must use the -pg option with both the compile and link commands.

2. Run your serial or parallel code as usual. When it has completed, you will find one statistics file file for each task. Serial codes produce gmon.out. For parallel jobs, the files will be called gmon.out.0, gmon.out.1, gmon.out.2 and so on.

3. Invoke xprofiler. This can be done several ways.

   xprofiler	Starts without a file loaded. Must load file by using xprofiler's File pull-down menu.
   xprofiler myprog gmon.out	Loads the serial program with it's stat file
   xprofiler myprog gmon.out.N	Loads parallel program with selected stat file
   xprofiler myprog gmon.out.*	Loads parallel program with combined/merged stat files

   Note that there are also several command line flags available to define certain xprofiler characteristics and behaviors.

4. Use xprofiler's pull down menus and hidden menus (press right mouse button on an object such as an arc or function box) to accomplish desired actions, such as:

   Zooming-in, out Examining arc information Examining function statistics Producing reports Loading new files Setting configuration options Saving/producing screen dumps Unclustering functions from their library group Collapsing/hide library information and more....

   xprofiler hidden function menu

   xprofiler hidden arc menu

   Important note: it is often necessary to uncluster functions and zoom-in to get to important detailed information. It is also usually useful to collapse/hide library information that isn't needed (like system libs).

Documentation:

IBM Parallel Environment for AIX: Operation and Use Volume 2 Tools Reference. Complete product documentation.

mpiP

• mpiP is a lightweight profiling library for MPI applications.
  • Software developed by LLNL. Currently installed under /usr/local/tools/mpiP. Some documentation included.
  • Collects only statistical information about MPI routines
  • Captures and stores information local to each task (local memory and disk)
  • Uses communication only at the end of the application to merge results from all tasks into one output file.

• mpiP provides statistical information about a program's MPI calls:
  • Percent of a task's time attributed to MPI calls
  • Where each MPI call is made within the program (callsites)
  • Top 20 callsites
  • Callsite statistics (for all callsites)

• A GUI interface called mpipview has also been developed for mpiP output files.

• Using mpiP is very simple. It involves little more than linking with the mpiP libraries, currently installed under /usr/local/tools/mpiP on LLNL's ASCI systems.

• If your source code has been compiled with the -g flag, recompilation isn't even necessary. In fact, most mpiP features are operative without the -g flag.

• An example compilation appears below. In your compilations, be sure that the mpiP libraries appear before any other MPI libraries.

  mpcc_r -g -o myprog myprog.c -L/usr/local/tools/mpiP/lib -lmpiP -lbfd -liberty -lintl -lm

• After compiling, run your application as usual. You can verify that mpiP is working by header and trailer output it sends to stdout.

• After your application completes, mpiP will write its output file to the current directory. The output file name will have the format of myprog.N.XXXXX.mpiP where N=#MPI tasks and XXXXX=collector task process id.

• mpiP's output file is divided into 5 sections:
  1. Environment Information
  2. MPI Time Per Task
  3. Callsites
  4. Aggregate Times of Top 20 Callsites
  5. Callsite Statistics

• Examples of each section follow below.

  Environment Information Section

  @ mpiP @ Command : sphot @ Version : 0.9 @ Build date : Mar 8 2001, 16:22:46 @ Start time : 2001 04 11 16:04:23 @ Stop time : 2001 04 11 16:04:51 @ Number of tasks : 4 @ Collector Rank : 0 @ Collector PID : 30088 @ Event Buffer Size : 100000 @ Final Trace Dir : . @ Local Trace Dir : /usr/tmp @ Task Map : 0 blue333.pacific.llnl.gov 0 @ Task Map : 1 blue334.pacific.llnl.gov 0 @ Task Map : 2 blue335.pacific.llnl.gov 0 @ Task Map : 3 blue336.pacific.llnl.gov 0

  MPI Time Per Task

  ------------------------------------------------------------------------------- @--- MPI Time (seconds) ------------------------------------------------------- ------------------------------------------------------------------------------- Task AppTime MPITime MPI% 0 27.9 7.18 25.73 1 27.9 7.5 26.89 2 27.9 7.78 27.90 3 27.9 7.73 27.72 * 112 30.2 27.06

  Callsites

  ------------------------------------------------------------------------------- @--- Callsites: 38 ------------------------------------------------------------ ------------------------------------------------------------------------------- ID MPICall ParentFunction Filename Line PC 1 Barrier copyglob copyglob.f 65 10000b9c 2 Barrier copypriv@OL@1 copypriv.f 195 10001cd4 3 Barrier copypriv@OL@2 copypriv.f 237 1000213c 4 Barrier copypriv@OL@3 copypriv.f 279 10002624 5 Barrier copypriv@OL@4 copypriv.f 324 10002b04 6 Barrier sphot sphot.f 269 10008f2c 7 Bcast rdopac rdopac.f 49 10008638 8 Comm_rank copyglob copyglob.f 13 100003a8 9 Comm_rank copypriv copypriv.f 75 10000c38 10 Comm_rank genxsec genxsec.f 37 1000503c 11 Comm_rank rdinput rdinput.f 17 100071d4 12 Comm_rank rdopac rdopac.f 29 1000806c 13 Comm_rank sphot sphot.f 67 10008a04 14 Comm_size copyglob copyglob.f 12 10000390 15 Comm_size copypriv copypriv.f 76 10000c50 16 Comm_size sphot sphot.f 68 10008a1c 17 Finalize sphot sphot.f 279 10008f60 18 Init sphot sphot.f 66 100089e8 19 Irecv copyglob copyglob.f 47 10000a70 20 Irecv copypriv@OL@1 copypriv.f 162 1000184c 21 Irecv copypriv@OL@2 copypriv.f 205 10001db4 22 Irecv copypriv@OL@3 copypriv.f 254 1000221c 23 Irecv copypriv@OL@4 copypriv.f 297 10002704 24 Irecv sphot@OL@1@OL@2 sphot.f 201 1000974c 25 Reduce sphot sphot.f 258 10008eac 26 Reduce sphot sphot.f 262 10008eec 27 Send copyglob copyglob.f 60 10000b78 28 Send copypriv@OL@1 copypriv.f 191 10001cb8 29 Send copypriv@OL@2 copypriv.f 233 10002120 30 Send copypriv@OL@3 copypriv.f 275 10002608 31 Send copypriv@OL@4 copypriv.f 320 10002ae8 32 Send sphot@OL@1@OL@3 sphot.f 234 100099d8 33 Waitall copyglob copyglob.f 51 10000ac4 34 Waitall copypriv@OL@1 copypriv.f 168 10001928 35 Waitall copypriv@OL@2 copypriv.f 212 10001e94 36 Waitall copypriv@OL@3 copypriv.f 260 100022fc 37 Waitall copypriv@OL@4 copypriv.f 304 100027e4 38 Waitall sphot@OL@1@OL@2 sphot.f 206 100097b4

  Aggregate Times of Top 20 Callsites

  ------------------------------------------------------------------------------- @--- Aggregate Time (top twenty, descending, milliseconds) -------------------- ------------------------------------------------------------------------------- Call Site Time App% MPI% Bcast 7 1.54e+04 13.79 50.95 Barrier 1 1.42e+04 12.73 47.03 Barrier 2 563 0.50 1.87 Waitall 34 25.7 0.02 0.09 Reduce 25 7.4 0.01 0.02 Barrier 5 2.54 0.00 0.01 Barrier 6 1.55 0.00 0.01 Barrier 4 1.44 0.00 0.00 Comm_rank 13 1.22 0.00 0.00 Barrier 3 1.01 0.00 0.00 Comm_rank 9 0.967 0.00 0.00 Send 27 0.755 0.00 0.00 Send 31 0.694 0.00 0.00 Waitall 37 0.42 0.00 0.00 Send 28 0.336 0.00 0.00 Waitall 35 0.21 0.00 0.00 Waitall 36 0.202 0.00 0.00 Waitall 38 0.2 0.00 0.00 Irecv 19 0.2 0.00 0.00 Reduce 26 0.185 0.00 0.00 Waitall 33 0.161 0.00 0.00 Comm_size 15 0.132 0.00 0.00

  Callsite Statistics

  ------------------------------------------------------------------------------- @--- Callsite statistics (all, milliseconds): 102 ----------------------------- ------------------------------------------------------------------------------- Name Site Rank Count Max Mean Min App% MPI% Barrier 1 0 1 0.087 0.087 0.087 0.00 0.00 Barrier 1 1 1 12.7 12.7 12.7 0.05 0.17 Barrier 1 2 1 7.09e+03 7.09e+03 7.09e+03 25.44 91.17 Barrier 1 3 1 7.09e+03 7.09e+03 7.09e+03 25.44 91.75 Barrier 1 * 4 7.09e+03 3.55e+03 0.087 12.73 47.03 Barrier 2 0 1 0.12 0.12 0.12 0.00 0.00 Barrier 2 1 1 0.29 0.29 0.29 0.00 0.00 Barrier 2 2 1 307 307 307 1.10 3.95 Barrier 2 3 1 255 255 255 0.92 3.31 Barrier 2 * 4 307 141 0.12 0.50 1.87 ..... [snip]..... Send 31 1 1 0.169 0.169 0.169 0.00 0.00 Send 31 2 1 0.341 0.341 0.341 0.00 0.00 Send 31 3 1 0.184 0.184 0.184 0.00 0.00 Send 31 * 3 0.341 0.231 0.169 0.00 0.00 Send 32 1 1 0.027 0.027 0.027 0.00 0.00 Send 32 2 1 0.042 0.042 0.042 0.00 0.00 Send 32 3 1 0.043 0.043 0.043 0.00 0.00 Send 32 * 3 0.043 0.0373 0.027 0.00 0.00 Waitall 33 0 1 0.161 0.161 0.161 0.00 0.00 Waitall 33 * 1 0.161 0.161 0.161 0.00 0.00 Waitall 34 0 1 25.7 25.7 25.7 0.09 0.36 Waitall 34 * 1 25.7 25.7 25.7 0.02 0.09 Waitall 35 0 1 0.21 0.21 0.21 0.00 0.00 Waitall 35 * 1 0.21 0.21 0.21 0.00 0.00 Waitall 36 0 1 0.202 0.202 0.202 0.00 0.00 Waitall 36 * 1 0.202 0.202 0.202 0.00 0.00 Waitall 37 0 1 0.42 0.42 0.42 0.00 0.01 Waitall 37 * 1 0.42 0.42 0.42 0.00 0.00 Waitall 38 0 1 0.2 0.2 0.2 0.00 0.00 Waitall 38 * 1 0.2 0.2 0.2 0.00 0.00

HPM Toolkit

• The Hardware Performance Monitor (HPM) Toolkit is a set of libraries and utilities provided by IBM that lets the user access hardware event counters within the physical SP processor.

• There are many hardware events that can be measured, such as:
  • clock cycles
  • instructions completed
  • L1 load/store misses
  • L2 load/store misses
  • TLB misses
  • FPU/FXU activity
  • number of branches
  • branch mispredictions
  • loads/stores completed
  • FMAs executed

• The POWER3-II processor possesses 8 hardware counters that can be used to measure many hardware events - up to 8 simultaneously. For convenience, IBM provides four "canned" sets of events that can be measured easily by the user. These four sets are:

  Event Set 1	Event Set 2	Event Set 3	Event Set 4
  Cycles	Cycles	Cycles	Cycles
  Inst. Completed	Inst. Completed	Inst. Completed	TLB Misses
  TLB Misses	TLB Misses	Inst. Cache Misses	Loads Completed
  Stores Completed	Stores Dispatched	FXU0 Operations	Stores Completed
  Loads Completed	L1 Store Misses	FXU1 Operations	L2 Load Misses
  FPU0 Operations	Loads Dispatched	FXU2 Operations	L2 Store Misses
  FPU1 Operations	L1 Load Misses	FPU0 Operations	Branches
  FMAs Executed	Load/Store Unit Idle	FPU1 Operations	Branches Mispredicted

• The HPM Toolkit actually consists of three more-or-less independent components:

  • hpmcount: a command-line utility that provides an overall view of your code's performance

  • libhpm: an instrumentation library that provides the user with a set of function calls for Fortran, C, and C++ programs that can be used to manually instrument sections of your code.

  • hpmviz: a GUI utility for viewing the performance results generated by libhpm calls.

• One of the greatest advantages of the HPM toolkit is that it can quickly tell you why your code is performing the way it does from a hardware level.

Using hpmcount:

• Using the command-line hpmcount utility is fairly straight-forward. First, find where the executable is located if it isn't already in your path - and then put it in your path.

• Compile your source as usual

• Invoke your executable through hpmcount. The general syntax is:

  hpmcount [-h] [-o <file name>] [-s <set>] [-e ev[,ev]*] program
  

  where:

  -h	Prints help message
  -o <filename>	Sets the output file name. For parallel jobs, each process gets a unique output file.
  -s <set>	Defines one of four default event sets to measure. Event set 1 is the default.
  -e ev[,ev]*	Manually defines a list of hardware counters to monitor. (Only for the truly adventurous.)

  Sample hpmcount output

  % hpmcount a.out -s 1 Running pipe()... s= 80200000000.0000000 Running unroll()... s= 51840000160.0000000 Running strength()... s= 84147.0984807570785 Running block()... c(N,N) = 67239936.0000000000 adding counter 5 event 12 Cycles adding counter 0 event 1 Instructions completed adding counter 7 event 0 TLB misses adding counter 2 event 9 Stores completed adding counter 3 event 5 Loads completed adding counter 4 event 5 FPU 0 instructions adding counter 1 event 35 FPU 1 instructions adding counter 6 event 9 FMAs executed hpmcount (V 2.3.1) summary Total execution time (wall clock time): 85.366748 seconds ######## Resource Usage Statistics ######## Total amount of time in user mode : 75.190000 seconds Total amount of time in system mode : 0.090000 seconds Maximum resident set size : 7648 Kbytes Average shared memory use in text segment : 120432 Kbytes*sec Average unshared memory use in data segment : 26017908 Kbytes*sec Number of page faults without I/O activity : 1912 Number of page faults with I/O activity : 3 Number of times process was swapped out : 0 Number of times file system performed INPUT : 0 Number of times file system performed OUTPUT : 0 Number of IPC messages sent : 0 Number of IPC messages received : 0 Number of signals delivered : 0 Number of voluntary context switches : 47 Number of involuntary context switches : 1321 ####### End of Resource Statistics ######## PM_CYC (Cycles) : 27845219686 PM_INST_CMPL (Instructions completed) : 20517718852 PM_TLB_MISS (TLB misses) : 138272209 PM_ST_CMPL (Stores completed) : 1722228911 PM_LD_CMPL (Loads completed) : 6770324612 PM_FPU0_CMPL (FPU 0 instructions) : 1485346931 PM_FPU1_CMPL (FPU 1 instructions) : 200209450 PM_EXEC_FMA (FMAs executed) : 1259225176 Utilization rate : 86.968 % Avg number of loads per TLB miss : 48.964 Load and store operations : 8492.554 M Instructions per load/store : 2.416 MIPS : 240.348 Instructions per cycle : 0.737 HW Float points instructions per Cycle : 0.061 Floating point instructions + FMAs : 2944.782 M Float point instructions + FMA rate : 34.496 Mflip/s FMA percentage : 85.522 % Computation intensity : 0.347

• The libhpm library consists of several C/C++/Fortran routines that are used to instrument specific sections of your code. You must insert these routines into your source code manually as desired. You must also supply the necessary include file.

• When compiling your code, you will be required to link with the necessary libhpm libraries.

• Documentation and examples are distributed with the source code.

• Then execute your code as usual. libhpm will create two files for each task:

  perfhpm[taskID].[pid] which contains a text version of the performance data
  hpm[taskID]_[progName]_[pid].viz which contains data for the hpmviz program.

  For example, a 4 task run of an executable called "swim" produces"

  -rw-------   1 blaise   blaise        31840 Jul 18 18:38 hpm0000_swim_53912.viz
  -rw-------   1 blaise   blaise        31832 Jul 18 18:38 hpm0001_swim_53042.viz
  -rw-------   1 blaise   blaise        31840 Jul 18 18:38 hpm0002_swim_51346.viz
  -rw-------   1 blaise   blaise        31840 Jul 18 18:38 hpm0003_swim_56720.viz
  -rw-------   1 blaise   blaise        52662 Jul 18 18:38 perfhpm0000.53912
  -rw-------   1 blaise   blaise        52633 Jul 18 18:38 perfhpm0001.53042
  -rw-------   1 blaise   blaise        52684 Jul 18 18:38 perfhpm0002.51346
  -rw-------   1 blaise   blaise        52673 Jul 18 18:38 perfhpm0003.56720
  

  Example libhpm report

• Rather than sorting through the text output files generated with the libhpm instrumentation, the graphical utility hpmviz can be used to easily browse both the performance data and the associated source code.

• After making sure your X-Windows display environment is setup correctly, you can invoke hpmviz with any of the *.viz files produced by libhpm. For example:

  hpmviz hpm0003_swim_56720.viz
  

• The initial two-paned hpmviz window will appear, showing any instrumented routines in the left pane and their source code in the right pane. Example here

• Left clicking on any instrumentation label (routine name) in the left pane will cause its source code to appear in the right pane. Example here

• Right clicking on any instrumentation label in the left pane will cause a new window to appear showing that code segment's statistics. Example here

• In the statistics window, red is used to indicate "bad" performance and "green" for good performance.

PE Benchmarker Toolset

• The PE Benchmarker toolset is a suite of applications and utilities designed to analyze the performance of programs run within the IBM Parallel Environment for AIX.

• Requires:
  • AIX version 5+
  • PSSP version 3.4+
  • IBM's Java software version 1.3
  • Argonne National Lab's Jumpshot utility (for viewing MPI events)

• The PE Benchmarker suite consists of three primary components:

  • Performance Collection Tool (PCT): Enables you to collect either MPI and user event data, or hardware and operating system profiles for one or more application processes. Results in the production of AIX trace files.

  • Unified Trace Environment (UTE) utilities: Permit you to convert and/or merge the PCT produced AIX trace files into UTE format to produce statistical a report or for use with the Jumpshot GUI.

  • Profile Visualization Tool (PVT): When you collect hardware and operating system profiles using the PCT, it is saved as netCDF (network Common Data Form) files. The PVT can read netCDF files and summarize the profile information in reports.

• Assuming that your software environment is setup correctly, you can start the Performance Collection Tool in either graphical (GUI) mode or command line mode. Examples:

  pct - graphical mode. Example here
  pct -c - command line
  pct -c -s - command line reading commands from a script file

• You can load a new application or attach to one that is already running

• Enables you to select monitoring of MPI events, user events or hardware and operating system events - from either the GUI or command line interface.

• Monitors events at the program, file and/or function level

• Provides built-in help (much more for the GUI than the command line interface)

• Stores program execution information in AIX trace file format. Requires the UTE utilities or Profile Visualization Tool to interpret.

• Intended for use only with MPI and user events collected by PCT's AIX trace files

• Convert AIX timestamp files into "interval" files - to time how long events actually take, and for possible visualization.

• Four utilities are provided:
  • uteconvert: converts AIX event trace files into UTE interval trace files.
  • utemerge: merges multiple UTE interval files into a single UTE interval file.
  • utestats: generates statistics tables from UTE interval files.
  • slogmerge: converts and merges UTE interval files into a single SLOG file for analysis within Argonne National Laboratory's Jumpshot tool.

• Jumpshot must be acquired and installed separately (it is part of Argonne's MPICH distribution).

• Provides both a GUI and command line interface for analyzing hardware and operating system events collected by the PCT.

• Startup examples:

  pvt - starts the GUI
  pvt filename(s) - starts GUI with one or more input files. Example here
  pvt -c - starts the command line interface
  pvt -c filename(s) - starts command line interface with one or more input files

• Options enable you to view:
  • Function Call Count
  • Wall Clock Time
  • Resource Usage
  • Hardware Counters

• The GUI has extensive built-in help, like PCT

IBM Parallel Environment for AIX: Operation and Use Volume 2 Tools Reference. Complete product documentation.

VampirGuideView (VGV)

• VGV is a performance analysis tool for mixed OpenMP and MPI parallel programming. It has been developed by Intel KAI lab and Pallas as a part of the ASCI PathForward Program.

• It has been designed to support application performance measurement, visualization, analysis, and improvement. A major focus is scalability to keep pace with the rapid improvements in ASCI platforms

• A sophisticated and evolving tool available to LLNL ASCI users.

• Deserves a full day tutorial in itself. Such has been offered several times at LLNL. Tutorials and further information is available at: Livermore Computing Training - see the "Online Tutorials" section.

Paraver and Dimemas

• Paraver and Dimemas are two performance analysis tools from CEPBA (European Center for Parallelism of Barcelona).

• Paraver is a flexible performance visualization and analysis tool that can be used to analyze MPI, OpenMP, MPI+OpenMP, Java, hardware counters profiling, operating system activity and more.

• Dimemas is performance analysis tool for message-passing programs. It enables the user to develop and tune parallel applications on a workstation while providing an accurate prediction of their performance on the target parallel machine.

• Paraver and Dimemas are both sophisticated tools that deserve a full day workshop in themselves. Such has been recently conducted at LLNL. Tutorials and further information is available at: Livermore Computing Training - see the "Online Tutorials" section.

• PS: "Paraver" means "to see" and "Dime mas" means "tell me more" in Spanish.

Performance Toolbox

Overview:

• The Performance Toolbox is an X Windows based application from IBM that provides a graphical means of monitoring, analyzing and controlling AIX real time machine resource usage.

• Statistics that can be monitored include:
  • cpu utilization
  • disk activity
  • paging activity
  • network activity
  • list top processes

• Features include:
  • Customization of which statistics are monitoring and how they are displayed
  • Ability to record and playback statistics
  • Multi-processor 3D-monitor
  • Monitor local or remote systems

• Must be obtained from IBM and then installed on your system as an IBM software product. It is not part of the operating system or the usual SP software suite. Not currently available at LLNL.

Example Displays:

	Performance Toolbox monitor view 1
	Performance Toolbox monitor view 2:
	Performance Toolbox 3D monitor view 1: multiple hosts
	Performance Toolbox 3D monitor view 2: single host

Dynamic Probe Class Library (DPCL)

• The Dynamic Probe Class Library (DPCL) is a C++ class library whose application programming interface (API) enables a program to dynamically insert instrumentation code patches, or "probes", into an executing program.

• The program that uses DPCL calls to insert probes is called the "analysis tool", while the program that accepts and runs the probes is called the "target application".

• The DPCL product is an asynchronous software system designed to serve as a foundation for a variety of analysis tools that need to dynamically instrument (insert probes into and remove probes from) target applications.

• In addition to its API, the DPCL system consists of daemon processes that attach themselves to the target application process(es) to perform most of the actual work, and an asynchronous communication and callback facility that connects the class library to the daemon processes.

• DPCL is not intended for the average user. It is intended for the developers of performance analysis tools for the IBM environment.

• Was considered part of POE software 3.1, however it is now distributed with POE version 3.2 as a convenience and is actually offered through IBM's open source sofware at http://oss.software.ibm.com.

Using DPCL:

• Need to be a brave C++ programmer and have the most recent IBM hardware/software.

• Otherwise, wait until IBM and/or other independent software developers release tools based upon DPCL. The good news is that these are already in progress.

Documentation:

DPCL Home Page

Other Multi-Platform Parallel Performance Analysis Tools:

A number of multi-platform, parallel, performance analysis tools are available. The table below summarizes some of the more popular and widely used ones.

This information changes. New tools are appearing all of the time and some of these may be extinct already.

All of these tools are sophisticated and require a learning curve. Some more than others.

In the table below, each tool is linked to its corresponding home page in column 1.

Tools with an * asterisk are installed on LLNL ASCI systems.

Package	Supplier	Availability
AIMS	NASA Ames Research Center	Free
DEEP	Veridian Systems	$$?
Falcon	Georgia Tech	Free
SiGMA	IBM (ACTC)	???
Jumpshot *	Argonne National Lab - distributed with MPICH	Free
Pablo/SvPablo	University of Illinois, Urbana-Champaign	Free (non commericial use)
Paradyn *	University of Wisconsin	Free
PGPROF	Portland Group, Inc.	License
TAU *	Univ. Oregon	Free

Miscellaneous Tools

mpi_trace:

• Provides statistical information for an application's MPI calls.

• Two components:
  • mpi_trace.c, mpi_trace.o: low overhead wrappers for MPI routines
  • libmpiprof.a: MPI time per user-level subroutine. Requires compilation with -g option.

• To use:
  • Link with either mpi_trace.o or libmpiprof.a
  • Run the application - be sure to call MPI_Finalize().
  • An output file will be produced for each MPI task, called mpi_profile.N where N is the MPI rank number.
  • No utility is provided to summarize all reports - they must be viewed individually or processed through a utility like grep or a "home grown" filter/utility.

• Status: Not an IBM product or generally available. Provided to LLNL as part of a previous workshop. Still available on ASCI systems under /usr/local/spclass/walkup. Some documentation included.

  Sample mpi_trace output

MPIMap:

• MPIMap is a tool for graphically displaying the structure of complex MPI data types.

• Only works with MPICH, but should be portable to any Unix implementation of MPICH.

• Status: Developed at LLNL. Available for LC users.

• Additional information: see the LLNL MPIMap web page.

And More...

• MPX - LLNL developed hardware performance monitor. Produces min, max and mean statistics for parallel jobs. Can be used on LLNL ASCI IBM systems. See www.llnl.gov/casc/mpx for download and usage information.

• Umpire - LLNL developed MPI correctness tool. Available later.

• PAPI - University of Tennessee portable hardware performance monitor API

• PMAPI - IBM hardware performance monitor API

This completes the tutorial.

Please complete the online evaluation form - unless you are doing the exercise, in which case please complete it at the end of the exercise.

Where would you like to go now?

• Exercise
• Agenda
• Back to the top

• "Optimization and Tuning Guide for Fortran, C, and C++". AIX Version 4. IBM Corporation.

• "Using ASCI White: Advanced Topics for Early Users". Workshop materials from Bob Walkup, IBM Corporation. Jan. 2001.

• "XL Fortran: Eight Ways to Boost Performance", IBM Corporation.
  www.software.ibm.com/ad/fortran/xlfortran/optim.htm

• IBM Parallel Environment for AIX Manuals: Operation and Use Volume 1 and Volume 2. IBM Corporation.
  www-1.ibm.com/servers/eserver/pseries/library/sp_books/pe.html

• "Performance Basics". Tutorial by the Cornell Theory Center.
  www.tc.cornell.edu