On Sat, 31 Mar 2007, Jean-Louis Martineau wrote:

Could you post the amdump.1 log files and the curinfo/b02.foo.com/_var_db_pkg/info file.

amanda.conf:

# general setup

org "DailySet"                  # name of this config
mailto "ops AT foo DOT com"        # where reports go
dumpcycle 30                    # how often a 'full dump' happens
runspercycle 15                 # 0=same as dumpcycle
tapecycle 24                    # min tapes in a cycle
                                # this will be a problem w/o a changer
dumpuser "operator"             # user to run as
usetimestamps YES               # allow multiple runs per day (??)

# tape options

tapedev "/dev/nsa0"             # tape device
labelstr "DAILY[0-9][0-9]*"     # regex to determine if we've got a tape
                                # for this config
tapetype LTO                    # type of tape, see below

# resource usage

netusage 200                    # max datarate in KB/s
inparallel 5                    # number of concurrent dumps
#dumporder "tttTTTTTT"          # no idea, using defaults
maxdumps 1                      # max dumps/host in parallel
bumpsize 10                     # see manpage
bumpmult 1.5                    # see manpage

#reserve 40                     # max % of holding disk space to use

# file locations

logdir "/var/log/amanda"        # where to log
indexdir "/var/db/amanda/index" # where backup catalogs are stored
infofile "/var/db/amanda/db"    # where ? is stored
tapelist "tapelist"             # filename for tape index

# holding disk(s)

holdingdisk spool1 {
        directory "/spool2/amanda"
        use -5 Gb               # leave 5GB free
}

# dumptypes - referred to in the "disklist" file

define dumptype normaldump {
        comment "normal operation - amanda controls full/inc"
        auth "bsdtcp"           # type of auth, also krb4
        compress client fast    # compress on client side, fast
        # exclude list file     # define an exclude file (tar)
        # include list file     # inverse of exclude (tar)
        index yes               # make a catalog of files
        maxdumps 1              # num parallel dumps
        record yes              # update 'dumpdates' on client
        strategy standard       # amanda sets dump type
}

define dumptype normaltar {
        comment "normal operation - amanda controls full/inc"
        auth "bsdtcp"           # type of auth, also krb4
        program "GNUTAR"        # use dump or tar
        compress client fast    # compress on client side, fast
        # exclude list file     # define an exclude file (tar)
        # include list file     # inverse of exclude (tar)
        index yes               # make a catalog of files
        maxdumps 1              # num parallel dumps
        record yes              # update 'dumpdates' on client
        strategy standard       # amanda sets dump type
}

define tapetype LTO {
   length 100 gb
   filemark 0 kbytes
   speed 13872 kps

 }

disklist snippet:

# this machine
devel2.foo.com / normaldump
devel2.foo.com /spool normaldump
devel2.foo.com /spool2/data/CQ_Logs normaltar
devel2.foo.com /spool2/jails normaltar
devel2.foo.com /usr/local normaldump
devel2.foo.com /home normaldump
devel2.foo.com /var/db normaltar

# toolbox
toolbox.foo.com / normaldump
toolbox.foo.com /home normaldump
toolbox.foo.com /usr/local normaldump
toolbox.foo.com /var/qmail/control normaltar
toolbox.foo.com /var/qmail/bin normaltar
toolbox.foo.com /var/qmail/alias normaltar
toolbox.foo.com /var/db normaltar
toolbox.foo.com /spool normaldump

example failed report:

*** THE DUMPS DID NOT FINISH PROPERLY!

These dumps were to tape DAILY19.
The next tape Amanda expects to use is: a new tape.

FAILURE AND STRANGE DUMP SUMMARY:

[...]
  toolbox.foo.com  /                     RESULTS MISSING
  toolbox.foo.com  /home                 RESULTS MISSING
  toolbox.foo.com  /usr/local            RESULTS MISSING
  toolbox.foo.com  /var/db               RESULTS MISSING
  toolbox.foo.com  /spool                RESULTS MISSING

(amandad.20070331031002.debug)

security_getdriver(name=bsdtcp) returns 0x28094900
amandad: version 2.5.1p3
amandad: build: VERSION="Amanda-2.5.1p3"
amandad:        BUILT_DATE="Sat Feb 17 23:26:18 EST 2007"

rc/sys/PIII-XEON-single2 i386"
amandad:        CC="cc"

