Problems replicating a a macro from a MWSUG paper

[MMariani]

Hello there SAS community,

I was looking for a way to analyze logs and found a MWSUG paper about the topic (MWSUG 2016 - Paper BB18 - SAS Advanced Programming with Efficiency in Mind: A Real Case Study) that was promising; it contains two macros and the first works perfectly but the second appears to be truncated in the paper (page 6); I still tried to solve it but I keep receiving multiple errors indicating there is something missing.    

The code is this and the macro that gives errors is the second one:

%macro log_IO_search(log = , doc = );

%*if not %index(&log, '_') %then %let log = &log.*.log;

data _null_;

length logname f logline $200;
infile "&log" filename=f end=done;
file "&doc";
logname=f;

if logname ne lag(logname) then do;
	if line then put line "lines read";
	put //'-----' logname '------';
		line=0;
end;
input ;
line + 1;
output = index(_infile_, 'NOTE: the data set') and 
			not index(_infile_, '--NOTE:')
				or
			index(_infile_, 'were written to the file')
;
input = index(_infile_, 'read from')  or index(_infile_, 'WHERE ');
time  = index(_infile_, ' time');
logline = _infile_;
keep = ifc(input, 'INPUT  ', 'OUTPUT');
keep = ifc(input, keep, 'TIME  ');
if input or output or time then put keep logline;
if done then put line "lines read";
run;

%mend log_IO_search;

%let log = .log;
%let name_log = ;
%let doc = ;

%log_IO_search(log = &log , doc = &doc);

/****************************/

*step 2;
*log = file_name from step 1;
*doc = results file;

%macro log_IO_data(log = , doc = );

data log_runtime_messy log_runtime(keep = dsn ntime ctime procdat obs);

length logname f logline $200 dsn $32 PROCDAT $6;

retain dsn obs;

infile "&log" filename=f end=done;
 file  "&doc"; *optional;

logname = f;
if logname ne lag(logname) then do;
	if line then put line "lines read";
	put //'-----' logname '------';
		line=0;
end;

input @;
if
index(_infile_, 'TIME NOTE: the data set')
 or index(_infile_,  'TIME NOTE: DATA statement used (total precess time):')
 or index(_infile_,  'TIME NOTE: PROCEDURE SORT used (total precess time):')
 or index(_infile_,  'TIME NOTE: PROCEDURE SQL used (total precess time):')

 then do;

 input /;

 ctime = scan(_infile_,4,'');
 if index(ctime, ':') then do;
	if countc(ctime, ':') = 1 then ctime='0:'||ctime ;
 	ntime = input(strip(ctime), time11.2);
end; 
 
else ntime=ctime+0;
	if PROCDAT='DATA: ' then do;
							DATA_TIME+ntime;
							DATA_steps+1;
						end;
	else if PROCDAT='SORT: ' then do;
						      SORT_TIME+ntime;
							  SORT_steps+1;
							 end;
	else do;
		SQL_TIME+ntime;
		SQL_steps+1;
	end;

output;

	put PROCDAT _infile_ @46 OBS comma10.0 ' ' @60 DSN "---" ntime=mmss8.2; *optional;
  end;
 else input;
end;
else input;
 if done then do;
 	put DATA_steps " DATA steps -- total process time " DATA_time = time11.2 ;  *optional;
	put SORT_steps " SORT steps -- total process time " SORT_time = time11.2 ;  *optional;
	put SQL_steps  " SQL steps  -- total process time " SQL_time  = time11.2 ;  *optional;
end;

run;

%mend log_IO_data;	

I hope you can help me find out what is missing.

Thanks a lot

[ballardw]

Set options MPRINT; Run the code.

Show the log results with the generated code and all the warnings and errors.

Without actual log messages in relation to the code macro problems are nearly impossible to solve.

It appears that this may only collect the information for Data step, Proc SQL and Proc sort procedures. If you are expecting to work with other procedures you need to look closely at the paper and the log for your procedures.

[MMariani]

You are right I forgot about the errors.

Here is the log for the step 2:

