RMS RU journaling issue

[jimduff]

I hope I'm posting in the appropriate place...

In my list of code examples, I have a program to demonstrate RMS journaling (located here)

Compiling and linking this on V9.2-1 on VirtualBox 7.0.6_Ubuntu r155176 produces no errors. However, running the program produces a traceback as a result of the call to the sys$put():

Code: Select all

%RMS-F-ACC_RUJ, recovery unit journal can not be accessed
%TRACE-F-TRACEBACK, symbolic stack dump follows
image     module    routine               line      rel PC           abs PC
Error: traceback pc= 00000410 was not found
SYS_TRANS  SYS_TRANS.C;1  main               0 0000000000000410 0000000080000410
SYS_TRANS  SYS_TRANS.C;1  __main         35786 00000000000006F5 00000000800006F5
                                             0 FFFF8300081FBEA6 FFFF8300081FBEA6
DCL                                          0 000000008006778B 000000007ADFF78B
%TRACE-I-END, end of TRACE stack dump

I've ensured I have a valid log file via LMCP and journaling is enabled (logical name SYS$DECDTM_INHIBIT is not defined and process TP_SERVER is up and running).

Assuming it was my code, I ran sys$examples:rmsjnl_example.com, and it produced the same error, which makes me think that the error is something to do with dtm or my setup thereof.

So I read through the system manager's manual ensuring I'd followed the steps to set up a log file and it seems that my memory has not totally failed me since the last time I did this.

Can anyone suggest something that I've missed?

P.S. LMCP does not accept CTRL-Z as a shortcut for exit. Pretty sure it did on other architectures.

[hb]

Works for me:

Code: Select all

$ sh sys/noproc
OpenVMS V9.2-1  on node HBX   26-JUL-2023 12:50:10.06   Uptime  0 00:00:52
$ cc/vers
VSI C X7.4-745 (GEM 50X23) on OpenVMS x86_64 V9.2-1  
$ cc sys_trans
$ link sys_trans
$ r sys_trans
You have successfully created the test file SYS_TRANS.IDX
Please issue the following DCL command and run the code again:

        $ SET FILE/RU_JOURNAL SYS_TRANS.IDX

$ SET FILE/RU_JOURNAL SYS_TRANS.IDX
$ r sys_trans
The program is now about to write a record to the file.  A suggested order
for running the tests is to answer no to the commit question first.  Then
you can look at the file and see it's empty, then run the program again 
and answer yes.  In this way, you won't get a message about duplicate keys.

Starting a transaction
No log file found.  Please use MCR LMCP to create one!
$ lmcp create log/size=5000 system$'f$getsyi("nodename")
Transaction log SYS$COMMON:[SYSEXE]SYSTEM$HBX.LM$JOURNAL;1 created.
$ r sys_trans
The program is now about to write a record to the file.  A suggested order
for running the tests is to answer no to the commit question first.  Then
you can look at the file and see it's empty, then run the program again 
and answer yes.  In this way, you won't get a message about duplicate keys.

