Amanda-Users

Re: Full backup worked, incrementals fail

2003-12-23 01:24:26
Subject: Re: Full backup worked, incrementals fail
From: Fran Fabrizio <fran AT cis.uab DOT edu>
To: amanda-users AT amanda DOT org
Date: Tue, 23 Dec 2003 00:18:50 -0600

Here is my amdump log for the last run....see note in there where I think it's failing....

# more amdump.1
amdump: start at Mon Dec 22 18:06:54 CST 2003
amdump: datestamp 20031222
planner: pid 9956 executable /usr/local/libexec/planner version 2.4.4p1
planner: build: VERSION="Amanda-2.4.4p1"
planner:        BUILT_DATE="Mon Dec 22 15:56:59 CST 2003"
planner: BUILT_MACH="Linux keep.cis.uab.edu 2.4.20-8smp #1 SMP Thu Mar 13 17:45:54 EST 2003 i686 i686 i386 GNU/Linux"
planner:        CC="gcc"
planner: CONFIGURE_COMMAND="'./configure' '--with-user=amanda' '--with-group=disk' '--with-config=CIS'"
planner: paths: bindir="/usr/local/bin" sbindir="/usr/local/sbin"
planner:        libexecdir="/usr/local/libexec" mandir="/usr/local/man"
planner:        AMANDA_TMPDIR="/tmp/amanda" AMANDA_DBGDIR="/tmp/amanda"
planner:        CONFIG_DIR="/usr/local/etc/amanda" DEV_PREFIX="/dev/"
planner:        RDEV_PREFIX="/dev/" DUMP="/sbin/dump"
planner:        RESTORE="/sbin/restore" SAMBA_CLIENT="/usr/bin/smbclient"
planner:        GNUTAR="/bin/gtar" COMPRESS_PATH="/bin/gzip"
planner:        UNCOMPRESS_PATH="/bin/gzip" MAILER="/usr/bin/Mail"
planner:        listed_incr_dir="/usr/local/var/amanda/gnutar-lists"
planner: defs:  DEFAULT_SERVER="keep.cis.uab.edu" DEFAULT_CONFIG="CIS"
planner:        DEFAULT_TAPE_SERVER="keep.cis.uab.edu"
planner:        DEFAULT_TAPE_DEVICE="/dev/null" HAVE_MMAP HAVE_SYSVSHM
planner:        LOCKING=POSIX_FCNTL SETPGRP_VOID DEBUG_CODE
planner:        AMANDA_DEBUG_DAYS=4 BSD_SECURITY USE_AMANDAHOSTS
planner:        CLIENT_LOGIN="amanda" FORCE_USERID HAVE_GZIP
planner:        COMPRESS_SUFFIX=".gz" COMPRESS_FAST_OPT="--fast"
planner:        COMPRESS_BEST_OPT="--best" UNCOMPRESS_OPT="-dc"
planner: time 0.000: dgram_bind: socket bound to 0.0.0.0.514
READING CONF FILES...
planner: time 0.003: startup took 0.003 secs

SETTING UP FOR ESTIMATES...
planner: time 0.003: setting up estimates for keep.cis.uab.edu:/usr/local
setup_estimate: keep.cis.uab.edu:/usr/local: command 0, options:
    last_level 0 next_level0 7 level_days 0
    getting estimates 0 (50910) 1 (0) -1 (-1)
planner: time 0.003: setting up estimates took 0.000 secs

