Date: Fri, 14 Nov 2008 16:41:45 -0600
Reply-To: Mary <mlhoward@avalon.net>
Sender: "SAS(r) Discussion" <SAS-L@LISTSERV.UGA.EDU>
From: Mary <mlhoward@AVALON.NET>
Subject: Re: Call Execute usage/behavior on Macros
Content-Type: text/plain; charset="iso-8859-1"
Mark,
Thank you so much for your explanation; I will reread this several
times. I actually got brave and did my very first call execute
ever today! Despite over 20 years of SAS programming!
And it worked! Happy dance! BUT, I was really confused as
to why the output of all the put statements came first; that it
is making multiple passes is important to know, as it really isn't
the same as a subroutine despite trying to think of it that way.
-Mary
----- Original Message -----
From: Terjeson, Mark
To: SAS-L@LISTSERV.UGA.EDU
Sent: Friday, November 14, 2008 4:30 PM
Subject: Re: Call Execute usage/behavior on Macros
Hi,
As you have deduced already the issue is
purely "timing". Once you get a feel for
the sas macro parser making pass(es) through
the text to resolve as much as it can, and
then the resultant text substitutions and
macro storage of parts and pieces are done,
then the end resultant text goes to the
compiler/runtime.
Long story short, if you comment out the %PUT
from inside the %MACRO you will notice that
the warning message goes away. When the macro
parser first looks through the code inside the
%MACRO/%MEND it incurs a datastep and a %PUT.
It actively looks at that %PUT right then and
there and says, "I don't find a pre-set-up storage
for &cnt1 yet. And it hasn't got one yet at this
time. So it is correct. The datastep code text has
been parsed and all the macro references and
goodies get resolved, just as if you hand-resolved
them yourself, and the text substitutions have been
made, and then THAT customized code text gets sent
to the compiler. i.e. the CALL SYMPUT() is a datastep
instruction that has *not* been executed yet, so
the call symput() has *not* created the macro
variable storage yet. The call symput() macro variables
do not exist until AFTER the datastep has completed.
So as you can see the live %PUT didn't have a macro
variable container to fetch from until after the
datastep completed and only then did a container for
&cnt1 exist.
You will note that your datastep does indeed work
and complete successfully, and you see in the log
your values 1,25,101. Therefore your code actually
processes the code in sequence, -and- the values
are actually really there upon completion of each
of those passes. So during the compiler/runtime
execution everything was in order and results were
in order timingwise.
In your %MACRO there is no %GLOBAL or %LET, etc.
that would have created the storage container for
a macro variable called cnt1 at the time your %PUT
is incurred. If you placed a %GLOBAL or %LET statement
somewhere, you would then have gotten rid of the warning
about there not being a macro variable container at the
time the %PUT tried to find one. However, you would note
that the %PUT would complete successfully BUT would not
have a value yet to display. Remember, the macro parser
pre-substitutes all of the macro text and reference links
and then all of that replicated code text goes to the SAS
compiler and the datasteps get executed. During that first
datastep the CALL EXECUTE() sends its lines of text to
the code queue and after the datastep has completed, THEN
the code queued up gets submitted and run, so basically
your macro variable still haven't been created yet.
If your intention is to see what the value of the
created macro variable is, then you cannot fetch and
display it until AFTER it has been created and loaded.
So what you really want is a %PUT *after* it has been
created. Therefore, it is timing and you want a %PUT
after the CALL EXECUTE() has been executed, which got
queued up and not run until after the datastep. So,
the easy fix is to get the sequencing right, and have
the %PUT occur after the CALL SYMPUT, which just means
that if you put the %PUT into a CALL EXECUTE() line
just after the other CALL EXECUTE, then the %PUT would
occur after the &cnt1 got created and loaded and the
%PUT would find a container and the value to display.
i.e one of the best ways to debug CALL EXECUTE is to
comment out the CALL EXECUTE() and substitute a PUT
statement printing the entire line of text to the log.
If you did so, your original CALL EXECUTE text that
gets queued up would look like this:
%fam_data(file1 )
%fam_data(file2 )
%fam_data(file3 )
For CALL EXECUTE and SAS MACRO goodies, you can debug
by pretending to manually do the code text replacement
yourself. Because that way you actually can understand
what the compiler is going to see and execute. In other
words, you can work backwards to get this all working.
So to get the timing right what you really want is:
%fam_data(file1 )
%PUT cnt1 is >&cnt1<;
%fam_data(file2 )
%PUT cnt1 is >&cnt1<;
%fam_data(file3 )
%PUT cnt1 is >&cnt1<;
Which will work as intented.
Thus, now all you have to do is to create this text
going to the compiler. Merely pass the second line
with a second CALL EXECUTE() and it will automatically
interleave them as seen above.
Now the %PUT will look for and find the macro value
at the right time (after it is created and loaded).
I know this paper is overly simplistic for your level
of macro use already, but if you checked it out you
might get the *feel* for the timing aspects that may
or maynot have eluded your initial skilled adroitness.
http://www.pnwsug.org/Conference_2006/Procedings/PNWSUGotherfiles/PN21Ma
rkTerjesonMacro101.pdf
Hope this is helpful.
Mark Terjeson
Senior Programmer Analyst
Investment Management & Research
Russell Investments
253-439-2367
Russell
Global Leaders in Multi-Manager Investing
-----Original Message-----
From: SAS(r) Discussion [mailto:SAS-L@LISTSERV.UGA.EDU] On Behalf Of
dc353@hotmail.com
Sent: Friday, November 14, 2008 1:03 PM
To: SAS-L@LISTSERV.UGA.EDU
Subject: Call Execute usage/behavior on Macros
Hi,
This is a follow up on a previous post Macro Control problem. Both
Howard Schreirer and Ian Whitlock have helped with this development.
I have the following simplified example:
data f_name;
input fname : $12.;
cards;
file1
file2
file3
;
data file1; cnt = 1; run;
data file2; cnt = 25; run;
data file3; cnt = 101; run;
options mtrace mprint mlogic;
%macro fam_data (tmp_data);
data _null_;
set &tmp_data;
put 'cnt = ' cnt;
call symput ('cnt1',trim(left(put(cnt,best12.))));
run;
%put '&cnt = ' &cnt1;
%mend fam_data;
data _null_;
set f_name;
%let tmp_data = fname;
call execute('%fam_data('|| &tmp_data ||')');
* call execute('%nrstr(%fam_data('|| &tmp_data ||'))');
put 'test1 ' &tmp_data;
run;
I run the code first as shown and then change the Call execute
statement as indicated and run it again. I'm trying to better
understand what's actually going on and why &cnt1 doesn't resolve in
the first case but does resolve in the second even though cnt always
has the right value. I also notice that the put statement "PUT 'TEST1
&TMP_DATA; is being executed at different times relative to the macro
between the two different versions. Again, I'm trying to better
understand what's actually going on. While the second version is
doing what I want it sems the first version if modified could create a
new macro variable each time the macro is called. Some of my problem
is just about developing a basic understanding of how macros execute.
Thanks.
Here is the log:
1 data f_name;
2 input fname : $12.;
3 cards;
NOTE: The data set WORK.F_NAME has 3 observations and 1 variables.
NOTE: DATA statement used:
real time 0.01 seconds
cpu time 0.01 seconds
7 ;
8
9 data file1; cnt = 1; run;
NOTE: The data set WORK.FILE1 has 1 observations and 1 variables.
NOTE: DATA statement used:
real time 0.01 seconds
cpu time 0.01 seconds
10 data file2; cnt = 25; run;
NOTE: The data set WORK.FILE2 has 1 observations and 1 variables.
NOTE: DATA statement used:
real time 0.00 seconds
cpu time 0.00 seconds
11 data file3; cnt = 101; run;
NOTE: The data set WORK.FILE3 has 1 observations and 1 variables.
NOTE: DATA statement used:
real time 0.01 seconds
cpu time 0.01 seconds
12
13 options mtrace mprint mlogic;
14
15 %macro fam_data (tmp_data);
16
17 data _null_;
18 set &tmp_data;
19
20 put 'cnt = ' cnt;
21 call symput ('cnt1',trim(left(put(cnt,best12.))));
22
23 run;
24
25 %put '&cnt = ' &cnt1;
26
27 %mend fam_data;
28
29
30 data _null_;
31 set f_name;
32
33 %let tmp_data = fname;
34
35 call execute('%fam_data('|| &tmp_data ||')');
36 * call execute('%nrstr(%fam_data('|| &tmp_data ||'))');
37
38 put 'test1 ' &tmp_data;
39 run;
MLOGIC(FAM_DATA): Beginning execution.
MLOGIC(FAM_DATA): Parameter TMP_DATA has value file1
MPRINT(FAM_DATA): data _null_;
MPRINT(FAM_DATA): set file1;
MPRINT(FAM_DATA): put 'cnt = ' cnt;
MPRINT(FAM_DATA): call symput ('cnt1',trim(left(put(cnt,best12.))));
MPRINT(FAM_DATA): run;
MLOGIC(FAM_DATA): %PUT '&cnt = ' &cnt1
WARNING: Apparent symbolic reference CNT1 not resolved.
*****COMPARE THIS TO SECOND VERSION
'&cnt = ' &cnt1
MLOGIC(FAM_DATA): Ending execution.
test1 file1 ------------------------------>>>>>>
*****NOTICE WHERE THIS IS (FROM LINE 38)
MLOGIC(FAM_DATA): Beginning execution.
MLOGIC(FAM_DATA): Parameter TMP_DATA has value file2
MPRINT(FAM_DATA): data _null_;
MPRINT(FAM_DATA): set file2;
MPRINT(FAM_DATA): put 'cnt = ' cnt;
MPRINT(FAM_DATA): call symput ('cnt1',trim(left(put(cnt,best12.))));
MPRINT(FAM_DATA): run;
MLOGIC(FAM_DATA): %PUT '&cnt = ' &cnt1
WARNING: Apparent symbolic reference CNT1 not resolved.
'&cnt = ' &cnt1
MLOGIC(FAM_DATA): Ending execution.
test1 file2
MLOGIC(FAM_DATA): Beginning execution.
MLOGIC(FAM_DATA): Parameter TMP_DATA has value file3
MPRINT(FAM_DATA): data _null_;
MPRINT(FAM_DATA): set file3;
MPRINT(FAM_DATA): put 'cnt = ' cnt;
MPRINT(FAM_DATA): call symput ('cnt1',trim(left(put(cnt,best12.))));
MPRINT(FAM_DATA): run;
MLOGIC(FAM_DATA): %PUT '&cnt = ' &cnt1
WARNING: Apparent symbolic reference CNT1 not resolved.
'&cnt = ' &cnt1
NOTE: DATA statement used:
real time 0.00 seconds
cpu time 0.00 seconds
MLOGIC(FAM_DATA): Ending execution.
test1 file3
NOTE: There were 3 observations read from the data set WORK.F_NAME.
NOTE: CALL EXECUTE generated line.
1 + data _null_; set file1; put 'cnt = ' cnt; call symput
('cnt1',trim(left(put(cnt,best12.)))); run;
cnt = 1
NOTE: There were 1 observations read from the data set WORK.FILE1.
NOTE: DATA statement used:
real time 0.00 seconds
cpu time 0.00 seconds
2 + data _null_; set file2; put 'cnt = ' cnt; call symput
('cnt1',trim(left(put(cnt,best12.)))); run;
cnt = 25
NOTE: There were 1 observations read from the data set WORK.FILE2.
NOTE: DATA statement used:
real time 0.00 seconds
cpu time 0.00 seconds
3 + data _null_; set file3; put 'cnt = ' cnt; call symput
('cnt1',trim(left(put(cnt,best12.)))); run;
cnt = 101
NOTE: There were 1 observations read from the data set WORK.FILE3.
NOTE: DATA statement used:
real time 0.00 seconds
cpu time 0.00 seconds
*****************************************************************
END OF FIRST EXECUTION
*****************************************************************
40 data f_name;
41 input fname : $12.;
42 cards;
NOTE: The data set WORK.F_NAME has 3 observations and 1 variables.
NOTE: DATA statement used:
real time 0.00 seconds
cpu time 0.00 seconds
46 ;
47
48 data file1; cnt = 1; run;
NOTE: The data set WORK.FILE1 has 1 observations and 1 variables.
NOTE: DATA statement used:
real time 0.01 seconds
cpu time 0.01 seconds
49 data file2; cnt = 25; run;
NOTE: The data set WORK.FILE2 has 1 observations and 1 variables.
NOTE: DATA statement used:
real time 0.00 seconds
cpu time 0.00 seconds
50 data file3; cnt = 101; run;
NOTE: The data set WORK.FILE3 has 1 observations and 1 variables.
NOTE: DATA statement used:
real time 0.00 seconds
cpu time 0.00 seconds
51
52 options mtrace mprint mlogic;
53
54 %macro fam_data (tmp_data);
55
56 data _null_;
57 set &tmp_data;
58
59 put 'cnt = ' cnt;
60 call symput ('cnt1',trim(left(put(cnt,best12.))));
61
62 run;
63
64 %put '&cnt = ' &cnt1;
65
66 %mend fam_data;
67
68
69 data _null_;
70 set f_name;
71
72 %let tmp_data = fname;
73
74 * call execute('%fam_data('|| &tmp_data ||')');
75 call execute('%nrstr(%fam_data('|| &tmp_data ||'))');
76
77 put 'test1 ' &tmp_data;
78 run;
test1 file1
test1 file2 ----------------->>>>>> NOTICE HOW THESE ARE
WRITTEN TO LOG (FROM LINE 77)
test1 file3
NOTE: There were 3 observations read from the data set WORK.F_NAME.
NOTE: DATA statement used:
real time 0.01 seconds
cpu time 0.01 seconds
NOTE: CALL EXECUTE generated line.
1 + %fam_data(file1 )
MLOGIC(FAM_DATA): Beginning execution.
MLOGIC(FAM_DATA): Parameter TMP_DATA has value file1
MPRINT(FAM_DATA): data _null_;
MPRINT(FAM_DATA): set file1;
MPRINT(FAM_DATA): put 'cnt = ' cnt;
MPRINT(FAM_DATA): call symput ('cnt1',trim(left(put(cnt,best12.))));
MPRINT(FAM_DATA): run;
cnt = 1
NOTE: There were 1 observations read from the data set WORK.FILE1.
NOTE: DATA statement used:
real time 0.00 seconds
cpu time 0.00 seconds
MLOGIC(FAM_DATA): %PUT '&cnt = ' &cnt1
'&cnt = ' 1 ------------------>>>>>>>>>>>>>>>> NOTICE HOW
MACRO &CNT1 IS NOW RESOLVED
MLOGIC(FAM_DATA): Ending execution.
2 + %fam_data(file2 )
MLOGIC(FAM_DATA): Beginning execution.
MLOGIC(FAM_DATA): Parameter TMP_DATA has value file2
MPRINT(FAM_DATA): data _null_;
MPRINT(FAM_DATA): set file2;
MPRINT(FAM_DATA): put 'cnt = ' cnt;
MPRINT(FAM_DATA): call symput ('cnt1',trim(left(put(cnt,best12.))));
MPRINT(FAM_DATA): run;
cnt = 25
NOTE: There were 1 observations read from the data set WORK.FILE2.
NOTE: DATA statement used:
real time 0.01 seconds
cpu time 0.01 seconds
MLOGIC(FAM_DATA): %PUT '&cnt = ' &cnt1
'&cnt = ' 25
MLOGIC(FAM_DATA): Ending execution.
3 + %fam_data(file3 )
MLOGIC(FAM_DATA): Beginning execution.
MLOGIC(FAM_DATA): Parameter TMP_DATA has value file3
MPRINT(FAM_DATA): data _null_;
MPRINT(FAM_DATA): set file3;
MPRINT(FAM_DATA): put 'cnt = ' cnt;
MPRINT(FAM_DATA): call symput ('cnt1',trim(left(put(cnt,best12.))));
MPRINT(FAM_DATA): run;
cnt = 101
NOTE: There were 1 observations read from the data set WORK.FILE3.
NOTE: DATA statement used:
real time 0.00 seconds
cpu time 0.00 seconds
MLOGIC(FAM_DATA): %PUT '&cnt = ' &cnt1
'&cnt = ' 101
MLOGIC(FAM_DATA): Ending execution.
