JSON File is locked error

[texasmfp]

Thanks to input from this forum, I developed a nice JSON call routine to extract data from the Census Bureau.  The data is too large to call at once, so it sits in a macro that repeats the calls by varying a value and appends the results to eventually build a complete database.  I also developed a trap that deals with two issues: there is no data to draw for that value (SYSLIBRC=2050601) or, there was an issue with the call (internet interruption or Census server too busy, etc - SYSLIBRC NE 0)).  The trap tosses the values for latter into a database, which the program loops back to retry until all calls are good.  It normally works without flaw.  However, I recently noticed a weird error while watching the log.  I got the "lock is not available" error.  I was running two iterations of the program at the same time (each in its own SAS session and drawing data for different time periods.  64b SAS 9.4 in a Windows environment).  The same error appeared in both logs for the same number of calls at the same time.  It is not an error that is caught by the trap (i.e., here the SYSLIBRC =0).  The error cascades for about 6 loops, somehow finds its footing again and continues without error.  So, in the final database, the data for those 6 calls is not there and my traps are empty - I would not have known the data was missing. 

I have two goals here: 1) understand why this occurred (shared resources, external conflict, ???) and 2) design a trap to put the API call value in with the others for a retry, or an alert so I need to run the program again.  I do need to occasionally run the program in two or more simultaneous sessions (pulling from different time periods).

Here is the macro loop

data _null_;
  time="&period";
  CTY_CODE="&country";
  I_COMMODITY="&product*";
  length url $500;
  url = cats('https://api.census.gov................
  );
   rc=filename('in',url,'url');
run;

filename json temp;
%let rc=%sysfunc(fcopy(in,json));
libname json json;

%if &syslibrc ne 0 %then %do;
filename json temp;
%let rc=%sysfunc(fcopy(in,json));
libname json json;
%end;

%if &syslibrc ne 0 %then %do;
data next;
  parm2=&product;
  reason=&syslibrc;
run;

proc append force base=redo data=next;
run;

%goto exit;
%end;

proc copy inlib=json out=work; 
run;

proc append force base=impdetl data=ROOT;
run;

the errors in the log.

MPRINT(GET_EXAMPLES): filename json temp;
MLOGIC(GET_EXAMPLES): %LET (variable name is RC)
MPRINT(GET_EXAMPLES): libname json json;
NOTE: JSON data is only read once. To read the JSON again, reassign the JSON LIBNAME.
NOTE: Libref JSON was successfully assigned as follows:
Engine: JSON
Physical Name: e:\SAS Temporary Files\_TD1676_DESKTOP-575EP3T_\#LN01071
SYMBOLGEN: Macro variable SYSLIBRC resolves to 0
MLOGIC(GET_EXAMPLES): %IF condition &syslibrc ne 0 is FALSE
SYMBOLGEN: Macro variable SYSLIBRC resolves to 0
MLOGIC(GET_EXAMPLES): %IF condition &syslibrc ne 0 is FALSE
MPRINT(GET_EXAMPLES): proc copy inlib=json out=work;
MPRINT(GET_EXAMPLES): run;
NOTE: Copying JSON.ALLDATA to WORK.ALLDATA (memtype=DATA).
NOTE: BUFSIZE is not cloned when copying across different engines. System Option for BUFSIZE was used.
ERROR: A lock is not available for WORK.ALLDATA.DATA.
ERROR: File WORK.ALLDATA.DATA has not been saved because copy could not be completed.
NOTE: Copying JSON.ROOT to WORK.ROOT (memtype=DATA).
NOTE: BUFSIZE is not cloned when copying across different engines. System Option for BUFSIZE was used.
ERROR: A lock is not available for WORK.ROOT.DATA.
ERROR: File WORK.ROOT.DATA has not been saved because copy could not be completed.
NOTE: Statements not processed because of errors noted above.
NOTE: PROCEDURE COPY used (Total process time):
real time 0.00 seconds
cpu time 0.01 seconds
NOTE: The SAS System stopped processing this step because of errors.
ERROR: A lock is not available for WORK.IMPDETL.DATA.
MPRINT(GET_EXAMPLES): proc append force base=impdetl data=ROOT;
MPRINT(GET_EXAMPLES): run;
NOTE: Statements not processed because of errors noted above.
NOTE: PROCEDURE APPEND used (Total process time):
real time 0.00 seconds
cpu time 0.00 seconds
NOTE: The SAS System stopped processing this step because of errors.

 Thanks

