[Info-vax] strange backup behavior

B Hobbs bdhobbs18 at acm.org
Fri Aug 7 15:02:38 EDT 2009


I've noticed that the more data on our backup SDLT tape, the longer it
takes to add additional files to the same tape.  When a file of about
35 blocks (BACKUP-STUFF.COM;67) is backed up at the beginning of the
tape, that backup takes less than a minute.  Backing up the same file
after about 45 gigabytes of other backup files takes over 30 minutes.

Our backup job starts at 04:10 every day, full backups are done on
Saturday, incrementals are done the rest of the time.  If the time is
after 08:00 Monday thru Friday, then the remaining backup steps are
skipped.

We don't work weekends, the tape I put in Friday afternoon will get
the Saturday full backup, Sunday incremental backup, and Monday
incremental backup.  The Monday morning incremental backup usually
runs out of time and is incomplete.  Incremental backups that are done
Tuesday thru Friday to empty tapes take about 2.5 hours and are
complete.


System configuration and versions:
  OpenVMS V7.1
  VMS thinks it is running on a VAX 4000-105A
  VAX emulator Charon-VAX/XL (Plus) V 3.1 B 50 (VAX 4000 model 108)
  Windows Server 2003 SP1, v 5.2
  HP ProLiant DL385, AMD 64 Opertron
  HP 160/320 GB SDLT, SCSI connection


>From the log files:

04:11:15.00 $ allocate/log mua0:
%DCL-I-ALLOC, _MADVX2$MUA0: allocated
04:11:15.00 $ mount/noassist/foreign/nounload mua0:
%MOUNT-I-MOUNTED, VAX005 mounted on _MADVX2$MUA0:
04:11:18.28 $!! Move past previous backup files.
04:11:18.28 $ set magtape/log/skip=end_of_tape mua0:
%SET-I-DEVSET1, MUA0: set to /END_OF_TAPE
04:11:18.88 $ show device/full mua0:
Magtape MADVX2$MUA0:, device type TK50, is online, allocated, mounted
foreign,
    record-oriented device, file-oriented device, available to
cluster, error
    logging is enabled.
    Error count                   41    Operations
completed             197156
    Owner process        "BATCH_823"    Owner UIC
[BACKUP]
    Owner process ID        00003A2D    Dev Prot
S:RWPL,O:RWPL,G:R,W
    Reference count                2    Default buffer
size                 512
    Volume label            "VAX005"    Relative volume
no.                   0
    Record size                    0    Transaction
count                     1
    Mount status             Process    Mount
count                           1
    ACP process name              ""
    Density                     6666    Format
Normal-11
  Volume status:  no-unload on dismount, odd parity.


Initialize/erase done to VAX005 on Friday, prior to this set of
backups.

Saturday morning full backup:

04:11:48.72 $ backup/noalias/brief/ignore=(interlock)/log -
                []BACKUP-STUFF.com; -
                mua0:Sat-disk-full.aaa -
                  /block_size=65024/norewind/save_set/label=(VAX005)
%BACKUP-S-COPIED, copied DISK$JOURNALS:[USERS.HOBBS.PROJECT.BACKUP]
BACKUP-STUFF.COM;67
04:12:39.82 $ backup/noalias/brief/ignore=(interlock)/log -

... full backup of all disks ...

Full backup step:

15:28:42.52 $     backup/noalias/brief/ignore=(interlock)/log -
                    /fast -
                    /journal=[.evidence]backup.bjl -
                    /list=[.evidence]dua10.lis -
                    /record -
                    dua10:[000000...]*.*;* -
                       -
                    mua0:Sat-dua10.bck -
                      /block_size=65024/norewind/save_set/label=
(VAX005)
%BACKUP-I-JOURNAL, journaling to DISK$JOURNALS:
[USERS.HOBBS.PROJECT.BACKUP.EVIDENCE]BACKUP.BJL;3
%BACKUP-S-COPIED, copied DUA10:[000000]000000.DIR;1
--snip--
%BACKUP-I-STARTRECORD, starting backup date recording pass
15:55:20.67 $     show symbol $status
  $STATUS == "%X10000001"


