Past my knowledge level using SUBMIT - Any help would be appreciated

[mpiazza]

We are currently running an older agent version of Data Protector which is providing backup capability for our aging VMS and OpenVMS systems. This old version of Data Protector ties us to more EOL equipment in the form of LT04/LT05 storage tape juke boxes. The enterprise has moved on to Veeam for the Windows and Linux systems to take advantage of intermediate disc caching but there is no Veeam support for VMS. In order for us to continue providing a backup solution we need to somehow migrate our VMS backups to the enterprise Veeam solution. Our solution was to fall back to using the built-in BACKUP capabilities native to VMS. We would then provide an intermediate Windows storage server where our VMS created save sets could be transferred and staged for Veeam to record and store them. To solve the problem of maintaining the VMS file attributes we added in a third-party solution called KnapSac that provides a fast backup utility combining file compression and file handing operations to enable storage of VMS file objects as pacsets. These pacsets provide a wrapper around the VMS files, in this case both image and non-image save sets, maintaining the VMS file attributes which are ultimately unaffected by Windows or Veeam’s Linux NFS file transfer and manipulations.

We run a DCL script in our SYS$BATCH queue called VMS_BACKUP_SCHEDULER which emulates the backup schedule that is running in Data Protector. After some initialization it resubmits itself successfully to the batch queue with the following command:

Code: Select all

$ SUBMIT/QUEUE=SYS$BATCH/AFTER="TOMORROW00:00:10"/NOPRINTER/LOG=$1$DGA322: - 
[VEEAM_VMS_BACKUPS.LOGS]'DATE'_'THISNODE'_VMS_BACKUP_SCHEDULER.LOG - 
$1$DGA322:[VEEAM_VMS_BACKUPS]VMS_BACKUP_SCHEDULER.COM

As you can see in the following snippet, the VMS_BACKUP_SCHEDULER.COM script is submitting the actual selected backup script job to the SYS$BATCH queue exactly as the
main SCHEDULER script has done with the system echoing the successful status of the job submittal.

Code: Select all

$ DISPLAY "SUBMITTING WEEKLY_SATSS1_INCR_BACKUP ON ''DATE'" -
SUBMITTING WEEKLY_SATSS1_INCR_BACKUP ON 19-APR-2023 00:00:04.47
$ SUBMIT/QUEUE=SYS$BATCH/AFTER="+3"/NOPRINTER/LOG=$1$DGA322:[VEEAM_VMS_BACKUPS.LOGS]'DATE'_'THISNODE'_WEEKLY_INCR_BACKUP.LOG $1$DGA322:[VEEAM_VMS_BACKUPS]WEEKLY_SATSS1_INCR_BACKUP.COM
Job WEEKLY_SATSS1_INCR_BACKUP (queue SATSS1$BATCH, entry 402) holding until 19-APR-2023 03:00

When the system eventually executes the batch job nothing happens. There is no output log or any indication that the job executed except that it is no longer in the batch queue.

Looking for some kind of error I ran the following command:

Code: Select all

ANALYZE/AUDIT/FULL/NOINTERACTIVE SYS$MANAGER:SECURITY.AUDIT$JOURNAL

I found the following single relevant entry in the security audit log:

Code: Select all

                  Security Audit Analysis Utility

Security alarm (SECURITY) and security audit (SECURITY) on SATSS1, system id: 31
Auditable event:	Batch process login failure
Event time:		19-APR-2023 03:00:04.59
PID:			20D4F2D0
Process name:		BATCH 402
Username:		SYSTEM
Process owner:		[SYSTEM]
Image name:		SATSS1SDKAO:[SYSO.SYSCOMMON.][SYSEXE]LOGINOUT.EXE
Posix UID:		-2
Posix GID:		-2 (%XFFFFFFFE)
Status:			%RMS-E-CRE, ACP file create failed

It shows a batch process login error.

This is what makes no sense and has me completely stymied. Both the Scheduling script job and the backup script job submitted from the scheduler are both running as SYSTEM processes. At least that has always been my understanding of how things work. Obviously I’m missing something because the login is failing but I don’t understand why. The thing that is confusing me is the “%RMS-E-CRE, ACP file create failure” statement in the Audit Log. What is it trying to create that it can’t. Is it complaining because it is unable to create the LOG file? If so why doesn't it say that? I mean seriously, a security person looking through the log would like to know something like that I would think. Other than the Audit Log failure record shown above there is nothing to indicate the process ever existed. The error message “%RMS-E-CRE, ACP file create failure” is one step above useless! This has always been one of my complaints about VMS.

I have looked in all my books and all the VMS manuals I can find. I’ve searched online rephrasing the query as many different ways that I can think of and I can come up with no explanation of exactly what this is telling me with any relevance to my current issue. I thought maybe a password failure and when I checked I did find that the SYSTEM password had expired so I set the new one but that has had no effect. I’ve included the SYSTEM account info and file directory permissions info below as I thought maybe it was telling me it couldn’t open the log file due to permissions or something but you can see that as a SYSTEM level process it should have all the access it needs.

Code: Select all