[Tom]

That is NOT saying the JSON file is locked.  It is saying the SAS dataset you are trying to create from the JSON file is locked.

How did you run that code?  Are you running SAS interactively?  Did you happen to open the WORK.ROOT dataset to look at it in something like FSVIEW? that has locked the file?  If so then close the file before running the program again.

[texasmfp]

Tom:  no, I did not open any datasets to look at anything.  In fact, I was doing nothing, not touching the mouse or keyboard -nada.

Not sure what you mean by interactively.  This was not a batch file that was submitted, if that it what you mean.  Thanks  

[Tom]

Is the problem reproducible?  If you start a new SAS session and run the same code do you get the same error?  Perhaps there is some backup process that just happened to lock that file when you ran.

If it is reproducible perhaps the trouble is the JSON text actually has a structure that SAS sees as defining a ROOT dataset that conflicts with the default ROOT dataset that it always makes.

If you look at the actual JSON do you see the word ROOT in there?

[texasmfp]

In the code, ROOT only appears in the append statement:

proc append force base=impdetl data=ROOT;
run;

In the log, it is apparent that ROOT appears twice, before the append statement, it is created by SAS. 

NOTE: Copying JSON.ROOT to WORK.ROOT (memtype=DATA).
NOTE: BUFSIZE is not cloned when copying across different engines. System Option for BUFSIZE was used.
ERROR: A lock is not available for WORK.ROOT.DATA.
ERROR: File WORK.ROOT.DATA has not been saved because copy could not be completed.

ROOT and the ALLDATA dataset are generated, as far as I know, in the following code.  

filename json temp;
%let rc=%sysfunc(fcopy(in,json));
libname json json;

As far as reproducing the error, my main goal is to set up an alert or trap for when this apparent glitch happens.  I am not concerned about reproducing it, just trapping it when it does happen.  Otherwise, the only way to see if the error can be reproduced is to scan the log file.  The program loops for 371 calls and takes two hours to run.  

[Tom]

That is what is in the SAS code.  If the JSON file is going to create a ROOT dataset that will be determined by the text in the JSON file itself, not by the SAS code.

[Kurt_Bremser]

Since this happens on a toybox (Windows), I'd say some kind of anti-virus interferes by scanning a newly created dataset file.

[texasmfp]

Thanks Kurt.  However, I put SAS on the AVs exclusion list 9 months ago.  It runs freely.

Diagnosing is helpful, but is more importantly, I am hoping someone can give me a few hints on how to trap and save the call value (in this case it happens to be the I_COMMODITY value) for that fatal loop, so that I can retry that call again later in the program.

[Kurt_Bremser]

Set SYSCC to 0 before the crucial step(s), and check it after. Make sure you don't have another issue before your loop starts (have a clean log).

Another culprit which came to my mind is some kind of backup which reads the file at the moment.

[Patrick]

The following is not addressing the not yet determined root cause of the locking issue but is code that eventually will help to circumvent negative effects if locking occurs. 

/*%local sv_dlcreatedir;*/
%let sv_dlcreatedir=%sysfunc(getoption(dlcreatedir));
options dlcreatedir;
libname my_work "%sysfunc(pathname(work))/my_work" filelockwait=600;
options &sv_dlcreatedir;

proc copy inlib=json out=my_work; 
run;
proc append force base=my_work.impdetl data=my_work.ROOT;
run;

The main thought: Create a sub-folder under the WORK directory and define a libname to it with option filelockwait set to the maximum (=SAS trying for up-to 600 seconds to access a file before throwing a lock not available error). The current theory is that some external process like a virus scanner or a backup process is locking the file. If so then an up-to 600 seconds wait should be more than enough to avoid such locking conflicts. 