21:58:13.54 $ backup/noalias/brief/ignore=(interlock)/log -
                []BACKUP-STUFF.com; -
                mua0:Sat-disk-full.zzz -
                  /block_size=65024/norewind/save_set/label=(VAX005)
%BACKUP-S-COPIED, copied DISK$JOURNALS:[USERS.HOBBS.PROJECT.BACKUP]
BACKUP-STUFF.COM;67
22:29:13.33 $ backup/noalias/brief/ignore=(interlock)/log -


Sunday morning backup:

04:17:08.89 $ backup/noalias/brief/ignore=(interlock)/log -
                []BACKUP-STUFF.com; -
                mua0:Sun-disk-incr.aaa -
                  /block_size=65024/norewind/save_set/label=(VAX005)
%BACKUP-S-COPIED, copied DISK$JOURNALS:[USERS.HOBBS.PROJECT.BACKUP]
BACKUP-STUFF.COM;67
04:48:03.02 $ backup/noalias/brief/ignore=(interlock)/log -

... incremental backup of disks ...

Incremental backup step:

14:15:26.30 $     backup/noalias/brief/ignore=(interlock)/log -
                    /journal=[.evidence]backup.bjl -
                    /list=[.evidence]dua10.lis -
                    dua10:[000000...]*.*;* -
                       -
                      /since=backup -
                    mua0:Sun-dua10.bck -
                      /block_size=65024/norewind/save_set/label=
(VAX005)
%BACKUP-I-JOURNAL, journaling to DISK$JOURNALS:
[USERS.HOBBS.PROJECT.BACKUP.EVIDENCE]BACKUP.BJL;3
%BACKUP-S-COPIED, copied DUA10:[000000]000000.DIR;1
%BACKUP-S-COPIED, copied DUA10:[000000]SORTWORK.DIR;1
14:46:46.29 $     show symbol $status
  $STATUS == "%X10000001"

21:17:55.29 $ backup/noalias/brief/ignore=(interlock)/log -
                []BACKUP-STUFF.com; -
                mua0:Sun-disk-incr.zzz -
                  /block_size=65024/norewind/save_set/label=(VAX005)
%BACKUP-S-COPIED, copied DISK$JOURNALS:[USERS.HOBBS.PROJECT.BACKUP]
BACKUP-STUFF.COM;67
21:49:54.07 $ backup/noalias/brief/ignore=(interlock)/log -


Monday morning backup:

04:18:53.49 $ backup/noalias/brief/ignore=(interlock)/log -
                []BACKUP-STUFF.com; -
                mua0:Mon-disk-incr.aaa -
                  /block_size=65024/norewind/save_set/label=(VAX005)
%BACKUP-S-COPIED, copied DISK$JOURNALS:[USERS.HOBBS.PROJECT.BACKUP]
BACKUP-STUFF.COM;67
04:50:56.50 $ backup/noalias/brief/ignore=(interlock)/log -

... incremental backup of some disks, ran out of time ...

09:18:01.99 $ backup/noalias/brief/ignore=(interlock)/log -
                []BACKUP-STUFF.com; -
                mua0:Mon-disk-incr.zzz -
                  /block_size=65024/norewind/save_set/label=(VAX005)
%BACKUP-S-COPIED, copied DISK$JOURNALS:[USERS.HOBBS.PROJECT.BACKUP]
BACKUP-STUFF.COM;67
09:50:22.44 $ backup/noalias/brief/ignore=(interlock)/log -


Sat, first  marker backup, 51 s
Sat, second marker backup, 31 m
Sun, first  marker backup, 31 m
Sun, second marker backup, 32 m
Mon, first  marker backup, 32 m
Mon, second marker backup, 32 m

Is the tape rewinding and then advancing to end-of-tape for each
file?  Am I inadvertently telling backup to do this?

Any ideas or suggestions?

Thanks



More information about the Info-vax mailing list