Conference vaxaxp::vmsnotes

634.0. "Strange output in BACKUP log file" by COMICS::SYMONDSK () Fri May 23 1997 07:22

    Dear All,
    
    I have a customer with a problem with backup log files containing
    strange characters, the following is a sample from the log file:
    
    %BACKUP-W-ACCONFLICT, SYS$SYSDEVICE:[USR.V2R2.DATA]USR_MENU.ISM;92 is
    open for 
    %BACKUP-E-OPENIN, error opening SYS$SYSDEVICE:[]SYS$SYSDEVICE.BLI;1 as
    input
    -SYSTEM-W-ACCONFLICT, file access conflict
    %BACKUP-E-OPENIN, error opening
    SYS$SYSDEVICE:[]00000000000000TE0010^@^@^@^@�^@<FF>^@^@^@^@^@<XF0>^S^A^@^@^@^@^@^@     
    �~^@^@^@^@
    -SYSTEM-W-ACCONFLICT, file access conflict
    %BACKUP-I-STARTRECORD, starting backup date recording pass
    
    
    I have suggested increasing ASTLM ~20 units larger than DIOLM, but with no 
    joy, and the following are the account quotas:
    
    Maxjobs:         0  Fillm:     15573  Bytlm:      1000000
    Maxacctjobs:     0  Shrfillm:      0  Pbytlm:           0
    Maxdetach:       0  BIOlm:     15573  JTquota:      20000
    Prclm:          10  DIOlm:     30000  WSdef:         8192
    Prio:            4  ASTlm:     30010  WSquo:        16384
    Queprio:         0  TQElm:        50  WSextent:     65500
    CPU:        (none)  Enqlm:     20000  Pgflquo:     500000
    
    The problem only occurs when my customer performs a job called capacity
    planning when they do their backup. They run this code across all their
    systems (run every Wednesday) and only happens on the 3 alpha 4100's
    running a raid configuration. The code is as follows:
    
$! See EOF for Copyright and full description
$!
$! Brief Description: Performs Backup Using TAPECONTROL
$! Filename: DML__TCTL:[CODE]TCTL__BACKUP.COM
$!
$! Initialize variables
$!
$	status = 0
$	nodename = f$edit(f$getsyi("scsnode"),"collapse,upcase")
$	this_proc = f$element(0,";",f$environment("procedure"))
$	this_proc_name = f$parse(this_proc,,,"name")
$	debug_proc_status = f$trnlnm("debug_''this_proc_name'")
$	debug_all_status = f$trnlnm("debug_all")
$	if f$string(debug_proc_status) .eqs. "1" .or. -
	  f$string(debug_all_status) .eqs. "1"
$	    then	verify = f$verify(1)
$	    else	verify = f$verify(0)
$	endif
$	on control_y then goto CTRLY_TRAP
$	on warning then goto ERROR_TRAP
$	wso		:= write sys$output
$	std__ask	:= @dml__util:[code]std__ask
$	std__message	:= @dml__util:[code]std__message
$	std__banner	:= @dml__util:[code]std__banner
$	unique		= f$getjpi(0,"pid")
$	bd_file		= nodename + "_BDF_" + unique
$	now		= f$time()
$	day_name	= f$edit(f$cvtime(now,"absolute","weekday"),"upcase") 
$	blistfn_ctl	= "dml__tctl:[listing]!AS.BLI"
$	blistfo_ctl	= "dml__tctl:[listing]!AS.OLD"
$	blistc_ctl	= "/list=!AS"
$	non_jb_backup	= "FALSE"
$	dism_comm	= "dismount"
$!
$! Setup Tapecontrol Symbols, etc.
$!
$	@sys$manager:tctl_login
$!
$! Get parameter P1 - Backup Data File
$!
$	backup_data	=  f$edit(p1,"collapse,upcase")
$	if backup_data .eqs. "" .or. f$search(backup_data) .eqs. ""
$	  then
$		std__message tctl f invfil "Invalid backup data-file"
$		status = ss$_abort
$		goto FINAL_EXIT
$	endif
$!
$! Get optional parameter P2 - Non-Jukebox Backup Flag
$!
$	nj_flag		= f$edit(p2,"collapse,upcase")
$	if nj_flag .nes. "" then non_jb_backup = "TRUE"
$!	if non_jb_backup then dism_comm	= "dismount/nounload"
$!
$! Open and read backup data-file
$!
$	open/read/share 'bd_file' 'backup_data'
$!
$! Read until EOF or "START_OF_DISK_LIST" is encountered, ignore lines
$! containing comment characters
$!
$READ_BACKUP:
$!
$	read/end_of_file=CLOSE_BACKUP/error=CLOSE_BACKUP 'bd_file' line
$	temp = f$edit(line,"collapse,upcase")
$	if temp .eqs. "" .or. f$locate("!",temp) .ne. f$length(temp) then -
	  goto READ_BACKUP
