%PUT STATEMENT WONT PRINT TO LOG

[whs278]

I have a program with a lot of huge sorting procedures.  I would like to print messages to the log so I can easily check on the progress of the program while it's running.  I have written something to similar to the code below but when I run it, nothing gets printed to the log even after the PROC SORT procedure is finished.

%put SORT ED DATA BY KEYVAR;
proc sort data = ED_DATA;
  by KEYVAR;
run;

[jimbarbour]

There's probably an error of some kind higher up in the code, possibly a missing semi-colon.  Can you post more of your code?

If your log is in color (i.e. not a batch job), you can make the %PUT statement stand out more by adding the text, "NOTE:" before it.  See example, below.  This will colorize the text to a sort of light blue which will make it easier to spot.  Probably it's not working, just as you say, but sometimes it's just hard to spot.

Jim

%put NOTE: SORT ED DATA BY KEYVAR;
proc sort data = ED_DATA;
  by KEYVAR;
run;

[whs278]

Unfortunately, there is a lot of stuff before for that code so it's hard to pinpoint

/*----------------------------------------------------------------
/*  ORGANIZATION
/* - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -
/*
/*  FIRST CREATED ON: 03/28/2018 	
/*  CREATOR:    INITIALS      
/*
/*  CODE BORROWED FROM:
/*
/* - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -
/*  PROJECT:           CTE 
/*                     
/*
/*  PROGRAM FUNCTION: CREATE HSAP APPLICATION FILE 
/*                    WITH CTE PROGRAM INFORMATION
/*                    CREATE ANALYSIS VARIABLES
/*                    ADD CTE COURSE DETAIL VARIABLES
/*
/*
/*  DATA IN:  /data/production/data/Master/HSAP_APPS20072018
/*			  /data/projects/CTE/Data/Master/Programs/HSPCTES2
/*		      CTEIMSDV.CTEIMSSTUMA
/*
/*  DATA OUT: /data/projects/CTE/data/Master/Students/CTE_APPLICATIONS
/*            
/*  PRECEDING PROGRAM: /data/production/student/programs/master/STUCOHHSP20072018MA
/*  FOLLOWING PROGRAM: /data/projects/CTE/Master/CTE_REP1_SAMP
/*
/*  REVISIONS
/*  PROGRAMMER	DATE	 	DESCRIPTION
/*  JJK         01/03/2019  MERGE CTE COURSE DATA 
/*  JJK         02/20/2019  MATCH WITH UPDATED HSPCTES2 FILE 
/*                          THAT INCLUDES FLAGS FOR OTHER HSAP-CTE MATCHES
/*	JJK			09/13/2019  UPDATED WITH 2017 HSAP COHORT AND FOLLOW-UP THROUGH 2017-2018
/*	JJK			02/13/2020  UPDATED WITH REVISED VERSION OF THE HSAP-CTE LINK FILE
/*                          NOTE NEW VARIABLE NAMES ON HSAP-CTE LINK FILE
/*                          NEW FILE NAME (CTE_APPLICATIONS) TO AVOID CONFUSION WITH PREVIOUS VERSION
/*  JS          06/26/2020  UPDATED CTESCHGRP TO SEPARATE DISCONTINUED HSAP-CTE FROM NEVER CTE     
/*  WHS         06/26/2020  CHANGED INPUT DATSET TO UPDATED VERSION OF HSAP_APPS20072018                 
/*	WHS			11/03/2020 	CHANGED IF STATEMENT TO CTEPOSPERMAT=2 FOR MATCHENRDAN VARIABLE
/*  WHS			11/05/2020	CREATE MACRO VARIABLE FOR NSC VARIABLES AND ADDED IT TO DUMVR ARRAY
/*  WHS			11/11/2020	CREATE MACRO VARIABLE FOR CNY VARIABLES AND ADDED IT TO DUMVR ARRAY
/*  WHS			03/05/2021  MERGE APP DATA WITH IMS (I.E. INTERNSHIP) DATA
/*	WHS			04/08/2021	UPDATED DO STATEMENT IN %CTECRS MACRO TO INCLUDE 2019 CTE-COURSE DATA
/*  WHS			05/14/2021  ADD IF STATEMENT TO CTE COURSE CREDIT VARIABLES FOR INCOMPLETE COHORTS
/*	JJK			07/20/2021	UPDATED TO INCLUDE DATA THROUGH 2020 
/*							COMMENTED OUT SUPLEMENTAL CTE COURSE DATA PENDING FURTHER DISCUSSION
/*  WHS			08/04/2021  ADDED LABEL FOR MATCHPRGM: UNMATCHED AFTER MAIN ROUND
/*
/* COMMENTS:  WE SHOULD MAKE IT CLEAR THAT MATCHPRG = MATCHPRGFIN WHEN NO MAIN ROUND MATCH
/*			  ESTIMATED RUN TIME PER HSAP_APPS SORT: 6-8 MINUTES
/*
/* - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -*/
%PUT LAST RUN: &SYSDATE;
OPTIONS NOCENTER PAGESIZE=62 LINESIZE=200 MERGENOBY=WARN ; 
OPTIONS ERRORS=50 ;
OPTIONS NOMPRINT ;
OPTIONS FMTSEARCH=(STUPROUT.STUFORMATS) ;
OPTIONS NOSYMBOLGEN NOMLOGIC;  **** Use to diagnose macro problems ;
/* - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -*/

