Amanda-Users

Re: Amanda stopped working...

2006-06-19 13:03:02
Subject: Re: Amanda stopped working...
From: Pavel Pragin <ppragin AT zmanda DOT com>
To: Josef Wolf <jw AT raven.inka DOT de>
Date: Mon, 19 Jun 2006 09:50:23 -0700
Josef Wolf wrote:

Hello!

Amanda-2.5.0b2 was working for about six months here.  Now it stopped
working for some reason, and I can't figure out why.  It looks to me as
if there's something wrong with getting stimates.

From the amdump file it looks like estimates are scheduled, but never
return any results.

Here's the amdump file:

amdump: start at Sa Jun 17 16:50:46 CEST 2006
amdump: datestamp 20060617
planner: pid 5050 executable /usr/lib/amanda/planner version 2.5.0b2
planner: build: VERSION="Amanda-2.5.0b2"
planner:        BUILT_DATE="Tue Feb 14 00:04:47 CET 2006"
planner:        BUILT_MACH="Linux host 2.6.13-15.7-default #1 Tue Nov 29 14:32:29 
UTC 2005 i686 athlon i386 GNU/Linux"
planner:        CC="gcc"
planner:        CONFIGURE_COMMAND="'./configure' '--mandir=/usr/share/man' 
'--prefix=/usr' '--infodir=/usr/share/info' '--sysconfdir=/etc' '--libdir=/usr/lib' 
'--libexecdir=/usr/lib/amanda' '--localstatedir=/var/lib' 
'--with-dumperdir=/usr/lib/amanda' '--with-index-server=localhost' 
'--with-gnutar-listdir=/var/lib/amanda/gnutar-lists' 
'--with-smbclient=/usr/bin/smbclient' '--with-amandahosts' '--with-user=amanda' 
'--with-group=disk' '--with-gnutar=/bin/tar' '--disable-libtool' '--disable-shared' 
'--disable-static'"
planner: paths: bindir="/usr/bin" sbindir="/usr/sbin"
planner:        libexecdir="/usr/lib/amanda" mandir="/usr/share/man"
planner:        AMANDA_TMPDIR="/tmp/amanda" AMANDA_DBGDIR="/tmp/amanda"
planner:        CONFIG_DIR="/etc/amanda" DEV_PREFIX="/dev/"
planner:        RDEV_PREFIX="/dev/" DUMP="/sbin/dump"
planner:        RESTORE="/sbin/restore" VDUMP=UNDEF VRESTORE=UNDEF
planner:        XFSDUMP=UNDEF XFSRESTORE=UNDEF VXDUMP=UNDEF VXRESTORE=UNDEF
planner:        SAMBA_CLIENT="/usr/bin/smbclient" GNUTAR="/bin/tar"
planner:        COMPRESS_PATH="/usr/bin/gzip"
planner:        UNCOMPRESS_PATH="/usr/bin/gzip" LPRCMD="/usr/bin/lpr"
planner:        MAILER="/usr/bin/Mail"
planner:        listed_incr_dir="/var/lib/amanda/gnutar-lists"
planner: defs:  DEFAULT_SERVER="localhost" DEFAULT_CONFIG="DailySet1"
planner:        DEFAULT_TAPE_SERVER="localhost"
planner:        DEFAULT_TAPE_DEVICE="null:" HAVE_MMAP HAVE_SYSVSHM
planner:        LOCKING=POSIX_FCNTL SETPGRP_VOID DEBUG_CODE
planner:        AMANDA_DEBUG_DAYS=4 BSD_SECURITY RSH_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"
READING CONF FILES...
planner: time 0.001: startup took 0.001 secs

SENDING FLUSHES...
FLUSH host.do.main /m/l 20060611 1 
/b/amchanger/ppc/hold/20060611030501/host.do.main._m_l.1
FLUSH host.do.main /m/l 20060612 1 
/b/amchanger/ppc/hold/20060612030501/host.do.main._m_l.1
ENDFLUSH