$	if f$locate("START_OF_DISK_LIST",temp) .ne. f$length(temp) then -
	  goto CHECK_CYCLE
$!
$! Extract data from line
$!
$	variable	= f$edit(f$element(0,"=",line),"collapse")
$	value		= f$edit(f$element(1,"=",line),"collapse")
$	'variable'	= "''value'"
$	goto READ_BACKUP
$!
$! Work out which cycle this backup is for (i.e. DAILY, WEEKLY, MONTHLY)
$!
$CHECK_CYCLE:
$!
$!
$! DAILY Cycle
$!
$	if day_name .nes. CYCLE_DAY
$	  then
$		pool = DAILY_POOL
$		backup_name = DAILY_NAME
$		goto MOUNT_TAPE
$	endif
$!
$! WEEKLY/MONTHLY Cycle
$!
$	cur_month = f$cvtime(now,"absolute","month")
$	chk_month = f$cvtime("''now'+7-00:00","absolute","month")
$	if cur_month .eqs. chk_month
$	  then
$		pool = WEEKLY_POOL
$		backup_name = WEEKLY_NAME
$	  else
$		pool = MONTHLY_POOL
$		backup_name = MONTHLY_NAME
$	endif
$!
$! Get tape for this backup. If the backup is a daily cycle and it's not the
$! start of the daily cycle and the previous daily backup was successful and
$! this is a jukebox backup, pick the last tape used. 
$! Otherwise pick a scratch tape.
$!
$MOUNT_TAPE:
$!
$	s_file = f$search("dml__tctl:[work]''backup_name'.success;0")
$!
$	if	pool	.eqs.	DAILY_POOL		.and. -
		day_name .nes.	DAILY_CYCLE_START	.and. -
		s_file	.nes.	""			.and. -
		.not. non_jb_backup
$	  then
$!
$! Try to find tape with the marker saveset on
$!
$		tapecontrol read saveset 'backup_name'.bck
$		if saveset_located
$		  then
$!
$! Saveset exists so mount that tape
$!
$			std__message tctl i mntprv -
			  "Attempting to mount previous backup tape"
$			mount -
				/foreign -
				/$append -
				/$saveset='backup_name'.bck -
				/$pool='pool' -
				*tape1*
$		endif
$	  else
$!
$! Mount a scratch tape
$!
$		std__message tctl i mntscr "Attempting to mount a scratch tape"
$		mount -
			/foreign -
			/write -
			/$pool='pool' -
			*tape1*
$	endif
$!
$! Delete the success marker file for this backup (if it exists)
$!
$	if f$search("dml__tctl:[work]''backup_name'.success;0") .nes. "" then -
	  delete/nolog/noconfirm dml__tctl:[work]'backup_name'.success;*
$!
$! Tape has been selected, read the backup data file and process each disk.
$! Ignore blank lines and lines containing comment characters. 
$!
$READ_DISK:
$!
$	read/end_of_file=CLOSE_BACKUP/error=CLOSE_BACKUP 'bd_file' line
$	temp = f$edit(line,"collapse,upcase")
$	if temp .eqs. "" .or. f$locate("!",temp) .ne. f$length(temp) then -
	  goto READ_DISK
$	if f$locate("END_OF_DISK_LIST",temp) .ne. f$length(temp) then -
	  goto FINISH_BACKUP
$!
$	disk	= f$edit(f$element(0,"|",line),"collapse,upcase")
$	saveset	= f$edit(f$element(1,"|",line),"collapse,upcase")
$	day	= f$integer(f$cvtime(f$time(),"absolute","day"))
$	day	= f$string(f$fao("!2ZL",day))
$	month	= f$cvtime(f$time(),"absolute","month")
$	year	= f$cvtime(f$time(),"absolute","year")
$	sav_ext	= day + month + year
$	saveset	= f$element(0,".",saveset) + "." + sav_ext
$!
$! Check if today is the day to produce the backup listing file for each
$! disk for capacity planning purposes.
$!
$	if day_name .eqs. CAP_PLAN_DAY
$	  then
$		l_disk = disk - ":"
$		listing_file = f$fao(blistfn_ctl,l_disk)
$		listing_file_old = f$fao(blistfo_ctl,l_disk)
$		listing_cmd  = f$fao(blistc_ctl,listing_file)
$		if f$search(listing_file) .nes. "" then -
$		  rename/log 'listing_file' 'listing_file_old'
$		std__message tctl i crelis -
		  "Creating backup listing file ''listing_file'"
