Amanda-Users

[LONG] Amanda Tru64 V5.1A client sendsize, /sbin/dump fails

2003-02-13 14:50:50
Subject: [LONG] Amanda Tru64 V5.1A client sendsize, /sbin/dump fails
From: Sean McGeever <seanm AT pobox DOT com>
To: amanda-users AT amanda DOT org
Date: Thu, 13 Feb 2003 18:14:30 +0000
Hi,
        I've failed to find this precise error condition in either the 
amanda or Tru64 archives, so any hints as to solutions would be most welcome.
Sorry for the length of the appended logs, but I hope by including them 
I've provided enough data to enable someone to point me in the right 
direction.

Cheers,

Sean



Context:
--------
Amanda server:  OpenBSD 3.2, (amanda 2.4.2p2)
Amanda client:  Tru64 V5.1A, (amanda 2.4.2p2)
Amanda client operator == amanda (group system), which owns the amanda 
binaries.  Tru64 disk devices are owned by root:system with permissions 660.
Amanda client filesystems are UFS, and are definitely online during this 
operation.

Problem:
--------
'amdump Daily' when run on the amanda server fails when trying to backup 
Tru64 client.  It succeeds, however, when backing-up other clients 
(OpenBSD, Debian).  Logs show failure at the client's estimation stage
(i.e., sendsize).  'amcheck Daily' when run on the amanda server reports 
no error when checking the Tru64 client machine.

Logs:
-----

amanda-server amdump log:

amdump: start at Thu Feb 13 15:31:42 GMT 2003
planner: pid 21505 executable /usr/local/libexec/amanda/planner version 2.4.2p2
planner: build: VERSION="Amanda-2.4.2p2"
planner:        BUILT_DATE="Thu Oct 3 03:37:25 MDT 2002"
planner:        BUILT_MACH="OpenBSD i386.ports.openbsd.org 3.2 GENERIC#26 i386"
planner:        CC="cc"
planner: paths: bindir="/usr/local/bin" sbindir="/usr/local/sbin"
planner:        libexecdir="/usr/local/libexec/amanda"
planner:        mandir="/usr/local/man" AMANDA_TMPDIR="/tmp/amanda"
planner:        AMANDA_DBGDIR="/tmp/amanda" CONFIG_DIR="/etc/amanda"
planner:        DEV_PREFIX="/dev/" RDEV_PREFIX="/dev/r"
planner:        DUMP="/sbin/dump" RESTORE="/sbin/restore"
planner:        SAMBA_CLIENT="/usr/local/bin/smbclient"
planner:        GNUTAR="/usr/local/bin/gtar" COMPRESS_PATH="/usr/bin/gzip"
planner:        UNCOMPRESS_PATH="/usr/bin/gzip" MAILER="/usr/bin/Mail"
planner:        listed_incr_dir="/var/amanda/gnutar-lists"
planner: defs:  DEFAULT_SERVER="i386.ports.openbsd.org"
planner:        DEFAULT_CONFIG="DailySet1"
planner:        DEFAULT_TAPE_SERVER="i386.ports.openbsd.org"
planner:        DEFAULT_TAPE_DEVICE="/dev/nrst0" HAVE_MMAP
planner:        LOCKING=POSIX_FCNTL DEBUG_CODE AMANDA_DEBUG_DAYS=4
planner:        BSD_SECURITY USE_AMANDAHOSTS CLIENT_LOGIN="operator"
planner:        FORCE_USERID HAVE_GZIP COMPRESS_SUFFIX=".gz"
planner:        COMPRESS_FAST_OPT="--fast" COMPRESS_BEST_OPT="--best"
planner:        UNCOMPRESS_OPT="-dc"
planner: dgram_bind: socket bound to 0.0.0.0.607
READING CONF FILES...
driver: pid 11319 executable /usr/local/libexec/amanda/driver version 2.4.2p2
driver: send-cmd time 0.002 to taper: START-TAPER 20030213
startup took 0.011 secs

SETTING UP FOR ESTIMATES...
setting up estimates for $Tru64-client:/
$Tru64-client:/ overdue 12097 days for level 0
setup_estimate: $Tru64-client:/: command 0, options:
    last_level -1 next_level0 -12097 level_days 0
    getting estimates 0 (0) -1 (-1) -1 (-1)