47 *passo 2;
48 *analisi log;
49 *log = file_name from step 1;
50 *doc = results file;
51
52 %macro log_IO_data(log = , doc = );
53
54 data log_runtime_messy log_runtime(keep = dsn ntime ctime procdat obs);
55
56 length logname f logline $200 dsn $32 PROCDAT $6;
57
58 retain dsn obs;
59
60 infile "&log" filename=f end=done;
61 file "&doc"; *optional;
62
63 logname = f;
64 if logname ne lag(logname) then do;
65 if line then put line "lines read";
66 put //'-----' logname '------';
67 line=0;
68 end;
69
70 input @;
71 if
72 index(_infile_, 'TIME NOTE: the data set')
73 or index(_infile_, 'TIME NOTE: DATA statement used (total precess time):')
74 or index(_infile_, 'TIME NOTE: PROCEDURE SORT used (total precess time):')
75 or index(_infile_, 'TIME NOTE: PROCEDURE SQL used (total precess time):')
76
77 then do;
78
79 input /;
80
81 ctime = scan(_infile_,4,'');
82 if index(ctime, ':') then do;
83 if countc(ctime, ':') = 1 then ctime='0:'||ctime ;
84 ntime = input(strip(ctime), time11.2);
85 end;
86
87 else ntime=ctime+0;
88 if PROCDAT='DATA: ' then do;
89 DATA_TIME+ntime;
90 DATA_steps+1;
91 end;
92 else if PROCDAT='SORT: ' then do;
93 SORT_TIME+ntime;
94 SORT_steps+1;
95 end;
96 else do;
97 SQL_TIME+ntime;
98 SQL_steps+1;
99 end;
100
101 output;
102
103 put PROCDAT _infile_ @46 OBS comma10.0 ' ' @60 DSN "---" ntime=mmss8.2; *optional;
104 end;
105 else input;
106 end;
107 else input;
108 if done then do;
109 put DATA_steps " DATA steps -- total process time " DATA_time = time11.2 ; *optional;
110 put SORT_steps " SORT steps -- total process time " SORT_time = time11.2 ; *optional;
111 put SQL_steps " SQL steps -- total process time " SQL_time = time11.2 ; *optional;
112 end;
113
114 run;
115
116 %mend log_IO_data;
117
118 option mprint;
119
120 %let log =
120! C:\applicazioni_SAS\a0032_L1\tariffe_rifiuti_2020\log\risultati_prima_analisi_a0032_estrazione
120! _ambiti_20210518_114553.txt ;
121 %let doc =
121! C:\applicazioni_SAS\a0032_L1\tariffe_rifiuti_2020\log\risultati_seconda_analisi_a0032_estrazio
121! ne_ambiti_20210518_114553.txt ;
122
123 %log_IO_data(log=&log, doc=&doc);
MPRINT(LOG_IO_DATA): data log_runtime_messy log_runtime(keep = dsn ntime ctime procdat obs);
MPRINT(LOG_IO_DATA): length logname f logline $200 dsn $32 PROCDAT $6;
MPRINT(LOG_IO_DATA): retain dsn obs;
MPRINT(LOG_IO_DATA): infile
"C:\applicazioni_SAS\a0032_L1\tariffe_rifiuti_2020\log\risultati_prima_analisi_a0032_estrazione_amb
iti_20210518_114553.txt" filename=f end=done;
MPRINT(LOG_IO_DATA): file
"C:\applicazioni_SAS\a0032_L1\tariffe_rifiuti_2020\log\risultati_seconda_analisi_a0032_estrazione_a
mbiti_20210518_114553.txt";
MPRINT(LOG_IO_DATA): *optional;
MPRINT(LOG_IO_DATA): logname = f;
MPRINT(LOG_IO_DATA): if logname ne lag(logname) then do;
MPRINT(LOG_IO_DATA): if line then put line "lines read";
MPRINT(LOG_IO_DATA): put //'-----' logname '------';
MPRINT(LOG_IO_DATA): line=0;
MPRINT(LOG_IO_DATA): end;
MPRINT(LOG_IO_DATA): input @;
MPRINT(LOG_IO_DATA): if index(_infile_, 'TIME NOTE: the data set') or index(_infile_, 'TIME
NOTE: DATA statement used (total precess time):') or index(_infile_, 'TIME NOTE: PROCEDURE SORT
used (total precess time):') or index(_infile_, 'TIME NOTE: PROCEDURE SQL used (total precess
time):') then do;
MPRINT(LOG_IO_DATA): input /;
MPRINT(LOG_IO_DATA): ctime = scan(_infile_,4,'');
NOTE: Variable "ctime" was given a default length of 32767 as the result of a function call. If
you do not like this, please use a LENGTH statement to declare "ctime".
MPRINT(LOG_IO_DATA): if index(ctime, ':') then do;
MPRINT(LOG_IO_DATA): if countc(ctime, ':') = 1 then ctime='0:'||ctime ;
MPRINT(LOG_IO_DATA): ntime = input(strip(ctime), time11.2);
MPRINT(LOG_IO_DATA): end;
MPRINT(LOG_IO_DATA): else ntime=ctime+0;
MPRINT(LOG_IO_DATA): if PROCDAT='DATA: ' then do;
MPRINT(LOG_IO_DATA): DATA_TIME+ntime;
MPRINT(LOG_IO_DATA): DATA_steps+1;
MPRINT(LOG_IO_DATA): end;
MPRINT(LOG_IO_DATA): else if PROCDAT='SORT: ' then do;
MPRINT(LOG_IO_DATA): SORT_TIME+ntime;
MPRINT(LOG_IO_DATA): SORT_steps+1;
MPRINT(LOG_IO_DATA): end;
MPRINT(LOG_IO_DATA): else do;
MPRINT(LOG_IO_DATA): SQL_TIME+ntime;
MPRINT(LOG_IO_DATA): SQL_steps+1;
MPRINT(LOG_IO_DATA): end;
MPRINT(LOG_IO_DATA): output;
MPRINT(LOG_IO_DATA): put PROCDAT _infile_ @46 OBS comma10.0 ' ' @60 DSN "---" ntime=mmss8.2;
MPRINT(LOG_IO_DATA): *optional;
MPRINT(LOG_IO_DATA): end;
NOTE: Line generated by the invoked macro "LOG_IO_DATA".
7 @46 OBS comma10.0 ' ' @60 DSN "---" ntime=mmss8.2; *optional; end; else input; end; else
---
161
7 ! input; if done then do; put DATA_steps " DATA steps -- total process time " DATA_time =
7 ! time11.2 ; *optional; put SORT_steps
ERROR 161-185: No matching DO/SELECT statement.

MPRINT(LOG_IO_DATA): else input;
MPRINT(LOG_IO_DATA): end;
NOTE: Line generated by the invoked macro "LOG_IO_DATA".
7 @46 OBS comma10.0 ' ' @60 DSN "---" ntime=mmss8.2; *optional; end; else input; end; else
                                                                                 ----
160
7 ! input; if done then do; put DATA_steps " DATA steps -- total process time " DATA_time =
7 ! time11.2 ; *optional; put SORT_steps
ERROR 160-185: No matching IF-THEN clause.

MPRINT(LOG_IO_DATA): else input;
MPRINT(LOG_IO_DATA): if done then do;
MPRINT(LOG_IO_DATA): put DATA_steps " DATA steps -- total process time " DATA_time = time11.2 ;
MPRINT(LOG_IO_DATA): *optional;
MPRINT(LOG_IO_DATA): put SORT_steps " SORT steps -- total process time " SORT_time = time11.2 ;
MPRINT(LOG_IO_DATA): *optional;
MPRINT(LOG_IO_DATA): put SQL_steps " SQL steps -- total process time " SQL_time = time11.2 ;
MPRINT(LOG_IO_DATA): *optional;
MPRINT(LOG_IO_DATA): end;
MPRINT(LOG_IO_DATA): run;

NOTE: Character values have been converted to numeric values at the places given by:
(Line):(Column).
5:82
NOTE: The SAS System stopped processing this step because of errors.
WARNING: The data set WORK.LOG_RUNTIME_MESSY may be incomplete. When this step was stopped there
were 0 observations and 14 variables.
WARNING: The data set WORK.LOG_RUNTIME may be incomplete. When this step was stopped there were 0
observations and 5 variables.
NOTE: DATA statement used (Total process time):
real time 0.07 seconds
cpu time 0.07 seconds


124
125 *Sintesi risultati;
126
127 proc means data=log_runtime mean max min sum;
128 class procdat dsn;
129 var ntime obs;
130 types dsn procdat procdat*dsn;
131 run;

NOTE: Writing HTML Body file: sashtml.htm
NOTE: No observations in data set WORK.LOG_RUNTIME.
NOTE: PROCEDURE MEANS used (Total process time):
real time 0.88 seconds
cpu time 0.56 seconds

 
It appears that this may only collect the information for Data step, Proc SQL and Proc sort procedures. If you are expecting to work with other procedures you need to look closely at the paper and the log for your procedures.

So, if my log has informations related to other procedures/steps could it cause errors? I thought it might just ignore those?

Thanks for the insights