-without-server' '--prefix=/usr/local' '--build=i386-portbld-freebsd4.11'"
amandad: paths: bindir="/usr/local/bin" sbindir="/usr/local/sbin"
amandad:        libexecdir="/usr/local/libexec/amanda"
amandad:        mandir="/usr/local/man" AMANDA_TMPDIR="/tmp/amanda"
amandad:        AMANDA_DBGDIR="/tmp/amanda"
amandad:        CONFIG_DIR="/usr/local/etc/amanda" DEV_PREFIX="/dev/"
amandad:        RDEV_PREFIX="/dev/r" DUMP="/sbin/dump"
amandad:        RESTORE="/sbin/restore" VDUMP=UNDEF VRESTORE=UNDEF

amandad:        SAMBA_CLIENT=UNDEF GNUTAR="/usr/local/bin/gtar"
amandad:        COMPRESS_PATH="/usr/bin/gzip"
amandad:        UNCOMPRESS_PATH="/usr/bin/gzip" LPRCMD="/usr/bin/lpr"
amandad:        MAILER="/usr/bin/Mail"
amandad:        listed_incr_dir="/usr/local/var/amanda/gnutar-lists"
amandad: defs:  DEFAULT_SERVER="devel2.foo.com"
amandad:        DEFAULT_CONFIG="DailySet1"
amandad:        DEFAULT_TAPE_SERVER="devel2.foo.com" HAVE_MMAP
amandad:        LOCKING=POSIX_FCNTL DEBUG_CODE AMANDA_DEBUG_DAYS=4
amandad:        BSD_SECURITY RSH_SECURITY USE_AMANDAHOSTS
amandad:        CLIENT_LOGIN="operator" FORCE_USERID HAVE_GZIP
amandad:        COMPRESS_SUFFIX=".gz" COMPRESS_FAST_OPT="--fast"
amandad:        COMPRESS_BEST_OPT="--best" UNCOMPRESS_OPT="-dc"
security_handleinit(handle=0x8051080, driver=0x28094900 (BSDTCP))
security_streaminit(stream=0x8058000, driver=0x28094900 (BSDTCP))
amandad: time 0.078: accept recv REQ pkt:
<<<<<
SERVICE noop
OPTIONS features=fffffeff9ffeffffff7f;

amandad: time 0.078: creating new service: noop
OPTIONS features=fffffeff9ffeffffff7f;
amandad: time 0.079: sending ACK pkt:
<<<<<

amandad: time 0.083: sending REP pkt:
<<<<<
OPTIONS features=fffffeff9ffeffffff7f;

amandad: time 0.384: received ACK pkt:
<<<<<

security_close(handle=0x8051080, driver=0x28094900 (BSDTCP))
security_stream_close(0x8058000)
security_handleinit(handle=0x8058000, driver=0x28094900 (BSDTCP))
security_streaminit(stream=0x8059000, driver=0x28094900 (BSDTCP))
amandad: time 0.558: accept recv REQ pkt:
<<<<<
SERVICE sendsize

=DailySet1;

DUMP /  0 1970:1:1:0:0:0 -1  OPTIONS |;auth=bsdtcp;compress-fast;index;
DUMP /  1 2007:3:29:7:34:51 -1  OPTIONS |;auth=bsdtcp;compress-fast;index;

amandad: time 0.558: creating new service: sendsize

=DailySet1;

ex;

DUMP /  0 1970:1:1:0:0:0 -1  OPTIONS |;auth=bsdtcp;compress-fast;index;
DUMP /  1 2007:3:29:7:34:51 -1  OPTIONS |;auth=bsdtcp;compress-fast;index;

amandad: time 0.559: sending ACK pkt:
<<<<<

amandad: time 0.564: sending PREP pkt:
<<<<<
OPTIONS features=fffffeff9ffeffffff7f;

amandad: time 1.997: sending PREP pkt:
<<<<<
OPTIONS features=fffffeff9ffeffffff7f;
/ 0 SIZE 48443

amandad: time 3.656: sending PREP pkt:
<<<<<
OPTIONS features=fffffeff9ffeffffff7f;
/ 0 SIZE 48443
/ 1 SIZE 64

amandad: time 7.225: sending PREP pkt:
<<<<<
OPTIONS features=fffffeff9ffeffffff7f;
/ 0 SIZE 48443
/ 1 SIZE 64
/home 0 SIZE 271194

amandad: time 12.663: sending PREP pkt:
<<<<<
OPTIONS features=fffffeff9ffeffffff7f;
/ 0 SIZE 48443
/ 1 SIZE 64
/home 0 SIZE 271194
/home 1 SIZE 135189

