Operating System - OpenVMS
cancel
Showing results for 
Search instead for 
Did you mean: 

RMS-E-RSA, record stream currently active

 
Klaus Heim
Advisor

RMS-E-RSA, record stream currently active

A Pascal image crashes with "RMS-E-RSA, record stream currently active" during writeln on sys$output. The image is started with:

RUN /DETACH /NODEBUG -
/PROC=bstr -
/INP=LVS$MANAGER:bstr.COM -
/OUT=LVS$LOG:bstr.LOG -
/PRIV=(SHARE) -
/PRIO=8 -
SYS$SYSTEM:LOGINOUT

and lvs$manager:bstr.com contains:

$ show time
$ run/nodebug lvs$system:bstr

The image works completly synchronous. Wait for a trigger, so some work and some logging to sys$output. That's all. No Threads, no ASTs.

We also had the same error in other PASCAL images which run as batch job.
12 REPLIES 12
Klaus Heim
Advisor

Re: RMS-E-RSA, record stream currently active

The attachment contains a part of the PASCAL listing (line 726).
P Muralidhar Kini
Honored Contributor

Re: RMS-E-RSA, record stream currently active

Hi Klaus,

What is the VMS & RMS version ?

Check the following link -
http://www.openvms.org/stories.php?story=06/04/17/0326101

It talks about fix for a scenario in which the "RMS-E-RSA, record stream
currently active" error could occur. Check whether this is applicable in
your case.

>> some logging to sys$output.
Will the problem occur even if we direct the output to a file rather than
SYS$OUTPUT ?

Hope this helps.

Regards,
Murali
Let There Be Rock - AC/DC
Klaus Heim
Advisor

Re: RMS-E-RSA, record stream currently active

Hi P Muralidhar Kini,

It is OpenVMS V8.3-1H1. Your link describes a problem in V7.3-2 and CRTL. I don't known if PASCAL writeln (pas$writeln2) calls CRTL. I did not use pthread. The problem looks like two threads simultaneously write to sys$output.

>>>Will the problem occur even if we direct the output to a file rather than
SYS$OUTPUT ?

I never test to change the output device. In my opinion the logfile is the best solution for a detached process.

Klaus Heim
Hoff
Honored Contributor

Re: RMS-E-RSA, record stream currently active

The snippet of Pascal code shown isn't enough code to figure out what's going on, and seven lines is nowhere near enough to try to reproduce the problem.

You'll want to run the application in the detached process under the debugger, and debug your code.

Here's how to get the debugger on-line for this case:

http://labs.hoffmanlabs.com/node/803

Log files are adequate for after-the-fact analysis and dump files and integrated debugging can provide better insight into the run-time environment. For debugging problems live, the VMS debugger is a typical choice, either directly operated by a programmer with source access, entering commands directly or via debugging scripts to test for and capture an occurrence of an error in a more complex application, or a debugger session activated by the application upon unhandled error, or (as part of integrated debugging) entirely under program control by the running program itself.

Having done support from log files for years, the availability of a process dump or (better) a debugger session and debugger-generated contextual dump (and preferably with integrated debugging) automatically mailed over to me (or mailed to a crash scanner, when there are higher volumes of errors) when the application tips over makes the limited support resources available rather more efficient.

Definitely also get the current ECOs loaded here, as VMS can sometimes be pretty wonky without those.

Opening a file twice is entirely possible within one process context, BTW. Works nicely for various requirements, too.

Repost. ITRC failed to post again. Also just noticed that ITRC is clipping its text (in some browsers?) when you reply to posts. Check the posting date to the right of the "Question" subheader when you're replying.
John Gillings
Honored Contributor

Re: RMS-E-RSA, record stream currently active

Klaus,
Not a lot to go on, but there's a few things you can look at.

First, Pascal does its own I/O, so the CRTL doesn't enter into the picture (as can be seen from the traceback).

I'm curious as to why you're closing OUTPUT - that seems odd to me, but is unlikely to be a contributing factor. Normally I'd expect the opening and closing of "special" files like INPUT and OUTPUT to be left in the hands of the language.

RSA is most commonly a result of recursion inside an active WriteLn. For example:

WriteLn('result of my function: ',MyFunction(some,args));

...
FUNCTION MyFunction(...)
BEGIN
...
WriteLn('somthing');
...
END;

So, the caller has commenced a WriteLn operation, then MyFunction has attempted start another one, before the first has finished.

Your traceback shows PTHREAD$RTL, so this could also be the result of one thread being interrupted in the middle of a WriteLn, and another thread attempting to perform one.

Examine your uses of WriteLn and try to eliminate any potential interrupts. In the above example, this could be done by removing the function call from the argument list of WriteLn, like this:

ResultString='result of my function: ' + MyFunction(some,args);
WriteLn(ResultString);

For the threaded case, depending on the copmplexity of your code, it may be necessary to make your own WriteLn function with a semaphore or lock protecting it from being reentered by another thread while active. If you have a small number of independent threads, give each its own output file, pointing to the same device and let the OpenVMS device driver deal with any conflicts.
A crucible of informative mistakes
Klaus Heim
Advisor

