Hello!
It's me again with taking my vtapes based config from old Amanda 2.4.4
server to new Amanda 2.5.1p2 server. I have my tapetype definition set
so that one 160 GB partition is divided into 5x50GB vtapes. This is done
considering that on most nights Amanda doesn't really fill the vtape so
there is actually safe to write more than 160GB/5 to a vtape on some
other nights. The 50 GB limit is there just so Amanda doesn't plan too
many full dumps for any single run.
define tapetype HARDDISK {
comment "Backup to external HDD"
length 51200 mbytes
filemark 0 kbytes
speed 40000 kbytes
}
On the old server this consideration seemed to hold true - on some
nights less than 40 GB got dumped, on some days even more than the 51200
MB specified in the tapetype (when Amanda miscalculated slightly). The
only time there was an "out of tape" error was when the external HDD
actually filled up.
Yesterday, I made the first amdump run on new server. Since amdump
hadn't been run for several days, Amanda tried to schedule as many full
backups as possible. Most of the DLEs were backed up successfully, but
the last one failed with
server Archive lev 1 FAILED [out of tape]
server Archive lev 1 FAILED [data write: Broken pipe]
server Archive lev 1 FAILED [dump to tape failed]
And the external HDD didn't fill up, it still has 40 GB free.
However the size of vtape from this amdump run is suspiciously close to
my "length" parameter:
# pwd
/backup/slot6
# du -m
51213 .
Hence my question: Does Amanda now enforce the "length" parameter when
writing to a vtape? In such a way that if "length" is reached in the
middle of taping the DLE then taping is stopped and "out of tape" announced?
Here's the end of amandad.debug from this run:
amandad: time 4353.619: stream_accept: connection from 12.34.56.78.1026
amandad: try_socksize: send buffer size is 65536
amandad: try_socksize: receive buffer size is 65536
amandad: time 4353.619: stream_accept: connection from 12.34.56.78.1026
amandad: try_socksize: send buffer size is 65536
amandad: try_socksize: receive buffer size is 65536
amandad: time 4353.619: stream_accept: connection from 12.34.56.78.1026
amandad: try_socksize: send buffer size is 65536
amandad: try_socksize: receive buffer size is 65536
security_close(handle=0x50d100, driver=0x80085d040 (BSD))
security_stream_seterr(0x527000, write error on stream 63480: Connection
reset by peer)
amandad: time 6183.197: sending NAK pkt:
<<<<<
ERROR write error on stream 63480: write error on stream 63480:
Connection reset by peer
>>>>>
And interestingly Amanda actually dumped core at the time which matches
the timestamp of this amandad.debug file:
Jan 26 01:26:20 server kernel: pid 40527 (amandad), uid 3951: exited on
signal 11 (core dumped)
Jan 26 01:26:20 server sendbackup[41450]: index tee cannot write [Broken
pipe]
Jan 26 01:26:20 server sendbackup[41447]: error [/usr/local/bin/gtar
returned 2, compress returned 1]
Jan 26 01:26:20 server inetd[16676]:
/usr/local/libexec/amanda/amandad[40527]: exited, signal 11
Here is also the relevant sendbackup.debug from the client (which is
actually the same as the server):
Could not open conf file "/usr/local/etc/amanda/amanda-client.conf": No
such file or directory
Reading conf file "/usr/local/etc/amanda/BACKUP/amanda-client.conf".
sendbackup: debug 1 pid 41447 ruid 3951 euid 3951: rename at Fri Jan 26
00:55:50 2007
sendbackup req: <GNUTAR Archive /storage/files/Archive 1
2007:1:11:3:34:13 OPTIONS |;auth=BSD;compress-fast
;index;>
parsed request as: program `GNUTAR'
disk `Archive'
device `/storage/files/Archive'
level 1
since 2007:1:11:3:34:13
options `|;auth=BSD;compress-fast;index;'
sendbackup: start: server.domain.ee:Archive lev 1
sendbackup: time 0.000: spawning /usr/bin/gzip in pipeline
sendbackup: argument list: /usr/bin/gzip --fast
sendbackup-gnutar: time 0.001: pid 41449: /usr/bin/gzip --fast
sendbackup-gnutar: time 0.001: error opening
'/var/amanda/gnutar-lists/serverArchive_0': No such file or directory
sendbackup-gnutar: time 0.001: doing level 1 dump as listed-incremental
to '/var/amanda/gnutar-lists/serverArchive_1.new'
sendbackup-gnutar: time 0.005: doing level 1 dump from date: 1970-01-01
0:00:00 GMT
sendbackup: time 0.006: spawning /usr/local/libexec/amanda/runtar in
pipeline
sendbackup: argument list: runtar BACKUP GNUTAR --create --file -
--directory /storage/files/Archive --one-file-system
--listed-incremental /var/amanda/gnutar-lists/serverArchive_1.new
--sparse --ignore-failed-read --totals .
sendbackup-gnutar: time 0.007: /usr/local/libexec/amanda/runtar: pid 41451
sendbackup: time 0.007: started backup
sendbackup: time 0.007: started index creator: "/usr/local/bin/gtar -tf
- 2>/dev/null | sed -e 's/^\.//'"
sendbackup: time 1829.721: 118: strange(?):
sendbackup: time 1829.721: index tee cannot write [Broken pipe]
sendbackup: time 1829.721: 118: strange(?): gzip: stdout: Broken pipe
sendbackup: time 1829.721: pid 41450 finish time Fri Jan 26 01:26:20 2007
sendbackup: time 1829.722: 118: strange(?): sendbackup: index tee cannot
write [Broken pipe]
sendbackup: time 1829.722: 47: size(|): Total bytes written:
23088240640 (22GiB, ?/s)
sendbackup: time 1829.730: 118: strange(?): GNUTAR: -: Cannot write:
Broken pipe
sendbackup: time 1829.739: 118: strange(?): GNUTAR: sed: stdout: Broken pipe
sendbackup: time 1829.739: 118: strange(?): Error is not recoverable:
exiting now
sendbackup: time 1829.758: error [/usr/local/bin/gtar returned 2,
compress returned 1]
sendbackup: time 1829.758: pid 41447 finish time Fri Jan 26 01:26:20 2007
| 