amandad: time 14.733: sending PREP pkt:
<<<<<
OPTIONS features=fffffeff9ffeffffff7f;
/ 0 SIZE 48443
/ 1 SIZE 64
/home 0 SIZE 271194
/home 1 SIZE 135189
/usr/local 0 SIZE 670873

amandad: time 40.595: sending PREP pkt:
<<<<<
OPTIONS features=fffffeff9ffeffffff7f;
/ 0 SIZE 48443
/ 1 SIZE 64
/home 0 SIZE 271194
/home 1 SIZE 135189
/usr/local 0 SIZE 670873
/usr/local 2 SIZE 3893

amandad: time 40.618: sending PREP pkt:
<<<<<
OPTIONS features=fffffeff9ffeffffff7f;
/ 0 SIZE 48443
/ 1 SIZE 64
/home 0 SIZE 271194
/home 1 SIZE 135189
/usr/local 0 SIZE 670873
/usr/local 2 SIZE 3893
/var/qmail/control 0 SIZE 50

amandad: time 40.639: sending PREP pkt:
<<<<<
OPTIONS features=fffffeff9ffeffffff7f;
/ 0 SIZE 48443
/ 1 SIZE 64
/home 0 SIZE 271194
/home 1 SIZE 135189
/usr/local 0 SIZE 670873
/usr/local 2 SIZE 3893
/var/qmail/control 0 SIZE 50
/var/qmail/control 1 SIZE 10

amandad: time 40.662: sending PREP pkt:
<<<<<
OPTIONS features=fffffeff9ffeffffff7f;
/ 0 SIZE 48443
/ 1 SIZE 64
/home 0 SIZE 271194
/home 1 SIZE 135189
/usr/local 0 SIZE 670873
/usr/local 2 SIZE 3893
/var/qmail/control 0 SIZE 50
/var/qmail/control 1 SIZE 10
/var/qmail/bin 0 SIZE 750

amandad: time 40.683: sending PREP pkt:
<<<<<
OPTIONS features=fffffeff9ffeffffff7f;
/ 0 SIZE 48443
/ 1 SIZE 64
/home 0 SIZE 271194
/home 1 SIZE 135189
/usr/local 0 SIZE 670873
/usr/local 2 SIZE 3893
/var/qmail/control 0 SIZE 50
/var/qmail/control 1 SIZE 10
/var/qmail/bin 0 SIZE 750
/var/qmail/bin 1 SIZE 10

amandad: time 40.706: sending PREP pkt:
<<<<<
OPTIONS features=fffffeff9ffeffffff7f;
/ 0 SIZE 48443
/ 1 SIZE 64
/home 0 SIZE 271194
/home 1 SIZE 135189
/usr/local 0 SIZE 670873
/usr/local 2 SIZE 3893
/var/qmail/control 0 SIZE 50
/var/qmail/control 1 SIZE 10
/var/qmail/bin 0 SIZE 750
/var/qmail/bin 1 SIZE 10
/var/qmail/alias 0 SIZE 10

amandad: time 40.727: sending PREP pkt:
<<<<<
OPTIONS features=fffffeff9ffeffffff7f;
/ 0 SIZE 48443
/ 1 SIZE 64
/home 0 SIZE 271194
/home 1 SIZE 135189
/usr/local 0 SIZE 670873
/usr/local 2 SIZE 3893
/var/qmail/control 0 SIZE 50
/var/qmail/control 1 SIZE 10
/var/qmail/bin 0 SIZE 750
/var/qmail/bin 1 SIZE 10
/var/qmail/alias 0 SIZE 10
/var/qmail/alias 1 SIZE 10

amandad: time 40.811: sending PREP pkt:
<<<<<
OPTIONS features=fffffeff9ffeffffff7f;
/ 0 SIZE 48443
/ 1 SIZE 64
/home 0 SIZE 271194
/home 1 SIZE 135189
/usr/local 0 SIZE 670873
/usr/local 2 SIZE 3893
/var/qmail/control 0 SIZE 50
/var/qmail/control 1 SIZE 10
/var/qmail/bin 0 SIZE 750
/var/qmail/bin 1 SIZE 10
/var/qmail/alias 0 SIZE 10
/var/qmail/alias 1 SIZE 10
/var/db 0 SIZE 888850