Re: RMS-E-RSA, record stream currently active

John,

thanks. It's a great example.

>>>Your traceback shows PTHREAD$RTL, so this could also be the result of one thread being interrupted in the middle of a WriteLn, and another thread attempting to perform one.

My program didn't use pthreads at all. In my opinion in a multiprocessor environment every image is initialized from pthread$rtl.
Is my opinion wrong?

In my mind the problem isn't in my program, because there is no asychnronously logic or other interrupt. It should be something in PAS$RTL similar to CRTL in V7.3-2.

I've included the whole PASCAL source. The source contains only a few writeln statements. I make a bet, that the problem is not in the source.

>>>I'm curious as to why you're closing OUTPUT - that seems odd to me, but is unlikely to be a contributing factor.

I close OUTPUT when there is nothing to do and extent OUTPUT after trigger. I've implemented this to flush the logfile when one cycle is done.
abrsvc
Respected Contributor

Re: RMS-E-RSA, record stream currently active

It has been a while for me for pascal programming, but a few questions arise:

1) You are using writeln to write to "DSTR" and are extend(ing) and close(ing) output.

2) Both streams end up pointing to the log file correct? The OPEN for DSTR is not in the code you posted.

3) If the intent of the extend is to make sure that the file is flushed, perhaps an RMS $FLUSH would be more appropriate?

4) File "extend" operations are fairly expensive and perhaps on the new hardware the relative cost is higher and thus sets up the seemingly parallel operations.

There is nothing blatently wrong in the code set up that I can see. This problem appears to be a synchronization issue between file operations that is occurring behind the scenes. If the BSTR file and the output are actually 2 channels to the same file, it is possible to see the RSA error.

Hope this helps a bit.

Dan
Klaus Heim
Advisor

Re: RMS-E-RSA, record stream currently active

Hi Dan,

>>>1) You are using writeln to write to "DSTR" and are extend(ing) and close(ing) output.

Yes.
>>>2) Both streams end up pointing to the log file correct? The OPEN for DSTR is not in the code you posted.

Yes.
>>>3) If the intent of the extend is to make sure that the file is flushed, perhaps an RMS $FLUSH would be more appropriate?

Yes. Close/Extend is easy to code. $FLUSH is a little bit complicated.

>>>4) File "extend" operations are fairly expensive and perhaps on the new hardware the relative cost is higher and thus sets up the seemingly parallel operations.

That's a good aspect. I think there is a seemingly parallet operation. But I also think, that it is not the extend operation. We also had this problem in other PASCAL programs, which run in batch mode. These programs do there job and end without close/extend. And there is the same error.

>>>This problem appears to be a synchronization issue between file operations that is occurring behind the scenes.

Right, that's my opinion.
John Gillings
Honored Contributor

Re: RMS-E-RSA, record stream currently active

Klaus,

As a (human language) monolingual, I can't read your comments, so I don't know what the program is doing. However, having spent many years in language support, I know that it's extremely rare to that a program bug is the fault of the RTL. When they do occur, it's usually CRTL. Of all the OpenVMS languages, Pascal is probably the hardest to prove an RTL bug against.

As Mr Sagan says about extraordinary claims... I've yet to see any extraordinary evidence!

I'm not happy about all those CLOSE(OUTPUT) statements, especially with ERROR:=CONTINUE (why was that coded in the first place?). You're reporting an error on OUTPUT, so don't you think you should be checking STATUS rather than ignoring it? Perhaps the real problem occured in one of those ERROR:=CONTINUE calls and the subsequent WriteLn is a victim?

Skinning this cat a different way. Since you talk about flushing data, presumably you want an external process to be able to see the contents of the log file while it's being written? If that's the case, there's a MUCH better way to do that.

First strip out ALL the CLOSE and EXTEND calls in your code, just use WriteLn to send data to SYS$OUTPUT and ignore the needs of other processes. Let THEM do the work!

In the DCL that runs your program try this:

$ OPEN/WRITE/SHARE=WRITE LOG YOUR_LOG_FILE.TXT
$ DEFINE/USER SYS$OUTPUT LOG
$ RUN YOUR_PROGRAM


SYS$OUTPUT is now have a shared write, process permanent log file.

Any time you want to see the up-to-date contents of the log from another process, do this:

$ OPEN/APPEND/SHARE=WRITE LOG YOUR_LOG_FILE.TXT
$ CLOSE LOG
$ TYPE YOUR_LOG_FILE.TXT

Since you've opened the file as SHARED with APPEND intent, RMS will force your running process to update the EOF. You can now TYPE or EDIT/READ, or any other shared read operation on the file up to that point in time.

The big benefit is you only incur the cost of flushing the file when and if you actually need it, rather than each time around your loop. Your application code needs no special flush logic and need not concern itself with what's happening on the outside. All the tricky stuff is handled by RMS.