UAF> sho system
Username: SYSTEM                        Owner: SYSTEM MANAGER #System
Account: LMCO                           UIC:	[1,4] ([SYSTEM])
CLI:	DCL                             Tables: DCLTABLES
Default: SYS$SYSROOT:[SYSMGR]
LGICMD:
Flags: PwdMix
Primary days:	Mon Tue Wed Thu Fri
Secondary days:	Sat Sun
No access restrictions
Expiration:	(none)	Pwdminimum: 14	Login Fails:	0
Pwdlifetime:	60 00:00	Pwdchange: 17-APR-2023 17:08 5-MAR-1999 12:02
Last Login: 17-APR-2023 17:08 (interactive), 19-APR-2023 14:25 (non-interactive)
Maxjobs:	0 Fillm:	5000 Bytlm:	250000
Maxacctjobs:	0 Shrfillm:	   0 Pbytlm:	     0
Maxdetach: 	0 BIOlm: 	2500 3Tquota:     8192
Prclm: 	    36372 DIOlm: 	8000 WSdef:       8192
Prio: 		4 AST1m: 	4096 WSquo:      64000
Queprio: 	0 TQElm: 	 200 WSextent:   32768
CPU: 	   (none) Enqlm: 	2000 Pgflquo:  7000000

Authorized Privileges:
  ACNT	       ALLSPOOL	    ALTPRI      AUDIT     BUGCHK    BYPASS 
  CMEXEC       CMKRNL	    DIAGNOSE    DOWNGRADE EXQUOTA   GROUP
  GRPNAM       GRPPRV	    IMPERSONATE IMPORT    LOG_IO    MOUNT
  NETMBX       OPER	    PFNMAP      PHY_IO    PRMCEB    PRMGBL
  PRMMBX       PSWAPM	    READALL     SECURITY  SETPRV    SHARE
  SHMEM	       SYSGBL	    SYSLCK      SYSNAM    SYSPRV    TMPMBX
  UPGRADE      VOLPRO 	    WORLD
Default Privileges:
  ACNT	       ALLSPOOL	    ALTPRI      AUDIT     BUGCHK    BYPASS 
  CMEXEC       CMKRNL	    DIAGNOSE    DOWNGRADE EXQUOTA   GROUP
  GRPNAM       GRPPRV	    IMPERSONATE IMPORT    LOG_IO    MOUNT
  NETMBX       OPER	    PFNMAP      PHY_IO    PRMCEB    PRMGBL
  PRMMBX       PSWAPM	    READALL     SECURITY  SETPRV    SHARE
  SHMEM	       SYSGBL	    SYSLCK      SYSNAM    SYSPRV    TMPMBX
  UPGRADE      VOLPRO	    WORLD	
Identifier

SATSS1> dir/full WEEKLY_SATSS1_INCR_BACKUP.COM; 

Directory $1$DGA322:[000000.VEEAM_VMS_BACKUPS]

WEEKLY _SATSS1_INCR_BACKUP.COM;5 File ID:	(3820,313,0)
Size:            6/200	      Owner:     [SYSTEM]
Created:    13-APR-2023 17:47:36.67
Revised:    15-APR-2023 00:16:31.74 (4)
Expires:    16-APR-2023 00:16:31.74
Backup:     14-APR-2023 11:11:59.47
Effective:  <None specified>
Recording:  <None specified>
Accessed:   <None specified>
Attributes: <None specified>
Modified:   <None specified>
Linkcount:  1
File organization:  Sequential
Shelved state:	    Online
Caching attribute:  Writethrough
File attributes:    Allocation: 200, Extend: 0, Global buffer count: 0
		    No version limit
Record format:      Variable length, maximum 255 bytes, longest 85 bytes
Record attributes:  Carriage return carriage control
RMS attributes:     None
Journaling enabled: None
File protection:    System:RWED, Owner:RWED, Group:RE, World:
Access Cntrl List:  None
Client attributes:  None
 
Total of 1 file, 6/200 blocks.


SATSS1> sho que sys$batch/full
Batch queue SATSS1$BATCH, idle, on SATSS1::
  /BASE_PRIORITY=3 /CPUMAXIMUM=INFINITE /JOB_LIMIT=24 /OWNER=[SYSTEM]
  /PROTECTION=(S:M,O:D,G:R,W:S) /WSQUOTA=1000

  Entry Jobname          Username             Status	
  -----  ------          --------             ------	
    401  VMS_BACKUP_SCHEDULER
                         SYSTEM               Holding until 20-APR-2023 00:00:00
         Submitted 19-APR-2023 00:00:04.47 /KEEP 
         /LOG=$1$DGA322:[VEEAM_VMS_BACKUPS.LOGS]19-APR-2023_SATSS1_VMS_BACKUP_SC 
         /NOPRINT /PRIORITY=3
         File: _$1$DGA322:[VEEAM_VMS_BACKUPS]VMS_BACKUP_SCHEDULER.COM;10

    403  DAILY_WS        SYSTEM               Holding until 20-APR-2023 00:00:00
         Submitted 19-APR-2023 00:00:04.66 /KEEP
         /L°G=SATSSISDKAO:[SYS0.][sYsMGR]DAILY_Ws.LOG; /PARAM=("DAILY_WS", 
         "00:00","SYS$BATCH","8") /NOPRINT /PRIORITY=3
         File: _$1$DGA300:[VMS$COMMON.MGRSW.OPSJOBS]SUBMIT_BATCH_30B.COM;123

