Track Performance in SAS with the LOGPARSE Macro

Feb 2, 2018

SAS programmers are often interested in the time it takes for their program to run. The common way to measure performance is to simply run code, look in the log, and manually write down the performance statistic of interest. The LOGPARSE Macro is an attempt by SAS Institute to make this program a lot easier, by gathering as much information as possible from your executed code and save it in a data set for later analysis. This post is a fast track example to using the macro and creating a data set with performance statistics.

The LOGPARSE Macro

The LOGPARSE macro provided by SAS Institute lets you track performance statistics and save them in a data set. The macro is available at the SAS Documentation Page. Follow the link and download the ZIP file. The ZIP file contains three files:

  • readme.txt: Documents and describes the possibilities of the macro.
  • passinfo.sas: A macro definition that passes information to the log. The logparse macro later looks for this information. The passinfo works across all operating systems. I work in a Windows environment. Therefore, I have written it a bit simpler, since I do not need to check whether I work in UNIX, LINUX etc. You can download my simplified version here.
  • logparse.sas: The main macro definition that retrieves performance information from the log and saves them in a data set.

Before you can use the macro, you have to compile the two macros passinfo and logparse. This is most easily done by Setting up a Library of Compiled Macros or by Using the AUTOEXEC File. The macro works by printing the log of the program of performance interest to a specified directory. Next, the log is parsed to the macro, and performance information is retrieved and saved in a data set.

A Simple Example

Now, let us look at a very simple example. The example below uses six simple steps when utilizing the logparse macro, provided that the two macros as already compiled. I briefly describe the steps in the comments above each step, though the best understanding of how the macro works is by playing around with it yourself.

Shortly put, the six steps goes as follows. First, I use the FULLSTIMER System Option to write as much performance information as possible to the log. Next, I use PROC PRINTTO to redirect the log into a .log file at my desktop. I use the NONOTES and NOSOURCE System Options to suppress information about this specific step in the external log, since performance of this step is not of interest. Then, I call the PASSINFO macro as described above. Next, I run the the SAS program of which I am interested in measuring performance. Finally, I direct the log back from the desktop file to the internal log and call the logparse macro to retrieve information from the log on the desktop and save the relevant performance statistics in a SAS data set.

/* 1) Set the fullstimer option to write sufficient performance information to the log */
options fullstimer;
 
/* 2) Save log in a file */
options nonotes nosource;
proc printto log="c:\Users\Peter\Desktop\MyProgram.log";
run;
options notes source;
 
/* 3) Call the PASSINFO macro */
%passinfo;
 
/* 4) Run some SAS program steps */
data class;
   set sashelp.class;
run;
 
proc sort data=class;
run;
 
proc reg data=class;
   model weight=height;
   by sex;
run;quit;
 
/* 5) Reset log options */
proc printto;
run;
 
/* 6) Call LOGPARSE Macro and save performance statistics in work.PerfStat data set */
%logparse(c:\Users\Peter\Desktop\MyProgram.log,work.PerfStat,,,append=NO);

The PerfStat data set contains performance statistics of the executed code. Opening the data set or running a PROC CONTENTS on the data set reveals that the data set contains many variables. Also, you may notice that most of the variables contain missing values. This happens because the logparse macro works on many different procedures/steps and not all variables apply to every procedure. For example, if a procedure does not write any observations, the Observations Written variable is missing.

Summary

This post demonstrates how you can easily measure the performance of your SAS programs in terms of I/O, CPU Time, Time Elapsed and so on. Doing this is fairly easy using the LOGPARSE Macro provided by SAS Institute. This demonstration is far from thorough. For a more in-depth introduction to the macro and its facilities, go to the SAS Documentation on the subject. Also, the article Programmatically Measure SAS Application Performance On Any Computer Platform is a really nice article on the topic.

I have used the LOGPARSE Macro in several performance-related posts in my blog. A few of them include Multi Threaded Processing In SAS, Three PROC SORT Options You Should Know, Run Time Effect Of Hash Object HASHEXP Argument Size and A SAS Case Study of the BUFSIZE and BUFNO System Options.

If you are interested in learning about performance of SAS programs, check out the book High Performance SAS Coding, which I have previously described on the post What SAS Books Are On My Shelf.

You can download the entire code supporting this post here.