Starting a transaction
No log file found.  Please use MCR LMCP to create one!
$ cre/dir sys$sysdevice:[sysjnl.'f$getsyi("nodename")]
$ r sys_trans
The program is now about to write a record to the file.  A suggested order
for running the tests is to answer no to the commit question first.  Then
you can look at the file and see it's empty, then run the program again 
and answer yes.  In this way, you won't get a message about duplicate keys.

Starting a transaction
Writing record to file
Commit the record? (Y/N) y
Commit tranaction.
You should be able to dump the test file and see the record.
$ 

... and ...

Code: Select all

$ @sys$examples:rmsjnl_example.com
$ !+
$ ! RMSJNL_EXAMPLE.COM
$ ! This command procedure shows how to run the RMSJNL_EXAMPLE program that 
$ ! uses the transaction services.  This command file is also good for 
$ ! verifying the installation of VAX RMS Journaling.
$ ! 
$ ! NOTE: All file names have dollar signs in them to prevent any
$ ! possible conflict with user file names.  Of course, any valid
$ ! file name can be used instead.
$ !-
$ !
$ ! First, delete any old files that may be lying around.
$ ! Ignore error messages here.
$ !
$ !
$ ON ERROR THEN $EXIT $STATUS
$ !
$ ! Initialize RMSJNL$CHECKING.IDX and RMSJNL$SAVINGS.IDX.
$ !
$ CREATE/FDL=SYS$INPUT RMSJNL$CHECKING.IDX
FILE
        ORGANIZATION            indexed
RECORD
        FORMAT                  fixed
        SIZE                    18
KEY 0
        PROLOG                  3
        SEG0_LENGTH             9
        SEG0_POSITION           0
$ !
$ COPY RMSJNL$CHECKING.IDX RMSJNL$SAVINGS.IDX
$ !
$ ! Mark the files for all types of journaling.
$ !
$ ! NOTE: A warning will be issued that our AI journal is on the same
$ ! device as our data file.  Normally one should put the AI journal on a
$ ! different device in case the disk is wiped out, but for the purposes
$ ! of installation verification this is acceptable.
$ !
$ SET FILE RMSJNL$CHECKING.IDX -
                /RU_JOURNAL -
                /AI_JOURNAL=(FILE=RMSJNL$AI.RMS$JOURNAL,CREATE) -
                /BI_JOURNAL=(FILE=RMSJNL$BI.RMS$JOURNAL,CREATE)
%SET-W-INVAIJDEV, after-image journal SYS$SYSROOT:[SYSMGR]RMSJNL$AI.RMS$JOURNAL;1 is on same device as data file SYS$SYSROOT:[SYSMGR]
RMSJNL$CHECKING.IDX;1
$ !
$ SET FILE RMSJNL$SAVINGS.IDX -
                /RU_JOURNAL -
                /AI_JOURNAL=FILE=RMSJNL$AI.RMS$JOURNAL -
                /BI_JOURNAL=FILE=RMSJNL$BI.RMS$JOURNAL
%SET-W-INVAIJDEV, after-image journal SYS$SYSROOT:[SYSMGR]RMSJNL$AI.RMS$JOURNAL;1 is on same device as data file SYS$SYSROOT:[SYSMGR]
RMSJNL$SAVINGS.IDX;1
$ !
$ ! Backup the files.  Note that this is done after marking them for journaling.
$ !
$ BACKUP/RECORD RMSJNL$CHECKING.IDX;0 RMSJNL$CHECKING.BCK
%BACKUP-W-NOFILES, no files selected from HBX$DKC300:[SYS0.SYSCOMMON.][SYSMGR]RMSJNL$CHECKING.IDX;0
%BACKUP-I-STARTRECORD, starting backup date recording pass at 26-JUL-2023 12:57:44.02
%BACKUP-I-MODOUTAI, RMS after-image journaling disabled on saved copy of _HBX$DKC300:[SYS0.SYSMGR]RMSJNL$CHECKING.IDX;1
%BACKUP-I-MODOUTBI, RMS before-image journaling disabled on saved copy of _HBX$DKC300:[SYS0.SYSMGR]RMSJNL$CHECKING.IDX;1
$ !
$ BACKUP/RECORD RMSJNL$SAVINGS.IDX;0  RMSJNL$SAVINGS.BCK
%BACKUP-W-NOFILES, no files selected from HBX$DKC300:[SYS0.SYSCOMMON.][SYSMGR]RMSJNL$SAVINGS.IDX;0
%BACKUP-I-STARTRECORD, starting backup date recording pass at 26-JUL-2023 12:57:44.17
%BACKUP-I-MODOUTAI, RMS after-image journaling disabled on saved copy of _HBX$DKC300:[SYS0.SYSMGR]RMSJNL$SAVINGS.IDX;1
%BACKUP-I-MODOUTBI, RMS before-image journaling disabled on saved copy of _HBX$DKC300:[SYS0.SYSMGR]RMSJNL$SAVINGS.IDX;1
$ !
$ ! Test RU journaling by running the example program.  This program performs
$ ! two transactions.  The first initializes the checking and savings acounts
$ ! to $100.00 each.  The second transaction transfers $10.00 from the
$ ! savings account to the savings account.  During the second transaction
$ ! the program pauses for 5 seconds before committing the transaction.  If this
$ ! program is allowed to run to completion then the checking balance should
$ ! be $90.00 and the savings balance should be $110.00.  However, if this
$ ! procedure is interrupted by a Control-Y during the pause, then the
$ ! original $100.00 balances should be restored in both the savings and
$ ! checking accounts.
$ !
$ ON CONTROL_Y THEN $CONTINUE
$ !
$ RUN SYS$EXAMPLES:RMSJNL_EXAMPLE
%DCL-W-ACTIMAGE, error activating image SYS$EXAMPLES:RMSJNL_EXAMPLE
-CLI-E-IMAGEFNF, image file not found HBX$DKC300:[SYS0.SYSCOMMON.][SYSHLP.EXAMPLES]RMSJNL_EXAMPLE.EXE;
$ dir SYS$EXAMPLES:RMSJNL_EXAMPLE

Directory SYS$COMMON:[SYSHLP.EXAMPLES]

RMSJNL_EXAMPLE.C;1  RMSJNL_EXAMPLE.COB;1                    RMSJNL_EXAMPLE.COM;1

Total of 3 files.
$ cc SYS$EXAMPLES:RMSJNL_EXAMPLE
$ link RMSJNL_EXAMPLE
$ r RMSJNL_EXAMPLE
Pausing for 5 seconds.
The new checking account balance is 90
The new savings account balance is 110
$ 

[hein]

Thank you Hartmut for testing.

%RMS-F-ACC_RUJ is an STS status value which should be accompanied by a detail reason in the STV.
Did you examine that? It's probably one of the lesser valuable ones like NOPRIV, but still.
Speaking of which, which privs were used? If tested as normal user, did you own all files/directories?
Can you try running with SYSPRV?

Maybe, just maybe, you can find more error details when running with SET WATCH FILE/CLASS=MAJOR ! or ALL. NONE to disable.

The program seems to use default RUJ file placement, maybe you can check/play with that?
From the manual:

Code: Select all

5.6.6 Determining volume placement
You can determine the volume placement for a recovery unit journal by using
three different methods:
• Default placement
• SET FILE/RU_JOURNAL=LABEL command
• XABITM item list entry XAB$_RUJVOLNAM
5.6.7 Default placement
By default, the recovery unit journal is on the same volume as the file associated
with the first record stream that joins the transaction. If RMS journaling does
not find a [SYSJNL] directory, it creates one. The file name for the recovery
unit journal has the form RMS$process_id (where process_id is the hexadecimal
representation of the process ID) and a file type of RMS$JOURNAL.

Hein.

[jimduff]

I'm running fully privileged.

Chucking in a printf statement shows the STV is RMS-E-DNF, directory not found, underlaid by a %x910.

I had to set watch/class=all to find out what was going on. Journaling is attempting to access a directory called [SYSJNL.XXXXXX], where XXXXXX is the name of the node. This directory doesn't exist. Yesterday, I read the part of the manual that Hein quoted, the relevant part reading "If RMS journaling does not find a [SYSJNL] directory, it creates one". But it didn't. So I created one. But there is no mention of a subdirectory named the same thing as the name of the node. I manually created that too and the program works.

The relevant part of the set watch output:

Code: Select all

%XQP, Thread #0, Read only directory access (3170,11,0)
%XQP, Thread #0, Directory scan for: XXXXXX.;0, Status: 00000000
%XQP, Thread #0, Directory scan for: XXXXXX.DIR;1, Status: 00000000
%XQP, Thread #0, Lookup SYSJNL.DIR;1 (3170,11,0) Status: 00000910

And that's it, it then just fails. No attempt to create the directory structure as the manual (incompletely) claims.

To confirm, after I had it working, I renamed [000000]SYSJNL.DIR and the problem is reproducible, this time with the set watch output showing it can't find SYSJNL.DIR. The question now is, why doesn't RMS Journaling automatically create the directory structure?

Thanks for your help guys, and VSI might like to either update the manual or make RMS Journaling do what the manual claims

[hein]

>> VSI might like to either update the manual or make RMS Journaling do what the manual claims

My reference came from my now 30 year old July 1993 copy of the manual :-).

The current online doc is - Document Number: DO-RMSJNL-01A, Publication Date: July 2019, VSI OpenVMS Integrity Version
8.4-2
It looks identical. Jim is absolutely correct that the document should read "under" [SYSJNL] not 'in' and be specific about the [SYSJNL.XXXXXX], where XXXXXX is the name of the node. It would be nice if RMS Journaling were to create those subdirectories as the documentation suggests, but at this point the life of OpenVMS, and RMS Journaling specifically I think just documenting the need to pre-create is adequate. Too expensive (risky) to fix other than documenting as requirement.

fwiw,
Hein.