If you want to debug the real problem, First remove all the ERROR:=CONTINUE clauses, or code a STATUS check. Enable a process dump, or run the program under DEBUG. When you get an error, walk back through the call stack and see how it got there. I still suspect some form of recursion, perhaps involving an external routine.
A crucible of informative mistakes
Klaus Heim
Advisor

Re: RMS-E-RSA, record stream currently active

John,

I have changed my program. Since 28.06.2010 the open/close is removed (see attachment). The same error occurred at 30.06.2010

30-JUN-2010 08:30:17.87 warte auf Trigger
%PAS-F-ERRDURWRI, error during WRITELN
File "OUTPUT" Filename "SYS$OUTPUT:.;"
-RMS-E-RSA, record stream currently active
%TRACE-F-TRACEBACK, symbolic stack dump follows
image module routine line rel PC abs PC
PAS$RTL 0 00000000000301A0 FFFFFFFF855001A0
PAS$RTL 0 000000000005E161 FFFFFFFF8552E161
PAS$RTL 0 0000000000046FA1 FFFFFFFF85516FA1
PAS$RTL 0 0000000000046D30 FFFFFFFF85516D30
BSTR BSTR BSTR 590 0000000000002AD2 0000000000032AD2
BSTR 0 00000000000345B2 00000000000345B2
BSTR 0 00000000000352E2 00000000000352E2
PTHREAD$RTL THD_THREAD thdBase 244744 0000000000005BE2 FFFFFFFF84543282
PTHREAD$RTL THD_INIT pthread_main 244538 00000000000006B2 FFFFFFFF844FA6B2
0 FFFFFFFF80BA8192 FFFFFFFF80BA8192
DCL 0 000000000006BAF2 000000007AE27AF2
%TRACE-I-END, end of TRACE stack dump

Any suggestion?
John Gillings
Honored Contributor

Re: RMS-E-RSA, record stream currently active

Klaus,

As I suggested earlier:

>Enable a process dump, or run the program
>under DEBUG. When you get an error, walk
>back through the call stack and see how it
>got there. I still suspect some form of
>recursion, perhaps involving an external
>routine.

Add /DUMP to your RUN/DETACHED command.

What does "baur$bewbckclose" do?

Looking at the code, it appears the error can only have resulted from the WriteLn of "BSTR Shutdown" at the end of the program.

I wonder if the exit handler has anything to do with it? I can't see how it would result in the error you have, but your exit handler looks a bit odd. What is lvs_stckdmp? If exitstatus is already the same as lvs_stckdmp, then it will be returned as R0, and effectively signalled anyway. I'd also prefer to see the exit status examined as the parameter to the exit handler, rather than an uplevel reference.

Simple stylistic issue, since you're always adding date and time stamps to the output, rather than repeat the same code in numerous places, I'd pull out the WriteLn calls into a routine, say "LogMsg":

PROCEDURE LogMsg(str:VARYING OF CHAR);
VAR dstr, tstr : PACKED ARRAY [1..11] OF CHAR;
BEGIN
DATE(dstr); TIME(tstr);
WriteLn(dstr,' ',tstr,str);
END;

PROCEDURE DbgMsg(str:VARYING OF CHAR);
BEGIN
IF dbgFlag
THEN
LogMsg(str)
END;
END;

Then call it like:

if sc.sc$w_phase<>sc$c_internphase then
begin
DbgMsg(' warte auf Trigger');
end;
end; {not(lvs$ifbrk)}
{schlieà e backup datei}
baur$bewbckclose;
LogMsg(' BSTR shutdown');

Places where you want to include decimal values are easily dealt with using concatenation and the formatting routines, like DEC:

DbgMsg(' keine Arbeit in SP='+DEC(sc.sc$w_phase));

By decluttering the program you may find it easier to spot inconsistencies. You also make it much easier to do stuff like closing and reopening the file, if that's what you really need to do, since it's all in one place. Consistency in things like message formats is enforced.

The other trick you can do by abstracting the log message function is easily switch to a different output file. Perhaps the issue is something corrupting the internal Pascal structure for OUTPUT?
A crucible of informative mistakes
Klaus Heim
Advisor

Re: RMS-E-RSA, record stream currently active

John,

thank you very much for your suggestions. I have change my program accordingly.

I have also added the /dump qualifier. I need some help to analyse the dump file. Please, can you give me some hints.

The last crash is in line 590 of bstr. This line contains the statement writeln(...,'trigger empfangen'). The problem occured during normal work of the server process bstr. Nobody has stopped the server process bstr. In my opinion the problem will not be found in the exit handler.

The Rtn. baur$bewbckclose will close a backup file of the server process bstr.

The Rtn. bstr_shutdown is the exit handler of the server process bstr. With sys$forcex() and status equal lvs__stckdmp it is possible to trigger the server process bstr. When this trigger is received the process will lib$signal(lvs__stckdmp) and I got a traceback info before bstr will stop.