Added in 7 minutes 17 seconds:
There are some typos I missed from the scanning/OCR process. Some $ signs in the device names were OCR'd as S's and I didn't notice until I had posted the text.

[arne_v]

Indeed a mystery.

I have no great ideas,

You can of course double check the name of the log directory and check that it exists and that it does not already contain a log file with the name with version 32767.

I don't get why you you need a commercial offering to store save sets with VMS file attributes. VMS ZIP is able to do that.

[mpiazza]

Our versions of OpenVMS are old, 7.2 -7.3 and our disk size limitations preclude our ability to create our save sets locally. One of our Oracle DB RMAN snapshots is over a TB of data. KnapSac uses a client server model allowing us to execute the KnapSac BACKUP call on each OpenVMS client with the actual save set/pac file of compressed data passed over a dedicated virtual port and built on the WIndow's KnapSac host server which enables us to get around our VMS disk limitations. This KnapSac host server is also a Veeam client and makes the .pac files available for Veeam to backup. Restoration now becomes a two-step process but it is relatively straight forward. KnapSac also uses an identical BACKUP syntax with a few extensions so there is no real learning curve.

Added in 3 minutes 46 seconds:
Also, because of the 'date' and 'thisnode' symbols in the log file name there is only ever a version 1 of the file.

[bobwilson]

Can you add /RETAIN=ERROR or /RETAIN=ALWAYS to the job?

The retained entry may provide some additional clues about what might have gone wrong.

[sms]

Code: Select all

> [...] These pacsets provide a wrapper around the VMS files, in this
> case both image and non-image save sets, maintaining the VMS file
> attributes which are ultimately unaffected by Windows or Veeam's Linux
> NFS file transfer and manipulations.

> I don't get why you you need a commercial offering to store save sets
> with VMS file attributes. VMS ZIP is able to do that.

   All more work than necessary.  Any scheme which preserves the data in
a BACKUP save set should be good enough; restoring the attributes of a
save set is easy:

      http://antinode.info/dec/sw/fixrec.html

> When the system eventually executes the batch job nothing happens.
> There is no output log or any indication that the job executed except
> that it is no longer in the batch queue.

   I know nothing, but if the SUBMIT does put the job into the queue,
and it doesn't stay there, then the lack of a log file makes me wonder
if the problem is that the specified log file can't be written --
permissions, disk quota, disk full, ...

> [...] This has always been one of my complaints about VMS. [...]

   Useless error messages, like many kinds of bad software, are found
beyond the borders of VMS.

   Can you write files to those locations manually, without involving a
batch job?

[bhall]

Are you auditing file access failures? If you are not, enabling it may give you a clue as to why and where the file create error is happening.

Code: Select all

 $SET AUDIT/AUDIT/ENABLE=ACCESS=FAILURE/CLASS=FILE

Bill

[volkerhalle]

SUBMIT/RETAIN=ERROR (or /RETAIN=ALWAYS) will show you the 'condition vector', not just the exit status of the process.

Example:

969 X HALLE Retained on error
%RMS-E-CRE, ACP file create failed
-RMS-E-CRE, ACP file create failed
-SYSTEM-W-BADFILEVER, bad file version number
On idle batch queue SYS$BATCH
Completed 21-APR-2023 07:29:30.88 on queue SYS$BATCH

AXPVMS $ dir x.log

Directory USERDISK1:[HALLE]

X.LOG;32767

It produces the same security audit log as you've posted.

ACCOUNTING/PROCESS=BATCH/TYPE=LOGFAIL also shows this, but also just the exit status.

Volker.

[bobwilson]

What exactly is the log file name? It appears to be truncated in your original problem report.

I was able to reproduce this issue by specifying a log file name that was longer than 39 characters (from the SHOW ENTRY):

Code: Select all

/LOG=_DSA71:[RWILSON]D862F5679DD8FB9311EDE017713195C2D862F5679DD8FB9311EDE017713195C2.LOG;

When I released the job it gave me:

Code: Select all

Job LOGIN (queue <node>_BATCH, entry 116) terminated with error status
%RMS-E-CRE, ACP file create failed

This seems like a bug. An obviously illegal file specification will result in no file being created.

I'll report this issue.

[volkerhalle]

Bob,

is the disk, on which your .LOG file is to be written ODS-2 or ODS-5 ? For ODS-5, file name plus type can be up to 236 bytes long. ODS-2 only allowed 39.39 file names.

Volker.

[bobwilson]

Yes my login disk is ODS-2...I forgot that ODS-5 allow for other formats (including longer than 39 characters)

In any case, seems like a bug that you can specify an illegal file name on a target where it is/should-be "known" to be invalid.

It would be interesting to specify a invalid /LOG=<filename> for a ODS-5 volume to see if the SUBMIT is accepted and results in the RMS error...I'll try that later today.