Examples of Gathering Performance Data

Logging Internal SAS Processing Transactions

This example illustrates how to collect transaction statistics on internal SAS processing. For this example, only file input/output information is logged.

The only additional code that is added to the SAS program is the OPTIONS statement, which specifies the name of the ARM log output file and the ARMSUBSYS= system option, which specifies the specific SAS subsystem ARM_DSIO.

The following SAS program does the following:

1. Creates three SAS data sets: WORK.ONE, WORK.TWO, and WORK.THREE.

2. Builds an index for the variable A in WORK.THREE.

3. Prints two reports that are subsets of WORK.THREE.

4. Appends WORK.ONE to WORK.TWO.

5. Uses PROC SQL to modify WORK.THREE.

6. Prints the contents of WORK.THREE.

7. Copies all three WORK data sets to the permanent library SASUSER.

 options armloc='myarmlog.txt' armsubsys=(ARM_DSIO OPENCLOSE);   data work.one work.two;      input a $ b;   datalines;   1 1   2 2   3 3   ;   data work.three;      do a = 1 to 200;         b = a;         c = a;         output;      end;   run;   proc datasets library=work;      modify three;      index create a;   run;   quit;   proc print data=work.three;      where a <= 101;   run;   proc print data=work.three;      where a <= 10;   run;   proc append data=work.one base=work.two;   run;   proc sql;      delete from work.three where a > 100;      run;      update work.three set a = 75 where a > 75;      run;   quit;   proc contents data=work.three;   run;   proc copy in=work out=sasuser;      select three;   run; 

Here is the resulting ARM log:

Output 15.2: ARM Log

 I,1320332339.838000,1,2.814046,5.988611,SAS,xxxxxx   G,1320332339.858000,1,1,MVA_DSIO.OPEN_CLOSE,DATA SET OPEN/CLOSE,LIBNAME,      ShortStr,MEMTYPE,ShortStr,MEMNAME,LongStr   S,1320332347.549000,1,1,1,2.914190,6.669590,WORK ,DATA ,ONE   S,1320332348.390000,1,1,2,2.934219,6.729676,WORK ,DATA ,TWO   P,1320332348.410000,1,1,1,2.954248,6.729676,0,WORK ,DATA ,ONE   P,1320332348.420000,1,1,2,2.964262,6.729676,0,WORK ,DATA ,TWO   S,1320332348.490000,1,1,3,2.994305,6.739691,WORK ,DATA ,THREE   P,1320332348.530000,1,1,3,3.14334,6.749705,0,WORK ,DATA ,THREE   S,1320332359.216000,1,1,4,3.224636,7.661016,WORK ,DATA ,THREE   P,1320332360.948000,1,1,4,3.254680,7.851289,0,WORK ,DATA ,THREE   S,1320332362.170000,1,1,5,3.304752,7.951433,WORK ,DATA ,THREE   P,1320332367.358000,1,1,5,3.334795,8.51577,0,WORK ,DATA ,THREE   S,1320332367.388000,1,1,6,3.354824,8.61592,WORK ,DATA ,THREE   P,1320332367.398000,1,1,6,3.364838,8.61592,0,WORK ,DATA ,THREE   S,1320332367.428000,1,1,7,3.384867,8.71606,WORK ,DATA ,ONE   S,1320332367.438000,1,1,8,3.394881,8.71606,WORK ,DATA ,TWO   P,1320332372.655000,1,1,8,3.424924,8.131692,0,WORK ,DATA ,TWO   P,1320332372.665000,1,1,7,3.424924,8.141707,0,WORK ,DATA ,ONE   S,1320332375.970000,1,1,9,3.454968,8.392067,WORK ,DATA ,THREE   P,1320332377.282000,1,1,9,3.515054,8.562312,0,WORK ,DATA ,THREE   S,1320332377.302000,1,1,10,3.525068,8.572326,WORK ,DATA ,THREE   P,1320332377.923000,1,1,10,3.575140,8.632412,0,WORK ,DATA ,THREE   S,1320332377.953000,1,1,11,3.585155,8.652441,WORK ,DATA ,THREE   P,1320332383.521000,1,1,11,3.655256,8.832700,0,WORK ,DATA ,THREE   S,1320332389.89000,1,1,12,3.715342,8.912816,WORK ,DATA ,THREE   S,1320332389.159000,1,1,13,3.725356,8.922830,SASUSER ,DATA ,THREE   P,1320332391.182000,1,1,12,3.765414,9.32988,0,WORK ,DATA ,THREE   P,1320332391.192000,1,1,13,3.775428,9.32988,0,SASUSER ,DATA ,THREE   E,1320336057.253000,1,4.105904,10.194659 

 

Using ARM System Options and ARM Macros to Log Performance Statistics

This example uses the ARM system options as well as the ARM macros.

 /* set up ARM environment with ARM system options */   options      armagent=sasarmmg      armsubsys=arm_all      armloc=mylog;   filename mylog 'C:\MyDocuments\myfiles\ARMlog.txt';      /* enable ARM macros */   %let _armexec=1;      /* initialize work datasets */   data work1 work2 work3;   do _I_ = 1 to 100;     output;   end;   run;   %arminit(APPNAME='Sample ARM',APPUSER='Arm UserID',MACONLY=YES);   %armgtid(TXNNAME='Sample 1',MACONLY=YES);      /* armgtid and armstrt can be combined */   %armstrt(LEVEL=1,MACONLY=YES);      /* Step 1 */   data one;      set work1;   run;   %armstop(MACONLY=YES);   %armgtid(TXNNAME='Sample 2',MACONLY=YES);   %armstrt(LEVEL=1,MACONLY=YES);      /* Step 2 */   data two;      set work2;   run;   %armstop(MACONLY=YES);   %armgtid(TXNNAME='Sample 3',MACONLY=YES);   %armstrt(LEVEL=1,MACONLY=YES);      /* Step 3 */   data three;      set work3;   run;   %armstop(MACONLY=YES);   %armend(MACONLY=YES);   run; 

Post Processing an ARM Log

The following code uses the post-processing ARM macros in order to convert the ARM log into SAS data sets.

 %armproc;   %armjoin;   run;      /* redirect output to text file */   proc printto print='F:\arm\armlogs\USWest2ARM.log';   run;   proc print data=updtview;      title "Results of ARM calls";      sum deltelap deltcpu noncpu;      by txname;      sumby txname;   run;      /* redirect proc output to normal queue */   proc printto print=print;   run;