amandad: time 40.861: sending PREP pkt:
<<<<<
OPTIONS features=fffffeff9ffeffffff7f;
/ 0 SIZE 48443
/ 1 SIZE 64
/home 0 SIZE 271194
/home 1 SIZE 135189
/usr/local 0 SIZE 670873
/usr/local 2 SIZE 3893
/var/qmail/control 0 SIZE 50
/var/qmail/control 1 SIZE 10
/var/qmail/bin 0 SIZE 750
/var/qmail/bin 1 SIZE 10
/var/qmail/alias 0 SIZE 10
/var/qmail/alias 1 SIZE 10
/var/db 0 SIZE 888850
/var/db 1 SIZE 11830

amandad: time 40.910: sending PREP pkt:
<<<<<
OPTIONS features=fffffeff9ffeffffff7f;
/ 0 SIZE 48443
/ 1 SIZE 64
/home 0 SIZE 271194
/home 1 SIZE 135189
/usr/local 0 SIZE 670873
/usr/local 2 SIZE 3893
/var/qmail/control 0 SIZE 50
/var/qmail/control 1 SIZE 10
/var/qmail/bin 0 SIZE 750
/var/qmail/bin 1 SIZE 10
/var/qmail/alias 0 SIZE 10
/var/qmail/alias 1 SIZE 10
/var/db 0 SIZE 888850
/var/db 1 SIZE 11830
/var/db 2 SIZE 8880

amandad: time 43.744: sending PREP pkt:
<<<<<
OPTIONS features=fffffeff9ffeffffff7f;
/ 0 SIZE 48443
/ 1 SIZE 64
/home 0 SIZE 271194
/home 1 SIZE 135189
/usr/local 0 SIZE 670873
/usr/local 2 SIZE 3893
/var/qmail/control 0 SIZE 50
/var/qmail/control 1 SIZE 10
/var/qmail/bin 0 SIZE 750
/var/qmail/bin 1 SIZE 10
/var/qmail/alias 0 SIZE 10
/var/qmail/alias 1 SIZE 10
/var/db 0 SIZE 888850
/var/db 1 SIZE 11830
/var/db 2 SIZE 8880
/spool 0 SIZE 4112

amandad: time 46.293: sending PREP pkt:
<<<<<
OPTIONS features=fffffeff9ffeffffff7f;
/ 0 SIZE 48443
/ 1 SIZE 64
/home 0 SIZE 271194
/home 1 SIZE 135189
/usr/local 0 SIZE 670873
/usr/local 2 SIZE 3893
/var/qmail/control 0 SIZE 50
/var/qmail/control 1 SIZE 10
/var/qmail/bin 0 SIZE 750
/var/qmail/bin 1 SIZE 10
/var/qmail/alias 0 SIZE 10
/var/qmail/alias 1 SIZE 10
/var/db 0 SIZE 888850
/var/db 1 SIZE 11830
/var/db 2 SIZE 8880
/spool 0 SIZE 4112
/spool 1 SIZE 43

amandad: time 46.294: sending REP pkt:
<<<<<
OPTIONS features=fffffeff9ffeffffff7f;
/ 0 SIZE 48443
/ 1 SIZE 64
/home 0 SIZE 271194
/home 1 SIZE 135189
/usr/local 0 SIZE 670873
/usr/local 2 SIZE 3893
/var/qmail/control 0 SIZE 50
/var/qmail/control 1 SIZE 10
/var/qmail/bin 0 SIZE 750
/var/qmail/bin 1 SIZE 10
/var/qmail/alias 0 SIZE 10
/var/qmail/alias 1 SIZE 10
/var/db 0 SIZE 888850
/var/db 1 SIZE 11830
/var/db 2 SIZE 8880
/spool 0 SIZE 4112
/spool 1 SIZE 43

amandad: time 46.442: received ACK pkt:
<<<<<

security_close(handle=0x8058000, driver=0x28094900 (BSDTCP))
security_stream_close(0x8059000)
amandad: time 46.455: pid 43785 finish time Sat Mar 31 03:10:48 2007

(amandad.20070331033130.debug - trimmed compile info)
security_handleinit(handle=0x8052000, driver=0x28094900 (BSDTCP))
security_streaminit(stream=0x8058000, driver=0x28094900 (BSDTCP))
amandad: time 0.000: accept recv REQ pkt:
<<<<<
SERVICE sendbackup

;index;

amandad: time 0.001: creating new service: sendbackup

;index;

amandad: time 0.001: sending ACK pkt:
<<<<<

security_streaminit(stream=0x8079000, driver=0x28094900 (BSDTCP))
security_streaminit(stream=0x8082000, driver=0x28094900 (BSDTCP))
security_streaminit(stream=0x808b000, driver=0x28094900 (BSDTCP))
amandad: time 0.007: sending REP pkt:
<<<<<
CONNECT DATA 499999 MESG 499998 INDEX 499997
OPTIONS features=fffffeff9ffeffffff7f;