SETTING UP FOR ESTIMATES...
planner: time 0.002: setting up estimates for dssl-gw.do.main:/
setup_estimate: dssl-gw.do.main:/: command 1, options: none    last_level -1 
next_level0 0 level_days 0    getting estimates 0 (-2) -1 (-2) -1 (-2)
planner: time 0.002: setting up estimates for host.do.main:/
setup_estimate: host.do.main:/: command 1, options: none    last_level -1 
next_level0 0 level_days 0    getting estimates 0 (-2) -1 (-2) -1 (-2)
planner: time 0.003: setting up estimates for host.do.main:/m/b
setup_estimate: host.do.main:/m/b: command 1, options: none    last_level -1 
next_level0 0 level_days 0    getting estimates 0 (-2) -1 (-2) -1 (-2)
planner: time 0.003: setting up estimates for host.do.main:/m/check
setup_estimate: host.do.main:/m/check: command 1, options: none    last_level 
-1 next_level0 0 level_days 0    getting estimates 0 (-2) -1 (-2) -1 (-2)
planner: time 0.004: setting up estimates for host.do.main:/m/l
setup_estimate: host.do.main:/m/l: command 1, options: none    last_level -1 
next_level0 0 level_days 0    getting estimates 0 (-2) -1 (-2) -1 (-2)
planner: time 0.004: setting up estimates for host.do.main:/var
setup_estimate: host.do.main:/var: command 1, options: none    last_level -1 
next_level0 0 level_days 0    getting estimates 0 (-2) -1 (-2) -1 (-2)
planner: time 0.005: setting up estimates took 0.003 secs