LIBNAME STUPROMA  '/data/production/student/data/master';
LIBNAME STUPRORW  '/data/production/student/data/raw';
LIBNAME STUPROS1  '/data/production/student/data/step1';
LIBNAME STUPROS2  '/data/production/student/data/step2';
LIBNAME STUPROUT  '/data/production/student/util' ;
LIBNAME SCHPROS1  '/data/production/school/data/step1';

LIBNAME CTEPRGDV    '/data/projects/CTE/Data/development/CTEPRG';
LIBNAME CTESTUMA    '/data/projects/CTE/Data/Master/Students';
LIBNAME CTESTUR1    '/data/projects/CTE/Data/Report 1';
LIBNAME CTEPRGMA    '/data/projects/CTE/Data/Master/Programs';
LIBNAME CTECRSMA    '/data/projects/CTE/Data/Master/Courses';
LIBNAME CTEIMSDV  '/data/projects/CTE/Data/development/CTEIMS'  ;

LIBNAME DEVJJKCT  '/data/development/jjk/CTE' ;

TITLE1 'RESEARCH ALLIANCE FOR NEW YORK CITY SCHOOLS' ;
TITLE2 'HSAP APPLICATION FILE WITH CTE PROGRAM INFORMATION' ;

/*WHS NOTE: STUCRSCTES2 UPDATED TO 2019-2020 SCHOOL YEAR*/
%LET CTELASTYR = 2020 ; 

PROC FORMAT ;
  VALUE CTESCHTYPF
    1 = '1:CTE HS'
    2 = '2:ACADEMIC HS'
    ;
  VALUE CTEPRGCURF
    0 = '0:PHASED OUT'
    1 = '1:PERSISTED'
    2 = '2:PHASED OUT'
    ;
  VALUE CTESCHGRPF
    1 = '1:CTE HS (PERSISTING)'
    2 = '2:ACAD HS (PERSISTING)'
    3 = '3:PHASED OUT'
    9 = '9:NO CTE'
    ;
RUN;

/* PREPARE HSAP APPLICATION DATA FOR MERGING WITH HSAP-CTE PROGRAM DATA */
%PUT SORT HSAP_APPS DATA BY APPLICATION PROGRAM;
PROC SORT DATA=STUPROMA.HSAP_APPS20072018 OUT=CTE_APPS ;
  BY HSCOHG9A PROG ;
RUN;

[jimbarbour]

OK, excellent, thank you.  I don't see anything obvious that is wrong.

Now, can you post the log?  Please, as you are with the SAS programs (thank you!), use the below indicated icon to post the log.

There should be some messages that precede the %PUT statement, something like 

DEVJJKCT assigned sucessfully

There should also be some SAS generated statements after the Format procedure.  

If the above normal log information is present, then we know that the log is working up to the point where the %PUT occurs.

Jim

[whs278]

Thanks, for the quick reply.

I just realized that it does actually print to the log after the PROC SORT is completed. Sorry for the mistake.

Is there anyway to get it to print to the log before the PROC SORT procedure starts?

[jimbarbour]

As long as the %PUT is before the Sort, then it is correctly placed.  SAS can be odd sometimes in terms of when it writes what to the log.  We're just going to have to play with it a bit.  We should see if you're options are set to WRITE=IMMEDIATE, which may help, and we can try moving the %PUT to inside the Proc Sort, before the BY statement.  Placement may make a difference; I don't know; I'm just trying things here.

Lastly, we could make the %PUT statement write multiple lines which may force SAS to write it out sooner, depending on how much SAS is buffering the log (assuming that SAS is buffering).

In order to tell whether you are operating under WRITE=IMMEDIATE or WRITE=BUFFERED, please run the following and post the log:

PROC  OPTIONS OPTION=LOGPARM;
RUN;

Jim

[whs278]

This is what I get....

SAS (r) Proprietary Software Release 9.4 TS1M2

LOGPARM=WRITE=BUFFERED ROLLOVER=NONE OPEN=REPLACE
specifies when SAS log files are opened, closed, and according to the LOG= system option, how they are named.
NOTE: PROCEDURE OPTIONS used (Total process time):
real time 0.00 seconds
cpu time 0.00 seconds


Can you change to WRITE=IMMEDIATE for one SAS program or does this have to be set up in the system?

Perhaps writing a macro similar to the one ballardw suggested is my best option.

[jimbarbour]

---

@whs278 wrote:
LOGPARM=WRITE=BUFFERED ROLLOVER=NONE OPEN=REPLACE

Can you change to WRITE=IMMEDIATE for one SAS program or does this have to be set up in the system?

Perhaps writing a macro similar to the one ballardw suggested is my best option.

---

If you're submitting a batch job (command line, shell script, etc), then yes.  With Display Manager (PC SAS), Enterprise Guide, and SAS Studio, generally no.  The Admin has to set that up.  

In the mean time, try this:

%PUT  NOTE-  ;

Place that statement after your existing %PUT.  Repeat that statement five times, all after your original %PUT. 

I'm assuming here that you have added "NOTE:" to your original %PUT.  The "NOTE: " induces colorization and makes things easier to see.  If you for some reason don't want to add "NOTE: ", then delete "NOTE- " from the SAS code I posted above.

Hopefully a few "blank" %PUT statements will cause SAS to write to the log before the sort.  If not, we could try a macro as @ballardw suggests.

Jim

[whs278]

Unfortunately, adding %put statements after the initial statement didn't work.

[jimbarbour]

So, neither the %PUT or the SLEEP worked?  Yipes!  I wonder what the buffering parameters are on your system.

This is very unusual behavior.  M2 is a little bit old (7 years), so maybe that's it?  I've been using M4, M5, and M6 over the last several years.

Maybe try @ballardw's macro idea?  or try 25 %PUT statements. See macro, below.  This is kind of ridiculous though, just to get SAS to do what it should have been doing all along.

%MACRO	Blank_Line(Lines);
	%LOCAL	i;
	%IF	%BQUOTE(&Lines)	=	%BQUOTE()	%THEN
		%LET	lines	=	1;

	%DO	i				=	1	%TO		&Lines;
		%PUT	NOTE-  ;
	%END;
%MEND	Blank_Line;

%Blank_line(25);

Jim

[jimbarbour]

If my first suggestion in my most recent prior post doesn't do what you need, then try this:

%PUT	NOTE:  Intiating SORT of SAShelp.Cars %Get_Date %Get_Time;
%LET	Sleep_Time	=	%SYSFUNC(SLEEP(1,1));

PROC	SORT	DATA=SAShelp.Cars
				OUT	=WORK.Cars;
		BY		MPG_Highway;
RUN;

I'm adding a SYSFUNC(SLEEP(1,1)) after the initial %PUT.  This puts the job to "sleep" (suspends execution) for 1 second (on Windows; the settings are different for UNIX or z/OS).  Hopefully, this will cause the log statements to be written in the order we want.

Jim

[whs278]

Unfortunately, this didn't work.

[Cynthia_sas]

Hi:

In this configuration of options in SAS 9.4 M7::

I find everything works as expected as shown below. With and without NOTE in the %PUT:

Tech Support can test on older versions of SAS and probably on the same operating system. What you see is odd behavior, I can't explain it.

Cynthia

[jimbarbour]

@whs278, 

Make sure you try it at least once with NOTE:  (case sensitive, must be upper case) as part of your %PUT.  I've seen SAS handle %PUT with and without NOTE: differently.

Jim

[ballardw]

---

@whs278 wrote:
Thanks, for the quick reply.

I just realized that it does actually print to the log after the PROC SORT is completed. Sorry for the mistake.

Is there anyway to get it to print to the log before the PROC SORT procedure starts?

---

It might be worth experiment with using a data _null_ step and PUT or PUTLOG there instead of the macro %put if the actual location in the log is critical. Yes the log has more text from the data step.

data _null_;
   put "this is the text I want in the log";
run;

Or maybe a dummy macro that when executed only shows the macro invocation including your text:

%macro Message(text);
data _null_;
run;
%mend;

%Message(this is the text I want in the log);

%Message(Another bit of text to display);

A more creative name than Message might even help readability of your log.