I still would add the error checking you had in mind to capture locking issues. 

Other or additional potential measures for adding robustness to your code:

- Create individually named target tables so they are always new (like base name and some counter)

- If you can issue OS commands (XCMD set) then delete the target table via OS command prior to creating a new copy (like: rm -f %sysfunc(pathname(work))/alldata.sas7b* )

data _null_;
  rc=system("rm -f %sysfunc(pathname(work))/alldata.sas7b*");
run;

[s_lassen]

You say that you handle some other errors like this

The trap tosses the values for latter into a database, which the program loops back to retry until all calls are good.

Why don't you try the same for your program execution, something like

data _null_;
  time="&period";
  CTY_CODE="&country";
  I_COMMODITY="&product*";
  length url $500;
  url = cats('https://api.census.gov................
  );
   rc=filename('in',url,'url');
run;

filename json temp;
%let rc=%sysfunc(fcopy(in,json));
libname json json;

%if &syslibrc ne 0 %then %do;
filename json temp;
%let rc=%sysfunc(fcopy(in,json));
libname json json;
%end;

%if &syslibrc ne 0 %then %do;
data next;
  parm2=&product;
  reason=&syslibrc;
run;

proc append force base=redo data=next;
run;

%goto exit;
%end;

%let syscc=0; /* so far, so good */
proc copy inlib=json out=work; 
run;

proc append force base=impdetl data=ROOT;
run;

%if &syscc>4 %then %do;  /* SYSCC=4 is a warning, we will assume that's OK */
/* I assume this is your code to repeat the call later, copied from above */
data next;
  parm2=&product;
  reason="&syserrortext"; /* or maybe some other informative value? */
run;

proc append force base=redo data=next;
run;

%goto exit;
%end;

I am not sure why your code sometimes fails, it sounds like an earlier iteration did somehow not let go of the data, but it may be something else. Of course, this will only work if the datasets NEXT and REDO are not also locked.

[texasmfp]

Update:  First, thanks to all who have shared their insight.  I really appreciate this forum.  Under the maxim that the simplest solutions are the often the best, I took Patrick's suggestion to incorporate the FILEWAITLOCK option.  I noticed that an existing log file created to record the time for each loop and the # of records pulled skipped logging a record when the locked file error occurred.  So I also created a simple trap that compares the total number of primary called loops (fixed at 373) to the count of the log file.  I now get a text if they are not a match, including the # of missed loops, another if its all good.  While I still need to rerun the program, at least now I know when there is an issue.  With that trap in place, I uncovered a new flaw, which I also fixed.  By shear coincidence, one failed call was for the plug value of "07".  However, when that failed call is added to the redo file, it is added as a numeric 7.  In the API call, there is a world of difference in calling for 7* versus 07*.  7* is too big and keeps failing.  Had I not encountered the file lock, I would never have known.  For now, between my missed call trap, Patrick's FILEWAITLOCK approach, and the new flaw patch, it appears to be working - at least six hours in (that is 3 near two-hour cycles with 115 more cycles to go).  I also suspended the AV software's daily scans, which were running at the same time as the errors and, were set for deep scans.  I also am running only one instance of the program to avoid any shared resources issues.  After I am done building out the 10-year database, I will try Kurt and s_lassen's suggestion to use SYSCC.    

As to the cause, jury is still out but I suspect the AV scan as several have suggested.  I will circle back and do more troubleshooting by running the program with two instances and then running it while running the AV scans.  

Tom:  

I was able to reproduce the issue.  In fact, there were more errors the next night.  I also noticed some bizarre behavior in my log window of one of the two programs.  One program started about a 1/2 hour before the other and, shortly after starting, had a change in the font/typeface/boldness etc in the log window.  Here is a side by side view of the log in both programs log windows:

The one on the left originally had the normal font/look as the one on the right.

It subsequently started to have greyed out areas that blocked most of the log screen's acreage.  Notice also the wavy corners of the greyed out areas:

Not sure what to make of it.  Perhaps it is an indicator of a shared resource issue.  I have since sent the log to print to file. 

Again, thanks to all.  I will update in early 2023.