amandad: time 0.139: received ACK pkt:
<<<<<

security_close(handle=0x8052000, driver=0x28094900 (BSDTCP))
security_stream_close(0x8058000)
security_stream_close(0x808b000)
security_stream_close(0x8082000)
security_stream_close(0x8079000)
amandad: time 0.180: pid 48113 finish time Sat Mar 31 03:31:30 2007

(amandad.20070331033147.debug - trimmed compile info)
security_handleinit(handle=0x8052000, driver=0x28094900 (BSDTCP))
security_streaminit(stream=0x8058000, driver=0x28094900 (BSDTCP))
amandad: time 0.000: accept recv REQ pkt:
<<<<<
SERVICE sendbackup

dex;

amandad: time 0.000: creating new service: sendbackup

dex;

amandad: time 0.001: sending ACK pkt:
<<<<<

security_streaminit(stream=0x8079000, driver=0x28094900 (BSDTCP))
security_streaminit(stream=0x8082000, driver=0x28094900 (BSDTCP))
security_streaminit(stream=0x808b000, driver=0x28094900 (BSDTCP))
amandad: time 0.014: sending REP pkt:
<<<<<
CONNECT DATA 499999 MESG 499998 INDEX 499997
OPTIONS features=fffffeff9ffeffffff7f;

amandad: time 0.135: received ACK pkt:
<<<<<

security_close(handle=0x8052000, driver=0x28094900 (BSDTCP))
security_stream_close(0x8058000)
security_stream_close(0x808b000)
security_stream_close(0x8082000)
security_stream_close(0x8079000)
amandad: time 0.177: pid 48154 finish time Sat Mar 31 03:31:47 2007

(amandad.20070331033203.debug - compile info trimmed)
security_handleinit(handle=0x8052000, driver=0x28094900 (BSDTCP))
security_streaminit(stream=0x8058000, driver=0x28094900 (BSDTCP))
amandad: time 0.001: accept recv REQ pkt:
<<<<<
SERVICE sendbackup

st;index;

amandad: time 0.001: creating new service: sendbackup

st;index;

amandad: time 0.001: sending ACK pkt:
<<<<<

security_streaminit(stream=0x8079000, driver=0x28094900 (BSDTCP))
security_streaminit(stream=0x8082000, driver=0x28094900 (BSDTCP))
security_streaminit(stream=0x808b000, driver=0x28094900 (BSDTCP))
amandad: time 0.014: sending REP pkt:
<<<<<
CONNECT DATA 499999 MESG 499998 INDEX 499997
OPTIONS features=fffffeff9ffeffffff7f;

amandad: time 0.136: received ACK pkt:
<<<<<

security_close(handle=0x8052000, driver=0x28094900 (BSDTCP))
security_stream_close(0x8058000)
security_stream_close(0x808b000)
security_stream_close(0x8082000)
security_stream_close(0x8079000)
amandad: time 0.179: pid 48217 finish time Sat Mar 31 03:32:03 2007

(amandad.20070331180321.debug - compile info trimmed)
security_handleinit(handle=0x8051080, driver=0x28094900 (BSDTCP))
security_streaminit(stream=0x8058000, driver=0x28094900 (BSDTCP))
amandad: time 0.557: accept recv REQ pkt:
<<<<<
SERVICE noop
OPTIONS features=fffffeff9ffeffffff7f;

amandad: time 0.557: creating new service: noop
OPTIONS features=fffffeff9ffeffffff7f;

amandad: time 0.557: sending ACK pkt:
<<<<<

amandad: time 0.562: sending REP pkt:
<<<<<
OPTIONS features=fffffeff9ffeffffff7f;

amandad: time 0.757: received ACK pkt:
<<<<<

security_close(handle=0x8051080, driver=0x28094900 (BSDTCP))
security_stream_close(0x8058000)
security_handleinit(handle=0x8058000, driver=0x28094900 (BSDTCP))
security_streaminit(stream=0x8059000, driver=0x28094900 (BSDTCP))
amandad: time 0.929: accept recv REQ pkt:
<<<<<
SERVICE selfcheck

