SAS Program Timer

SAS is great. Well SAS is okay. Eh, 70% of the time SAS is fine. The issue with SAS, or rather one of the issues, is it’s continued and almost dogged choice to refuse to see the wood for the trees. Let’s improve that a little by building a program timer.

Grab this from GitHub

What we’re currently working with…

Let it not be said that SAS doesn’t make an effort. In fact, it would be a fairly extreme departure from common sense if they were not to note somewhere the running times for parts of SAS objects. An inspection of any SAS log will show data steps and procedures that producing the following output.

10 proc sort data=logsample; **[12]**
11 by LastName;
12

NOTE: There were 5 observations read from the dataset
 WORK.LOGSAMPLE. 
NOTE: The data set WORK.LOGSAMPLE has 5 observations and 10
 variables. **[13]**
NOTE: PROCEDURE SORT used:
 real time 0.16 seconds
 cpu time 0.03 seconds

Here we can see that the PROCEDURE SORT used 0.16 seconds of real-time which equates to 0.03 seconds of CPU time. The difference here doesn’t matter for our purposes but a more in-depth look at these notes is discussed here.

This is all very nice to know, but in the more usual case that you're working with 100s of different procedures, data steps and god knows what else, it would be useful to get an overall time for the entire program, not just the individual steps.

A SAS Program Timer

First things first, let’s grab the time at which the program was started. Not as simple as you might expect. SAS doesn’t store a macro variable with the time of execution. SAS does have automatically generated macro variables such as SYSTIME. However, these refer to the time the session was opened, and not when we explicitly started the program.

As such we need to create our own macro variable. Let’s call it launchTime to avoid any confusion with other macro variables that might be hanging around.

Launching and landing

%let launchTime = %sysfunc(time());

If we place the above snippet at the start of our program we will capture our start time. Next, let’s capture the end time. Which fortunately is just the exact same snippet! We just need to rename the macro variable.

%let landTime = %sysfunc(time());

%let timeTaken = %sysevalf(&landTime.-&launchTime.);

We have our two times, the total run time for the entire program is simply the difference. Done! we’ve successfully timed our program. All we need to do is to %PUT our timeTaken macro variable. Alas, in its current form, our timeTaken variable is just the number of seconds taken. It would be nice if we could format this into hours, minutes and seconds.

Formatting, formatting, formatting

In order to do so, we’d need to convert this from a time delta (a difference between two times) into something that SAS’s DateTime formats can understand. So we can add on the reference point for all SAS DateTime objects 1st January 1960.

%let timeTaken = %sysevalf(mdy(1,1,1960)+&landTime.-&launchTime.);

%let timeTakenFmt = %sysfunc(putn(&timeTaken.,e8601tm15.6));
%put &timeTakenFmt.;

Then all we need to do is add on our desired format. I’ve picked e8601tm15.6 which gives a nicely formatted time to the millisecond but feel free to use any one of SAS’s many built-in formats.

This is fine, but a bit of a pain in the arse if we have to copy these lines into every script that we worth with from now on.

Enterprise Guide ain’t all bad.

Enterprise Guide to the rescue! In EG we are able to set scripts that execute at the beginning and end of every program execution.

In Options > SAS Programs > Additional SAS Code, there are two checkboxes for ‘Insert custom SAS code before submitted code’ and ‘Insert custom SAS code after submitted code’. Placing our launchTime macro variable definition in the before section and our landTime macro variable definition and %PUT in the after section every program from now on will be timed!

Extra Credit

Make this information stand out in the log, add an ASCII box, tab this away from the left-hand side, add a title and context.

%let tab = %str( );

%put ;
%put &tab.############################### ;
%put &tab.# SAS CODE SUMMARY #;
%put &tab.# TIME TAKEN: &timeTakenFmt. #;
%PUT &TAB.# #; 
%PUT &TAB.###############################;

In the end, your log should look something like this…

Grab this from GitHub

Website: https://www.benjamincorcoran.com