GETTING ESTIMATES...
driver: pid 9958 executable /usr/local/libexec/driver version 2.4.4p1
driver: send-cmd time 0.009 to taper: START-TAPER 20031222
dumper: dgram_bind: socket bound to 0.0.0.0.520
dumper: pid 9962 executable dumper0 version 2.4.4p1, using port 520
driver: started dumper0 pid 9962
taper: pid 9960 executable taper version 2.4.4p1
dumper: dgram_bind: socket bound to 0.0.0.0.525
dumper: pid 9967 executable dumper1 version 2.4.4p1, using port 525
driver: started dumper1 pid 9967
driver: started dumper2 pid 9968
taper: page size is 4096
taper: buffer size is 32768
taper: buffer[00] at 0x400cf000
taper: buffer[01] at 0x400d7000
taper: buffer[02] at 0x400df000
taper: buffer[03] at 0x400e7000
taper: buffer[04] at 0x400ef000
taper: buffer[05] at 0x400f7000
taper: buffer[06] at 0x400ff000
taper: buffer[07] at 0x40107000
taper: buffer[08] at 0x4010f000
taper: buffer[09] at 0x40117000
taper: buffer[10] at 0x4011f000
taper: buffer[11] at 0x40127000
taper: buffer[12] at 0x4012f000
taper: buffer[13] at 0x40137000
taper: buffer[14] at 0x4013f000
taper: buffer[15] at 0x40147000
taper: buffer[16] at 0x4014f000
taper: buffer[17] at 0x40157000
taper: buffer[18] at 0x4015f000
taper: buffer[19] at 0x40167000
taper: buffer structures at 0x4016f000 for 240 bytes
changer: opening pipe to: /usr/local/libexec/chg-scsi -info
dumper: dgram_bind: socket bound to 0.0.0.0.527
dumper: pid 9969 executable dumper3 version 2.4.4p1, using port 527
driver: started dumper3 pid 9969
dumper: dgram_bind: socket bound to 0.0.0.0.526
dumper: pid 9968 executable dumper2 version 2.4.4p1, using port 526
planner: time 2.097: got result for host keep.cis.uab.edu disk /usr/local: 0 -> 396030K, 1 -> -1K, -1 -> -1K
planner: time 2.097: getting estimates took 2.093 secs
FAILED QUEUE: empty
DONE QUEUE:
  0: keep.cis.uab.edu /usr/local

[it must be right above here that something failed...it saw that the new size of /usr/local was 396M, so that's right. What's the 1 -> 1K, -1 -> -1K stuff? Is that (a level 0 would be 396M, a level 1 is -1M?]


ANALYZING ESTIMATES...
pondering keep.cis.uab.edu:/usr/local... next_level0 7 last_level 0 (not due for a full dump, picking an incr level)
   picklev: last night 0, so tonight level 1
  curr level 1 size -1 total size 95 total_lev0 0 balanced-lev0size 56575
INITIAL SCHEDULE (size 95):
  keep.cis.uab.edu /usr/local pri 0 lev 1 size -1

DELAYING DUMPS IF NEEDED, total_size 95, tape length 499384320 mark 0
planner: FAILED keep.cis.uab.edu /usr/local 20031222 1 [dump larger than tape, -1 KB, skipping incremental]
  delay: Total size now 64.
planner: cannot fit anything on tape, bailing out
planner: time 2.098: cannot fit anything on tape, bailing out
planner: time 2.098: pid 9956 finish time Mon Dec 22 18:06:56 2003
driver: adding holding disk 0 dir /dumps/amanda size 52428800
reserving 52428800 out of 52428800 for degraded-mode dumps
driver: start time 2.090 inparallel 4 bandwidth 6720 diskspace 52428800 dir OBSOLETE datestamp 20031222 driver: drain-ends ta
peq FIRST big-dumpers sssS
changer: got exit: 0 str: 4 10 1 1
changer_query: changer return was 10 1 1
changer_query: searchable = 1
changer_find: looking for CIS-005 changer is searchable = 1
changer_search: CIS-005
changer: opening pipe to: /usr/local/libexec/chg-scsi -search CIS-005
changer: got exit: 0 str: 5 /dev/nst0
taper: slot 5: date X        label CIS-005 (exact label match)
taper: read label `CIS-005' date `X'
taper: wrote label `CIS-005' date `20031222'
driver: result time 140.421 from taper: TAPER-OK
driver: state time 140.422 free kps: 6720 space: 52428800 taper: idle idle-dumpers: 4 qlen tapeq: 0 runq: 0 roomq: 0 wakeup:
86400 driver-idle: not-idle
driver: interface-state time 140.422 if : free 600 if ETH2: free 5120 if LOCAL: free 1000
driver: hdisk-state time 140.422 hdisk 0: free 52428800 dumpers 0
driver: QUITTING time 140.422 telling children to quit
driver: send-cmd time 140.422 to dumper0: QUIT
driver: send-cmd time 140.422 to dumper1: QUIT
driver: send-cmd time 140.422 to dumper2: QUIT
driver: send-cmd time 140.422 to dumper3: QUIT
driver: send-cmd time 140.422 to taper: QUIT
taper: DONE [idle wait: 0.000 secs]
taper: writing end marker. [CIS-005 OK kb 0 fm 0]
driver: FINISHED time 150.571
amdump: end at Mon Dec 22 18:09:24 CST 2003
<Prev in Thread] Current Thread [Next in Thread>