=DailySet1;
DUMP /spool 0 OPTIONS |;auth=bsdtcp;compress-fast;index;
GNUTAR /var/db 0 OPTIONS |;auth=bsdtcp;compress-fast;index;
GNUTAR /var/qmail/alias 0 OPTIONS |;auth=bsdtcp;compress-fast;index;
GNUTAR /var/qmail/bin 0 OPTIONS |;auth=bsdtcp;compress-fast;index;
GNUTAR /var/qmail/control 0 OPTIONS |;auth=bsdtcp;compress-fast;index;
DUMP /usr/local 0 OPTIONS |;auth=bsdtcp;compress-fast;index;
DUMP /home 0 OPTIONS |;auth=bsdtcp;compress-fast;index;
DUMP / 0 OPTIONS |;auth=bsdtcp;compress-fast;index;

amandad: time 0.929: creating new service: selfcheck

=DailySet1;
DUMP /spool 0 OPTIONS |;auth=bsdtcp;compress-fast;index;
GNUTAR /var/db 0 OPTIONS |;auth=bsdtcp;compress-fast;index;
GNUTAR /var/qmail/alias 0 OPTIONS |;auth=bsdtcp;compress-fast;index;
GNUTAR /var/qmail/bin 0 OPTIONS |;auth=bsdtcp;compress-fast;index;
GNUTAR /var/qmail/control 0 OPTIONS |;auth=bsdtcp;compress-fast;index;
DUMP /usr/local 0 OPTIONS |;auth=bsdtcp;compress-fast;index;
DUMP /home 0 OPTIONS |;auth=bsdtcp;compress-fast;index;
DUMP / 0 OPTIONS |;auth=bsdtcp;compress-fast;index;

amandad: time 0.930: sending ACK pkt:
<<<<<

amandad: time 0.939: sending REP pkt:
<<<<<
OPTIONS features=fffffeff9ffeffffff7f;
OK /spool
OK /spool
OK /dev/da0s1g
OK /var/db
OK /var/db
OK /var/db
OK /var/qmail/alias
OK /var/qmail/alias
OK /var/qmail/alias
OK /var/qmail/bin
OK /var/qmail/bin
OK /var/qmail/bin
OK /var/qmail/control
OK /var/qmail/control
OK /var/qmail/control
OK /usr/local
OK /usr/local
OK /dev/da0s1f
OK /home
OK /home
OK /dev/da0s2g
OK /
OK /
OK /dev/da0s1a
OK /usr/local/libexec/amanda/runtar executable
OK /sbin/dump executable
OK /sbin/restore executable
OK /usr/local/bin/gtar executable
OK /usr/local/var/amanda/gnutar-lists/. read/writable
OK /etc/amandates read/writable
OK /usr/bin/gzip executable
OK /etc/dumpdates read/writable
OK /dev/null read/writable
OK /tmp/amanda has more than 64 KB available.
OK /tmp/amanda has more than 64 KB available.
OK /etc has more than 64 KB available.

amandad: time 1.168: received ACK pkt:
<<<<<

security_close(handle=0x8058000, driver=0x28094900 (BSDTCP))
security_stream_close(0x8059000)
amandad: time 1.170: pid 22907 finish time Sat Mar 31 18:03:22 2007

Last night's run has gotten worse. No report was generated, and amcheck thinks that a dump is still running (it's not). While before I had two problem hosts, it seems to be growing. This run had a ton of "MISSING RESULTS" in my manually-generated amreport. I've attached the last amdump log - it's gzipped because it's around 1MB uncompressed.

On the server, the infofile you're looking for does not exist:

[devel2]/var/db/amanda/db # grep infofile /usr/local/etc/amanda/DailySet1/amanda.conf

infofile "/var/db/amanda/db"

[devel2]/var/db/amanda/db # ls -la b02.foo.com/
total 4
drwx------   4 operator  wheel   512 Mar 31 03:32 .
drwx------  24 operator  wheel  1024 Mar 29 05:18 ..
drwx------   2 operator  wheel   512 Mar 30 16:32 _usr_local
drwx------   2 operator  wheel   512 Mar 31 03:32 _var_qmail

[devel2]/var/db/amanda/db # ls -la b02.foo.com/_var_qmail/
total 2
drwx------  2 operator  wheel  512 Mar 31 03:32 .
drwx------  4 operator  wheel  512 Mar 31 03:32 ..

[devel2]/var/db/amanda/db # ls -la b02.foo.com/_usr_local/
total 2
drwx------  2 operator  wheel  512 Mar 30 16:32 .
drwx------  4 operator  wheel  512 Mar 31 03:32 ..
[devel2]/var/db/amanda/db #

Something is going wrong, and it's getting worse.

