peterprec Tracker

Re: Severe penalty for using MFILE?

peterprec — Wed, 01 May 2024 14:08:43 GMT

Looking at @yabwon 's code, I think it should be quadratic as you have 2 %do-loops with the same counter inside each other. Nice to see that theory and reality aligns. 🙂 And it still confirms the rather large penalty for using MFILE...

@Tom : Do you know something about the inner workings of the MFILE?

Re: Severe penalty for using MFILE?

peterprec — Wed, 01 May 2024 08:28:46 GMT

@yabwon - grid, sounds sick! 🙂 Perhaps you can run this a well:

%macro genCode(genlineOfCode);
    %if %nrbquote(&genlineOfCode)=%nrbquote() %then %let genlineOfCode=100;

    data _null_;
        %do i=1 %to &genlineOfCode;
            a=&i;
        %end;
    run;

%mend;

Would be interesting to see - and I'm still a little baffled why you don't see much penalty with the data _null_ code when both myself and @Patrick does... Any ideas?

Re: Severe penalty for using MFILE?

peterprec — Wed, 01 May 2024 06:37:45 GMT

I've now managed to run both test scripts, and their variations, on both SODA and in my work enviroment (SAS server, windows) and in all cases I can replicate the results shown in this thread.

Re: Severe penalty for using MFILE?

peterprec — Tue, 30 Apr 2024 17:45:18 GMT

@yabwon - good stuff! Your results baffled me...

So, however, I made the use case just a little different and only slightly more complicated:

%macro genCode(genlineOfCode);
    %if %nrbquote(&genlineOfCode)=%nrbquote() %then
        %let genlineOfCode=100;

    data _null_;
        %do i=1 %to &genlineOfCode;
            a=&i;
        %end;
    run;

%mend;

and then I get this (SODA environment):

So, to me, @ChrisHemedinger, it still looks like the MFILE is not behaving according to intention? Disagree? 🙂

Re: Severe penalty for using MFILE?

peterprec — Tue, 30 Apr 2024 12:11:36 GMT

Great post, @Patrick ! It completely confirms my observations. It aligns poorly with cause being the MFILE target written to a slow location, but supports that something in the MFILE implementations does not work as intended. Completely guessing here, it almost feels like MFILE writes one resolved programming statement/token at a time to disk (i.e., no buffering at all) while the rest of the execution sits and waits for the MFILE I/O to finish.

Re: Severe penalty for using MFILE?

peterprec — Tue, 30 Apr 2024 04:33:24 GMT

Thanks for the nice comment! I tried using RUN CANCEL in the script, however, it had no effect on execution time. I also used CALL EXECUTE and it does require a fair bit of rewriting the script because of the way it works compared to dosubl(), but the results were the same.

Sending the MFILE target to work doesn't change performance compared to TEMP - the two locations are also very much "neighbors"...

Re: Severe penalty for using MFILE?

peterprec — Tue, 30 Apr 2024 04:35:02 GMT

Thank you @ChrisHemedinger for taking your time to reply. Really appreciate it. I see your points and making sure you write to a fast location makes absolute sense. Supporting that is the observation that shifting the MFILE target, via the FILENAME statement, to DUMMY from TEMP removes any performance difference.

However, as a layman not knowing too much about the behind-the-scenes-stuff… I'm not buying it. 😊 I think there is a problem with the MFILE implementation. Reason being, that if I run this script in my work environment in batch, having set the location of the MFILE file to the exact same folder location as the .log file, you still see huge differences. And we must bear in mind that SAS, because of the MPRINT, writes character for character the exact same content to the log and to the MFILE target. But enabling MFILE, as the only difference, slows the process down enormously. And to me, that behavior make no sense, and I doubt that is the intention of the MFILE implementation.
I have also placed the MFILE target in WORK, but the performance is exactly the same as with using TEMP on FILENAME. That is expected, I guess, as the TEMP location points basically to the same location as WORK.

I tested in SODA to see whether what I observed in my work environment was linked to the setup at work or not. The results points to that it wasn’t but rather it points to the MFILE implementation being the culprit. Note: As a whole the SODA setup is so much faster than SAS at work, niiice, and less impacted by MFILE. I had hoped raising a ticket in the SODA environment would have been taken a bit better care of, but I’ll now make sure to push it through the work channels as well.

Severe penalty for using MFILE?

peterprec — Mon, 29 Apr 2024 18:04:06 GMT

I’ve noticed that when enabling the MFILE option, which is very handy in many situations ranging from debugging to producing production-ready programs, program execution time is severely impacted. Much more than the simple I/O operation of writing the MPRINT statements already being written to the program log would suggest. Depending on the complexity and amount of macro code to be resolved, this may cause the execution to take 5-7 times longer. And to be precise, I am only referring to adding the MFILE option on top of the MPRINT. I’ve coded a simple example in which the performance within SODA is ~2.5 times slower. I’ve noticed this behavior in the past, in local DM, SAS server, SAS EG, etc. applications., in Windows environments etc. It seems like a global issue with the MFILE implementation.

To investigate, I’ve also played around with the FILENAME statement (in which the MPRINT fileref is set) but it seems to have little impact.

Here is a snip of the proc print and means output

@Sas technical support? Anyone has any ideas?

The code used to test:

%macro test;
    %do i=1 %to 250;

        data t&i.;
            %do j=1 %to 100;

                do k&j.=1 to 5;
                    output;
                end;
            %end;
        run;

    %end;

    %do i=1 %to 250;

        data t&i.;
            %do j=1 %to 100;

                do k&j.=1 to 5;
                    output;
                end;
            %end;
        run;

    %end;
%mend;

%macro wmfile;
    filename mprint temp;
    options mprint mfile;
    %test;
    options nomfile;
%mend;

%macro womfile;
    options mprint nomfile;
    %test;
%mend;

data bench;
    length onbench $200;

    do run=1 to 3;
        do onbench='%wmfile', '%womfile';
            start=time();
            rc=dosubl(onbench);
            end=time();
            mark=end-start;
            output;
        end;
    end;
run;

proc print data=bench;
run;

proc means data=bench;
    class onbench;
    var mark;
run;

20 year SAS user, but first post here. Thanks for your time.