$	  else
$		listing_cmd = ""
$	endif
$!
$! Perform backup
$!
$	set noon
$	wso f$fao("!80*-")
$	wso f$fao("!30AS : !AS","Backing Up",disk)
$	wso f$fao("!30AS : !AS","Saveset",saveset)
$	wso f$fao("!30AS : !AS","Tape Drive",f$trnlnm("tctl_mounted"))
$	wso f$fao("!30AS : !AS","Time",f$time())
$	wso f$fao("!30AS : !AS","Tape",f$trnlnm("tape$volume"))
$	wso f$fao("!30AS : !AS","Pool",pool)
$	wso f$fao("!80*-")
$	set on
$!
$	set noon
$	backup	/image 'listing_cmd' -
		/ignore=interlock -
		/record -
		/block_size='BLOCK_SIZE' -
		/nocrc -
		/group_size=0 -
		'disk' -
		*tape1*:'saveset'/save_set
$
$	set on
$!
$! Loop back for next disk
$!
$	goto READ_DISK
$!
$! Finish backup by writing the marker saveset onto the tape
$!
$FINISH_BACKUP:
$!
$	create dml__tctl:[work]'backup_name'.marker;0
$	backup/log dml__tctl:[work]'backup_name'.marker -
	  *tape1*:'backup_name'.bck/save
$	delete/nolog/noconfirm dml__tctl:[work]'backup_name'.marker;*
$	create dml__tctl:[work]'backup_name'.success;0
$!
$! Exit Procedure
$!
$FINAL_EXIT:
$!
$	if f$trnlnm("tctl_mounted") .nes. ""
$	  then
$		if f$getdvi("tctl_mounted","mnt") then 'dism_comm' *tape1*
$	endif
$	if f$string(debug_all_status) .nes. "1" then -
 	  exit_verify = f$verify(verify)
$	if f$string(status) .nes. "0" then exit 'status'
$	exit
$!
$! Control-Y interrupt handler
$!
$CTRLY_TRAP:
$!
$	status = %x2c
$	wso ""
$	wso "** Warning - Control-Y Interrupt Detected - Aborting **"
$	wso ""
$	goto FINAL_EXIT
$!
$! Error Handler
$!
$ERROR_TRAP:
$!
$	status = $status
$	wso ""
$	wso "** Error Detected - Aborting **"
$	wso ""
$	goto FINAL_EXIT
$!
$!-----------------------------------------------------------------------------
$!
$! Procedure	:	TCTL__BACKUP
$! Version	:	V1.5
$! Created	:	30-Oct-1996
$! Filename	:	DML__TCTL:[CODE]TCTL__BACKUP.COM
$! Author	:	Graham Smith
$! Environment	:	DCL, OpenVMS V6.2
$!
$! Copyright (C) 1996 Devonport Management Limited.
$!
$! Facility	:	Tapecontrol Backups
$! Function	:	This command procedure performs a backup as specified
$!			by a data-file passed in P1.
$!
$!			The routine attempts to use the unused portion of the 
$!			tape used for the previous night's backup - for the
$!			daily cycle only and only for jukebox backups. 
$!			If there is no previous backup or the tape is 
$!			unavailable or the previous night's backup
$!			was unsuccessful, a scratch tape is used.
$!
$!			The data-file contains the day on which the backup
$!			cycle changes (i.e. from daily to weekly to monthly).
$!
$!			The data-file specifies which tapecontrol pools are to
$!			be used for each cycle.
$!
$!			Finally, the data-file contains the disks to be backed
$!			up and the saveset name to use. The saveset name
$!			extention will be the date. For example:
$!			DEV_BCKDSK1.18APR996
$!
$! Parameters	:	P1 - Backup Data-File. Mandatory Parameter.
$!
$!			P2 - Non-Jukebox Backup Flag. Optional Parameter.
$!
$!			P3 - Not Used.
$!			P4 - Not Used.
$!			P5 - Not Used.
$!			P6 - Not Used.
$!			P7 - Not Used.
$!			P8 - Not Used.
$!
$! Procedures Called	:	DML__UTIL:[CODE]STD__MESSAGE.COM
$!				SYS$MANAGER:TCTL_LOGIN.COM
$!
$! Files Accessed	:	Backup data-file specified in P1 (Read Access)
$!
$! Special Requirements	:	None
    
    
    Any help is welcome is tracking down why the strange characters are present
    in the backup log file.
    
    Thanks in advance,
    Kevin Symonds
    (CSC - BAsingstoke)

   Is that `Capacity Planning' job creating temporary files in the file
   structure?  (It looks like it.)  Who has the source code to this job?

   The apparent corrupt name, and the SYS$SYSDEVICE:[]SYS$SYSDEVICE.BLI;1
   name, point to a potential error in the `Capacity Planning' job.

   When `Capacity Planning' starts up, use a SHOW DEVICE/FILES on the
   SYS$SYSDEVICE: disk, and see what channels are open.

   It does look like there might be a minor bug in BACKUP or RMS here,
   where invalid names can creep into the file structure.