setting up estimates for $Tru64-client:/usr
$Tru64-client:/usr overdue 12097 days for level 0
setup_estimate: $Tru64-client:/usr: command 0, options:
    last_level -1 next_level0 -12097 level_days 0
    getting estimates 0 (0) -1 (-1) -1 (-1)
setting up estimates took 0.000 secs

GETTING ESTIMATES...
taper: pid 9962 executable taper version 2.4.2p2
driver: started dumper0 pid 863
driver: started dumper1 pid 31272
driver: started dumper2 pid 14500
driver: started dumper3 pid 23981
dumper: dgram_bind: socket bound to 0.0.0.0.958
dumper: pid 863 executable dumper version 2.4.2p2, using port 958
dumper: dgram_bind: socket bound to 0.0.0.0.647
dumper: pid 31272 executable dumper version 2.4.2p2, using port 647
dumper: dgram_bind: socket bound to 0.0.0.0.771
dumper: pid 14500 executable dumper version 2.4.2p2, using port 771
dumper: dgram_bind: socket bound to 0.0.0.0.524
dumper: pid 23981 executable dumper version 2.4.2p2, using port 524
got result for host $Tru64-client disk /usr: 0 -> -1K, -1 -> -1K, -1 -> -1K
got result for host $Tru64-client disk /: 0 -> -1K, -1 -> -1K, -1 -> -1K
getting estimates took 2.094 secs
FAILED QUEUE:
  0: $Tru64-client     /usr
  1: $Tru64-client     /   
DONE QUEUE: empty

ANALYZING ESTIMATES...
planner: FAILED $Tru64-client /usr 0 [disk /usr offline on $Tru64-client?]
planner: FAILED $Tru64-client / 0 [disk / offline on $Tru64-client?]
INITIAL SCHEDULE (size 4064):

DELAYING DUMPS IF NEEDED, total_size 4064, tape length 20480000 mark 2000
  delay: Total size now 4064.

PROMOTING DUMPS IF NEEDED, total_lev0 0, balanced_size 0...
analysis took 0.000 secs

GENERATING SCHEDULE:
--------
--------
driver: adding holding disk 0 dir /usr/dump size 296960
reserving 296960 out of 296960 for degraded-mode dumps
driver: start time 2.099 inparallel 4 bandwidth 2000 diskspace 296960 dir 
OBSOLETE datestamp 20030213 driver: drain-ends tapeq LFFO big-dumpers 1
taper: read label `DailySet103' date `20030211'
taper: wrote label `DailySet103' date `20030213'
driver: result time 6.972 from taper: TAPER-OK
driver: state time 6.972 free kps: 2000 space: 296960 taper: idle idle-dumpers: 
4 qlen tapeq: 0 runq: 0 roomq: 0 wakeup: 86400 driver-idle: not-idle
driver: interface-state time 6.972 if : free 600 if LE0: free 400 if LOCAL: 
free 1000
driver: hdisk-state time 6.972 hdisk 0: free 296960 dumpers 0
driver: QUITTING time 6.972 telling children to quit
driver: send-cmd time 6.972 to dumper0: QUIT
driver: send-cmd time 6.973 to dumper1: QUIT
driver: send-cmd time 6.973 to dumper2: QUIT
driver: send-cmd time 6.974 to dumper3: QUIT
driver: send-cmd time 6.975 to taper: QUIT
taper: DONE [idle wait: 0.001 secs]
taper: writing end marker. [DailySet103 OK kb 0 fm 0]
driver: FINISHED time 13.001
amdump: end at Thu Feb 13 15:31:56 GMT 2003

********************************************************

Tru64-client amandad.debug:

amandad: debug 1 pid 268246 ruid 203 euid 203 start time Thu Feb 13 17:39:50 
2003
amandad: version 2.4.2p2
amandad: build: VERSION="Amanda-2.4.2p2"
amandad:        BUILT_DATE="Tue Feb 11 20:21:47 GMT 2003"
amandad:        BUILT_MACH="OSF1 $Tru64-client V5.1 1885 alpha"
amandad:        CC="cc"
amandad: paths: bindir="/usr/local/bin" sbindir="/usr/local/sbin"
amandad:        libexecdir="/usr/local/libexec" mandir="/usr/local/man"
amandad:        AMANDA_TMPDIR="/tmp/amanda" AMANDA_DBGDIR="/tmp/amanda"
amandad:        CONFIG_DIR="/usr/local/etc/amanda" DEV_PREFIX="/dev/"
amandad:        RDEV_PREFIX="/dev/" DUMP="/sbin/dump"
amandad:        RESTORE="/sbin/restore" VDUMP="/sbin/vdump"
amandad:        VRESTORE="/sbin/vrestore" GNUTAR="/usr/local/bin/gtar"
amandad:        COMPRESS_PATH="/bin/gzip" UNCOMPRESS_PATH="/bin/gzip"
amandad:        MAILER="/bin/Mail"
amandad:        listed_incr_dir="/usr/local/var/amanda/gnutar-lists"
amandad: defs:  DEFAULT_SERVER="$Tru64-client"
amandad:        DEFAULT_CONFIG="DailySet1"
amandad:        DEFAULT_TAPE_SERVER="$Tru64-client"
amandad:        DEFAULT_TAPE_DEVICE="/dev/null" HAVE_MMAP HAVE_SYSVSHM
amandad:        LOCKING=**NONE** STATFS_OSF1 DEBUG_CODE AMANDA_DEBUG_DAYS=4
amandad:        BSD_SECURITY USE_AMANDAHOSTS CLIENT_LOGIN="amanda"
amandad:        FORCE_USERID HAVE_GZIP COMPRESS_SUFFIX=".gz"
amandad:        COMPRESS_FAST_OPT="--fast" COMPRESS_BEST_OPT="--best"
amandad:        UNCOMPRESS_OPT="-dc"
got packet:
--------
Amanda 2.4 REQ HANDLE 000-00330200 SEQ 1045158323
SECURITY USER operator
SERVICE sendsize
OPTIONS maxdumps=1;hostname=$Tru64-client;
DUMP /usr 0 1970:1:1:0:0:0 -1
DUMP / 0 1970:1:1:0:0:0 -1
--------

sending ack:
----
Amanda 2.4 ACK HANDLE 000-00330200 SEQ 1045158323
----

bsd security: remote host $amanda-server user operator local user amanda
amandahosts security check passed
amandad: running service "/usr/local/libexec/sendsize"
amandad: sending REP packet:
----
Amanda 2.4 REP HANDLE 000-00330200 SEQ 1045158323
OPTIONS maxdumps=1;
/ 0 SIZE -1
/usr 0 SIZE -1
----

amandad: got packet:
----
Amanda 2.4 ACK HANDLE 000-00330200 SEQ 1045158323
----

amandad: pid 268246 finish time Thu Feb 13 17:39:52 2003

*******************************************************************

Tru64-client sendsize.debug:

sendsize: debug 1 pid 268247 ruid 203 euid 203 start time Thu Feb 13 17:39:50 
2003
/usr/local/libexec/sendsize: version 2.4.2p2
calculating for amname '/', dirname '/'
sendsize: getting size via dump for / level 0
sendsize: running "/sbin/dump 0Ssf 1048576 - /dev/rdisk/dsk0a"
running /usr/local/libexec/killpgrp
dump: Cannot fopen /dev/tty for reading
query(): fopen(): No such device or address
dump: SIGTERM received 
dump: The ENTIRE dump is aborted
.....
(no size line match in above dump output)
.....
asking killpgrp to terminate
calculating for amname '/usr', dirname '/usr'
sendsize: getting size via dump for /usr level 0
sendsize: running "/sbin/dump 0Ssf 1048576 - /dev/rdisk/dsk0d"
running /usr/local/libexec/killpgrp
dump: Cannot fopen /dev/tty for reading
query(): fopen(): No such device or address
dump: SIGTERM received 
dump: The ENTIRE dump is aborted
.....
(no size line match in above dump output)
.....
asking killpgrp to terminate
sendsize: pid 268247 finish time Thu Feb 13 17:39:52 2003


************************************************************