GETTING ESTIMATES...
planner: time 0.035: bind_portrange2: trying port=659
planner: time 0.035: dgram_bind: socket bound to 0.0.0.0.659
driver: pid 5051 executable /usr/lib/amanda/driver version 2.5.0b2
driver: tape size 4096000
taper: pid 5052 executable taper version 2.5.0b2
taper: page size is 4096
taper: buffer size is 32768
taper: buffer[00] at 0x401e4000
taper: buffer[01] at 0x401ec000
taper: buffer[02] at 0x401f4000
taper: buffer[03] at 0x401fc000
taper: buffer[04] at 0x40204000
taper: buffer[05] at 0x4020c000
taper: buffer[06] at 0x40214000
taper: buffer[07] at 0x4021c000
taper: buffer[08] at 0x40224000
taper: buffer[09] at 0x4022c000
taper: buffer[10] at 0x40234000
taper: buffer[11] at 0x4023c000
taper: buffer[12] at 0x40244000
taper: buffer[13] at 0x4024c000
taper: buffer[14] at 0x40254000
taper: buffer[15] at 0x4025c000
taper: buffer[16] at 0x40264000
taper: buffer[17] at 0x4026c000
taper: buffer[18] at 0x40274000
taper: buffer[19] at 0x4027c000
taper: buffer structures at 0x40284000 for 240 bytes
driver: send-cmd time 0.004 to taper: START-TAPER 20060617
driver: adding holding disk 0 dir /b/amchanger/ppc/hold size 9437184 chunksize 
1048576
reserving 9437184 out of 9437184 for degraded-mode dumps
dumper: pid 5054 executable dumper0 version 2.5.0b2
driver: started dumper0 pid 5054
dumper: pid 5055 executable dumper1 version 2.5.0b2
driver: started dumper1 pid 5055
dumper: pid 5056 executable dumper2 version 2.5.0b2
driver: started dumper2 pid 5056
dumper: pid 5057 executable dumper3 version 2.5.0b2
driver: started dumper3 pid 5057
dumper: pid 5058 executable dumper4 version 2.5.0b2
driver: started dumper4 pid 5058
changer: opening pipe to: /usr/local/bin/chg-disk.pl -info
driver: started dumper5 pid 5059
dumper: pid 5061 executable dumper6 version 2.5.0b2
driver: started dumper6 pid 5061
dumper: pid 5063 executable dumper7 version 2.5.0b2
driver: started dumper7 pid 5063
dumper: pid 5064 executable dumper8 version 2.5.0b2
driver: started dumper8 pid 5064
dumper: pid 5065 executable dumper9 version 2.5.0b2
dumper: pid 5059 executable dumper5 version 2.5.0b2
driver: started dumper9 pid 5065
driver: start time 0.041 inparallel 10 bandwidth 19600 diskspace 9437184 dir 
OBSOLETE datestamp 20060617 driver: drain-ends tapeq LARGESTFIT big-dumpers ttt
changer: got exit: 0 str: 2 10 1 1
changer_query: changer return was 10 1 1
changer_query: searchable = 1
changer_find: looking for PPC03 changer is searchable = 1
changer_search: PPC03
changer: opening pipe to: /usr/local/bin/chg-disk.pl -search PPC03
changer: got exit: 0 str: 3 file:/b/amchanger/ppc
taper: wrote label `PPC03' date `20060617'
driver: result time 7.616 from taper: TAPER-OK driver: send-cmd time 7.616 to taper: FILE-WRITE 00-00001 /b/amchanger/ppc/hold/20060611030501/host.do.main._m_l.1 host.do.main UNKNOWNFEATURE /m/l 1 20060611 716800
driver: startaflush: LARGESTFIT host.do.main /m/l 117 4096000
driver: state time 7.616 free kps: 19600 space: 9437184 taper: writing 
idle-dumpers: 10 qlen tapeq: 1 runq: 0 roomq: 0 wakeup: 0 driver-idle: not-idle
driver: interface-state time 7.616 if : free 800 if ETH10: free 800 if ETH100: 
free 8000 if LOCAL: free 10000
driver: hdisk-state time 7.616 hdisk 0: free 9437184 dumpers 0
driver: flush size 0
taper: r: Total dump size should be 85kb, chunk size is 716800kb
taper: r: Expecting to split into 1 parts taper: reader-side: got label PPC03 filenum 1
driver: state time 7.643 free kps: 19600 space: 9437184 taper: writing 
idle-dumpers: 10 qlen tapeq: 1 runq: 0 roomq: 0 wakeup: 0 driver-idle: 
no-dumpers
driver: interface-state time 7.643 if : free 800 if ETH10: free 800 if ETH100: 
free 8000 if LOCAL: free 10000
driver: hdisk-state time 7.643 hdisk 0: free 9437184 dumpers 0
driver: result time 7.643 from taper: DONE 00-00001 PPC03 1 [sec 0.026 kb 128 
kps 4821.1 {wr: writers 4 rdwait 0.024 wrwait 0.001 filemark 0.000}]
driver: finished-cmd time 7.659 taper wrote host.do.main:/m/l
driver: send-cmd time 7.659 to taper: FILE-WRITE 00-00002 
/b/amchanger/ppc/hold/20060612030501/host.do.main._m_l.1 host.do.main 
UNKNOWNFEATURE /m/l 1 20060612 716800
driver: startaflush: LARGESTFIT host.do.main /m/l 129 4095883
taper: r: Total dump size should be 97kb, chunk size is 716800kb
taper: r: Expecting to split into 1 parts driver: state time 7.660 free kps: 19600 space: 9437301 taper: writing idle-dumpers: 10 qlen tapeq: 0 runq: 0 roomq: 0 wakeup: 0 driver-idle: no-dumpers
driver: interface-state time 7.660 if : free 800 if ETH10: free 800 if ETH100: 
free 8000 if LOCAL: free 10000
driver: hdisk-state time 7.660 hdisk 0: free 9437301 dumpers 0
driver: result time 7.660 from taper: SPLIT-CONTINUE 00-00002 PPC03
taper: reader-side: got label PPC03 filenum 2
driver: state time 7.684 free kps: 19600 space: 9437301 taper: writing 
idle-dumpers: 10 qlen tapeq: 0 runq: 0 roomq: 0 wakeup: 0 driver-idle: 
no-dumpers
driver: interface-state time 7.684 if : free 800 if ETH10: free 800 if ETH100: 
free 8000 if LOCAL: free 10000
driver: hdisk-state time 7.684 hdisk 0: free 9437301 dumpers 0
driver: result time 7.684 from taper: DONE 00-00002 PPC03 2 [sec 0.023 kb 160 
kps 6699.3 {wr: writers 5 rdwait 0.021 wrwait 0.001 filemark 0.000}]
driver: finished-cmd time 7.699 taper wrote host.do.main:/m/l
driver: state time 7.699 free kps: 19600 space: 9437430 taper: idle 
idle-dumpers: 10 qlen tapeq: 0 runq: 0 roomq: 0 wakeup: 0 driver-idle: 
no-dumpers
driver: interface-state time 7.699 if : free 800 if ETH10: free 800 if ETH100: 
free 8000 if LOCAL: free 10000
driver: hdisk-state time 7.699 hdisk 0: free 9437430 dumpers 0
driver: QUITTING time 7.699 telling children to quit
driver: send-cmd time 7.699 to dumper0: QUIT
driver: send-cmd time 7.699 to dumper1: QUIT
driver: send-cmd time 7.699 to dumper2: QUIT
driver: send-cmd time 7.699 to dumper3: QUIT
driver: send-cmd time 7.699 to dumper4: QUIT
driver: send-cmd time 7.699 to dumper5: QUIT
driver: send-cmd time 7.699 to dumper6: QUIT
driver: send-cmd time 7.699 to dumper7: QUIT
driver: send-cmd time 7.699 to dumper8: QUIT
driver: send-cmd time 7.700 to dumper9: QUIT
driver: send-cmd time 7.700 to taper: QUIT
taper: DONE [idle wait: 0.033 secs]
taper: writing end marker. [PPC03 OK kb 288 fm 2]
driver: FINISHED time 7.703
amdump: end at Sa Jun 17 16:50:54 CEST 2006
Scanning /b/amchanger/ppc/hold...
Josef,
I think we will need a little more information. Can you please tar up post the debug logs from /tmp/amanda on the server?
thanks

<Prev in Thread] Current Thread [Next in Thread>