Since there were some questions about permissions, here's a list of both one problem client and the server.

server:

[devel2]/usr/local/libexec/amanda # ls -la
total 733
drwxr-xr-x   2 root      wheel       1024 Mar 14 01:54 .
drwxr-xr-x  10 root      wheel        512 Mar 16 19:46 ..
-r-xr-xr-x   1 operator  operator   18504 Mar 14 01:54 amandad
-r--r--r--   1 operator  operator     184 Mar 14 01:54 amcat.awk
-r-xr-xr-x   1 operator  operator    8008 Mar 14 01:54 amcleanupdisk
-r-xr-xr-x   1 operator  operator   15780 Mar 14 01:54 amidxtaped
-r-xr-xr-x   1 operator  operator   31520 Mar 14 01:54 amindexd
-r-xr-xr-x   1 operator  operator    6760 Mar 14 01:54 amlogroll
-r--r--r--   1 operator  operator   17606 Mar 14 01:54 amplot.awk
-r--r--r--   1 operator  operator    3283 Mar 14 01:54 amplot.g
-r--r--r--   1 operator  operator    3293 Mar 14 01:54 amplot.gp
-r-xr-xr-x   1 operator  operator    9268 Mar 14 01:54 amtrmidx
-r-xr-xr-x   1 operator  operator    8684 Mar 14 01:54 amtrmlog
-r-sr-x---   1 root      operator   10504 Mar 14 01:51 calcsize
-r-xr-xr-x   1 operator  operator   11428 Mar 14 01:54 chg-chio
-r-xr-xr-x   1 operator  operator   10059 Mar 14 01:54 chg-chs
-r-xr-xr-x   1 operator  operator    7896 Mar 14 01:54 chg-disk
-r-xr-xr-x   1 operator  operator    7407 Mar 14 01:54 chg-iomega
-r-xr-xr-x   1 operator  operator    5145 Mar 14 01:54 chg-juke
-r-xr-xr-x   1 operator  operator    6854 Mar 14 01:54 chg-manual
-r-xr-xr-x   1 operator  operator   13091 Mar 14 01:54 chg-mcutil
-r-xr-xr-x   1 operator  operator    5773 Mar 14 01:54 chg-mtx
-r-xr-xr-x   1 operator  operator   11955 Mar 14 01:54 chg-multi
-r-xr-xr-x   1 operator  operator    1698 Mar 14 01:54 chg-null
-r-xr-xr-x   1 operator  operator    3980 Mar 14 01:54 chg-rait
-r-xr-xr-x   1 operator  operator    6925 Mar 14 01:54 chg-rth
-r-xr-xr-x   1 operator  operator  148392 Mar 14 01:54 chg-scsi
-r-xr-xr-x   1 operator  operator   40239 Mar 14 01:54 chg-zd-mtx
-r-xr-xr-x   1 operator  operator   17032 Mar 14 01:54 chunker
-r-xr-xr-x   1 operator  operator   46704 Mar 14 01:54 driver
-r-sr-x---   1 root      operator   30344 Mar 14 01:54 dumper
-r-sr-x---   1 root      operator    5792 Mar 14 01:51 killpgrp
-r-xr-xr-x   1 operator  operator    4224 Mar 14 01:51 noop
-r-xr-xr-x   1 operator  operator    4847 Mar 14 01:51 patch-system
-r-sr-x---   1 root      operator   42776 Mar 14 01:54 planner
-r-sr-x---   1 root      operator    4088 Mar 14 01:51 rundump
-r-sr-x---   1 root      operator    6292 Mar 14 01:51 runtar
-r-xr-xr-x   1 operator  operator   17852 Mar 14 01:51 selfcheck
-r-xr-xr-x   1 operator  operator   30792 Mar 14 01:51 sendbackup
-r-xr-xr-x   1 operator  operator   32880 Mar 14 01:51 sendsize
-r-xr-xr-x   1 operator  operator   50632 Mar 14 01:54 taper
-r-xr-xr-x   1 operator  operator    3260 Mar 14 01:51 versionsuffix

client:

bash-2.04$ cd /usr/local/libexec/amanda/
bash-2.04$ ls -la
total 148
drwxr-xr-x  2 root      wheel       512 Mar 14 01:38 .
drwxr-xr-x  7 root      wheel       512 Mar 20 20:06 ..
-r-xr-xr-x  1 operator  operator  18344 Feb 17 23:39 amandad
-r-sr-x---  1 root      operator  10440 Feb 17 23:39 calcsize
-r-sr-x---  1 root      operator   5792 Feb 17 23:40 killpgrp
-r-xr-xr-x  1 operator  operator   4224 Feb 17 23:39 noop
-r-xr-xr-x  1 operator  operator   4857 Feb 17 23:40 patch-system
-r-sr-x---  1 root      operator   4088 Feb 17 23:40 rundump
-r-sr-x---  1 root      operator   6292 Feb 17 23:40 runtar
-r-xr-xr-x  1 operator  operator  17788 Feb 17 23:40 selfcheck
-r-xr-xr-x  1 operator  operator  30632 Feb 17 23:40 sendbackup
-r-xr-xr-x  1 operator  operator  32688 Feb 17 23:40 sendsize
-r-xr-xr-x  1 operator  operator   3260 Feb 17 23:40 versionsuffix

I have lots more logs on all these clients.  Nothing is jumping out at me...

Thanks,

Charles

Charles Sprickman wrote:

Hello all,

I recently upgraded from 2.4.3 to 2.5.1p3 and things have mostly been working correctly except for a few rough edges. To complicate matters, we also upgraded from an AIT drive to an LTO drive. We're currently using 100GB tapes, which comfortably fit an entire level 0 dump (about 60GB).

We run bsdtcp auth on all hosts (the main thing driving the update, some remote sites had mtu issues that would cause big estimates to get dropped).

We have about 20GB of holding disk space available.

We use a mix of gtar (1.16.1) and dump, all on FreeBSD 4.11.

Going through the logs it looks like I've got a number of problems.

First is the tape size issue:

[devel2]/var/log/amanda # grep FAIL log.20070329.0 FAIL planner b02.foo.com /var/qmail 20070329 0 [dump larger than available tape space, 2147483647 KB, but cannot incremental dump new disk] FAIL planner b02.foo.com /var/db/pkg 20070329 0 [dump larger than available tape space, 2147483647 KB, but cannot incremental dump new disk]

This seems odd since not only do we have more than enough tape space, but those are very, very small tar backups:

[b02]/var/db/pkg # du -hs
3.8M    .
[b02]/var/qmail # du -hs
1.5M    .

Then we have issues that look like permissions issues, but I can't reproduce them by hand:

FAIL dumper b02.foo.com / 20070329 0 [err create /var/db/amanda/index/b02.foo.com/_/20070329_0.gz.tmp: Operation not permitted]

[devel2]/var/log/amanda # su -m operator -c "touch /var/db/amanda/index/b02.foo.com/_/20070329_0.gz.tmp" [devel2]/var/log/amanda # ls -l /var/db/amanda/index/b02.fo.com/_/20070329_0.gz.tmp -rw-r--r-- 1 operator wheel 0 Mar 30 20:24 /var/db/amanda/index/b02.foo.com/_/20070329_0.gz.tmp

And then I assume this error is related:

FAIL chunker b02.foo.com / 20070329 0 [cannot read header: got 0 instead of 32768]

And on the client side:

sendbackup: time 1.226: 87: normal(|): DUMP: dumping (Pass III) [directories] sendbackup: time 1.387: 87: normal(|): DUMP: dumping (Pass IV) [regular files]

sendbackup: time 6426.054: index tee cannot write [Broken pipe]
sendbackup: time 6426.055: pid 64720 finish time Thu Mar 29 05:19:43 2007

And also some chunker errors that have no corresponding dumper errors:

FAIL chunker h10.foo.com /spool 20070329 0 [cannot read header: got 0 instead of 32768]

On the client:

sendbackup: time 5543.622: 87: normal(|): DUMP: 3.63% done, finished in 37:33 sendbackup: time 5843.560: 87: normal(|): DUMP: 3.86% done, finished in 37:19 sendbackup: time 6143.781: 87: normal(|): DUMP: 4.09% done, finished in 37:07

sendbackup: time 6358.556: index tee cannot write [Broken pipe]
sendbackup: time 6358.557: pid 67054 finish time Thu Mar 29 05:20:00 2007

And then at the end of the log I have a number of warnings:

WARNING driver chunker4 pid 18178 exited with signal 1
WARNING driver dumper4 pid 18032 exited with signal 1
WARNING driver dumper3 pid 18031 exited with signal 1
WARNING driver dumper2 pid 18030 exited with signal 1
WARNING driver chunker2 pid 18852 exited with signal 1

Can anyone help me kind of focus on a few root issues here? I'm having a really hard time chasing down all these different errors at once.

Thanks,

Charles